[CI-NO-BUILD] [vioscsi] Implement cold and hot tracing paths

[benyamin-codez]

1. Introduced three (3) compile-time environment variables:
   a) RUN_WPP_ALL_PATHS
   Compile WPP for the hot path too.
   Is the inverse of RUN_COLD_PATH_ONLY, which is the default behaviour.
   b) FORCE_RUN_UNCHECKED
   Run without EVENT_TRACING or DBG. Defines RUN_UNCHECKED.
   c) FORCE_RUN_DEBUG
   Run with DBG rather than EVENT_TRACING. Undefines EVENT_TRACING.

2. WPP scans for WPP config on a per file basis. Sections of the config file cannot be excluded and conditional macros will be ignored. To solve this, we establish two new files with WPP configuration data. One holds exclusively cold path data (wpp_cold_path.h) and the other holds data for all paths (wpp_all_paths.h). Which file to use is set conditionally per the vioscsi.vcxproj project file configuration.

3. The hot path DBG and WPP macro variants are a clone of the cold path macros, but with a "_HP" suffix. The exception to this is RhelDbgPrint() which we extend as RhelDbgPrintHotPath().

4. Encapsulated exisitng cold and and hot trace messages in compile-time conditional macros and in same manner drops *.tmh includes when necessary. The general format for the cold path is #if !defined(RUN_UNCHECKED) and for the hot path #if !defined(RUN_UNCHECKED) || !defined(RUN_COLD_PATH_ONLY).

5. Minor refactoring of:
   a) helper.c - GetScsiConfig()
   b) helper.c - SetGuestFeatures()

6. Major refactoring of:
   a) trace.h
   b) vioscsi.c - VioScsiHwInitialize() - corrects order of init for benefit of clean trace.

7. Major new instrumentation of:
   a) helper.c - InitVirtIODevice()

8. Reconfigured the following for INLINE function tracing:
   a) vioscsi.c - HandleResponse()
   b) vioscsi.c - PreProcessRequest()
   c) vioscsi.c - PostProcessRequest()
   d) vioscsi.c - DispatchQueue()

9. Mnemonic rename of VioScsiPassiveInitializeRoutine() to VioScsiPassiveDpcInitializeRoutine().

10. Correct struct virtio_bar for bMemorySpace rather than bPortSpace (vioscsi.h and virtio_pci.c).

11. Add missing structs for PCI Capabilities (vioscsi.h).

12. Included stddef.h for offsetof function.

13. Also added RhelDebugPrintInclude() and RhelDebugPrintIncludeHotPath().

14. Inline functions use an enum INL_FUNC_IDX to encode a ULONG index to each function that either calls or is an inline function. We then use inline_func_string_map[] to map / decode the ULONG index to a string literal (the name of the function). This can then be used to properly label the calling and inline function names within messages.

15. Renamed adaptExt->dpc_ok to adaptExt->dpc_ready.

Hard to split this one up further methinks.
I do have a fair bit of additional instrumentation to merge after this one.

[benyamin-codez]

Note somewhat cheeky inclusion to raise the NTDDI_VERSION for Win11 builds to NTDDI_WIN10_CO, i.e. Cobalt / 21H2.

kvm-guest-drivers-windows/vioscsi/vioscsi.vcxproj

Lines 141 to 148 in 9b47ab2

	<ItemDefinitionGroup Condition="'$(Configuration)'=='Win11 Release'">
	<ClCompile>
	<PreprocessorDefinitions Condition="'$(DisableTracing)'=='true'">%(PreprocessorDefinitions);RUN_UNCHECKED=1</PreprocessorDefinitions>
	<PreprocessorDefinitions Condition="'$(LimitPathsWPP)'=='WPPColdPathOnly'">%(PreprocessorDefinitions);RUN_COLD_PATH_ONLY=1</PreprocessorDefinitions>
	<PreprocessorDefinitions Condition="'$(UseDebugTracing)'!='true'">%(PreprocessorDefinitions);EVENT_TRACING=1</PreprocessorDefinitions>
	<PreprocessorDefinitions>%(PreprocessorDefinitions);NTDDI_VERSION=NTDDI_WIN10_CO</PreprocessorDefinitions>
	</ClCompile>
	</ItemDefinitionGroup>

EDIT: This was removed.

[benyamin-codez]

Note somewhat cheeky inclusion to raise the NTDDI_VERSION for Win11 builds to NTDDI_WIN10_CO, i.e. Cobalt / 21H2.

Let me know if you need me to split that off and return to NTDDI_WINTHRESHOLD / NTDDI_THRESHOLD / NTDDI_WIN10 / 0x0A000000, i.e. ABRACADABRA_THRESHOLD, Windows build 10.0.10240, Version 1507, Threshold 1.

EDIT: This was removed. See PR #1309. Still valid:

Does this need to be done by a different means anyway, e.g. via *.rc or *.ver files?

[benyamin-codez]

@YanVugenfirer @vrozenfe

I've left PR #1214 in draft until this PR merges as that one may have hot path entries that I will need to refactor to make use of the RUN_COLD_PATH_ONLY conditional.

Let me know what might be needed to progress this one.

Best regards,
Ben

[benyamin-codez]

@YanVugenfirer @vrozenfe @kostyanf14

Note somewhat cheeky inclusion to raise the NTDDI_VERSION for Win11 builds to NTDDI_WIN10_CO...

Let me know if you need me to split that off and return to NTDDI_WIN10, i.e. Windows 10, Version 1507, Threshold 1.

Does this need to be done by a different means anyway, e.g. via *.rc or *.ver files?

If you're ok with retaining this and there are no other issues, it looks like this one's ready to go...

EDIT: This was removed.

[benyamin-codez]

@YanVugenfirer @vrozenfe @kostyanf14

I have split the cheeky NTDDI version raise to PR #1309 and rebased.

This one is probably the plug in the pipe... Any concerns I need to address...?

[benyamin-codez]

@kostyanf14

The HCK-CI/vioscsi-Win2025x64_host check here passes the Flush Test but fails Disk Verification (LOGO).
You've mentioned elsewhere the Flush Test can go one way or the other with the HCK.
It seems Disk Verification (LOGO) does somewhat too.
Is that observation remarkable in any way...?

Some observations:

Check	Flush Test	Disk Verification (LOGO)	Disk Stress (LOGO)
vioscsi-Win2022x64	?Fails?	Known Issue	Pass
vioscsi-Win2025x64_host	?Fails?	?Fails?	Pass
vioscsi-Win11_24H2x64_host_uefi_viommu	?Fails?	Known Issue	Pass
viostor-Win2022x64	?Fails?	?Fails?	Pass
viostor-Win2025x64_host	?Fails?	?Fails?	Pass
viostor-Win11_24H2x64_host_uefi_viommu	?Fails?	Pass	?Fails?

Under here is the table's scaffold if you want to reply with corrections.

| Check | `Flush Test` | `Disk Verification (LOGO)` | `Disk Stress (LOGO)` |
|---| :---: | :---: | :---: |
| vioscsi-Win2022x64 | ?Fails? | Known Issue | Pass |
| vioscsi-Win2025x64_host| ?Fails? |?Fails?| Pass |
| vioscsi-Win11_24H2x64_host_uefi_viommu | ?Fails? | Known Issue | Pass |
| viostor-Win2022x64 | ?Fails? |  ?Fails? | Pass |
| viostor-Win2025x64_host | ?Fails? |  ?Fails? | Pass |
| viostor-Win11_24H2x64_host_uefi_viommu | ?Fails? | Pass | ?Fails? |

Any further prudent vioscsi checks needed for this PR?

[benyamin-codez]

@kostyanf14

I'm guessing we should probably do a vioscsi-Win2022x64 for the other configuration pathway.

[benyamin-codez]

@kostyanf14

So it looks like vioscsi-Win2022x64 had failures for Flush Test and Disk Verification (LOGO).
I shall presume these are false.

Where there any more checks you wanted to run?

_Outdated content_

I have the following I want to force push:

--- a/vioscsi/vioscsi.c
+++ b/vioscsi/vioscsi.c
@@ -1551,6 +1551,9 @@ VioScsiBuildIo(IN PVOID DeviceExtension, IN PSCSI_REQUEST_BLOCK Srb)
     {
         SRB_SET_SRB_STATUS(Srb, SRB_STATUS_NO_DEVICE);
         StorPortNotification(RequestComplete, DeviceExtension, Srb);
+#if !defined(RUN_UNCHECKED) || !defined(RUN_COLD_PATH_ONLY)
+        EXIT_FN_SRB_HP();
+#endif
         return FALSE;
     }
 
@@ -1922,7 +1925,6 @@ PreProcessRequest(IN PVOID DeviceExtension, IN PSRB_TYPE Srb, IN PVOID InlineFun
 #if !defined(RUN_UNCHECKED)
                     RhelDbgPrint(TRACE_LEVEL_INFORMATION, " Completing all pending SRBs\n");
 #endif
-                    // CompletePendingRequestsOnReset(DeviceExtension, DpcLock);
                     CompletePendingRequestsOnReset(DeviceExtension);
                     SRB_SET_SRB_STATUS(Srb, SRB_STATUS_SUCCESS);
 #if !defined(RUN_UNCHECKED)

Is that ok...? Shall I push that first, before any more checks?

[benyamin-codez]

@kostyanf14 @YanVugenfirer @vrozenfe

I have the following I want to force push...

I've also noticed I should relocate some of the ENTER_FN() calls (to above variable initialisation where possible).

_Outdated content_

So I could do these and the new commit I mentioned above in a new PR if preferred.
There is no functional impact of leaving these changes out for now and they can be merged afterwards.

If someone can please let me know which way to go that would be helpful...? 8^d

[benyamin-codez]

fwiw, here are those changes.
There is one breaking change in helper.c with an unwrapped orphan...

_Outdated content_

--- a/vioscsi/helper.c
+++ b/vioscsi/helper.c
@@ -237,7 +237,6 @@ DeviceReset(IN PVOID DeviceExtension)
     ULONG fragLen;
     ULONG sgElement;
 
-    ENTER_FN();
     if (adaptExt->dump_mode)
     {
 #if !defined(RUN_UNCHECKED)

--- a/vioscsi/vioscsi.c
+++ b/vioscsi/vioscsi.c
@@ -1524,6 +1524,10 @@ VioScsiUnitControl(IN PVOID DeviceExtension, IN SCSI_UNIT_CONTROL_TYPE ControlTy
 BOOLEAN
 VioScsiBuildIo(IN PVOID DeviceExtension, IN PSCSI_REQUEST_BLOCK Srb)
 {
+#if !defined(RUN_UNCHECKED) || !defined(RUN_COLD_PATH_ONLY)
+    ENTER_FN_SRB_HP();
+#endif
+
     PCDB cdb;
     ULONG i;
     ULONG fragLen;
@@ -1536,10 +1540,6 @@ VioScsiBuildIo(IN PVOID DeviceExtension, IN PSCSI_REQUEST_BLOCK Srb)
     UCHAR TargetId;
     UCHAR Lun;
 
-#if !defined(RUN_UNCHECKED) || !defined(RUN_COLD_PATH_ONLY)
-    ENTER_FN_SRB_HP();
-#endif
-
     cdb = SRB_CDB(Srb);
     srbExt = SRB_EXTENSION(Srb);
     adaptExt = (PADAPTER_EXTENSION)DeviceExtension;
@@ -1677,6 +1677,10 @@ VOID FORCEINLINE DispatchQueue(IN PVOID DeviceExtension, IN ULONG MessageId, IN
 
 VOID ProcessBuffer(IN PVOID DeviceExtension, IN ULONG MessageId, IN STOR_SPINLOCK LockMode)
 {
+#if !defined(RUN_UNCHECKED) || !defined(RUN_COLD_PATH_ONLY)
+    ENTER_FN_HP();
+#endif
+
     PVirtIOSCSICmd cmd;
     unsigned int len;
     PADAPTER_EXTENSION adaptExt = (PADAPTER_EXTENSION)DeviceExtension;
@@ -1689,10 +1693,6 @@ VOID ProcessBuffer(IN PVOID DeviceExtension, IN ULONG MessageId, IN STOR_SPINLOC
     ULONG vq_req_idx;
     PVOID LockContext = NULL; // sanity check for LockMode = InterruptLock or StartIoLock
 
-#if !defined(RUN_UNCHECKED) || !defined(RUN_COLD_PATH_ONLY)
-    ENTER_FN_HP();
-#endif
-
     if (QueueNumber >= (adaptExt->num_queues + VIRTIO_SCSI_REQUEST_QUEUE_0))
     {
 #if !defined(RUN_UNCHECKED)
@@ -1755,10 +1755,10 @@ VOID ProcessBuffer(IN PVOID DeviceExtension, IN ULONG MessageId, IN STOR_SPINLOC
 
 VOID VioScsiCompleteDpcRoutine(IN PSTOR_DPC Dpc, IN PVOID Context, IN PVOID SystemArgument1, IN PVOID SystemArgument2)
 {
-    ULONG MessageId;
 #if !defined(RUN_UNCHECKED) || !defined(RUN_COLD_PATH_ONLY)
     ENTER_FN_HP();
 #endif
+    ULONG MessageId;
     MessageId = PtrToUlong(SystemArgument1);
     ProcessBuffer(Context, MessageId, DpcLock);
 #if !defined(RUN_UNCHECKED) || !defined(RUN_COLD_PATH_ONLY)

[benyamin-codez]

Plus new clang-format conflict --> Opportunity to rename trace.h to tracing.h as it is now clang-format compliant.

[benyamin-codez]

I'm also having another round at in-lined tracing.
It needs a fix (don't rely on %!FUNC!) and tbh it presently has quite distasteful mechanics.

[benyamin-codez]

I'm also having another round at in-lined tracing. It needs a fix (don't rely on %!FUNC!) and tbh it presently has quite distasteful mechanics.

Just to be clear, the problem with ETW / WPP and inline functions is that the built-in variable %!FUNC! will be the calling function and not the inline function. It will also be the calling function where the inline function was optimised. The other calling functions will then just refer to this pointer. This means that you cannot determine which function left the trace message using %!FUNC!.

So I started with building an enum containing all inline function names, both calling and called functions, so that we could use an integer-based index of names when calling inline functions rather than a string literal via PVOID.

Spent a bit of time using WPP TYPEMACRO() with this index (the index also enabled me to use the feature), which unfortunately results in indexed trace output, i.e. [0x00000001(ProcessBuffer)] rather than just [ProcessBuffer], which was more than a bit unsightly.

Then it was on to parameterised USEPREFIX which is much more presentable (no index was displayed) and is working quite nicely. This was in the hot path; I still need to refactor for cold path exclusions and DBG pathway. Then some sanity / performance testing before pushing changes...

[benyamin-codez]

I've seen a radical improvement in performance with my new solution for inline functions. It would appear using %!func! from an inline function adds significant overhead. This, of course, seems entirely logical in hindsight... 8^d

With max-segments=512 (to compare with v266):

Target	Flavour	SEQ1M Q8T1 (MiBps)	RND4K Q32T16 (MiBps)	RND4K Q32T16 (IOPS)	RND4K Q32T16 (μs)
Win10	v266	6,704	1,193	291,205	1,757
Win10	WIP Cold-Path Only	6,698	1,223	298,455	1,712
Win10	WIP All Paths	6,709	1,203	293,691	1,742
Win11	v266	7,146	1,497	365,579	1,397
Win11	WIP Cold-Path Only	7,146	1,524	372,001	1,375
Win11	WIP All Paths	7,158	1,504	367,153	1,391

As such, my comments here are perhaps not correct:

When the WPP runs it creates the relevant *.tmh file(s) with entries for any and all matching functions as determined by the scan file. This means that the WPP performance overhead is directly proportional to the number of entries, regardless of whether they are printed. Therefore, changes to the verbosity of debug messages will have no effect on performance with ETW - it will consistently be the worst possible.

...all of which - to a certain degree - diminishes the case for RUN_UNCHECKED or even to divide by hot and cold paths (esp. with those values above being all within a margin of error of each other).

Of course, there is still a performance overhead when monitoring or capturing a trace, with say TraceView, but this is mostly in user-mode CPU consumption.

As such, one argument for separate hot and cold code paths, might be for when monitoring a trace on a system that must maintain performance without the additional user-mode CPU consumption by ETW. In such - perhaps production environments - the better approach might be to use a default cold-path only collection of messages, but then issue all desired/critical hot-path messages in the cold-path under TRACE_ALL or TRACE_LEVEL_NONE flags instead.

The addition of RUN_UNCHECKED could still be beneficial to eliminate tracing as a cause of performance loss or to otherwise quantify any overhead, so perhaps there is value in retaining it.

I'm leaning towards keeping things as posted in the last push, but I would appreciate some discussion and sharing of alternate views and considerations, to inform me as to where to go from here.

In the meantime, I'll drop this to draft.
PRs #1293 and #1296 should merge first anyway methinks...

[benyamin-codez]

I built a version without RUN_UNCHECKED or separate hot and cold paths...
... which below I call "WIP Consolidated"...
... and did some more performance testing.

If you are interested in perusing the relevant WIPs:
I will try to push them to my repo in a few hours time (when I have some time to do so).

With max-segments=512 (to compare with v266):

Target	Flavour	SEQ1M Q8T1 (MiBps)	RND4K Q32T16 (MiBps)	RND4K Q32T16 (IOPS)	RND4K Q32T16 (μs)
Win10	v266	6,699	1,211	295,603	1,729
Win10	WIP Consolidated	6,701	1,211	295,651	1,728
Win10	WIP Cold-Path Only	6,714	1,218	297,454	1,720
Win10	WIP All Paths	6,703	1,204	293,845	1,741
Win11	v266	7,153	1,480	361,334	1,413
Win11	WIP Consolidated	7,134	1,480	361,358	1,414
Win11	WIP Cold-Path Only	7,136	1,489	363,585	1,405
Win11	WIP All Paths	7,111	1,466	357,851	1,427

The instrumentation in my WIP is already fairly extensive, but if we were to add more (will we though?), I think the latency will grow a bit. Therefore, my thoughts are that it's probably best to keep the hot and cold path variant. The cold path variant is usually also marginally quicker. Arguments for keeping RUN_UNCHECKED are as above.

Please do let me know your views per the request in my last post so that we can progress this.