microsoft / windows-container-tools

Collection of tools to improve the Windows Containers experience
MIT License
240 stars 68 forks source link

Formatting for scalar integer property values using TdhFormatProperty #129

Closed bobsira closed 1 year ago

bobsira commented 1 year ago

This PR is to address the issue: https://github.com/microsoft/windows-container-tools/issues/101

To test this issue toggle the Bluetooth on/off with the config file below:

=== < Config file > ===

{
   "LogConfig":{
      "sources":[
         {
            "type":"ETW",
            "eventFormatMultiLine":false,
            "providers":[
               {
                  "providerName":"BthPort",
                  "providerGuid":"A8DD90AF-85F0-40B1-B022-4F54961E8AE5",
                  "level":"Verbose"
               }
            ]
         }
      ]
   }
}

=== </Config file> ===

=== < Initial Error > ===

<Source>EtwEvent</Source><Time>2022-11-25T03:09:38.000Z</Time><Provider idGuid="{A8DD90AF-85F0-40B1-B022-4F54961E8AE5}"/><DecodingSource>DecodingSourceTlg</DecodingSource><Execution ProcessID="0" ThreadID="0" /><Level>Information</Level><Keyword>0x400000000101</Keyword><EventData><PartA_PrivTags>50333696</PartA_PrivTags><DeviceExtensionSessionId>{9e3d7242-0079-0004-9a75-3d9e7900d901}</DeviceExtensionSessionId><HciConnectionSessionId>{9e3d7242-0079-0000-02ab-519e7900d901}</HciConnectionSessionId><CxnActivityId>{00000000-0000-0000-0000-000000000000}</CxnActivityId><WeInitiatedThisEvent>true</WeInitiatedThisEvent><ConnectionType>0</ConnectionType><BDIFFlags>17183</BDIFFlags><StatusErrorCode>4</StatusErrorCode><CreateConnectionTicks>7406551736</CreateConnectionTicks><ConnectionCompleteTicks>7457814175</ConnectionCompleteTicks><BTDeviceAddress>233717558281702</BTDeviceAddress></EventData>
[2022-11-25T03:09:40.000Z][LOGMONITOR] ERROR: Failed to format ETW event property. Unexpected length of 0 for intype 300 and outtype 0
[2022-11-25T03:09:40.000Z][LOGMONITOR] ERROR: Failed to query ETW event property length. Error: 15005l
[2022-11-25T03:09:40.000Z][LOGMONITOR] ERROR: Failed to format ETW event user data.
[2022-11-25T03:09:40.000Z][LOGMONITOR] ERROR: Failed to format ETW event property. Unexpected length of 0 for intype 300 and outtype 0
[2022-11-25T03:09:40.000Z][LOGMONITOR] ERROR: Failed to query ETW event property length. Error: 15005l
[2022-11-25T03:09:40.000Z][LOGMONITOR] ERROR: Failed to format ETW event user data.
[2022-11-25T03:09:40.000Z][LOGMONITOR] ERROR: Failed to format ETW event property. Unexpected length of 0 for intype 300 and outtype 0
[2022-11-25T03:09:40.000Z][LOGMONITOR] ERROR: Failed to query ETW event property length. Error: 15005l
[2022-11-25T03:09:40.000Z][LOGMONITOR] ERROR: Failed to format ETW event user data.
[2022-11-25T03:09:40.000Z][LOGMONITOR] ERROR: Failed to format ETW event property. Unexpected length of 0 for intype 300 and outtype 0
[2022-11-25T03:09:40.000Z][LOGMONITOR] ERROR: Failed to query ETW event property length. Error: 15005l
[2022-11-25T03:09:40.000Z][LOGMONITOR] ERROR: Failed to format ETW event user data.
[2022-11-25T03:09:40.000Z][LOGMONITOR] ERROR: Failed to format ETW event property. Unexpected length of 0 for intype 300 and outtype 0
[2022-11-25T03:09:40.000Z][LOGMONITOR] ERROR: Failed to query ETW event property length. Error: 15005l
[2022-11-25T03:09:40.000Z][LOGMONITOR] ERROR: Failed to format ETW event user data.
[2022-11-25T03:09:40.000Z][LOGMONITOR] ERROR: Failed to format ETW event property. Unexpected length of 0 for intype 300 and outtype 0
[2022-11-25T03:09:40.000Z][LOGMONITOR] ERROR: Failed to query ETW event property length. Error: 15005l
[2022-11-25T03:09:40.000Z][LOGMONITOR] ERROR: Failed to format ETW event user data.
[2022-11-25T03:09:40.000Z][LOGMONITOR] ERROR: Failed to format ETW event user data..
[2022-11-25T03:09:40.000Z][LOGMONITOR] ERROR: Failed to format ETW event data. Error: 15005
[2022-11-25T03:09:40.000Z][LOGMONITOR] ERROR: Failed to print event. Error: 15005
[2022-11-25T03:09:40.000Z][LOGMONITOR] ERROR: Failed to record ETW event. Error: 15005
<Source>EtwEvent</Source><Time>2022-11-25T03:09:43.000Z</Time><Provider idGuid="{A8DD90AF-85F0-40B1-B022-4F54961E8AE5}"/><DecodingSource>DecodingSourceTlg</DecodingSource><Execution ProcessID="0" ThreadID="0" /><Level>Verbose</Level><Keyword>0x400000000104</Keyword><EventData><PartA_PrivTags>50333696</PartA_PrivTags><DeviceExtensionSessionId>{9e3d7242-0079-0004-9a75-3d9e7900d901}</DeviceExtensionSessionId><HciConnectionSessionId>{9e3d7242-0079-0000-11ab-519e7900d901}</HciConnectionSessionId><CxnActivityId>{00000000-0000-0000-0000-000000000000}</CxnActivityId><WeInitiatedThisEvent>1</WeInitiatedThisEvent><BTDeviceAddress>106291079628612</BTDeviceAddress></EventData>

=== <\Initial Error> ===

Look up error code 15005 at: https://windowsinternalservices.azurewebsites.net/Static/Errors/

=== < Logs after fix > ===

{"Source":"ETW","LogEntry":{"Time":"2023-04-25T13:54:48.000Z","ProviderName":"Microsoft.Windows.Bluetooth.BthPort","ProviderId":"{A8DD90AF-85F0-40B1-B022-4F54961E8AE5}","DecodingSource":"DecodingSourceTlg","Execution":{"ProcessId":0,"ThreadId":0},"Level":"Information","Keyword":"0x400000000102","EventId":"","EventData":{"PartA_PrivTags":50333696,"HciConnectionSessionId":"{a817c7e8-73d2-0001-b169-98a8d273d901}","CxnActivityId":"{00000000-0000-0000-0000-000000000000}","StatusErrorCode":22,"ConnectionType":0,"AllowRoleSwitch":0,"EncryptionCompleteTicks":3946018662407,"DisconnectionCompleteTicks":4032296304067,"LEDataLengthChangeCount":0,"BTDeviceAddress":264010515245299}},"SchemaVersion":"1.0.0"}
{"Source":"ETW","LogEntry":{"Time":"2023-04-25T13:54:51.000Z","ProviderName":"Microsoft.Windows.Bluetooth.BthPort","ProviderId":"{A8DD90AF-85F0-40B1-B022-4F54961E8AE5}","DecodingSource":"DecodingSourceTlg","Execution":{"ProcessId":4,"ThreadId":46852},"Level":"Verbose","Keyword":"0x400000000000","EventId":"","EventData":{"PartA_PrivTags":50333696,"DeviceExtensionSessionId":"{a817c7e8-73d2-0004-9fc8-17a8d273d901}"}},"SchemaVersion":"1.0.0"}
{"Source":"ETW","LogEntry":{"Time":"2023-04-25T13:54:52.000Z","ProviderName":"Microsoft.Windows.Bluetooth.BthPort","ProviderId":"{A8DD90AF-85F0-40B1-B022-4F54961E8AE5}","DecodingSource":"DecodingSourceTlg","Execution":{"ProcessId":4,"ThreadId":38464},"Level":"Verbose","Keyword":"0x400000000000","EventId":"","EventData":{"PartA_PrivTags":50333696,"DeviceExtensionSessionId":"{a817c7e8-73d2-0004-9fc8-17a8d273d901}"}},"SchemaVersion":"1.0.0"}
{"Source":"ETW","LogEntry":{"Time":"2023-04-25T13:54:52.000Z","ProviderName":"Microsoft.Windows.Bluetooth.BthPort","ProviderId":"{A8DD90AF-85F0-40B1-B022-4F54961E8AE5}","DecodingSource":"DecodingSourceTlg","Execution":{"ProcessId":2788,"ThreadId":3016},"Level":"Verbose","Keyword":"0x400000000000","EventId":"","EventData":{"PartA_PrivTags":33556480,"DeviceExtensionSessionId":"{a817c7e8-73d2-0004-9fc8-17a8d273d901}","ScanType":0,"ScanInteval":588,"ScanWindow":60}},"SchemaVersion":"1.0.0"}
{"Source":"ETW","LogEntry":{"Time":"2023-04-25T13:54:56.000Z","ProviderName":"Microsoft.Windows.Bluetooth.BthPort","ProviderId":"{A8DD90AF-85F0-40B1-B022-4F54961E8AE5}","DecodingSource":"DecodingSourceTlg","Execution":{"ProcessId":4,"ThreadId":48516},"Level":"Verbose","Keyword":"0x400000000104","EventId":"","EventData":{"PartA_PrivTags":50333696,"DeviceExtensionSessionId":"{a817c7e8-73d2-0004-9fc8-17a8d273d901}","HciConnectionSessionId":"{a817c7e8-73d2-0002-5d98-2da9d273d901}","CxnActivityId":"{00000000-0000-0000-0000-000000000000}","WeInitiatedThisEvent":1,"BTDeviceAddress":71201803738383}},"SchemaVersion":"1.0.0"}

=== < Logs after fix > ===