SchOS/tools/bootcheck.ps1

# Headless boot check: run SchOS under QEMU, type commands at the shell, and
# assert on what actually comes back.
#
# Booting to a prompt proves nothing on its own -- a filesystem can mount and
# still fail on the first real command, and exactly that has happened here
# before. So this drives the serial console and greps the transcript for the
# answers those commands should produce.
#
# The console is stdio with a chardev logfile: QEMU writes every byte of the
# session to a file itself, so this script only ever has to *write* to stdin.
# Reading QEMU's stdout from PowerShell needs a reader that cannot block the
# writer, and two attempts at that (a background task, then a duplex named
# pipe) both deadlocked. Letting QEMU do the logging removes the problem.
#
# QEMU's serial line has no flow control: a burst of characters gets dropped,
# and anything typed before the shell is listening is discarded outright. Hence
# the pacing below -- not superstition, just the difference between a reliable
# check and a flaky one.
#
#   tools\bootcheck.ps1
#   tools\bootcheck.ps1 -Tty -Ps

param(
    [switch]$Fb,
    # Boot schos.iso from an emulated optical drive with NO hard disk
    # attached, which is the only way to prove the ISO is self-contained.
    # Needs `make iso` first.
    [switch]$Iso,
    # Terminal behaviour: pipes, isatty, SIGPIPE, and Ctrl-C. None of these
    # can be checked by looking at a screenshot, and all of them were broken
    # in ways that looked like broken *commands*.
    [switch]$Tty,
    # Attach an xHCI controller with a keyboard, a mouse and a mass storage
    # device on it. Nothing on the default machine has a USB port, so without
    # this the USB driver is never asked to do anything and a broken one looks
    # exactly like a working one.
    [switch]$Usb,
    # Unix domain sockets. Nothing in the default command set opens one, and a
    # socket layer that accepted every call and dropped every byte would look
    # identical from the outside -- socktest has one process write and another
    # read, which is the only check that can tell the difference.
    [switch]$Sock,
    # Raw input events. Needs the QEMU monitor for the same reason the USB run
    # does: a key has to be *pressed*, and characters typed at the serial port
    # never touch the keyboard controller at all.
    [switch]$Evdev,
    # Process enumeration. /proc is a synthetic filesystem now, and the thing
    # it exists for -- one directory per process -- is exactly what nothing
    # else in this suite touches.
    [switch]$Ps,
    [int]$BootSeconds = 20,
    [string]$Qemu = "$env:USERPROFILE\scoop\apps\qemu\current\qemu-system-x86_64.exe"
)

$ErrorActionPreference = 'Stop'
$root = Split-Path $PSScriptRoot -Parent
$hda  = Join-Path $root 'schos.img'
# The root filesystem. SchFS is the only root there is, so this is not a
# choice -- a kernel handed anything else on device 1 panics in forkret().
$hdb  = Join-Path $root 'build\schfs.img'
$log  = Join-Path $root 'build\bootcheck.log'

Remove-Item -Force $log -ErrorAction SilentlyContinue

# The default run exercises the *root* filesystem: create a file, read it back,
# grow it, list a directory, seek around it. Booting to a prompt proves nothing
# on its own, and every one of these has broken at some point while the boot
# still looked perfectly healthy.
$commands = @(
    'echo hello-from-schos > /tmp/bc.txt'
    'cat /tmp/bc.txt'
    'echo second-line >> /tmp/bc.txt'
    'wc -c /tmp/bc.txt'
    'mkdir /tmp/bcdir'
    'cp /tmp/bc.txt /tmp/bcdir/copy.txt'
    'cat /tmp/bcdir/copy.txt'
    'ls /tmp/bcdir'
    'rm /tmp/bcdir/copy.txt'
    'rmdir /tmp/bcdir'
    'ls /bin | wc -l'
    'cat /proc/pci'
)
# Every command above already went to SchFS. What is left is to show that
# it is SchFS they went to, and that the volume noticed: the generation
# counter must advance across the writes, which is the one thing a
# read-only mount or a silently-discarded write could not fake.
$commands += 'cat /proc/schfs'
# Mounting the root device a second time has to fail. It is the check that
# tells "the volume is genuinely mounted as /" apart from "it happens to be
# readable", and getting EBUSY here is the correct answer, not a defect.
$commands += 'mkdir /mnt'
$commands += 'mount -t schfs /dev/hdb /mnt'
# A deep path built and torn down entirely on the root volume.
$commands += 'mkdir /tmp/rootdir'
$commands += 'mkdir /tmp/rootdir/sub'
$commands += 'echo schfs-is-root > /tmp/rootdir/sub/deep.txt'
$commands += 'cat /tmp/rootdir/sub/deep.txt'
$commands += 'ls /tmp/rootdir/sub'
$commands += 'rm /tmp/rootdir/sub/deep.txt'
$commands += 'rmdir /tmp/rootdir/sub'
$commands += 'rmdir /tmp/rootdir'
# A binary loaded off the root volume, not a shell builtin: exec() reading
# an ELF through schfs_ops is the path that carried init itself.
$commands += 'wc -l /etc/motd'
# The second dump. The generation counter is compared against the first
# one: on a copy-on-write volume it moves on every committed transaction,
# so a root that silently discarded its writes would still pass every read
# above and fail here.
$commands += 'cat /proc/schfs'

if ($Fb) {
    # /dev/fb0. The geometry has to come back from the mode the bootloader
    # actually programmed -- three places in the kernel used to assume
    # 0xfd000000 at 800x600x32, and nothing would have said when that stopped
    # being true. `bars` goes through the device's write(), `fill` through
    # mmap, so a failure names which of the two paths broke.
    $commands += 'fbinfo'
    $commands += 'fbinfo bars'
    $commands += 'fbinfo fill'
}
if ($Tty) {
    # `ls` piped into `wc -l` reported 48 rather than 240 because ioctl
    # answered TIOCGWINSZ on a *pipe* with success, so ls formatted in
    # columns. `yes` failed outright because writev capped iovcnt at 16 and
    # toybox builds 256 of them. `cat | head` killed the shell, because
    # SIG_IGN is handler value 1 and signal delivery jumped to address 1.
    # Three different-looking bugs, none of them in the commands.
    $commands += 'ls /bin | wc -l'
    $commands += 'yes | head -2'
    # 4 bytes, not 3: an ELF file starts with 0x7F 'E' 'L' 'F', so three bytes
    # stops at "EL" and the invisible leading byte makes that easy to misread.
    $commands += 'cat /bin/toybox | head -c 4; echo'
    $commands += 'printf ''caf\303\251-\303\261-\303\266\n'''
    $commands += 'echo TTY-SURVIVED'
    # Shared memory and file-backed mmap: the two things a display server
    # cannot be written without, and the two whose failure mode is a
    # successful-looking return value.
    $commands += 'shmtest'
}
if ($Usb) {
    # /proc/interrupts is how you tell a registered handler from one that
    # merely compiled. A line with a zero count is a device that was found and
    # never heard from.
    $commands += 'cat /proc/interrupts'
    # Read a real block off the USB stick, through the buffer cache. Answering
    # INQUIRY proves a device is there; only this proves it can read.
    $commands += 'echo s > /proc/sysrq'
}
if ($Sock) {
    $commands += 'socktest'
}
if ($Ps) {
    $commands += 'ls /proc'
    $commands += 'cat /proc/1/stat'
    $commands += 'ps'
    $commands += 'ps -A -o pid,ppid,comm'
    $commands += 'top -b -n 1 | head -6'
}
$commands += 'echo MARKER-DONE'

# The ISO run attaches no hard disk at all. That is the whole point: a kernel
# that still quietly needs one would boot happily here otherwise, and only
# fail on someone else's machine.
$isoPath = Join-Path $root 'schos.iso'
if ($Iso -and -not (Test-Path $isoPath)) { throw "no $isoPath -- run 'make iso' first" }

$drives = if ($Iso) {
    @("-cdrom `"$isoPath`"", '-boot d')
} else {
    @("-drive file=`"$hda`",format=raw,index=0,media=disk"
      "-drive file=`"$hdb`",format=raw,index=1,media=disk")
}

$psi = New-Object System.Diagnostics.ProcessStartInfo
$psi.FileName = $Qemu
$usbDevices = if ($Usb) {
    # One device of each speed class QEMU can produce: usb-storage negotiates
    # SuperSpeed on qemu-xhci, the HID devices come up high speed. They take
    # different paths through enumeration -- a USB3 port arrives already
    # enabled and a USB2 port has to be reset first -- so one of each is the
    # difference between testing the driver and testing half of it.
    @('-device qemu-xhci,id=xhci'
      '-device usb-kbd,bus=xhci.0'
      # The mouse goes behind a hub, so the tree is a tree and not a row of
      # root ports. That exercises the route string, the hub's own slot
      # context, and the transaction translator -- none of which a device
      # plugged straight into the controller touches at all.
      # QEMU places a device under a hub by port *path*, not by a child bus:
      # the hub sits on port 2 and the mouse on port 2.1 of the same bus.
      '-device usb-hub,id=hub,bus=xhci.0,port=2'
      '-device usb-mouse,bus=xhci.0,port=2.1'
      # Always the v1 image, never $hdb. The checks below read a v1 superblock
      # off this stick and assert on its sector count and size field, so the
      # stick has to be a v1 image whatever the root filesystem is -- under
      # the root $hdb is a SchFS volume and those fields are simply not
      # there, which failed three USB checks that had nothing wrong with USB.
      # It also stops the same file being attached twice, once as the root
      # disk and once as a USB device.
      "-drive id=usbstick,file=`"$(Join-Path $root 'build\fs.img')`",format=raw,if=none"
      '-device usb-storage,bus=xhci.0,drive=usbstick')
} else { @() }

# The USB run needs the QEMU monitor, because `sendkey` is the only way to
# press a key on an emulated USB keyboard -- typing on stdin goes to the
# serial port and proves nothing about USB.
# Ask the OS for a free port rather than hardcoding one. A run that dies
# before its `finally` leaves QEMU holding the old number, and every later run
# then fails with "Failed to find an available port" -- which looks like a
# bug in whatever is being tested rather than in the harness.
$monPort = if ($Usb -or $Evdev) {
    $l = [System.Net.Sockets.TcpListener]::new([System.Net.IPAddress]::Loopback, 0)
    $l.Start(); $p = $l.LocalEndpoint.Port; $l.Stop(); $p
} else { 0 }
$monitor = if ($Usb -or $Evdev) { @("-monitor tcp:127.0.0.1:$monPort,server,nowait") } else { @() }

$psi.Arguments = ($drives + $usbDevices + $monitor + @(
    '-m 1G -smp 1 -cpu qemu64,+rdtscp -machine pc-i440fx-9.2'
    '-display none'
    "-chardev stdio,id=c0,logfile=`"$log`""
    '-serial chardev:c0'
)) -join ' '
$psi.RedirectStandardInput = $true
$psi.UseShellExecute       = $false

$what = if ($Iso) { 'schos.iso, no hard disk' } else { "hdb = $(Split-Path $hdb -Leaf)" }
Write-Host "==> booting ($what)" -ForegroundColor Cyan
$p = [System.Diagnostics.Process]::Start($psi)

try {
    Start-Sleep -Seconds $BootSeconds     # wait for the shell prompt

    if ($Usb) {
        # Type a whole command on the *USB* keyboard. QEMU routes sendkey to
        # the most recently attached keyboard, so with usb-kbd present these
        # keystrokes go through xHCI, the interrupt endpoint, the HID report
        # decoder and the console -- none of which the serial path touches.
        # If any link in that chain is broken the characters simply vanish,
        # which is exactly how the missing interrupt showed up.
        Write-Host '  > (usb keyboard) echo usbworks' -ForegroundColor DarkGray
        $mon = New-Object System.Net.Sockets.TcpClient('127.0.0.1', $monPort)
        $monw = New-Object System.IO.StreamWriter($mon.GetStream())
        $monw.AutoFlush = $true
        Start-Sleep -Milliseconds 400
        foreach ($k in @('e','c','h','o','spc','u','s','b','w','o','r','k','s','ret')) {
            $monw.WriteLine("sendkey $k")
            Start-Sleep -Milliseconds 200
        }
        Start-Sleep -Seconds 2
        $mon.Close()
    }

    # Wait until the shell has finished the last command and printed a fresh
    # prompt, rather than sleeping a fixed interval and hoping.
    #
    # A flat 4-second wait was wrong in both directions: too long for the
    # dozens of commands that answer instantly, and too short for `ls /bin |
    # wc -l`, which reliably overran it. When it overran, the next command was
    # typed while the shell was still busy -- the tty echoed it but no reader
    # took it, and it ended up concatenated onto the following one. The
    # transcript showed `cat /proc/pcicat /proc/schfs` and three PCI checks
    # failed, which looks exactly like a broken PCI driver and is not one.
    #
    # This cannot read QEMU's stdout -- see the header; two attempts at that
    # deadlocked. It reads the logfile QEMU is writing instead, which is the
    # same bytes with none of the plumbing.
    function Wait-Prompt([int]$TimeoutMs = 20000) {
        $deadline = (Get-Date).AddMilliseconds($TimeoutMs)
        while ((Get-Date) -lt $deadline) {
            Start-Sleep -Milliseconds 150
            $tail = ''
            try { $tail = Get-Content $log -Raw -ErrorAction Stop } catch { continue }
            if ($null -eq $tail) { continue }
            # A prompt at the very end, with nothing typed after it.
            if ($tail -match '(?s)#[ ]?$') { return $true }
        }
        return $false
    }

    foreach ($cmd in $commands) {
        Write-Host "  > $cmd" -ForegroundColor DarkGray
        foreach ($ch in ($cmd + "`n").ToCharArray()) {
            $p.StandardInput.Write($ch)
            $p.StandardInput.Flush()
            Start-Sleep -Milliseconds 30   # no flow control: pace the input
        }
        if (-not (Wait-Prompt)) {
            Write-Host "  (no prompt after '$cmd' -- continuing)" -ForegroundColor Yellow
            Start-Sleep -Seconds 2
        }
    }

    if ($Evdev) {
        # Start a reader on /dev/input/event0 and then press keys at it. The
        # program blocks in read() until events arrive, so if the keyboard
        # driver is not feeding the input layer this hangs and prints nothing
        # -- which is a failure that says exactly which half is broken.
        Write-Host '  > inputtest -n 6, then press keys' -ForegroundColor DarkGray
        foreach ($ch in "inputtest -n 6`n".ToCharArray()) {
            $p.StandardInput.Write($ch); $p.StandardInput.Flush()
            Start-Sleep -Milliseconds 30
        }
        Start-Sleep -Seconds 2

        $mon  = New-Object System.Net.Sockets.TcpClient('127.0.0.1', $monPort)
        $monw = New-Object System.IO.StreamWriter($mon.GetStream())
        $monw.AutoFlush = $true
        Start-Sleep -Milliseconds 400
        # 'a' is keycode 30 and shift is 42, chosen because both numbers are
        # unmistakable in the output and neither is a scancode by accident.
        # Each sendkey is a press *and* a release, which is the whole point:
        # the console would report one character and nothing else.
        foreach ($k in @('a', 'shift', 'a', 'b')) {
            $monw.WriteLine("sendkey $k")
            Start-Sleep -Milliseconds 400
        }
        $mon.Close()
        Start-Sleep -Seconds 3

        # Those keypresses reached the console as well as the input device --
        # that is the design, not a leak -- so the shell's input line now holds
        # "aab". Clear it before typing the next command, or the shell tries to
        # run `aabecho`.
        $p.StandardInput.Write("`n"); $p.StandardInput.Flush()
        Start-Sleep -Milliseconds 500

        foreach ($ch in "echo INPUT-DONE`n".ToCharArray()) {
            $p.StandardInput.Write($ch); $p.StandardInput.Flush()
            Start-Sleep -Milliseconds 30
        }
        Start-Sleep -Seconds 3
    }

    if ($Tty) {
        # Ctrl-C has to reach the *foreground process group*. The old handler
        # set killed=1 on whatever process happened to be running when the
        # keyboard interrupt fired, which is almost never the one on screen.
        Write-Host '  > sleep 30, then Ctrl-C' -ForegroundColor DarkGray
        foreach ($ch in "sleep 30`n".ToCharArray()) {
            $p.StandardInput.Write($ch); $p.StandardInput.Flush()
            Start-Sleep -Milliseconds 30
        }
        Start-Sleep -Seconds 2
        $p.StandardInput.Write([char]3)   # ^C
        $p.StandardInput.Flush()
        Start-Sleep -Seconds 2
        foreach ($ch in "echo INTERRUPTED-OK`n".ToCharArray()) {
            $p.StandardInput.Write($ch); $p.StandardInput.Flush()
            Start-Sleep -Milliseconds 30
        }
        Start-Sleep -Seconds 3
    }
} finally {
    if (-not $p.HasExited) { $p.Kill() }
    Start-Sleep -Milliseconds 800
}

if (-not (Test-Path $log)) { throw "no serial log produced at $log" }
$text = Get-Content $log -Raw
if ($null -eq $text) { $text = '' }

Write-Host "==> serial transcript ($($text.Length) bytes) -> $log" -ForegroundColor Cyan
Write-Host $text

$script:fail = $false
function Expect($pattern, $what) {
    if ($script:text -match $pattern) {
        Write-Host "  [ok] $what" -ForegroundColor Green
    } else {
        Write-Host "  FAIL: $what (no match for /$pattern/)" -ForegroundColor Red
        $script:fail = $true
    }
}

Expect 'MARKER-DONE'              'shell stayed alive through every command'
Expect 'hello-from-schos'       'a file written on the root filesystem reads back'
Expect 'second-line'              'appending to that file works'
# 17 bytes of "hello-from-schos\n" plus 12 of "second-line\n". The exact
# number is the point: an append that silently truncated still produced a file,
# and only the byte count said which one.
#
# It follows the string above, so changing that changes this -- the SchOS
# rename shortened "hello-from-schunix" by two characters and this check went
# red on a filesystem that was working perfectly.
Expect '(?m)^\s*29\s'             'append extended the file rather than replacing it'
Expect '(?m)^copy\.txt'           'a copied file appears in a new directory'
Expect '(?ms)copy\.txt.*rmdir'    'rmdir removed the directory without an error'

# PCI. The point of these is that the numbers come off the bus rather than out
# of a header: the host bridge identifies the chipset QEMU is emulating, and
# the display controller's aperture is the same address VBE reported, checked
# by two completely independent paths.
Expect 'pci: \d+ devices'         'the PCI bus enumerated'
Expect '00:00\.0 8086:1237'       'the host bridge is where a host bridge belongs'
Expect '00:01\.1 8086:7010 IDE'   'the IDE controller was identified by class'
Expect '\[vga\]'                  'a driver bound itself to the display controller'
Expect 'vga: display controller'  'the display driver found its aperture'

Expect 'schfs: mounted'       'the kernel mounted SchFS as the root filesystem'
Expect 'init: ready'          'init came up on a SchFS root'
Expect 'label:\s*schos'     '/proc/schfs reports the volume label'
Expect 'root_objectid:\s*16'  '/proc/schfs reports the root object id'
Expect 'dir\s+bin'            'the root directory really contains bin/'
# / is the mounted volume, so mounting that same device again must be
# refused. Without this a kernel that had quietly fallen back to some other
# root would still pass everything else here.
Expect 'Resource busy'        'mounting the root device twice is refused'
Expect 'schfs-is-root'        'a file three directories deep reads back'
Expect '(?m)^deep\.txt'       'that file is listed by its full name'
Expect '(?m)^\s*1\s+/etc/motd' 'a binary loaded off the SchFS root runs'
# Two /proc/schfs dumps, before and after the writes. Same volume, so the
# generation must have moved -- if it has not, nothing was committed.
$gens = [regex]::Matches($text, 'generation:\s*(\d+)')
if ($gens.Count -ge 2 -and
    [int]$gens[$gens.Count-1].Groups[1].Value -gt [int]$gens[0].Groups[1].Value) {
    Write-Host "  [ok] the volume generation advanced across the writes" -ForegroundColor Green
} else {
    Write-Host "  FAIL: the volume generation did not advance -- writes were not committed" -ForegroundColor Red
    $script:fail = $true
}

if ($Fb) {
    Expect 'id\s+schosfb'        'FBIOGET_FSCREENINFO identifies the device'
    # 800x600 is what boot/stage2.S asks VBE for. Asserting the numbers rather
    # than just "the ioctl returned" is the point: the old code path returned
    # success with an untouched buffer, i.e. a 0x0 screen.
    Expect '(?m)^xres\s+800'       'the reported width is the mode actually set'
    Expect '(?m)^yres\s+600'       'the reported height is the mode actually set'
    Expect '(?m)^bits_per_pixel\s+32' 'the reported depth is the mode actually set'
    Expect '(?m)^smem_start\s+0x'  'the framebuffer reports a physical address'
    Expect '(?m)^line_length\s+3200' 'the stride comes from VBE, not from xres*bpp'
    Expect 'transp.*absent'        'the absent alpha channel is reported as length 0'
    Expect 'colour bars drawn'     'writing pixels through write() reaches the screen'
    Expect 'gradient drawn'        'mmap of /dev/fb0 maps the real framebuffer'
}

if ($script:fail) { exit 1 }
Write-Host 'boot check passed' -ForegroundColor Green