Improve disk benchmark suites and timing, and fix command launch race

doc/src/driver/storage/driver.storage.mgr.md

@@ -219,3 +219,37 @@ Drop-in procedure replacements for callers using the old void-returning API. For
 - `dispatch_next` is an internal procedure called with interrupts disabled. It dequeues the head of the CFIFO, allocates a heap copy via `ioreq_copy` (for ISR safety), and invokes the appropriate `dispatchRead` or `dispatchWrite` on the device. If neither dispatch pointer is set, the request is failed with `eDeviceNotFound`.
 - The blocking path relies on pointer-dereferenced spin (`puint32(@wait.Done)^`) to prevent FPC from caching the `Done` flag in a register across the `hlt` instruction.
 - Devices without `dispatchRead`/`dispatchWrite` set (i.e., drivers not yet migrated to Phase 2) will have `submit_io` return `eDeviceNotFound`. Legacy drivers must be migrated before they can use the new I/O path.
+
+
+## Bounded performance path
+
+The manager merges up to 32 consecutive queued requests when operation, device,
+LBA range, and virtual buffer range are contiguous. It never searches past the
+queue head or delays a lone request to create a merge. Drivers opt in through
+`mergeMaxSectors`; SATA AHCI advertises 65,536 sectors, while other drivers default
+to zero (disabled). A merged command delivers one completion to each original
+request, in FIFO order. A command error fails every member conservatively.
+
+`storage_get_stats` takes an interrupt-protected snapshot of the device counters.
+`DISK info <index>` displays accepted/completed/failed logical requests, hardware
+commands, merged requests, queue-full rejections, queue and active high-water
+marks, successful read/write sectors, request-size buckets, queue/service ticks,
+and FAT metadata cache hits/misses. Queue ticks are accumulated per logical
+request; service ticks are accumulated per hardware command. Tick values use
+`Counters.c32`, not milliseconds. Counters are unsigned 32-bit values, start at
+device registration, and wrap; use snapshot differences over bounded benchmark
+intervals. Size buckets are <=8, 9..256, and >256 sectors.
+
+FAT32 blocking and async reads share a pooled transfer engine with batches of up
+to four outstanding reads, capped by device queue depth. Destination slices are
+disjoint. On any error, the engine drains every accepted request before releasing
+its context and reports only the contiguous successful byte prefix. Unaligned
+edges and odd DMA addresses use the context's private scratch sector. Writes
+remain sequential. Run maps store cumulative file-cluster offsets; an open-file
+cursor handles sequential locality and binary search handles random seeks.
+
+`STORPERF` runs memory-backed regression checks (also included in boot unit tests)
+for reverse completion order, failures, unaligned reads, run lookup, queue
+rejection, merging limits, and callback accounting. It does not access real disks
+or measure hardware throughput. Compare counters alongside `STORBENCH` and file
+benchmarks on contiguous and fragmented files for actual performance validation.

doc/src/driver/storage/driver.storage.test.md

@@ -58,3 +58,111 @@ Registers the `STORTEST` and `DISKTEST` shell commands with `io.stdio`. Must be
 - `run_tests` exercises `makeAbsolutePathFrom`, `resolvePathFrom`, `changeDirectoryFrom`, `GetDirectoryListingFrom`, `newVirtualDirectory`, and `PathValid` including `.` and `..` traversal.
 - `run_disk_tests` is destructive and will irreversibly wipe the partition table of disk 0. It is never called automatically.
 - The `Assert` helper used in both procedures increments `passed` or `failed` counters and logs the test name on failure; passing tests produce no output to avoid noise.
+
+
+## Raw read benchmark
+
+`STORBENCH` is implemented and registered by `driver.storage.bench`. It performs
+read-only raw-device I/O; it does not invoke the destructive `DISKTEST` path.
+
+```text
+STORBENCH [disk] [MiB]
+STORBENCH list
+STORBENCH run [disk] [MiB] [KiB/request] [depth] [seq|random] [start_lba]
+STORBENCH compare [disk] [MiB]
+STORBENCH help
+```
+
+Manual (`run`) defaults are disk 0, 128 MiB, 1024 KiB/request, sequential reads, and a depth of
+`min(4, hardware depth)` (at least one). Examples:
+
+```text
+STORBENCH 0 128 64 4
+STORBENCH 0 128 4 16 random
+STORBENCH 0 256 1024 1 seq 2048
+STORBENCH compare 0 128
+```
+
+The comparison runs sequential reads at 4, 64, and 1024 KiB/request, each at depths
+1, 4, 16, and 32. The MiB argument applies to each of the twelve cases. Queue depth
+may exceed hardware depth to expose software queuing and request merging.
+
+Limits are 1..16384 MiB, 1..1024 KiB/request, and depth 1..32. Request size must be
+an exact number of device sectors. Buffers are allocated once per case, with a
+separate slice for every outstanding request and a maximum total size of 32 MiB.
+The transfer range is clamped to the device. Without an explicit LBA, reads start
+at sector 2048 when the full requested range fits there; otherwise they start at
+zero. Random mode uses a fixed xorshift seed and samples that range with replacement,
+so total bytes read are bounded but unique coverage is not guaranteed.
+
+Reports include successful bytes, elapsed microseconds, MiB/s, IOPS, accepted and
+completed request counts, peak outstanding requests, average/p95/max completion
+latency, and per-run storage-counter deltas. Latencies are measured from submission
+to callback. The p95 is an upper bound from logarithmic microsecond buckets, not an exact
+microsecond percentile. Runs shorter than 10 ms are excluded from suite speed comparisons.
+No console output occurs inside the measured loop. Any failure stops new work;
+already accepted DMA is drained before buffers are freed, and failed requests
+contribute no bytes or successful IOPS.
+
+Timing prefers the Hyper-V-compatible VM reference counter (100 ns ticks), detected
+through its Hv#1 interface and reference-counter privilege. It needs no calibration.
+Other platforms use an invariant TSC calibrated against two complete RTC seconds,
+with up to three attempts to tolerate transient RTC updates or scheduling delays.
+Calibration requires agreement within 1%; failures include the specific reason.
+Unlike delivered timer interrupts, this clock advances while interrupts are masked.
+Queue submission restores interrupts between requests. Filesystem caches are
+bypassed, but drive and virtual-machine/host caches may still affect results.
+Virtual or sparse disks can report throughput above physical-media speed.
+Device counter deltas may include concurrent I/O from other processes;
+benchmark-owned byte, request, and latency counters do not.
+
+`driver.storage.bench.UnitTest` runs memory-only parser, arithmetic, range,
+queue-depth, completion-order, and error-accounting tests at boot. It never reads
+or writes a real disk. The clock tests also verify that an advertised VM reference
+counter advances with interrupts masked; they never calibrate the RTC at boot.
+
+
+### Automatic suite and table output
+
+`STORBENCH` without arguments, or `STORBENCH auto [disk] [MiB]`, runs six
+read-only profiles. Auto defaults to disk 0 and **32 MiB per profile** (up to
+192 MiB total before device-size clamping). One or two numeric arguments select the auto suite: `STORBENCH 2 512` tests
+disk 2 with 512 MiB per profile. `STORBENCH list` lists disk indices, capacities,
+controllers, sector sizes, and hardware queue depths. Three or more numeric
+arguments retain the legacy manual syntax; `run` selects manual mode explicitly.
+
+| Profile | Request size | Queue depth |
+| --- | --- | --- |
+| Seq large | 1024 KiB | 1 |
+| Seq queued | 1024 KiB | queued |
+| Seq medium | 64 KiB | queued |
+| Random small | 4 KiB | 1 |
+| Random queued | 4 KiB | queued |
+| Random medium | 64 KiB | queued |
+
+Queued depth is the device hardware depth clamped to 4..16, allowing software
+queue testing even on serial devices. A request smaller than a device sector is
+increased to one sector. Each profile samples the same byte-span size, with the
+existing fixed random seed and range clamping rules.
+
+Auto and compare modes print an aligned ASCII table with request KiB, queue
+depth, MiB/s, IOPS, average latency, p95 latency upper bound, and status. Rows are
+printed outside the measured loop. Successful runs shorter than 10 ms show `-` metrics and
+`SHORT`, and are excluded from best-result and queue-gain summaries. Errors show
+`FAILED`, stop the suite after accepted DMA has drained, and leave remaining
+profiles unrun. The summary includes successful profiles, bytes actually read,
+measured time, best sequential throughput, peak random IOPS, and (in auto mode)
+queued/QD1 throughput ratios. These ratios describe the measured cases, including
+any controller-cache effects; they are not a hardware rating.
+
+```text
+STORBENCH
+STORBENCH list
+STORBENCH 2 512
+STORBENCH auto 0 64
+STORBENCH compare 0 32
+```
+
+Profiles reuse the same raw device range. Host/drive caches are not flushed, so
+later profiles may read warm data. These results are observed raw read throughput,
+not a claim of uncached physical-media performance.

src/app/app.diskcmd.pas

@@ -150,6 +150,7 @@ var
     device   : PStorage_Device;
     volCount : uint32;
     freeSec  : uint32;
+    stats : TStorageStats;
 begin
     if paramCount(params) < 2 then begin
         println('Usage: DISK info <disk>');
@@ -191,6 +192,16 @@ begin
     else
         volCount := 0;
     print('Partitions:      '); printint(volCount); println('');
+    storage_get_stats(device,stats);
+    print('I/O submitted/completed/failed: '); printint(stats.Submitted); print(' / '); printint(stats.Completed); print(' / '); printint(stats.Failed); println('');
+    print('Commands / merged requests: '); printint(stats.Commands); print(' / '); printint(stats.Merged); println('');
+    print('Queue peak / active peak / queue full: '); printint(stats.QueuePeak); print(' / '); printint(stats.ActivePeak); print(' / '); printint(stats.QueueFull); println('');
+    print('Read / written sectors: '); printint(stats.ReadSectors); print(' / '); printint(stats.WriteSectors); println('');
+    print('Requests <=8 / <=256 / >256 sectors: '); printint(stats.SmallRequests); print(' / '); printint(stats.MediumRequests); print(' / '); printint(stats.LargeRequests); println('');
+    print('Queue ticks total / max: '); printint(stats.QueueTicks); print(' / '); printint(stats.MaxQueueTicks); println('');
+    print('Service ticks total / max: '); printint(stats.ServiceTicks); print(' / '); printint(stats.MaxServiceTicks); println('');
+    print('FAT cache hits / misses: '); printint(stats.FatCacheHits); print(' / '); printint(stats.FatCacheMisses); println('');
+
 end;
 
 { ---------- DISK WIPE ---------- }

src/arch/x86/isr/arch.x86.isr.tmr0.pas

@@ -27,6 +27,10 @@ uses
     arch.x86.isr.mgr,
     arch.x86.idt;
 
+const
+    PIT_INPUT_HZ = 1193182;
+    PIT_DIVISOR = 149;
+
 procedure register();
 procedure hook(hook_method : uint32);
 procedure unhook(hook_method : uint32);
@@ -54,7 +58,7 @@ procedure register();
 begin
     if not registered then begin
         asm
-            mov ax, 149
+            mov ax, PIT_DIVISOR
             out $40, al
             mov al, ah
             out $40, al

src/driver/storage/ctl/ahci/driver.storage.ctl.ahci.types.pas

@@ -21,6 +21,7 @@ unit driver.storage.ctl.ahci.types;
 interface
 uses
     io.syslog,
+    driver.storage.types,
     driver.mgr,
     driver.types,
     driver.storage.ctl.ide.types,
@@ -251,11 +252,13 @@ type
     { Callback signature fired from IRQ context when an async I/O command completes.
       Must be very short — set a flag or post to a queue.
       Never call kalloc/kfree/VFS from within this callback. }
-    TIOCompletion = procedure(success : boolean; userdata : puint32);
+    TIOCompletion = procedure(error : TError; userdata : puint32);
 
     { Per-slot pending operation — one entry per HBA command slot }
     TPendingOp = record
         inUse      : boolean;
+        issued     : boolean;
+        started    : uint32;
         completion : TIOCompletion;
         userdata   : puint32;
     end;
@@ -267,6 +270,11 @@ type
     }
     TAHCI_Device = record
         port         : PHBA_Port;
+        owner        : pointer; { stable PAHCI_Controller }
+        offline      : boolean;
+        recovering   : boolean;
+        recoveryTick : uint32;
+        recoveryError: TError;
         device_type  : TDeviceType;
         ata_info     : TIdentResponse;
         supportsNCQ  : boolean;
@@ -288,6 +296,7 @@ type
     }
     TAHCI_Controller = record
         pci_device : PPCI_Device;
+        offline : boolean;
         mio: PHBA_Memory;
         ata_info : TIdentResponse;
         devices : array[0..31] of TAHCI_Device;

src/driver/storage/driver.storage.iorequest.pas

@@ -39,8 +39,8 @@ function  ioreq_alloc(reqType  : TIORequestType;
 procedure ioreq_free(req : PIORequest);
 
 { Copy an existing TIORequest into a new pooled allocation (deep copy of the
-  record, NOT the buffer it points to). Used by dispatch_next to create an
+  record, NOT the buffer it points to). Used by submit_io before enqueueing
-  ISR-safe copy from the CFIFO value-element. }
+  the owned pointer. Manager-only merge/timing fields are initialised here. }
 function  ioreq_copy(src : PIORequest) : PIORequest;
 
 implementation
@@ -132,6 +132,9 @@ begin
         ioreq_alloc := nil;
         exit;
     end;
+    req^.MergeNext := nil;
+    req^.OriginalSectors := sectors;
+    req^.QueuedTick := 0; req^.DispatchTick := 0;
     req^.RequestType := reqType;
     req^.State       := iosPending;
     req^.Device      := device;
@@ -161,6 +164,9 @@ begin
         ioreq_copy := nil;
         exit;
     end;
+    dst^.MergeNext := nil;
+    dst^.OriginalSectors := src^.SectorCount;
+    dst^.QueuedTick := 0; dst^.DispatchTick := 0;
     dst^.RequestType := src^.RequestType;
     dst^.State       := src^.State;
     dst^.Device      := src^.Device;

src/driver/storage/driver.storage.metatest.pas

@@ -14,7 +14,7 @@ type
     PMock = ^TMock;
     TMock = record
         Data : puint8;
-        Writes, FailWrite, Callbacks : uint32;
+        Writes, FailWrite, Callbacks, Depth, MaxDepth : uint32;
         Error : TError;
         OutOfBounds, FailRead : boolean;
     end;
@@ -27,7 +27,10 @@ begin
        (request^.SectorCount > device^.maxSectorCount-request^.LBA) then begin
         m^.OutOfBounds := true; complete_io(request, false, eInvalidArgument); exit;
     end;
-    if (request^.RequestType <> ioWrite) and m^.FailRead then begin complete_io(request, false, eIOError); exit; end;
+    if (request^.RequestType <> ioWrite) and m^.FailRead then begin
+        Inc(m^.Depth); if m^.Depth > m^.MaxDepth then m^.MaxDepth := m^.Depth;
+        complete_io(request,false,eIOError); Dec(m^.Depth); exit;
+    end;
     offset := request^.LBA*512; size := request^.SectorCount*512;
     if request^.RequestType = ioWrite then begin
         Inc(m^.Writes);
@@ -81,7 +84,17 @@ begin
     device^.controllerId0 := uint32(mock); device^.sectorSize := 512;
     device^.maxSectorCount := 256; device^.writable := true; device^.maxActive := 1;
     device^.dispatchRead := @dispatch; device^.dispatchWrite := @dispatch;
-    device^.requestQueue := CFIFO_New(sizeof(Pointer),4);
+    device^.requestQueue := CFIFO_New(sizeof(Pointer),8);
+    device^.maxActive := 0; mock^.FailRead := true;
+    for i := 1 to 4 do
+        Assert(storage_read_async(device,0,1,puint32(mock^.Data),@completion,mock)=eNone,'queued fault request accepted');
+    Assert(mock^.Callbacks=0,'queued requests wait for dispatch');
+    device^.maxActive := 1;
+    Assert(storage_read_async(device,0,1,puint32(mock^.Data),@completion,mock)=eNone,'fault queue drain accepted');
+    Assert((mock^.Callbacks=5) and (mock^.Error=eIOError),'every queued error completes once');
+    Assert((mock^.MaxDepth=1) and (device^.activeCount=0) and (CFIFO_Size(device^.requestQueue)=0),
+           'inline failures drain without recursive driver dispatch');
+    mock^.FailRead := false; mock^.Callbacks := 0;
     device^.cachedMBR := kalloc(512);
     mbr := PMaster_Boot_Record(device^.cachedMBR);
     memset(uint32(mbr),0,512); mbr^.boot_sector := $AA55; mbr^.signature := $12345678;

src/driver/storage/driver.storage.types.pas

@@ -252,11 +252,22 @@ type
         UserData     : pointer;         { points back to caller's stack-local request (blocking path) }
         Callback     : TIOCallback;     { async completion callback (nil for blocking path) }
         CallbackData : pointer;         { opaque data passed to Callback }
+        { Manager-owned fields; callers need not initialise these. }
+        MergeNext : PIORequest;
+        OriginalSectors, QueuedTick, DispatchTick : uint32;
     end;
 
     byteArray8  = array[0..7] of char;
     PByteArray8 = ^byteArray8;
 
+    TStorageStats = record
+        Submitted, Completed, Failed, Commands, Merged, QueueFull : uint32;
+        ReadSectors, WriteSectors, QueuePeak, ActivePeak : uint32;
+        QueueTicks, ServiceTicks, MaxQueueTicks, MaxServiceTicks : uint32;
+        SmallRequests, MediumRequests, LargeRequests : uint32;
+        FatCacheHits, FatCacheMisses : uint32;
+    end;
+
     { Generic storage device }
     TStorage_Device = record
         id               : uint8;
@@ -270,7 +281,9 @@ type
         dispatchRead     : TDriverDispatch;   { nil if driver not yet migrated }
         dispatchWrite    : TDriverDispatch;   { nil if driver not yet migrated }
         requestQueue     : PCFIFOQueue;       { per-device I/O request CFIFO }
+        dispatching      : boolean; { prevents recursive synchronous-error queue draining }
         activeCount      : uint32;            { number of commands currently dispatched to HW }
+        mergeMaxSectors  : uint32; { zero disables merging; driver sets safe command limit }
         maxActive        : uint32;            { max concurrent commands (NCQ depth) }
 
         maxSectorCount   : uint32;
@@ -280,6 +293,7 @@ type
         mbrWriteBusy     : boolean; { serializes staged sector-zero writes }
         cachedMBR        : pointer;           { cached mbr data, nil if not yet read }
         isBootDevice     : boolean;           { true if this is the device GRUB booted from }
+        Stats            : TStorageStats; { cold tail: wrapping counters, timer ticks }
     end;
 
     { Filesystem driver descriptor }

src/driver/storage/fs/fat32/driver.storage.fs.fat32.types.pas

@@ -99,6 +99,7 @@ type
     TFATRun = record
         StartCluster : uint32;
         ClusterCount : uint32;
+        FileClusterStart : uint32;
     end;
 
     TFATAllocHint = record
@@ -183,6 +184,13 @@ type
     PFATVolumeCtx = ^TFATVolumeCtx;
     PFATTransferCtx = ^TFATTransferCtx;
 
+    PFATReadSlot = ^TFATReadSlot;
+    TFATReadSlot = record
+        Owner : PFATTransferCtx;
+        Bytes : uint32;
+        Error : TError;
+    end;
+
     TFATTransferCtx = record
         Next                 : PFATTransferCtx;
         VolumeCtx            : PFATVolumeCtx;
@@ -209,6 +217,10 @@ type
         RunHintIndex         : uint32;
         RunHintFileCluster   : uint32;
         LastError            : TError;
+        Pumping, Resume, Finished : boolean;
+        ReadSubmitting : boolean;
+        ReadPending, ReadCount : uint32;
+        ReadSlots : array[0..3] of TFATReadSlot;
     end;
 
     TFATVolumeCtx = record

src/io/io.stdio.pas

@@ -486,6 +486,10 @@ var
 begin
     search := params;
     for i := 0 to index do begin
+        if search = nil then begin
+            getParam := nil;
+            exit;
+        end;
         if search^.next = nil then begin
             getParam := nil;
             exit;

src/proc/proc.mgr.pas

@@ -107,10 +107,10 @@ procedure process_trampoline; forward;
 
 { ---- Process creation ---- }
 
-function create(name : pchar;
+function createInternal(name : pchar;
                 entry : TProcessEntryPoint;
                 localData : void;
-                priority : uint8) : PProcessContext;
+                priority : uint8; runnable : boolean) : PProcessContext;
 var
     ctx      : PProcessContext;
     slotPtr  : ^uint32;
@@ -119,7 +119,7 @@ var
     prio     : uint8;
 begin
     push_trace('proc.mgr.create');
-    create := nil;
+    createInternal := nil;
 
     if priority = 0 then prio := 1 else prio := priority;
 
@@ -140,7 +140,7 @@ begin
         ctx^.ParentID := CurrentProcess^.ProcessID;
 
     { State }
-    ctx^.State := psCreated;
+    ctx^.State := psSuspended;
     ctx^.ExitCode := 0;
 
     { Entry point }
@@ -269,14 +269,22 @@ begin
     slotPtr^ := uint32(ctx);
 
     { Mark as ready for scheduling }
-    ctx^.State := psReady;
+    if runnable then ctx^.State := psReady;
     asm popf end;
 
     io.syslog.log('PROCMGR', 'Created process: ');
     io.syslog.writestringln(name);
 
     pop_trace;
-    create := ctx;
+    createInternal := ctx;
+end;
+
+{ Public creation retains its ready-on-return behavior. Commands need their
+  arguments and streams installed before the scheduler may enter them. }
+function create(name : pchar; entry : TProcessEntryPoint;
+                localData : void; priority : uint8) : PProcessContext;
+begin
+    create := createInternal(name, entry, localData, priority, true);
 end;
 
 { ---- Process trampoline ---- }
@@ -543,12 +551,17 @@ function runCommand(name : pchar; method : TCommandMethod; params : PParamList;
 var
     ctx : PProcessContext;
 begin
-    ctx := create(name, @legacy_entry, void(method), 1);
+    ctx := createInternal(name, @legacy_entry, void(method), 1, false);
     if ctx <> nil then begin
         ctx^.MsgData := void(params);
         ctx^.StdIn := stdin_buf;
         ctx^.StdOut := stdout_buf;
         ctx^.StdErr := stderr_buf;
+        { Publish only after all fields read by legacy_entry are initialized.
+          psCreated is also runnable, so creation must use psSuspended. }
+        asm pushf; cli end;
+        ctx^.State := psReady;
+        asm popf end;
     end;
     runCommand := ctx;
 end;

src/test/test.pas

@@ -33,7 +33,10 @@ uses
     core.ds.prio,
     driver.storage.vfs,
     driver.storage.test,
+    driver.storage.bench,
     driver.storage.metatest,
+    driver.storage.perftest,
+    driver.storage.ctl.ahci,
     core.enc.fnv1a,
     core.enc.djb2,
     core.ds.bloom,
@@ -69,7 +72,10 @@ begin
     core.ds.prio.UnitTest;
     driver.storage.vfs.UnitTest;
     driver.storage.test.UnitTest;
+    driver.storage.bench.UnitTest;
     driver.storage.metatest.UnitTest;
+    driver.storage.perftest.UnitTest;
+    driver.storage.ctl.ahci.UnitTest;
     core.enc.fnv1a.UnitTest;
     core.enc.djb2.UnitTest;
     core.ds.bloom.UnitTest;