From 972601aa204f76a015788ecebcdaf6fa03eb5926 Mon Sep 17 00:00:00 2001 From: Sung Yoon Whang Date: Tue, 30 Mar 2021 23:13:43 -0700 Subject: [PATCH 1/7] allow >100KB events to be written --- src/native/eventpipe/ep-file.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/native/eventpipe/ep-file.c b/src/native/eventpipe/ep-file.c index 40acec0a8392c0..34b0cfc39d9190 100644 --- a/src/native/eventpipe/ep-file.c +++ b/src/native/eventpipe/ep-file.c @@ -317,7 +317,7 @@ ep_file_alloc ( instance->stream_writer = stream_writer; instance->format = format; - instance->event_block = ep_event_block_alloc (100 * 1024, format); + instance->event_block = ep_event_block_alloc (1024 * 1024, format); ep_raise_error_if_nok (instance->event_block != NULL); instance->metadata_block = ep_metadata_block_alloc (100 * 1024); From 77dd87433ba3edb7646fc6239205f5c7fb2d9619 Mon Sep 17 00:00:00 2001 From: Sung Yoon Whang Date: Thu, 1 Apr 2021 11:42:26 -0700 Subject: [PATCH 2/7] prevent events > 64KB from being written --- src/native/eventpipe/ep-buffer-manager.c | 3 + .../tracing/eventpipe/bigevent/bigevent.cs | 89 +++++++++++++++++++ .../eventpipe/bigevent/bigevent.csproj | 15 ++++ 3 files changed, 107 insertions(+) create mode 100644 src/tests/tracing/eventpipe/bigevent/bigevent.cs create mode 100644 src/tests/tracing/eventpipe/bigevent/bigevent.csproj diff --git a/src/native/eventpipe/ep-buffer-manager.c b/src/native/eventpipe/ep-buffer-manager.c index 74d8b542e726b5..8ada4ac6f07686 100644 --- a/src/native/eventpipe/ep-buffer-manager.c +++ b/src/native/eventpipe/ep-buffer-manager.c @@ -897,6 +897,9 @@ ep_buffer_manager_write_event ( // Before we pick a buffer, make sure the event is enabled. ep_return_false_if_nok (ep_event_is_enabled (ep_event)); + // Check that the payload size is less than 64 KB (max size for ETW events) + ep_return_false_if_nok (ep_event_payload_get_size (payload) <= 64 * 1024); + // Check to see an event thread was specified. If not, then use the current thread. if (event_thread == NULL) event_thread = thread; diff --git a/src/tests/tracing/eventpipe/bigevent/bigevent.cs b/src/tests/tracing/eventpipe/bigevent/bigevent.cs new file mode 100644 index 00000000000000..dd5294188efb17 --- /dev/null +++ b/src/tests/tracing/eventpipe/bigevent/bigevent.cs @@ -0,0 +1,89 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.Diagnostics.Tracing; +using System.IO; +using System.Linq; +using System.Threading; +using System.Threading.Tasks; +using System.Collections.Generic; +using Microsoft.Diagnostics.Tools.RuntimeClient; +using Microsoft.Diagnostics.Tracing; +using Tracing.Tests.Common; +using Microsoft.Diagnostics.Tracing.Parsers.Clr; + +namespace Tracing.Tests.BigEventsValidation +{ + + public sealed class BigEventSource : EventSource + { + private static string bigString = new String('a', 100 * 1024); + private static string smallString = new String('a', 10); + + private BigEventSource() + { + } + + public static BigEventSource Log = new BigEventSource(); + + public void BigEvent() + { + WriteEvent(1, bigString); + } + + public void SmallEvent() + { + WriteEvent(2, smallString); + } + } + + + public class BigEventsValidation + { + public static int Main(string[] args) + { + // This test tries to send a big event (>100KB) and checks that the app does not crash + // See https://github.com/dotnet/runtime/issues/50515 for the regression issue + var providers = new List() + { + new Provider("BigEventSource") + }; + + var configuration = new SessionConfiguration(circularBufferSizeMB: 1024, format: EventPipeSerializationFormat.NetTrace, providers: providers); + return IpcTraceTest.RunAndValidateEventCounts(_expectedEventCounts, _eventGeneratingAction, configuration, _Verify); + } + + private static Dictionary _expectedEventCounts = new Dictionary() + { + { "BigEventSource", -1 } + }; + + private static Action _eventGeneratingAction = () => + { + // Write 10 big events + for (int i = 0; i < 10; i++) + { + BigEventSource.Log.BigEvent(); + } + // Write 10 small events + for (int i = 0; i < 10; i++) + { + BigEventSource.Log.SmallEvent(); + } + }; + + private static Func> _Verify = (source) => + { + bool hasSmallEvent = false; + source.Dynamic.All += (TraceEvent data) => + { + if (data.EventName == "SmallEvent") + { + hasSmallEvent = true; + } + }; + return () => hasSmallEvent ? 100 : -1; + }; + } +} diff --git a/src/tests/tracing/eventpipe/bigevent/bigevent.csproj b/src/tests/tracing/eventpipe/bigevent/bigevent.csproj new file mode 100644 index 00000000000000..04bd61f8dc87e4 --- /dev/null +++ b/src/tests/tracing/eventpipe/bigevent/bigevent.csproj @@ -0,0 +1,15 @@ + + + .NETCoreApp + exe + BuildAndRun + true + 0 + true + true + + + + + + From 8e337549da76a9e3f028da3fe21364410fd15e1a Mon Sep 17 00:00:00 2001 From: Sung Yoon Whang Date: Mon, 5 Apr 2021 09:48:31 -0700 Subject: [PATCH 3/7] code review feedback --- src/native/eventpipe/ep-buffer-manager.c | 7 ++++++- src/native/eventpipe/ep-buffer-manager.h | 3 +++ src/native/eventpipe/ep-file.c | 2 +- 3 files changed, 10 insertions(+), 2 deletions(-) diff --git a/src/native/eventpipe/ep-buffer-manager.c b/src/native/eventpipe/ep-buffer-manager.c index 8ada4ac6f07686..82946f608a7dd6 100644 --- a/src/native/eventpipe/ep-buffer-manager.c +++ b/src/native/eventpipe/ep-buffer-manager.c @@ -787,6 +787,7 @@ ep_buffer_manager_alloc ( instance->session = session; instance->size_of_all_buffers = 0; + instance->num_oversized_events_dropped = 0; #ifdef EP_CHECKED_BUILD instance->num_buffers_allocated = 0; @@ -898,7 +899,11 @@ ep_buffer_manager_write_event ( ep_return_false_if_nok (ep_event_is_enabled (ep_event)); // Check that the payload size is less than 64 KB (max size for ETW events) - ep_return_false_if_nok (ep_event_payload_get_size (payload) <= 64 * 1024); + if (ep_event_payload_get_size (payload) > 64 * 1024) + { + ep_rt_atomic_inc_int64_t (&buffer_manager->num_oversized_events_dropped); + return false; + } // Check to see an event thread was specified. If not, then use the current thread. if (event_thread == NULL) diff --git a/src/native/eventpipe/ep-buffer-manager.h b/src/native/eventpipe/ep-buffer-manager.h index e9fe64d25e63fa..822b8450279f98 100644 --- a/src/native/eventpipe/ep-buffer-manager.h +++ b/src/native/eventpipe/ep-buffer-manager.h @@ -125,6 +125,9 @@ struct _EventPipeBufferManager_Internal { // The total amount of allocations we can do after one sequence // point before triggering the next one size_t sequence_point_alloc_budget; + // number of times an event was dropped due to it being too + // large to fit in the 64KB size limit + volatile int64_t num_oversized_events_dropped; #ifdef EP_CHECKED_BUILD volatile int64_t num_events_stored; diff --git a/src/native/eventpipe/ep-file.c b/src/native/eventpipe/ep-file.c index 34b0cfc39d9190..40acec0a8392c0 100644 --- a/src/native/eventpipe/ep-file.c +++ b/src/native/eventpipe/ep-file.c @@ -317,7 +317,7 @@ ep_file_alloc ( instance->stream_writer = stream_writer; instance->format = format; - instance->event_block = ep_event_block_alloc (1024 * 1024, format); + instance->event_block = ep_event_block_alloc (100 * 1024, format); ep_raise_error_if_nok (instance->event_block != NULL); instance->metadata_block = ep_metadata_block_alloc (100 * 1024); From 60339ee4ba05eed7ba423f22bcb914ba9c45513f Mon Sep 17 00:00:00 2001 From: Sung Yoon Whang Date: Mon, 5 Apr 2021 09:52:57 -0700 Subject: [PATCH 4/7] increment seq num --- src/native/eventpipe/ep-buffer-manager.c | 16 ++++++++++------ 1 file changed, 10 insertions(+), 6 deletions(-) diff --git a/src/native/eventpipe/ep-buffer-manager.c b/src/native/eventpipe/ep-buffer-manager.c index 82946f608a7dd6..55d96a0023a67e 100644 --- a/src/native/eventpipe/ep-buffer-manager.c +++ b/src/native/eventpipe/ep-buffer-manager.c @@ -902,6 +902,10 @@ ep_buffer_manager_write_event ( if (ep_event_payload_get_size (payload) > 64 * 1024) { ep_rt_atomic_inc_int64_t (&buffer_manager->num_oversized_events_dropped); + EP_SPIN_LOCK_ENTER (thread_lock, section1) + session_state = ep_thread_get_or_create_session_state (current_thread, session); + ep_thread_session_state_increment_sequence_number (session_state); + EP_SPIN_LOCK_EXIT (thread_lock, section1) return false; } @@ -925,7 +929,7 @@ ep_buffer_manager_write_event ( ep_rt_spin_lock_handle_t *thread_lock; thread_lock = ep_thread_get_rt_lock_ref (current_thread); - EP_SPIN_LOCK_ENTER (thread_lock, section1) + EP_SPIN_LOCK_ENTER (thread_lock, section2) session_state = ep_thread_get_or_create_session_state (current_thread, session); ep_raise_error_if_nok_holding_spin_lock (session_state != NULL, section1); @@ -939,7 +943,7 @@ ep_buffer_manager_write_event ( else alloc_new_buffer = true; } - EP_SPIN_LOCK_EXIT (thread_lock, section1) + EP_SPIN_LOCK_EXIT (thread_lock, section2) // alloc_new_buffer is reused below to detect if overflow happened, so cache it here to see if we should // signal the reader thread @@ -959,15 +963,15 @@ ep_buffer_manager_write_event ( // This lock looks unnecessary for the sequence number, but didn't want to // do a broader refactoring to take it out. If it shows up as a perf // problem then we should. - EP_SPIN_LOCK_ENTER (thread_lock, section2) + EP_SPIN_LOCK_ENTER (thread_lock, section3) ep_thread_session_state_increment_sequence_number (session_state); - EP_SPIN_LOCK_EXIT (thread_lock, section2) + EP_SPIN_LOCK_EXIT (thread_lock, section3) } else { current_thread = ep_thread_get (); EP_ASSERT (current_thread != NULL); thread_lock = ep_thread_get_rt_lock_ref (current_thread); - EP_SPIN_LOCK_ENTER (thread_lock, section3) + EP_SPIN_LOCK_ENTER (thread_lock, section4) ep_thread_session_state_set_write_buffer (session_state, buffer); // Try to write the event after we allocated a buffer. // This is the first time if the thread had no buffers before the call to this function. @@ -975,7 +979,7 @@ ep_buffer_manager_write_event ( alloc_new_buffer = !ep_buffer_write_event (buffer, event_thread, session, ep_event, payload, activity_id, related_activity_id, stack); EP_ASSERT(!alloc_new_buffer); ep_thread_session_state_increment_sequence_number (session_state); - EP_SPIN_LOCK_EXIT (thread_lock, section3) + EP_SPIN_LOCK_EXIT (thread_lock, section4) } } From 2efcc894a33f5cd3edc53469b2c9cc05cb4eab3f Mon Sep 17 00:00:00 2001 From: Sung Yoon Whang Date: Mon, 5 Apr 2021 09:58:34 -0700 Subject: [PATCH 5/7] fix build --- src/native/eventpipe/ep-buffer-manager.c | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/src/native/eventpipe/ep-buffer-manager.c b/src/native/eventpipe/ep-buffer-manager.c index 55d96a0023a67e..a020174b4f5e2c 100644 --- a/src/native/eventpipe/ep-buffer-manager.c +++ b/src/native/eventpipe/ep-buffer-manager.c @@ -902,6 +902,8 @@ ep_buffer_manager_write_event ( if (ep_event_payload_get_size (payload) > 64 * 1024) { ep_rt_atomic_inc_int64_t (&buffer_manager->num_oversized_events_dropped); + EventPipeThread *current_thread = ep_thread_get(); + ep_rt_spin_lock_handle_t *thread_lock = ep_thread_get_rt_lock_ref (current_thread); EP_SPIN_LOCK_ENTER (thread_lock, section1) session_state = ep_thread_get_or_create_session_state (current_thread, session); ep_thread_session_state_increment_sequence_number (session_state); @@ -931,7 +933,7 @@ ep_buffer_manager_write_event ( EP_SPIN_LOCK_ENTER (thread_lock, section2) session_state = ep_thread_get_or_create_session_state (current_thread, session); - ep_raise_error_if_nok_holding_spin_lock (session_state != NULL, section1); + ep_raise_error_if_nok_holding_spin_lock (session_state != NULL, section2); buffer = ep_thread_session_state_get_write_buffer (session_state); if (!buffer) { From baf67b5aafd629d1b769b16e79f3dcb291a57dab Mon Sep 17 00:00:00 2001 From: Sung Yoon Whang Date: Mon, 5 Apr 2021 10:34:39 -0700 Subject: [PATCH 6/7] fix build on clang --- src/native/eventpipe/ep-buffer-manager.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/native/eventpipe/ep-buffer-manager.c b/src/native/eventpipe/ep-buffer-manager.c index a020174b4f5e2c..c0febe06c3bf4f 100644 --- a/src/native/eventpipe/ep-buffer-manager.c +++ b/src/native/eventpipe/ep-buffer-manager.c @@ -888,6 +888,8 @@ ep_buffer_manager_write_event ( bool alloc_new_buffer = false; EventPipeBuffer *buffer = NULL; EventPipeThreadSessionState *session_state = NULL; + EventPipeStackContents stack_contents; + EventPipeStackContents *current_stack_contents = nullptr; EP_ASSERT (buffer_manager != NULL); EP_ASSERT (ep_event != NULL); @@ -915,8 +917,6 @@ ep_buffer_manager_write_event ( if (event_thread == NULL) event_thread = thread; - EventPipeStackContents stack_contents; - EventPipeStackContents *current_stack_contents; current_stack_contents = ep_stack_contents_init (&stack_contents); if (stack == NULL && ep_event_get_need_stack (ep_event) && !ep_session_get_rundown_enabled (session)) { ep_walk_managed_stack_for_current_thread (current_stack_contents); From a38660c1d8cd4b4e8e52a5dc1b93a112b060e558 Mon Sep 17 00:00:00 2001 From: Sung Yoon Whang Date: Mon, 5 Apr 2021 12:30:00 -0700 Subject: [PATCH 7/7] fix mono build --- src/native/eventpipe/ep-buffer-manager.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/native/eventpipe/ep-buffer-manager.c b/src/native/eventpipe/ep-buffer-manager.c index c0febe06c3bf4f..2355d1361ae7e3 100644 --- a/src/native/eventpipe/ep-buffer-manager.c +++ b/src/native/eventpipe/ep-buffer-manager.c @@ -889,7 +889,7 @@ ep_buffer_manager_write_event ( EventPipeBuffer *buffer = NULL; EventPipeThreadSessionState *session_state = NULL; EventPipeStackContents stack_contents; - EventPipeStackContents *current_stack_contents = nullptr; + EventPipeStackContents *current_stack_contents = NULL; EP_ASSERT (buffer_manager != NULL); EP_ASSERT (ep_event != NULL);