Events with fixed array data arguments results in bad parsing (offset issues)

[kael-msft]

I have an ETW event that uses TraceLoggingUInt32FixedArray and TraceLoggingFloat32FixedArray. In WPA, these fields process correctly. When I load the same etl with a tool that uses perfview, the output is incorrect. It appears that the offsets are incorrect during processing.

Here is a ToString() call. Sorry it's long. You can see after AppUpdateCpuMs that the values begin to be incorrect. Attaching a sample etl. It only has a few events, the one of interes is VolumeFrameTimeAggregated.

VolumeFrameTimeAggregated-FixedArrayOffsetIssue.zip

My quick investigation led me to this area of code. It looks like arraySize is read as bytes, but for fixed count args it is being set as element count instead. Or maybe FixedCountArrayPayloadFetch should be used instead.

perfview/src/TraceEvent/RegisteredTraceEventParser.cs

Line 997 in e1eacef

if ((propertyInfo->Flags & (PROPERTY_FLAGS.ParamFixedLength | PROPERTY_FLAGS.ParamFixedCount)) != 0)

data.ToString()
"<Event MSec= \"45978.7094\" PID=\"32772\" PName=\"cpp_sample_plugin\" TID=\"26820\" EventName=\"VolumeFrameTimeAggregated\" ProviderName=\"Microsoft.MixedReality.Volumetric.RuntimeProvider\" PartA_PrivTags=\"16,777,216\" PartA_PrivacyProduct=\"1\" PartA_PrivacyDataCategory=\"1\" VolumeId=\"93a5478d-8f6b-4c36-ac0c-8831d601991b\" RuntimeFps=\"51.49569\" PlatformFps=\"59.69514\" BatchDurationSeconds=\"60.005024\" AppUpdateCpuMs=\"[1.6673,13.2686,3.202998]\" MeshSyncWaitMs=\"[3.507931E+12,133126664,9E-44]\" MeshSyncWaitFrameCount=\"-34,913,964\" WaitMs=\"[2.3065E-41,0,0]\" PreSendMs=\"[0,0,0]\" PostEndMs=\"[0,0,0]\" RuntimeTurnaroundMs=\"[0,0,-4.9326464E+32]\" AppUpdateCpuMsBucket_LE_7ms=\"0\" AppUpdateCpuMsBucket_LE_14ms=\"-1,030,815,744\" AppUpdateCpuMsBucket_LE_28ms=\"-1,329,710,091\" AppUpdateCpuMsBucket_LE_100ms=\"1,702,642,083\" AppUpdateCpuMsBucket_GT_100ms=\"694,108,393\" PlatformCadenceMs=\"[3.2448037E+36,1.03890016E-20,-2.0139442E+24]\" MinPlatformFrameDeclaredMs=\"760.5232\" MaxPlatformFrameDeclaredMs=
\"-1.2923856E+13\" UnexpectedGap=\"[-247600409,155147363,1212045494]\" PlatformCommandQueueSize=\"[1063019505,1046001161,1073069896]\" RuntimeCommandQueueSize=\"[1488324927,-172013506,-1066963649]\" FrameCount=\"-1,085,784,488\" SkippedPlatformFrameCount=\"1,735,213,045\" CvWakeRealFrameCount=\"2,035,892,672\" CvWakeStateChangeOnlyCount=\"190,529,835\" TransportWaitTimeoutCount=\"11,993,088\" IpcFrameDropCount=\"0\" SendFrameUpdateCount=\"0\" BeginUpdateCount=\"0\" RemovedQueuedUpdateCount=\"-2,137,194,496\" MissedFrameCount=\"1,020,477,739\" UpdateMode=\"?A?\u0003?AUU?AUU?A\" BatchNumber=\"16,777,216\" IsTeardown=\"False\"/>"

[brianrob]

Thanks for reporting this @kael-msft. This will be in the next release.