AoE support seems to have problems

[mrjrt]

Long story short, I've been tinkering with this for a week or so now, and I'm not really informed enough to fix the code myself, sadly. My use case is to use iPXE to hook an AoE disk to BIOS drive 0x81, then boot a USB stick with GRUB4DOS on it, and use that to load an ISO into RAM, then boot from that. This enables me to install XP from an ISO to an AoE target.

My testbed for all of this is a VMWare host with a floppy image of iPXE (sanhook -d 0x81 aoe:e0.0), my USB stick mapped as a physical IDE drive (VMWare doesn't do USB booting), and the Win32 build of VBlade acting as AoE target.

Now, revision 2ebc053 (Date: 24/12/2010 15:30:09) is the newest revision of WinVBlock that works for me - I am able to install XP end to end using that code (abet I have to load the ISO into memory though). Beyond that point though I suffer a variety of BSODs until a point after revision: ebc7158 (Date: 04/01/2011 08:34:53), where it no longer crashes, but I instead get errors about firstly being unable to add the AoE bus to the WinVBlock bus, and a bit later (Revision: bb6f3af - Date: 07/01/2011 06:50:16), being unable to create the AoE bus PDO, and this persists to the most recent revision (7eed6ad - Date: 25/01/2016 00:31:00).

Aside from this, I ideally want to be able to use sector-mapped ISOs. I have this working fine with Firadisk, but this does not seem to work so well with the old revision of WinVBlock that AoE works with...but works fine in the latest revisions, as far as I can tell. My next attempted workaround for the time being is going to be to try disabling WinVBlock's GRUB4DOS handling in a branch from revision 2ebc053 so I can use Firadisk for the mappings and WinVBlock for AoE, as I figure disabling stuff is a lot more likely to work than trying to fix something you don't understand!

I created my own fork on Github and have grabbed full debug logs (edited into the notes for each commit) and tagged revisions I've tested. Dunno if you would find that information useful, but I'll push it up at some point.

[mrjrt]

sigh scratch most of that. I've just wasted a large part of my day...very frustrating.

At some point earlier today I tested the original aoe32 driver WinVBlk was based on (to confirm it doesn't work in text mode) - and I disabled the WvBlk32.sys driver whilst doing so...and forgot to re-enable it afterwards. I could have sworn that it didn't error last time I tried the latest revision of of yours, it just didn't seem to do anything.

Anyway. Having re-enabled WvBlk32.sys I have returned to the behaviour I was expecting - no debug messages about the AoE code, nothing, just sits there waiting on the SAN disk.

I've just reverted back to revision 72ed155 (Date: 22/09/2011 06:39:45), and it too just seems to sit there, but I at least get messages suggesting it's not picking up responses?

g:\temp\coding\winvblock\src\aoe\driver.c @ 275: T[81BB0020]: DriverEntry(): Entry
g:\temp\coding\winvblock\src\aoe\registry.c @ 61: T[81BB0020]: AoeRegSetup(): Entry
g:\temp\coding\winvblock\src\aoe\driver.c @ 290: T[81BB0020]: DriverEntry(): Registry updated
g:\temp\coding\winvblock\src\aoe\protocol.c @ 168: T[81BB0020]: Protocol_Start(): Entry
g:\temp\coding\winvblock\src\aoe\protocol.c @ 204: T[81BB0020]: Protocol_Start(): Exit
g:\temp\coding\winvblock\src\winvblock\libbus\libbus.c @ 65: T[81BB0020]: WvlBusAddNode_(): Adding PDO 81A277D0 to bus FBF2AF34.
g:\temp\coding\winvblock\src\aoe\protocol.c @ 726: T[81A27978]: Protocol_BindAdapter(): Adapter: Ethernet Controller
g:\temp\coding\winvblock\src\aoe\protocol.c @ 728: T[81A27978]: Protocol_BindAdapter(): Device Name: \DEVICE\{4DB30059-46A5-4F69-B52A-C67B3DE4C8A3}
g:\temp\coding\winvblock\src\aoe\protocol.c @ 753: T[81A27978]: Protocol_BindAdapter(): Mac: 00:0c:29:d2:ea:f9
g:\temp\coding\winvblock\src\aoe\protocol.c @ 776: T[81A27978]: Protocol_BindAdapter(): MTU: 1500
g:\temp\coding\winvblock\src\aoe\bus.c @ 344: T[81BB0020]: AoeBusCreate(): Exit
g:\temp\coding\winvblock\src\aoe\driver.c @ 1228: T[81A26020]: AoeThread_(): Entry
g:\temp\coding\winvblock\src\aoe\driver.c @ 1560g:\temp\coding\winvblock\src\aoe\driver.c @ 1265: T[81A26020]: AoeThread_(): Sends: 0  Resends: 0  ResendFails: 0  Fails: 0  AoePendingTags_: 0  RequestTimeout: 0
: T[81BB0020]: AoeProcessAbft_(): Found aBFT at segment: 0x9e3c
g:\temp\coding\winvblock\src\aoe\driver.c @ 1791: T[81BB0020]: AoeDiskCreatePdo_(): Creating AoE disk PDO...
g:\temp\coding\winvblock\src\aoe\driver.c @ 1833: T[81BB0020]: AoeDiskCreatePdo_(): New PDO: 81A27A28
g:\temp\coding\winvblock\src\aoe\driver.c @ 1596: T[81BB0020]: AoeProcessAbft_(): Attaching AoE disk from client NIC 00:0c:29:d2:ea:f9 to major: 0 minor: 0
g:\temp\coding\winvblock\src\aoe\driver.c @ 1084: T[81A26020]: aoe__reply(): Major: 0 minor: 0 found on server 00:11:43:26:ca:65
g:\temp\coding\winvblock\src\aoe\driver.c @ 1154: T[FC1B9E20]: aoe__reply(): Got MaxSectorsPerPacket 2 at size of 1024. MTU of 1500 reached
g:\temp\coding\winvblock\src\aoe\driver.c @ 669: T[81BB0020]: AoeDiskInit_(): Disk size: 10240M cylinders: 1305 heads: 255sectors: 63 sectors per packet: 2
g:\temp\coding\winvblock\src\aoe\bus.c @ 369: T[81BB0020]: AoeBusAddDev(): Entry
g:\temp\coding\winvblock\src\winvblock\libbus\libbus.c @ 65: T[81BB0020]: WvlBusAddNode_(): Adding PDO 81A27A28 to bus FBFF79D8.
g:\temp\coding\winvblock\src\aoe\bus.c @ 382: T[81BB0020]: AoeBusAddDev(): Exit
g:\temp\coding\winvblock\src\aoe\driver.c @ 401: T[81BB0020]: DriverEntry(): Exit
g:\temp\coding\winvblock\src\winvblock\libbus\pnp.c @ 335: T[81BB0020]: WvlBusPnp(): IRP_MN_QUERY_DEVICE_RELATIONS
Waiting for SAN system disk (attempt 1)
  System disk is <unknown>, boot disk is <unknown>
g:\temp\coding\winvblock\src\aoe\driver.c @ 1265: T[81A26020]: AoeThread_(): Sends: 3  Resends: 0  ResendFails: 0  Fails: 0  AoePendingTags_: 0  RequestTimeout: 200000
g:\temp\coding\winvblock\src\winvblock\driver.c @ 149: T[81BB0020]: WvDriverReinitialize(): Called
g:\temp\coding\winvblock\src\winvblock\driver.c @ 158: T[81BB0020]: WvDriverReinitialize(): Exiting...
Waiting for SAN system disk (attempt 2)
  System disk is <unknown>, boot disk is <unknown>
g:\temp\coding\winvblock\src\aoe\driver.c @ 1265: T[81A26020]: AoeThread_(): Sends: 0  Resends: 0  ResendFails: 0  Fails: 0  AoePendingTags_: 0  RequestTimeout: 200000
Waiting for SAN system disk (attempt 3)
...etc

...as mentioned above, this works in earlier revisions of the code. I'll have to try and find where this breaks...again. sigh

[Sha0]

I am a bit lost. Is this the log from a GRUB4DOS RAM-disk boot? (Regardless of the presence of an aBFT established by iPXE, before-hand.)

[mrjrt]

Yes. Post iPXE, booted from G4D, loaded the ISO into RAM, then booted it.

Relevant equivalent bit of log from 2ebc053:

g:\temp\coding\winvblock\src\aoe\driver.c: DriverEntry() @ line 226: Entry
g:\temp\coding\winvblock\src\aoe\registry.c: AoeRegSetup() @ line 61: Entry
g:\temp\coding\winvblock\src\aoe\driver.c: DriverEntry() @ line 238: Registry updated
g:\temp\coding\winvblock\src\aoe\protocol.c: Protocol_Start() @ line 171: Entry
g:\temp\coding\winvblock\src\aoe\protocol.c: Protocol_Start() @ line 207: Exit
g:\temp\coding\winvblock\src\winvblock\bus\bus.c: WvBusAddChild() @ line 94: Entry
g:\temp\coding\winvblock\src\winvblock\bus\bus.c: WvBusAddChild() @ line 153: Exit
g:\temp\coding\winvblock\src\aoe\protocol.c: Protocol_BindAdapter() @ line 729: Adapter: Ethernet Controller
g:\temp\coding\winvblock\src\aoe\protocol.c: Protocol_BindAdapter() @ line 731: Device Name: \DEVICE\{4DB30059-46A5-4F69-B52A-C67B3DE4C8A3}
g:\temp\coding\winvblock\src\aoe\driver.c: AoeThread_() @ line 1296: Entry
g:\temp\coding\winvblock\src\aoe\protocol.c: Protocol_BindAdapter() @ line 756: Mac: 00:0c:29:d2:ea:f9
g:\temp\coding\winvblock\src\aoe\protocol.c: Protocol_BindAdapter() @ line 779: MTU: 1500
g:\temp\coding\winvblock\src\aoe\driver.c: AoeThread_() @ line 1327: Sends: 0  Resends: 0  ResendFails: 0  Fails: 0  AoePendingTags_: 0  RequestTimeout: 0
g:\temp\coding\winvblock\src\aoe\driver.c: AoeProcessAbft_() @ line 1544: Found aBFT at segment: 0x9e3c
g:\temp\coding\winvblock\src\aoe\driver.c: AoeProcessAbft_() @ line 1580: Attaching AoE disk from client NIC 00:0c:29:d2:ea:f9 to major: 0 minor: 0
g:\temp\coding\winvblock\src\winvblock\bus\bus.c: WvBusAddChild() @ line 94: Entry
g:\temp\coding\winvblock\src\winvblock\disk\disk.c: create_pdo() @ line 140: Entry
g:\temp\coding\winvblock\src\winvblock\disk\disk.c: create_pdo() @ line 167: Exit
g:\temp\coding\winvblock\src\aoe\driver.c: aoe__reply() @ line 1159: Major: 0 minor: 0 found on server 00:11:43:26:ca:65
g:\temp\coding\winvblock\src\aoe\driver.c: aoe__reply() @ line 1228: Got MaxSectorsPerPacket 2 at size of 1024. MTU of 1500 reached
g:\temp\coding\winvblock\src\aoe\driver.c: AoeDiskInit_() @ line 666: Disk size: 10240M cylinders: 1305 heads: 255 sectors: 63 sectors per packet: 2
g:\temp\coding\winvblock\src\winvblock\bus\bus.c: WvBusAddChild() @ line 153: Exit
g:\temp\coding\winvblock\src\aoe\driver.c: DriverEntry() @ line 321: Exit
g:\temp\coding\winvblock\src\winvblock\bus\pnp.c: WvBusPnp() @ line 468: bus_pnp: IRP_MN_QUERY_DEVICE_RELATIONS
g:\temp\coding\winvblock\src\winvblock\bus\pnp.c: WvBusPnp() @ line 468: bus_pnp: IRP_MN_QUERY_DEVICE_RELATIONS
g:\temp\coding\winvblock\src\winvblock\bus\bus.c: WvBusDefaultThread_() @ line 597: Alive.
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__dispatch() @ line 390: disk_pnp: IRP_MN_QUERY_DEVICE_RELATIONS
g:\temp\coding\winvblock\src\winvblock\bus\pnp.c: WvBusPnp() @ line 456: bus_pnp: IRP_MN_QUERY_ID
g:\temp\coding\winvblock\src\winvblock\bus\pnp.c: WvBusPnp() @ line 472: bus_pnp: IRP_MN_QUERY_CAPABILITIES
g:\temp\coding\winvblock\src\winvblock\bus\pnp.c: WvBusPnp() @ line 472: bus_pnp: IRP_MN_QUERY_CAPABILITIES
g:\temp\coding\winvblock\src\winvblock\bus\pnp.c: WvBusPnp() @ line 460: bus_pnp: IRP_MN_QUERY_DEVICE_TEXT
g:\temp\coding\winvblock\src\winvblock\bus\pnp.c: WvBusPnp() @ line 460: bus_pnp: IRP_MN_QUERY_DEVICE_TEXT
g:\temp\coding\winvblock\src\winvblock\bus\pnp.c: WvBusPnp() @ line 456: bus_pnp: IRP_MN_QUERY_ID
g:\temp\coding\winvblock\src\winvblock\bus\pnp.c: WvBusPnp() @ line 456: bus_pnp: IRP_MN_QUERY_ID
g:\temp\coding\winvblock\src\winvblock\bus\pnp.c: WvBusPnp() @ line 456: bus_pnp: IRP_MN_QUERY_ID
g:\temp\coding\winvblock\src\winvblock\bus\pnp.c: WvBusPnpSimple_() @ line 429: bus_pnp: IRP_MN_QUERY_RESOURCE*
g:\temp\coding\winvblock\src\winvblock\bus\pnp.c: WvBusPnp() @ line 464: bus_pnp: IRP_MN_QUERY_BUS_INFORMATION
g:\temp\coding\winvblock\src\winvblock\bus\pnp.c: WvBusPnpSimple_() @ line 429: bus_pnp: IRP_MN_QUERY_RESOURCE*
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__dispatch() @ line 382: disk_pnp: IIRP_MN_QUERY_ID
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__dispatch() @ line 398: disk_pnp: IRP_MN_QUERY_CAPABILITIES
g:\temp\coding\winvblock\src\winvblock\bus\pnp.c: WvBusPnp() @ line 472: bus_pnp: IRP_MN_QUERY_CAPABILITIES
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__dispatch() @ line 386: disk_pnp: IRP_MN_QUERY_DEVICE_TEXT
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__dispatch() @ line 386: disk_pnp: IRP_MN_QUERY_DEVICE_TEXT
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__dispatch() @ line 382: disk_pnp: IIRP_MN_QUERY_ID
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__dispatch() @ line 382: disk_pnp: IIRP_MN_QUERY_ID
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__dispatch() @ line 382: disk_pnp: IIRP_MN_QUERY_ID
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__simple_() @ line 365: disk_pnp: Unhandled IRP_MN_*: 11
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__dispatch() @ line 394: disk_pnp: IRP_MN_QUERY_BUS_INFORMATION
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__simple_() @ line 365: disk_pnp: Unhandled IRP_MN_*: 10
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__simple_() @ line 365: disk_pnp: Unhandled IRP_MN_*: 24
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__simple_() @ line 365: disk_pnp: Unhandled IRP_MN_*: 11
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__simple_() @ line 365: disk_pnp: Unhandled IRP_MN_*: 13
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__simple_() @ line 304: disk_pnp: IRP_MN_START_DEVICE
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__dispatch() @ line 398: disk_pnp: IRP_MN_QUERY_CAPABILITIES
g:\temp\coding\winvblock\src\winvblock\bus\pnp.c: WvBusPnp() @ line 472: bus_pnp: IRP_MN_QUERY_CAPABILITIES
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__simple_() @ line 298: disk_pnp: IRP_MN_QUERY_PNP_DEVICE_STATE
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__dispatch() @ line 390: disk_pnp: IRP_MN_QUERY_DEVICE_RELATIONS
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__dispatch() @ line 390: disk_pnp: IRP_MN_QUERY_DEVICE_RELATIONS
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__dispatch() @ line 390: disk_pnp: IRP_MN_QUERY_DEVICE_RELATIONS
Waiting for SAN system disk (attempt 1)
  System disk is <unknown>, boot disk is <unknown>
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__dispatch() @ line 390: disk_pnp: IRP_MN_QUERY_DEVICE_RELATIONS
  MBR f9e4bcb6: "\??\WinVBlock#AoEHardDisk#1&c0ac9c8&0&AoE_at_Shelf_0.Slot_0#{53f56307-b6bf-11d0-94f2-00a0c91efb8b}"
Found system disk at "\??\WinVBlock#AoEHardDisk#1&c0ac9c8&0&AoE_at_Shelf_0.Slot_0#{53f56307-b6bf-11d0-94f2-00a0c91efb8b}"
Found SAN system disk; proceeding with boot
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__dispatch() @ line 390: disk_pnp: IRP_MN_QUERY_DEVICE_RELATIONS
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__dispatch() @ line 390: disk_pnp: IRP_MN_QUERY_DEVICE_RELATIONS
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__dispatch() @ line 390: disk_pnp: IRP_MN_QUERY_DEVICE_RELATIONS
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__dispatch() @ line 390: disk_pnp: IRP_MN_QUERY_DEVICE_RELATIONS
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__dispatch() @ line 390: disk_pnp: IRP_MN_QUERY_DEVICE_RELATIONS
g:\temp\coding\winvblock\src\winvblock\disk\pnp.c: disk_pnp__dispatch() @ line 390: disk_pnp: IRP_MN_QUERY_DEVICE_RELATIONS
g:\temp\coding\winvblock\src\aoe\driver.c: AoeThread_() @ line 1327: Sends: 30  Resends: 0  ResendFails: 0  Fails: 0  AoePendingTags_: 0  RequestTimeout: 195527

[mrjrt]

Had another poke at it this evening. Still no joy, but thought I'd mention that when I turn on IRP debugging (to see if that shines any light on things) it seems to BSOD. So I left that off.

Trace from 7eed6ad:

NIC Boot Configuration Driver finalizing
SAN Boot Configuration Driver initialising
SystemStartOptions are /FASTDETECT /NOGUIBOOT /DEBUGPORT=COM1 /BAUDRATE=115200 /BREAK
Graphical boot is disabled
Boot screen text is enabled
No iBFT found
Found ACPI table "aBFT" at 9e3c0 OEM ID "FENSYS" OEM table ID "iPXE"
AoE boot via iPXE
Found aBFT target e0.0
Found aBFT NIC 00:0c:29:d2:ea:f9
NIC 00:0c:29:d2:ea:f9 target e0.0
Found NIC with MAC address 00:0c:29:d2:ea:f9 at "\??\PCI#VEN_1022&DEV_2000&SUBSYS_20001022&REV_10#4&47b7341&0&0888#{ad498944-762f-11d0-8dcb-00c04fc3358c}\{4DB30059-46A5-4F69-B52A-C67B3DE4C8A3}"
NIC 00:0c:29:d2:ea:f9 is interface "\??\PCI#VEN_1022&DEV_2000&SUBSYS_20001022&REV_10#4&47b7341&0&0888#{ad498944-762f-11d0-8dcb-00c04fc3358c}\{4DB30059-46A5-4F69-B52A-C67B3DE4C8A3}"
NIC 00:0c:29:d2:ea:f9 is PDO 81A5EAA0
NIC 00:0c:29:d2:ea:f9 is NetCfgInstanceId "{4DB30059-46A5-4F69-B52A-C67B3DE4C8A3}"
Successfully identified aBFT NIC
No sBFT found
Attempting SAN boot; will wait for system disk
g:\temp\coding\winvblock\src\winvblock\driver.c @ 249: T[81BB0020]: DriverEntry(): Entry
g:\temp\coding\winvblock\src\winvblock\registry.c @ 410: T[81BB0020]: WvlRegNoteOsLoadOpts(): OsLoadOptions: /FASTDETECT /NOGUIBOOT /DEBUGPORT=COM1 /BAUDRATE=115200 /BREAK
g:\temp\coding\winvblock\src\winvblock\registry.c @ 115: T[81BB0020]: WvlRegFetchKvi(): Could not get KVI length for "CddbDone": c0000034
g:\temp\coding\winvblock\src\winvblock\registry.c @ 115: T[81BB0020]: WvlRegFetchKvi(): Could not get KVI length for "PdoDone": c0000034
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1642: T[81A86458]: WvDeviceThread(): Thread for device 81A866E8 started
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1340: T[81A86458]: WvTestDeviceThread(): Thread test for device 81A866E8 passed
g:\temp\coding\winvblock\src\winvblock\mainbus\mainbus.c @ 280: T[81BB0020]: WvMainBusDriveDevice(): Driving PDO 81A869E0
g:\temp\coding\winvblock\src\winvblock\driver.c @ 338: T[81BB0020]: DriverEntry(): Exit
g:\temp\coding\winvblock\src\winvblock\mainbus\busirp.c @ 287: T[81A86458]: WvMainBusDispatchPnpIrp(): Unhandled IRP_MN_*: 19
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1914: T[81A86458]: WvlPassIrpDown(): Passing IRP FFBD97F0 down
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81A86458]: WvlPassIrpUp(): Passing IRP FFBD97F0 up
g:\temp\coding\winvblock\src\winvblock\mainbus\busirp.c @ 287: T[81A86458]: WvMainBusDispatchPnpIrp(): Unhandled IRP_MN_*: 19
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1914: T[81A86458]: WvlPassIrpDown(): Passing IRP FFBD97F0 down
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81A86458]: WvlPassIrpUp(): Passing IRP FFBD97F0 up
g:\temp\coding\winvblock\src\winvblock\mainbus\busirp.c @ 212: T[81A86458]: WvMainBusDispatchPnpIrp(): IRP_MN_QUERY_CAPABILITIES
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1914: T[81A86458]: WvlPassIrpDown(): Passing IRP FFBD97F0 down
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81A86458]: WvlPassIrpUp(): Passing IRP FFBD97F0 up
g:\temp\coding\winvblock\src\winvblock\mainbus\busirp.c @ 229: T[81A86458]: WvMainBusDispatchPnpIrp(): IRP_MN_QUERY_PNP_DEVICE_STATE
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1914: T[81A86458]: WvlPassIrpDown(): Passing IRP FFBD97F0 down
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81A86458]: WvlPassIrpUp(): Passing IRP FFBD97F0 up
g:\temp\coding\winvblock\src\winvblock\mainbus\busirp.c @ 207: T[81A86458]: WvMainBusDispatchPnpIrp(): IRP_MN_QUERY_DEVICE_RELATIONS
g:\temp\coding\winvblock\src\winvblock\safehook\probe.c @ 358: T[81A86458]: WvlCreateSafeHookDevice(): Probing for safe hook at 98C0:0100 (0x00098D00)...
g:\temp\coding\winvblock\src\winvblock\safehook\probe.c @ 369: T[81A86458]: WvlCreateSafeHookDevice(): Found safe hook with vendor ID: GRUB4DOS
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1642: T[81A21DA8]: WvDeviceThread(): Thread for device 81A21020 started
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1340: T[81A21DA8]: WvTestDeviceThread(): Thread test for device 81A21020 passed
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1914: T[81A86458]: WvlPassIrpDown(): Passing IRP FFBD97F0 down
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81A86458]: WvlPassIrpUp(): Passing IRP FFBD97F0 up
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81BB0020]: WvlPassIrpUp(): Passing IRP 81BD4A30 up
g:\temp\coding\winvblock\src\winvblock\mainbus\busirp.c @ 212: T[81A86458]: WvMainBusDispatchPnpIrp(): IRP_MN_QUERY_CAPABILITIES
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1914: T[81A86458]: WvlPassIrpDown(): Passing IRP FFBD97F0 down
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81A86458]: WvlPassIrpUp(): Passing IRP FFBD97F0 up
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81BB0020]: WvlPassIrpUp(): Passing IRP 81BD4A30 up
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81BB0020]: WvlPassIrpUp(): Passing IRP 81BD4A30 up
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81BB0020]: WvlPassIrpUp(): Passing IRP 81BD4A30 up
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81BB0020]: WvlPassIrpUp(): Passing IRP 81BD4A30 up
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81BB0020]: WvlPassIrpUp(): Passing IRP 81BD4A30 up
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81BB0020]: WvlPassIrpUp(): Passing IRP 81BD4A30 up
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81BB0020]: WvlPassIrpUp(): Passing IRP 81BD4A30 up
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81BB0020]: WvlPassIrpUp(): Passing IRP 81BD4A30 up
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81BB0020]: WvlPassIrpUp(): Passing IRP 81BD4A30 up
g:\temp\coding\winvblock\src\winvblock\mainbus\busirp.c @ 207: T[81A86458]: WvMainBusDispatchPnpIrp(): IRP_MN_QUERY_DEVICE_RELATIONS
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1914: T[81A86458]: WvlPassIrpDown(): Passing IRP FFBD97F0 down
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81A86458]: WvlPassIrpUp(): Passing IRP FFBD97F0 up
iBFT requested
No iBFT available!
g:\temp\coding\winvblock\src\aoe\driver.c @ 275: T[81BB0020]: DriverEntry(): Entry
g:\temp\coding\winvblock\src\aoe\registry.c @ 61: T[81BB0020]: AoeRegSetup(): Entry
g:\temp\coding\winvblock\src\aoe\driver.c @ 290: T[81BB0020]: DriverEntry(): Registry updated
g:\temp\coding\winvblock\src\aoe\protocol.c @ 168: T[81BB0020]: Protocol_Start(): Entry
g:\temp\coding\winvblock\src\aoe\protocol.c @ 204: T[81BB0020]: Protocol_Start(): Exit
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1642: T[81A66DA8]: WvDeviceThread(): Thread for device 81A1F800 started
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1340: T[81A66DA8]: WvTestDeviceThread(): Thread test for device 81A1F800 passed
g:\temp\coding\winvblock\src\aoe\protocol.c @ 724: T[81A66020]: Protocol_BindAdapter(): Adapter: Ethernet Controller
g:\temp\coding\winvblock\src\aoe\protocol.c @ 726: T[81A66020]: Protocol_BindAdapter(): Device Name: \DEVICE\{4DB30059-46A5-4F69-B52A-C67B3DE4C8A3}
g:\temp\coding\winvblock\src\aoe\protocol.c @ 751: T[81A66020]: Protocol_BindAdapter(): Mac: 00:0c:29:d2:ea:f9
g:\temp\coding\winvblock\src\aoe\protocol.c @ 774: T[81A66020]: Protocol_BindAdapter(): MTU: 1500
g:\temp\coding\winvblock\src\aoe\bus.c @ 376: T[81BB0020]: AoeBusCreate(): Exit
g:\temp\coding\winvblock\src\aoe\driver.c @ 1228: T[81A66020]: AoeThread_(): Entry
g:\temp\coding\winvblock\src\aoe\driver.c @ 1560: T[81BB0020]: AoeProcessAbft_(): Found aBFT at segment: 0x9e3c
g:\temp\coding\winvblock\src\aoe\driver.c @ 1791: T[81BB0020]: AoeDiskCreatePdo_(): Creating AoE disk PDO...
g:\temp\coding\winvblock\src\aoe\driver.c @ 1833: T[81BB0020]: AoeDiskCreatePdo_(): New PDO: 81A669C0
g:\temp\coding\winvblock\src\aoe\driver.c @ 1596: T[81BB0020]: AoeProcessAbft_(): Attaching AoE disk from client NIC 00:0c:29:d2:ea:f9 to major: 0 minor: 0
g:\temp\coding\winvblock\src\aoe\driver.c @ 1265: T[81A66020]: AoeThread_(): Sends: 0  Resends: 0  ResendFails: 0  Fails: 0  AoePendingTags_: 0  RequestTimeout: 0
g:\temp\coding\winvblock\src\aoe\driver.c @ 1084: T[81A66020]: aoe__reply(): Major: 0 minor: 0 found on server 00:11:43:26:ca:65
g:\temp\coding\winvblock\src\aoe\driver.c @ 1154: T[81A66020]: aoe__reply(): Got MaxSectorsPerPacket 2 at size of 1024. MTU of 1500 reached
g:\temp\coding\winvblock\src\aoe\driver.c @ 669: T[81BB0020]: AoeDiskInit_(): Disk size: 10240M cylinders: 1305 heads: 255sectors: 63 sectors per packet: 2
g:\temp\coding\winvblock\src\aoe\bus.c @ 401: T[81BB0020]: AoeBusAddDev(): Entry
g:\temp\coding\winvblock\src\winvblock\libbus\libbus.c @ 65: T[81BB0020]: WvlBusAddNode_(): Adding PDO 81A669C0 to bus FBFE79DC.
g:\temp\coding\winvblock\src\aoe\bus.c @ 414: T[81BB0020]: AoeBusAddDev(): Exit
g:\temp\coding\winvblock\src\aoe\driver.c @ 401: T[81BB0020]: DriverEntry(): Exit
g:\temp\coding\winvblock\src\winvblock\mainbus\busirp.c @ 207: T[81A86458]: WvMainBusDispatchPnpIrp(): IRP_MN_QUERY_DEVICE_RELATIONS
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1914: T[81A86458]: WvlPassIrpDown(): Passing IRP FFBD97F0 down
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81A86458]: WvlPassIrpUp(): Passing IRP FFBD97F0 up
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81BB0020]: WvlPassIrpUp(): Passing IRP 81BD45F8 up
g:\temp\coding\winvblock\src\winvblock\mainbus\busirp.c @ 212: T[81A86458]: WvMainBusDispatchPnpIrp(): IRP_MN_QUERY_CAPABILITIES
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1914: T[81A86458]: WvlPassIrpDown(): Passing IRP FFBD97F0 down
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81A86458]: WvlPassIrpUp(): Passing IRP FFBD97F0 up
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81BB0020]: WvlPassIrpUp(): Passing IRP 81BD45F8 up
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81BB0020]: WvlPassIrpUp(): Passing IRP 81BD45F8 up
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81BB0020]: WvlPassIrpUp(): Passing IRP 81BD45F8 up
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81BB0020]: WvlPassIrpUp(): Passing IRP 81BD45F8 up
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81BB0020]: WvlPassIrpUp(): Passing IRP 81BD45F8 up
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81BB0020]: WvlPassIrpUp(): Passing IRP 81BD45F8 up
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81BB0020]: WvlPassIrpUp(): Passing IRP 81BD45F8 up
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81BB0020]: WvlPassIrpUp(): Passing IRP 81BD45F8 up
g:\temp\coding\winvblock\src\winvblock\driver.c @ 1898: T[81BB0020]: WvlPassIrpUp(): Passing IRP 81BD45F8 up
Waiting for SAN system disk (attempt 1)
  System disk is <unknown>, boot disk is <unknown>
g:\temp\coding\winvblock\src\aoe\driver.c @ 1265: T[81A66020]: AoeThread_(): Sends: 3  Resends: 0  ResendFails: 0  Fails: 0  AoePendingTags_: 0  RequestTimeout: 200000
g:\temp\coding\winvblock\src\winvblock\driver.c @ 199: T[81BB0020]: WvDriverReinitialize(): Called
g:\temp\coding\winvblock\src\winvblock\driver.c @ 209: T[81BB0020]: WvDriverReinitialize(): Exiting...
Waiting for SAN system disk (attempt 2)
  System disk is <unknown>, boot disk is <unknown>
g:\temp\coding\winvblock\src\aoe\driver.c @ 1265: T[81A66020]: AoeThread_(): Sends: 0  Resends: 0  ResendFails: 0  Fails: 0  AoePendingTags_: 0  RequestTimeout: 200000
Waiting for SAN system disk (attempt 3)
  System disk is <unknown>, boot disk is <unknown>
g:\temp\coding\winvblock\src\aoe\driver.c @ 1265: T[81A66020]: AoeThread_(): Sends: 0  Resends: 0  ResendFails: 0  Fails: 0  AoePendingTags_: 0  RequestTimeout: 200000

[Sha0]

I think you have too many drivers in the mix. If there is a Microsoft iSCSI driver installed in the image, please remove it. If mcb30's sanbootconf driver is in the mix, please remove it. Some of the messages in this log are not from WinVBlock, including those which might be related to hanging the system.

[mrjrt]

If you think it will help, I'll certainly do as you ask. Though I should mention, I just tried again (both on VMWare and on a physical machine) with 2ebc053 and had zero problems, iSCSI, SanBootConf, and Firadisk included (abet I disabled G4D detection in WVB to prevent clashing), so I don't think they're a problem. I'll let you know how the stripped-down build turns out...

[mrjrt]

Alrighty then, as requested, here's a trace from my build with those other drivers stripped out:
http://pastebin.com/3a0Kv5fr

...and for completeness, here's a trace from the working revision with those drivers disabled as well:
http://pastebin.com/iNmmkL2h

Looking at the trace of your latest revision, it BSODs because it loses the boot volume, which I suspect is because the WinVBlock driver is being unloaded. This didn't BSOD before as Firadisk was providing the boot volume, but because I've disabled it, WinVBlock unloading becomes fatal as we don't just lose the AoE support, we lose the RAMdisk as well...?

Same setup as before: Boot VMWare from iPXE floppy, hook AoE target, follow-through to boot USB disk mapped to a VMware IDE device, use G4D to load ISO into RAM, boot ISO RAMdisk.

[Sha0]

Hello again. This message is not from WinVBlock, meaning that another driver is still present:

NIC Boot Configuration Driver finalizing

If you would kindly remove that driver, perhaps we'll observe different results.

Please use the "stable" WinVBlock from here: http://reboot.pro/topic/8168-winvblock/page-9#entry101308

[mrjrt]

...the stable version works fine (AoE-wise, and with all the other drivers). I'm just trying to help you out with some testing by letting you know your changes since 2ebc053 seem to have broken something that was working previously...

Is that stable version you've linked to a checked build with debug messages enabled?

[mrjrt]

Ok, threw the stable version into my test build anyway (and disabled the nic boot driver), and I'm not getting any messages now - the system just hangs on the startup (Setup is starting Windows) screen. If I break into the target the stack trace shows it's just in an idle loop.

So I've taken the liberty of building a checked version of the revision tagged as 0.0.1.8 with debugging enabled, and to my surprise, it explains the apparent hang - it's just stalling the same as the latest revision. I swear the stable build worked when I tested it in my "normal" setup (before I started any compiling of my own). I'll try it again with the NIC Boot Config driver enabled and see if that "unsticks" it, and I'll try the revision I know works fine normally but without the NIC Boot Config driver to see if removing it causes it to stop working.

[mrjrt]

Ok, adding the NIC Boot Config driver back in makes 0.0.1.8 work - no hanging: http://pastebin.com/apMUwrPT

It may be of relevance that I should mention the load order I'm using in my txtsetup.sif (I've removed the defaults and left in the disabled drivers to give a bit more context):

[SCSI.Load]
;firadisk = firadisk.sys,4 
wvblk32 = wvblk32.sys,4

[BusExtenders.Load]
ndis     = ndis.sys

[Keyboard.Load]
RTLE8023xp  = RTLE8023xp.sys
PCnet       = PCnet.sys
;sanbootconf = sanbootconf.sys
;nicbtcfg    = nicbtcfg.sys

[CdRomDrivers.Load]
;iScsiPrt = iScsiPrt.sys
AoE32    = aoe32.sys

...and based upon the information in this post: http://www.msfn.org/board/topic/146541-xp-preventing-a-scsiload-txtsetupsif-entry-from-being-installed/?do=findComment&comment=977050

...I determine the load order to be:

• ndis.sys
• RTLE8023xp.sys
• PCnet.sys
• ;sanbootconf.sys
• ;nicbtcfg.sys
• ;firadisk = firadisk.sys,4
• wvblk32 = wvblk32.sys,4
• ;iScsiPrt = iScsiPrt.sys
• AoE32 = aoe32.sys

...which should all be fine?

[Sha0]

I'm afraid that nobody should build WinVBlock from the current master, as it's not expected to be fully working. WinVBlock development is in a transitional period between an older strategy and a newer strategy.

Yes, if WinVBlock AoE is boot-enabled but the NIC driver isn't driving the NIC, then the system will hang. I'd suggest only starting the AoE driver after the system has booted to the RAM disk. (And after the NIC driver is driving the NIC.) This behaviour is expected.

[mrjrt]

Main reason for me building from source was to get file-backed disk support working as my ISO is (or at least, will be) bigger than 4GB, and this doesn't work in 0.0.1.8, so I had to try later revisions...(which unfortunately broke AoE for my use case, which is more important to me!) Given I can disable all the RAM disk support and use alternatives (like Firadisk) and just utilise the AoE support in 0.0.1.8 that's fine, but I don't want to miss out on your bug fixes and any performance improvements by having a fork, hence why I'm here to offer any help I can to you to try and ensure it all works in the eventual 0.0.1.9 (or 0.0.2.0!) :)

I would imagine having a driver that works all the way through from text mode (aka. an AoE counterpart to the Microsft iSCSI driver) is a reasonable goal to have as it means the driver is as robust and feature complete as it can be, and given it already worked at an earlier point in development, I suspect the majority of what is needed is already there - just needs to make sure it doesn't get broken accidentally by the architecture changes you've been working on, which is what I suspect has happened, (possibly due to the new messages/threading/mini driver separation creating a runtime initialisation dependency of some sort?) If it introduces an optional dependency for setup on the NIC Boot Config driver if you want to install to it, then that seems reasonable enough use case to support? (Just as you can use the MS iSCSI driver without it if you don't care about installing to an iSCSI target)

[Sha0]

What I intended to convey is that the behaviour that you have observed is by design and not an accident. If the AoE driver is enabled at boot-time, then it will discover any established aBFT and inform Windows that there is an AoE disk available. Windows demands to be able to read from every disk and will hang until it is able to read from every disk. If the NIC driver isn't operating, then the AoE disk cannot operate, so reads cannot happen, so Windows will hang.

I believe that your scenario does not require an AoE disk to be present at boot-time, so I'd suggest delaying the AoE driver until after you've booted from your RAM- or file-backed disk.

Alternatively, you can ensure that the NIC driver is boot-enabled, so that the AoE disk will be able to operate and to satisfy Windows that it is present. Since you could be booting on a variety of hardware, I doubt that you want to include many NIC drivers and have them all boot-enabled, however.

If I've misunderstood something, you are welcome to continue to help me to understand.

[mrjrt]

(Thanks for hanging around on this thread, btw)

My scenario is that I want to be able to install directly to an AoE disk, and then reboot and continue installation from the AoE target, and then reboot and boot the AoE target without it ever needing a local disk, so I agree that the NIC drivers need to be boot drivers, (and indeed they are, for the iSCSI support).

The file-backed disk is purely the installation ISO. The system disk is the remote AoE target.

With all that in mind, 2ebc053 works for me with all my drivers enabled - I can start text mode, select my AoE target, copy the files to it, reboot, boot from the AoE target and continue setup, reboot, and boot from the AoE target into XP. I have to copy the ISO into a Grub4DOS RAM disk though - if I want to use the ISO in file-backed mode I have to disable WinVBlock's Grub4DOS support so I can use Firadisk.

Revisions after that don't seem to work - the NIC is initialised fine as normal (as can be seen in the logs) and the only change is in the build of WinVBlock - there are no changes to any other files. You're the expert on why that would be - I don't understand enough about how the various components interact to make any kind of informed judgement beyond what I can see in the logs.

[Sha0]

15e7df1 is the last commit for the last released version, if I recall correctly. "Revisions after that" aren't expected to work. I have put all development into the "master" branch instead of a "hidden" branch, so I apologize for the confusion.

If 15e7df1 doesn't work with GRUB4DOS ISOs, I'm sorry, but WinVBlock 0.0.1.8 can't drive your RAM disk. It almost appears that you could use V.'s original WinAoE driver with Firadisk and forget about WinVBlock.

I'd obviously like for the next release of WinVBlock to address your needs.

[mrjrt]

Cool, as long as you're happy to consider that use case then we can leave this until you need some testing done, then I'll be happy to help if you want anything. :)

[Sha0]

I appreciate that, very much. I hope to get back into a WinVBlock groove... Just have to balance with paid work.