Hi Laszlo, > Can you capture a call stack when Snp.Start() is invoked for the very > first time (which, IIUC, is a call that should not happen, in your > opinion)? > Unfortunately I do not have access to the platform firmware itself (I maintain an IHV network driver that's shipped in OptionROMs) and I don't believe a generic stack capture is available in EDK2 yet. However I have comprehensive debug from my driver that shows that our driver gets a DriverBinding.Start() at TPL_APPLICATION and we perform the entire probe at TPL_NOTIFY and as soon as that completes and we drop the TPL, the newly installed SNP gets a Snp.Start() call at TPL_CALLBACK - I assume that MNP or something higher had an event registered that fired as soon as the TPL dropped after the DriverBinding.Start() finished.
Here is a snip of the debug log (that I assume will not be of much interest). We don't observe the actual call to DriverBinding.Start() because the debug output is initialised as one of the first things that method does. 1 [sfc]..|INFO: [sfc] Debug Output Initialised 2 [sfc]..|INFO: Linked list max_size=1000000 3 [sfc]..|SfcDebugLibStart:208 [Not Found] 4 [sfc]..|[0x866D9396<] SfcDebugLibStart:222 [Success] 5 [sfc]..|INFO: Running Solarflare UEFI Driver 2.7.8.5 (f71064c4d0a0) for MEDFORD 6 [sfc]..|INFO: Ctrl=954E4B18 Driver=954E4418 Image=866B0000 Size=0x4D9C0 loaded from Device=954E4B18 7 [sfc]..|INFO: Probing PciDev=942C3118 ... snip ... 376 [sfc]..|INFO: Support strings done 377 [sfc]..|INFO: Hii init on hunt=942A6018 complete 378 [sfc]..|TRACE: Closing the DeferredInit event 379 [sfc]..|INFO: Processed deferred init okay 380 [sfc].|[0x9940F873<] GetSupportedTypes:178 [Success] 381 [sfc]|[0x9D4E1DE8<] DriverBindingStart:211 [Success] 382 [sfc].|INFO: Starting SNP=942A2018 383 [sfc].|[0x99653BA4<] SimpleNetworkStart:33 [Success] 384 [sfc].|INFO: Init snp=942A2018 385 [sfc].|TRACE: INIT: Found netdev=942A5D18 386 [sfc].|INFO: Hunt open netdev=942A5D18 387 [sfc].|INFO: Resetting mcdi=942A6480 388 [sfc].|[Base+0x209E0<] HuntReset:312 [Success] 389 [sfc].|INFO: Allocating vis count=3 on mcdi=942A6480 ... snip ... 491 [sfc].|TRACE: Final state filters=0x942A2018 mcastcnt=7 492 [sfc].|TRACE: Filter Snp=942A2018 Add=0x7 Del=0x18 Reset=0 McastCount=1 List=9400EE98 493 [sfc].|TRACE: Final state filters=0x942A2018 mcastcnt=7 494 [sfc].|TRACE: Filter Snp=942A2018 Add=0x7 Del=0x18 Reset=0 McastCount=2 List=93FB5A98 495 [sfc].|TRACE: Final state filters=0x942A2018 mcastcnt=7 496 [sfc]|TRACE: Name Handle=0x954E4B18 PciDev=942C3118 Child=0x0 497 [sfc]|INFO: STR [*ControllerName]=[Solarflare Adapter 17:00.0] 498 [sfc]|TRACE: Name Handle=0x954E4B18 PciDev=942C3118 Child=0x942A5F98 499 [sfc]|INFO: STR [*ControllerName]=[Solarflare NIC [00:0F:53:4C:A7:A0]] 500 [sfc]..|INFO: [sfc] Debug Output Initialised 501 [sfc]..|INFO: Linked list max_size=1000000 502 [sfc]..|SfcDebugLibStart:208 [Not Found] 503 [sfc]..|[Base+0x29396<] SfcDebugLibStart:222 [Success] 504 [sfc]..|INFO: Running Solarflare UEFI Driver 2.7.8.5 (f71064c4d0a0) for MEDFORD 505 [sfc]..|INFO: Ctrl=954E3B98 Driver=954E4418 Image=866B0000 Size=0x4D9C0 loaded from Device=954E4B18 ... snip ... --- The dots between [sfc] and | symbol indicate the TPL the operation is being carried out at. No dots mean TPL_APPLICATION, one dot is TPL_CALLBACK etc. You can see that the Snp.Start() on the first device is called before even the second device gets a DriverBinding.Start(). Cheers, Tom _______________________________________________ edk2-devel mailing list edk2-devel@lists.01.org https://lists.01.org/mailman/listinfo/edk2-devel
