microsoft
/
msquic
зеркало из https://github.com/microsoft/msquic.git
1
0
Форкнуть 0
Код Задачи Пакеты Проекты Релизы Вики Активность

RPS Events (#2045)

This commit is contained in:
Nick Banks 2021-12-20 13:19:44 -05:00 коммит произвёл GitHub
Родитель f346fe40a9
Коммит 3821394622
Не найден ключ, соответствующий данной подписи
Идентификатор ключа GPG: 4AEE18F83AFDEB23
41 изменённых файлов: 2077 добавлений и 202 удалений
Показать статистику Скачать Patch файл Скачать Diff файл Показать все файлы Свернуть все файлы

1
.azure/azure-pipelines.perf.yml
Просмотреть файл

@ -26,6 +26,7 @@ parameters:
- Datapath.Light
- Datapath.Verbose
- Stacks.Light
- RPS.Light
- Performance.Light
- Basic.Verbose
- Performance.Light

2
docs/Diagnostics.md
Просмотреть файл

@ -27,7 +27,7 @@ netsh.exe trace stop
To convert the trace, you can use the following command:
```
netsh.exe trace convert quic.etl
netsh.exe trace convert quic.etl overwrite=yes
```
If you're using a version of MsQuic that uses an ETW manifest version more recent than the one built into the Windows image, decoding may not provide correct output. To solve this issue, newer versions of Windows (11 and Server 2022) support a `manpath` flag that can be used to manually specify a manifest. This will likely always be needed for apps using MsQuic in user mode.

2
scripts/log.ps1
Просмотреть файл

@ -46,7 +46,7 @@ param (
[switch]$Stream = $false,
[Parameter(Mandatory = $false, ParameterSetName='Start')]
[ValidateSet("Basic.Light", "Datapath.Light", "Datapath.Verbose", "Stacks.Light", "Performance.Light", "Basic.Verbose", "Performance.Light", "Performance.Verbose", "Full.Light", "Full.Verbose", "SpinQuic.Light")]
[ValidateSet("Basic.Light", "Datapath.Light", "Datapath.Verbose", "Stacks.Light", "RPS.Light", "Performance.Light", "Basic.Verbose", "Performance.Light", "Performance.Verbose", "Full.Light", "Full.Verbose", "SpinQuic.Light")]
[string]$Profile = "Full.Light",
[Parameter(Mandatory = $false, ParameterSetName='Cancel')]

8
scripts/performance-helper.psm1
Просмотреть файл

@ -360,7 +360,7 @@ function Invoke-RemoteExe {
$LogScript = Join-Path $RemoteDirectory log.ps1
if ($Record) {
& $LogScript -Start -Profile $LogProfile -ProfileInScriptDirectory | Out-Null
& $LogScript -Start -Profile $LogProfile -ProfileInScriptDirectory -InstanceName msquicperf | Out-Null
}
$Arch = Split-Path (Split-Path $Exe -Parent) -Leaf
@ -387,7 +387,7 @@ function Invoke-RemoteExe {
}
if ($Record) {
& $LogScript -Stop -OutputPath (Join-Path $RemoteDirectory serverlogs server) -ProfileInScriptDirectory | Out-Null
& $LogScript -Stop -OutputPath (Join-Path $RemoteDirectory serverlogs server) -ProfileInScriptDirectory -InstanceName msquicperf | Out-Null
}
} -AsJob -ArgumentList $Exe, $RunArgs, $BasePath, $Record, $LogProfile, $Kernel, $RemoteDirectory
}
@ -452,7 +452,7 @@ function Start-Tracing {
param($LocalDirectory)
if ($Record -and !$Local) {
$LogScript = Join-Path $LocalDirectory log.ps1
& $LogScript -Start -Profile $LogProfile -ProfileInScriptDirectory | Out-Null
& $LogScript -Start -Profile $LogProfile -ProfileInScriptDirectory -InstanceName msquicperf | Out-Null
}
}
@ -460,7 +460,7 @@ function Stop-Tracing {
param($LocalDirectory, $OutputDir, $Test)
if ($Record -and !$Local) {
$LogScript = Join-Path $LocalDirectory log.ps1
& $LogScript -Stop -OutputPath (Join-Path $OutputDir $Test.ToString() client) -ProfileInScriptDirectory | Out-Null
& $LogScript -Stop -OutputPath (Join-Path $OutputDir $Test.ToString() client) -ProfileInScriptDirectory -InstanceName msquicperf | Out-Null
}
}

6
scripts/performance.ps1
Просмотреть файл

@ -92,7 +92,7 @@ param (
[string]$ComputerName = "quic-server",
[Parameter(Mandatory = $false)]
[ValidateSet("Basic.Light", "Datapath.Light", "Datapath.Verbose", "Stacks.Light", "Performance.Light", "Basic.Verbose", "Performance.Light", "Performance.Verbose", "Full.Light", "Full.Verbose", "SpinQuic.Light", "None")]
[ValidateSet("Basic.Light", "Datapath.Light", "Datapath.Verbose", "Stacks.Light", "RPS.Light", "Performance.Light", "Basic.Verbose", "Performance.Light", "Performance.Verbose", "Full.Light", "Full.Verbose", "SpinQuic.Light", "None")]
[string]$LogProfile = "None",
[Parameter(Mandatory = $false)]
@ -497,12 +497,12 @@ $LocalDataCache = LocalSetup
if ($Record -and $IsWindows) {
try {
wpr.exe -cancel 2> $null
wpr.exe -cancel -instancename msquicperf 2> $null
} catch {
}
Invoke-TestCommand -Session $Session -ScriptBlock {
try {
wpr.exe -cancel 2> $null
wpr.exe -cancel -instancename msquicperf 2> $null
} catch {
}
}

8
src/core/api.c
Просмотреть файл

@ -1084,6 +1084,14 @@ MsQuicStreamSend(
goto Exit;
}
QuicTraceEvent(
StreamAppSend,
"[strm][%p] App queuing send [%llu bytes, %u buffers, 0x%x flags]",
Stream,
TotalLength,
BufferCount,
Flags);
SendRequest->Next = NULL;
SendRequest->Buffers = Buffers;
SendRequest->BufferCount = BufferCount;

13
src/core/binding.c
Просмотреть файл

@ -1148,7 +1148,7 @@ QuicBindingPreprocessDatagram(
)
{
CXPLAT_RECV_PACKET* Packet = CxPlatDataPathRecvDataToRecvPacket(Datagram);
CxPlatZeroMemory(Packet, sizeof(CXPLAT_RECV_PACKET));
CxPlatZeroMemory(&Packet->PacketNumber, sizeof(CXPLAT_RECV_PACKET) - sizeof(uint64_t));
Packet->Buffer = Datagram->Buffer;
Packet->BufferLength = Datagram->BufferLength;
@ -1560,6 +1560,9 @@ QuicBindingReceive(
// connection it was delivered to.
//
uint32_t Proc = CxPlatProcCurrentNumber();
uint64_t ProcShifted = ((uint64_t)Proc) << 40;
CXPLAT_RECV_DATA* Datagram;
while ((Datagram = DatagramChain) != NULL) {
TotalChainLength++;
@ -1574,9 +1577,17 @@ QuicBindingReceive(
CXPLAT_RECV_PACKET* Packet =
CxPlatDataPathRecvDataToRecvPacket(Datagram);
CxPlatZeroMemory(Packet, sizeof(CXPLAT_RECV_PACKET));
Packet->PacketId =
ProcShifted | InterlockedIncrement64((int64_t*)&MsQuicLib.PerProc[Proc].ReceivePacketId);
Packet->Buffer = Datagram->Buffer;
Packet->BufferLength = Datagram->BufferLength;
CXPLAT_DBG_ASSERT(Packet->PacketId != 0);
QuicTraceEvent(
PacketReceive,
"[pack][%llu] Received",
Packet->PacketId);
#if QUIC_TEST_DATAPATH_HOOKS_ENABLED
//
// The test datapath receive callback allows for test code to modify

5
src/core/binding.h
Просмотреть файл

@ -28,6 +28,11 @@ typedef struct QUIC_RETRY_TOKEN_CONTENTS {
//
typedef struct CXPLAT_RECV_PACKET {
//
// The unique identifier for the packet.
//
uint64_t PacketId;
//
// The bytes that represent the fully decoded packet number.
//

12
src/core/connection.c
Просмотреть файл

@ -3809,10 +3809,16 @@ QuicConnRecvDecryptAndAuthenticate(
QUIC_STATELESS_RESET_TOKEN_LENGTH);
}
CXPLAT_DBG_ASSERT(Packet->PacketId != 0);
QuicTraceEvent(
PacketDecrypt,
"[pack][%llu] Decrypting",
Packet->PacketId);
uint8_t Iv[CXPLAT_MAX_IV_LENGTH];
QuicCryptoCombineIvAndPacketNumber(
Connection->Crypto.TlsState.ReadKeys[Packet->KeyType]->Iv,
(uint8_t*) &Packet->PacketNumber,
(uint8_t*)&Packet->PacketNumber,
Iv);
//
@ -4362,7 +4368,7 @@ QuicConnRecvFrames(
QUIC_STATUS Status =
QuicStreamRecv(
Stream,
Packet->EncryptedWith0Rtt,
Packet,
FrameType,
PayloadLength,
Payload,
@ -5105,6 +5111,7 @@ QuicConnRecvDatagramBatch(
CXPLAT_DBG_ASSERT(Datagrams[i]->Allocated);
CXPLAT_ECN_TYPE ECN = CXPLAT_ECN_FROM_TOS(Datagrams[i]->TypeOfService);
Packet = CxPlatDataPathRecvDataToRecvPacket(Datagrams[i]);
CXPLAT_DBG_ASSERT(Packet->PacketId != 0);
if (QuicConnRecvPrepareDecrypt(
Connection, Packet, HpMask + i * CXPLAT_HP_SAMPLE_LENGTH) &&
QuicConnRecvDecryptAndAuthenticate(Connection, Path, Packet) &&
@ -5204,6 +5211,7 @@ QuicConnRecvDatagrams(
CXPLAT_RECV_PACKET* Packet =
CxPlatDataPathRecvDataToRecvPacket(Datagram);
CXPLAT_DBG_ASSERT(Packet != NULL);
CXPLAT_DBG_ASSERT(Packet->PacketId != 0);
CXPLAT_DBG_ASSERT(Packet->ReleaseDeferred == IsDeferred);
Packet->ReleaseDeferred = FALSE;

4
src/core/library.h
Просмотреть файл

@ -66,6 +66,10 @@ typedef struct QUIC_CACHEALIGN QUIC_LIBRARY_PP {
CXPLAT_HASH* ResetTokenHash;
CXPLAT_LOCK ResetTokenLock;
uint64_t SendBatchId;
uint64_t SendPacketId;
uint64_t ReceivePacketId;
//
// Per-processor performance counters.
//

26
src/core/packet_builder.c
Просмотреть файл

@ -208,6 +208,9 @@ QuicPacketBuilderPrepare(
// the current one doesn't match, finalize it and then start a new one.
//
uint32_t Proc = CxPlatProcCurrentNumber();
uint64_t ProcShifted = ((uint64_t)Proc) << 40;
BOOLEAN NewQuicPacket = FALSE;
if (Builder->PacketType != NewPacketType || IsPathMtuDiscovery ||
(Builder->Datagram != NULL && (Builder->Datagram->Length - Builder->DatagramLength) < QUIC_MIN_PACKET_SPARE_SPACE)) {
@ -240,6 +243,8 @@ QuicPacketBuilderPrepare(
//
BOOLEAN SendDataAllocated = FALSE;
if (Builder->SendData == NULL) {
Builder->BatchId =
ProcShifted | InterlockedIncrement64((int64_t*)&MsQuicLib.PerProc[Proc].SendBatchId);
Builder->SendData =
CxPlatSendDataAlloc(
Builder->Path->Binding->Socket,
@ -347,6 +352,14 @@ QuicPacketBuilderPrepare(
Builder->EncryptionOverhead = 0;
}
Builder->Metadata->PacketId =
ProcShifted | InterlockedIncrement64((int64_t*)&MsQuicLib.PerProc[Proc].SendPacketId);
QuicTraceEvent(
PacketCreated,
"[pack][%llu] Created in batch %llu",
Builder->Metadata->PacketId,
Builder->BatchId);
Builder->Metadata->FrameCount = 0;
Builder->Metadata->PacketNumber = Connection->Send.NextPacketNumber++;
Builder->Metadata->Flags.KeyType = NewPacketKeyType;
@ -760,6 +773,11 @@ QuicPacketBuilderFinalize(
// Encrypt the data.
//
QuicTraceEvent(
PacketEncrypt,
"[pack][%llu] Encrypting",
Builder->Metadata->PacketId);
PayloadLength += Builder->EncryptionOverhead;
Builder->DatagramLength += Builder->EncryptionOverhead;
@ -878,6 +896,10 @@ QuicPacketBuilderFinalize(
Builder->Metadata->SentTime = CxPlatTimeUs32();
Builder->Metadata->PacketLength =
Builder->HeaderLength + PayloadLength;
QuicTraceEvent(
PacketFinalize,
"[pack][%llu] Finalizing",
Builder->Metadata->PacketId);
QuicTraceEvent(
ConnPacketSent,
@ -928,6 +950,10 @@ Exit:
CXPLAT_DBG_ASSERT(Builder->TotalCountDatagrams > 0);
QuicPacketBuilderSendBatch(Builder);
CXPLAT_DBG_ASSERT(Builder->Metadata->FrameCount == 0);
QuicTraceEvent(
PacketBatchSent,
"[pack][%llu] Batch sent",
Builder->BatchId);
}
if (Builder->PacketType == QUIC_RETRY) {

2
src/core/packet_builder.h
Просмотреть файл

@ -136,6 +136,8 @@ typedef struct QUIC_PACKET_BUILDER {
//
uint32_t SendAllowance;
uint64_t BatchId;
//
// Represents the metadata of the current QUIC packet.
//

1
src/core/sent_packet_metadata.h
Просмотреть файл

@ -101,6 +101,7 @@ typedef struct QUIC_SENT_PACKET_METADATA {
struct QUIC_SENT_PACKET_METADATA *Next;
uint64_t PacketId;
uint64_t PacketNumber;
uint32_t SentTime; // In microseconds
uint16_t PacketLength;

6
src/core/stream.c
Просмотреть файл

@ -37,6 +37,12 @@ QuicStreamInitialize(
Status = QUIC_STATUS_OUT_OF_MEMORY;
goto Exit;
}
QuicTraceEvent(
StreamAlloc,
"[strm][%p] Allocated, Conn=%p",
Stream,
Connection);
CxPlatZeroMemory(Stream, sizeof(QUIC_STREAM));
#if DEBUG

2
src/core/stream.h
Просмотреть файл

@ -860,7 +860,7 @@ _IRQL_requires_max_(PASSIVE_LEVEL)
QUIC_STATUS
QuicStreamRecv(
_In_ QUIC_STREAM* Stream,
_In_ BOOLEAN EncryptedWith0Rtt,
_In_ CXPLAT_RECV_PACKET* Packet,
_In_ QUIC_FRAME_TYPE FrameType,
_In_ uint16_t BufferLength,
_In_reads_bytes_(BufferLength)

23
src/core/stream_recv.c
Просмотреть файл

@ -498,7 +498,7 @@ _IRQL_requires_max_(PASSIVE_LEVEL)
QUIC_STATUS
QuicStreamRecv(
_In_ QUIC_STREAM* Stream,
_In_ BOOLEAN EncryptedWith0Rtt,
_In_ CXPLAT_RECV_PACKET* Packet,
_In_ QUIC_FRAME_TYPE FrameType,
_In_ uint16_t BufferLength,
_In_reads_bytes_(BufferLength)
@ -509,6 +509,12 @@ QuicStreamRecv(
{
QUIC_STATUS Status = QUIC_STATUS_SUCCESS;
QuicTraceEvent(
StreamReceiveFrame,
"[strm][%p] Processing frame in packet %llu",
Stream,
Packet->PacketId);
switch (FrameType) {
case QUIC_FRAME_RESET_STREAM: {
@ -613,7 +619,7 @@ QuicStreamRecv(
Status =
QuicStreamProcessStreamFrame(
Stream, EncryptedWith0Rtt, &Frame);
Stream, Packet->EncryptedWith0Rtt, &Frame);
break;
}
@ -805,10 +811,10 @@ QuicStreamRecvFlush(
Stream->Flags.ReceiveCallPending = TRUE;
Stream->RecvPendingLength = Event.RECEIVE.TotalBufferLength;
QuicTraceLogStreamVerbose(
IndicateReceive,
QuicTraceEvent(
StreamAppReceive,
"[strm][%p] Indicating QUIC_STREAM_EVENT_RECEIVE [%llu bytes, %u buffers, 0x%x flags]",
Stream,
"Indicating QUIC_STREAM_EVENT_RECEIVE [%llu bytes, %u buffers, 0x%x flags]",
Event.RECEIVE.TotalBufferLength,
Event.RECEIVE.BufferCount,
Event.RECEIVE.Flags);
@ -899,10 +905,11 @@ QuicStreamReceiveComplete(
"App overflowed read buffer!");
Stream->Flags.ReceiveCallPending = FALSE;
QuicTraceLogStreamVerbose(
ReceiveComplete,
QuicTraceEvent(
StreamAppReceiveComplete,
"[strm][%p] Receive complete [%llu bytes]",
Stream,
"Recv complete (%llu bytes)",
BufferLength);
//

6
src/core/stream_send.c
Просмотреть файл

@ -1027,6 +1027,12 @@ QuicStreamSendWrite(
Builder->Metadata->Flags.KeyType == QUIC_PACKET_KEY_0_RTT);
CXPLAT_DBG_ASSERT(QuicStreamAllowedByPeer(Stream));
QuicTraceEvent(
StreamWriteFrames,
"[strm][%p] Writing frames to packet %llu",
Stream,
Builder->Metadata->PacketId);
if (Stream->SendFlags & QUIC_STREAM_SEND_FLAG_MAX_DATA) {
QUIC_MAX_STREAM_DATA_EX Frame = { Stream->ID, Stream->MaxAllowedRecvOffset };

27
src/generated/linux/api.c.clog.h
Просмотреть файл

@ -713,6 +713,33 @@ tracepoint(CLOG_API_C, StreamError , arg2, arg3);\
#ifndef _clog_6_ARGS_TRACE_StreamAppSend
/*----------------------------------------------------------
// Decoder Ring for StreamAppSend
// [strm][%p] App queuing send [%llu bytes, %u buffers, 0x%x flags]
// QuicTraceEvent(
StreamAppSend,
"[strm][%p] App queuing send [%llu bytes, %u buffers, 0x%x flags]",
Stream,
TotalLength,
BufferCount,
Flags);
// arg2 = arg2 = Stream
// arg3 = arg3 = TotalLength
// arg4 = arg4 = BufferCount
// arg5 = arg5 = Flags
----------------------------------------------------------*/
#define _clog_6_ARGS_TRACE_StreamAppSend(uniqueId, encoded_arg_string, arg2, arg3, arg4, arg5)\
tracepoint(CLOG_API_C, StreamAppSend , arg2, arg3, arg4, arg5);\
#endif
#ifndef _clog_4_ARGS_TRACE_AllocFailure

31
src/generated/linux/api.c.clog.h.lttng.h
Просмотреть файл

@ -121,6 +121,37 @@ TRACEPOINT_EVENT(CLOG_API_C, StreamError,
/*----------------------------------------------------------
// Decoder Ring for StreamAppSend
// [strm][%p] App queuing send [%llu bytes, %u buffers, 0x%x flags]
// QuicTraceEvent(
StreamAppSend,
"[strm][%p] App queuing send [%llu bytes, %u buffers, 0x%x flags]",
Stream,
TotalLength,
BufferCount,
Flags);
// arg2 = arg2 = Stream
// arg3 = arg3 = TotalLength
// arg4 = arg4 = BufferCount
// arg5 = arg5 = Flags
----------------------------------------------------------*/
TRACEPOINT_EVENT(CLOG_API_C, StreamAppSend,
TP_ARGS(
const void *, arg2,
unsigned long long, arg3,
unsigned int, arg4,
unsigned int, arg5),
TP_FIELDS(
ctf_integer_hex(uint64_t, arg2, arg2)
ctf_integer(uint64_t, arg3, arg3)
ctf_integer(unsigned int, arg4, arg4)
ctf_integer(unsigned int, arg5, arg5)
)
)
/*----------------------------------------------------------
// Decoder Ring for LibraryError
// [ lib] ERROR, %s.

21
src/generated/linux/binding.c.clog.h
Просмотреть файл

@ -582,6 +582,27 @@ tracepoint(CLOG_BINDING_C, BindingExecOper , arg2, arg3);\
#ifndef _clog_3_ARGS_TRACE_PacketReceive
/*----------------------------------------------------------
// Decoder Ring for PacketReceive
// [pack][%llu] Received
// QuicTraceEvent(
PacketReceive,
"[pack][%llu] Received",
Packet->PacketId);
// arg2 = arg2 = Packet->PacketId
----------------------------------------------------------*/
#define _clog_3_ARGS_TRACE_PacketReceive(uniqueId, encoded_arg_string, arg2)\
tracepoint(CLOG_BINDING_C, PacketReceive , arg2);\
#endif
#ifdef __cplusplus
}
#endif

19
src/generated/linux/binding.c.clog.h.lttng.h
Просмотреть файл

@ -392,3 +392,22 @@ TRACEPOINT_EVENT(CLOG_BINDING_C, BindingExecOper,
ctf_integer(unsigned int, arg3, arg3)
)
)
/*----------------------------------------------------------
// Decoder Ring for PacketReceive
// [pack][%llu] Received
// QuicTraceEvent(
PacketReceive,
"[pack][%llu] Received",
Packet->PacketId);
// arg2 = arg2 = Packet->PacketId
----------------------------------------------------------*/
TRACEPOINT_EVENT(CLOG_BINDING_C, PacketReceive,
TP_ARGS(
unsigned long long, arg2),
TP_FIELDS(
ctf_integer(uint64_t, arg2, arg2)
)
)

21
src/generated/linux/connection.c.clog.h
Просмотреть файл

@ -3116,6 +3116,27 @@ tracepoint(CLOG_CONNECTION_C, ConnHandshakeStart , arg2);\
#ifndef _clog_3_ARGS_TRACE_PacketDecrypt
/*----------------------------------------------------------
// Decoder Ring for PacketDecrypt
// [pack][%llu] Decrypting
// QuicTraceEvent(
PacketDecrypt,
"[pack][%llu] Decrypting",
Packet->PacketId);
// arg2 = arg2 = Packet->PacketId
----------------------------------------------------------*/
#define _clog_3_ARGS_TRACE_PacketDecrypt(uniqueId, encoded_arg_string, arg2)\
tracepoint(CLOG_CONNECTION_C, PacketDecrypt , arg2);\
#endif
#ifndef _clog_6_ARGS_TRACE_ConnPacketRecv

19
src/generated/linux/connection.c.clog.h.lttng.h
Просмотреть файл

@ -2194,6 +2194,25 @@ TRACEPOINT_EVENT(CLOG_CONNECTION_C, ConnHandshakeStart,
/*----------------------------------------------------------
// Decoder Ring for PacketDecrypt
// [pack][%llu] Decrypting
// QuicTraceEvent(
PacketDecrypt,
"[pack][%llu] Decrypting",
Packet->PacketId);
// arg2 = arg2 = Packet->PacketId
----------------------------------------------------------*/
TRACEPOINT_EVENT(CLOG_CONNECTION_C, PacketDecrypt,
TP_ARGS(
unsigned long long, arg2),
TP_FIELDS(
ctf_integer(uint64_t, arg2, arg2)
)
)
/*----------------------------------------------------------
// Decoder Ring for ConnPacketRecv
// [conn][%p][RX][%llu] %c (%hu bytes)

86
src/generated/linux/packet_builder.c.clog.h
Просмотреть файл

@ -162,6 +162,50 @@ tracepoint(CLOG_PACKET_BUILDER_C, AllocFailure , arg2, arg3);\
#ifndef _clog_4_ARGS_TRACE_PacketCreated
/*----------------------------------------------------------
// Decoder Ring for PacketCreated
// [pack][%llu] Created in batch %llu
// QuicTraceEvent(
PacketCreated,
"[pack][%llu] Created in batch %llu",
Builder->Metadata->PacketId,
Builder->BatchId);
// arg2 = arg2 = Builder->Metadata->PacketId
// arg3 = arg3 = Builder->BatchId
----------------------------------------------------------*/
#define _clog_4_ARGS_TRACE_PacketCreated(uniqueId, encoded_arg_string, arg2, arg3)\
tracepoint(CLOG_PACKET_BUILDER_C, PacketCreated , arg2, arg3);\
#endif
#ifndef _clog_3_ARGS_TRACE_PacketEncrypt
/*----------------------------------------------------------
// Decoder Ring for PacketEncrypt
// [pack][%llu] Encrypting
// QuicTraceEvent(
PacketEncrypt,
"[pack][%llu] Encrypting",
Builder->Metadata->PacketId);
// arg2 = arg2 = Builder->Metadata->PacketId
----------------------------------------------------------*/
#define _clog_3_ARGS_TRACE_PacketEncrypt(uniqueId, encoded_arg_string, arg2)\
tracepoint(CLOG_PACKET_BUILDER_C, PacketEncrypt , arg2);\
#endif
#ifndef _clog_5_ARGS_TRACE_ConnErrorStatus
@ -187,6 +231,27 @@ tracepoint(CLOG_PACKET_BUILDER_C, ConnErrorStatus , arg2, arg3, arg4);\
#ifndef _clog_3_ARGS_TRACE_PacketFinalize
/*----------------------------------------------------------
// Decoder Ring for PacketFinalize
// [pack][%llu] Finalizing
// QuicTraceEvent(
PacketFinalize,
"[pack][%llu] Finalizing",
Builder->Metadata->PacketId);
// arg2 = arg2 = Builder->Metadata->PacketId
----------------------------------------------------------*/
#define _clog_3_ARGS_TRACE_PacketFinalize(uniqueId, encoded_arg_string, arg2)\
tracepoint(CLOG_PACKET_BUILDER_C, PacketFinalize , arg2);\
#endif
#ifndef _clog_6_ARGS_TRACE_ConnPacketSent
@ -214,6 +279,27 @@ tracepoint(CLOG_PACKET_BUILDER_C, ConnPacketSent , arg2, arg3, arg4, arg5);\
#ifndef _clog_3_ARGS_TRACE_PacketBatchSent
/*----------------------------------------------------------
// Decoder Ring for PacketBatchSent
// [pack][%llu] Batch sent
// QuicTraceEvent(
PacketBatchSent,
"[pack][%llu] Batch sent",
Builder->BatchId);
// arg2 = arg2 = Builder->BatchId
----------------------------------------------------------*/
#define _clog_3_ARGS_TRACE_PacketBatchSent(uniqueId, encoded_arg_string, arg2)\
tracepoint(CLOG_PACKET_BUILDER_C, PacketBatchSent , arg2);\
#endif
#ifdef __cplusplus
}
#endif

80
src/generated/linux/packet_builder.c.clog.h.lttng.h
Просмотреть файл

@ -112,6 +112,48 @@ TRACEPOINT_EVENT(CLOG_PACKET_BUILDER_C, AllocFailure,
/*----------------------------------------------------------
// Decoder Ring for PacketCreated
// [pack][%llu] Created in batch %llu
// QuicTraceEvent(
PacketCreated,
"[pack][%llu] Created in batch %llu",
Builder->Metadata->PacketId,
Builder->BatchId);
// arg2 = arg2 = Builder->Metadata->PacketId
// arg3 = arg3 = Builder->BatchId
----------------------------------------------------------*/
TRACEPOINT_EVENT(CLOG_PACKET_BUILDER_C, PacketCreated,
TP_ARGS(
unsigned long long, arg2,
unsigned long long, arg3),
TP_FIELDS(
ctf_integer(uint64_t, arg2, arg2)
ctf_integer(uint64_t, arg3, arg3)
)
)
/*----------------------------------------------------------
// Decoder Ring for PacketEncrypt
// [pack][%llu] Encrypting
// QuicTraceEvent(
PacketEncrypt,
"[pack][%llu] Encrypting",
Builder->Metadata->PacketId);
// arg2 = arg2 = Builder->Metadata->PacketId
----------------------------------------------------------*/
TRACEPOINT_EVENT(CLOG_PACKET_BUILDER_C, PacketEncrypt,
TP_ARGS(
unsigned long long, arg2),
TP_FIELDS(
ctf_integer(uint64_t, arg2, arg2)
)
)
/*----------------------------------------------------------
// Decoder Ring for ConnErrorStatus
// [conn][%p] ERROR, %u, %s.
@ -139,6 +181,25 @@ TRACEPOINT_EVENT(CLOG_PACKET_BUILDER_C, ConnErrorStatus,
/*----------------------------------------------------------
// Decoder Ring for PacketFinalize
// [pack][%llu] Finalizing
// QuicTraceEvent(
PacketFinalize,
"[pack][%llu] Finalizing",
Builder->Metadata->PacketId);
// arg2 = arg2 = Builder->Metadata->PacketId
----------------------------------------------------------*/
TRACEPOINT_EVENT(CLOG_PACKET_BUILDER_C, PacketFinalize,
TP_ARGS(
unsigned long long, arg2),
TP_FIELDS(
ctf_integer(uint64_t, arg2, arg2)
)
)
/*----------------------------------------------------------
// Decoder Ring for ConnPacketSent
// [conn][%p][TX][%llu] %hhu (%hu bytes)
@ -167,3 +228,22 @@ TRACEPOINT_EVENT(CLOG_PACKET_BUILDER_C, ConnPacketSent,
ctf_integer(unsigned short, arg5, arg5)
)
)
/*----------------------------------------------------------
// Decoder Ring for PacketBatchSent
// [pack][%llu] Batch sent
// QuicTraceEvent(
PacketBatchSent,
"[pack][%llu] Batch sent",
Builder->BatchId);
// arg2 = arg2 = Builder->BatchId
----------------------------------------------------------*/
TRACEPOINT_EVENT(CLOG_PACKET_BUILDER_C, PacketBatchSent,
TP_ARGS(
unsigned long long, arg2),
TP_FIELDS(
ctf_integer(uint64_t, arg2, arg2)
)
)

23
src/generated/linux/stream.c.clog.h
Просмотреть файл

@ -146,6 +146,29 @@ tracepoint(CLOG_STREAM_C, IndicateStreamShutdownComplete , arg1, arg3);\
#ifndef _clog_4_ARGS_TRACE_StreamAlloc
/*----------------------------------------------------------
// Decoder Ring for StreamAlloc
// [strm][%p] Allocated, Conn=%p
// QuicTraceEvent(
StreamAlloc,
"[strm][%p] Allocated, Conn=%p",
Stream,
Connection);
// arg2 = arg2 = Stream
// arg3 = arg3 = Connection
----------------------------------------------------------*/
#define _clog_4_ARGS_TRACE_StreamAlloc(uniqueId, encoded_arg_string, arg2, arg3)\
tracepoint(CLOG_STREAM_C, StreamAlloc , arg2, arg3);\
#endif
#ifndef _clog_3_ARGS_TRACE_StreamDestroyed

23
src/generated/linux/stream.c.clog.h.lttng.h
Просмотреть файл

@ -116,6 +116,29 @@ TRACEPOINT_EVENT(CLOG_STREAM_C, IndicateStreamShutdownComplete,
/*----------------------------------------------------------
// Decoder Ring for StreamAlloc
// [strm][%p] Allocated, Conn=%p
// QuicTraceEvent(
StreamAlloc,
"[strm][%p] Allocated, Conn=%p",
Stream,
Connection);
// arg2 = arg2 = Stream
// arg3 = arg3 = Connection
----------------------------------------------------------*/
TRACEPOINT_EVENT(CLOG_STREAM_C, StreamAlloc,
TP_ARGS(
const void *, arg2,
const void *, arg3),
TP_FIELDS(
ctf_integer_hex(uint64_t, arg2, arg2)
ctf_integer_hex(uint64_t, arg3, arg3)
)
)
/*----------------------------------------------------------
// Decoder Ring for StreamDestroyed
// [strm][%p] Destroyed

123
src/generated/linux/stream_recv.c.clog.h
Просмотреть файл

@ -429,56 +429,6 @@ tracepoint(CLOG_STREAM_RECV_C, IgnoreRecvFlush , arg1);\
#ifndef _clog_6_ARGS_TRACE_IndicateReceive
/*----------------------------------------------------------
// Decoder Ring for IndicateReceive
// [strm][%p] Indicating QUIC_STREAM_EVENT_RECEIVE [%llu bytes, %u buffers, 0x%x flags]
// QuicTraceLogStreamVerbose(
IndicateReceive,
Stream,
"Indicating QUIC_STREAM_EVENT_RECEIVE [%llu bytes, %u buffers, 0x%x flags]",
Event.RECEIVE.TotalBufferLength,
Event.RECEIVE.BufferCount,
Event.RECEIVE.Flags);
// arg1 = arg1 = Stream
// arg3 = arg3 = Event.RECEIVE.TotalBufferLength
// arg4 = arg4 = Event.RECEIVE.BufferCount
// arg5 = arg5 = Event.RECEIVE.Flags
----------------------------------------------------------*/
#define _clog_6_ARGS_TRACE_IndicateReceive(uniqueId, arg1, encoded_arg_string, arg3, arg4, arg5)\
tracepoint(CLOG_STREAM_RECV_C, IndicateReceive , arg1, arg3, arg4, arg5);\
#endif
#ifndef _clog_4_ARGS_TRACE_ReceiveComplete
/*----------------------------------------------------------
// Decoder Ring for ReceiveComplete
// [strm][%p] Recv complete (%llu bytes)
// QuicTraceLogStreamVerbose(
ReceiveComplete,
Stream,
"Recv complete (%llu bytes)",
BufferLength);
// arg1 = arg1 = Stream
// arg3 = arg3 = BufferLength
----------------------------------------------------------*/
#define _clog_4_ARGS_TRACE_ReceiveComplete(uniqueId, arg1, encoded_arg_string, arg3)\
tracepoint(CLOG_STREAM_RECV_C, ReceiveComplete , arg1, arg3);\
#endif
#ifndef _clog_3_ARGS_TRACE_IndicatePeerSendShutdown
@ -591,6 +541,79 @@ tracepoint(CLOG_STREAM_RECV_C, StreamError , arg2, arg3);\
#ifndef _clog_4_ARGS_TRACE_StreamReceiveFrame
/*----------------------------------------------------------
// Decoder Ring for StreamReceiveFrame
// [strm][%p] Processing frame in packet %llu
// QuicTraceEvent(
StreamReceiveFrame,
"[strm][%p] Processing frame in packet %llu",
Stream,
Packet->PacketId);
// arg2 = arg2 = Stream
// arg3 = arg3 = Packet->PacketId
----------------------------------------------------------*/
#define _clog_4_ARGS_TRACE_StreamReceiveFrame(uniqueId, encoded_arg_string, arg2, arg3)\
tracepoint(CLOG_STREAM_RECV_C, StreamReceiveFrame , arg2, arg3);\
#endif
#ifndef _clog_6_ARGS_TRACE_StreamAppReceive
/*----------------------------------------------------------
// Decoder Ring for StreamAppReceive
// [strm][%p] Indicating QUIC_STREAM_EVENT_RECEIVE [%llu bytes, %u buffers, 0x%x flags]
// QuicTraceEvent(
StreamAppReceive,
"[strm][%p] Indicating QUIC_STREAM_EVENT_RECEIVE [%llu bytes, %u buffers, 0x%x flags]",
Stream,
Event.RECEIVE.TotalBufferLength,
Event.RECEIVE.BufferCount,
Event.RECEIVE.Flags);
// arg2 = arg2 = Stream
// arg3 = arg3 = Event.RECEIVE.TotalBufferLength
// arg4 = arg4 = Event.RECEIVE.BufferCount
// arg5 = arg5 = Event.RECEIVE.Flags
----------------------------------------------------------*/
#define _clog_6_ARGS_TRACE_StreamAppReceive(uniqueId, encoded_arg_string, arg2, arg3, arg4, arg5)\
tracepoint(CLOG_STREAM_RECV_C, StreamAppReceive , arg2, arg3, arg4, arg5);\
#endif
#ifndef _clog_4_ARGS_TRACE_StreamAppReceiveComplete
/*----------------------------------------------------------
// Decoder Ring for StreamAppReceiveComplete
// [strm][%p] Receive complete [%llu bytes]
// QuicTraceEvent(
StreamAppReceiveComplete,
"[strm][%p] Receive complete [%llu bytes]",
Stream,
BufferLength);
// arg2 = arg2 = Stream
// arg3 = arg3 = BufferLength
----------------------------------------------------------*/
#define _clog_4_ARGS_TRACE_StreamAppReceiveComplete(uniqueId, encoded_arg_string, arg2, arg3)\
tracepoint(CLOG_STREAM_RECV_C, StreamAppReceiveComplete , arg2, arg3);\
#endif
#ifndef _clog_4_ARGS_TRACE_StreamRecvState

131
src/generated/linux/stream_recv.c.clog.h.lttng.h
Просмотреть файл

@ -383,60 +383,6 @@ TRACEPOINT_EVENT(CLOG_STREAM_RECV_C, IgnoreRecvFlush,
/*----------------------------------------------------------
// Decoder Ring for IndicateReceive
// [strm][%p] Indicating QUIC_STREAM_EVENT_RECEIVE [%llu bytes, %u buffers, 0x%x flags]
// QuicTraceLogStreamVerbose(
IndicateReceive,
Stream,
"Indicating QUIC_STREAM_EVENT_RECEIVE [%llu bytes, %u buffers, 0x%x flags]",
Event.RECEIVE.TotalBufferLength,
Event.RECEIVE.BufferCount,
Event.RECEIVE.Flags);
// arg1 = arg1 = Stream
// arg3 = arg3 = Event.RECEIVE.TotalBufferLength
// arg4 = arg4 = Event.RECEIVE.BufferCount
// arg5 = arg5 = Event.RECEIVE.Flags
----------------------------------------------------------*/
TRACEPOINT_EVENT(CLOG_STREAM_RECV_C, IndicateReceive,
TP_ARGS(
const void *, arg1,
unsigned long long, arg3,
unsigned int, arg4,
unsigned int, arg5),
TP_FIELDS(
ctf_integer_hex(uint64_t, arg1, arg1)
ctf_integer(uint64_t, arg3, arg3)
ctf_integer(unsigned int, arg4, arg4)
ctf_integer(unsigned int, arg5, arg5)
)
)
/*----------------------------------------------------------
// Decoder Ring for ReceiveComplete
// [strm][%p] Recv complete (%llu bytes)
// QuicTraceLogStreamVerbose(
ReceiveComplete,
Stream,
"Recv complete (%llu bytes)",
BufferLength);
// arg1 = arg1 = Stream
// arg3 = arg3 = BufferLength
----------------------------------------------------------*/
TRACEPOINT_EVENT(CLOG_STREAM_RECV_C, ReceiveComplete,
TP_ARGS(
const void *, arg1,
unsigned long long, arg3),
TP_FIELDS(
ctf_integer_hex(uint64_t, arg1, arg1)
ctf_integer(uint64_t, arg3, arg3)
)
)
/*----------------------------------------------------------
// Decoder Ring for IndicatePeerSendShutdown
// [strm][%p] Indicating QUIC_STREAM_EVENT_PEER_SEND_SHUTDOWN
@ -522,3 +468,80 @@ TRACEPOINT_EVENT(CLOG_STREAM_RECV_C, StreamError,
ctf_string(arg3, arg3)
)
)
/*----------------------------------------------------------
// Decoder Ring for StreamReceiveFrame
// [strm][%p] Processing frame in packet %llu
// QuicTraceEvent(
StreamReceiveFrame,
"[strm][%p] Processing frame in packet %llu",
Stream,
Packet->PacketId);
// arg2 = arg2 = Stream
// arg3 = arg3 = Packet->PacketId
----------------------------------------------------------*/
TRACEPOINT_EVENT(CLOG_STREAM_RECV_C, StreamReceiveFrame,
TP_ARGS(
const void *, arg2,
unsigned long long, arg3),
TP_FIELDS(
ctf_integer_hex(uint64_t, arg2, arg2)
ctf_integer(uint64_t, arg3, arg3)
)
)
/*----------------------------------------------------------
// Decoder Ring for StreamAppReceive
// [strm][%p] Indicating QUIC_STREAM_EVENT_RECEIVE [%llu bytes, %u buffers, 0x%x flags]
// QuicTraceEvent(
StreamAppReceive,
"[strm][%p] Indicating QUIC_STREAM_EVENT_RECEIVE [%llu bytes, %u buffers, 0x%x flags]",
Stream,
Event.RECEIVE.TotalBufferLength,
Event.RECEIVE.BufferCount,
Event.RECEIVE.Flags);
// arg2 = arg2 = Stream
// arg3 = arg3 = Event.RECEIVE.TotalBufferLength
// arg4 = arg4 = Event.RECEIVE.BufferCount
// arg5 = arg5 = Event.RECEIVE.Flags
----------------------------------------------------------*/
TRACEPOINT_EVENT(CLOG_STREAM_RECV_C, StreamAppReceive,
TP_ARGS(
const void *, arg2,
unsigned long long, arg3,
unsigned int, arg4,
unsigned int, arg5),
TP_FIELDS(
ctf_integer_hex(uint64_t, arg2, arg2)
ctf_integer(uint64_t, arg3, arg3)
ctf_integer(unsigned int, arg4, arg4)
ctf_integer(unsigned int, arg5, arg5)
)
)
/*----------------------------------------------------------
// Decoder Ring for StreamAppReceiveComplete
// [strm][%p] Receive complete [%llu bytes]
// QuicTraceEvent(
StreamAppReceiveComplete,
"[strm][%p] Receive complete [%llu bytes]",
Stream,
BufferLength);
// arg2 = arg2 = Stream
// arg3 = arg3 = BufferLength
----------------------------------------------------------*/
TRACEPOINT_EVENT(CLOG_STREAM_RECV_C, StreamAppReceiveComplete,
TP_ARGS(
const void *, arg2,
unsigned long long, arg3),
TP_FIELDS(
ctf_integer_hex(uint64_t, arg2, arg2)
ctf_integer(uint64_t, arg3, arg3)
)
)

23
src/generated/linux/stream_send.c.clog.h
Просмотреть файл

@ -457,6 +457,29 @@ tracepoint(CLOG_STREAM_SEND_C, StreamSendState , arg2, arg3);\
#ifndef _clog_4_ARGS_TRACE_StreamWriteFrames
/*----------------------------------------------------------
// Decoder Ring for StreamWriteFrames
// [strm][%p] Writing frames to packet %llu
// QuicTraceEvent(
StreamWriteFrames,
"[strm][%p] Writing frames to packet %llu",
Stream,
Builder->Metadata->PacketId);
// arg2 = arg2 = Stream
// arg3 = arg3 = Builder->Metadata->PacketId
----------------------------------------------------------*/
#define _clog_4_ARGS_TRACE_StreamWriteFrames(uniqueId, encoded_arg_string, arg2, arg3)\
tracepoint(CLOG_STREAM_SEND_C, StreamWriteFrames , arg2, arg3);\
#endif
#ifndef _clog_4_ARGS_TRACE_StreamSendState

23
src/generated/linux/stream_send.c.clog.h.lttng.h
Просмотреть файл

@ -406,3 +406,26 @@ TRACEPOINT_EVENT(CLOG_STREAM_SEND_C, StreamSendState,
ctf_integer(unsigned char, arg3, arg3)
)
)
/*----------------------------------------------------------
// Decoder Ring for StreamWriteFrames
// [strm][%p] Writing frames to packet %llu
// QuicTraceEvent(
StreamWriteFrames,
"[strm][%p] Writing frames to packet %llu",
Stream,
Builder->Metadata->PacketId);
// arg2 = arg2 = Stream
// arg3 = arg3 = Builder->Metadata->PacketId
----------------------------------------------------------*/
TRACEPOINT_EVENT(CLOG_STREAM_SEND_C, StreamWriteFrames,
TP_ARGS(
const void *, arg2,
unsigned long long, arg3),
TP_FIELDS(
ctf_integer_hex(uint64_t, arg2, arg2)
ctf_integer(uint64_t, arg3, arg3)
)
)

16
src/manifest/MsQuic.wprp
Просмотреть файл

@ -52,6 +52,11 @@
<Keyword Value="0xE0000800"/>
</Keywords>
</EventProvider>
<EventProvider Id="EP_MsQuicEtw_RPS" Name="ff15e657-4f26-570e-88ab-0796b258d11c" NonPagedMemory="true">
<Keywords>
<Keyword Value="0x00002000"/>
</Keywords>
</EventProvider>
<EventProvider Id="EP_TcpIpEtw" Name="Microsoft-Windows-TCPIP" NonPagedMemory="true" />
<EventProvider Id="EP_WinSockEtw" Name="Microsoft-Windows-Winsock-AFD" NonPagedMemory="true" />
@ -85,6 +90,17 @@
</Profile>
<Profile Id="Stacks.Light.Memory" Base="Stacks.Light.File" Name="Stacks" Description="CPU Stacks" LoggingMode="Memory" DetailLevel="Light"/>
<Profile Id="RPS.Light.File" Name="RPS" Description="RPS related MsQuic ETW Events" LoggingMode="File" DetailLevel="Light">
<Collectors>
<EventCollectorId Value="EC_HighVolume">
<EventProviders>
<EventProviderId Value="EP_MsQuicEtw_RPS" />
</EventProviders>
</EventCollectorId>
</Collectors>
</Profile>
<Profile Id="RPS.Light.Memory" Base="RPS.Light.File" Name="RPS" Description="RPS related MsQuic ETW Events" LoggingMode="Memory" DetailLevel="Light"/>
<Profile Id="Performance.Light.File" Name="Performance" Description="Perf related MsQuic ETW Events" LoggingMode="File" DetailLevel="Light">
<Collectors>
<EventCollectorId Value="EC_HighVolume">

225
src/manifest/MsQuicEtw.man
Просмотреть файл

@ -106,6 +106,10 @@
mask="0x0000000000001000"
name="ut:Log"
/>
<keyword
mask="0x0000000000002000"
name="ut:RPS"
/>
<!-- High bits are operation category. -->
<keyword
mask="0x0000000080000000"
@ -1433,6 +1437,44 @@
name="Message"
/>
</template>
<template tid="tid_STREAM_CONN">
<data
inType="win:Pointer"
name="Stream"
/>
<data
inType="win:Pointer"
name="Connection"
/>
</template>
<template tid="tid_STREAM_U64">
<data
inType="win:Pointer"
name="Stream"
/>
<data
inType="win:UInt64"
name="ID"
/>
</template>
<template tid="tid_STREAM_RECV">
<data
inType="win:Pointer"
name="Stream"
/>
<data
inType="win:UInt64"
name="BufLength"
/>
<data
inType="win:UInt32"
name="BufCount"
/>
<data
inType="win:UInt32"
name="Flags"
/>
</template>
<template tid="tid_BINDING">
<data
inType="win:Pointer"
@ -1779,6 +1821,22 @@
outType="win:SocketAddress"
/>
</template>
<template tid="tid_ID">
<data
inType="win:UInt64"
name="ID"
/>
</template>
<template tid="tid_ID_ID">
<data
inType="win:UInt64"
name="ID"
/>
<data
inType="win:UInt64"
name="ID2"
/>
</template>
</templates>
<events>
<!-- Don't use value=0 as some parsers don't like it -->
@ -2225,7 +2283,7 @@
value="5122"
/>
<event
keywords="ut:Connection ut:Scheduling"
keywords="ut:Connection ut:Scheduling ut:RPS"
level="win:Informational"
message="$(string.Etw.ConnScheduleState)"
opcode="Connection"
@ -2450,7 +2508,7 @@
value="5147"
/>
<event
keywords="ut:Connection ut:LowVolume"
keywords="ut:Connection ut:LowVolume ut:RPS"
level="win:Verbose"
message="$(string.Etw.ConnSourceCidAdd)"
opcode="Connection"
@ -2459,7 +2517,7 @@
value="5148"
/>
<event
keywords="ut:Connection ut:LowVolume"
keywords="ut:Connection ut:LowVolume ut:RPS"
level="win:Verbose"
message="$(string.Etw.ConnDestCidAdd)"
opcode="Connection"
@ -2793,7 +2851,7 @@
/>
<!-- 6144 - 7167 | Stream Events -->
<event
keywords="ut:Stream ut:LowVolume"
keywords="ut:Stream ut:LowVolume ut:RPS"
level="win:Informational"
message="$(string.Etw.StreamCreated)"
opcode="Stream"
@ -2802,7 +2860,7 @@
value="6144"
/>
<event
keywords="ut:Stream ut:LowVolume"
keywords="ut:Stream ut:LowVolume ut:RPS"
level="win:Informational"
message="$(string.Etw.StreamDestroyed)"
opcode="Stream"
@ -2900,6 +2958,60 @@
template="tid_STREAM_MESSAGE"
value="6155"
/>
<event
keywords="ut:Stream ut:RPS"
level="win:Verbose"
message="$(string.Etw.StreamAlloc)"
opcode="Stream"
symbol="QuicStreamAlloc"
template="tid_STREAM_CONN"
value="6156"
/>
<event
keywords="ut:Stream ut:RPS"
level="win:Verbose"
message="$(string.Etw.StreamWriteFrames)"
opcode="Stream"
symbol="QuicStreamWriteFrames"
template="tid_STREAM_U64"
value="6157"
/>
<event
keywords="ut:Stream ut:RPS"
level="win:Verbose"
message="$(string.Etw.StreamReceiveFrame)"
opcode="Stream"
symbol="QuicStreamReceiveFrame"
template="tid_STREAM_U64"
value="6158"
/>
<event
keywords="ut:Stream ut:RPS"
level="win:Verbose"
message="$(string.Etw.StreamAppReceive)"
opcode="Stream"
symbol="QuicStreamAppReceive"
template="tid_STREAM_RECV"
value="6159"
/>
<event
keywords="ut:Stream ut:RPS"
level="win:Verbose"
message="$(string.Etw.StreamAppReceiveComplete)"
opcode="Stream"
symbol="QuicStreamAppReceiveComplete"
template="tid_STREAM_U64"
value="6160"
/>
<event
keywords="ut:Stream ut:RPS"
level="win:Verbose"
message="$(string.Etw.StreamAppSend)"
opcode="Stream"
symbol="QuicStreamAppSend"
template="tid_STREAM_RECV"
value="6161"
/>
<!-- 7168 - 8191 | Binding Events -->
<event
keywords="ut:Binding ut:LowVolume"
@ -3102,6 +3214,61 @@
template="tid_MESSAGE"
value="10243"
/>
<!-- 11264 - 12287 | Packet Events -->
<event
keywords="ut:RPS"
level="win:Verbose"
message="$(string.Etw.PacketCreated)"
opcode="Global"
symbol="QuicPacketCreated"
template="tid_ID_ID"
value="11264"
/>
<event
keywords="ut:RPS"
level="win:Verbose"
message="$(string.Etw.PacketEncrypt)"
opcode="Global"
symbol="QuicPacketEncrypt"
template="tid_ID"
value="11265"
/>
<event
keywords="ut:RPS"
level="win:Verbose"
message="$(string.Etw.PacketFinalize)"
opcode="Global"
symbol="QuicPacketFinalize"
template="tid_ID"
value="11266"
/>
<event
keywords="ut:RPS"
level="win:Verbose"
message="$(string.Etw.PacketBatchSent)"
opcode="Global"
symbol="QuicPacketBatchSent"
template="tid_ID"
value="11267"
/>
<event
keywords="ut:RPS"
level="win:Verbose"
message="$(string.Etw.PacketReceive)"
opcode="Global"
symbol="QuicPacketReceive"
template="tid_ID"
value="11268"
/>
<event
keywords="ut:RPS"
level="win:Verbose"
message="$(string.Etw.PacketDecrypt)"
opcode="Global"
symbol="QuicPacketDecrypt"
template="tid_ID"
value="11269"
/>
</events>
</provider>
</events>
@ -3370,6 +3537,30 @@
id="Etw.StreamMessage"
value="[strm][%1] %2"
/>
<string
id="Etw.StreamAlloc"
value="[strm][%1] Allocated, Conn=%2"
/>
<string
id="Etw.StreamWriteFrames"
value="[strm][%1] Writing frames to packet %2"
/>
<string
id="Etw.StreamReceiveFrame"
value="[strm][%1] Processing frame in packet %2"
/>
<string
id="Etw.StreamAppReceive"
value="[strm][%1] Indicating QUIC_STREAM_EVENT_RECEIVE [%2 bytes, %3 buffers, %4 flags]"
/>
<string
id="Etw.StreamAppReceiveComplete"
value="[strm][%1] Receive complete [%2 bytes]"
/>
<string
id="Etw.StreamAppSend"
value="[strm][%1] App queuing send [%2 bytes, %3 buffers, %4 flags]"
/>
<string
id="Etw.WorkerCreated"
value="[wrkr][%1] Created, IdealProc=%2 Owner=%3"
@ -3626,6 +3817,30 @@
id="Etw.LibraryVersion"
value="[ lib] Version %1.%2.%3.%4"
/>
<string
id="Etw.PacketCreated"
value="[pack][%1] Created in batch %2"
/>
<string
id="Etw.PacketEncrypt"
value="[pack][%1] Encrypting"
/>
<string
id="Etw.PacketFinalize"
value="[pack][%1] Finalizing"
/>
<string
id="Etw.PacketBatchSent"
value="[pack][%1] Batch sent"
/>
<string
id="Etw.PacketReceive"
value="[pack][%1] Received"
/>
<string
id="Etw.PacketDecrypt"
value="[pack][%1] Decrypting"
/>
<!-- Map/enum strings -->
<string
id="Enum.QUIC_SCHEDULE_STATE.IDLE"

246
src/manifest/clog.sidecar
Просмотреть файл

@ -111,6 +111,30 @@
],
"macroName": "QuicTraceEvent"
},
"StreamAppSend": {
"ModuleProperites": {},
"TraceString": "[strm][%p] App queuing send [%llu bytes, %u buffers, 0x%x flags]",
"UniqueId": "StreamAppSend",
"splitArgs": [
{
"DefinationEncoding": "p",
"MacroVariableName": "arg2"
},
{
"DefinationEncoding": "llu",
"MacroVariableName": "arg3"
},
{
"DefinationEncoding": "u",
"MacroVariableName": "arg4"
},
{
"DefinationEncoding": "x",
"MacroVariableName": "arg5"
}
],
"macroName": "QuicTraceEvent"
},
"LibraryError": {
"ModuleProperites": {},
"TraceString": "[ lib] ERROR, %s.",
@ -370,6 +394,18 @@
],
"macroName": "QuicTraceEvent"
},
"PacketReceive": {
"ModuleProperites": {},
"TraceString": "[pack][%llu] Received",
"UniqueId": "PacketReceive",
"splitArgs": [
{
"DefinationEncoding": "llu",
"MacroVariableName": "arg2"
}
],
"macroName": "QuicTraceEvent"
},
"ConfigurationOpenStorageFailed": {
"ModuleProperites": {},
"TraceString": "[cnfg][%p] Failed to open settings, 0x%x",
@ -1974,6 +2010,18 @@
],
"macroName": "QuicTraceEvent"
},
"PacketDecrypt": {
"ModuleProperites": {},
"TraceString": "[pack][%llu] Decrypting",
"UniqueId": "PacketDecrypt",
"splitArgs": [
{
"DefinationEncoding": "llu",
"MacroVariableName": "arg2"
}
],
"macroName": "QuicTraceEvent"
},
"ConnPacketRecv": {
"ModuleProperites": {},
"TraceString": "[conn][%p][RX][%llu] %c (%hu bytes)",
@ -6056,6 +6104,46 @@
],
"macroName": "QuicTraceLogConnVerbose"
},
"PacketCreated": {
"ModuleProperites": {},
"TraceString": "[pack][%llu] Created in batch %llu",
"UniqueId": "PacketCreated",
"splitArgs": [
{
"DefinationEncoding": "llu",
"MacroVariableName": "arg2"
},
{
"DefinationEncoding": "llu",
"MacroVariableName": "arg3"
}
],
"macroName": "QuicTraceEvent"
},
"PacketEncrypt": {
"ModuleProperites": {},
"TraceString": "[pack][%llu] Encrypting",
"UniqueId": "PacketEncrypt",
"splitArgs": [
{
"DefinationEncoding": "llu",
"MacroVariableName": "arg2"
}
],
"macroName": "QuicTraceEvent"
},
"PacketFinalize": {
"ModuleProperites": {},
"TraceString": "[pack][%llu] Finalizing",
"UniqueId": "PacketFinalize",
"splitArgs": [
{
"DefinationEncoding": "llu",
"MacroVariableName": "arg2"
}
],
"macroName": "QuicTraceEvent"
},
"ConnPacketSent": {
"ModuleProperites": {},
"TraceString": "[conn][%p][TX][%llu] %hhu (%hu bytes)",
@ -6080,6 +6168,18 @@
],
"macroName": "QuicTraceEvent"
},
"PacketBatchSent": {
"ModuleProperites": {},
"TraceString": "[pack][%llu] Batch sent",
"UniqueId": "PacketBatchSent",
"splitArgs": [
{
"DefinationEncoding": "llu",
"MacroVariableName": "arg2"
}
],
"macroName": "QuicTraceEvent"
},
"PathInitialized": {
"ModuleProperites": {},
"TraceString": "[conn][%p] Path[%hhu] Initialized",
@ -6900,6 +7000,22 @@
],
"macroName": "QuicTraceLogStreamVerbose"
},
"StreamAlloc": {
"ModuleProperites": {},
"TraceString": "[strm][%p] Allocated, Conn=%p",
"UniqueId": "StreamAlloc",
"splitArgs": [
{
"DefinationEncoding": "p",
"MacroVariableName": "arg2"
},
{
"DefinationEncoding": "p",
"MacroVariableName": "arg3"
}
],
"macroName": "QuicTraceEvent"
},
"StreamDestroyed": {
"ModuleProperites": {},
"TraceString": "[strm][%p] Destroyed",
@ -7264,14 +7380,42 @@
],
"macroName": "QuicTraceLogStreamVerbose"
},
"IndicateReceive": {
"IndicatePeerSendShutdown": {
"ModuleProperites": {},
"TraceString": "[strm][%p] Indicating QUIC_STREAM_EVENT_RECEIVE [%llu bytes, %u buffers, 0x%x flags]",
"UniqueId": "IndicateReceive",
"TraceString": "[strm][%p] Indicating QUIC_STREAM_EVENT_PEER_SEND_SHUTDOWN",
"UniqueId": "IndicatePeerSendShutdown",
"splitArgs": [
{
"DefinationEncoding": "p",
"MacroVariableName": "arg1"
}
],
"macroName": "QuicTraceLogStreamVerbose"
},
"StreamReceiveFrame": {
"ModuleProperites": {},
"TraceString": "[strm][%p] Processing frame in packet %llu",
"UniqueId": "StreamReceiveFrame",
"splitArgs": [
{
"DefinationEncoding": "p",
"MacroVariableName": "arg2"
},
{
"DefinationEncoding": "llu",
"MacroVariableName": "arg3"
}
],
"macroName": "QuicTraceEvent"
},
"StreamAppReceive": {
"ModuleProperites": {},
"TraceString": "[strm][%p] Indicating QUIC_STREAM_EVENT_RECEIVE [%llu bytes, %u buffers, 0x%x flags]",
"UniqueId": "StreamAppReceive",
"splitArgs": [
{
"DefinationEncoding": "p",
"MacroVariableName": "arg2"
},
{
"DefinationEncoding": "llu",
@ -7286,35 +7430,23 @@
"MacroVariableName": "arg5"
}
],
"macroName": "QuicTraceLogStreamVerbose"
"macroName": "QuicTraceEvent"
},
"ReceiveComplete": {
"StreamAppReceiveComplete": {
"ModuleProperites": {},
"TraceString": "[strm][%p] Recv complete (%llu bytes)",
"UniqueId": "ReceiveComplete",
"TraceString": "[strm][%p] Receive complete [%llu bytes]",
"UniqueId": "StreamAppReceiveComplete",
"splitArgs": [
{
"DefinationEncoding": "p",
"MacroVariableName": "arg1"
"MacroVariableName": "arg2"
},
{
"DefinationEncoding": "llu",
"MacroVariableName": "arg3"
}
],
"macroName": "QuicTraceLogStreamVerbose"
},
"IndicatePeerSendShutdown": {
"ModuleProperites": {},
"TraceString": "[strm][%p] Indicating QUIC_STREAM_EVENT_PEER_SEND_SHUTDOWN",
"UniqueId": "IndicatePeerSendShutdown",
"splitArgs": [
{
"DefinationEncoding": "p",
"MacroVariableName": "arg1"
}
],
"macroName": "QuicTraceLogStreamVerbose"
"macroName": "QuicTraceEvent"
},
"IndicateSendShutdownComplete": {
"ModuleProperites": {},
@ -7596,6 +7728,22 @@
],
"macroName": "QuicTraceLogStreamVerbose"
},
"StreamWriteFrames": {
"ModuleProperites": {},
"TraceString": "[strm][%p] Writing frames to packet %llu",
"UniqueId": "StreamWriteFrames",
"splitArgs": [
{
"DefinationEncoding": "p",
"MacroVariableName": "arg2"
},
{
"DefinationEncoding": "llu",
"MacroVariableName": "arg3"
}
],
"macroName": "QuicTraceEvent"
},
"NotAccepted": {
"ModuleProperites": {},
"TraceString": "[strm][%p] New stream wasn't accepted, 0x%x",
@ -10900,6 +11048,10 @@
"UniquenessHash": "c3b546cc-e127-435d-8bf4-cf20ca3d2d5e",
"TraceID": "StreamError"
},
{
"UniquenessHash": "a35cb953-343e-6914-a737-cd53044edb92",
"TraceID": "StreamAppSend"
},
{
"UniquenessHash": "2cbc406b-c1c0-ba4d-eee8-669f30330f4a",
"TraceID": "LibraryError"
@ -10964,6 +11116,10 @@
"UniquenessHash": "3726f8cb-fca2-1ea3-208b-0f223c09aae2",
"TraceID": "BindingExecOper"
},
{
"UniquenessHash": "f1741ac1-9c6a-e567-0c1c-9dc411e88b49",
"TraceID": "PacketReceive"
},
{
"UniquenessHash": "c020fe47-4ec6-93b0-03db-ec72593a14b5",
"TraceID": "ConfigurationOpenStorageFailed"
@ -11380,6 +11536,10 @@
"UniquenessHash": "01d5a727-8287-c441-9ff0-0ebbd899549f",
"TraceID": "ConnHandshakeStart"
},
{
"UniquenessHash": "b27efe89-6500-60ee-bdbb-b417ecce6d62",
"TraceID": "PacketDecrypt"
},
{
"UniquenessHash": "af137df5-1055-7424-de16-65895d8d276b",
"TraceID": "ConnPacketRecv"
@ -12256,10 +12416,26 @@
"UniquenessHash": "f2859068-aa3b-758e-45b8-db7e1bf4063f",
"TraceID": "PacketBuilderSendBatch"
},
{
"UniquenessHash": "e0aaacd6-02f1-c4f2-571b-290d53b0ebf7",
"TraceID": "PacketCreated"
},
{
"UniquenessHash": "040e32a3-ba11-8989-d6d4-57d7c799c359",
"TraceID": "PacketEncrypt"
},
{
"UniquenessHash": "e1679e26-ce08-f741-23b6-23fa6f1de264",
"TraceID": "PacketFinalize"
},
{
"UniquenessHash": "8acd91f1-3c17-7458-fb5b-e3453f2825d3",
"TraceID": "ConnPacketSent"
},
{
"UniquenessHash": "64d69663-eb58-98c9-1c06-2b1fa209874b",
"TraceID": "PacketBatchSent"
},
{
"UniquenessHash": "607e449d-59a9-9d66-fcd1-b0a2e12f1dc1",
"TraceID": "PathInitialized"
@ -12500,6 +12676,10 @@
"UniquenessHash": "8340b390-8b79-ab44-6593-7e449f0ec748",
"TraceID": "IndicateStreamShutdownComplete"
},
{
"UniquenessHash": "cbc983bb-6d04-149e-6eda-09d855f77d4c",
"TraceID": "StreamAlloc"
},
{
"UniquenessHash": "cfaab7b3-b77b-3a94-a433-4c9b57907696",
"TraceID": "StreamDestroyed"
@ -12596,18 +12776,22 @@
"UniquenessHash": "b7d10598-79a4-31fa-8455-0d393b45c1e7",
"TraceID": "IgnoreRecvFlush"
},
{
"UniquenessHash": "e4987d94-23ad-702c-46c0-5e0ae549c4b7",
"TraceID": "IndicateReceive"
},
{
"UniquenessHash": "ce1008cb-0d5e-dd9c-0714-8d37be5b7d60",
"TraceID": "ReceiveComplete"
},
{
"UniquenessHash": "7b23cd90-0d41-8339-9622-e84277f95b5d",
"TraceID": "IndicatePeerSendShutdown"
},
{
"UniquenessHash": "aaf00b3c-6719-7619-1362-6058d0d3be90",
"TraceID": "StreamReceiveFrame"
},
{
"UniquenessHash": "e6e8eceb-d044-4536-96cc-97d53de7e620",
"TraceID": "StreamAppReceive"
},
{
"UniquenessHash": "92e805e6-d2f5-68d3-fdcd-f56c490ed368",
"TraceID": "StreamAppReceiveComplete"
},
{
"UniquenessHash": "e7d79111-7d5f-45a3-50b8-e4ca6de3c081",
"TraceID": "IndicateSendShutdownComplete"
@ -12668,6 +12852,10 @@
"UniquenessHash": "b5af9a64-4d59-3aa3-f0d4-abcbbbfd0329",
"TraceID": "SendDumpAck"
},
{
"UniquenessHash": "cc7f8746-a729-760b-90cc-8f3973b3fde2",
"TraceID": "StreamWriteFrames"
},
{
"UniquenessHash": "48b0b691-89c1-4bb2-1ba4-5bc91586b2b3",
"TraceID": "NotAccepted"

4
src/plugins/QuicTrace.sln
Просмотреть файл

@ -1,7 +1,7 @@

Microsoft Visual Studio Solution File, Format Version 12.00
# Visual Studio Version 16
VisualStudioVersion = 16.0.29102.190
# Visual Studio Version 17
VisualStudioVersion = 17.1.31911.260
MinimumVisualStudioVersion = 10.0.40219.1
Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "QuicTraceLib", "trace\dll\QuicTraceLib.csproj", "{CCE5ECE9-8DCD-4E3F-8389-D48B728355DF}"
EndProject

5
src/plugins/trace/dll/DataModel/ETW/QuicEtwDataReader.cs
Просмотреть файл

@ -42,6 +42,11 @@ namespace QuicTrace.DataModel.ETW
return PointerSize == 8 ? ReadValue<ulong>() : ReadValue<uint>();
}
internal ReadOnlySpan<byte> ReadBytes()
{
return Data.Slice(0, ReadValue<byte>());
}
internal string ReadString()
{
var chars = new List<char>();

30
src/plugins/trace/dll/DataModel/ETW/QuicEtwEvent.cs
Просмотреть файл

@ -25,6 +25,7 @@ namespace QuicTrace.DataModel.ETW
Platform = 0x0000000000000400ul,
Api = 0x0000000000000800ul,
Log = 0x0000000000001000ul,
RPS = 0x0000000000002000ul,
LowVolume = 0x0000000080000000ul,
DataFlow = 0x0000000040000000ul,
Scheduling = 0x0000000020000000ul,
@ -198,6 +199,10 @@ namespace QuicTrace.DataModel.ETW
return new QuicConnectionInFlowStatsEvent(timestamp, processor, processId, threadId, pointerSize, data.ReadPointer(), data.ReadULong());
case QuicEventId.ConnCongestion:
return new QuicConnectionCongestionEvent(timestamp, processor, processId, threadId, pointerSize, data.ReadPointer());
case QuicEventId.ConnSourceCidAdded:
return new QuicConnectionSourceCidAddedEvent(timestamp, processor, processId, threadId, pointerSize, data.ReadPointer(), data.ReadULong(), data.ReadBytes());
case QuicEventId.ConnDestCidAdded:
return new QuicConnectionDestinationCidAddedEvent(timestamp, processor, processId, threadId, pointerSize, data.ReadPointer(), data.ReadULong(), data.ReadBytes());
case QuicEventId.ConnStats:
return new QuicConnectionStatsEvent(timestamp, processor, processId, threadId, pointerSize, data.ReadPointer(), data.ReadUInt(), data.ReadUInt(), data.ReadUInt(), data.ReadULong(), data.ReadULong());
case QuicEventId.ConnOutFlowStreamStats:
@ -222,6 +227,18 @@ namespace QuicTrace.DataModel.ETW
case QuicEventId.StreamErrorStatus:
if (QuicEvent.ParseMode != QuicEventParseMode.Full) return null;
return new QuicStreamErrorStatusEvent(timestamp, processor, processId, threadId, pointerSize, data.ReadPointer(), data.ReadUInt(), data.ReadString());
case QuicEventId.StreamAlloc:
return new QuicStreamAllocEvent(timestamp, processor, processId, threadId, pointerSize, data.ReadPointer(), data.ReadULong());
case QuicEventId.StreamWriteFrames:
return new QuicStreamWriteFramesEvent(timestamp, processor, processId, threadId, pointerSize, data.ReadPointer(), data.ReadULong());
case QuicEventId.StreamReceiveFrame:
return new QuicStreamReceiveFrameEvent(timestamp, processor, processId, threadId, pointerSize, data.ReadPointer(), data.ReadULong());
case QuicEventId.StreamAppReceive:
return new QuicStreamAppReceiveEvent(timestamp, processor, processId, threadId, pointerSize, data.ReadPointer());
case QuicEventId.StreamAppReceiveComplete:
return new QuicStreamAppReceiveCompleteEvent(timestamp, processor, processId, threadId, pointerSize, data.ReadPointer());
case QuicEventId.StreamAppSend:
return new QuicStreamAppSendEvent(timestamp, processor, processId, threadId, pointerSize, data.ReadPointer());
case (QuicEventId)9216: // Temporary, while there are still builds out there generating this old event
return new QuicDatapathSendEvent(timestamp, processor, processId, threadId, pointerSize, data.ReadPointer(), data.ReadUInt(), data.ReadByte(), data.ReadUShort(), data.ReadAddress(), new System.Net.IPEndPoint(0,0));
@ -247,6 +264,19 @@ namespace QuicTrace.DataModel.ETW
if (QuicEvent.ParseMode != QuicEventParseMode.Full) return null;
return new QuicLibraryMessageEvent(id, timestamp, processor, processId, threadId, pointerSize, data.ReadString());
case QuicEventId.PacketCreated:
return new QuicPacketCreatedEvent(timestamp, processor, processId, threadId, pointerSize, data.ReadULong(), data.ReadULong());
case QuicEventId.PacketEncrypt:
return new QuicPacketEncryptEvent(timestamp, processor, processId, threadId, pointerSize, data.ReadULong());
case QuicEventId.PacketFinalize:
return new QuicPacketFinalizeEvent(timestamp, processor, processId, threadId, pointerSize, data.ReadULong());
case QuicEventId.PacketBatchSent:
return new QuicPacketBatchSentEvent(timestamp, processor, processId, threadId, pointerSize, data.ReadULong());
case QuicEventId.PacketReceive:
return new QuicPacketReceiveEvent(timestamp, processor, processId, threadId, pointerSize, data.ReadULong());
case QuicEventId.PacketDecrypt:
return new QuicPacketDecryptEvent(timestamp, processor, processId, threadId, pointerSize, data.ReadULong());
default:
return null;
}

15
src/plugins/trace/dll/DataModel/QuicEvent.cs
Просмотреть файл

@ -162,6 +162,12 @@ namespace QuicTrace.DataModel
StreamLogWarning,
StreamLogInfo,
StreamLogVerbose,
StreamAlloc,
StreamWriteFrames,
StreamReceiveFrame,
StreamAppReceive,
StreamAppReceiveComplete,
StreamAppSend,
BindingCreated = 7168,
BindingRundown,
@ -187,7 +193,14 @@ namespace QuicTrace.DataModel
LogError = 10240,
LogWarning,
LogInfo,
LogVerbose
LogVerbose,
PacketCreated = 11264,
PacketEncrypt,
PacketFinalize,
PacketBatchSent,
PacketReceive,
PacketDecrypt
}
//

160
src/plugins/trace/dll/DataModel/QuicEvents.cs
Просмотреть файл

@ -720,6 +720,42 @@ namespace QuicTrace.DataModel
}
}
public class QuicConnectionSourceCidAddedEvent : QuicEvent
{
public ulong SequenceNumber { get; }
#pragma warning disable CA1819 // Properties should not return arrays
public byte[] CID { get; }
#pragma warning restore CA1819 // Properties should not return arrays
internal QuicConnectionSourceCidAddedEvent(Timestamp timestamp, ushort processor, uint processId, uint threadId, int pointerSize, ulong objectPointer,
ulong sequenceNumber, ReadOnlySpan<byte> cid) :
base(QuicEventId.ConnSourceCidAdded, QuicObjectType.Connection, timestamp, processor, processId, threadId, pointerSize, objectPointer)
{
SequenceNumber = sequenceNumber;
CID = cid.ToArray();
}
}
public class QuicConnectionDestinationCidAddedEvent : QuicEvent
{
public ulong SequenceNumber { get; }
#pragma warning disable CA1819 // Properties should not return arrays
public byte[] CID { get; }
#pragma warning restore CA1819 // Properties should not return arrays
internal QuicConnectionDestinationCidAddedEvent(Timestamp timestamp, ushort processor, uint processId, uint threadId, int pointerSize, ulong objectPointer,
ulong sequenceNumber, ReadOnlySpan<byte> cid) :
base(QuicEventId.ConnDestCidAdded, QuicObjectType.Connection, timestamp, processor, processId, threadId, pointerSize, objectPointer)
{
SequenceNumber = sequenceNumber;
CID = cid.ToArray();
}
}
public class QuicConnectionStatsEvent : QuicEvent
{
public uint SmoothedRtt { get; }
@ -850,6 +886,63 @@ namespace QuicTrace.DataModel
}
}
public class QuicStreamAllocEvent : QuicEvent
{
public ulong Connection { get; }
internal QuicStreamAllocEvent(Timestamp timestamp, ushort processor, uint processId, uint threadId, int pointerSize, ulong objectPointer, ulong connection) :
base(QuicEventId.StreamAlloc, QuicObjectType.Stream, timestamp, processor, processId, threadId, pointerSize, objectPointer)
{
Connection = connection;
}
}
public class QuicStreamWriteFramesEvent : QuicEvent
{
public ulong ID { get; }
internal QuicStreamWriteFramesEvent(Timestamp timestamp, ushort processor, uint processId, uint threadId, int pointerSize, ulong objectPointer, ulong id) :
base(QuicEventId.StreamWriteFrames, QuicObjectType.Stream, timestamp, processor, processId, threadId, pointerSize, objectPointer)
{
ID = id;
}
}
public class QuicStreamReceiveFrameEvent : QuicEvent
{
public ulong ID { get; }
internal QuicStreamReceiveFrameEvent(Timestamp timestamp, ushort processor, uint processId, uint threadId, int pointerSize, ulong objectPointer, ulong id) :
base(QuicEventId.StreamReceiveFrame, QuicObjectType.Stream, timestamp, processor, processId, threadId, pointerSize, objectPointer)
{
ID = id;
}
}
public class QuicStreamAppReceiveEvent : QuicEvent
{
internal QuicStreamAppReceiveEvent(Timestamp timestamp, ushort processor, uint processId, uint threadId, int pointerSize, ulong objectPointer) :
base(QuicEventId.StreamAppReceive, QuicObjectType.Stream, timestamp, processor, processId, threadId, pointerSize, objectPointer)
{
}
}
public class QuicStreamAppReceiveCompleteEvent : QuicEvent
{
internal QuicStreamAppReceiveCompleteEvent(Timestamp timestamp, ushort processor, uint processId, uint threadId, int pointerSize, ulong objectPointer) :
base(QuicEventId.StreamAppReceiveComplete, QuicObjectType.Stream, timestamp, processor, processId, threadId, pointerSize, objectPointer)
{
}
}
public class QuicStreamAppSendEvent : QuicEvent
{
internal QuicStreamAppSendEvent(Timestamp timestamp, ushort processor, uint processId, uint threadId, int pointerSize, ulong objectPointer) :
base(QuicEventId.StreamAppSend, QuicObjectType.Stream, timestamp, processor, processId, threadId, pointerSize, objectPointer)
{
}
}
#endregion
#region Datapath Events
@ -964,4 +1057,71 @@ namespace QuicTrace.DataModel
}
#endregion
#region Packet Events
public class QuicPacketCreatedEvent : QuicEvent
{
public ulong ID => ObjectPointer;
public ulong BatchID { get; }
internal QuicPacketCreatedEvent(Timestamp timestamp, ushort processor, uint processId, uint threadId, int pointerSize, ulong id, ulong id2) :
base(QuicEventId.PacketCreated, QuicObjectType.Global, timestamp, processor, processId, threadId, pointerSize, id)
{
BatchID = id2;
}
}
public class QuicPacketEncryptEvent : QuicEvent
{
public ulong ID => ObjectPointer;
internal QuicPacketEncryptEvent(Timestamp timestamp, ushort processor, uint processId, uint threadId, int pointerSize, ulong id) :
base(QuicEventId.PacketEncrypt, QuicObjectType.Global, timestamp, processor, processId, threadId, pointerSize, id)
{
}
}
public class QuicPacketFinalizeEvent : QuicEvent
{
public ulong ID => ObjectPointer;
internal QuicPacketFinalizeEvent(Timestamp timestamp, ushort processor, uint processId, uint threadId, int pointerSize, ulong id) :
base(QuicEventId.PacketFinalize, QuicObjectType.Global, timestamp, processor, processId, threadId, pointerSize, id)
{
}
}
public class QuicPacketBatchSentEvent : QuicEvent
{
public ulong ID => ObjectPointer;
internal QuicPacketBatchSentEvent(Timestamp timestamp, ushort processor, uint processId, uint threadId, int pointerSize, ulong id) :
base(QuicEventId.PacketBatchSent, QuicObjectType.Global, timestamp, processor, processId, threadId, pointerSize, id)
{
}
}
public class QuicPacketReceiveEvent : QuicEvent
{
public ulong ID => ObjectPointer;
internal QuicPacketReceiveEvent(Timestamp timestamp, ushort processor, uint processId, uint threadId, int pointerSize, ulong id) :
base(QuicEventId.PacketReceive, QuicObjectType.Global, timestamp, processor, processId, threadId, pointerSize, id)
{
}
}
public class QuicPacketDecryptEvent : QuicEvent
{
public ulong ID => ObjectPointer;
internal QuicPacketDecryptEvent(Timestamp timestamp, ushort processor, uint processId, uint threadId, int pointerSize, ulong id) :
base(QuicEventId.PacketDecrypt, QuicObjectType.Global, timestamp, processor, processId, threadId, pointerSize, id)
{
}
}
#endregion
}

3
src/plugins/trace/dll/DataModel/QuicObjectSet.cs
Просмотреть файл

@ -36,7 +36,8 @@ namespace QuicTrace.DataModel
}
}
internal QuicObjectKey(QuicEvent evt) : this(evt.PointerSize, evt.ObjectPointer, evt.ProcessId)
[System.Diagnostics.CodeAnalysis.SuppressMessage("Design", "CA1062:Validate arguments of public methods")]
public QuicObjectKey(QuicEvent evt) : this(evt.PointerSize, evt.ObjectPointer, evt.ProcessId)
{
}

798
src/plugins/trace/exe/Program.cs
Просмотреть файл

@ -4,6 +4,9 @@
//
using System;
using System.Collections;
using System.Collections.Generic;
using System.Linq;
using System.Threading;
using Microsoft.Diagnostics.Tracing.Session;
using Microsoft.Performance.SDK.Extensibility;
@ -20,7 +23,8 @@ namespace QuicTrace
"\n" +
"Commands:\n" +
" -p, --print Prints events as text\n" +
" -r, --report Prints out an analysis of possible problems in the trace\n"
" -r, --report Prints out an analysis of possible problems in the trace\n" +
" -s, --rps Prints out an analysis RPS-related events in the trace\n"
);
}
@ -56,37 +60,42 @@ namespace QuicTrace
return fileName;
}
static QuicState ProcessTraceFile(string filePath)
static QuicState[] ProcessTraceFiles(IEnumerable<string> filePaths)
{
//
// Create our runtime environment, add file, enable cookers, and process.
//
PluginSet pluginSet;
if (string.IsNullOrWhiteSpace(typeof(QuicEtwSource).Assembly.Location))
var quicStates = new List<QuicState>();
foreach (var filePath in filePaths)
{
// Single File EXE
pluginSet = PluginSet.Load(new[] { Environment.CurrentDirectory }, new SingleFileAssemblyLoader());
}
else
{
pluginSet = PluginSet.Load();
//
// Create our runtime environment, add file, enable cookers, and process.
//
PluginSet pluginSet;
if (string.IsNullOrWhiteSpace(typeof(QuicEtwSource).Assembly.Location))
{
// Single File EXE
pluginSet = PluginSet.Load(new[] { Environment.CurrentDirectory }, new SingleFileAssemblyLoader());
}
else
{
pluginSet = PluginSet.Load();
}
using var dataSources = DataSourceSet.Create(pluginSet);
dataSources.AddFile(filePath);
var info = new EngineCreateInfo(dataSources.AsReadOnly());
using var runtime = Engine.Create(info);
runtime.EnableCooker(QuicEventCooker.CookerPath);
//Console.Write("Processing {0}...", filePath);
var results = runtime.Process();
//Console.WriteLine("Done.\n");
//
// Return our 'cooked' data.
//
quicStates.Add(results.QueryOutput<QuicState>(new DataOutputPath(QuicEventCooker.CookerPath, "State")));
}
using var dataSources = DataSourceSet.Create(pluginSet);
dataSources.AddFile(filePath);
var info = new EngineCreateInfo(dataSources.AsReadOnly());
using var runtime = Engine.Create(info);
runtime.EnableCooker(QuicEventCooker.CookerPath);
Console.WriteLine("Processing...");
var results = runtime.Process();
Console.WriteLine("Done.\n");
//
// Return our 'cooked' data.
//
return results.QueryOutput<QuicState>(new DataOutputPath(QuicEventCooker.CookerPath, "State"));
return quicStates.ToArray();
}
static void RunReport(QuicState quicState)
@ -159,7 +168,713 @@ namespace QuicTrace
//
}
static void RunCommand(QuicState quicState, string[] args)
public enum RequestState
{
Idle,
QueueSend,
ProcessSend,
Frame,
Write,
Encrypt,
Send,
Udp,
AwaitPeer,
QueueRecv,
ProcessRecv,
Decrypt,
Read,
AppRecv,
Complete,
COUNT
};
internal class RequestTiming
{
//
// The time spent in each RequestState.
//
public ulong[] Times = new ulong[(int)RequestState.COUNT];
//
// The current state of the request.
//
public RequestState State = RequestState.Idle;
//
// The last time State was updated.
//
public ulong LastStateChangeTime = 0;
//
// Triggers a state change and updates variables accordingly.
//
public void UpdateToState(RequestState state, ulong time, bool allowPrevious = false)
{
if (EncounteredError) return;
if (time < LastStateChangeTime)
{
if (allowPrevious)
{
State = state; // Just treat it as if we entered this new state instead of the old one
}
else
{
Console.WriteLine("ERROR: Invalid state change from {0} to {1}", State, state);
EncounteredError = true;
}
return;
}
Times[(int)State] += (time - LastStateChangeTime);
LastStateChangeTime = time;
State = state;
}
//
// Returns the sum of all the calculated times for individual layers.
//
public ulong TotalTime { get { return Times.Aggregate((temp, x) => temp + x); } }
//
// The connection used for this request.
//
public QuicRequestConn? Connection = null;
//
// The corresponding peer's timings.
//
public RequestTiming? Peer = null;
//
// The stream identifier for this request.
//
public ulong StreamID = ulong.MaxValue;
//
// Indicates if this timings is for the client or server side.
//
public bool IsServer = false;
public ulong FirstPacketRecv = 0;
public ulong FirstPacketSend = 0;
//
// Indicates if an error or unexpected state occurred while processing this request.
//
public bool EncounteredError = false;
//
// Writes the header for the CSV data.
//
public static void WriteCsvHeader(bool withTotal = true)
{
if (withTotal) Console.Write("Total");
foreach (var state in Enum.GetValues(typeof(RequestState)).Cast<RequestState>())
{
if (state == RequestState.COUNT) break;
Console.Write(",{0}", state);
}
Console.WriteLine();
}
//
// Writes all the times in comma seperated vector format.
//
public void WriteCsv()
{
Console.Write("{0},", TotalTime);
Console.WriteLine(String.Join(",", Times));
}
}
internal class QuicRequestConn : IQuicObject
{
public static QuicRequestConn New(ulong pointer, uint processId) => new QuicRequestConn(pointer, processId);
public static ushort CreateEventId => (ushort)QuicEventId.ConnCreated;
public static ushort DestroyedEventId => 0;
public ulong Id { get; }
private static ulong NextId = 1;
public ulong Pointer { get; }
public uint ProcessId { get; }
public QuicRequestConn? Peer = null;
public QuicScheduleState SchedulingState = QuicScheduleState.Idle;
public ulong LastScheduleTime = 0;
internal QuicRequestConn(ulong pointer, uint processId)
{
Id = NextId++;
Pointer = pointer;
ProcessId = processId;
}
}
internal class QuicPacketBatch : IQuicObject
{
public static QuicPacketBatch New(ulong pointer, uint processId) => new QuicPacketBatch(pointer, processId);
public static ushort CreateEventId => (ushort)QuicEventId.PacketCreated;
public static ushort DestroyedEventId => 0;
public ulong Id { get; }
public ulong Pointer { get; }
public uint ProcessId { get; }
public ulong BatchSent = 0;
public List<QuicPacket> Packets = new List<QuicPacket> { };
internal QuicPacketBatch(ulong pointer, uint processId)
{
Id = pointer;
Pointer = pointer;
ProcessId = processId;
}
}
internal class QuicPacket : IQuicObject
{
public static QuicPacket New(ulong pointer, uint processId) => new QuicPacket(pointer, processId);
public static ushort CreateEventId => (ushort)QuicEventId.PacketCreated;
public static ushort DestroyedEventId => 0;
public ulong Id { get; }
public ulong Pointer { get; }
public uint ProcessId { get; }
public QuicPacketBatch? Batch = null;
public List<QuicStreamRequest> Streams = new List<QuicStreamRequest> { };
public ulong PacketCreate = 0;
public ulong PacketEncrypt = 0;
public ulong PacketFinalize = 0;
public ulong PacketReceive = 0;
public ulong PacketDecrypt = 0;
internal QuicPacket(ulong pointer, uint processId)
{
Id = pointer;
Pointer = pointer;
ProcessId = processId;
}
}
internal class QuicStreamRequest : IQuicObject
{
public static QuicStreamRequest New(ulong pointer, uint processId) => new QuicStreamRequest(pointer, processId);
public static ushort CreateEventId => (ushort)QuicEventId.StreamAlloc;
public static ushort DestroyedEventId => (ushort)QuicEventId.StreamDestroyed;
public ulong Id { get; }
private static ulong NextId = 1;
public ulong Pointer { get; }
public uint ProcessId { get; }
public RequestTiming Timings { get; }
public QuicPacket? SendPacket = null;
public QuicPacket? RecvPacket = null;
public ulong StreamAlloc = 0;
public ulong StreamCreate = 0;
public ulong StreamSend = 0;
public ulong StreamDelete = 0;
public ulong PacketWrite = 0;
public ulong PacketRead = 0;
public ulong AppRecv = 0;
public ulong AppRecvComplete = 0;
internal QuicStreamRequest(ulong pointer, uint processId)
{
Id = NextId++;
Pointer = pointer;
ProcessId = processId;
Timings = new RequestTiming();
}
}
class SequentialByteComparer : IEqualityComparer<byte[]>
{
#pragma warning disable CS8767 // Nullability of reference types in type of parameter doesn't match implicitly implemented member (possibly because of nullability attributes).
public bool Equals(byte[] x, byte[] y) => StructuralComparisons.StructuralEqualityComparer.Equals(x, y);
#pragma warning restore CS8767 // Nullability of reference types in type of parameter doesn't match implicitly implemented member (possibly because of nullability attributes).
public int GetHashCode([System.Diagnostics.CodeAnalysis.DisallowNull] byte[] obj)
{
return StructuralComparisons.StructuralEqualityComparer.GetHashCode(obj);
}
}
static void RunRpsAnalysis(QuicState[] quicStates)
{
var ConnSet = new QuicObjectSet<QuicRequestConn>(QuicRequestConn.CreateEventId, QuicRequestConn.DestroyedEventId, QuicRequestConn.New);
var StreamSet = new QuicObjectSet<QuicStreamRequest>(QuicStreamRequest.CreateEventId, QuicStreamRequest.DestroyedEventId, QuicStreamRequest.New);
var PacketBatchSet = new QuicObjectSet<QuicPacketBatch>(QuicPacketBatch.CreateEventId, QuicPacketBatch.DestroyedEventId, QuicPacketBatch.New);
var PacketSet = new QuicObjectSet<QuicPacket>(QuicPacket.CreateEventId, QuicPacket.DestroyedEventId, QuicPacket.New);
var ConnSourceCIDs = new Dictionary<byte[], QuicRequestConn>(new SequentialByteComparer());
var ConnDestinationCIDs = new Dictionary<byte[], QuicRequestConn>(new SequentialByteComparer());
var ClientRequests = new List<RequestTiming>();
var ServerRequests = new List<RequestTiming>();
foreach (var quicState in quicStates)
{
foreach (var evt in quicState.Events)
{
switch (evt.EventId)
{
case QuicEventId.ConnScheduleState:
{
var Conn = ConnSet.FindOrCreateActive((ushort)evt.EventId, new QuicObjectKey(evt));
Conn.SchedulingState = (evt as QuicConnectionScheduleStateEvent)!.ScheduleState;
Conn.LastScheduleTime = (ulong)evt.TimeStamp.ToNanoseconds;
//Console.WriteLine("ConnScheduleState {0} {1}", evt.ObjectPointer, Conn.SchedulingState);
break;
}
case QuicEventId.ConnSourceCidAdded:
{
//Console.WriteLine("ConnSourceCidAdded {0}", evt.ObjectPointer);
var Conn = ConnSet.FindOrCreateActive((ushort)evt.EventId, new QuicObjectKey(evt));
ConnSourceCIDs.Add((evt as QuicConnectionSourceCidAddedEvent)!.CID, Conn);
if (Conn.Peer == null && ConnDestinationCIDs.TryGetValue((evt as QuicConnectionSourceCidAddedEvent)!.CID, out var peer))
{
Conn.Peer = peer;
peer.Peer = Conn;
//Console.WriteLine("Peer Set {0}", evt.ObjectPointer);
}
break;
}
case QuicEventId.ConnDestCidAdded:
{
//Console.WriteLine("ConnDestCidAdded {0}", evt.ObjectPointer);
var Conn = ConnSet.FindOrCreateActive((ushort)evt.EventId, new QuicObjectKey(evt));
ConnDestinationCIDs.Add((evt as QuicConnectionDestinationCidAddedEvent)!.CID, Conn);
if (Conn.Peer == null && ConnSourceCIDs.TryGetValue((evt as QuicConnectionDestinationCidAddedEvent)!.CID, out var peer))
{
Conn.Peer = peer;
peer.Peer = Conn;
//Console.WriteLine("Peer Set (dest) {0}", evt.ObjectPointer);
}
break;
}
case QuicEventId.StreamAlloc:
{
//Console.WriteLine("StreamAlloc {0}", evt.ObjectPointer);
var Stream = StreamSet.FindOrCreateActive((ushort)evt.EventId, new QuicObjectKey(evt));
if (Stream.Timings.EncounteredError) break;
Stream.Timings.Connection = ConnSet.FindOrCreateActive(new QuicObjectKey(evt.PointerSize, (evt as QuicStreamAllocEvent)!.Connection, evt.ProcessId));
//Console.WriteLine("Set Conn {0}", (evt as QuicStreamAllocEvent)!.Connection);
Stream.StreamAlloc = (ulong)evt.TimeStamp.ToNanoseconds;
Stream.Timings.LastStateChangeTime = (ulong)evt.TimeStamp.ToNanoseconds;
break;
}
case QuicEventId.StreamCreated:
{
//Console.WriteLine("StreamCreated {0}", evt.ObjectPointer);
var Stream = StreamSet.FindActive(new QuicObjectKey(evt));
if (Stream == null || Stream.Timings.EncounteredError) break;
Stream.Timings.StreamID = (evt as QuicStreamCreatedEvent)!.StreamID;
Stream.Timings.IsServer = (evt as QuicStreamCreatedEvent)!.IsLocalOwned == 0;
Stream.StreamCreate = (ulong)evt.TimeStamp.ToNanoseconds;
break;
}
case QuicEventId.StreamAppSend:
{
//Console.WriteLine("StreamAppSend {0}", evt.ObjectPointer);
var Stream = StreamSet.FindActive(new QuicObjectKey(evt));
if (Stream == null || Stream.Timings.EncounteredError) break;
Stream.StreamSend = (ulong)evt.TimeStamp.ToNanoseconds;
if (Stream.Timings.State == RequestState.Idle)
{
Stream.Timings.UpdateToState(RequestState.QueueSend, (ulong)evt.TimeStamp.ToNanoseconds);
}
else
{
Console.WriteLine("Stream in unexpected state {0} for Send", Stream.Timings.State);
}
break;
}
case QuicEventId.PacketCreated:
{
//Console.WriteLine("PacketCreated {0} in {1}", evt.ObjectPointer, (evt as QuicPacketCreatedEvent)!.BatchID);
var Packet = PacketSet.FindOrCreateActive((ushort)evt.EventId, new QuicObjectKey(evt));
Packet.Batch = PacketBatchSet.FindOrCreateActive(new QuicObjectKey(evt.PointerSize, (evt as QuicPacketCreatedEvent)!.BatchID, evt.ProcessId));
Packet.Batch.Packets.Add(Packet);
Packet.PacketCreate = (ulong)evt.TimeStamp.ToNanoseconds;
break;
}
case QuicEventId.StreamWriteFrames:
{
//Console.WriteLine("StreamWriteFrames {0} in {1}", evt.ObjectPointer, (evt as QuicStreamWriteFramesEvent)!.ID);
var Stream = StreamSet.FindActive(new QuicObjectKey(evt));
if (Stream == null || Stream.Timings.EncounteredError) break;
if (Stream.Timings.State == RequestState.Write) break; // Already in the Write state
if (Stream.Timings.Connection!.SchedulingState != QuicScheduleState.Processing)
{
Console.WriteLine("ERROR: Connection not in processing state for Write");
Stream.Timings.EncounteredError = true;
break;
}
Stream.SendPacket = PacketSet.FindActive(new QuicObjectKey(evt.PointerSize, (evt as QuicStreamWriteFramesEvent)!.ID, evt.ProcessId));
if (Stream.SendPacket == null)
{
Console.WriteLine("ERROR: Failed to find Packet {0} for Write", (evt as QuicStreamWriteFramesEvent)!.ID);
Stream.Timings.EncounteredError = true;
break;
}
Stream.SendPacket.Streams.Add(Stream);
Stream.PacketWrite = (ulong)evt.TimeStamp.ToNanoseconds;
if (Stream.Timings.State == RequestState.QueueSend)
{
Stream.Timings.UpdateToState(RequestState.ProcessSend, Stream.Timings.Connection.LastScheduleTime, true);
Stream.Timings.UpdateToState(RequestState.Frame, Stream.SendPacket.PacketCreate);
}
else if (Stream.Timings.State == RequestState.Send)
{
Stream.Timings.State = RequestState.Frame;
}
else if (Stream.Timings.State == RequestState.Complete ||
Stream.Timings.State == RequestState.AwaitPeer ||
Stream.Timings.State == RequestState.Idle)
{
Stream.Timings.State = RequestState.ProcessSend; // TODO - What state should we consider this?
Stream.Timings.UpdateToState(RequestState.Frame, Stream.SendPacket.PacketCreate);
}
else
{
Console.WriteLine("Stream in unexpected state {0} for Write", Stream.Timings.State);
}
Stream.Timings.UpdateToState(RequestState.Write, (ulong)evt.TimeStamp.ToNanoseconds);
break;
}
case QuicEventId.PacketEncrypt:
{
//Console.WriteLine("PacketEncrypt {0}", evt.ObjectPointer);
var Packet = PacketSet.FindActive(new QuicObjectKey(evt));
if (Packet == null)
{
Console.WriteLine("ERROR: Failed to find Packet {0} for Encrypt", (evt as QuicPacketEncryptEvent)!.ID);
break;
}
Packet.PacketEncrypt = (ulong)evt.TimeStamp.ToNanoseconds;
foreach (var Stream in Packet.Streams)
{
if (Stream.Timings.State != RequestState.Write)
{
Console.WriteLine("ERROR: Stream in {0} state for Encrypt", Stream.Timings.State);
Stream.Timings.EncounteredError = true;
continue;
}
Stream.Timings.UpdateToState(RequestState.Encrypt, (ulong)evt.TimeStamp.ToNanoseconds);
}
break;
}
case QuicEventId.PacketFinalize:
{
//Console.WriteLine("PacketFinalize {0}", evt.ObjectPointer);
var Packet = PacketSet.FindActive(new QuicObjectKey(evt));
if (Packet == null)
{
Console.WriteLine("ERROR: Failed to find Packet {0} for Finalize", (evt as QuicPacketFinalizeEvent)!.ID);
break;
}
Packet.PacketFinalize = (ulong)evt.TimeStamp.ToNanoseconds;
foreach (var Stream in Packet.Streams)
{
if (Stream.Timings.State != RequestState.Encrypt)
{
Console.WriteLine("ERROR: Stream in state {0} for Finalize", Stream.Timings.State);
Stream.Timings.EncounteredError = true;
continue;
}
if (Stream.Timings.FirstPacketSend == 0)
{
Stream.Timings.FirstPacketSend = (ulong)evt.TimeStamp.ToNanoseconds;
}
Stream.SendPacket = null;
Stream.Timings.UpdateToState(RequestState.Send, (ulong)evt.TimeStamp.ToNanoseconds);
}
break;
}
case QuicEventId.PacketBatchSent:
{
//Console.WriteLine("PacketBatchSent {0}", evt.ObjectPointer);
var Batch = PacketBatchSet.FindActive(new QuicObjectKey(evt));
if (Batch == null) break;
Batch.BatchSent = (ulong)evt.TimeStamp.ToNanoseconds;
foreach (var Packet in Batch.Packets)
{
foreach (var Stream in Packet.Streams)
{
if (Stream.Timings.State == RequestState.Send)
{
if (Stream.Timings.IsServer)
{
Stream.Timings.UpdateToState(RequestState.Idle, (ulong)evt.TimeStamp.ToNanoseconds);
}
else
{
Stream.Timings.UpdateToState(RequestState.AwaitPeer, (ulong)evt.TimeStamp.ToNanoseconds);
}
}
else if (Stream.Timings.State != RequestState.Idle && Stream.Timings.State != RequestState.AwaitPeer)
{
Console.WriteLine("ERROR: Stream in state {0} for BatchSent", Stream.Timings.State);
Stream.Timings.EncounteredError = true;
}
}
}
break;
}
case QuicEventId.PacketReceive:
{
//Console.WriteLine("PacketReceive {0}", evt.ObjectPointer);
var Packet = PacketSet.FindOrCreateActive((ushort)evt.EventId, new QuicObjectKey(evt));
Packet.PacketReceive = (ulong)evt.TimeStamp.ToNanoseconds;
break;
}
case QuicEventId.PacketDecrypt:
{
//Console.WriteLine("PacketDecrypt {0}", evt.ObjectPointer);
var Packet = PacketSet.FindActive(new QuicObjectKey(evt));
if (Packet == null)
{
Console.WriteLine("ERROR: Failed to find Packet {0} for Decrypt", (evt as QuicPacketDecryptEvent)!.ID);
break;
}
if (Packet.PacketDecrypt == 0)
{
Packet.PacketDecrypt = (ulong)evt.TimeStamp.ToNanoseconds;
}
break;
}
case QuicEventId.StreamReceiveFrame:
{
//Console.WriteLine("StreamReceiveFrame {0} in {1}", evt.ObjectPointer, (evt as QuicStreamReceiveFrameEvent)!.ID);
var Stream = StreamSet.FindActive(new QuicObjectKey(evt));
if (Stream == null || Stream.Timings.EncounteredError) break;
Stream.RecvPacket = PacketSet.FindActive(new QuicObjectKey(evt.PointerSize, (evt as QuicStreamReceiveFrameEvent)!.ID, evt.ProcessId));
if (Stream.RecvPacket == null)
{
Console.WriteLine("ERROR: Failed to find Packet {0} for Read", (evt as QuicStreamReceiveFrameEvent)!.ID);
Stream.Timings.EncounteredError = true;
break;
}
if (Stream.RecvPacket.PacketDecrypt == 0)
{
Console.WriteLine("ERROR: No PacketDecrypt for Read");
Stream.Timings.EncounteredError = true;
break;
}
if (Stream.Timings.FirstPacketRecv == 0)
{
Stream.Timings.FirstPacketRecv = Stream.RecvPacket.PacketReceive;
}
if (Stream.PacketRead == 0)
{
Stream.PacketRead = (ulong)evt.TimeStamp.ToNanoseconds;
if (Stream.StreamAlloc > Stream.RecvPacket.PacketReceive)
{
Stream.Timings.State = RequestState.QueueRecv;
Stream.Timings.LastStateChangeTime = Stream.RecvPacket.PacketReceive;
Stream.Timings.UpdateToState(RequestState.ProcessRecv, Stream.Timings.Connection!.LastScheduleTime, true);
Stream.Timings.UpdateToState(RequestState.Decrypt, Stream.RecvPacket.PacketDecrypt);
Stream.Timings.UpdateToState(RequestState.Read, (ulong)evt.TimeStamp.ToNanoseconds);
}
else
{
Stream.Timings.UpdateToState(RequestState.QueueRecv, Stream.RecvPacket.PacketReceive, true);
Stream.Timings.UpdateToState(RequestState.ProcessRecv, Stream.Timings.Connection!.LastScheduleTime, true);
Stream.Timings.UpdateToState(RequestState.Decrypt, Stream.RecvPacket.PacketDecrypt);
Stream.Timings.UpdateToState(RequestState.Read, (ulong)evt.TimeStamp.ToNanoseconds);
}
}
break;
}
case QuicEventId.StreamAppReceive:
{
//Console.WriteLine("StreamAppReceive {0}", evt.ObjectPointer);
var Stream = StreamSet.FindActive(new QuicObjectKey(evt));
if (Stream == null || Stream.Timings.EncounteredError) break;
Stream.AppRecv = (ulong)evt.TimeStamp.ToNanoseconds;
Stream.Timings.UpdateToState(RequestState.AppRecv, (ulong)evt.TimeStamp.ToNanoseconds);
break;
}
case QuicEventId.StreamAppReceiveComplete:
{
//Console.WriteLine("StreamAppReceiveComplete {0}", evt.ObjectPointer);
var Stream = StreamSet.FindActive(new QuicObjectKey(evt));
if (Stream == null || Stream.Timings.EncounteredError) break;
if (Stream.Timings.StreamID == ulong.MaxValue)
{
Console.WriteLine("ERROR: Missing StreamID for AppRecvComplete");
Stream.Timings.EncounteredError = true;
break;
}
Stream.AppRecvComplete = (ulong)evt.TimeStamp.ToNanoseconds;
if (Stream.Timings.IsServer)
{
Stream.Timings.UpdateToState(RequestState.Idle, (ulong)evt.TimeStamp.ToNanoseconds);
}
else
{
Stream.Timings.UpdateToState(RequestState.Complete, (ulong)evt.TimeStamp.ToNanoseconds);
}
break;
}
case QuicEventId.StreamDestroyed:
{
//Console.WriteLine("StreamDestroyed {0}", evt.ObjectPointer);
var Stream = StreamSet.FindActive(new QuicObjectKey(evt));
if (Stream == null || Stream.Timings.EncounteredError) break;
if (Stream.Timings.StreamID == ulong.MaxValue)
{
Console.WriteLine("ERROR: Missing StreamID for StreamDestroyed");
Stream.Timings.EncounteredError = true;
break;
}
Stream.Timings.UpdateToState(RequestState.Idle, (ulong)evt.TimeStamp.ToNanoseconds);
if (Stream.Timings.IsServer)
{
//Console.WriteLine("Added server-side request");
ServerRequests.Add(Stream.Timings);
}
else
{
//Console.WriteLine("Added client-side request");
ClientRequests.Add(Stream.Timings);
}
break;
}
default: break;
}
}
}
var clientRequestCount = ClientRequests.Count;
var serverRequestCount = ServerRequests.Count;
if (clientRequestCount == 0)
{
Console.WriteLine("No complete client requests! Found {0} server requests.", serverRequestCount);
return;
}
Console.WriteLine("{0} client and {1} server complete requests found.\n", clientRequestCount, serverRequestCount);
var ServerDict = ServerRequests.ToDictionary(x => ( x.Connection!.Pointer, x.StreamID ) );
foreach (var timing in ClientRequests)
{
if (timing.Connection!.Peer == null)
{
Console.WriteLine("WARNING: Missing connection peer!");
}
else if(!ServerDict.TryGetValue(( timing.Connection!.Peer.Pointer, timing.StreamID ), out var peer))
{
Console.WriteLine("WARNING: Cannot find matching peer timings!");
}
else
{
timing.Peer = peer;
peer.Peer = timing;
//Console.WriteLine("Request Peer Set {0}", timing.StreamID);
var PeerResponseTime = timing.Peer.FirstPacketSend - timing.Peer.FirstPacketRecv;
if (PeerResponseTime > timing.Times[(int)RequestState.AwaitPeer])
{
PeerResponseTime = timing.Times[(int)RequestState.AwaitPeer];
}
timing.Times[(int)RequestState.Udp] = timing.Times[(int)RequestState.AwaitPeer] - PeerResponseTime;
timing.Times[(int)RequestState.AwaitPeer] = PeerResponseTime;
}
}
var sortedRequests = ClientRequests.OrderBy(t => t.TotalTime);
/*RequestTiming.WriteCsvHeader();
foreach (var timing in sortedRequests)
{
timing.WriteCsv();
}
Console.WriteLine();*/
Console.Write("Percentile,");
RequestTiming.WriteCsvHeader();
var Percentiles = new List<double>() { 0, 50, 90, 99, 99.9, 99.99, 99.999 };
foreach (var percentile in Percentiles)
{
var t = sortedRequests.ElementAt((int)((clientRequestCount * percentile) / 100));
Console.Write("{0}th,", percentile);
t.WriteCsv();
}
Console.WriteLine();
var layerTimes = new List<IOrderedEnumerable<RequestTiming>>();
foreach (var state in Enum.GetValues(typeof(RequestState)).Cast<RequestState>())
{
if (state == RequestState.COUNT) break;
layerTimes.Add(ClientRequests.OrderBy(t => t.Times[(int)state]));
}
Console.Write("Percentile");
RequestTiming.WriteCsvHeader(false);
foreach (var percentile in Percentiles)
{
var i = (int)((clientRequestCount * percentile) / 100);
Console.Write("{0}th", percentile);
foreach (var state in Enum.GetValues(typeof(RequestState)).Cast<RequestState>())
{
if (state == RequestState.COUNT) break;
Console.Write(",{0}", layerTimes[(int)state].ElementAt(i).Times[(int)state]);
}
Console.WriteLine();
}
Console.WriteLine();
}
static void RunCommand(QuicState[] quicStates, string[] args)
{
if (args[0] == "--print" || args[0] == "-p")
{
@ -169,14 +884,18 @@ namespace QuicTrace
return;
}
foreach (var evt in quicState.Events)
foreach (var evt in quicStates[0].Events)
{
Console.WriteLine(evt);
}
}
else if (args[0] == "--report" || args[0] == "-r")
{
RunReport(quicState);
RunReport(quicStates[0]);
}
else if (args[0] == "--rps" || args[0] == "-s")
{
RunRpsAnalysis(quicStates);
}
else if (args[0] == "--help" || args[0] == "-h" || args[0] == "-?")
{
@ -192,7 +911,7 @@ namespace QuicTrace
static void Main(string[] args)
{
var i = 0;
string? traceFile = null;
var traceFiles = new List<string>();
//
// Process input args for initial 'option' values.
@ -201,11 +920,12 @@ namespace QuicTrace
{
if (args[i] == "--capture" || args[i] == "-c")
{
traceFile = CaptureLocalTrace();
var traceFile = CaptureLocalTrace();
if (traceFile == null)
{
return;
}
traceFiles.Add(traceFile);
}
else if (args[i] == "--file" || args[i] == "-f")
{
@ -216,7 +936,7 @@ namespace QuicTrace
}
++i;
traceFile = args[i];
traceFiles.Add(args[i]);
}
else if (args[i] == "--help" || args[i] == "-h" || args[i] == "-?")
{
@ -239,16 +959,16 @@ namespace QuicTrace
//
// Make sure we have something valid to process.
//
if (traceFile == null)
if (traceFiles.Count == 0)
{
Console.WriteLine("Missing valid option! Run '--help' for additional usage information!");
return;
}
//
// Process the trace file to generate the QUIC state.
// Process the trace files to generate the QUIC state.
//
var quicState = ProcessTraceFile(traceFile);
var quicStates = ProcessTraceFiles(traceFiles);
if (i == args.Length)
{
@ -268,7 +988,7 @@ namespace QuicTrace
if (input.Length > 0)
{
var cmdArgs = input.Split(" \t\r\n");
RunCommand(quicState, cmdArgs);
RunCommand(quicStates, cmdArgs);
}
}
}
@ -277,7 +997,7 @@ namespace QuicTrace
//
// Process specified commands inline.
//
RunCommand(quicState, args[i..]);
RunCommand(quicStates, args[i..]);
}
}
}