Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
101 changes: 78 additions & 23 deletions src/native/common/include/runtime-base/timing-internal.hh
Original file line number Diff line number Diff line change
Expand Up @@ -5,12 +5,10 @@
#include <chrono>
#include <cstdio>
#include <cstdlib>
#include <cstring>
#include <ctime>
#include <functional>
#include <limits>
#include <memory>
#include <stack>
#include <string>
#include <string_view>
#include <thread>

Expand Down Expand Up @@ -65,7 +63,7 @@ namespace xamarin::android {
time_point start;
time_point end;
TimingEventKind kind;
std::string *more_info = nullptr;
char *more_info = nullptr;
bool complete = false;
};

Expand All @@ -85,6 +83,14 @@ namespace xamarin::android {
TimingEventChunk *next = nullptr;
};

// A single entry on the per-thread stack of timing events which have been started but
// not yet ended.
struct OpenSequence
{
TimingEvent *event;
OpenSequence *next;
};

// defaults
static constexpr bool default_fast_timing_enabled = false;
static constexpr bool default_log_to_file = false;
Expand All @@ -96,6 +102,9 @@ namespace xamarin::android {
static constexpr std::string_view OPT_FILE_NAME { "filename=" };
static constexpr std::string_view OPT_TO_FILE { "to-file" };

// Enough to hold any value the `debug.mono.timing` property can carry, `PROP_VALUE_MAX` is 92.
static constexpr size_t MAX_TIMING_FILE_NAME_SIZE = 128uz;

protected:
void configure_for_use () noexcept
{
Expand All @@ -112,7 +121,7 @@ namespace xamarin::android {
while (chunk != nullptr) {
TimingEventChunk *next = chunk->next;
for (TimingEvent &event : chunk->events) {
delete event.more_info;
std::free (event.more_info);
}
std::free (chunk);
chunk = next;
Expand Down Expand Up @@ -207,7 +216,7 @@ namespace xamarin::android {
event.before_managed ? "[0/" : "[1/",
static_cast<unsigned int>(event.kind),
event_kind_description (event.kind),
event.more_info == nullptr ? "" : event.more_info->c_str (),
event.more_info == nullptr ? "" : event.more_info,
static_cast<unsigned long long>(chrono::duration_cast<chrono::seconds>(interval).count ()),
static_cast<unsigned long long>(chrono::duration_cast<chrono::milliseconds>(interval).count ()),
static_cast<unsigned long long>((interval % 1ms).count ())
Expand Down Expand Up @@ -268,7 +277,7 @@ namespace xamarin::android {
return;
}

if (skip_log_if_more_info_missing && (event.more_info == nullptr || event.more_info->empty ())) {
if (skip_log_if_more_info_missing && (event.more_info == nullptr || event.more_info[0] == '\0')) {
return;
}

Expand All @@ -283,7 +292,7 @@ namespace xamarin::android {
ev.start = get_time ();
ev.kind = kind;
ev.before_managed = MonodroidState::is_startup_in_progress ();
open_sequences.push (&ev);
push_sequence_event (&ev);
}

// If `uses_more_info` is `true`, the caller **MUST** call `add_more_info`, since the
Expand All @@ -309,17 +318,15 @@ namespace xamarin::android {
[[gnu::always_inline]]
void add_more_info (const char *str, size_t length) noexcept
{
store_more_info (new std::string (str, length));
store_more_info (duplicate_more_info (std::string_view { str, length }, {}));
}

// Builds the message from two parts, so that its exact length is known up front and the
// caller doesn't need a temporary buffer that the message might not fit into.
[[gnu::always_inline]]
void add_more_info (std::string_view const& first, std::string_view const& second) noexcept
{
auto *more_info = new std::string (first.data (), first.length ());
more_info->append (second);
store_more_info (more_info);
store_more_info (duplicate_more_info (first, second));
}

[[gnu::always_inline]]
Expand Down Expand Up @@ -389,13 +396,40 @@ namespace xamarin::android {
void dump_to_file (size_t entries) noexcept;
void dump (size_t entries, bool indent, std::function<void(std::string_view const&)> line_writer) noexcept;

// Returns a NUL-terminated copy of `first` and `second` concatenated, or `nullptr` if it
// cannot be allocated. Timing is a diagnostic facility, so a failure here only costs us the
// extra information attached to a single event and must not bring the application down.
[[gnu::always_inline]]
static auto duplicate_more_info (std::string_view const& first, std::string_view const& second) noexcept -> char*
{
size_t length = Helpers::add_with_overflow_check<size_t> (first.length (), second.length ());
auto *more_info = static_cast<char*> (std::malloc (Helpers::add_with_overflow_check<size_t> (length, 1uz)));
if (more_info == nullptr) [[unlikely]] {
return nullptr;
}

// `memcpy` must not be called with a `nullptr` source, not even for a zero length, and an
// empty `std::string_view` is allowed to have a `nullptr` data pointer.
if (!first.empty ()) {
std::memcpy (more_info, first.data (), first.length ());
}

if (!second.empty ()) {
std::memcpy (more_info + first.length (), second.data (), second.length ());
}

more_info[length] = '\0';

return more_info;
}

// Takes ownership of `more_info`.
[[gnu::always_inline]]
void store_more_info (std::string *more_info) noexcept
void store_more_info (char *more_info) noexcept
{
TimingEvent *event = pop_sequence_event ();
if (event == nullptr) [[unlikely]] {
delete more_info;
std::free (more_info);
log_warnf (LOG_TIMING, "FastTiming::add_more_info called without prior FastTiming::start_event called");
return;
}
Expand All @@ -406,23 +440,41 @@ namespace xamarin::android {
}

[[gnu::always_inline]]
auto get_sequence_event () noexcept -> TimingEvent*
static void push_sequence_event (TimingEvent *event) noexcept
{
auto *entry = static_cast<OpenSequence*> (std::malloc (sizeof (OpenSequence)));
if (entry == nullptr) [[unlikely]] {
Helpers::abort_application (LOG_TIMING, "Unable to allocate memory for an open timing sequence");
}

entry->event = event;
entry->next = open_sequences;
open_sequences = entry;
}

[[gnu::always_inline]]
static auto get_sequence_event () noexcept -> TimingEvent*
{
if (open_sequences.empty ()) [[unlikely]] {
OpenSequence *entry = open_sequences;
if (entry == nullptr) [[unlikely]] {
return nullptr;
}

return open_sequences.top ();
return entry->event;
}

[[gnu::always_inline]]
auto pop_sequence_event () noexcept -> TimingEvent*
static auto pop_sequence_event () noexcept -> TimingEvent*
{
TimingEvent *event = get_sequence_event ();
if (event != nullptr) [[likely]] {
open_sequences.pop ();
OpenSequence *entry = open_sequences;
if (entry == nullptr) [[unlikely]] {
return nullptr;
}

TimingEvent *event = entry->event;
open_sequences = entry->next;
std::free (entry);

return event;
}

Expand Down Expand Up @@ -550,9 +602,12 @@ namespace xamarin::android {
private:
std::atomic_size_t next_event_index = 0uz;
TimingEventChunk *first_event_chunk = nullptr;
std::unique_ptr<std::string> output_file_name{};
// The name is read from the `debug.mono.timing` system property, whose whole value is limited
// to `PROP_VALUE_MAX` (92) bytes, so a fixed buffer is always large enough. Keeping it inline
// also keeps `FastTiming` constant-initialized, so the global instance needs no guard variable.
char output_file_name[MAX_TIMING_FILE_NAME_SIZE] = {};

static inline thread_local std::stack<TimingEvent*> open_sequences;
static inline thread_local OpenSequence *open_sequences = nullptr;
static inline thread_local TimingEventChunk *cached_event_chunk = nullptr;
static inline thread_local size_t cached_event_chunk_index = 0uz;
static inline bool is_enabled = false;
Expand Down
17 changes: 12 additions & 5 deletions src/native/common/runtime-base/timing-internal.cc
Original file line number Diff line number Diff line change
Expand Up @@ -21,8 +21,8 @@ void FastTiming::really_initialize (bool log_immediately) noexcept

// TLS variables are initialized on first use, do it here so that we can have
// the overhead out of mind later, at least for the main thread.
open_sequences.push (0);
open_sequences.pop ();
push_sequence_event (nullptr);
pop_sequence_event ();

// Options in `debug.mono.timing` are relevant only when immediate logging is disabled
if (immediate_logging) {
Expand Down Expand Up @@ -54,7 +54,14 @@ void FastTiming::parse_options (const char *options) noexcept
if (param_length == OPT_TO_FILE.length () && strncmp (param, OPT_TO_FILE.data (), param_length) == 0) {
log_to_file = true;
} else if (param_length >= OPT_FILE_NAME.length () && strncmp (param, OPT_FILE_NAME.data (), OPT_FILE_NAME.length ()) == 0) {
output_file_name = std::make_unique<std::string> (param + OPT_FILE_NAME.length (), param_length - OPT_FILE_NAME.length ());
const char *name = param + OPT_FILE_NAME.length ();
size_t name_length = param_length - OPT_FILE_NAME.length ();
if (name_length >= sizeof (output_file_name)) [[unlikely]] {
log_warnf (LOG_TIMING, "Timing file name '%.*s' is too long, will use the default one", static_cast<int>(name_length), name);
} else {
memcpy (output_file_name, name, name_length);
output_file_name[name_length] = '\0';
}
} else if (param_length >= OPT_DURATION.length () && strncmp (param, OPT_DURATION.data (), OPT_DURATION.length ()) == 0) {
const char *duration = param + OPT_DURATION.length ();
char *end;
Expand All @@ -71,7 +78,7 @@ void FastTiming::parse_options (const char *options) noexcept
param = separator == nullptr ? nullptr : separator + 1;
}

if (output_file_name) {
if (output_file_name[0] != '\0') {
log_to_file = true;
}

Expand Down Expand Up @@ -232,7 +239,7 @@ void FastTiming::dump_to_file (size_t entries) noexcept
return;
}

std::string_view file_name = output_file_name == nullptr ? default_timing_file_name : *output_file_name;
std::string_view file_name = output_file_name[0] == '\0' ? default_timing_file_name : std::string_view { output_file_name };
char stack_buffer [Util::LocalPathBufferSize];
char *timing_log_path = Util::join_paths (stack_buffer, sizeof (stack_buffer), temporary_directory, file_name);

Expand Down
Loading