From 9382e9af75f9a9cbcd2fe4a4bb2d480cb17b7bd7 Mon Sep 17 00:00:00 2001 From: Mike Date: Tue, 17 Mar 2026 11:40:59 -0700 Subject: [PATCH 01/14] realm: add support for background work profiling that dumps log files for background work items --- src/CMakeLists.txt | 1 + src/realm/activemsg.cc | 23 ++ src/realm/activemsg.h | 3 + src/realm/bgwork.cc | 18 +- src/realm/bgwork.h | 3 + src/realm/bgwork_profile.cc | 443 ++++++++++++++++++++++++++++++++ src/realm/bgwork_profile.h | 222 ++++++++++++++++ src/realm/bgwork_profile.inl | 240 +++++++++++++++++ src/realm/cuda/cuda_internal.cc | 41 +++ src/realm/cuda/cuda_internal.h | 21 ++ src/realm/cuda/cuda_module.cc | 39 ++- src/realm/deppart/partitions.cc | 16 ++ src/realm/deppart/partitions.h | 2 + src/realm/hip/hip_internal.cc | 10 + src/realm/hip/hip_internal.h | 21 ++ src/realm/hip/hip_module.cc | 39 ++- src/realm/runtime_impl.cc | 13 + src/realm/runtime_impl.h | 6 + src/realm/transfer/channel.h | 4 + src/realm/transfer/channel.inl | 13 + tests/CMakeLists.txt | 2 + tests/bgwork_profile.cc | 440 +++++++++++++++++++++++++++++++ 22 files changed, 1611 insertions(+), 9 deletions(-) create mode 100644 src/realm/bgwork_profile.cc create mode 100644 src/realm/bgwork_profile.h create mode 100644 src/realm/bgwork_profile.inl create mode 100644 tests/bgwork_profile.cc diff --git a/src/CMakeLists.txt b/src/CMakeLists.txt index 7054eb2e94b..4770e27f394 100644 --- a/src/CMakeLists.txt +++ b/src/CMakeLists.txt @@ -23,6 +23,7 @@ set(REALM_SOURCES timers.cc utils.cc bgwork.cc + bgwork_profile.cc comp_queue_impl.cc event_impl.cc barrier_impl.cc diff --git a/src/realm/activemsg.cc b/src/realm/activemsg.cc index 671db37ced4..62a90ae0214 100644 --- a/src/realm/activemsg.cc +++ b/src/realm/activemsg.cc @@ -19,6 +19,7 @@ #include "realm/atomics.h" #include "realm/activemsg.h" +#include "realm/bgwork_profile.h" #include "realm/mutex.h" #include "realm/cmdline.h" #include "realm/logging.h" @@ -190,6 +191,8 @@ namespace Realm { // at least one of the two above must be non-null assert((e.handler != 0) || (e.handler_notimeout != 0)); e.handler_inline = nextreg->get_handler_inline(); + e.profile_sub_item_id = 0; + e.profile_id_registered = false; handlers.push_back(e); } @@ -754,14 +757,28 @@ namespace Realm { long long t_start = 0; bool do_profile = Config::profile_activemsg_handlers; + // lazily register this handler for fine-grained profiling + if(bgwork_profiler.get_level() >= 2 && + !current_msg->handler->profile_id_registered) { + current_msg->handler->profile_sub_item_id = bgwork_profiler.register_sub_item( + BGWP_SUB_AM_HANDLER, current_msg->handler->name); + current_msg->handler->profile_id_registered = true; + } + // do we have a handler that understands time limits? if(current_msg->handler->handler != 0) { if(do_profile) t_start = Clock::current_time_in_nanoseconds(); + if(current_msg->handler->profile_id_registered) + bgwork_profile_fine_begin(current_msg->handler->profile_sub_item_id); + (current_msg->handler->handler)(current_msg->sender, current_msg->hdr, current_msg->payload, current_msg->payload_size, work_until); + + if(current_msg->handler->profile_id_registered) + bgwork_profile_fine_end(); } else { // estimate how long this handler will take, clamping at a // semi-arbitrary 20us @@ -788,9 +805,15 @@ namespace Realm { do_profile = true; t_start = Clock::current_time_in_nanoseconds(); + if(current_msg->handler->profile_id_registered) + bgwork_profile_fine_begin(current_msg->handler->profile_sub_item_id); + (current_msg->handler->handler_notimeout)(current_msg->sender, current_msg->hdr, current_msg->payload, current_msg->payload_size); + + if(current_msg->handler->profile_id_registered) + bgwork_profile_fine_end(); } long long t_end = 0; diff --git a/src/realm/activemsg.h b/src/realm/activemsg.h index 4d76f76fe30..b9eed548dfe 100644 --- a/src/realm/activemsg.h +++ b/src/realm/activemsg.h @@ -271,6 +271,9 @@ namespace Realm { ActiveMessageHandlerStats stats; std::optional extract_frag_info; + + uint16_t profile_sub_item_id; + bool profile_id_registered; }; HandlerEntry *lookup_message_handler(MessageID id); diff --git a/src/realm/bgwork.cc b/src/realm/bgwork.cc index 4990464374f..1fca8d8f7f0 100644 --- a/src/realm/bgwork.cc +++ b/src/realm/bgwork.cc @@ -18,6 +18,7 @@ // manager for background work that can be performed by available threads #include "realm/bgwork.h" +#include "realm/bgwork_profile.h" #include "realm/timers.h" #include "realm/logging.h" #include "realm/utils.h" @@ -78,6 +79,8 @@ namespace Realm { void BackgroundWorkThread::main_loop(void) { + bgwork_profile_thread_init(); + BackgroundWorkManager::Worker worker; worker.set_manager(manager); worker.set_numa_domain(numa_domain); @@ -378,6 +381,8 @@ namespace Realm { << " slot=" << index << " name=" << name << " domain=" << numa_domain << " timeslice=" << min_timeslice_needed; + if(bgwork_profiler.get_level() > 0) + bgwork_profiler.register_work_item(static_cast(index), name); } // mark this work item as active (i.e. having work to do) @@ -472,6 +477,10 @@ namespace Realm { bool BackgroundWorkManager::Worker::do_work(long long max_time_in_ns, atomic *interrupt_flag) { + // lazily initialize profiling state for this thread + if(bgwork_profiler.get_level() > 0 && !tl_bgwork_profile) + bgwork_profile_thread_init(); + // set our deadline for returning long long work_until_time = ((max_time_in_ns > 0) @@ -563,6 +572,7 @@ namespace Realm { log_bgwork.debug() << "work claimed: manager=" << manager << " slot=" << slot << " worker=" << this; long long t_start = Clock::current_time_in_nanoseconds(true /*absolute*/); + bgwork_profile_begin(static_cast(slot)); // don't spend more than 1ms on any single task before going on to the // next thing - TODO: pull this out as a config variable long long t_quantum = (manager->cfg.work_item_timeslice + t_start); @@ -605,13 +615,7 @@ namespace Realm { } else break; } -#ifdef REALM_BGWORK_PROFILE - long long t_stop = Clock::current_time_in_nanoseconds(true /*absolute*/); - long long elapsed = t_stop - t_start; - long long overshoot = ((t_stop > t_quantum) ? (t_stop - t_quantum) : 0); - log_bgwork.print() << "work: slot=" << slot << " elapsed=" << elapsed - << " overshoot=" << overshoot; -#endif + bgwork_profile_end(); // we're done with this slot for now manager->work_item_usecounts[slot].fetch_sub_acqrel(1); diff --git a/src/realm/bgwork.h b/src/realm/bgwork.h index 1a5de477a14..5073d057c40 100644 --- a/src/realm/bgwork.h +++ b/src/realm/bgwork.h @@ -140,6 +140,9 @@ namespace Realm { // completed (or if 'make_active' has already been called) virtual bool do_work(TimeLimit work_until) = 0; + // returns the slot index assigned by the background work manager + unsigned get_slot() const { return index; } + protected: friend class BackgroundWorkManager::Worker; diff --git a/src/realm/bgwork_profile.cc b/src/realm/bgwork_profile.cc new file mode 100644 index 00000000000..c190b9d8f24 --- /dev/null +++ b/src/realm/bgwork_profile.cc @@ -0,0 +1,443 @@ +/* + * Copyright 2026 Stanford University, NVIDIA Corporation + * SPDX-License-Identifier: Apache-2.0 + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +// Background work profiling manager implementation + +#include "realm/bgwork_profile.h" +#include "realm/timers.h" +#include "realm/logging.h" +#include "realm/network.h" + +#include +#include +#include +#include + +#ifdef REALM_ON_WINDOWS +#include +#include +#else +#include +#include +#endif + +#ifdef REALM_BGWORK_PROFILE_USE_ZLIB +#include +#endif + +namespace Realm { + + Logger log_bgwork_profile("bgwork_profile"); + + thread_local BgWorkProfileState *tl_bgwork_profile = nullptr; + + BgWorkProfileManager bgwork_profiler; + + BgWorkProfileManager::BgWorkProfileManager() + : profile_level(0) + , initialized(false) + , max_buffer_bytes(1ULL << 30) // 1GB default + , fd(-1) + , node_id(0) + , next_sub_item_id(0) + , free_blocks(nullptr) + , completed_head(nullptr) + , completed_tail(nullptr) + , buffered_bytes(0) + , next_sequence(0) + {} + + BgWorkProfileManager::~BgWorkProfileManager() + { + // free any remaining blocks in the free list + while(free_blocks) { + ProfileBlock *next = free_blocks->next; + delete free_blocks; + free_blocks = next; + } + } + + void BgWorkProfileManager::set_level(int level) { profile_level = level; } + + void BgWorkProfileManager::set_logfile(const std::string &filename) + { + logfile_pattern = filename; + } + + void BgWorkProfileManager::set_bufsize(size_t megabytes) + { + max_buffer_bytes = (megabytes == 0) ? SIZE_MAX : megabytes * (1ULL << 20); + } + + int BgWorkProfileManager::get_level() const { return profile_level; } + + void BgWorkProfileManager::initialize(uint32_t _node_id) + { + if(profile_level == 0) + return; + + node_id = _node_id; + + // determine output filename + std::string filename = logfile_pattern; + if(filename.empty()) + filename = "bgwork_profile_%.bin"; + + // replace % with node ID + size_t pct = filename.find('%'); + if(pct != std::string::npos) { + char buf[32]; + snprintf(buf, sizeof(buf), "%u", node_id); + filename.replace(pct, 1, buf); + } else if(Network::max_node_id > 0) { + log_bgwork_profile.fatal() + << "multi-node run requires '%' in bgwork profile filename: " << filename; + abort(); + } + + // open output file +#ifdef REALM_ON_WINDOWS + fd = _open(filename.c_str(), _O_WRONLY | _O_CREAT | _O_TRUNC | _O_BINARY, 0644); +#else + fd = open(filename.c_str(), O_WRONLY | O_CREAT | O_TRUNC, 0644); +#endif + if(fd < 0) { + log_bgwork_profile.fatal() << "failed to open bgwork profile file: " << filename; + abort(); + } + + log_bgwork_profile.info() << "bgwork profiling enabled: level=" << profile_level + << " file=" << filename + << " bufsize=" << (max_buffer_bytes >> 20) << "MB"; + + // Write header with placeholder counts/offset. Data blocks are appended + // starting at offset HEADER_SIZE. Descriptor tables and final header + // patch happen at shutdown. + write_file_header(); + + initialized = true; + } + + void BgWorkProfileManager::shutdown() + { + if(!initialized) + return; + + // flush all thread-local blocks + { + AutoLock<> al(thread_mutex); + for(BgWorkProfileState *state : thread_states) { + if(state->current_block) { + if(state->current_block->num_records > 0) { + AutoLock<> bl(block_mutex); + ProfileBlock *block = state->current_block; + if(completed_tail) { + completed_tail->next = block; + } else { + completed_head = block; + } + completed_tail = block; + block->next = nullptr; + buffered_bytes += block->used; + } else { + // empty block goes back to free list + AutoLock<> bl(block_mutex); + state->current_block->next = free_blocks; + free_blocks = state->current_block; + } + state->current_block = nullptr; + } + // disable profiling for this thread + // (the thread_local pointer was set to state, but we can't clear + // other threads' TLS - they should have stopped by now) + } + } + + // Flush all remaining in-memory data blocks to disk + flush_all_blocks(); + + // Record current file position — this is where descriptor tables start + uint64_t desc_offset = lseek(fd, 0, SEEK_CUR); + + // Write descriptor tables (now complete) at end of file + write_descriptor_tables(); + + // Patch header with final counts and descriptor offset + { + AutoLock<> al(desc_mutex); + uint32_t work_count = static_cast(work_item_descs.size()); + uint32_t sub_count = static_cast(sub_item_descs.size()); + lseek(fd, 20, SEEK_SET); + write(fd, &work_count, sizeof(work_count)); + write(fd, &sub_count, sizeof(sub_count)); + write(fd, &desc_offset, sizeof(desc_offset)); + lseek(fd, 0, SEEK_END); + } + + // close file + if(fd >= 0) { +#ifdef REALM_ON_WINDOWS + _close(fd); +#else + close(fd); +#endif + fd = -1; + } + + log_bgwork_profile.info() << "bgwork profiling shutdown complete"; + initialized = false; + } + + void BgWorkProfileManager::register_work_item(uint16_t slot, const std::string &name) + { + AutoLock<> al(desc_mutex); + // check for duplicate + for(const auto &d : work_item_descs) { + if(d.slot == slot) + return; + } + work_item_descs.push_back({slot, name}); + log_bgwork_profile.debug() << "registered work item: slot=" << slot + << " name=" << name; + } + + uint16_t BgWorkProfileManager::register_sub_item(uint8_t type, const std::string &name) + { + AutoLock<> al(desc_mutex); + uint16_t id = next_sub_item_id++; + sub_item_descs.push_back({id, type, name}); + log_bgwork_profile.debug() << "registered sub-item: id=" << id + << " type=" << (int)type << " name=" << name; + return id; + } + + ProfileBlock *BgWorkProfileManager::alloc_block(uint64_t thread_id) + { + AutoLock<> al(block_mutex); + + ProfileBlock *block; + if(free_blocks) { + block = free_blocks; + free_blocks = block->next; + } else { + block = new ProfileBlock; + } + + block->used = 0; + block->base_timestamp = 0; + block->num_records = 0; + block->thread_id = thread_id; + block->sequence = next_sequence++; + block->next = nullptr; + + return block; + } + + void BgWorkProfileManager::complete_block(ProfileBlock *block) + { + bool need_flush = false; + + { + AutoLock<> al(block_mutex); + + if(completed_tail) { + completed_tail->next = block; + } else { + completed_head = block; + } + completed_tail = block; + block->next = nullptr; + buffered_bytes += block->used; + + need_flush = (buffered_bytes >= max_buffer_bytes); + } + + // Flush half the buffer to keep memory bounded while retaining some + // buffering to reduce write syscall frequency + if(need_flush) + flush_blocks_to_disk(max_buffer_bytes / 2); + } + + void BgWorkProfileManager::register_thread_state(BgWorkProfileState *state) + { + AutoLock<> al(thread_mutex); + thread_states.push_back(state); + } + + void BgWorkProfileManager::write_file_header() + { + // header: magic(4) + version(2) + flags(2) + node_id(4) + zero_time(8) + + // work_item_count(4) + sub_item_count(4) + desc_offset(8) = 36 bytes + uint8_t header[HEADER_SIZE]; + uint8_t *p = header; + + memcpy(p, BGWP_MAGIC, 4); + p += 4; + + uint16_t version = BGWP_VERSION; + memcpy(p, &version, 2); + p += 2; + + uint16_t flags = 0; + if(profile_level >= 2) + flags |= BGWP_FLAG_HAS_FINE; + memcpy(p, &flags, 2); + p += 2; + + memcpy(p, &node_id, 4); + p += 4; + + int64_t zero_time = Clock::get_zero_time(); + memcpy(p, &zero_time, 8); + p += 8; + + // descriptor counts and offset will be patched at shutdown + uint32_t zero32 = 0; + uint64_t zero64 = 0; + memcpy(p, &zero32, 4); + p += 4; // work item count + memcpy(p, &zero32, 4); + p += 4; // sub item count + memcpy(p, &zero64, 8); + p += 8; // descriptor table offset + + ssize_t written = write(fd, header, sizeof(header)); + (void)written; + } + + void BgWorkProfileManager::write_descriptor_tables() + { + AutoLock<> al(desc_mutex); + + // write work item descriptors + for(const auto &d : work_item_descs) { + uint16_t slot = d.slot; + uint16_t name_len = static_cast(d.name.size()); + write(fd, &slot, sizeof(slot)); + write(fd, &name_len, sizeof(name_len)); + write(fd, d.name.data(), name_len); + } + + // write sub-item descriptors + for(const auto &d : sub_item_descs) { + uint16_t id = d.id; + uint8_t type = d.type; + uint16_t name_len = static_cast(d.name.size()); + write(fd, &id, sizeof(id)); + write(fd, &type, sizeof(type)); + write(fd, &name_len, sizeof(name_len)); + write(fd, d.name.data(), name_len); + } + } + + void BgWorkProfileManager::flush_blocks_to_disk(size_t target_size) + { + while(true) { + ProfileBlock *block = nullptr; + { + AutoLock<> al(block_mutex); + if(!completed_head || buffered_bytes <= target_size) + return; + block = completed_head; + completed_head = block->next; + if(!completed_head) + completed_tail = nullptr; + buffered_bytes -= block->used; + } + + // write block header fields individually to avoid padding + uint64_t bh_thread_id = block->thread_id; + uint32_t bh_sequence = block->sequence; + uint32_t bh_record_count = block->num_records; + int64_t bh_base_timestamp = block->base_timestamp; + uint32_t bh_data_size = block->used; + uint32_t bh_compressed_size = 0; + +#ifdef REALM_BGWORK_PROFILE_USE_ZLIB + // try to compress the block + uLongf compressed_bound = compressBound(block->used); + std::vector compressed(compressed_bound); + int zret = compress2(compressed.data(), &compressed_bound, block->data, block->used, + Z_DEFAULT_COMPRESSION); + if(zret == Z_OK && compressed_bound < block->used) { + bh_compressed_size = static_cast(compressed_bound); + } +#endif + + write(fd, &bh_thread_id, 8); + write(fd, &bh_sequence, 4); + write(fd, &bh_record_count, 4); + write(fd, &bh_base_timestamp, 8); + write(fd, &bh_data_size, 4); + write(fd, &bh_compressed_size, 4); + +#ifdef REALM_BGWORK_PROFILE_USE_ZLIB + if(bh_compressed_size > 0) + write(fd, compressed.data(), bh_compressed_size); + else + write(fd, block->data, block->used); +#else + write(fd, block->data, block->used); +#endif + + // return block to free list + { + AutoLock<> al(block_mutex); + block->next = free_blocks; + free_blocks = block; + } + } + } + + void BgWorkProfileManager::flush_all_blocks() { flush_blocks_to_disk(0); } + + void bgwork_profile_thread_init() + { + if(bgwork_profiler.get_level() == 0) + return; + if(tl_bgwork_profile) + return; // already initialized + + BgWorkProfileState *state = new BgWorkProfileState; + state->current_block = nullptr; + state->last_timestamp = 0; + // use hash of std::thread::id as our thread identifier + state->thread_id = + static_cast(std::hash{}(std::this_thread::get_id())); + + tl_bgwork_profile = state; + bgwork_profiler.register_thread_state(state); + } + + void bgwork_profile_thread_fini() + { + BgWorkProfileState *state = tl_bgwork_profile; + if(!state) + return; + + // flush current block if it has data + if(state->current_block && state->current_block->num_records > 0) { + bgwork_profiler.complete_block(state->current_block); + state->current_block = nullptr; + } + + tl_bgwork_profile = nullptr; + // note: state is not freed here - the manager owns the pointer list + // and will clean up at shutdown + } + +}; // namespace Realm diff --git a/src/realm/bgwork_profile.h b/src/realm/bgwork_profile.h new file mode 100644 index 00000000000..14d6033e8b8 --- /dev/null +++ b/src/realm/bgwork_profile.h @@ -0,0 +1,222 @@ +/* + * Copyright 2026 Stanford University, NVIDIA Corporation + * SPDX-License-Identifier: Apache-2.0 + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +// Background work profiling for Realm +// +// Binary file format specification (RBWP = Realm Background Work Profile): +// +// FILE HEADER (36 bytes, written at start, counts/offset patched at shutdown): +// Magic: 4 bytes "RBWP" +// Version: uint16_t (currently 1) +// Flags: uint16_t (bit 0 = has fine-grained data) +// Node ID: uint32_t +// Clock zero time: int64_t (nanoseconds, absolute) +// Work item descriptor count: uint32_t (patched at shutdown) +// Sub-item descriptor count: uint32_t (patched at shutdown) +// Descriptor table offset: uint64_t (patched at shutdown) +// +// DATA BLOCKS (appended during run and at shutdown, starting at offset 36): +// Block header: +// Thread ID: uint64_t +// Block sequence: uint32_t +// Record count: uint32_t +// Base timestamp: int64_t +// Data size: uint32_t (uncompressed) +// Compressed size: uint32_t (0 = uncompressed) +// Block data: uint8_t[compressed_size or data_size] +// +// DESCRIPTOR TABLES (written at shutdown, at descriptor_table_offset): +// +// WORK ITEM DESCRIPTOR TABLE: +// For each work item: +// Slot: uint16_t +// Name length: uint16_t +// Name: char[name_length] (not null-terminated) +// +// SUB-ITEM DESCRIPTOR TABLE (follows work item table): +// For each sub-item: +// ID: uint16_t +// Type: uint8_t (0=AM_HANDLER, 1=XFER_CHANNEL, 2=DEPPART_OP, 3=GPU_REAP) +// Name length: uint16_t +// Name: char[name_length] (not null-terminated) +// +// RECORDS within a block (variable-length, packed): +// Timestamp delta: 2, 4, or 8 bytes (see encoding below) +// Record type: uint8_t +// Payload: depends on record type +// +// Timestamp delta encoding: +// If delta fits in 15 bits: 2 bytes, high bit 0: 0bbb bbbb bbbb bbbb +// If delta fits in 30 bits: 4 bytes, high bits 10: 10bb bbbb ... bbbb bbbb +// Otherwise: 8 bytes, high bits 11: 11xx xxxx + 7 more bytes +// (stores absolute timestamp, not delta) +// +// Record types and payloads: +// COARSE_BEGIN (0x01): uint8_t slot +// COARSE_END (0x02): (no payload) +// FINE_BEGIN (0x11): uint16_t sub_item_id +// FINE_END (0x12): (no payload) +// GPU_WORK (0x21): uint64_t proc_id, uint8_t slot, int64_t start, int64_t stop + +#ifndef REALM_BGWORK_PROFILE_H +#define REALM_BGWORK_PROFILE_H + +#include "realm/realm_config.h" +#include "realm/mutex.h" +#include "realm/atomics.h" + +#include +#include +#include +#include + +namespace Realm { + + // Record type constants + enum BgWorkProfileRecordType : uint8_t + { + BGWP_COARSE_BEGIN = 0x01, + BGWP_COARSE_END = 0x02, + BGWP_FINE_BEGIN = 0x11, + BGWP_FINE_END = 0x12, + BGWP_GPU_WORK = 0x21, + }; + + // Sub-item type constants + enum BgWorkProfileSubItemType : uint8_t + { + BGWP_SUB_AM_HANDLER = 0, + BGWP_SUB_XFER_CHANNEL = 1, + BGWP_SUB_DEPPART_OP = 2, + BGWP_SUB_GPU_REAP = 3, + }; + + // File format constants + static const char BGWP_MAGIC[4] = {'R', 'B', 'W', 'P'}; + static const uint16_t BGWP_VERSION = 1; + static const uint16_t BGWP_FLAG_HAS_FINE = 0x0001; + + struct ProfileBlock { + static const size_t BLOCK_SIZE = 16384; // 16KB + uint8_t data[BLOCK_SIZE]; + uint32_t used; + int64_t base_timestamp; + uint32_t num_records; + uint64_t thread_id; + uint32_t sequence; + ProfileBlock *next; + }; + + struct BgWorkProfileState { + ProfileBlock *current_block; + int64_t last_timestamp; // for delta encoding + uint64_t thread_id; + }; + + // thread-local pointer: null when profiling is disabled + extern thread_local BgWorkProfileState *tl_bgwork_profile; + + struct BgWorkItemDescriptor { + uint16_t slot; + std::string name; + }; + + struct BgWorkSubItemDescriptor { + uint16_t id; + uint8_t type; + std::string name; + }; + + class BgWorkProfileManager { + public: + BgWorkProfileManager(); + ~BgWorkProfileManager(); + + // configuration (called before initialize) + void set_level(int level); + void set_logfile(const std::string &filename); + void set_bufsize(size_t megabytes); + + // returns the configured profiling level (0, 1, or 2) + int get_level() const; + + // lifecycle + void initialize(uint32_t node_id); + void shutdown(); + + // descriptor registration (called during module init, before recording starts) + void register_work_item(uint16_t slot, const std::string &name); + uint16_t register_sub_item(uint8_t type, const std::string &name); + + // block management (called by recording functions) + ProfileBlock *alloc_block(uint64_t thread_id); + void complete_block(ProfileBlock *block); + + // thread state management + void register_thread_state(BgWorkProfileState *state); + + private: + void write_file_header(); + void write_descriptor_tables(); + void flush_blocks_to_disk(size_t target_size); + void flush_all_blocks(); + + static const size_t HEADER_SIZE = 36; + + int profile_level; + std::string logfile_pattern; + bool initialized; + size_t max_buffer_bytes; + + // file state + int fd; + uint32_t node_id; + + // descriptors + Mutex desc_mutex; + std::vector work_item_descs; + std::vector sub_item_descs; + uint16_t next_sub_item_id; + + // block pool and completed list + Mutex block_mutex; + ProfileBlock *free_blocks; + ProfileBlock *completed_head; + ProfileBlock *completed_tail; + size_t buffered_bytes; + uint32_t next_sequence; + + // thread states (for shutdown flushing) + Mutex thread_mutex; + std::vector thread_states; + }; + + // global instance + extern BgWorkProfileManager bgwork_profiler; + + // call at thread entry to set up thread-local profiling state + // safe to call when profiling is disabled (does nothing) + void bgwork_profile_thread_init(); + + // call at thread exit to flush thread-local block + void bgwork_profile_thread_fini(); + +}; // namespace Realm + +#include "realm/bgwork_profile.inl" + +#endif // REALM_BGWORK_PROFILE_H diff --git a/src/realm/bgwork_profile.inl b/src/realm/bgwork_profile.inl new file mode 100644 index 00000000000..784e8e5eead --- /dev/null +++ b/src/realm/bgwork_profile.inl @@ -0,0 +1,240 @@ +/* + * Copyright 2026 Stanford University, NVIDIA Corporation + * SPDX-License-Identifier: Apache-2.0 + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +// inline recording functions for background work profiling +// these are the hot path - every call checks tl_bgwork_profile first + +#ifndef REALM_BGWORK_PROFILE_INL +#define REALM_BGWORK_PROFILE_INL + +#include "realm/timers.h" + +#include + +namespace Realm { + + // Timestamp delta encoding: + // 15-bit: 2 bytes, MSB=0 + // 30-bit: 4 bytes, MSB=10 + // 64-bit: 8 bytes, MSB=11 (stores absolute timestamp) + inline size_t bgwork_profile_encode_timestamp(uint8_t *buf, int64_t delta, + int64_t absolute) + { + if(delta >= 0 && delta < (1 << 15)) { + uint16_t val = static_cast(delta); + buf[0] = (val >> 8) & 0x7F; + buf[1] = val & 0xFF; + return 2; + } else if(delta >= 0 && delta < (1LL << 30)) { + uint32_t val = static_cast(delta) | 0x80000000U; + buf[0] = (val >> 24) & 0xFF; + buf[1] = (val >> 16) & 0xFF; + buf[2] = (val >> 8) & 0xFF; + buf[3] = val & 0xFF; + return 4; + } else { + // 8-byte encoding: store absolute timestamp + uint64_t val = static_cast(absolute); + buf[0] = 0xC0 | ((val >> 56) & 0x3F); + buf[1] = (val >> 48) & 0xFF; + buf[2] = (val >> 40) & 0xFF; + buf[3] = (val >> 32) & 0xFF; + buf[4] = (val >> 24) & 0xFF; + buf[5] = (val >> 16) & 0xFF; + buf[6] = (val >> 8) & 0xFF; + buf[7] = val & 0xFF; + return 8; + } + } + + // ensures enough space in the current block, rotating if needed + // returns pointer to write position, or nullptr on failure + inline uint8_t *bgwork_profile_ensure_space(BgWorkProfileState *state, + size_t needed) + { + ProfileBlock *block = state->current_block; + if(block && (block->used + needed <= ProfileBlock::BLOCK_SIZE)) + return block->data + block->used; + + // need a new block - complete old one and get fresh + if(block) + bgwork_profiler.complete_block(block); + + block = bgwork_profiler.alloc_block(state->thread_id); + state->current_block = block; + if(!block) + return nullptr; + + // reset delta encoding for new block + state->last_timestamp = 0; + return block->data; + } + + inline void bgwork_profile_begin(uint8_t slot) + { + BgWorkProfileState *state = tl_bgwork_profile; + if(!state) + return; + + int64_t now = Clock::current_time_in_nanoseconds(true /*absolute*/); + + // max record size: 8 (timestamp) + 1 (type) + 1 (slot) = 10 + uint8_t *buf = bgwork_profile_ensure_space(state, 10); + if(!buf) + return; + + ProfileBlock *block = state->current_block; + if(block->num_records == 0) + block->base_timestamp = now; + + int64_t delta = now - state->last_timestamp; + size_t ts_size = bgwork_profile_encode_timestamp(buf, delta, now); + buf += ts_size; + + *buf++ = BGWP_COARSE_BEGIN; + *buf++ = slot; + + block->used += ts_size + 2; + block->num_records++; + state->last_timestamp = now; + } + + inline void bgwork_profile_end() + { + BgWorkProfileState *state = tl_bgwork_profile; + if(!state) + return; + + int64_t now = Clock::current_time_in_nanoseconds(true /*absolute*/); + + // max: 8 (timestamp) + 1 (type) = 9 + uint8_t *buf = bgwork_profile_ensure_space(state, 9); + if(!buf) + return; + + ProfileBlock *block = state->current_block; + if(block->num_records == 0) + block->base_timestamp = now; + + int64_t delta = now - state->last_timestamp; + size_t ts_size = bgwork_profile_encode_timestamp(buf, delta, now); + buf += ts_size; + + *buf++ = BGWP_COARSE_END; + + block->used += ts_size + 1; + block->num_records++; + state->last_timestamp = now; + } + + inline void bgwork_profile_fine_begin(uint16_t sub_item_id) + { + BgWorkProfileState *state = tl_bgwork_profile; + if(!state) + return; + + int64_t now = Clock::current_time_in_nanoseconds(true /*absolute*/); + + // max: 8 + 1 + 2 = 11 + uint8_t *buf = bgwork_profile_ensure_space(state, 11); + if(!buf) + return; + + ProfileBlock *block = state->current_block; + if(block->num_records == 0) + block->base_timestamp = now; + + int64_t delta = now - state->last_timestamp; + size_t ts_size = bgwork_profile_encode_timestamp(buf, delta, now); + buf += ts_size; + + *buf++ = BGWP_FINE_BEGIN; + memcpy(buf, &sub_item_id, sizeof(uint16_t)); + buf += sizeof(uint16_t); + + block->used += ts_size + 3; + block->num_records++; + state->last_timestamp = now; + } + + inline void bgwork_profile_fine_end() + { + BgWorkProfileState *state = tl_bgwork_profile; + if(!state) + return; + + int64_t now = Clock::current_time_in_nanoseconds(true /*absolute*/); + + // max: 8 + 1 = 9 + uint8_t *buf = bgwork_profile_ensure_space(state, 9); + if(!buf) + return; + + ProfileBlock *block = state->current_block; + if(block->num_records == 0) + block->base_timestamp = now; + + int64_t delta = now - state->last_timestamp; + size_t ts_size = bgwork_profile_encode_timestamp(buf, delta, now); + buf += ts_size; + + *buf++ = BGWP_FINE_END; + + block->used += ts_size + 1; + block->num_records++; + state->last_timestamp = now; + } + + inline void bgwork_profile_gpu_work(uint64_t proc_id, uint8_t slot, + int64_t start_time, int64_t stop_time) + { + BgWorkProfileState *state = tl_bgwork_profile; + if(!state) + return; + + int64_t now = Clock::current_time_in_nanoseconds(true /*absolute*/); + + // max: 8 (timestamp) + 1 (type) + 8 (proc_id) + 1 (slot) + 8 (start) + 8 (stop) = 34 + uint8_t *buf = bgwork_profile_ensure_space(state, 34); + if(!buf) + return; + + ProfileBlock *block = state->current_block; + if(block->num_records == 0) + block->base_timestamp = now; + + int64_t delta = now - state->last_timestamp; + size_t ts_size = bgwork_profile_encode_timestamp(buf, delta, now); + buf += ts_size; + + *buf++ = BGWP_GPU_WORK; + memcpy(buf, &proc_id, sizeof(uint64_t)); + buf += sizeof(uint64_t); + *buf++ = slot; + memcpy(buf, &start_time, sizeof(int64_t)); + buf += sizeof(int64_t); + memcpy(buf, &stop_time, sizeof(int64_t)); + buf += sizeof(int64_t); + + block->used += ts_size + 26; + block->num_records++; + state->last_timestamp = now; + } + +}; // namespace Realm + +#endif // REALM_BGWORK_PROFILE_INL diff --git a/src/realm/cuda/cuda_internal.cc b/src/realm/cuda/cuda_internal.cc index 9a1ca7a475b..be93664cd44 100644 --- a/src/realm/cuda/cuda_internal.cc +++ b/src/realm/cuda/cuda_internal.cc @@ -555,6 +555,7 @@ namespace Realm { WriteSequenceCache wseqcache(this, 2 << 20); GPUStream *stream = 0; size_t total_bytes = 0; + BgWorkGpuCudaNotification *gpu_timing = nullptr; AffineCopyInfo<3> copy_infos; CUDA_MEMCPY3D cuda_copy; @@ -763,6 +764,11 @@ namespace Realm { if(in_gpu && in_gpu->can_access_peer(out_gpu) && transpose_copy.extents[0] != 0 && transpose_copy.extents[0] <= CUDA_MAX_FIELD_BYTES) { + if(!gpu_timing && tl_bgwork_profile) { + gpu_timing = new BgWorkGpuCudaNotification(stream->get_gpu()->proc->me.id, + channel->get_bgwork_slot()); + stream->add_notification(gpu_timing); + } stream->get_gpu()->launch_transpose_kernel(transpose_copy, min_align, stream); bytes_to_fence += transpose_copy.extents[0] * transpose_copy.extents[1] * transpose_copy.extents[2]; @@ -821,6 +827,11 @@ namespace Realm { log_gpudma.info() << "\tLaunching kernel for rects=" << copy_infos.num_rects << " bytes=" << copy_info_total << " out_is_ipc=" << out_is_ipc; + if(!gpu_timing && tl_bgwork_profile) { + gpu_timing = new BgWorkGpuCudaNotification(stream->get_gpu()->proc->me.id, + channel->get_bgwork_slot()); + stream->add_notification(gpu_timing); + } stream->get_gpu()->launch_batch_affine_kernel( ©_infos, 3, min_align, copy_info_total / min_align, stream); bytes_to_fence += copy_info_total; @@ -875,6 +886,9 @@ namespace Realm { } } + if(gpu_timing) + stream->add_notification(gpu_timing); + rseqcache.flush(); wseqcache.flush(); @@ -1823,6 +1837,8 @@ namespace Realm { bool GPUfillXferDes::progress_xd(GPUfillChannel *channel, TimeLimit work_until) { bool did_work = false; + BgWorkGpuCudaNotification *gpu_timing = nullptr; + GPUStream *gpu_timing_stream = nullptr; ReadSequenceCache rseqcache(this, 2 << 20); WriteSequenceCache wseqcache(this, 2 << 20); @@ -1893,6 +1909,12 @@ namespace Realm { Realm::Cuda::AffineFillInfo<2, size_t>::MAX_NUM_RECTS) { // Filled the current info, time to start all over log_gpudma.info() << "pushing fill kernel"; + if(!gpu_timing && tl_bgwork_profile) { + gpu_timing = new BgWorkGpuCudaNotification( + stream->get_gpu()->proc->me.id, channel->get_bgwork_slot()); + stream->add_notification(gpu_timing); + gpu_timing_stream = stream; + } stream->get_gpu()->launch_batch_affine_fill_kernel( &fill_info, 2, reduced_fill_size, total_info_bytes / reduced_fill_size, stream); @@ -2071,6 +2093,12 @@ namespace Realm { if(fill_info.num_rects > 0) { log_gpudma.info() << "pushing fill kernel"; + if(!gpu_timing && tl_bgwork_profile) { + gpu_timing = new BgWorkGpuCudaNotification(stream->get_gpu()->proc->me.id, + channel->get_bgwork_slot()); + stream->add_notification(gpu_timing); + gpu_timing_stream = stream; + } stream->get_gpu()->launch_batch_affine_fill_kernel( &fill_info, 2, reduced_fill_size, total_info_bytes / reduced_fill_size, stream); @@ -2093,6 +2121,9 @@ namespace Realm { break; } + if(gpu_timing) + gpu_timing_stream->add_notification(gpu_timing); + rseqcache.flush(); return did_work; @@ -2303,6 +2334,7 @@ namespace Realm { bool GPUreduceXferDes::progress_xd(GPUreduceChannel *channel, TimeLimit work_until) { bool did_work = false; + BgWorkGpuCudaNotification *gpu_timing = nullptr; ReadSequenceCache rseqcache(this, 2 << 20); ReadSequenceCache wseqcache(this, 2 << 20); @@ -2453,6 +2485,12 @@ namespace Realm { { AutoGPUContext agc(channel->gpu); + if(!gpu_timing && tl_bgwork_profile) { + gpu_timing = new BgWorkGpuCudaNotification( + stream->get_gpu()->proc->me.id, channel->get_bgwork_slot()); + stream->add_notification(gpu_timing); + } + if(kernel != 0) { // Use params array to pass kernel arguments (pointers to each // parameter) instead of CU_LAUNCH_PARAM_BUFFER_POINTER (packed buffer). @@ -2538,6 +2576,9 @@ namespace Realm { break; } + if(gpu_timing) + stream->add_notification(gpu_timing); + rseqcache.flush(); wseqcache.flush(); diff --git a/src/realm/cuda/cuda_internal.h b/src/realm/cuda/cuda_internal.h index 614710bfe16..c0406a309e4 100644 --- a/src/realm/cuda/cuda_internal.h +++ b/src/realm/cuda/cuda_internal.h @@ -43,6 +43,7 @@ #include "realm/proc_impl.h" #include "realm/mem_impl.h" #include "realm/bgwork.h" +#include "realm/bgwork_profile.h" #include "realm/transfer/channel.h" #include "realm/transfer/ib_memory.h" #include "realm/cuda/cuda_memcpy.h" @@ -200,6 +201,22 @@ namespace Realm { virtual void request_completed(void) = 0; }; + // Profiling notification for GPU kernel timing in background work items. + // Registered as a GPUCompletionNotification on a stream twice: once before + // GPU kernel submissions (start marker) and once after (end marker). + // Uses host-side timestamps taken when the existing events are reaped. + class BgWorkGpuCudaNotification : public GPUCompletionNotification { + public: + BgWorkGpuCudaNotification(uint64_t _proc_id, uint8_t _slot); + void request_completed(void) override; + + private: + uint64_t proc_id; + uint8_t slot; + int64_t start_time; + bool started; + }; + class GPUWorkFence : public Realm::Operation::AsyncWorkItem { public: GPUWorkFence(GPU *gpu, Realm::Operation *op); @@ -330,6 +347,10 @@ namespace Realm { Realm::Thread *worker_thread; bool thread_sleeping; atomic worker_shutdown_requested; + + // Level 2 bgwork profiling + uint16_t profile_sub_item_id; + bool profile_id_registered; }; // a little helper class to manage a pool of CUevents that can be reused diff --git a/src/realm/cuda/cuda_module.cc b/src/realm/cuda/cuda_module.cc index 0147bc2b0d2..b6039e2004c 100644 --- a/src/realm/cuda/cuda_module.cc +++ b/src/realm/cuda/cuda_module.cc @@ -365,6 +365,29 @@ namespace Realm { return work_left; } + //////////////////////////////////////////////////////////////////////// + // + // class BgWorkGpuCudaNotification + + BgWorkGpuCudaNotification::BgWorkGpuCudaNotification(uint64_t _proc_id, uint8_t _slot) + : proc_id(_proc_id) + , slot(_slot) + , start_time(0) + , started(false) + {} + + void BgWorkGpuCudaNotification::request_completed(void) + { + if(!started) { + start_time = Clock::current_time_in_nanoseconds(true /*absolute*/); + started = true; + } else { + int64_t stop_time = Clock::current_time_in_nanoseconds(true /*absolute*/); + bgwork_profile_gpu_work(proc_id, slot, start_time, stop_time); + delete this; + } + } + //////////////////////////////////////////////////////////////////////// // // class GPUWorkFence @@ -1309,6 +1332,8 @@ namespace Realm { , worker_thread(0) , thread_sleeping(false) , worker_shutdown_requested(false) + , profile_sub_item_id(0) + , profile_id_registered(false) {} GPUWorker::~GPUWorker(void) @@ -1396,10 +1421,22 @@ namespace Realm { make_active(); } + // lazily register for fine-grained profiling + if(bgwork_profiler.get_level() >= 2 && !profile_id_registered) { + profile_sub_item_id = + bgwork_profiler.register_sub_item(BGWP_SUB_GPU_REAP, "cuda gpu reap"); + profile_id_registered = true; + } + // do work for the stream we popped, paying attention to the cutoff // time bool was_empty = false; - if(stream->reap_events(work_until)) { + if(profile_id_registered) + bgwork_profile_fine_begin(profile_sub_item_id); + bool has_more = stream->reap_events(work_until); + if(profile_id_registered) + bgwork_profile_fine_end(); + if(has_more) { AutoLock<> al(lock); was_empty = active_streams.empty(); diff --git a/src/realm/deppart/partitions.cc b/src/realm/deppart/partitions.cc index b023f468fce..6eb3516bf85 100644 --- a/src/realm/deppart/partitions.cc +++ b/src/realm/deppart/partitions.cc @@ -839,6 +839,7 @@ namespace Realm { : BackgroundWorkItem("deppart op queue") , shutdown_flag(false), rsrv(_rsrv), condvar(mutex) , work_advertised(false) + , profile_sub_item_id(0), profile_id_registered(false) { if(_bgwork) add_to_manager(_bgwork); @@ -969,6 +970,13 @@ namespace Realm { make_active(); } + // lazily register for fine-grained profiling + if(bgwork_profiler.get_level() >= 2 && !profile_id_registered) { + profile_sub_item_id = + bgwork_profiler.register_sub_item(BGWP_SUB_DEPPART_OP, "deppart op"); + profile_id_registered = true; + } + // now we can work on the op we got in parallel with everybody else // (neither branch will be taken if there are dedicated workers and they // already got to the queued operations) @@ -976,7 +984,11 @@ namespace Realm { bool ok_to_run = op->mark_started(); if(ok_to_run) { log_part.info() << "worker " << this << " starting op " << op; + if(profile_id_registered) + bgwork_profile_fine_begin(profile_sub_item_id); op->execute(); + if(profile_id_registered) + bgwork_profile_fine_end(); log_part.info() << "worker " << this << " finished op " << op; op->mark_finished(true /*successful*/); } else { @@ -988,7 +1000,11 @@ namespace Realm { if(uop != 0) { log_part.info() << "worker " << this << " starting uop " << uop; uop->mark_started(); + if(profile_id_registered) + bgwork_profile_fine_begin(profile_sub_item_id); uop->execute(); + if(profile_id_registered) + bgwork_profile_fine_end(); log_part.info() << "worker " << this << " finished uop " << uop; uop->mark_finished(); } diff --git a/src/realm/deppart/partitions.h b/src/realm/deppart/partitions.h index 7bb68c3630c..4b3529bacdf 100644 --- a/src/realm/deppart/partitions.h +++ b/src/realm/deppart/partitions.h @@ -218,6 +218,8 @@ namespace Realm { Mutex::CondVar condvar; std::vector workers; bool work_advertised; + uint16_t profile_sub_item_id; + bool profile_id_registered; }; diff --git a/src/realm/hip/hip_internal.cc b/src/realm/hip/hip_internal.cc index c3d3ea07e64..0584383b190 100644 --- a/src/realm/hip/hip_internal.cc +++ b/src/realm/hip/hip_internal.cc @@ -1125,6 +1125,7 @@ namespace Realm { bool GPUreduceXferDes::progress_xd(GPUreduceChannel *channel, TimeLimit work_until) { bool did_work = false; + BgWorkGpuHipNotification *gpu_timing = nullptr; ReadSequenceCache rseqcache(this, 2 << 20); ReadSequenceCache wseqcache(this, 2 << 20); @@ -1260,6 +1261,12 @@ namespace Realm { { AutoGPUContext agc(channel->gpu); + if(!gpu_timing && tl_bgwork_profile) { + gpu_timing = new BgWorkGpuHipNotification( + stream->get_gpu()->proc->me.id, channel->get_bgwork_slot()); + stream->add_notification(gpu_timing); + } + void *src_ptr = (void *)args->src_base; void *src_device = src_ptr; #ifndef __HIP_PLATFORM_NVIDIA__ @@ -1350,6 +1357,9 @@ namespace Realm { break; } + if(gpu_timing) + stream->add_notification(gpu_timing); + rseqcache.flush(); wseqcache.flush(); diff --git a/src/realm/hip/hip_internal.h b/src/realm/hip/hip_internal.h index af9fde98d16..9c24006ec8b 100644 --- a/src/realm/hip/hip_internal.h +++ b/src/realm/hip/hip_internal.h @@ -29,6 +29,7 @@ #include "realm/proc_impl.h" #include "realm/mem_impl.h" #include "realm/bgwork.h" +#include "realm/bgwork_profile.h" #include "realm/transfer/channel.h" #include "realm/transfer/ib_memory.h" @@ -110,6 +111,22 @@ namespace Realm { virtual void request_completed(void) = 0; }; + // Profiling notification for GPU kernel timing in background work items. + // Registered as a GPUCompletionNotification on a stream twice: once before + // GPU kernel submissions (start marker) and once after (end marker). + // Uses host-side timestamps taken when the existing events are reaped. + class BgWorkGpuHipNotification : public GPUCompletionNotification { + public: + BgWorkGpuHipNotification(uint64_t _proc_id, uint8_t _slot); + void request_completed(void) override; + + private: + uint64_t proc_id; + uint8_t slot; + int64_t start_time; + bool started; + }; + class GPUPreemptionWaiter : public GPUCompletionNotification { public: GPUPreemptionWaiter(GPU *gpu); @@ -259,6 +276,10 @@ namespace Realm { Realm::Thread *worker_thread; bool thread_sleeping; atomic worker_shutdown_requested; + + // Level 2 bgwork profiling + uint16_t profile_sub_item_id; + bool profile_id_registered; }; // a little helper class to manage a pool of CUevents that can be reused diff --git a/src/realm/hip/hip_module.cc b/src/realm/hip/hip_module.cc index 194d8844553..fe622567ea5 100644 --- a/src/realm/hip/hip_module.cc +++ b/src/realm/hip/hip_module.cc @@ -291,6 +291,29 @@ namespace Realm { } } + //////////////////////////////////////////////////////////////////////// + // + // class BgWorkGpuHipNotification + + BgWorkGpuHipNotification::BgWorkGpuHipNotification(uint64_t _proc_id, uint8_t _slot) + : proc_id(_proc_id) + , slot(_slot) + , start_time(0) + , started(false) + {} + + void BgWorkGpuHipNotification::request_completed(void) + { + if(!started) { + start_time = Clock::current_time_in_nanoseconds(true /*absolute*/); + started = true; + } else { + int64_t stop_time = Clock::current_time_in_nanoseconds(true /*absolute*/); + bgwork_profile_gpu_work(proc_id, slot, start_time, stop_time); + delete this; + } + } + //////////////////////////////////////////////////////////////////////// // // class GPUWorkFence @@ -1050,6 +1073,8 @@ namespace Realm { , worker_thread(0) , thread_sleeping(false) , worker_shutdown_requested(false) + , profile_sub_item_id(0) + , profile_id_registered(false) {} GPUWorker::~GPUWorker(void) @@ -1136,10 +1161,22 @@ namespace Realm { if(still_not_empty) make_active(); + // lazily register for fine-grained profiling + if(bgwork_profiler.get_level() >= 2 && !profile_id_registered) { + profile_sub_item_id = + bgwork_profiler.register_sub_item(BGWP_SUB_GPU_REAP, "hip gpu reap"); + profile_id_registered = true; + } + // do work for the stream we popped, paying attention to the cutoff // time bool was_empty = false; - if(stream->reap_events(work_until)) { + if(profile_id_registered) + bgwork_profile_fine_begin(profile_sub_item_id); + bool has_more = stream->reap_events(work_until); + if(profile_id_registered) + bgwork_profile_fine_end(); + if(has_more) { AutoLock<> al(lock); was_empty = active_streams.empty(); diff --git a/src/realm/runtime_impl.cc b/src/realm/runtime_impl.cc index 50de5eaed09..fc1bba9dc1b 100644 --- a/src/realm/runtime_impl.cc +++ b/src/realm/runtime_impl.cc @@ -841,6 +841,10 @@ namespace Realm { // enabled. cp.add_option_int("-ll:path_cache_size", Config::path_cache_lru_size); + cp.add_option_int("-ll:bgworkprofile", bgwork_profile_level); + cp.add_option_string("-ll:bgworkprofile_logfile", bgwork_profile_logfile); + cp.add_option_int("-ll:bgworkprofile_bufsize", bgwork_profile_bufsize); + bool cmdline_ok = cp.parse_command_line(cmdline); if(!cmdline_ok) { @@ -868,6 +872,12 @@ namespace Realm { "WARNING: prefix set, but NODE_LOGGING not enabled at compile time!\n"); } #endif + + // configure background work profiler + bgwork_profiler.set_level(bgwork_profile_level); + if(!bgwork_profile_logfile.empty()) + bgwork_profiler.set_logfile(bgwork_profile_logfile); + bgwork_profiler.set_bufsize(bgwork_profile_bufsize); } CoreModule::CoreModule(void) @@ -2148,6 +2158,8 @@ namespace Realm { bgwork.start_dedicated_workers(*core_reservations); + bgwork_profiler.initialize(Network::my_node_id); + PartitioningOpQueue::start_worker_threads(*core_reservations, &bgwork); #ifdef EVENT_TRACING @@ -2945,6 +2957,7 @@ namespace Realm { #ifdef DEBUG_REALM event_triggerer.shutdown_work_item(); #endif + bgwork_profiler.shutdown(); bgwork.stop_dedicated_workers(); // tear down the active message manager diff --git a/src/realm/runtime_impl.h b/src/realm/runtime_impl.h index 72b72c75feb..5ba0a0810ab 100644 --- a/src/realm/runtime_impl.h +++ b/src/realm/runtime_impl.h @@ -48,6 +48,7 @@ #include "realm/network.h" #include "realm/bgwork.h" +#include "realm/bgwork_profile.h" #include "realm/activemsg.h" #include "realm/repl_heap.h" #include "realm/dynamic_table.h" @@ -183,6 +184,11 @@ namespace Realm { // barriers int barrier_broadcast_radix = 4; + // background work profiling + int bgwork_profile_level = 0; + std::string bgwork_profile_logfile; + int bgwork_profile_bufsize = 1024; // MB + // topology of the host const HardwareTopology *host_topology = nullptr; }; diff --git a/src/realm/transfer/channel.h b/src/realm/transfer/channel.h index e693d0ff01a..d3641ee9bcd 100644 --- a/src/realm/transfer/channel.h +++ b/src/realm/transfer/channel.h @@ -1008,6 +1008,8 @@ namespace Realm { bool ordered_mode, in_ordered_worker; Mutex mutex; XferDes::XferDesList ready_xds; + uint16_t profile_sub_item_id; + bool profile_id_registered; }; template @@ -1016,6 +1018,8 @@ namespace Realm { SingleXDQChannel(BackgroundWorkManager *bgwork, XferDesKind _kind, const std::string &_name, int _numa_domain = -1); + unsigned get_bgwork_slot() const { return xdq.get_slot(); } + virtual void shutdown(); virtual void enqueue_ready_xd(XferDes *xd); diff --git a/src/realm/transfer/channel.inl b/src/realm/transfer/channel.inl index 0632025de07..59a608518cf 100644 --- a/src/realm/transfer/channel.inl +++ b/src/realm/transfer/channel.inl @@ -99,6 +99,8 @@ namespace Realm { , channel(_channel) , ordered_mode(_ordered) , in_ordered_worker(false) + , profile_sub_item_id(0) + , profile_id_registered(false) {} template @@ -151,6 +153,13 @@ namespace Realm { if(still_more && !ordered_mode) make_active(); + // lazily register for fine-grained profiling + if(bgwork_profiler.get_level() >= 2 && !profile_id_registered) { + profile_sub_item_id = + bgwork_profiler.register_sub_item(BGWP_SUB_XFER_CHANNEL, name); + profile_id_registered = true; + } + // now process this transfer request, paying attention to our deadline while(true) { @@ -159,7 +168,11 @@ namespace Realm { // on it unsigned progress = xd->current_progress(); + if(profile_id_registered) + bgwork_profile_fine_begin(profile_sub_item_id); bool did_work = xd->progress_xd(static_cast(channel), work_until); + if(profile_id_registered) + bgwork_profile_fine_end(); // if we didn't do any work, and we're not done (i.e. by // concluding there wasn't any work to actually do), re-check diff --git a/tests/CMakeLists.txt b/tests/CMakeLists.txt index a6213d8b46f..da0dbf4e388 100644 --- a/tests/CMakeLists.txt +++ b/tests/CMakeLists.txt @@ -295,6 +295,8 @@ set(sparse_construct_ARGS -verbose) add_integration_test(sparse_construct "${REALM_TEST_DIR}/sparse_construct.cc") add_integration_test(extres_alias "${REALM_TEST_DIR}/extres_alias.cc") add_integration_test(reservations "${REALM_TEST_DIR}/reservations.cc") +set(bgwork_profile_test_ARGS -ll:bgworkprofile 2 -ll:bgworkprofile_logfile bgwork_profile_test.bin -copies 32 -profile_file bgwork_profile_test.bin) +add_integration_test(bgwork_profile_test "${REALM_TEST_DIR}/bgwork_profile.cc") set(machine_queries_ARGS -ll:cpu 4 -ll:util 2) add_integration_test(machine_queries "${REALM_TEST_DIR}/machine_queries.cc") set(machine_config_test_ARGS diff --git a/tests/bgwork_profile.cc b/tests/bgwork_profile.cc new file mode 100644 index 00000000000..cef20767a54 --- /dev/null +++ b/tests/bgwork_profile.cc @@ -0,0 +1,440 @@ +/* + * Copyright 2026 Stanford University, NVIDIA Corporation + * SPDX-License-Identifier: Apache-2.0 + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +// Test program for background work profiling. +// Creates instances in available memories, runs a batch of copies to exercise +// DMA background work items, then optionally validates the output file. + +#include "realm.h" +#include "realm/cmdline.h" + +#include +#include +#include +#include +#include + +#ifdef REALM_ON_WINDOWS +#include +#include +#else +#include +#include +#include +#endif + +using namespace Realm; + +Logger log_app("app"); + +enum +{ + TOP_LEVEL_TASK = Processor::TASK_ID_FIRST_AVAILABLE + 0, +}; + +namespace TestConfig { + size_t copy_size = 1 << 20; // 1MB per copy + int num_copies = 16; + bool validate = false; + std::string profile_file = "bgwork_profile_test.bin"; +}; // namespace TestConfig + +// File format constants (duplicated from bgwork_profile.h for standalone validation) +static const char EXPECTED_MAGIC[4] = {'R', 'B', 'W', 'P'}; + +// Note: file header and block header fields are read individually +// to avoid C struct padding issues with the binary file format. + +// Read helpers +static bool read_exact(int fd, void *buf, size_t count) +{ + uint8_t *p = static_cast(buf); + while(count > 0) { + ssize_t n = read(fd, p, count); + if(n <= 0) + return false; + p += n; + count -= n; + } + return true; +} + +// Decode a timestamp delta, returns the absolute timestamp +// Updates pos to point past the consumed bytes +static bool decode_timestamp(const uint8_t *data, size_t data_size, size_t &pos, + int64_t &last_ts, int64_t &out_ts) +{ + if(pos >= data_size) + return false; + + uint8_t first = data[pos]; + if((first & 0x80) == 0) { + // 2-byte encoding, 15-bit delta + if(pos + 2 > data_size) + return false; + int64_t delta = ((int64_t)(first & 0x7F) << 8) | data[pos + 1]; + out_ts = last_ts + delta; + pos += 2; + } else if((first & 0xC0) == 0x80) { + // 4-byte encoding, 30-bit delta + if(pos + 4 > data_size) + return false; + int64_t delta = ((int64_t)(first & 0x3F) << 24) | ((int64_t)data[pos + 1] << 16) | + ((int64_t)data[pos + 2] << 8) | data[pos + 3]; + out_ts = last_ts + delta; + pos += 4; + } else { + // 8-byte encoding, absolute timestamp + if(pos + 8 > data_size) + return false; + uint64_t val = ((uint64_t)(first & 0x3F) << 56) | ((uint64_t)data[pos + 1] << 48) | + ((uint64_t)data[pos + 2] << 40) | ((uint64_t)data[pos + 3] << 32) | + ((uint64_t)data[pos + 4] << 24) | ((uint64_t)data[pos + 5] << 16) | + ((uint64_t)data[pos + 6] << 8) | (uint64_t)data[pos + 7]; + out_ts = static_cast(val); + pos += 8; + } + last_ts = out_ts; + return true; +} + +static bool validate_profile_file(const std::string &filename) +{ + int fd = open(filename.c_str(), O_RDONLY); + if(fd < 0) { + fprintf(stderr, "VALIDATE: cannot open file: %s\n", filename.c_str()); + return false; + } + + // read header fields individually to avoid struct padding issues + char magic[4]; + uint16_t version, flags; + uint32_t node_id; + int64_t zero_time; + uint32_t work_item_count, sub_item_count; + + if(!read_exact(fd, magic, 4) || !read_exact(fd, &version, 2) || + !read_exact(fd, &flags, 2) || !read_exact(fd, &node_id, 4) || + !read_exact(fd, &zero_time, 8) || !read_exact(fd, &work_item_count, 4) || + !read_exact(fd, &sub_item_count, 4)) { + fprintf(stderr, "VALIDATE: failed to read file header\n"); + close(fd); + return false; + } + + // check magic + if(memcmp(magic, EXPECTED_MAGIC, 4) != 0) { + fprintf(stderr, "VALIDATE: bad magic: %c%c%c%c\n", magic[0], magic[1], magic[2], + magic[3]); + close(fd); + return false; + } + + fprintf(stdout, "VALIDATE: magic OK, version=%u, flags=0x%04x, node_id=%u\n", version, + flags, node_id); + fprintf(stdout, "VALIDATE: zero_time=%lld, work_items=%u, sub_items=%u\n", + (long long)zero_time, work_item_count, sub_item_count); + + // read work item descriptors + for(uint32_t i = 0; i < work_item_count; i++) { + uint16_t slot, name_len; + if(!read_exact(fd, &slot, 2) || !read_exact(fd, &name_len, 2)) { + fprintf(stderr, "VALIDATE: failed reading work item descriptor %u\n", i); + close(fd); + return false; + } + std::vector name(name_len); + if(name_len > 0 && !read_exact(fd, name.data(), name_len)) { + fprintf(stderr, "VALIDATE: failed reading work item name %u\n", i); + close(fd); + return false; + } + fprintf(stdout, "VALIDATE: work item: slot=%u name='%.*s'\n", slot, (int)name_len, + name.data()); + } + + // read sub-item descriptors + for(uint32_t i = 0; i < sub_item_count; i++) { + uint16_t id, name_len; + uint8_t type; + if(!read_exact(fd, &id, 2) || !read_exact(fd, &type, 1) || + !read_exact(fd, &name_len, 2)) { + fprintf(stderr, "VALIDATE: failed reading sub-item descriptor %u\n", i); + close(fd); + return false; + } + std::vector name(name_len); + if(name_len > 0 && !read_exact(fd, name.data(), name_len)) { + fprintf(stderr, "VALIDATE: failed reading sub-item name %u\n", i); + close(fd); + return false; + } + fprintf(stdout, "VALIDATE: sub-item: id=%u type=%u name='%.*s'\n", id, type, + (int)name_len, name.data()); + } + + // read data blocks + uint32_t total_blocks = 0; + uint32_t total_records = 0; + while(true) { + // read block header fields individually to avoid padding + uint64_t blk_thread_id; + uint32_t blk_sequence, blk_record_count; + int64_t blk_base_timestamp; + uint32_t blk_data_size, blk_compressed_size; + + if(!read_exact(fd, &blk_thread_id, 8) || !read_exact(fd, &blk_sequence, 4) || + !read_exact(fd, &blk_record_count, 4) || !read_exact(fd, &blk_base_timestamp, 8) || + !read_exact(fd, &blk_data_size, 4) || !read_exact(fd, &blk_compressed_size, 4)) + break; // end of file or incomplete header + + total_blocks++; + total_records += blk_record_count; + + size_t read_size = (blk_compressed_size > 0) ? blk_compressed_size : blk_data_size; + std::vector data(read_size); + if(!read_exact(fd, data.data(), read_size)) { + fprintf(stderr, "VALIDATE: failed reading block data (block %u)\n", total_blocks); + close(fd); + return false; + } + + // if compressed, we'd need to decompress - skip detailed validation for compressed + // blocks + if(blk_compressed_size > 0) { + fprintf(stdout, + "VALIDATE: block %u: thread=%llu seq=%u records=%u compressed=%u->%u\n", + total_blocks, (unsigned long long)blk_thread_id, blk_sequence, + blk_record_count, blk_data_size, blk_compressed_size); + continue; + } + + // parse records and check timestamp monotonicity + size_t pos = 0; + int64_t last_ts = 0; + int64_t prev_ts = 0; + bool ts_monotonic = true; + + for(uint32_t r = 0; r < blk_record_count && pos < blk_data_size; r++) { + int64_t ts; + if(!decode_timestamp(data.data(), blk_data_size, pos, last_ts, ts)) { + fprintf(stderr, "VALIDATE: failed decoding timestamp in block %u record %u\n", + total_blocks, r); + close(fd); + return false; + } + + if(r > 0 && ts < prev_ts) { + ts_monotonic = false; + fprintf(stderr, + "VALIDATE: non-monotonic timestamp in block %u record %u: " + "%lld < %lld\n", + total_blocks, r, (long long)ts, (long long)prev_ts); + } + prev_ts = ts; + + // read record type + if(pos >= blk_data_size) { + fprintf(stderr, "VALIDATE: truncated record in block %u record %u\n", + total_blocks, r); + close(fd); + return false; + } + uint8_t rec_type = data[pos++]; + + // skip payload based on type + switch(rec_type) { + case 0x01: // COARSE_BEGIN: 1 byte slot + if(pos + 1 > blk_data_size) { + close(fd); + return false; + } + pos += 1; + break; + case 0x02: // COARSE_END: no payload + break; + case 0x11: // FINE_BEGIN: 2 byte sub_item_id + if(pos + 2 > blk_data_size) { + close(fd); + return false; + } + pos += 2; + break; + case 0x12: // FINE_END: no payload + break; + case 0x21: // GPU_WORK: 1 byte gpu_index + 4 byte duration + if(pos + 5 > blk_data_size) { + close(fd); + return false; + } + pos += 5; + break; + default: + fprintf(stderr, "VALIDATE: unknown record type 0x%02x in block %u record %u\n", + rec_type, total_blocks, r); + close(fd); + return false; + } + } + + fprintf(stdout, + "VALIDATE: block %u: thread=%llu seq=%u records=%u bytes=%u ts_mono=%s\n", + total_blocks, (unsigned long long)blk_thread_id, blk_sequence, + blk_record_count, blk_data_size, ts_monotonic ? "yes" : "NO"); + } + + close(fd); + + fprintf(stdout, "VALIDATE: total blocks=%u, total records=%u\n", total_blocks, + total_records); + + if(total_records == 0) { + fprintf(stderr, "VALIDATE: WARNING - no records found in profile\n"); + // not necessarily a failure - short tests may not generate records + } + + fprintf(stdout, "VALIDATE: PASSED\n"); + return true; +} + +void top_level_task(const void *args, size_t arglen, const void *userdata, size_t userlen, + Processor p) +{ + log_app.info() << "bgwork profile test starting"; + + // find system memory + Machine machine = Machine::get_machine(); + Machine::MemoryQuery mq(machine); + mq.only_kind(Memory::SYSTEM_MEM).local_address_space().has_capacity(1); + + std::vector sys_mems; + for(Machine::MemoryQuery::iterator it = mq.begin(); it; ++it) + sys_mems.push_back(*it); + + if(sys_mems.empty()) { + log_app.fatal() << "no system memories found!"; + abort(); + } + + log_app.info() << "found " << sys_mems.size() << " system memories"; + + // create instances in available memories + size_t num_elems = TestConfig::copy_size; + IndexSpace<1> is = Rect<1>(0, num_elems - 1); + std::vector field_sizes(1, 1); // 1 byte per element + + std::vector instances; + for(size_t i = 0; i < sys_mems.size() && i < 2; i++) { + RegionInstance inst; + RegionInstance::create_instance(inst, sys_mems[i], is, field_sizes, 0, + ProfilingRequestSet()) + .wait(); + assert(inst.exists()); + instances.push_back(inst); + log_app.info() << "created instance in memory " << sys_mems[i]; + } + + // if only one memory, create two instances in the same memory + if(instances.size() < 2) { + RegionInstance inst; + RegionInstance::create_instance(inst, sys_mems[0], is, field_sizes, 0, + ProfilingRequestSet()) + .wait(); + assert(inst.exists()); + instances.push_back(inst); + } + + // run a batch of copies between the instances + std::vector srcs(1), dsts(1); + Event prev = Event::NO_EVENT; + + for(int i = 0; i < TestConfig::num_copies; i++) { + int src_idx = i % instances.size(); + int dst_idx = (i + 1) % instances.size(); + + srcs[0].set_field(instances[src_idx], 0, 1); + dsts[0].set_field(instances[dst_idx], 0, 1); + + prev = is.copy(srcs, dsts, ProfilingRequestSet(), prev); + } + + // wait for all copies to finish + prev.wait(); + log_app.info() << "all " << TestConfig::num_copies << " copies completed"; + + // clean up instances + for(auto &inst : instances) + inst.destroy(); + + log_app.info() << "bgwork profile test done"; +} + +int main(int argc, char **argv) +{ + // pre-scan for validate-only mode + for(int i = 1; i < argc; i++) { + if(strcmp(argv[i], "-validate") == 0) { + TestConfig::validate = true; + } else if(strcmp(argv[i], "-profile_file") == 0 && i + 1 < argc) { + TestConfig::profile_file = argv[i + 1]; + i++; + } + } + + if(TestConfig::validate) { + // validate-only mode - no Realm runtime needed + if(!validate_profile_file(TestConfig::profile_file)) + return 1; + return 0; + } + + Runtime rt; + rt.init(&argc, &argv); + + CommandLineParser cp; + cp.add_option_int_units("-size", TestConfig::copy_size, 'M') + .add_option_int("-copies", TestConfig::num_copies) + .add_option_string("-profile_file", TestConfig::profile_file); + bool ok = cp.parse_command_line(argc, const_cast(argv)); + assert(ok); + + rt.register_task(TOP_LEVEL_TASK, top_level_task); + + // select a processor to run the top level task on + Processor p = Machine::ProcessorQuery(Machine::get_machine()) + .only_kind(Processor::LOC_PROC) + .first(); + assert(p.exists()); + + Event e = rt.collective_spawn(p, TOP_LEVEL_TASK, 0, 0); + rt.shutdown(e); + int ret = rt.wait_for_shutdown(); + + // validate after shutdown + if(ret == 0) { + struct stat st; + if(stat(TestConfig::profile_file.c_str(), &st) == 0) { + if(!validate_profile_file(TestConfig::profile_file)) + return 1; + } else { + fprintf(stdout, + "NOTE: profile file '%s' not found (profiling may not have been enabled)\n", + TestConfig::profile_file.c_str()); + } + } + return ret; +} From 536163308c9e74c54a3e01e8b5b3d13896c025cf Mon Sep 17 00:00:00 2001 From: Mike Date: Tue, 17 Mar 2026 12:03:29 -0700 Subject: [PATCH 02/14] test: fix bgwork profiling test after changing format --- tests/bgwork_profile.cc | 34 +++++++++++++++++++++++++++------- 1 file changed, 27 insertions(+), 7 deletions(-) diff --git a/tests/bgwork_profile.cc b/tests/bgwork_profile.cc index cef20767a54..3466f609614 100644 --- a/tests/bgwork_profile.cc +++ b/tests/bgwork_profile.cc @@ -121,16 +121,19 @@ static bool validate_profile_file(const std::string &filename) } // read header fields individually to avoid struct padding issues + // header: magic(4) + version(2) + flags(2) + node_id(4) + zero_time(8) + + // work_item_count(4) + sub_item_count(4) + descriptor_offset(8) = 36 bytes char magic[4]; uint16_t version, flags; uint32_t node_id; int64_t zero_time; uint32_t work_item_count, sub_item_count; + uint64_t descriptor_offset; if(!read_exact(fd, magic, 4) || !read_exact(fd, &version, 2) || !read_exact(fd, &flags, 2) || !read_exact(fd, &node_id, 4) || !read_exact(fd, &zero_time, 8) || !read_exact(fd, &work_item_count, 4) || - !read_exact(fd, &sub_item_count, 4)) { + !read_exact(fd, &sub_item_count, 4) || !read_exact(fd, &descriptor_offset, 8)) { fprintf(stderr, "VALIDATE: failed to read file header\n"); close(fd); return false; @@ -146,8 +149,18 @@ static bool validate_profile_file(const std::string &filename) fprintf(stdout, "VALIDATE: magic OK, version=%u, flags=0x%04x, node_id=%u\n", version, flags, node_id); - fprintf(stdout, "VALIDATE: zero_time=%lld, work_items=%u, sub_items=%u\n", - (long long)zero_time, work_item_count, sub_item_count); + fprintf(stdout, + "VALIDATE: zero_time=%lld, work_items=%u, sub_items=%u, desc_offset=%llu\n", + (long long)zero_time, work_item_count, sub_item_count, + (unsigned long long)descriptor_offset); + + // seek to descriptor tables (at end of file, after data blocks) + if(lseek(fd, descriptor_offset, SEEK_SET) < 0) { + fprintf(stderr, "VALIDATE: failed to seek to descriptor table at offset %llu\n", + (unsigned long long)descriptor_offset); + close(fd); + return false; + } // read work item descriptors for(uint32_t i = 0; i < work_item_count; i++) { @@ -187,10 +200,17 @@ static bool validate_profile_file(const std::string &filename) (int)name_len, name.data()); } + // seek back to read data blocks (from offset 36 to descriptor_offset) + if(lseek(fd, 36, SEEK_SET) < 0) { + fprintf(stderr, "VALIDATE: failed to seek to data blocks\n"); + close(fd); + return false; + } + // read data blocks uint32_t total_blocks = 0; uint32_t total_records = 0; - while(true) { + while(lseek(fd, 0, SEEK_CUR) < (off_t)descriptor_offset) { // read block header fields individually to avoid padding uint64_t blk_thread_id; uint32_t blk_sequence, blk_record_count; @@ -276,12 +296,12 @@ static bool validate_profile_file(const std::string &filename) break; case 0x12: // FINE_END: no payload break; - case 0x21: // GPU_WORK: 1 byte gpu_index + 4 byte duration - if(pos + 5 > blk_data_size) { + case 0x21: // GPU_WORK: 8 byte proc_id + 1 byte slot + 8 byte start + 8 byte stop + if(pos + 25 > blk_data_size) { close(fd); return false; } - pos += 5; + pos += 25; break; default: fprintf(stderr, "VALIDATE: unknown record type 0x%02x in block %u record %u\n", From ab0a069ed9def430d0db0f5ddbf55c99d8219ffb Mon Sep 17 00:00:00 2001 From: Mike Date: Tue, 17 Mar 2026 12:27:11 -0700 Subject: [PATCH 03/14] realm: fix sanitizer issues --- src/realm/bgwork_profile.cc | 2 ++ src/realm/runtime_impl.cc | 2 +- 2 files changed, 3 insertions(+), 1 deletion(-) diff --git a/src/realm/bgwork_profile.cc b/src/realm/bgwork_profile.cc index c190b9d8f24..4baed276e1e 100644 --- a/src/realm/bgwork_profile.cc +++ b/src/realm/bgwork_profile.cc @@ -164,7 +164,9 @@ namespace Realm { // disable profiling for this thread // (the thread_local pointer was set to state, but we can't clear // other threads' TLS - they should have stopped by now) + delete state; } + thread_states.clear(); } // Flush all remaining in-memory data blocks to disk diff --git a/src/realm/runtime_impl.cc b/src/realm/runtime_impl.cc index fc1bba9dc1b..a7671eed432 100644 --- a/src/realm/runtime_impl.cc +++ b/src/realm/runtime_impl.cc @@ -2957,8 +2957,8 @@ namespace Realm { #ifdef DEBUG_REALM event_triggerer.shutdown_work_item(); #endif - bgwork_profiler.shutdown(); bgwork.stop_dedicated_workers(); + bgwork_profiler.shutdown(); // tear down the active message manager message_manager->shutdown(); From 7477672da893adc170a8b75f8063750aa7632640 Mon Sep 17 00:00:00 2001 From: Mike Date: Tue, 17 Mar 2026 19:06:49 -0700 Subject: [PATCH 04/14] realm: add mising GPU context pushes for gpu background work timing --- src/realm/cuda/cuda_internal.cc | 12 +++++++++--- src/realm/hip/hip_internal.cc | 4 +++- 2 files changed, 12 insertions(+), 4 deletions(-) diff --git a/src/realm/cuda/cuda_internal.cc b/src/realm/cuda/cuda_internal.cc index be93664cd44..cc3ae33805c 100644 --- a/src/realm/cuda/cuda_internal.cc +++ b/src/realm/cuda/cuda_internal.cc @@ -886,8 +886,10 @@ namespace Realm { } } - if(gpu_timing) + if(gpu_timing) { + AutoGPUContext agc(stream->get_gpu()); stream->add_notification(gpu_timing); + } rseqcache.flush(); wseqcache.flush(); @@ -2121,8 +2123,10 @@ namespace Realm { break; } - if(gpu_timing) + if(gpu_timing) { + AutoGPUContext agc(channel->gpu); gpu_timing_stream->add_notification(gpu_timing); + } rseqcache.flush(); @@ -2576,8 +2580,10 @@ namespace Realm { break; } - if(gpu_timing) + if(gpu_timing) { + AutoGPUContext agc(channel->gpu); stream->add_notification(gpu_timing); + } rseqcache.flush(); wseqcache.flush(); diff --git a/src/realm/hip/hip_internal.cc b/src/realm/hip/hip_internal.cc index 0584383b190..b3ab181840e 100644 --- a/src/realm/hip/hip_internal.cc +++ b/src/realm/hip/hip_internal.cc @@ -1357,8 +1357,10 @@ namespace Realm { break; } - if(gpu_timing) + if(gpu_timing) { + AutoGPUContext agc(channel->gpu); stream->add_notification(gpu_timing); + } rseqcache.flush(); wseqcache.flush(); From 05fa1069e9d53317eb2b79a8c72efede7e46e84f Mon Sep 17 00:00:00 2001 From: Mike Date: Tue, 17 Mar 2026 19:26:20 -0700 Subject: [PATCH 05/14] realm: make sure to record background work items registered before the command line is parsed --- src/realm/bgwork.h | 3 +++ src/realm/bgwork_profile.cc | 11 +++++++++++ src/realm/bgwork_profile.h | 6 ++++++ src/realm/runtime_impl.cc | 1 + 4 files changed, 21 insertions(+) diff --git a/src/realm/bgwork.h b/src/realm/bgwork.h index 5073d057c40..67b04ee4b17 100644 --- a/src/realm/bgwork.h +++ b/src/realm/bgwork.h @@ -32,6 +32,7 @@ namespace Realm { class BackgroundWorkItem; class BackgroundWorkThread; + class BgWorkProfileManager; class BackgroundWorkManager { public: @@ -101,6 +102,7 @@ namespace Realm { BackgroundWorkItem *work_items[MAX_WORK_ITEMS]; friend class BackgroundWorkThread; + friend class BgWorkProfileManager; // to manage sleeping workers, we need to stuff three things into a // single atomically-updatable state variable: @@ -145,6 +147,7 @@ namespace Realm { protected: friend class BackgroundWorkManager::Worker; + friend class BgWorkProfileManager; // mark this work item as active (i.e. having work to do) void make_active(void); diff --git a/src/realm/bgwork_profile.cc b/src/realm/bgwork_profile.cc index 4baed276e1e..4bf6d1176af 100644 --- a/src/realm/bgwork_profile.cc +++ b/src/realm/bgwork_profile.cc @@ -18,6 +18,7 @@ // Background work profiling manager implementation #include "realm/bgwork_profile.h" +#include "realm/bgwork.h" #include "realm/timers.h" #include "realm/logging.h" #include "realm/network.h" @@ -227,6 +228,16 @@ namespace Realm { return id; } + void BgWorkProfileManager::register_existing_items(BackgroundWorkManager &mgr) + { + unsigned count = mgr.num_work_items.load(); + for(unsigned i = 0; i < count; i++) { + BackgroundWorkItem *item = mgr.work_items[i]; + if(item) + register_work_item(static_cast(i), item->name); + } + } + ProfileBlock *BgWorkProfileManager::alloc_block(uint64_t thread_id) { AutoLock<> al(block_mutex); diff --git a/src/realm/bgwork_profile.h b/src/realm/bgwork_profile.h index 14d6033e8b8..148c75a60fe 100644 --- a/src/realm/bgwork_profile.h +++ b/src/realm/bgwork_profile.h @@ -86,6 +86,8 @@ namespace Realm { + class BackgroundWorkManager; + // Record type constants enum BgWorkProfileRecordType : uint8_t { @@ -162,6 +164,10 @@ namespace Realm { void register_work_item(uint16_t slot, const std::string &name); uint16_t register_sub_item(uint8_t type, const std::string &name); + // retroactively register any work items that were added to the manager + // before the profiler was configured (e.g., network layer items) + void register_existing_items(BackgroundWorkManager &mgr); + // block management (called by recording functions) ProfileBlock *alloc_block(uint64_t thread_id); void complete_block(ProfileBlock *block); diff --git a/src/realm/runtime_impl.cc b/src/realm/runtime_impl.cc index a7671eed432..7758541e766 100644 --- a/src/realm/runtime_impl.cc +++ b/src/realm/runtime_impl.cc @@ -2159,6 +2159,7 @@ namespace Realm { bgwork.start_dedicated_workers(*core_reservations); bgwork_profiler.initialize(Network::my_node_id); + bgwork_profiler.register_existing_items(bgwork); PartitioningOpQueue::start_worker_threads(*core_reservations, &bgwork); From 40915d162acc637753296aedfe2dc877de46eee8 Mon Sep 17 00:00:00 2001 From: Mike Date: Wed, 18 Mar 2026 02:44:12 -0700 Subject: [PATCH 06/14] realm: more work on support for background work profiling --- src/CMakeLists.txt | 1 - src/realm/activemsg.cc | 13 +- src/realm/activemsg.h | 2 +- src/realm/bgwork.cc | 463 +++++++++++++++++++++++- src/realm/bgwork.h | 221 ++++++++++- src/realm/bgwork_profile.cc | 456 ----------------------- src/realm/bgwork_profile.h | 228 ------------ src/realm/bgwork_profile.inl | 240 ------------ src/realm/cuda/cuda_internal.cc | 14 +- src/realm/cuda/cuda_internal.h | 3 +- src/realm/cuda/cuda_module.cc | 19 +- src/realm/deppart/partitions.cc | 12 +- src/realm/deppart/partitions.h | 2 +- src/realm/event_impl.cc | 4 +- src/realm/event_impl.h | 2 +- src/realm/gasnet1/gasnetmsg.cc | 5 +- src/realm/gasnetex/gasnetex_internal.cc | 26 +- src/realm/gasnetex/gasnetex_internal.h | 10 +- src/realm/hip/hip_internal.cc | 4 +- src/realm/hip/hip_internal.h | 3 +- src/realm/hip/hip_module.cc | 19 +- src/realm/runtime_impl.h | 1 - src/realm/tasks.cc | 3 +- src/realm/tasks.h | 1 + src/realm/transfer/channel.h | 2 +- src/realm/transfer/channel.inl | 8 +- src/realm/transfer/lowlevel_dma.cc | 3 +- src/realm/transfer/lowlevel_dma.h | 2 +- src/realm/ucx/ucp_internal.cc | 7 +- src/realm/ucx/ucp_internal.h | 2 +- 30 files changed, 775 insertions(+), 1001 deletions(-) delete mode 100644 src/realm/bgwork_profile.cc delete mode 100644 src/realm/bgwork_profile.h delete mode 100644 src/realm/bgwork_profile.inl diff --git a/src/CMakeLists.txt b/src/CMakeLists.txt index 4770e27f394..7054eb2e94b 100644 --- a/src/CMakeLists.txt +++ b/src/CMakeLists.txt @@ -23,7 +23,6 @@ set(REALM_SOURCES timers.cc utils.cc bgwork.cc - bgwork_profile.cc comp_queue_impl.cc event_impl.cc barrier_impl.cc diff --git a/src/realm/activemsg.cc b/src/realm/activemsg.cc index 62a90ae0214..da8a42015ff 100644 --- a/src/realm/activemsg.cc +++ b/src/realm/activemsg.cc @@ -19,7 +19,6 @@ #include "realm/atomics.h" #include "realm/activemsg.h" -#include "realm/bgwork_profile.h" #include "realm/mutex.h" #include "realm/cmdline.h" #include "realm/logging.h" @@ -722,7 +721,8 @@ namespace Realm { return now_active; } - bool IncomingMessageManager::do_work(TimeLimit work_until) + bool IncomingMessageManager::do_work(TimeLimit work_until, + BgWorkProfileState &profstate) { // now that we've been called, our previous request for bgwork has been // granted and we will need another one if/when more work comes @@ -748,6 +748,7 @@ namespace Realm { size_t num_handled = 0; while(current_msg) { + profstate.worked(); Message *next_msg = current_msg->next_msg; #ifdef DETAILED_MESSAGE_TIMING int timing_idx = detailed_message_timing @@ -771,14 +772,14 @@ namespace Realm { t_start = Clock::current_time_in_nanoseconds(); if(current_msg->handler->profile_id_registered) - bgwork_profile_fine_begin(current_msg->handler->profile_sub_item_id); + profstate.fine_begin(current_msg->handler->profile_sub_item_id); (current_msg->handler->handler)(current_msg->sender, current_msg->hdr, current_msg->payload, current_msg->payload_size, work_until); if(current_msg->handler->profile_id_registered) - bgwork_profile_fine_end(); + profstate.fine_end(); } else { // estimate how long this handler will take, clamping at a // semi-arbitrary 20us @@ -806,14 +807,14 @@ namespace Realm { t_start = Clock::current_time_in_nanoseconds(); if(current_msg->handler->profile_id_registered) - bgwork_profile_fine_begin(current_msg->handler->profile_sub_item_id); + profstate.fine_begin(current_msg->handler->profile_sub_item_id); (current_msg->handler->handler_notimeout)(current_msg->sender, current_msg->hdr, current_msg->payload, current_msg->payload_size); if(current_msg->handler->profile_id_registered) - bgwork_profile_fine_end(); + profstate.fine_end(); } long long t_end = 0; diff --git a/src/realm/activemsg.h b/src/realm/activemsg.h index b9eed548dfe..69f191c4020 100644 --- a/src/realm/activemsg.h +++ b/src/realm/activemsg.h @@ -372,7 +372,7 @@ namespace Realm { void shutdown(void); - virtual bool do_work(TimeLimit work_until); + virtual bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); void handler_thread_loop(void); diff --git a/src/realm/bgwork.cc b/src/realm/bgwork.cc index 1fca8d8f7f0..4f2c4ac44c5 100644 --- a/src/realm/bgwork.cc +++ b/src/realm/bgwork.cc @@ -18,15 +18,453 @@ // manager for background work that can be performed by available threads #include "realm/bgwork.h" -#include "realm/bgwork_profile.h" #include "realm/timers.h" #include "realm/logging.h" +#include "realm/network.h" #include "realm/utils.h" #include "realm/numa/numasysif.h" +#include +#include +#include +#include + +#ifdef REALM_ON_WINDOWS +#include +#include +#else +#include +#include +#endif + +#ifdef REALM_BGWORK_PROFILE_USE_ZLIB +#include +#endif + namespace Realm { Logger log_bgwork("bgwork"); + Logger log_bgwork_profile("bgwork_profile"); + + BgWorkProfileManager bgwork_profiler; + + //////////////////////////////////////////////////////////////////////// + // + // class BgWorkProfileManager + // + + BgWorkProfileManager::BgWorkProfileManager() + : profile_level(0) + , initialized(false) + , max_buffer_bytes(1ULL << 30) // 1GB default + , fd(-1) + , node_id(0) + , next_sub_item_id(0) + , free_blocks(nullptr) + , completed_head(nullptr) + , completed_tail(nullptr) + , buffered_bytes(0) + , next_sequence(0) + {} + + BgWorkProfileManager::~BgWorkProfileManager() + { + // free any remaining blocks in the free list + while(free_blocks) { + ProfileBlock *next = free_blocks->next; + delete free_blocks; + free_blocks = next; + } + } + + void BgWorkProfileManager::set_level(int level) { profile_level = level; } + + void BgWorkProfileManager::set_logfile(const std::string &filename) + { + logfile_pattern = filename; + } + + void BgWorkProfileManager::set_bufsize(size_t megabytes) + { + max_buffer_bytes = (megabytes == 0) ? SIZE_MAX : megabytes * (1ULL << 20); + } + + int BgWorkProfileManager::get_level() const { return profile_level; } + + void BgWorkProfileManager::initialize(uint32_t _node_id) + { + if(profile_level == 0) + return; + + node_id = _node_id; + + // determine output filename + std::string filename = logfile_pattern; + if(filename.empty()) + filename = "bgwork_profile_%.bin"; + + // replace % with node ID + size_t pct = filename.find('%'); + if(pct != std::string::npos) { + char buf[32]; + snprintf(buf, sizeof(buf), "%u", node_id); + filename.replace(pct, 1, buf); + } else if(Network::max_node_id > 0) { + log_bgwork_profile.fatal() + << "multi-node run requires '%' in bgwork profile filename: " << filename; + abort(); + } + + // open output file +#ifdef REALM_ON_WINDOWS + fd = _open(filename.c_str(), _O_WRONLY | _O_CREAT | _O_TRUNC | _O_BINARY, 0644); +#else + fd = open(filename.c_str(), O_WRONLY | O_CREAT | O_TRUNC, 0644); +#endif + if(fd < 0) { + log_bgwork_profile.fatal() << "failed to open bgwork profile file: " << filename; + abort(); + } + + log_bgwork_profile.info() << "bgwork profiling enabled: level=" << profile_level + << " file=" << filename + << " bufsize=" << (max_buffer_bytes >> 20) << "MB"; + + // Write header with placeholder counts/offset. Data blocks are appended + // starting at offset HEADER_SIZE. Descriptor tables and final header + // patch happen at shutdown. + write_file_header(); + + initialized = true; + } + + void BgWorkProfileManager::shutdown() + { + if(!initialized) + return; + + // Flush any remaining blocks from registered profiling states. + // Dedicated worker threads flush their own blocks before exiting, + // but task scheduler bgworkers may still have data. + { + AutoLock<> al(thread_mutex); + for(BgWorkProfileState *state : thread_states) { + ProfileBlock* current_block = state->flush(); + if(current_block) { + if(current_block->num_records > 0) { + AutoLock<> bl(block_mutex); + ProfileBlock *block = current_block; + if(completed_tail) { + completed_tail->next = block; + } else { + completed_head = block; + } + completed_tail = block; + block->next = nullptr; + buffered_bytes += block->used; + } else { + AutoLock<> bl(block_mutex); + current_block->next = free_blocks; + free_blocks = current_block; + } + } + // Note: states are not heap-allocated, do not delete + } + thread_states.clear(); + } + + // Flush all remaining in-memory data blocks to disk + flush_all_blocks(); + + // Record current file position -- this is where descriptor tables start + uint64_t desc_offset = lseek(fd, 0, SEEK_CUR); + + // Write descriptor tables (now complete) at end of file + write_descriptor_tables(); + + // Patch header with final counts and descriptor offset + { + AutoLock<> al(desc_mutex); + uint32_t work_count = static_cast(work_item_descs.size()); + uint32_t sub_count = static_cast(sub_item_descs.size()); + lseek(fd, 20, SEEK_SET); + write(fd, &work_count, sizeof(work_count)); + write(fd, &sub_count, sizeof(sub_count)); + write(fd, &desc_offset, sizeof(desc_offset)); + lseek(fd, 0, SEEK_END); + } + + // close file + if(fd >= 0) { +#ifdef REALM_ON_WINDOWS + _close(fd); +#else + close(fd); +#endif + fd = -1; + } + + log_bgwork_profile.info() << "bgwork profiling shutdown complete"; + initialized = false; + } + + void BgWorkProfileManager::register_work_item(uint16_t slot, const std::string &name) + { + AutoLock<> al(desc_mutex); + // check for duplicate + for(const auto &d : work_item_descs) { + if(d.slot == slot) + return; + } + work_item_descs.push_back({slot, name}); + log_bgwork_profile.debug() << "registered work item: slot=" << slot + << " name=" << name; + } + + uint16_t BgWorkProfileManager::register_sub_item(uint8_t type, const std::string &name) + { + AutoLock<> al(desc_mutex); + uint16_t id = next_sub_item_id++; + sub_item_descs.push_back({id, type, name}); + log_bgwork_profile.debug() << "registered sub-item: id=" << id + << " type=" << (int)type << " name=" << name; + return id; + } + + void BgWorkProfileManager::register_existing_items(BackgroundWorkManager &mgr) + { + unsigned count = mgr.num_work_items.load(); + for(unsigned i = 0; i < count; i++) { + BackgroundWorkItem *item = mgr.work_items[i]; + if(item) + register_work_item(static_cast(i), item->name); + } + } + + ProfileBlock *BgWorkProfileManager::alloc_block(uint64_t thread_id) + { + AutoLock<> al(block_mutex); + + ProfileBlock *block; + if(free_blocks) { + block = free_blocks; + free_blocks = block->next; + } else { + block = new ProfileBlock; + } + + block->used = 0; + block->base_timestamp = 0; + block->num_records = 0; + block->thread_id = thread_id; + block->sequence = next_sequence++; + block->next = nullptr; + + return block; + } + + void BgWorkProfileManager::complete_block(ProfileBlock *block) + { + bool need_flush = false; + + { + AutoLock<> al(block_mutex); + + if(completed_tail) { + completed_tail->next = block; + } else { + completed_head = block; + } + completed_tail = block; + block->next = nullptr; + buffered_bytes += block->used; + + need_flush = (buffered_bytes >= max_buffer_bytes); + } + + // Flush half the buffer to keep memory bounded while retaining some + // buffering to reduce write syscall frequency + if(need_flush) + flush_blocks_to_disk(max_buffer_bytes / 2); + } + + void BgWorkProfileManager::register_thread_state(BgWorkProfileState *state) + { + AutoLock<> al(thread_mutex); + thread_states.push_back(state); + } + + void BgWorkProfileManager::unregister_thread_state(BgWorkProfileState *state) + { + AutoLock<> al(thread_mutex); + for(auto it = thread_states.begin(); it != thread_states.end(); ++it) { + if(*it == state) { + thread_states.erase(it); + return; + } + } + } + + void BgWorkProfileManager::write_file_header() + { + // header: magic(4) + version(2) + flags(2) + node_id(4) + zero_time(8) + + // work_item_count(4) + sub_item_count(4) + desc_offset(8) = 36 bytes + uint8_t header[HEADER_SIZE]; + uint8_t *p = header; + + memcpy(p, BGWP_MAGIC, 4); + p += 4; + + uint16_t version = BGWP_VERSION; + memcpy(p, &version, 2); + p += 2; + + uint16_t flags = 0; + if(profile_level >= 2) + flags |= BGWP_FLAG_HAS_FINE; + memcpy(p, &flags, 2); + p += 2; + + memcpy(p, &node_id, 4); + p += 4; + + int64_t zero_time = Clock::get_zero_time(); + memcpy(p, &zero_time, 8); + p += 8; + + // descriptor counts and offset will be patched at shutdown + uint32_t zero32 = 0; + uint64_t zero64 = 0; + memcpy(p, &zero32, 4); + p += 4; // work item count + memcpy(p, &zero32, 4); + p += 4; // sub item count + memcpy(p, &zero64, 8); + p += 8; // descriptor table offset + + ssize_t written = write(fd, header, sizeof(header)); + (void)written; + } + + void BgWorkProfileManager::write_descriptor_tables() + { + AutoLock<> al(desc_mutex); + + // write work item descriptors + for(const auto &d : work_item_descs) { + uint16_t slot = d.slot; + uint16_t name_len = static_cast(d.name.size()); + write(fd, &slot, sizeof(slot)); + write(fd, &name_len, sizeof(name_len)); + write(fd, d.name.data(), name_len); + } + + // write sub-item descriptors + for(const auto &d : sub_item_descs) { + uint16_t id = d.id; + uint8_t type = d.type; + uint16_t name_len = static_cast(d.name.size()); + write(fd, &id, sizeof(id)); + write(fd, &type, sizeof(type)); + write(fd, &name_len, sizeof(name_len)); + write(fd, d.name.data(), name_len); + } + } + + void BgWorkProfileManager::flush_blocks_to_disk(size_t target_size) + { + while(true) { + ProfileBlock *block = nullptr; + { + AutoLock<> al(block_mutex); + if(!completed_head || buffered_bytes <= target_size) + return; + block = completed_head; + completed_head = block->next; + if(!completed_head) + completed_tail = nullptr; + buffered_bytes -= block->used; + } + + // write block header fields individually to avoid padding + uint64_t bh_thread_id = block->thread_id; + uint32_t bh_sequence = block->sequence; + uint32_t bh_record_count = block->num_records; + int64_t bh_base_timestamp = block->base_timestamp; + uint32_t bh_data_size = block->used; + uint32_t bh_compressed_size = 0; + +#ifdef REALM_BGWORK_PROFILE_USE_ZLIB + // try to compress the block + uLongf compressed_bound = compressBound(block->used); + std::vector compressed(compressed_bound); + int zret = compress2(compressed.data(), &compressed_bound, block->data, block->used, + Z_DEFAULT_COMPRESSION); + if(zret == Z_OK && compressed_bound < block->used) { + bh_compressed_size = static_cast(compressed_bound); + } +#endif + + write(fd, &bh_thread_id, 8); + write(fd, &bh_sequence, 4); + write(fd, &bh_record_count, 4); + write(fd, &bh_base_timestamp, 8); + write(fd, &bh_data_size, 4); + write(fd, &bh_compressed_size, 4); + +#ifdef REALM_BGWORK_PROFILE_USE_ZLIB + if(bh_compressed_size > 0) + write(fd, compressed.data(), bh_compressed_size); + else + write(fd, block->data, block->used); +#else + write(fd, block->data, block->used); +#endif + + // return block to free list + { + AutoLock<> al(block_mutex); + block->next = free_blocks; + free_blocks = block; + } + } + } + + void BgWorkProfileManager::flush_all_blocks() { flush_blocks_to_disk(0); } + + //////////////////////////////////////////////////////////////////////// + // + // class BgWorkProfileState + // + + BgWorkProfileState::BgWorkProfileState(void) + : level(bgwork_profiler.get_level()), thread_id(static_cast(std::hash{}(std::this_thread::get_id()))) + { + if(level > 0) { + bgwork_profiler.register_thread_state(this); + } + } + + BgWorkProfileState::~BgWorkProfileState(void) + { + // flush any remaining profiling data and unregister before the + // stack-allocated state goes away + if(level > 0) { + if(current_block) { + if(current_block->num_records > 0) + bgwork_profiler.complete_block(current_block); + current_block = nullptr; + } + bgwork_profiler.unregister_thread_state(this); + } + } + + ProfileBlock* BgWorkProfileState::flush(void) + { + ProfileBlock *current = current_block; + current_block = nullptr; + return current; + } //////////////////////////////////////////////////////////////////////// // @@ -79,12 +517,13 @@ namespace Realm { void BackgroundWorkThread::main_loop(void) { - bgwork_profile_thread_init(); - BackgroundWorkManager::Worker worker; worker.set_manager(manager); worker.set_numa_domain(numa_domain); + // set up per-thread profiling state (stack-allocated, lives for thread lifetime) + BgWorkProfileState profstate; + log_bgwork.info() << "dedicated worker starting - worker=" << this << " numa=" << numa_domain; @@ -99,7 +538,7 @@ namespace Realm { spin_until = -1; // do work until there's none left - while(worker.do_work(-1 /*max_time*/, 0 /*interrupt_flag*/)) { + while(worker.do_work(-1 /*max_time*/, 0 /*interrupt_flag*/, profstate)) { } // and then retest state variable @@ -149,7 +588,7 @@ namespace Realm { } } log_bgwork.debug() << "dedicated worker awake - worker=" << this; - } + } log_bgwork.info() << "dedicated worker terminating - worker=" << this; } @@ -475,12 +914,9 @@ namespace Realm { } bool BackgroundWorkManager::Worker::do_work(long long max_time_in_ns, - atomic *interrupt_flag) + atomic *interrupt_flag, + BgWorkProfileState &profstate) { - // lazily initialize profiling state for this thread - if(bgwork_profiler.get_level() > 0 && !tl_bgwork_profile) - bgwork_profile_thread_init(); - // set our deadline for returning long long work_until_time = ((max_time_in_ns > 0) @@ -572,7 +1008,7 @@ namespace Realm { log_bgwork.debug() << "work claimed: manager=" << manager << " slot=" << slot << " worker=" << this; long long t_start = Clock::current_time_in_nanoseconds(true /*absolute*/); - bgwork_profile_begin(static_cast(slot)); + profstate.begin(static_cast(slot)); // don't spend more than 1ms on any single task before going on to the // next thing - TODO: pull this out as a config variable long long t_quantum = (manager->cfg.work_item_timeslice + t_start); @@ -591,7 +1027,8 @@ namespace Realm { item->make_inactive(); #endif while(true) { - bool requeue = item->do_work(TimeLimit::absolute(t_quantum, interrupt_flag)); + bool requeue = + item->do_work(TimeLimit::absolute(t_quantum, interrupt_flag), profstate); if(requeue) { // we can just call this item's work function again if we're not out // of time and if there's nothing else to do @@ -615,7 +1052,7 @@ namespace Realm { } else break; } - bgwork_profile_end(); + profstate.end(); // end() checks did_work internally // we're done with this slot for now manager->work_item_usecounts[slot].fetch_sub_acqrel(1); diff --git a/src/realm/bgwork.h b/src/realm/bgwork.h index 67b04ee4b17..cba0eb634cf 100644 --- a/src/realm/bgwork.h +++ b/src/realm/bgwork.h @@ -26,13 +26,225 @@ #include "realm/cmdline.h" #include "realm/timers.h" +#include +#include #include +#include namespace Realm { class BackgroundWorkItem; class BackgroundWorkThread; - class BgWorkProfileManager; + class BackgroundWorkManager; + + // Background work profiling for Realm + // + // Binary file format specification (RBWP = Realm Background Work Profile): + // + // FILE HEADER (36 bytes, written at start, counts/offset patched at shutdown): + // Magic: 4 bytes "RBWP" + // Version: uint16_t (currently 1) + // Flags: uint16_t (bit 0 = has fine-grained data) + // Node ID: uint32_t + // Clock zero time: int64_t (nanoseconds, absolute) + // Work item descriptor count: uint32_t (patched at shutdown) + // Sub-item descriptor count: uint32_t (patched at shutdown) + // Descriptor table offset: uint64_t (patched at shutdown) + // + // DATA BLOCKS (appended during run and at shutdown, starting at offset 36): + // Block header: + // Thread ID: uint64_t + // Block sequence: uint32_t + // Record count: uint32_t + // Base timestamp: int64_t + // Data size: uint32_t (uncompressed) + // Compressed size: uint32_t (0 = uncompressed) + // Block data: uint8_t[compressed_size or data_size] + // + // DESCRIPTOR TABLES (written at shutdown, at descriptor_table_offset): + // + // WORK ITEM DESCRIPTOR TABLE: + // For each work item: + // Slot: uint16_t + // Name length: uint16_t + // Name: char[name_length] (not null-terminated) + // + // SUB-ITEM DESCRIPTOR TABLE (follows work item table): + // For each sub-item: + // ID: uint16_t + // Type: uint8_t (0=AM_HANDLER, 1=XFER_CHANNEL, 2=DEPPART_OP, 3=GPU_REAP) + // Name length: uint16_t + // Name: char[name_length] (not null-terminated) + // + // RECORDS within a block (variable-length, packed): + // Timestamp delta: 2, 4, or 8 bytes (see encoding below) + // Record type: uint8_t + // Payload: depends on record type + // + // Timestamp delta encoding: + // If delta fits in 15 bits: 2 bytes, high bit 0: 0bbb bbbb bbbb bbbb + // If delta fits in 30 bits: 4 bytes, high bits 10: 10bb bbbb ... bbbb bbbb + // Otherwise: 8 bytes, high bits 11: 11xx xxxx + 7 more bytes + // (stores absolute timestamp, not delta) + // + // Record types and payloads: + // COARSE_BEGIN (0x01): uint8_t slot + // COARSE_END (0x02): (no payload) + // FINE_BEGIN (0x11): uint16_t sub_item_id + // FINE_END (0x12): (no payload) + // GPU_WORK (0x21): uint64_t proc_id, uint8_t slot, int64_t start, int64_t stop + + // Record type constants + enum BgWorkProfileRecordType : uint8_t + { + BGWP_COARSE_BEGIN = 0x01, + BGWP_COARSE_END = 0x02, + BGWP_FINE_BEGIN = 0x11, + BGWP_FINE_END = 0x12, + BGWP_GPU_WORK = 0x21, + }; + + // Sub-item type constants + enum BgWorkProfileSubItemType : uint8_t + { + BGWP_SUB_AM_HANDLER = 0, + BGWP_SUB_XFER_CHANNEL = 1, + BGWP_SUB_DEPPART_OP = 2, + BGWP_SUB_GPU_REAP = 3, + }; + + // File format constants + static const char BGWP_MAGIC[4] = {'R', 'B', 'W', 'P'}; + static const uint16_t BGWP_VERSION = 1; + static const uint16_t BGWP_FLAG_HAS_FINE = 0x0001; + + struct ProfileBlock { + static const size_t BLOCK_SIZE = 16384; // 16KB + uint8_t data[BLOCK_SIZE]; + uint32_t used; + int64_t base_timestamp; + uint32_t num_records; + uint64_t thread_id; + uint32_t sequence; + ProfileBlock *next; + }; + + class BgWorkProfileState { + private: + const int level; // 0 = disabled, 1 = coarse, 2 = fine + ProfileBlock *current_block = nullptr; + int64_t last_timestamp = 0; // for delta encoding + const uint64_t thread_id = 0; + + // did_work flag: set to true by fine_begin, fine_end, gpu_work, + // or explicitly by do_work implementations; checked by end() + // to decide whether to record or discard + bool did_work = false; + + // saved state for discard (set by begin()) + uint32_t begin_block_used = 0; + uint32_t begin_block_num_records = 0; + int64_t begin_last_timestamp = 0; + public: + BgWorkProfileState(void); + ~BgWorkProfileState(void); + // recording methods (all no-op when level == 0) + inline void begin(uint8_t slot); + inline void end(void); + inline void worked(void) { if(level > 0) did_work = true; } + inline void discard(void); + inline void fine_begin(uint16_t sub_item_id); + inline void fine_end(); + inline void gpu_work(uint64_t proc_id, uint8_t slot, int64_t start, int64_t stop); + ProfileBlock *flush(void); + + private: + uint8_t *ensure_space(size_t needed); + static size_t encode_timestamp(uint8_t *buf, int64_t delta, int64_t absolute); + }; + + struct BgWorkItemDescriptor { + uint16_t slot; + std::string name; + }; + + struct BgWorkSubItemDescriptor { + uint16_t id; + uint8_t type; + std::string name; + }; + + class BgWorkProfileManager { + public: + BgWorkProfileManager(); + ~BgWorkProfileManager(); + + // configuration (called before initialize) + void set_level(int level); + void set_logfile(const std::string &filename); + void set_bufsize(size_t megabytes); + + // returns the configured profiling level (0, 1, or 2) + int get_level() const; + + // lifecycle + void initialize(uint32_t node_id); + void shutdown(); + + // descriptor registration (called during module init, before recording starts) + void register_work_item(uint16_t slot, const std::string &name); + uint16_t register_sub_item(uint8_t type, const std::string &name); + + // retroactively register any work items that were added to the manager + // before the profiler was configured (e.g., network layer items) + void register_existing_items(BackgroundWorkManager &mgr); + + // block management (called by recording functions) + ProfileBlock *alloc_block(uint64_t thread_id); + void complete_block(ProfileBlock *block); + + // state management: Workers register their profstate so shutdown can flush + void register_thread_state(BgWorkProfileState *state); + void unregister_thread_state(BgWorkProfileState *state); + + private: + void write_file_header(); + void write_descriptor_tables(); + void flush_blocks_to_disk(size_t target_size); + void flush_all_blocks(); + + static const size_t HEADER_SIZE = 36; + + int profile_level; + std::string logfile_pattern; + bool initialized; + size_t max_buffer_bytes; + + // file state + int fd; + uint32_t node_id; + + // descriptors + Mutex desc_mutex; + std::vector work_item_descs; + std::vector sub_item_descs; + uint16_t next_sub_item_id; + + // block pool and completed list + Mutex block_mutex; + ProfileBlock *free_blocks; + ProfileBlock *completed_head; + ProfileBlock *completed_tail; + size_t buffered_bytes; + uint32_t next_sequence; + + // registered states (for shutdown flushing) + Mutex thread_mutex; + std::vector thread_states; + }; + + // global instance + extern BgWorkProfileManager bgwork_profiler; class BackgroundWorkManager { public: @@ -72,7 +284,8 @@ namespace Realm { void set_max_timeslice(long long _timeslice_in_ns); void set_numa_domain(int _numa_domain); // -1 == dont care - bool do_work(long long max_time_in_ns, atomic *interrupt_flag); + bool do_work(long long max_time_in_ns, atomic *interrupt_flag, + BgWorkProfileState &profstate); protected: BackgroundWorkManager *manager; @@ -140,7 +353,7 @@ namespace Realm { // true to request requeuing (this is more efficient than calling // 'make_active' at the end of 'do_work') or false if all work has been // completed (or if 'make_active' has already been called) - virtual bool do_work(TimeLimit work_until) = 0; + virtual bool do_work(TimeLimit work_until, BgWorkProfileState &profstate) = 0; // returns the slot index assigned by the background work manager unsigned get_slot() const { return index; } @@ -179,4 +392,6 @@ namespace Realm { }; // namespace Realm +#include "realm/bgwork.inl" + #endif diff --git a/src/realm/bgwork_profile.cc b/src/realm/bgwork_profile.cc deleted file mode 100644 index 4bf6d1176af..00000000000 --- a/src/realm/bgwork_profile.cc +++ /dev/null @@ -1,456 +0,0 @@ -/* - * Copyright 2026 Stanford University, NVIDIA Corporation - * SPDX-License-Identifier: Apache-2.0 - * - * Licensed under the Apache License, Version 2.0 (the "License"); - * you may not use this file except in compliance with the License. - * You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. - */ - -// Background work profiling manager implementation - -#include "realm/bgwork_profile.h" -#include "realm/bgwork.h" -#include "realm/timers.h" -#include "realm/logging.h" -#include "realm/network.h" - -#include -#include -#include -#include - -#ifdef REALM_ON_WINDOWS -#include -#include -#else -#include -#include -#endif - -#ifdef REALM_BGWORK_PROFILE_USE_ZLIB -#include -#endif - -namespace Realm { - - Logger log_bgwork_profile("bgwork_profile"); - - thread_local BgWorkProfileState *tl_bgwork_profile = nullptr; - - BgWorkProfileManager bgwork_profiler; - - BgWorkProfileManager::BgWorkProfileManager() - : profile_level(0) - , initialized(false) - , max_buffer_bytes(1ULL << 30) // 1GB default - , fd(-1) - , node_id(0) - , next_sub_item_id(0) - , free_blocks(nullptr) - , completed_head(nullptr) - , completed_tail(nullptr) - , buffered_bytes(0) - , next_sequence(0) - {} - - BgWorkProfileManager::~BgWorkProfileManager() - { - // free any remaining blocks in the free list - while(free_blocks) { - ProfileBlock *next = free_blocks->next; - delete free_blocks; - free_blocks = next; - } - } - - void BgWorkProfileManager::set_level(int level) { profile_level = level; } - - void BgWorkProfileManager::set_logfile(const std::string &filename) - { - logfile_pattern = filename; - } - - void BgWorkProfileManager::set_bufsize(size_t megabytes) - { - max_buffer_bytes = (megabytes == 0) ? SIZE_MAX : megabytes * (1ULL << 20); - } - - int BgWorkProfileManager::get_level() const { return profile_level; } - - void BgWorkProfileManager::initialize(uint32_t _node_id) - { - if(profile_level == 0) - return; - - node_id = _node_id; - - // determine output filename - std::string filename = logfile_pattern; - if(filename.empty()) - filename = "bgwork_profile_%.bin"; - - // replace % with node ID - size_t pct = filename.find('%'); - if(pct != std::string::npos) { - char buf[32]; - snprintf(buf, sizeof(buf), "%u", node_id); - filename.replace(pct, 1, buf); - } else if(Network::max_node_id > 0) { - log_bgwork_profile.fatal() - << "multi-node run requires '%' in bgwork profile filename: " << filename; - abort(); - } - - // open output file -#ifdef REALM_ON_WINDOWS - fd = _open(filename.c_str(), _O_WRONLY | _O_CREAT | _O_TRUNC | _O_BINARY, 0644); -#else - fd = open(filename.c_str(), O_WRONLY | O_CREAT | O_TRUNC, 0644); -#endif - if(fd < 0) { - log_bgwork_profile.fatal() << "failed to open bgwork profile file: " << filename; - abort(); - } - - log_bgwork_profile.info() << "bgwork profiling enabled: level=" << profile_level - << " file=" << filename - << " bufsize=" << (max_buffer_bytes >> 20) << "MB"; - - // Write header with placeholder counts/offset. Data blocks are appended - // starting at offset HEADER_SIZE. Descriptor tables and final header - // patch happen at shutdown. - write_file_header(); - - initialized = true; - } - - void BgWorkProfileManager::shutdown() - { - if(!initialized) - return; - - // flush all thread-local blocks - { - AutoLock<> al(thread_mutex); - for(BgWorkProfileState *state : thread_states) { - if(state->current_block) { - if(state->current_block->num_records > 0) { - AutoLock<> bl(block_mutex); - ProfileBlock *block = state->current_block; - if(completed_tail) { - completed_tail->next = block; - } else { - completed_head = block; - } - completed_tail = block; - block->next = nullptr; - buffered_bytes += block->used; - } else { - // empty block goes back to free list - AutoLock<> bl(block_mutex); - state->current_block->next = free_blocks; - free_blocks = state->current_block; - } - state->current_block = nullptr; - } - // disable profiling for this thread - // (the thread_local pointer was set to state, but we can't clear - // other threads' TLS - they should have stopped by now) - delete state; - } - thread_states.clear(); - } - - // Flush all remaining in-memory data blocks to disk - flush_all_blocks(); - - // Record current file position — this is where descriptor tables start - uint64_t desc_offset = lseek(fd, 0, SEEK_CUR); - - // Write descriptor tables (now complete) at end of file - write_descriptor_tables(); - - // Patch header with final counts and descriptor offset - { - AutoLock<> al(desc_mutex); - uint32_t work_count = static_cast(work_item_descs.size()); - uint32_t sub_count = static_cast(sub_item_descs.size()); - lseek(fd, 20, SEEK_SET); - write(fd, &work_count, sizeof(work_count)); - write(fd, &sub_count, sizeof(sub_count)); - write(fd, &desc_offset, sizeof(desc_offset)); - lseek(fd, 0, SEEK_END); - } - - // close file - if(fd >= 0) { -#ifdef REALM_ON_WINDOWS - _close(fd); -#else - close(fd); -#endif - fd = -1; - } - - log_bgwork_profile.info() << "bgwork profiling shutdown complete"; - initialized = false; - } - - void BgWorkProfileManager::register_work_item(uint16_t slot, const std::string &name) - { - AutoLock<> al(desc_mutex); - // check for duplicate - for(const auto &d : work_item_descs) { - if(d.slot == slot) - return; - } - work_item_descs.push_back({slot, name}); - log_bgwork_profile.debug() << "registered work item: slot=" << slot - << " name=" << name; - } - - uint16_t BgWorkProfileManager::register_sub_item(uint8_t type, const std::string &name) - { - AutoLock<> al(desc_mutex); - uint16_t id = next_sub_item_id++; - sub_item_descs.push_back({id, type, name}); - log_bgwork_profile.debug() << "registered sub-item: id=" << id - << " type=" << (int)type << " name=" << name; - return id; - } - - void BgWorkProfileManager::register_existing_items(BackgroundWorkManager &mgr) - { - unsigned count = mgr.num_work_items.load(); - for(unsigned i = 0; i < count; i++) { - BackgroundWorkItem *item = mgr.work_items[i]; - if(item) - register_work_item(static_cast(i), item->name); - } - } - - ProfileBlock *BgWorkProfileManager::alloc_block(uint64_t thread_id) - { - AutoLock<> al(block_mutex); - - ProfileBlock *block; - if(free_blocks) { - block = free_blocks; - free_blocks = block->next; - } else { - block = new ProfileBlock; - } - - block->used = 0; - block->base_timestamp = 0; - block->num_records = 0; - block->thread_id = thread_id; - block->sequence = next_sequence++; - block->next = nullptr; - - return block; - } - - void BgWorkProfileManager::complete_block(ProfileBlock *block) - { - bool need_flush = false; - - { - AutoLock<> al(block_mutex); - - if(completed_tail) { - completed_tail->next = block; - } else { - completed_head = block; - } - completed_tail = block; - block->next = nullptr; - buffered_bytes += block->used; - - need_flush = (buffered_bytes >= max_buffer_bytes); - } - - // Flush half the buffer to keep memory bounded while retaining some - // buffering to reduce write syscall frequency - if(need_flush) - flush_blocks_to_disk(max_buffer_bytes / 2); - } - - void BgWorkProfileManager::register_thread_state(BgWorkProfileState *state) - { - AutoLock<> al(thread_mutex); - thread_states.push_back(state); - } - - void BgWorkProfileManager::write_file_header() - { - // header: magic(4) + version(2) + flags(2) + node_id(4) + zero_time(8) + - // work_item_count(4) + sub_item_count(4) + desc_offset(8) = 36 bytes - uint8_t header[HEADER_SIZE]; - uint8_t *p = header; - - memcpy(p, BGWP_MAGIC, 4); - p += 4; - - uint16_t version = BGWP_VERSION; - memcpy(p, &version, 2); - p += 2; - - uint16_t flags = 0; - if(profile_level >= 2) - flags |= BGWP_FLAG_HAS_FINE; - memcpy(p, &flags, 2); - p += 2; - - memcpy(p, &node_id, 4); - p += 4; - - int64_t zero_time = Clock::get_zero_time(); - memcpy(p, &zero_time, 8); - p += 8; - - // descriptor counts and offset will be patched at shutdown - uint32_t zero32 = 0; - uint64_t zero64 = 0; - memcpy(p, &zero32, 4); - p += 4; // work item count - memcpy(p, &zero32, 4); - p += 4; // sub item count - memcpy(p, &zero64, 8); - p += 8; // descriptor table offset - - ssize_t written = write(fd, header, sizeof(header)); - (void)written; - } - - void BgWorkProfileManager::write_descriptor_tables() - { - AutoLock<> al(desc_mutex); - - // write work item descriptors - for(const auto &d : work_item_descs) { - uint16_t slot = d.slot; - uint16_t name_len = static_cast(d.name.size()); - write(fd, &slot, sizeof(slot)); - write(fd, &name_len, sizeof(name_len)); - write(fd, d.name.data(), name_len); - } - - // write sub-item descriptors - for(const auto &d : sub_item_descs) { - uint16_t id = d.id; - uint8_t type = d.type; - uint16_t name_len = static_cast(d.name.size()); - write(fd, &id, sizeof(id)); - write(fd, &type, sizeof(type)); - write(fd, &name_len, sizeof(name_len)); - write(fd, d.name.data(), name_len); - } - } - - void BgWorkProfileManager::flush_blocks_to_disk(size_t target_size) - { - while(true) { - ProfileBlock *block = nullptr; - { - AutoLock<> al(block_mutex); - if(!completed_head || buffered_bytes <= target_size) - return; - block = completed_head; - completed_head = block->next; - if(!completed_head) - completed_tail = nullptr; - buffered_bytes -= block->used; - } - - // write block header fields individually to avoid padding - uint64_t bh_thread_id = block->thread_id; - uint32_t bh_sequence = block->sequence; - uint32_t bh_record_count = block->num_records; - int64_t bh_base_timestamp = block->base_timestamp; - uint32_t bh_data_size = block->used; - uint32_t bh_compressed_size = 0; - -#ifdef REALM_BGWORK_PROFILE_USE_ZLIB - // try to compress the block - uLongf compressed_bound = compressBound(block->used); - std::vector compressed(compressed_bound); - int zret = compress2(compressed.data(), &compressed_bound, block->data, block->used, - Z_DEFAULT_COMPRESSION); - if(zret == Z_OK && compressed_bound < block->used) { - bh_compressed_size = static_cast(compressed_bound); - } -#endif - - write(fd, &bh_thread_id, 8); - write(fd, &bh_sequence, 4); - write(fd, &bh_record_count, 4); - write(fd, &bh_base_timestamp, 8); - write(fd, &bh_data_size, 4); - write(fd, &bh_compressed_size, 4); - -#ifdef REALM_BGWORK_PROFILE_USE_ZLIB - if(bh_compressed_size > 0) - write(fd, compressed.data(), bh_compressed_size); - else - write(fd, block->data, block->used); -#else - write(fd, block->data, block->used); -#endif - - // return block to free list - { - AutoLock<> al(block_mutex); - block->next = free_blocks; - free_blocks = block; - } - } - } - - void BgWorkProfileManager::flush_all_blocks() { flush_blocks_to_disk(0); } - - void bgwork_profile_thread_init() - { - if(bgwork_profiler.get_level() == 0) - return; - if(tl_bgwork_profile) - return; // already initialized - - BgWorkProfileState *state = new BgWorkProfileState; - state->current_block = nullptr; - state->last_timestamp = 0; - // use hash of std::thread::id as our thread identifier - state->thread_id = - static_cast(std::hash{}(std::this_thread::get_id())); - - tl_bgwork_profile = state; - bgwork_profiler.register_thread_state(state); - } - - void bgwork_profile_thread_fini() - { - BgWorkProfileState *state = tl_bgwork_profile; - if(!state) - return; - - // flush current block if it has data - if(state->current_block && state->current_block->num_records > 0) { - bgwork_profiler.complete_block(state->current_block); - state->current_block = nullptr; - } - - tl_bgwork_profile = nullptr; - // note: state is not freed here - the manager owns the pointer list - // and will clean up at shutdown - } - -}; // namespace Realm diff --git a/src/realm/bgwork_profile.h b/src/realm/bgwork_profile.h deleted file mode 100644 index 148c75a60fe..00000000000 --- a/src/realm/bgwork_profile.h +++ /dev/null @@ -1,228 +0,0 @@ -/* - * Copyright 2026 Stanford University, NVIDIA Corporation - * SPDX-License-Identifier: Apache-2.0 - * - * Licensed under the Apache License, Version 2.0 (the "License"); - * you may not use this file except in compliance with the License. - * You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. - */ - -// Background work profiling for Realm -// -// Binary file format specification (RBWP = Realm Background Work Profile): -// -// FILE HEADER (36 bytes, written at start, counts/offset patched at shutdown): -// Magic: 4 bytes "RBWP" -// Version: uint16_t (currently 1) -// Flags: uint16_t (bit 0 = has fine-grained data) -// Node ID: uint32_t -// Clock zero time: int64_t (nanoseconds, absolute) -// Work item descriptor count: uint32_t (patched at shutdown) -// Sub-item descriptor count: uint32_t (patched at shutdown) -// Descriptor table offset: uint64_t (patched at shutdown) -// -// DATA BLOCKS (appended during run and at shutdown, starting at offset 36): -// Block header: -// Thread ID: uint64_t -// Block sequence: uint32_t -// Record count: uint32_t -// Base timestamp: int64_t -// Data size: uint32_t (uncompressed) -// Compressed size: uint32_t (0 = uncompressed) -// Block data: uint8_t[compressed_size or data_size] -// -// DESCRIPTOR TABLES (written at shutdown, at descriptor_table_offset): -// -// WORK ITEM DESCRIPTOR TABLE: -// For each work item: -// Slot: uint16_t -// Name length: uint16_t -// Name: char[name_length] (not null-terminated) -// -// SUB-ITEM DESCRIPTOR TABLE (follows work item table): -// For each sub-item: -// ID: uint16_t -// Type: uint8_t (0=AM_HANDLER, 1=XFER_CHANNEL, 2=DEPPART_OP, 3=GPU_REAP) -// Name length: uint16_t -// Name: char[name_length] (not null-terminated) -// -// RECORDS within a block (variable-length, packed): -// Timestamp delta: 2, 4, or 8 bytes (see encoding below) -// Record type: uint8_t -// Payload: depends on record type -// -// Timestamp delta encoding: -// If delta fits in 15 bits: 2 bytes, high bit 0: 0bbb bbbb bbbb bbbb -// If delta fits in 30 bits: 4 bytes, high bits 10: 10bb bbbb ... bbbb bbbb -// Otherwise: 8 bytes, high bits 11: 11xx xxxx + 7 more bytes -// (stores absolute timestamp, not delta) -// -// Record types and payloads: -// COARSE_BEGIN (0x01): uint8_t slot -// COARSE_END (0x02): (no payload) -// FINE_BEGIN (0x11): uint16_t sub_item_id -// FINE_END (0x12): (no payload) -// GPU_WORK (0x21): uint64_t proc_id, uint8_t slot, int64_t start, int64_t stop - -#ifndef REALM_BGWORK_PROFILE_H -#define REALM_BGWORK_PROFILE_H - -#include "realm/realm_config.h" -#include "realm/mutex.h" -#include "realm/atomics.h" - -#include -#include -#include -#include - -namespace Realm { - - class BackgroundWorkManager; - - // Record type constants - enum BgWorkProfileRecordType : uint8_t - { - BGWP_COARSE_BEGIN = 0x01, - BGWP_COARSE_END = 0x02, - BGWP_FINE_BEGIN = 0x11, - BGWP_FINE_END = 0x12, - BGWP_GPU_WORK = 0x21, - }; - - // Sub-item type constants - enum BgWorkProfileSubItemType : uint8_t - { - BGWP_SUB_AM_HANDLER = 0, - BGWP_SUB_XFER_CHANNEL = 1, - BGWP_SUB_DEPPART_OP = 2, - BGWP_SUB_GPU_REAP = 3, - }; - - // File format constants - static const char BGWP_MAGIC[4] = {'R', 'B', 'W', 'P'}; - static const uint16_t BGWP_VERSION = 1; - static const uint16_t BGWP_FLAG_HAS_FINE = 0x0001; - - struct ProfileBlock { - static const size_t BLOCK_SIZE = 16384; // 16KB - uint8_t data[BLOCK_SIZE]; - uint32_t used; - int64_t base_timestamp; - uint32_t num_records; - uint64_t thread_id; - uint32_t sequence; - ProfileBlock *next; - }; - - struct BgWorkProfileState { - ProfileBlock *current_block; - int64_t last_timestamp; // for delta encoding - uint64_t thread_id; - }; - - // thread-local pointer: null when profiling is disabled - extern thread_local BgWorkProfileState *tl_bgwork_profile; - - struct BgWorkItemDescriptor { - uint16_t slot; - std::string name; - }; - - struct BgWorkSubItemDescriptor { - uint16_t id; - uint8_t type; - std::string name; - }; - - class BgWorkProfileManager { - public: - BgWorkProfileManager(); - ~BgWorkProfileManager(); - - // configuration (called before initialize) - void set_level(int level); - void set_logfile(const std::string &filename); - void set_bufsize(size_t megabytes); - - // returns the configured profiling level (0, 1, or 2) - int get_level() const; - - // lifecycle - void initialize(uint32_t node_id); - void shutdown(); - - // descriptor registration (called during module init, before recording starts) - void register_work_item(uint16_t slot, const std::string &name); - uint16_t register_sub_item(uint8_t type, const std::string &name); - - // retroactively register any work items that were added to the manager - // before the profiler was configured (e.g., network layer items) - void register_existing_items(BackgroundWorkManager &mgr); - - // block management (called by recording functions) - ProfileBlock *alloc_block(uint64_t thread_id); - void complete_block(ProfileBlock *block); - - // thread state management - void register_thread_state(BgWorkProfileState *state); - - private: - void write_file_header(); - void write_descriptor_tables(); - void flush_blocks_to_disk(size_t target_size); - void flush_all_blocks(); - - static const size_t HEADER_SIZE = 36; - - int profile_level; - std::string logfile_pattern; - bool initialized; - size_t max_buffer_bytes; - - // file state - int fd; - uint32_t node_id; - - // descriptors - Mutex desc_mutex; - std::vector work_item_descs; - std::vector sub_item_descs; - uint16_t next_sub_item_id; - - // block pool and completed list - Mutex block_mutex; - ProfileBlock *free_blocks; - ProfileBlock *completed_head; - ProfileBlock *completed_tail; - size_t buffered_bytes; - uint32_t next_sequence; - - // thread states (for shutdown flushing) - Mutex thread_mutex; - std::vector thread_states; - }; - - // global instance - extern BgWorkProfileManager bgwork_profiler; - - // call at thread entry to set up thread-local profiling state - // safe to call when profiling is disabled (does nothing) - void bgwork_profile_thread_init(); - - // call at thread exit to flush thread-local block - void bgwork_profile_thread_fini(); - -}; // namespace Realm - -#include "realm/bgwork_profile.inl" - -#endif // REALM_BGWORK_PROFILE_H diff --git a/src/realm/bgwork_profile.inl b/src/realm/bgwork_profile.inl deleted file mode 100644 index 784e8e5eead..00000000000 --- a/src/realm/bgwork_profile.inl +++ /dev/null @@ -1,240 +0,0 @@ -/* - * Copyright 2026 Stanford University, NVIDIA Corporation - * SPDX-License-Identifier: Apache-2.0 - * - * Licensed under the Apache License, Version 2.0 (the "License"); - * you may not use this file except in compliance with the License. - * You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. - */ - -// inline recording functions for background work profiling -// these are the hot path - every call checks tl_bgwork_profile first - -#ifndef REALM_BGWORK_PROFILE_INL -#define REALM_BGWORK_PROFILE_INL - -#include "realm/timers.h" - -#include - -namespace Realm { - - // Timestamp delta encoding: - // 15-bit: 2 bytes, MSB=0 - // 30-bit: 4 bytes, MSB=10 - // 64-bit: 8 bytes, MSB=11 (stores absolute timestamp) - inline size_t bgwork_profile_encode_timestamp(uint8_t *buf, int64_t delta, - int64_t absolute) - { - if(delta >= 0 && delta < (1 << 15)) { - uint16_t val = static_cast(delta); - buf[0] = (val >> 8) & 0x7F; - buf[1] = val & 0xFF; - return 2; - } else if(delta >= 0 && delta < (1LL << 30)) { - uint32_t val = static_cast(delta) | 0x80000000U; - buf[0] = (val >> 24) & 0xFF; - buf[1] = (val >> 16) & 0xFF; - buf[2] = (val >> 8) & 0xFF; - buf[3] = val & 0xFF; - return 4; - } else { - // 8-byte encoding: store absolute timestamp - uint64_t val = static_cast(absolute); - buf[0] = 0xC0 | ((val >> 56) & 0x3F); - buf[1] = (val >> 48) & 0xFF; - buf[2] = (val >> 40) & 0xFF; - buf[3] = (val >> 32) & 0xFF; - buf[4] = (val >> 24) & 0xFF; - buf[5] = (val >> 16) & 0xFF; - buf[6] = (val >> 8) & 0xFF; - buf[7] = val & 0xFF; - return 8; - } - } - - // ensures enough space in the current block, rotating if needed - // returns pointer to write position, or nullptr on failure - inline uint8_t *bgwork_profile_ensure_space(BgWorkProfileState *state, - size_t needed) - { - ProfileBlock *block = state->current_block; - if(block && (block->used + needed <= ProfileBlock::BLOCK_SIZE)) - return block->data + block->used; - - // need a new block - complete old one and get fresh - if(block) - bgwork_profiler.complete_block(block); - - block = bgwork_profiler.alloc_block(state->thread_id); - state->current_block = block; - if(!block) - return nullptr; - - // reset delta encoding for new block - state->last_timestamp = 0; - return block->data; - } - - inline void bgwork_profile_begin(uint8_t slot) - { - BgWorkProfileState *state = tl_bgwork_profile; - if(!state) - return; - - int64_t now = Clock::current_time_in_nanoseconds(true /*absolute*/); - - // max record size: 8 (timestamp) + 1 (type) + 1 (slot) = 10 - uint8_t *buf = bgwork_profile_ensure_space(state, 10); - if(!buf) - return; - - ProfileBlock *block = state->current_block; - if(block->num_records == 0) - block->base_timestamp = now; - - int64_t delta = now - state->last_timestamp; - size_t ts_size = bgwork_profile_encode_timestamp(buf, delta, now); - buf += ts_size; - - *buf++ = BGWP_COARSE_BEGIN; - *buf++ = slot; - - block->used += ts_size + 2; - block->num_records++; - state->last_timestamp = now; - } - - inline void bgwork_profile_end() - { - BgWorkProfileState *state = tl_bgwork_profile; - if(!state) - return; - - int64_t now = Clock::current_time_in_nanoseconds(true /*absolute*/); - - // max: 8 (timestamp) + 1 (type) = 9 - uint8_t *buf = bgwork_profile_ensure_space(state, 9); - if(!buf) - return; - - ProfileBlock *block = state->current_block; - if(block->num_records == 0) - block->base_timestamp = now; - - int64_t delta = now - state->last_timestamp; - size_t ts_size = bgwork_profile_encode_timestamp(buf, delta, now); - buf += ts_size; - - *buf++ = BGWP_COARSE_END; - - block->used += ts_size + 1; - block->num_records++; - state->last_timestamp = now; - } - - inline void bgwork_profile_fine_begin(uint16_t sub_item_id) - { - BgWorkProfileState *state = tl_bgwork_profile; - if(!state) - return; - - int64_t now = Clock::current_time_in_nanoseconds(true /*absolute*/); - - // max: 8 + 1 + 2 = 11 - uint8_t *buf = bgwork_profile_ensure_space(state, 11); - if(!buf) - return; - - ProfileBlock *block = state->current_block; - if(block->num_records == 0) - block->base_timestamp = now; - - int64_t delta = now - state->last_timestamp; - size_t ts_size = bgwork_profile_encode_timestamp(buf, delta, now); - buf += ts_size; - - *buf++ = BGWP_FINE_BEGIN; - memcpy(buf, &sub_item_id, sizeof(uint16_t)); - buf += sizeof(uint16_t); - - block->used += ts_size + 3; - block->num_records++; - state->last_timestamp = now; - } - - inline void bgwork_profile_fine_end() - { - BgWorkProfileState *state = tl_bgwork_profile; - if(!state) - return; - - int64_t now = Clock::current_time_in_nanoseconds(true /*absolute*/); - - // max: 8 + 1 = 9 - uint8_t *buf = bgwork_profile_ensure_space(state, 9); - if(!buf) - return; - - ProfileBlock *block = state->current_block; - if(block->num_records == 0) - block->base_timestamp = now; - - int64_t delta = now - state->last_timestamp; - size_t ts_size = bgwork_profile_encode_timestamp(buf, delta, now); - buf += ts_size; - - *buf++ = BGWP_FINE_END; - - block->used += ts_size + 1; - block->num_records++; - state->last_timestamp = now; - } - - inline void bgwork_profile_gpu_work(uint64_t proc_id, uint8_t slot, - int64_t start_time, int64_t stop_time) - { - BgWorkProfileState *state = tl_bgwork_profile; - if(!state) - return; - - int64_t now = Clock::current_time_in_nanoseconds(true /*absolute*/); - - // max: 8 (timestamp) + 1 (type) + 8 (proc_id) + 1 (slot) + 8 (start) + 8 (stop) = 34 - uint8_t *buf = bgwork_profile_ensure_space(state, 34); - if(!buf) - return; - - ProfileBlock *block = state->current_block; - if(block->num_records == 0) - block->base_timestamp = now; - - int64_t delta = now - state->last_timestamp; - size_t ts_size = bgwork_profile_encode_timestamp(buf, delta, now); - buf += ts_size; - - *buf++ = BGWP_GPU_WORK; - memcpy(buf, &proc_id, sizeof(uint64_t)); - buf += sizeof(uint64_t); - *buf++ = slot; - memcpy(buf, &start_time, sizeof(int64_t)); - buf += sizeof(int64_t); - memcpy(buf, &stop_time, sizeof(int64_t)); - buf += sizeof(int64_t); - - block->used += ts_size + 26; - block->num_records++; - state->last_timestamp = now; - } - -}; // namespace Realm - -#endif // REALM_BGWORK_PROFILE_INL diff --git a/src/realm/cuda/cuda_internal.cc b/src/realm/cuda/cuda_internal.cc index cc3ae33805c..de8850d6310 100644 --- a/src/realm/cuda/cuda_internal.cc +++ b/src/realm/cuda/cuda_internal.cc @@ -764,7 +764,7 @@ namespace Realm { if(in_gpu && in_gpu->can_access_peer(out_gpu) && transpose_copy.extents[0] != 0 && transpose_copy.extents[0] <= CUDA_MAX_FIELD_BYTES) { - if(!gpu_timing && tl_bgwork_profile) { + if(!gpu_timing && bgwork_profiler.get_level() > 0) { gpu_timing = new BgWorkGpuCudaNotification(stream->get_gpu()->proc->me.id, channel->get_bgwork_slot()); stream->add_notification(gpu_timing); @@ -827,7 +827,7 @@ namespace Realm { log_gpudma.info() << "\tLaunching kernel for rects=" << copy_infos.num_rects << " bytes=" << copy_info_total << " out_is_ipc=" << out_is_ipc; - if(!gpu_timing && tl_bgwork_profile) { + if(!gpu_timing && bgwork_profiler.get_level() > 0) { gpu_timing = new BgWorkGpuCudaNotification(stream->get_gpu()->proc->me.id, channel->get_bgwork_slot()); stream->add_notification(gpu_timing); @@ -1186,7 +1186,7 @@ namespace Realm { : SingleXDQChannel( bgwork, _kind, stringbuilder() << "cuda channel (gpu=" << _src_gpu->info->index - << " kind=" << (int)_kind << ")") + << " kind=" << _kind << ")") { src_gpu = _src_gpu; @@ -1467,7 +1467,7 @@ namespace Realm { : SingleXDQChannel( bgwork, _kind, stringbuilder() << "cuda channel (gpu=" << _src_gpu->info->index - << " kind=" << (int)_kind << ")") + << " kind=" << _kind << ")") { src_gpu = _src_gpu; @@ -1911,7 +1911,7 @@ namespace Realm { Realm::Cuda::AffineFillInfo<2, size_t>::MAX_NUM_RECTS) { // Filled the current info, time to start all over log_gpudma.info() << "pushing fill kernel"; - if(!gpu_timing && tl_bgwork_profile) { + if(!gpu_timing && bgwork_profiler.get_level() > 0) { gpu_timing = new BgWorkGpuCudaNotification( stream->get_gpu()->proc->me.id, channel->get_bgwork_slot()); stream->add_notification(gpu_timing); @@ -2095,7 +2095,7 @@ namespace Realm { if(fill_info.num_rects > 0) { log_gpudma.info() << "pushing fill kernel"; - if(!gpu_timing && tl_bgwork_profile) { + if(!gpu_timing && bgwork_profiler.get_level() > 0) { gpu_timing = new BgWorkGpuCudaNotification(stream->get_gpu()->proc->me.id, channel->get_bgwork_slot()); stream->add_notification(gpu_timing); @@ -2489,7 +2489,7 @@ namespace Realm { { AutoGPUContext agc(channel->gpu); - if(!gpu_timing && tl_bgwork_profile) { + if(!gpu_timing && bgwork_profiler.get_level() > 0) { gpu_timing = new BgWorkGpuCudaNotification( stream->get_gpu()->proc->me.id, channel->get_bgwork_slot()); stream->add_notification(gpu_timing); diff --git a/src/realm/cuda/cuda_internal.h b/src/realm/cuda/cuda_internal.h index c0406a309e4..d9d934a0228 100644 --- a/src/realm/cuda/cuda_internal.h +++ b/src/realm/cuda/cuda_internal.h @@ -43,7 +43,6 @@ #include "realm/proc_impl.h" #include "realm/mem_impl.h" #include "realm/bgwork.h" -#include "realm/bgwork_profile.h" #include "realm/transfer/channel.h" #include "realm/transfer/ib_memory.h" #include "realm/cuda/cuda_memcpy.h" @@ -325,7 +324,7 @@ namespace Realm { void start_background_thread(Realm::CoreReservationSet &crs, size_t stack_size); void shutdown_background_thread(void); - bool do_work(TimeLimit work_until); + bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); public: void thread_main(void); diff --git a/src/realm/cuda/cuda_module.cc b/src/realm/cuda/cuda_module.cc index b6039e2004c..7a7ff0e6a34 100644 --- a/src/realm/cuda/cuda_module.cc +++ b/src/realm/cuda/cuda_module.cc @@ -63,6 +63,10 @@ namespace Realm { namespace Cuda { + // file-local thread_local used by GPUWorker::do_work to communicate + // the profiling state to BgWorkGpuCudaNotification::request_completed + static thread_local BgWorkProfileState *tl_gpu_profstate = nullptr; + enum CudaIpcResponseType { CUDA_IPC_RESPONSE_TYPE_IPC = 0, @@ -383,7 +387,8 @@ namespace Realm { started = true; } else { int64_t stop_time = Clock::current_time_in_nanoseconds(true /*absolute*/); - bgwork_profile_gpu_work(proc_id, slot, start_time, stop_time); + if(tl_gpu_profstate) + tl_gpu_profstate->gpu_work(proc_id, slot, start_time, stop_time); delete this; } } @@ -1326,7 +1331,7 @@ namespace Realm { } GPUWorker::GPUWorker(void) - : BackgroundWorkItem("gpu worker") + : BackgroundWorkItem("cuda poll") , condvar(lock) , core_rsrv(0) , worker_thread(0) @@ -1403,8 +1408,11 @@ namespace Realm { make_active(); } - bool GPUWorker::do_work(TimeLimit work_until) + bool GPUWorker::do_work(TimeLimit work_until, BgWorkProfileState &profstate) { + // make profstate available to GPU notifications during reap_events + tl_gpu_profstate = &profstate; + // pop the first stream off the list and immediately become re-active // if more streams remain GPUStream *stream = 0; @@ -1432,11 +1440,12 @@ namespace Realm { // time bool was_empty = false; if(profile_id_registered) - bgwork_profile_fine_begin(profile_sub_item_id); + profstate.fine_begin(profile_sub_item_id); bool has_more = stream->reap_events(work_until); if(profile_id_registered) - bgwork_profile_fine_end(); + profstate.fine_end(); if(has_more) { + profstate.worked(); AutoLock<> al(lock); was_empty = active_streams.empty(); diff --git a/src/realm/deppart/partitions.cc b/src/realm/deppart/partitions.cc index 6eb3516bf85..e01e7d848bb 100644 --- a/src/realm/deppart/partitions.cc +++ b/src/realm/deppart/partitions.cc @@ -943,7 +943,7 @@ namespace Realm { make_active(); } - bool PartitioningOpQueue::do_work(TimeLimit work_until) + bool PartitioningOpQueue::do_work(TimeLimit work_until, BgWorkProfileState &profstate) { // attempt to take one item off the work queue - readvertise work if // more remains @@ -981,14 +981,15 @@ namespace Realm { // (neither branch will be taken if there are dedicated workers and they // already got to the queued operations) if(op != 0) { + profstate.worked(); bool ok_to_run = op->mark_started(); if(ok_to_run) { log_part.info() << "worker " << this << " starting op " << op; if(profile_id_registered) - bgwork_profile_fine_begin(profile_sub_item_id); + profstate.fine_begin(profile_sub_item_id); op->execute(); if(profile_id_registered) - bgwork_profile_fine_end(); + profstate.fine_end(); log_part.info() << "worker " << this << " finished op " << op; op->mark_finished(true /*successful*/); } else { @@ -998,13 +999,14 @@ namespace Realm { } if(uop != 0) { + profstate.worked(); log_part.info() << "worker " << this << " starting uop " << uop; uop->mark_started(); if(profile_id_registered) - bgwork_profile_fine_begin(profile_sub_item_id); + profstate.fine_begin(profile_sub_item_id); uop->execute(); if(profile_id_registered) - bgwork_profile_fine_end(); + profstate.fine_end(); log_part.info() << "worker " << this << " finished uop " << uop; uop->mark_finished(); } diff --git a/src/realm/deppart/partitions.h b/src/realm/deppart/partitions.h index 4b3529bacdf..33e0ba57037 100644 --- a/src/realm/deppart/partitions.h +++ b/src/realm/deppart/partitions.h @@ -207,7 +207,7 @@ namespace Realm { void worker_thread_loop(void); // called by BackgroundWorkers - bool do_work(TimeLimit work_until); + bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); protected: atomic shutdown_flag; diff --git a/src/realm/event_impl.cc b/src/realm/event_impl.cc index 9cb6133caf5..99a059523ed 100644 --- a/src/realm/event_impl.cc +++ b/src/realm/event_impl.cc @@ -510,7 +510,7 @@ namespace Realm { nested_normal = nested_poisoned = 0; } - bool EventTriggerNotifier::do_work(TimeLimit work_until) + bool EventTriggerNotifier::do_work(TimeLimit work_until, BgWorkProfileState &profstate) { // take the lock and grab both lists EventWaiter::EventWaiterList todo_normal, todo_poisoned; @@ -529,9 +529,11 @@ namespace Realm { // TODO: triggers are fast - consider doing more than one per time check? if(!todo_normal.empty()) { EventWaiter *w = todo_normal.pop_front(); + profstate.worked(); w->event_triggered(false /*!poisoned*/, work_until); } else if(!todo_poisoned.empty()) { EventWaiter *w = todo_poisoned.pop_front(); + profstate.worked(); w->event_triggered(true /*poisoned*/, work_until); } else break; diff --git a/src/realm/event_impl.h b/src/realm/event_impl.h index 58428a5c526..a9b4a4800e3 100644 --- a/src/realm/event_impl.h +++ b/src/realm/event_impl.h @@ -70,7 +70,7 @@ namespace Realm { void trigger_event_waiters(EventWaiter::EventWaiterList &to_trigger, bool poisoned, TimeLimit trigger_until); - virtual bool do_work(TimeLimit work_until); + virtual bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); protected: Mutex mutex; diff --git a/src/realm/gasnet1/gasnetmsg.cc b/src/realm/gasnet1/gasnetmsg.cc index d0bcd2cccb2..d4b7c04530e 100644 --- a/src/realm/gasnet1/gasnetmsg.cc +++ b/src/realm/gasnet1/gasnetmsg.cc @@ -33,6 +33,7 @@ #include "realm/threads.h" #include "realm/timers.h" #include "realm/logging.h" +#include "realm/bgwork.h" // so OpenMPI borrowed gasnet's platform-detection code and didn't change // the define names - work around it by undef'ing anything set via mpi.h @@ -2388,7 +2389,7 @@ class EndpointManager : public BackgroundWorkItem { void stop_threads(void); - virtual bool do_work(TimeLimit work_until); + virtual bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); protected: // runs in a separate thread @@ -2793,7 +2794,7 @@ void EndpointManager::stop_threads(void) #endif } -bool EndpointManager::do_work(TimeLimit work_until) +bool EndpointManager::do_work(TimeLimit work_until, BgWorkProfileState &profstate) { // make sure nested active mesage calls respect the time limit ThreadLocal::gasnet_work_until = &work_until; diff --git a/src/realm/gasnetex/gasnetex_internal.cc b/src/realm/gasnetex/gasnetex_internal.cc index 7060d3e4ec4..06dd09792d5 100644 --- a/src/realm/gasnetex/gasnetex_internal.cc +++ b/src/realm/gasnetex/gasnetex_internal.cc @@ -130,6 +130,7 @@ namespace Realm { namespace ThreadLocal { thread_local const TimeLimit *gex_work_until = nullptr; + thread_local BgWorkProfileState* gex_bgwork_profstate = nullptr; thread_local bool in_am_handler = false; }; // namespace ThreadLocal @@ -566,8 +567,9 @@ namespace Realm { make_active(); } - bool OutbufManager::do_work(TimeLimit work_until) + bool OutbufManager::do_work(TimeLimit work_until, BgWorkProfileState &profstate) { + profstate.worked(); // take the mutex and grab the first overflow and reserved realbuf - // don't decrement the counts yet, because we don't want more than one // thread working on this at a time @@ -2714,8 +2716,9 @@ namespace Realm { return !ready_xpairs.empty(); } - bool GASNetEXInjector::do_work(TimeLimit work_until) + bool GASNetEXInjector::do_work(TimeLimit work_until, BgWorkProfileState &profstate) { + profstate.worked(); // we're not supposed to end up handling AMs, but set this just in case // we do ThreadLocal::gex_work_until = &work_until; @@ -2804,9 +2807,10 @@ namespace Realm { return (!critical_xpairs.empty() || !pending_events.empty()); } - bool GASNetEXPoller::do_work(TimeLimit work_until) + bool GASNetEXPoller::do_work(TimeLimit work_until, BgWorkProfileState &profstate) { ThreadLocal::gex_work_until = &work_until; + ThreadLocal::gex_bgwork_profstate = &profstate; // we're going to try to be frugal about acquiring mutexes here, so peek // ahead in the critical xpair list to avoid the extra mutex acquire that @@ -2876,6 +2880,7 @@ namespace Realm { // try to push packets for any xmit pairs that are critical (i.e. cannot // use immediate mode) while(have_crit_xpairs) { + profstate.worked(); XmitSrcDestPair *xpair = nullptr; // don't wait on contention for the mutex - just skip and get it @@ -2921,6 +2926,7 @@ namespace Realm { gex_wrapper_handle.gex_am_poll(); ThreadLocal::gex_work_until = nullptr; + ThreadLocal::gex_bgwork_profstate = nullptr; // if there was a pollwaiter before we started the poll, we can wake it // now @@ -2976,7 +2982,7 @@ namespace Realm { bool GASNetEXCompleter::has_work_remaining() { return has_work.load(); } - bool GASNetEXCompleter::do_work(TimeLimit work_until) + bool GASNetEXCompleter::do_work(TimeLimit work_until, BgWorkProfileState &profstate) { // grab all the events but don't clear 'has_work' since we don't want // to be reactivated yet @@ -2987,6 +2993,7 @@ namespace Realm { } while(!todo.empty()) { + profstate.worked(); GASNetEXEvent *ev = todo.pop_front(); ev->trigger(internal); internal->event_alloc.free_obj(ev); @@ -3066,8 +3073,9 @@ namespace Realm { return (head != nullptr); } - bool ReverseGetter::do_work(TimeLimit work_until) + bool ReverseGetter::do_work(TimeLimit work_until, BgWorkProfileState &profstate) { + profstate.worked(); // we're not going to use immedate mode for rgets, so don't have more // than one dequeuer at a time - do this by peeking at the head but // not popping it until we've actually issued the rget @@ -5028,6 +5036,8 @@ namespace Realm { ((ThreadLocal::gex_work_until != nullptr) ? *ThreadLocal::gex_work_until : TimeLimit::relative(0))); ThreadLocal::in_am_handler = false; + if(ThreadLocal::gex_bgwork_profstate) + ThreadLocal::gex_bgwork_profstate->worked(); if(handled) { // if the message was handled immediately, we can use a reply for @@ -5078,6 +5088,8 @@ namespace Realm { ((ThreadLocal::gex_work_until != nullptr) ? *ThreadLocal::gex_work_until : TimeLimit::relative(0))); ThreadLocal::in_am_handler = false; + if(ThreadLocal::gex_bgwork_profstate) + ThreadLocal::gex_bgwork_profstate->worked(); if(handled) { // if the message was handled immediately, we can use a reply for @@ -5129,6 +5141,8 @@ namespace Realm { ((ThreadLocal::gex_work_until != nullptr) ? *ThreadLocal::gex_work_until : TimeLimit::relative(0))); ThreadLocal::in_am_handler = false; + if(ThreadLocal::gex_bgwork_profstate) + ThreadLocal::gex_bgwork_profstate->worked(); if(handled) { // if the message was handled immediately, we can use a reply for @@ -5294,6 +5308,8 @@ namespace Realm { } ThreadLocal::in_am_handler = false; + if(ThreadLocal::gex_bgwork_profstate) + ThreadLocal::gex_bgwork_profstate->worked(); } }; // namespace Realm diff --git a/src/realm/gasnetex/gasnetex_internal.h b/src/realm/gasnetex/gasnetex_internal.h index dae2fc95e1c..9aa5990f745 100644 --- a/src/realm/gasnetex/gasnetex_internal.h +++ b/src/realm/gasnetex/gasnetex_internal.h @@ -142,7 +142,7 @@ namespace Realm { bool new_endpoint); void free_outbuf(OutbufMetadata *md); - virtual bool do_work(TimeLimit work_until); + virtual bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); protected: OutbufMetadata *metadatas; @@ -510,7 +510,7 @@ namespace Realm { bool has_work_remaining(); - virtual bool do_work(TimeLimit work_until); + virtual bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); protected: GASNetEXInternal *internal; @@ -531,7 +531,7 @@ namespace Realm { bool has_work_remaining(); - virtual bool do_work(TimeLimit work_until); + virtual bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); // causes calling thread to wait for a full call to gasnet_AMPoll() to // be performed by the poller @@ -557,7 +557,7 @@ namespace Realm { bool has_work_remaining(); - virtual bool do_work(TimeLimit work_until); + virtual bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); protected: GASNetEXInternal *internal; @@ -626,7 +626,7 @@ namespace Realm { bool has_work_remaining(); - virtual bool do_work(TimeLimit work_until); + virtual bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); protected: friend class GASNetEXEvent; diff --git a/src/realm/hip/hip_internal.cc b/src/realm/hip/hip_internal.cc index b3ab181840e..a2978b53bf8 100644 --- a/src/realm/hip/hip_internal.cc +++ b/src/realm/hip/hip_internal.cc @@ -514,7 +514,7 @@ namespace Realm { : SingleXDQChannel( bgwork, _kind, stringbuilder() << "hip channel (gpu=" << _src_gpu->info->index - << " kind=" << (int)_kind << ")") + << " kind=" << _kind << ")") { src_gpu = _src_gpu; @@ -1261,7 +1261,7 @@ namespace Realm { { AutoGPUContext agc(channel->gpu); - if(!gpu_timing && tl_bgwork_profile) { + if(!gpu_timing && bgwork_profiler.get_level() > 0) { gpu_timing = new BgWorkGpuHipNotification( stream->get_gpu()->proc->me.id, channel->get_bgwork_slot()); stream->add_notification(gpu_timing); diff --git a/src/realm/hip/hip_internal.h b/src/realm/hip/hip_internal.h index 9c24006ec8b..4a93da11b56 100644 --- a/src/realm/hip/hip_internal.h +++ b/src/realm/hip/hip_internal.h @@ -29,7 +29,6 @@ #include "realm/proc_impl.h" #include "realm/mem_impl.h" #include "realm/bgwork.h" -#include "realm/bgwork_profile.h" #include "realm/transfer/channel.h" #include "realm/transfer/ib_memory.h" @@ -254,7 +253,7 @@ namespace Realm { void start_background_thread(Realm::CoreReservationSet &crs, size_t stack_size); void shutdown_background_thread(void); - bool do_work(TimeLimit work_until); + bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); public: void thread_main(void); diff --git a/src/realm/hip/hip_module.cc b/src/realm/hip/hip_module.cc index fe622567ea5..d67fe76e2b6 100644 --- a/src/realm/hip/hip_module.cc +++ b/src/realm/hip/hip_module.cc @@ -52,6 +52,10 @@ namespace Realm { namespace Hip { + // file-local thread_local used by GPUWorker::do_work to communicate + // the profiling state to BgWorkGpuHipNotification::request_completed + static thread_local BgWorkProfileState *tl_gpu_profstate = nullptr; + Logger log_gpu("hip"); Logger log_gpudma("hipdma"); Logger log_cudart("cudart"); @@ -309,7 +313,8 @@ namespace Realm { started = true; } else { int64_t stop_time = Clock::current_time_in_nanoseconds(true /*absolute*/); - bgwork_profile_gpu_work(proc_id, slot, start_time, stop_time); + if(tl_gpu_profstate) + tl_gpu_profstate->gpu_work(proc_id, slot, start_time, stop_time); delete this; } } @@ -1067,7 +1072,7 @@ namespace Realm { } GPUWorker::GPUWorker(void) - : BackgroundWorkItem("gpu worker") + : BackgroundWorkItem("hip poll") , condvar(lock) , core_rsrv(0) , worker_thread(0) @@ -1144,8 +1149,11 @@ namespace Realm { make_active(); } - bool GPUWorker::do_work(TimeLimit work_until) + bool GPUWorker::do_work(TimeLimit work_until, BgWorkProfileState &profstate) { + // make profstate available to GPU notifications during reap_events + tl_gpu_profstate = &profstate; + // pop the first stream off the list and immediately become re-active // if more streams remain GPUStream *stream = 0; @@ -1172,11 +1180,12 @@ namespace Realm { // time bool was_empty = false; if(profile_id_registered) - bgwork_profile_fine_begin(profile_sub_item_id); + profstate.fine_begin(profile_sub_item_id); bool has_more = stream->reap_events(work_until); if(profile_id_registered) - bgwork_profile_fine_end(); + profstate.fine_end(); if(has_more) { + profstate.worked(); AutoLock<> al(lock); was_empty = active_streams.empty(); diff --git a/src/realm/runtime_impl.h b/src/realm/runtime_impl.h index 5ba0a0810ab..bd92b30b7c4 100644 --- a/src/realm/runtime_impl.h +++ b/src/realm/runtime_impl.h @@ -48,7 +48,6 @@ #include "realm/network.h" #include "realm/bgwork.h" -#include "realm/bgwork_profile.h" #include "realm/activemsg.h" #include "realm/repl_heap.h" #include "realm/dynamic_table.h" diff --git a/src/realm/tasks.cc b/src/realm/tasks.cc index 308a0a6ed03..9d0f938ba51 100644 --- a/src/realm/tasks.cc +++ b/src/realm/tasks.cc @@ -1321,7 +1321,8 @@ namespace Realm { if(max_bgwork_timeslice > 0) { // try to be productive while we're waiting - bgworker.do_work(max_bgwork_timeslice, &bgworker_interrupt); + BgWorkProfileState profstate; + bgworker.do_work(max_bgwork_timeslice, &bgworker_interrupt, profstate); } else { // just let the work counter wake us up when there's stuff to do work_counter.wait_for_work(old_work_counter); diff --git a/src/realm/tasks.h b/src/realm/tasks.h index de5e6be1614..5efc3b1ffee 100644 --- a/src/realm/tasks.h +++ b/src/realm/tasks.h @@ -362,6 +362,7 @@ namespace Realm { WorkCounterUpdater wcu_resume_queue; BackgroundWorkManager::Worker bgworker; + BgWorkProfileState bgwork_profstate; atomic bgworker_interrupt; long long max_bgwork_timeslice; diff --git a/src/realm/transfer/channel.h b/src/realm/transfer/channel.h index d3641ee9bcd..e8d2b41a02b 100644 --- a/src/realm/transfer/channel.h +++ b/src/realm/transfer/channel.h @@ -999,7 +999,7 @@ namespace Realm { void enqueue_xd(XD *xd, bool at_front = false); - virtual bool do_work(TimeLimit work_until); + virtual bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); protected: friend CHANNEL; diff --git a/src/realm/transfer/channel.inl b/src/realm/transfer/channel.inl index 59a608518cf..26e8364d429 100644 --- a/src/realm/transfer/channel.inl +++ b/src/realm/transfer/channel.inl @@ -125,7 +125,7 @@ namespace Realm { } template - bool XDQueue::do_work(TimeLimit work_until) + bool XDQueue::do_work(TimeLimit work_until, BgWorkProfileState &profstate) { bool first_iteration = true; while(true) { @@ -169,10 +169,12 @@ namespace Realm { unsigned progress = xd->current_progress(); if(profile_id_registered) - bgwork_profile_fine_begin(profile_sub_item_id); + profstate.fine_begin(profile_sub_item_id); bool did_work = xd->progress_xd(static_cast(channel), work_until); if(profile_id_registered) - bgwork_profile_fine_end(); + profstate.fine_end(); + if(did_work) + profstate.worked(); // if we didn't do any work, and we're not done (i.e. by // concluding there wasn't any work to actually do), re-check diff --git a/src/realm/transfer/lowlevel_dma.cc b/src/realm/transfer/lowlevel_dma.cc index c2495f4925d..d94728a1d14 100644 --- a/src/realm/transfer/lowlevel_dma.cc +++ b/src/realm/transfer/lowlevel_dma.cc @@ -543,7 +543,7 @@ namespace Realm { } } - bool AsyncFileIOContext::do_work(TimeLimit work_until) + bool AsyncFileIOContext::do_work(TimeLimit work_until, BgWorkProfileState &profstate) { // first, reap as many events as we can - oldest first #ifdef REALM_USE_KERNEL_AIO @@ -590,6 +590,7 @@ namespace Realm { AIOOperation *op = launched_operations.front(); if(!op->check_completion()) break; + profstate.worked(); log_aio.debug("aio op completed: op=%p", static_cast(op)); // if(op->req != NULL) { diff --git a/src/realm/transfer/lowlevel_dma.h b/src/realm/transfer/lowlevel_dma.h index 3209d130fce..05665cc2a69 100644 --- a/src/realm/transfer/lowlevel_dma.h +++ b/src/realm/transfer/lowlevel_dma.h @@ -146,7 +146,7 @@ namespace Realm { static AsyncFileIOContext *get_singleton(void); - virtual bool do_work(TimeLimit work_until); + virtual bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); class AIOOperation { public: diff --git a/src/realm/ucx/ucp_internal.cc b/src/realm/ucx/ucp_internal.cc index e66276b35f4..f76cf959cfa 100644 --- a/src/realm/ucx/ucp_internal.cc +++ b/src/realm/ucx/ucp_internal.cc @@ -84,6 +84,7 @@ namespace Realm { namespace ThreadLocal { thread_local const TimeLimit *ucp_work_until = nullptr; + thread_local BgWorkProfileState *ucp_bgwork_profstate = nullptr; }; struct CompList { @@ -327,15 +328,17 @@ namespace Realm { poll_notify_cond.wait(); } - bool UCPPoller::do_work(TimeLimit work_until) + bool UCPPoller::do_work(TimeLimit work_until, BgWorkProfileState &profstate) { ThreadLocal::ucp_work_until = &work_until; + ThreadLocal::ucp_bgwork_profstate = &profstate; for(auto worker : workers) { (void)worker->progress(); } ThreadLocal::ucp_work_until = nullptr; + ThreadLocal::ucp_bgwork_profstate = nullptr; // if a poll notify has been requested, wake the waiter if(poll_notify_flag.load()) { @@ -1195,6 +1198,8 @@ namespace Realm { &am_realm_comp_handler, cb_data1, 0, (ThreadLocal::ucp_work_until != nullptr) ? *ThreadLocal::ucp_work_until : TimeLimit::relative(0)); + if(ThreadLocal::ucp_bgwork_profstate) + ThreadLocal::ucp_bgwork_profstate->worked(); if(completed) { am_realm_comp_handler(ucp_msg_hdr->src, cb_data1, 0); diff --git a/src/realm/ucx/ucp_internal.h b/src/realm/ucx/ucp_internal.h index d16f800f3f5..bf061a0691f 100644 --- a/src/realm/ucx/ucp_internal.h +++ b/src/realm/ucx/ucp_internal.h @@ -86,7 +86,7 @@ namespace Realm { void begin_polling(); void end_polling(); void wait_polling(); - bool do_work(TimeLimit work_until); + bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); void add_worker(UCPWorker *worker); private: From 1e6bc72af783c06cb5cddbef54960ef11b15310f Mon Sep 17 00:00:00 2001 From: Mike Date: Wed, 18 Mar 2026 02:44:39 -0700 Subject: [PATCH 07/14] fix formatting --- src/realm/bgwork.cc | 12 +++++++----- src/realm/bgwork.h | 7 ++++++- src/realm/gasnetex/gasnetex_internal.cc | 2 +- 3 files changed, 14 insertions(+), 7 deletions(-) diff --git a/src/realm/bgwork.cc b/src/realm/bgwork.cc index 4f2c4ac44c5..3b03e3780a9 100644 --- a/src/realm/bgwork.cc +++ b/src/realm/bgwork.cc @@ -149,7 +149,7 @@ namespace Realm { { AutoLock<> al(thread_mutex); for(BgWorkProfileState *state : thread_states) { - ProfileBlock* current_block = state->flush(); + ProfileBlock *current_block = state->flush(); if(current_block) { if(current_block->num_records > 0) { AutoLock<> bl(block_mutex); @@ -434,11 +434,13 @@ namespace Realm { //////////////////////////////////////////////////////////////////////// // - // class BgWorkProfileState + // class BgWorkProfileState // BgWorkProfileState::BgWorkProfileState(void) - : level(bgwork_profiler.get_level()), thread_id(static_cast(std::hash{}(std::this_thread::get_id()))) + : level(bgwork_profiler.get_level()) + , thread_id( + static_cast(std::hash{}(std::this_thread::get_id()))) { if(level > 0) { bgwork_profiler.register_thread_state(this); @@ -459,7 +461,7 @@ namespace Realm { } } - ProfileBlock* BgWorkProfileState::flush(void) + ProfileBlock *BgWorkProfileState::flush(void) { ProfileBlock *current = current_block; current_block = nullptr; @@ -588,7 +590,7 @@ namespace Realm { } } log_bgwork.debug() << "dedicated worker awake - worker=" << this; - } + } log_bgwork.info() << "dedicated worker terminating - worker=" << this; } diff --git a/src/realm/bgwork.h b/src/realm/bgwork.h index cba0eb634cf..33de33ee9d4 100644 --- a/src/realm/bgwork.h +++ b/src/realm/bgwork.h @@ -145,13 +145,18 @@ namespace Realm { uint32_t begin_block_used = 0; uint32_t begin_block_num_records = 0; int64_t begin_last_timestamp = 0; + public: BgWorkProfileState(void); ~BgWorkProfileState(void); // recording methods (all no-op when level == 0) inline void begin(uint8_t slot); inline void end(void); - inline void worked(void) { if(level > 0) did_work = true; } + inline void worked(void) + { + if(level > 0) + did_work = true; + } inline void discard(void); inline void fine_begin(uint16_t sub_item_id); inline void fine_end(); diff --git a/src/realm/gasnetex/gasnetex_internal.cc b/src/realm/gasnetex/gasnetex_internal.cc index 06dd09792d5..e0a6e6693db 100644 --- a/src/realm/gasnetex/gasnetex_internal.cc +++ b/src/realm/gasnetex/gasnetex_internal.cc @@ -130,7 +130,7 @@ namespace Realm { namespace ThreadLocal { thread_local const TimeLimit *gex_work_until = nullptr; - thread_local BgWorkProfileState* gex_bgwork_profstate = nullptr; + thread_local BgWorkProfileState *gex_bgwork_profstate = nullptr; thread_local bool in_am_handler = false; }; // namespace ThreadLocal From a54f48d3075b16524b575e07bfc62dee5c44f0b9 Mon Sep 17 00:00:00 2001 From: Mike Date: Wed, 18 Mar 2026 02:49:48 -0700 Subject: [PATCH 08/14] add missing file --- src/realm/bgwork.inl | 260 +++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 260 insertions(+) create mode 100644 src/realm/bgwork.inl diff --git a/src/realm/bgwork.inl b/src/realm/bgwork.inl new file mode 100644 index 00000000000..e7fb26973b5 --- /dev/null +++ b/src/realm/bgwork.inl @@ -0,0 +1,260 @@ +/* + * Copyright 2026 Stanford University, NVIDIA Corporation + * SPDX-License-Identifier: Apache-2.0 + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +// inline recording methods for BgWorkProfileState + +#ifndef REALM_BGWORK_INL +#define REALM_BGWORK_INL + +namespace Realm { + + // Timestamp delta encoding: + // 15-bit: 2 bytes, MSB=0 + // 30-bit: 4 bytes, MSB=10 + // 64-bit: 8 bytes, MSB=11 (stores absolute timestamp) + inline size_t BgWorkProfileState::encode_timestamp(uint8_t *buf, int64_t delta, + int64_t absolute) + { + if(delta >= 0 && delta < (1 << 15)) { + uint16_t val = static_cast(delta); + buf[0] = (val >> 8) & 0x7F; + buf[1] = val & 0xFF; + return 2; + } else if(delta >= 0 && delta < (1LL << 30)) { + uint32_t val = static_cast(delta) | 0x80000000U; + buf[0] = (val >> 24) & 0xFF; + buf[1] = (val >> 16) & 0xFF; + buf[2] = (val >> 8) & 0xFF; + buf[3] = val & 0xFF; + return 4; + } else { + // 8-byte encoding: store absolute timestamp + uint64_t val = static_cast(absolute); + buf[0] = 0xC0 | ((val >> 56) & 0x3F); + buf[1] = (val >> 48) & 0xFF; + buf[2] = (val >> 40) & 0xFF; + buf[3] = (val >> 32) & 0xFF; + buf[4] = (val >> 24) & 0xFF; + buf[5] = (val >> 16) & 0xFF; + buf[6] = (val >> 8) & 0xFF; + buf[7] = val & 0xFF; + return 8; + } + } + + // ensures enough space in the current block, rotating if needed + // returns pointer to write position, or nullptr on failure + inline uint8_t *BgWorkProfileState::ensure_space(size_t needed) + { + ProfileBlock *block = current_block; + if(block && (block->used + needed <= ProfileBlock::BLOCK_SIZE)) + return block->data + block->used; + + // need a new block - complete old one and get fresh + if(block) + bgwork_profiler.complete_block(block); + + block = bgwork_profiler.alloc_block(thread_id); + current_block = block; + if(!block) + return nullptr; + + // reset delta encoding for new block + last_timestamp = 0; + return block->data; + } + + inline void BgWorkProfileState::begin(uint8_t slot) + { + if(level == 0) + return; + REALM_ASSERT(!did_work); + + int64_t now = Clock::current_time_in_nanoseconds(true /*absolute*/); + + // max record size: 8 (timestamp) + 1 (type) + 1 (slot) = 10 + uint8_t *buf = ensure_space(10); + if(!buf) + return; + + ProfileBlock *block = current_block; + if(block->num_records == 0) + block->base_timestamp = now; + + // save state for potential discard + begin_block_used = block->used; + begin_block_num_records = block->num_records; + begin_last_timestamp = last_timestamp; + + int64_t delta = now - last_timestamp; + size_t ts_size = encode_timestamp(buf, delta, now); + buf += ts_size; + + *buf++ = BGWP_COARSE_BEGIN; + *buf++ = slot; + + block->used += ts_size + 2; + block->num_records++; + last_timestamp = now; + } + + inline void BgWorkProfileState::end(void) + { + if(level == 0) + return; + + if(!did_work) { + discard(); + return; + } else { + did_work = false; + } + + int64_t now = Clock::current_time_in_nanoseconds(true /*absolute*/); + + // max: 8 (timestamp) + 1 (type) = 9 + uint8_t *buf = ensure_space(9); + if(!buf) + return; + + ProfileBlock *block = current_block; + if(block->num_records == 0) + block->base_timestamp = now; + + int64_t delta = now - last_timestamp; + size_t ts_size = encode_timestamp(buf, delta, now); + buf += ts_size; + + *buf++ = BGWP_COARSE_END; + + block->used += ts_size + 1; + block->num_records++; + last_timestamp = now; + } + + inline void BgWorkProfileState::discard(void) + { + // rewind the block state to what it was before begin() + ProfileBlock *block = current_block; + if(!block) + return; + + block->used = begin_block_used; + block->num_records = begin_block_num_records; + last_timestamp = begin_last_timestamp; + } + + inline void BgWorkProfileState::fine_begin(uint16_t sub_item_id) + { + if(level < 2) + return; + + did_work = true; + + int64_t now = Clock::current_time_in_nanoseconds(true /*absolute*/); + + // max: 8 + 1 + 2 = 11 + uint8_t *buf = ensure_space(11); + if(!buf) + return; + + ProfileBlock *block = current_block; + if(block->num_records == 0) + block->base_timestamp = now; + + int64_t delta = now - last_timestamp; + size_t ts_size = encode_timestamp(buf, delta, now); + buf += ts_size; + + *buf++ = BGWP_FINE_BEGIN; + memcpy(buf, &sub_item_id, sizeof(uint16_t)); + buf += sizeof(uint16_t); + + block->used += ts_size + 3; + block->num_records++; + last_timestamp = now; + } + + inline void BgWorkProfileState::fine_end() + { + if(level < 2) + return; + + did_work = true; + + int64_t now = Clock::current_time_in_nanoseconds(true /*absolute*/); + + // max: 8 + 1 = 9 + uint8_t *buf = ensure_space(9); + if(!buf) + return; + + ProfileBlock *block = current_block; + if(block->num_records == 0) + block->base_timestamp = now; + + int64_t delta = now - last_timestamp; + size_t ts_size = encode_timestamp(buf, delta, now); + buf += ts_size; + + *buf++ = BGWP_FINE_END; + + block->used += ts_size + 1; + block->num_records++; + last_timestamp = now; + } + + inline void BgWorkProfileState::gpu_work(uint64_t proc_id, uint8_t slot, + int64_t start_time, int64_t stop_time) + { + if(level == 0) + return; + + did_work = true; + + int64_t now = Clock::current_time_in_nanoseconds(true /*absolute*/); + + // max: 8 (timestamp) + 1 (type) + 8 (proc_id) + 1 (slot) + 8 (start) + 8 (stop) = 34 + uint8_t *buf = ensure_space(34); + if(!buf) + return; + + ProfileBlock *block = current_block; + if(block->num_records == 0) + block->base_timestamp = now; + + int64_t delta = now - last_timestamp; + size_t ts_size = encode_timestamp(buf, delta, now); + buf += ts_size; + + *buf++ = BGWP_GPU_WORK; + memcpy(buf, &proc_id, sizeof(uint64_t)); + buf += sizeof(uint64_t); + *buf++ = slot; + memcpy(buf, &start_time, sizeof(int64_t)); + buf += sizeof(int64_t); + memcpy(buf, &stop_time, sizeof(int64_t)); + buf += sizeof(int64_t); + + block->used += ts_size + 26; + block->num_records++; + last_timestamp = now; + } + +}; // namespace Realm + +#endif // REALM_BGWORK_INL From 28ff1de497aeb6a3267afa81b2240f97a0200312 Mon Sep 17 00:00:00 2001 From: Mike Date: Wed, 18 Mar 2026 02:53:50 -0700 Subject: [PATCH 09/14] more fixes for background work profiling --- src/realm/cuda/cuda_module.cc | 6 +++++- src/realm/hip/hip_module.cc | 6 +++++- 2 files changed, 10 insertions(+), 2 deletions(-) diff --git a/src/realm/cuda/cuda_module.cc b/src/realm/cuda/cuda_module.cc index 7a7ff0e6a34..4236869c895 100644 --- a/src/realm/cuda/cuda_module.cc +++ b/src/realm/cuda/cuda_module.cc @@ -20,6 +20,7 @@ #include "realm/cuda/cuda_internal.h" #include "realm/cuda/cuda_memcpy.h" +#include "realm/bgwork.h" #include "realm/tasks.h" #include "realm/logging.h" #include "realm/cmdline.h" @@ -1562,8 +1563,11 @@ namespace Realm { worker.set_manager(&(get_runtime()->bgwork)); + BgWorkProfileState bgwork_profstate; + while(!completed.load()) - worker.do_work(-1 /* as long as it takes */, &completed /* until this is set */); + worker.do_work(-1 /* as long as it takes */, &completed /* until this is set */, + bgwork_profstate); } //////////////////////////////////////////////////////////////////////// diff --git a/src/realm/hip/hip_module.cc b/src/realm/hip/hip_module.cc index d67fe76e2b6..3af601bab3f 100644 --- a/src/realm/hip/hip_module.cc +++ b/src/realm/hip/hip_module.cc @@ -19,6 +19,7 @@ #include "realm/hip/hip_internal.h" #include "realm/hip/hip_access.h" +#include "realm/bgwork.h" #include "realm/tasks.h" #include "realm/logging.h" #include "realm/cmdline.h" @@ -1302,8 +1303,11 @@ namespace Realm { worker.set_manager(&(get_runtime()->bgwork)); + BgWorkProfileState bgwork_profstate; + while(!completed.load()) - worker.do_work(-1 /* as long as it takes */, &completed /* until this is set */); + worker.do_work(-1 /* as long as it takes */, &completed /* until this is set */, + bgwork_profstate); } //////////////////////////////////////////////////////////////////////// From 2ff3498f28a6fc51515ef166c1b97c536a9a4896 Mon Sep 17 00:00:00 2001 From: Mike Date: Wed, 18 Mar 2026 16:09:09 -0700 Subject: [PATCH 10/14] more refactoring of background work to simplify things --- src/realm/activemsg.cc | 14 ++-- src/realm/activemsg.h | 2 +- src/realm/bgwork.cc | 17 +++-- src/realm/bgwork.h | 15 ++-- src/realm/bgwork.inl | 15 ++-- src/realm/cuda/cuda_internal.h | 6 +- src/realm/cuda/cuda_module.cc | 93 ++++++------------------- src/realm/deppart/partitions.cc | 12 ++-- src/realm/deppart/partitions.h | 2 +- src/realm/event_impl.cc | 4 +- src/realm/event_impl.h | 2 +- src/realm/gasnet1/gasnetmsg.cc | 9 ++- src/realm/gasnetex/gasnetex_internal.cc | 30 +++----- src/realm/gasnetex/gasnetex_internal.h | 10 +-- src/realm/hip/hip_internal.h | 6 +- src/realm/hip/hip_module.cc | 93 ++++++------------------- src/realm/tasks.cc | 9 ++- src/realm/transfer/channel.h | 2 +- src/realm/transfer/channel.inl | 8 +-- src/realm/transfer/lowlevel_dma.cc | 3 +- src/realm/transfer/lowlevel_dma.h | 2 +- src/realm/ucx/ucp_internal.cc | 12 ++-- src/realm/ucx/ucp_internal.h | 2 +- 23 files changed, 127 insertions(+), 241 deletions(-) diff --git a/src/realm/activemsg.cc b/src/realm/activemsg.cc index da8a42015ff..504e6d52222 100644 --- a/src/realm/activemsg.cc +++ b/src/realm/activemsg.cc @@ -721,8 +721,7 @@ namespace Realm { return now_active; } - bool IncomingMessageManager::do_work(TimeLimit work_until, - BgWorkProfileState &profstate) + bool IncomingMessageManager::do_work(TimeLimit work_until) { // now that we've been called, our previous request for bgwork has been // granted and we will need another one if/when more work comes @@ -748,7 +747,6 @@ namespace Realm { size_t num_handled = 0; while(current_msg) { - profstate.worked(); Message *next_msg = current_msg->next_msg; #ifdef DETAILED_MESSAGE_TIMING int timing_idx = detailed_message_timing @@ -772,14 +770,15 @@ namespace Realm { t_start = Clock::current_time_in_nanoseconds(); if(current_msg->handler->profile_id_registered) - profstate.fine_begin(current_msg->handler->profile_sub_item_id); + ThreadLocal::bgwork_profstate->fine_begin( + current_msg->handler->profile_sub_item_id); (current_msg->handler->handler)(current_msg->sender, current_msg->hdr, current_msg->payload, current_msg->payload_size, work_until); if(current_msg->handler->profile_id_registered) - profstate.fine_end(); + ThreadLocal::bgwork_profstate->fine_end(); } else { // estimate how long this handler will take, clamping at a // semi-arbitrary 20us @@ -807,14 +806,15 @@ namespace Realm { t_start = Clock::current_time_in_nanoseconds(); if(current_msg->handler->profile_id_registered) - profstate.fine_begin(current_msg->handler->profile_sub_item_id); + ThreadLocal::bgwork_profstate->fine_begin( + current_msg->handler->profile_sub_item_id); (current_msg->handler->handler_notimeout)(current_msg->sender, current_msg->hdr, current_msg->payload, current_msg->payload_size); if(current_msg->handler->profile_id_registered) - profstate.fine_end(); + ThreadLocal::bgwork_profstate->fine_end(); } long long t_end = 0; diff --git a/src/realm/activemsg.h b/src/realm/activemsg.h index 69f191c4020..b9eed548dfe 100644 --- a/src/realm/activemsg.h +++ b/src/realm/activemsg.h @@ -372,7 +372,7 @@ namespace Realm { void shutdown(void); - virtual bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); + virtual bool do_work(TimeLimit work_until); void handler_thread_loop(void); diff --git a/src/realm/bgwork.cc b/src/realm/bgwork.cc index 3b03e3780a9..228174b12b3 100644 --- a/src/realm/bgwork.cc +++ b/src/realm/bgwork.cc @@ -445,6 +445,8 @@ namespace Realm { if(level > 0) { bgwork_profiler.register_thread_state(this); } + // Save ourselves into the thread local variable + ThreadLocal::bgwork_profstate = this; } BgWorkProfileState::~BgWorkProfileState(void) @@ -540,7 +542,7 @@ namespace Realm { spin_until = -1; // do work until there's none left - while(worker.do_work(-1 /*max_time*/, 0 /*interrupt_flag*/, profstate)) { + while(worker.do_work(-1 /*max_time*/, 0 /*interrupt_flag*/)) { } // and then retest state variable @@ -916,8 +918,7 @@ namespace Realm { } bool BackgroundWorkManager::Worker::do_work(long long max_time_in_ns, - atomic *interrupt_flag, - BgWorkProfileState &profstate) + atomic *interrupt_flag) { // set our deadline for returning long long work_until_time = @@ -1010,7 +1011,7 @@ namespace Realm { log_bgwork.debug() << "work claimed: manager=" << manager << " slot=" << slot << " worker=" << this; long long t_start = Clock::current_time_in_nanoseconds(true /*absolute*/); - profstate.begin(static_cast(slot)); + ThreadLocal::bgwork_profstate->begin(static_cast(slot)); // don't spend more than 1ms on any single task before going on to the // next thing - TODO: pull this out as a config variable long long t_quantum = (manager->cfg.work_item_timeslice + t_start); @@ -1028,9 +1029,9 @@ namespace Realm { #ifdef DEBUG_REALM item->make_inactive(); #endif + TimeLimit time_limit = TimeLimit::absolute(t_quantum, interrupt_flag); while(true) { - bool requeue = - item->do_work(TimeLimit::absolute(t_quantum, interrupt_flag), profstate); + bool requeue = item->do_work(time_limit); if(requeue) { // we can just call this item's work function again if we're not out // of time and if there's nothing else to do @@ -1044,6 +1045,7 @@ namespace Realm { t_quantum = (manager->cfg.work_item_timeslice + now); if((work_until_time > 0) && (work_until_time < t_quantum)) t_quantum = work_until_time; + time_limit = TimeLimit::absolute(t_quantum, interrupt_flag); continue; } } @@ -1054,7 +1056,8 @@ namespace Realm { } else break; } - profstate.end(); // end() checks did_work internally + ThreadLocal::bgwork_profstate->end( + time_limit); // end() checks did_work internally // we're done with this slot for now manager->work_item_usecounts[slot].fetch_sub_acqrel(1); diff --git a/src/realm/bgwork.h b/src/realm/bgwork.h index 33de33ee9d4..0ff413c466a 100644 --- a/src/realm/bgwork.h +++ b/src/realm/bgwork.h @@ -151,11 +151,11 @@ namespace Realm { ~BgWorkProfileState(void); // recording methods (all no-op when level == 0) inline void begin(uint8_t slot); - inline void end(void); - inline void worked(void) + inline void end(const TimeLimit &time_limit); + inline void set_worked(bool worked) { if(level > 0) - did_work = true; + did_work = worked; } inline void discard(void); inline void fine_begin(uint16_t sub_item_id); @@ -168,6 +168,10 @@ namespace Realm { static size_t encode_timestamp(uint8_t *buf, int64_t delta, int64_t absolute); }; + namespace ThreadLocal { + inline thread_local BgWorkProfileState *bgwork_profstate = nullptr; + }; + struct BgWorkItemDescriptor { uint16_t slot; std::string name; @@ -289,8 +293,7 @@ namespace Realm { void set_max_timeslice(long long _timeslice_in_ns); void set_numa_domain(int _numa_domain); // -1 == dont care - bool do_work(long long max_time_in_ns, atomic *interrupt_flag, - BgWorkProfileState &profstate); + bool do_work(long long max_time_in_ns, atomic *interrupt_flag); protected: BackgroundWorkManager *manager; @@ -358,7 +361,7 @@ namespace Realm { // true to request requeuing (this is more efficient than calling // 'make_active' at the end of 'do_work') or false if all work has been // completed (or if 'make_active' has already been called) - virtual bool do_work(TimeLimit work_until, BgWorkProfileState &profstate) = 0; + virtual bool do_work(TimeLimit work_until) = 0; // returns the slot index assigned by the background work manager unsigned get_slot() const { return index; } diff --git a/src/realm/bgwork.inl b/src/realm/bgwork.inl index e7fb26973b5..1dda2f1cfbe 100644 --- a/src/realm/bgwork.inl +++ b/src/realm/bgwork.inl @@ -83,6 +83,7 @@ namespace Realm { if(level == 0) return; REALM_ASSERT(!did_work); + did_work = true; int64_t now = Clock::current_time_in_nanoseconds(true /*absolute*/); @@ -112,16 +113,18 @@ namespace Realm { last_timestamp = now; } - inline void BgWorkProfileState::end(void) + inline void BgWorkProfileState::end(const TimeLimit& time_limit) { if(level == 0) return; - if(!did_work) { + if(did_work) { + did_work = false; + } else if(!time_limit.is_expired()) { + // If the timelimit expired we still record this + // because it is surprising that it took that long discard(); return; - } else { - did_work = false; } int64_t now = Clock::current_time_in_nanoseconds(true /*absolute*/); @@ -194,8 +197,6 @@ namespace Realm { if(level < 2) return; - did_work = true; - int64_t now = Clock::current_time_in_nanoseconds(true /*absolute*/); // max: 8 + 1 = 9 @@ -224,8 +225,6 @@ namespace Realm { if(level == 0) return; - did_work = true; - int64_t now = Clock::current_time_in_nanoseconds(true /*absolute*/); // max: 8 (timestamp) + 1 (type) + 8 (proc_id) + 1 (slot) + 8 (start) + 8 (stop) = 34 diff --git a/src/realm/cuda/cuda_internal.h b/src/realm/cuda/cuda_internal.h index d9d934a0228..0400a8c92de 100644 --- a/src/realm/cuda/cuda_internal.h +++ b/src/realm/cuda/cuda_internal.h @@ -324,7 +324,7 @@ namespace Realm { void start_background_thread(Realm::CoreReservationSet &crs, size_t stack_size); void shutdown_background_thread(void); - bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); + bool do_work(TimeLimit work_until); public: void thread_main(void); @@ -346,10 +346,6 @@ namespace Realm { Realm::Thread *worker_thread; bool thread_sleeping; atomic worker_shutdown_requested; - - // Level 2 bgwork profiling - uint16_t profile_sub_item_id; - bool profile_id_registered; }; // a little helper class to manage a pool of CUevents that can be reused diff --git a/src/realm/cuda/cuda_module.cc b/src/realm/cuda/cuda_module.cc index 4236869c895..8738e79797f 100644 --- a/src/realm/cuda/cuda_module.cc +++ b/src/realm/cuda/cuda_module.cc @@ -64,10 +64,6 @@ namespace Realm { namespace Cuda { - // file-local thread_local used by GPUWorker::do_work to communicate - // the profiling state to BgWorkGpuCudaNotification::request_completed - static thread_local BgWorkProfileState *tl_gpu_profstate = nullptr; - enum CudaIpcResponseType { CUDA_IPC_RESPONSE_TYPE_IPC = 0, @@ -304,12 +300,18 @@ namespace Realm { } // we'll keep looking at events until we find one that hasn't triggered + bool first = true; bool work_left = true; while(event_valid) { CUresult res = CUDA_DRIVER_FNPTR(cuEventQuery)(event); - if(res == CUDA_ERROR_NOT_READY) + if(res == CUDA_ERROR_NOT_READY) { return true; // oldest event hasn't triggered - check again later + } else if(first) { + // As long as we did at least one event we did work + ThreadLocal::bgwork_profstate->set_worked(true); + first = false; + } // no other kind of error is expected if(res != CUDA_SUCCESS) { @@ -388,8 +390,7 @@ namespace Realm { started = true; } else { int64_t stop_time = Clock::current_time_in_nanoseconds(true /*absolute*/); - if(tl_gpu_profstate) - tl_gpu_profstate->gpu_work(proc_id, slot, start_time, stop_time); + ThreadLocal::bgwork_profstate->gpu_work(proc_id, slot, start_time, stop_time); delete this; } } @@ -1409,11 +1410,10 @@ namespace Realm { make_active(); } - bool GPUWorker::do_work(TimeLimit work_until, BgWorkProfileState &profstate) + bool GPUWorker::do_work(TimeLimit work_until) { - // make profstate available to GPU notifications during reap_events - tl_gpu_profstate = &profstate; - + // This is a polling background work item so flip work polarity + ThreadLocal::bgwork_profstate->set_worked(false); // pop the first stream off the list and immediately become re-active // if more streams remain GPUStream *stream = 0; @@ -1430,23 +1430,10 @@ namespace Realm { make_active(); } - // lazily register for fine-grained profiling - if(bgwork_profiler.get_level() >= 2 && !profile_id_registered) { - profile_sub_item_id = - bgwork_profiler.register_sub_item(BGWP_SUB_GPU_REAP, "cuda gpu reap"); - profile_id_registered = true; - } - // do work for the stream we popped, paying attention to the cutoff // time bool was_empty = false; - if(profile_id_registered) - profstate.fine_begin(profile_sub_item_id); - bool has_more = stream->reap_events(work_until); - if(profile_id_registered) - profstate.fine_end(); - if(has_more) { - profstate.worked(); + if(stream->reap_events(work_until)) { AutoLock<> al(lock); was_empty = active_streams.empty(); @@ -1511,9 +1498,18 @@ namespace Realm { void GPUWorker::thread_main(void) { + // Create a background worker profiling state for this thread + BgWorkProfileState profstate; + const TimeLimit unlimited; + const uint8_t slot = get_slot(); // TODO: consider busy-waiting in some cases to reduce latency? while(!worker_shutdown_requested.load()) { + // This is a kind of background work item we're processing so time it + profstate.begin(slot); + // We're polling so set worked to false + profstate.set_worked(false); bool work_left = process_streams(true); + profstate.end(unlimited); // if there was work left, yield our thread for now to avoid a tight spin loop // TODO: enqueue a callback so we can go to sleep and wake up sooner than a kernel @@ -1523,53 +1519,6 @@ namespace Realm { } } - //////////////////////////////////////////////////////////////////////// - // - // class BlockingCompletionNotification - - class BlockingCompletionNotification : public GPUCompletionNotification { - public: - BlockingCompletionNotification(void); - virtual ~BlockingCompletionNotification(void); - - virtual void request_completed(void); - - virtual void wait(void); - - public: - atomic completed; - }; - - BlockingCompletionNotification::BlockingCompletionNotification(void) - : completed(false) - {} - - BlockingCompletionNotification::~BlockingCompletionNotification(void) {} - - void BlockingCompletionNotification::request_completed(void) - { - // no condition variable needed - the waiter is spinning - completed.store(true); - } - - void BlockingCompletionNotification::wait(void) - { - // blocking completion is horrible and should die as soon as possible - // in the mean time, we need to assist with background work to avoid - // the risk of deadlock - // note that this means you can get NESTED blocking completion - // notifications, which is just one of the ways this is horrible - BackgroundWorkManager::Worker worker; - - worker.set_manager(&(get_runtime()->bgwork)); - - BgWorkProfileState bgwork_profstate; - - while(!completed.load()) - worker.do_work(-1 /* as long as it takes */, &completed /* until this is set */, - bgwork_profstate); - } - //////////////////////////////////////////////////////////////////////// // // class GPUFBMemory diff --git a/src/realm/deppart/partitions.cc b/src/realm/deppart/partitions.cc index e01e7d848bb..042aadd7e83 100644 --- a/src/realm/deppart/partitions.cc +++ b/src/realm/deppart/partitions.cc @@ -943,7 +943,7 @@ namespace Realm { make_active(); } - bool PartitioningOpQueue::do_work(TimeLimit work_until, BgWorkProfileState &profstate) + bool PartitioningOpQueue::do_work(TimeLimit work_until) { // attempt to take one item off the work queue - readvertise work if // more remains @@ -981,15 +981,14 @@ namespace Realm { // (neither branch will be taken if there are dedicated workers and they // already got to the queued operations) if(op != 0) { - profstate.worked(); bool ok_to_run = op->mark_started(); if(ok_to_run) { log_part.info() << "worker " << this << " starting op " << op; if(profile_id_registered) - profstate.fine_begin(profile_sub_item_id); + ThreadLocal::bgwork_profstate->fine_begin(profile_sub_item_id); op->execute(); if(profile_id_registered) - profstate.fine_end(); + ThreadLocal::bgwork_profstate->fine_end(); log_part.info() << "worker " << this << " finished op " << op; op->mark_finished(true /*successful*/); } else { @@ -999,14 +998,13 @@ namespace Realm { } if(uop != 0) { - profstate.worked(); log_part.info() << "worker " << this << " starting uop " << uop; uop->mark_started(); if(profile_id_registered) - profstate.fine_begin(profile_sub_item_id); + ThreadLocal::bgwork_profstate->fine_begin(profile_sub_item_id); uop->execute(); if(profile_id_registered) - profstate.fine_end(); + ThreadLocal::bgwork_profstate->fine_end(); log_part.info() << "worker " << this << " finished uop " << uop; uop->mark_finished(); } diff --git a/src/realm/deppart/partitions.h b/src/realm/deppart/partitions.h index 33e0ba57037..4b3529bacdf 100644 --- a/src/realm/deppart/partitions.h +++ b/src/realm/deppart/partitions.h @@ -207,7 +207,7 @@ namespace Realm { void worker_thread_loop(void); // called by BackgroundWorkers - bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); + bool do_work(TimeLimit work_until); protected: atomic shutdown_flag; diff --git a/src/realm/event_impl.cc b/src/realm/event_impl.cc index 99a059523ed..9cb6133caf5 100644 --- a/src/realm/event_impl.cc +++ b/src/realm/event_impl.cc @@ -510,7 +510,7 @@ namespace Realm { nested_normal = nested_poisoned = 0; } - bool EventTriggerNotifier::do_work(TimeLimit work_until, BgWorkProfileState &profstate) + bool EventTriggerNotifier::do_work(TimeLimit work_until) { // take the lock and grab both lists EventWaiter::EventWaiterList todo_normal, todo_poisoned; @@ -529,11 +529,9 @@ namespace Realm { // TODO: triggers are fast - consider doing more than one per time check? if(!todo_normal.empty()) { EventWaiter *w = todo_normal.pop_front(); - profstate.worked(); w->event_triggered(false /*!poisoned*/, work_until); } else if(!todo_poisoned.empty()) { EventWaiter *w = todo_poisoned.pop_front(); - profstate.worked(); w->event_triggered(true /*poisoned*/, work_until); } else break; diff --git a/src/realm/event_impl.h b/src/realm/event_impl.h index a9b4a4800e3..58428a5c526 100644 --- a/src/realm/event_impl.h +++ b/src/realm/event_impl.h @@ -70,7 +70,7 @@ namespace Realm { void trigger_event_waiters(EventWaiter::EventWaiterList &to_trigger, bool poisoned, TimeLimit trigger_until); - virtual bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); + virtual bool do_work(TimeLimit work_until); protected: Mutex mutex; diff --git a/src/realm/gasnet1/gasnetmsg.cc b/src/realm/gasnet1/gasnetmsg.cc index d4b7c04530e..4256261c650 100644 --- a/src/realm/gasnet1/gasnetmsg.cc +++ b/src/realm/gasnet1/gasnetmsg.cc @@ -2389,7 +2389,7 @@ class EndpointManager : public BackgroundWorkItem { void stop_threads(void); - virtual bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); + virtual bool do_work(TimeLimit work_until); protected: // runs in a separate thread @@ -2614,6 +2614,7 @@ static void handle_new_activemsg(gasnet_token_t token, void *buf, size_t nbytes, } } else record_message(src, false); + ThreadLocal::bgwork_profstate->set_worked(true); } void gasnet_parse_command_line(std::vector &cmdline) @@ -2794,11 +2795,15 @@ void EndpointManager::stop_threads(void) #endif } -bool EndpointManager::do_work(TimeLimit work_until, BgWorkProfileState &profstate) +bool EndpointManager::do_work(TimeLimit work_until) { // make sure nested active mesage calls respect the time limit ThreadLocal::gasnet_work_until = &work_until; + // This is a polling background work item so make it look like + // we did no work unless we actually do + ThreadLocal::bgwork_profstate->set_worked(false); + push_messages(max_msgs_to_send, false /*!wait*/, work_until); // poll if we're not out of time diff --git a/src/realm/gasnetex/gasnetex_internal.cc b/src/realm/gasnetex/gasnetex_internal.cc index e0a6e6693db..5266f98f4d7 100644 --- a/src/realm/gasnetex/gasnetex_internal.cc +++ b/src/realm/gasnetex/gasnetex_internal.cc @@ -130,7 +130,6 @@ namespace Realm { namespace ThreadLocal { thread_local const TimeLimit *gex_work_until = nullptr; - thread_local BgWorkProfileState *gex_bgwork_profstate = nullptr; thread_local bool in_am_handler = false; }; // namespace ThreadLocal @@ -567,9 +566,8 @@ namespace Realm { make_active(); } - bool OutbufManager::do_work(TimeLimit work_until, BgWorkProfileState &profstate) + bool OutbufManager::do_work(TimeLimit work_until) { - profstate.worked(); // take the mutex and grab the first overflow and reserved realbuf - // don't decrement the counts yet, because we don't want more than one // thread working on this at a time @@ -2716,9 +2714,8 @@ namespace Realm { return !ready_xpairs.empty(); } - bool GASNetEXInjector::do_work(TimeLimit work_until, BgWorkProfileState &profstate) + bool GASNetEXInjector::do_work(TimeLimit work_until) { - profstate.worked(); // we're not supposed to end up handling AMs, but set this just in case // we do ThreadLocal::gex_work_until = &work_until; @@ -2807,10 +2804,11 @@ namespace Realm { return (!critical_xpairs.empty() || !pending_events.empty()); } - bool GASNetEXPoller::do_work(TimeLimit work_until, BgWorkProfileState &profstate) + bool GASNetEXPoller::do_work(TimeLimit work_until) { ThreadLocal::gex_work_until = &work_until; - ThreadLocal::gex_bgwork_profstate = &profstate; + // This is a poller so only count this as doing work if we handle messages + ThreadLocal::bgwork_profstate->set_worked(false); // we're going to try to be frugal about acquiring mutexes here, so peek // ahead in the critical xpair list to avoid the extra mutex acquire that @@ -2880,7 +2878,6 @@ namespace Realm { // try to push packets for any xmit pairs that are critical (i.e. cannot // use immediate mode) while(have_crit_xpairs) { - profstate.worked(); XmitSrcDestPair *xpair = nullptr; // don't wait on contention for the mutex - just skip and get it @@ -2926,7 +2923,6 @@ namespace Realm { gex_wrapper_handle.gex_am_poll(); ThreadLocal::gex_work_until = nullptr; - ThreadLocal::gex_bgwork_profstate = nullptr; // if there was a pollwaiter before we started the poll, we can wake it // now @@ -2982,7 +2978,7 @@ namespace Realm { bool GASNetEXCompleter::has_work_remaining() { return has_work.load(); } - bool GASNetEXCompleter::do_work(TimeLimit work_until, BgWorkProfileState &profstate) + bool GASNetEXCompleter::do_work(TimeLimit work_until) { // grab all the events but don't clear 'has_work' since we don't want // to be reactivated yet @@ -2993,7 +2989,6 @@ namespace Realm { } while(!todo.empty()) { - profstate.worked(); GASNetEXEvent *ev = todo.pop_front(); ev->trigger(internal); internal->event_alloc.free_obj(ev); @@ -3075,7 +3070,6 @@ namespace Realm { bool ReverseGetter::do_work(TimeLimit work_until, BgWorkProfileState &profstate) { - profstate.worked(); // we're not going to use immedate mode for rgets, so don't have more // than one dequeuer at a time - do this by peeking at the head but // not popping it until we've actually issued the rget @@ -5036,8 +5030,7 @@ namespace Realm { ((ThreadLocal::gex_work_until != nullptr) ? *ThreadLocal::gex_work_until : TimeLimit::relative(0))); ThreadLocal::in_am_handler = false; - if(ThreadLocal::gex_bgwork_profstate) - ThreadLocal::gex_bgwork_profstate->worked(); + ThreadLocal::bgwork_profstate->set_worked(true); if(handled) { // if the message was handled immediately, we can use a reply for @@ -5088,8 +5081,7 @@ namespace Realm { ((ThreadLocal::gex_work_until != nullptr) ? *ThreadLocal::gex_work_until : TimeLimit::relative(0))); ThreadLocal::in_am_handler = false; - if(ThreadLocal::gex_bgwork_profstate) - ThreadLocal::gex_bgwork_profstate->worked(); + ThreadLocal::bgwork_profstate->set_worked(true); if(handled) { // if the message was handled immediately, we can use a reply for @@ -5141,8 +5133,7 @@ namespace Realm { ((ThreadLocal::gex_work_until != nullptr) ? *ThreadLocal::gex_work_until : TimeLimit::relative(0))); ThreadLocal::in_am_handler = false; - if(ThreadLocal::gex_bgwork_profstate) - ThreadLocal::gex_bgwork_profstate->worked(); + ThreadLocal::bgwork_profstate->set_worked(true); if(handled) { // if the message was handled immediately, we can use a reply for @@ -5308,8 +5299,7 @@ namespace Realm { } ThreadLocal::in_am_handler = false; - if(ThreadLocal::gex_bgwork_profstate) - ThreadLocal::gex_bgwork_profstate->worked(); + ThreadLocal::bgwork_profstate->set_worked(true); } }; // namespace Realm diff --git a/src/realm/gasnetex/gasnetex_internal.h b/src/realm/gasnetex/gasnetex_internal.h index 9aa5990f745..dae2fc95e1c 100644 --- a/src/realm/gasnetex/gasnetex_internal.h +++ b/src/realm/gasnetex/gasnetex_internal.h @@ -142,7 +142,7 @@ namespace Realm { bool new_endpoint); void free_outbuf(OutbufMetadata *md); - virtual bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); + virtual bool do_work(TimeLimit work_until); protected: OutbufMetadata *metadatas; @@ -510,7 +510,7 @@ namespace Realm { bool has_work_remaining(); - virtual bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); + virtual bool do_work(TimeLimit work_until); protected: GASNetEXInternal *internal; @@ -531,7 +531,7 @@ namespace Realm { bool has_work_remaining(); - virtual bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); + virtual bool do_work(TimeLimit work_until); // causes calling thread to wait for a full call to gasnet_AMPoll() to // be performed by the poller @@ -557,7 +557,7 @@ namespace Realm { bool has_work_remaining(); - virtual bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); + virtual bool do_work(TimeLimit work_until); protected: GASNetEXInternal *internal; @@ -626,7 +626,7 @@ namespace Realm { bool has_work_remaining(); - virtual bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); + virtual bool do_work(TimeLimit work_until); protected: friend class GASNetEXEvent; diff --git a/src/realm/hip/hip_internal.h b/src/realm/hip/hip_internal.h index 4a93da11b56..45569e3ff1c 100644 --- a/src/realm/hip/hip_internal.h +++ b/src/realm/hip/hip_internal.h @@ -253,7 +253,7 @@ namespace Realm { void start_background_thread(Realm::CoreReservationSet &crs, size_t stack_size); void shutdown_background_thread(void); - bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); + bool do_work(TimeLimit work_until); public: void thread_main(void); @@ -275,10 +275,6 @@ namespace Realm { Realm::Thread *worker_thread; bool thread_sleeping; atomic worker_shutdown_requested; - - // Level 2 bgwork profiling - uint16_t profile_sub_item_id; - bool profile_id_registered; }; // a little helper class to manage a pool of CUevents that can be reused diff --git a/src/realm/hip/hip_module.cc b/src/realm/hip/hip_module.cc index 3af601bab3f..642ab9f7d47 100644 --- a/src/realm/hip/hip_module.cc +++ b/src/realm/hip/hip_module.cc @@ -53,10 +53,6 @@ namespace Realm { namespace Hip { - // file-local thread_local used by GPUWorker::do_work to communicate - // the profiling state to BgWorkGpuHipNotification::request_completed - static thread_local BgWorkProfileState *tl_gpu_profstate = nullptr; - Logger log_gpu("hip"); Logger log_gpudma("hipdma"); Logger log_cudart("cudart"); @@ -205,12 +201,18 @@ namespace Realm { } // we'll keep looking at events until we find one that hasn't triggered + bool first = true; bool work_left = true; while(event_valid) { hipError_t res = hipEventQuery(event); - if(res == hipErrorNotReady) + if(res == hipErrorNotReady) { return true; // oldest event hasn't triggered - check again later + } else if(first) { + // As long as we did at least one event we did work + ThreadLocal::bgwork_profstate->set_worked(true); + first = false; + } // no other kind of error is expected if(res != hipSuccess) { @@ -314,8 +316,7 @@ namespace Realm { started = true; } else { int64_t stop_time = Clock::current_time_in_nanoseconds(true /*absolute*/); - if(tl_gpu_profstate) - tl_gpu_profstate->gpu_work(proc_id, slot, start_time, stop_time); + ThreadLocal::bgwork_profstate->gpu_work(proc_id, slot, start_time, stop_time); delete this; } } @@ -1150,11 +1151,10 @@ namespace Realm { make_active(); } - bool GPUWorker::do_work(TimeLimit work_until, BgWorkProfileState &profstate) + bool GPUWorker::do_work(TimeLimit work_until) { - // make profstate available to GPU notifications during reap_events - tl_gpu_profstate = &profstate; - + // This is a polling background work item so flip work polarity + ThreadLocal::bgwork_profstate->set_worked(false); // pop the first stream off the list and immediately become re-active // if more streams remain GPUStream *stream = 0; @@ -1170,23 +1170,10 @@ namespace Realm { if(still_not_empty) make_active(); - // lazily register for fine-grained profiling - if(bgwork_profiler.get_level() >= 2 && !profile_id_registered) { - profile_sub_item_id = - bgwork_profiler.register_sub_item(BGWP_SUB_GPU_REAP, "hip gpu reap"); - profile_id_registered = true; - } - // do work for the stream we popped, paying attention to the cutoff // time bool was_empty = false; - if(profile_id_registered) - profstate.fine_begin(profile_sub_item_id); - bool has_more = stream->reap_events(work_until); - if(profile_id_registered) - profstate.fine_end(); - if(has_more) { - profstate.worked(); + if(stream->reap_events(work_until)) { AutoLock<> al(lock); was_empty = active_streams.empty(); @@ -1251,9 +1238,18 @@ namespace Realm { void GPUWorker::thread_main(void) { + // Create a background worker profiling state for this thread + BgWorkProfileState profstate; + const TimeLimit unlimited; + const uint8_t slot = get_slot(); // TODO: consider busy-waiting in some cases to reduce latency? while(!worker_shutdown_requested.load()) { + // This is a kind of background work item we're processing so time it + profstate.begin(slot); + // We're polling so set worked to false + profstate.set_worked(false); bool work_left = process_streams(true); + profstate.end(unlimited); // if there was work left, yield our thread for now to avoid a tight spin loop // TODO: enqueue a callback so we can go to sleep and wake up sooner than a kernel @@ -1263,53 +1259,6 @@ namespace Realm { } } - //////////////////////////////////////////////////////////////////////// - // - // class BlockingCompletionNotification - - class BlockingCompletionNotification : public GPUCompletionNotification { - public: - BlockingCompletionNotification(void); - virtual ~BlockingCompletionNotification(void); - - virtual void request_completed(void); - - virtual void wait(void); - - public: - atomic completed; - }; - - BlockingCompletionNotification::BlockingCompletionNotification(void) - : completed(false) - {} - - BlockingCompletionNotification::~BlockingCompletionNotification(void) {} - - void BlockingCompletionNotification::request_completed(void) - { - // no condition variable needed - the waiter is spinning - completed.store(true); - } - - void BlockingCompletionNotification::wait(void) - { - // blocking completion is horrible and should die as soon as possible - // in the mean time, we need to assist with background work to avoid - // the risk of deadlock - // note that this means you can get NESTED blocking completion - // notifications, which is just one of the ways this is horrible - BackgroundWorkManager::Worker worker; - - worker.set_manager(&(get_runtime()->bgwork)); - - BgWorkProfileState bgwork_profstate; - - while(!completed.load()) - worker.do_work(-1 /* as long as it takes */, &completed /* until this is set */, - bgwork_profstate); - } - //////////////////////////////////////////////////////////////////////// // // class GPUFBMemory diff --git a/src/realm/tasks.cc b/src/realm/tasks.cc index 9d0f938ba51..0d33ff4322a 100644 --- a/src/realm/tasks.cc +++ b/src/realm/tasks.cc @@ -17,8 +17,8 @@ // tasks and task scheduling for Realm +#include "realm/bgwork.h" #include "realm/tasks.h" - #include "realm/runtime_impl.h" #include "realm/proc_impl.h" @@ -1076,6 +1076,10 @@ namespace Realm { // the main scheduler loop void ThreadedTaskScheduler::scheduler_loop(void) { + // Need a background profiling state on these threads in case they need + // to handle any background work, lives for the duration of this thread + BgWorkProfileState profstate; + // the entire body of this method, except for when running an actual task, is // a critical section - lock should be taken by caller { @@ -1321,8 +1325,7 @@ namespace Realm { if(max_bgwork_timeslice > 0) { // try to be productive while we're waiting - BgWorkProfileState profstate; - bgworker.do_work(max_bgwork_timeslice, &bgworker_interrupt, profstate); + bgworker.do_work(max_bgwork_timeslice, &bgworker_interrupt); } else { // just let the work counter wake us up when there's stuff to do work_counter.wait_for_work(old_work_counter); diff --git a/src/realm/transfer/channel.h b/src/realm/transfer/channel.h index e8d2b41a02b..d3641ee9bcd 100644 --- a/src/realm/transfer/channel.h +++ b/src/realm/transfer/channel.h @@ -999,7 +999,7 @@ namespace Realm { void enqueue_xd(XD *xd, bool at_front = false); - virtual bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); + virtual bool do_work(TimeLimit work_until); protected: friend CHANNEL; diff --git a/src/realm/transfer/channel.inl b/src/realm/transfer/channel.inl index 26e8364d429..99851b224a8 100644 --- a/src/realm/transfer/channel.inl +++ b/src/realm/transfer/channel.inl @@ -125,7 +125,7 @@ namespace Realm { } template - bool XDQueue::do_work(TimeLimit work_until, BgWorkProfileState &profstate) + bool XDQueue::do_work(TimeLimit work_until) { bool first_iteration = true; while(true) { @@ -169,12 +169,10 @@ namespace Realm { unsigned progress = xd->current_progress(); if(profile_id_registered) - profstate.fine_begin(profile_sub_item_id); + ThreadLocal::bgwork_profstate->fine_begin(profile_sub_item_id); bool did_work = xd->progress_xd(static_cast(channel), work_until); if(profile_id_registered) - profstate.fine_end(); - if(did_work) - profstate.worked(); + ThreadLocal::bgwork_profstate->fine_end(); // if we didn't do any work, and we're not done (i.e. by // concluding there wasn't any work to actually do), re-check diff --git a/src/realm/transfer/lowlevel_dma.cc b/src/realm/transfer/lowlevel_dma.cc index d94728a1d14..c2495f4925d 100644 --- a/src/realm/transfer/lowlevel_dma.cc +++ b/src/realm/transfer/lowlevel_dma.cc @@ -543,7 +543,7 @@ namespace Realm { } } - bool AsyncFileIOContext::do_work(TimeLimit work_until, BgWorkProfileState &profstate) + bool AsyncFileIOContext::do_work(TimeLimit work_until) { // first, reap as many events as we can - oldest first #ifdef REALM_USE_KERNEL_AIO @@ -590,7 +590,6 @@ namespace Realm { AIOOperation *op = launched_operations.front(); if(!op->check_completion()) break; - profstate.worked(); log_aio.debug("aio op completed: op=%p", static_cast(op)); // if(op->req != NULL) { diff --git a/src/realm/transfer/lowlevel_dma.h b/src/realm/transfer/lowlevel_dma.h index 05665cc2a69..3209d130fce 100644 --- a/src/realm/transfer/lowlevel_dma.h +++ b/src/realm/transfer/lowlevel_dma.h @@ -146,7 +146,7 @@ namespace Realm { static AsyncFileIOContext *get_singleton(void); - virtual bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); + virtual bool do_work(TimeLimit work_until); class AIOOperation { public: diff --git a/src/realm/ucx/ucp_internal.cc b/src/realm/ucx/ucp_internal.cc index f76cf959cfa..cb1084620d0 100644 --- a/src/realm/ucx/ucp_internal.cc +++ b/src/realm/ucx/ucp_internal.cc @@ -84,7 +84,6 @@ namespace Realm { namespace ThreadLocal { thread_local const TimeLimit *ucp_work_until = nullptr; - thread_local BgWorkProfileState *ucp_bgwork_profstate = nullptr; }; struct CompList { @@ -328,17 +327,19 @@ namespace Realm { poll_notify_cond.wait(); } - bool UCPPoller::do_work(TimeLimit work_until, BgWorkProfileState &profstate) + bool UCPPoller::do_work(TimeLimit work_until) { ThreadLocal::ucp_work_until = &work_until; - ThreadLocal::ucp_bgwork_profstate = &profstate; + + // This is a polling background work item, so clear the + // worked bit and only set it if we do real work + ThreadLocal::bgwork_profstate->set_worked(false); for(auto worker : workers) { (void)worker->progress(); } ThreadLocal::ucp_work_until = nullptr; - ThreadLocal::ucp_bgwork_profstate = nullptr; // if a poll notify has been requested, wake the waiter if(poll_notify_flag.load()) { @@ -1198,8 +1199,7 @@ namespace Realm { &am_realm_comp_handler, cb_data1, 0, (ThreadLocal::ucp_work_until != nullptr) ? *ThreadLocal::ucp_work_until : TimeLimit::relative(0)); - if(ThreadLocal::ucp_bgwork_profstate) - ThreadLocal::ucp_bgwork_profstate->worked(); + ThreadLocal::bgwork_profstate->set_worked(true); if(completed) { am_realm_comp_handler(ucp_msg_hdr->src, cb_data1, 0); diff --git a/src/realm/ucx/ucp_internal.h b/src/realm/ucx/ucp_internal.h index bf061a0691f..d16f800f3f5 100644 --- a/src/realm/ucx/ucp_internal.h +++ b/src/realm/ucx/ucp_internal.h @@ -86,7 +86,7 @@ namespace Realm { void begin_polling(); void end_polling(); void wait_polling(); - bool do_work(TimeLimit work_until, BgWorkProfileState &profstate); + bool do_work(TimeLimit work_until); void add_worker(UCPWorker *worker); private: From 0ef1fdb1146655339bf1653ac45671567a069ce6 Mon Sep 17 00:00:00 2001 From: Mike Date: Wed, 18 Mar 2026 16:13:16 -0700 Subject: [PATCH 11/14] compilation fixes for submodules --- src/realm/cuda/cuda_module.cc | 8 +++----- src/realm/gasnetex/gasnetex_internal.cc | 2 +- src/realm/hip/hip_module.cc | 8 +++----- 3 files changed, 7 insertions(+), 11 deletions(-) diff --git a/src/realm/cuda/cuda_module.cc b/src/realm/cuda/cuda_module.cc index 8738e79797f..8e9085347f8 100644 --- a/src/realm/cuda/cuda_module.cc +++ b/src/realm/cuda/cuda_module.cc @@ -309,7 +309,7 @@ namespace Realm { return true; // oldest event hasn't triggered - check again later } else if(first) { // As long as we did at least one event we did work - ThreadLocal::bgwork_profstate->set_worked(true); + Realm::ThreadLocal::bgwork_profstate->set_worked(true); first = false; } @@ -390,7 +390,7 @@ namespace Realm { started = true; } else { int64_t stop_time = Clock::current_time_in_nanoseconds(true /*absolute*/); - ThreadLocal::bgwork_profstate->gpu_work(proc_id, slot, start_time, stop_time); + Realm::ThreadLocal::bgwork_profstate->gpu_work(proc_id, slot, start_time, stop_time); delete this; } } @@ -1339,8 +1339,6 @@ namespace Realm { , worker_thread(0) , thread_sleeping(false) , worker_shutdown_requested(false) - , profile_sub_item_id(0) - , profile_id_registered(false) {} GPUWorker::~GPUWorker(void) @@ -1413,7 +1411,7 @@ namespace Realm { bool GPUWorker::do_work(TimeLimit work_until) { // This is a polling background work item so flip work polarity - ThreadLocal::bgwork_profstate->set_worked(false); + Realm::ThreadLocal::bgwork_profstate->set_worked(false); // pop the first stream off the list and immediately become re-active // if more streams remain GPUStream *stream = 0; diff --git a/src/realm/gasnetex/gasnetex_internal.cc b/src/realm/gasnetex/gasnetex_internal.cc index 5266f98f4d7..23d79d3a66f 100644 --- a/src/realm/gasnetex/gasnetex_internal.cc +++ b/src/realm/gasnetex/gasnetex_internal.cc @@ -3068,7 +3068,7 @@ namespace Realm { return (head != nullptr); } - bool ReverseGetter::do_work(TimeLimit work_until, BgWorkProfileState &profstate) + bool ReverseGetter::do_work(TimeLimit work_until) { // we're not going to use immedate mode for rgets, so don't have more // than one dequeuer at a time - do this by peeking at the head but diff --git a/src/realm/hip/hip_module.cc b/src/realm/hip/hip_module.cc index 642ab9f7d47..be3d077b1d9 100644 --- a/src/realm/hip/hip_module.cc +++ b/src/realm/hip/hip_module.cc @@ -210,7 +210,7 @@ namespace Realm { return true; // oldest event hasn't triggered - check again later } else if(first) { // As long as we did at least one event we did work - ThreadLocal::bgwork_profstate->set_worked(true); + Realm::ThreadLocal::bgwork_profstate->set_worked(true); first = false; } @@ -316,7 +316,7 @@ namespace Realm { started = true; } else { int64_t stop_time = Clock::current_time_in_nanoseconds(true /*absolute*/); - ThreadLocal::bgwork_profstate->gpu_work(proc_id, slot, start_time, stop_time); + Realm::ThreadLocal::bgwork_profstate->gpu_work(proc_id, slot, start_time, stop_time); delete this; } } @@ -1080,8 +1080,6 @@ namespace Realm { , worker_thread(0) , thread_sleeping(false) , worker_shutdown_requested(false) - , profile_sub_item_id(0) - , profile_id_registered(false) {} GPUWorker::~GPUWorker(void) @@ -1154,7 +1152,7 @@ namespace Realm { bool GPUWorker::do_work(TimeLimit work_until) { // This is a polling background work item so flip work polarity - ThreadLocal::bgwork_profstate->set_worked(false); + Realm::ThreadLocal::bgwork_profstate->set_worked(false); // pop the first stream off the list and immediately become re-active // if more streams remain GPUStream *stream = 0; From 50dcacfa3af175fdbc46a7bf252b3e3cd3d6fedd Mon Sep 17 00:00:00 2001 From: Mike Date: Wed, 18 Mar 2026 17:21:25 -0700 Subject: [PATCH 12/14] handle cases where it looks like we are doing background work from a non-background work thread --- src/realm/activemsg.cc | 5 +++++ src/realm/cuda/cuda_module.cc | 3 ++- src/realm/gasnet1/gasnetmsg.cc | 4 +++- src/realm/gasnetex/gasnetex_internal.cc | 7 +++---- src/realm/hip/hip_module.cc | 3 ++- src/realm/tasks.cc | 6 ++---- src/realm/ucx/ucp_internal.cc | 1 - 7 files changed, 17 insertions(+), 12 deletions(-) diff --git a/src/realm/activemsg.cc b/src/realm/activemsg.cc index 504e6d52222..88948bf4eea 100644 --- a/src/realm/activemsg.cc +++ b/src/realm/activemsg.cc @@ -19,6 +19,7 @@ #include "realm/atomics.h" #include "realm/activemsg.h" +#include "realm/bgwork.h" #include "realm/mutex.h" #include "realm/cmdline.h" #include "realm/logging.h" @@ -393,6 +394,10 @@ namespace Realm { #ifdef DEBUG_INCOMING printf("adding incoming message from %d\n", sender); #endif + // Record that we did work handling a message for any networks + if(ThreadLocal::bgwork_profstate) { + ThreadLocal::bgwork_profstate->set_worked(true); + } // look up which message this is ActiveMessageHandlerTable::HandlerEntry *handler = diff --git a/src/realm/cuda/cuda_module.cc b/src/realm/cuda/cuda_module.cc index 8e9085347f8..72c46bfe5c2 100644 --- a/src/realm/cuda/cuda_module.cc +++ b/src/realm/cuda/cuda_module.cc @@ -390,7 +390,8 @@ namespace Realm { started = true; } else { int64_t stop_time = Clock::current_time_in_nanoseconds(true /*absolute*/); - Realm::ThreadLocal::bgwork_profstate->gpu_work(proc_id, slot, start_time, stop_time); + Realm::ThreadLocal::bgwork_profstate->gpu_work(proc_id, slot, start_time, + stop_time); delete this; } } diff --git a/src/realm/gasnet1/gasnetmsg.cc b/src/realm/gasnet1/gasnetmsg.cc index 4256261c650..4f59f0af3cc 100644 --- a/src/realm/gasnet1/gasnetmsg.cc +++ b/src/realm/gasnet1/gasnetmsg.cc @@ -2614,7 +2614,9 @@ static void handle_new_activemsg(gasnet_token_t token, void *buf, size_t nbytes, } } else record_message(src, false); - ThreadLocal::bgwork_profstate->set_worked(true); + if(ThreadLocal::bgwork_profstate) { + ThreadLocal::bgwork_profstate->set_worked(true); + } } void gasnet_parse_command_line(std::vector &cmdline) diff --git a/src/realm/gasnetex/gasnetex_internal.cc b/src/realm/gasnetex/gasnetex_internal.cc index 23d79d3a66f..c3dc4b389ee 100644 --- a/src/realm/gasnetex/gasnetex_internal.cc +++ b/src/realm/gasnetex/gasnetex_internal.cc @@ -5030,7 +5030,6 @@ namespace Realm { ((ThreadLocal::gex_work_until != nullptr) ? *ThreadLocal::gex_work_until : TimeLimit::relative(0))); ThreadLocal::in_am_handler = false; - ThreadLocal::bgwork_profstate->set_worked(true); if(handled) { // if the message was handled immediately, we can use a reply for @@ -5081,7 +5080,6 @@ namespace Realm { ((ThreadLocal::gex_work_until != nullptr) ? *ThreadLocal::gex_work_until : TimeLimit::relative(0))); ThreadLocal::in_am_handler = false; - ThreadLocal::bgwork_profstate->set_worked(true); if(handled) { // if the message was handled immediately, we can use a reply for @@ -5133,7 +5131,6 @@ namespace Realm { ((ThreadLocal::gex_work_until != nullptr) ? *ThreadLocal::gex_work_until : TimeLimit::relative(0))); ThreadLocal::in_am_handler = false; - ThreadLocal::bgwork_profstate->set_worked(true); if(handled) { // if the message was handled immediately, we can use a reply for @@ -5299,7 +5296,9 @@ namespace Realm { } ThreadLocal::in_am_handler = false; - ThreadLocal::bgwork_profstate->set_worked(true); + if(ThreadLocal::bgwork_profstate) { + ThreadLocal::bgwork_profstate->set_worked(true); + } } }; // namespace Realm diff --git a/src/realm/hip/hip_module.cc b/src/realm/hip/hip_module.cc index be3d077b1d9..22683ce7610 100644 --- a/src/realm/hip/hip_module.cc +++ b/src/realm/hip/hip_module.cc @@ -316,7 +316,8 @@ namespace Realm { started = true; } else { int64_t stop_time = Clock::current_time_in_nanoseconds(true /*absolute*/); - Realm::ThreadLocal::bgwork_profstate->gpu_work(proc_id, slot, start_time, stop_time); + Realm::ThreadLocal::bgwork_profstate->gpu_work(proc_id, slot, start_time, + stop_time); delete this; } } diff --git a/src/realm/tasks.cc b/src/realm/tasks.cc index 0d33ff4322a..ced7bf4fee6 100644 --- a/src/realm/tasks.cc +++ b/src/realm/tasks.cc @@ -1076,10 +1076,6 @@ namespace Realm { // the main scheduler loop void ThreadedTaskScheduler::scheduler_loop(void) { - // Need a background profiling state on these threads in case they need - // to handle any background work, lives for the duration of this thread - BgWorkProfileState profstate; - // the entire body of this method, except for when running an actual task, is // a critical section - lock should be taken by caller { @@ -1324,6 +1320,8 @@ namespace Realm { lock.unlock(); if(max_bgwork_timeslice > 0) { + // If we're going to go off and do background work then we need to profile it + BgWorkProfileState profstate; // try to be productive while we're waiting bgworker.do_work(max_bgwork_timeslice, &bgworker_interrupt); } else { diff --git a/src/realm/ucx/ucp_internal.cc b/src/realm/ucx/ucp_internal.cc index cb1084620d0..198ddd5ec5e 100644 --- a/src/realm/ucx/ucp_internal.cc +++ b/src/realm/ucx/ucp_internal.cc @@ -1199,7 +1199,6 @@ namespace Realm { &am_realm_comp_handler, cb_data1, 0, (ThreadLocal::ucp_work_until != nullptr) ? *ThreadLocal::ucp_work_until : TimeLimit::relative(0)); - ThreadLocal::bgwork_profstate->set_worked(true); if(completed) { am_realm_comp_handler(ucp_msg_hdr->src, cb_data1, 0); From f61646f4e0f5b899697ebd93566738e6adad4f38 Mon Sep 17 00:00:00 2001 From: Mike Date: Wed, 25 Mar 2026 13:04:11 -0700 Subject: [PATCH 13/14] realm: small fix for ucx bgwork profiling --- src/realm/ucx/ucp_internal.cc | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/realm/ucx/ucp_internal.cc b/src/realm/ucx/ucp_internal.cc index 198ddd5ec5e..d017d88fa4a 100644 --- a/src/realm/ucx/ucp_internal.cc +++ b/src/realm/ucx/ucp_internal.cc @@ -333,7 +333,7 @@ namespace Realm { // This is a polling background work item, so clear the // worked bit and only set it if we do real work - ThreadLocal::bgwork_profstate->set_worked(false); + Realm::ThreadLocal::bgwork_profstate->set_worked(false); for(auto worker : workers) { (void)worker->progress(); From 20b13e1299fa8f99cd82e956e4922cf3b9c5cc97 Mon Sep 17 00:00:00 2001 From: Mike Date: Wed, 25 Mar 2026 13:42:16 -0700 Subject: [PATCH 14/14] test: fix bgwork profile test for windows --- tests/bgwork_profile.cc | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/tests/bgwork_profile.cc b/tests/bgwork_profile.cc index 3466f609614..9f39179dac6 100644 --- a/tests/bgwork_profile.cc +++ b/tests/bgwork_profile.cc @@ -114,7 +114,11 @@ static bool decode_timestamp(const uint8_t *data, size_t data_size, size_t &pos, static bool validate_profile_file(const std::string &filename) { +#ifdef REALM_ON_WINDOWS + int fd = _open(filename.c_str(), _O_RDONLY | _O_BINARY); +#else int fd = open(filename.c_str(), O_RDONLY); +#endif if(fd < 0) { fprintf(stderr, "VALIDATE: cannot open file: %s\n", filename.c_str()); return false;