/* * SPDX-License-Identifier: LicenseRef-CSSL-1.0 */ #include #include #include #include #include #include #include #include #include #include "fmtlog.h" namespace ch = clickhouse; extern "C" { // For connect_to(), socket_send(), parse_database(), etc. #include #include #include #include #include #include "database.h" #include "utils.h" #include "../T_defs.h" #include "configuration.h" } const int MAX_QUERY_SIZE = 65536; const char *DEFAULT_CLICKHOUSE_HOST = "localhost"; const int DEFAULT_CLICKHOUSE_PORT = 9000; const char *DEFAULT_CLICKHOUSE_DB = "oai"; // Buffer multiple rows per event type and insert when: // 1. Buffer reaches BATCH_SIZE rows, OR // 2. INSERT_INTERVAL_MS milliseconds have elapsed since last insert // This reduces insertion time from ~30ms/event to <1ms/event amortized const size_t BATCH_SIZE = 500; // Number of rows to buffer before inserting const uint64_t INSERT_INTERVAL_MS = 500; // Insert every 500ms const size_t BUFFER_SIZE = 10 * 1024 * 1024; // 10MB const size_t BUFFER_MARGIN = 183'456; // UE_PHY_PDSCH_IQ size // 5G NR timing constants const uint64_t NS_PER_SEC = 1000000000ULL; const uint64_t FRAME_PERIOD_NS = 10000000ULL; // 10ms per frame const int SFN_MAX = 1024; // Duration of one full SFN cycle (1024 frames = 10.24 seconds) const uint64_t SFN_CYCLE_NS = FRAME_PERIOD_NS * SFN_MAX; // TAI to UTC offset in seconds (37 leap seconds as of 2017) // This may need to be updated when new leap seconds are added const int TAI_UTC_OFFSET_SEC = 37; // GPS epoch is January 6, 1980 00:00:00 UTC // Unix epoch is January 1, 1970 00:00:00 UTC // Offset = 315964800 seconds const uint64_t UNIX_TO_GPS_OFFSET_SEC = 315964800ULL; const uint64_t UNIX_TO_GPS_OFFSET_NS = UNIX_TO_GPS_OFFSET_SEC * NS_PER_SEC; const uint8_t UTC_TO_GPS_OFFSET_SEC = 18; // As of 2017, GPS time is 18 seconds ahead of UTC time. const uint64_t UTC_TO_GPS_OFFSET_NS = UTC_TO_GPS_OFFSET_SEC * NS_PER_SEC; /** * Calculate duration between two timestamps in nanoseconds * Works with both std::chrono::high_resolution_clock::time_point and uint64_t nanosecond timestamps */ #define DURATION_NS(start, end) (std::chrono::duration_cast((end) - (start)).count()) #define DURATION_US(start, end) (std::chrono::duration_cast((end) - (start)).count()) #define DURATION_MS(start, end) (std::chrono::duration_cast((end) - (start)).count()) /** * Calculate duration between two uint64_t nanosecond timestamps */ #define DURATION_NS_U64(end_ns, start_ns) ((int64_t)(end_ns) - (int64_t)(start_ns)) /** * Get slot duration in nanoseconds for a given numerology * mu=0 (15kHz): 1ms, mu=1 (30kHz): 0.5ms, mu=2 (60kHz): 0.25ms, etc. */ inline uint64_t get_slot_duration_ns(int mu) { static const uint64_t slot_durations_ns[] = { 1000000, // mu=0: 1ms 500000, // mu=1: 0.5ms 250000, // mu=2: 0.25ms 125000, // mu=3: 0.125ms 62500 // mu=4: 0.0625ms }; if (mu < 0 || mu > 4) { loge("Invalid numerology mu={}, using mu=0", mu); return slot_durations_ns[0]; } return slot_durations_ns[mu]; } /** * Get number of slots per frame for a given numerology */ inline int get_slots_per_frame(int mu) { static const int slots_per_frame[] = {10, 20, 40, 80, 160}; if (mu < 0 || mu > 4) { loge("Invalid numerology mu={}, using mu=0", mu); return slots_per_frame[0]; } return slots_per_frame[mu]; } /** * Convert Unix/Linux time to GPS time * * @param unix_time_ns Unix time in nanoseconds since Unix epoch (Jan 1, 1970) * @return GPS time in nanoseconds since GPS epoch (Jan 6, 1980) */ inline uint64_t unix_to_gps_ns(uint64_t unix_time_ns) { return unix_time_ns - UNIX_TO_GPS_OFFSET_NS + UTC_TO_GPS_OFFSET_NS; } /** * Convert GPS time to Unix/Linux time * * @param gps_time_ns GPS time in nanoseconds since GPS epoch * @return GPS time in nanoseconds since Unix epoch */ inline uint64_t gps_to_posix_ns(uint64_t gps_time_ns) { return gps_time_ns + UNIX_TO_GPS_OFFSET_NS; } /** * Convert GPS time to Unix/Linux time * * @param gps_time_ns GPS time in nanoseconds since GPS epoch * @return UTC time in nanoseconds since Unix epoch */ inline uint64_t gps_to_utc_ns(uint64_t gps_time_ns) { return gps_to_posix_ns(gps_time_ns) - UTC_TO_GPS_OFFSET_NS; } /** * Calculate the absolute GPS timestamp for a given SFN and slot, given a close time reference in Unix time. * * @param sfn System Frame Number (0-1023) * @param slot Slot number within the frame (depends on numerology) * @param mu Numerology (0-4): 0=15kHz, 1=30kHz, 2=60kHz, 3=120kHz, 4=240kHz * @param reference_utc_ns Reference UTC time in nanoseconds since Unix epoch * @return UTC timestamp in nanoseconds when the SFN/slot was transmitted */ uint64_t calculate_sfn_slot_gps_time(int sfn, int slot, int mu, uint64_t reference_unix_ns) { // Validate inputs if (sfn < 0 || sfn >= SFN_MAX) { loge("Invalid SFN={} (must be 0-1023)", sfn); sfn = sfn % SFN_MAX; return 0; } int slots_per_frame = get_slots_per_frame(mu); if (slot < 0 || slot >= slots_per_frame) { loge("Invalid slot={} for mu={} (must be 0-{})", slot, mu, slots_per_frame - 1); slot = slot % slots_per_frame; } // Nanoseconds since GPS epoch start, should be slightly larger than actual transmit time. uint64_t reference_gps_ns = unix_to_gps_ns(reference_unix_ns); // Calculate the offset within one SFN cycle for the given SFN/slot uint64_t slot_duration_ns = get_slot_duration_ns(mu); uint64_t offset_in_cycle_ns = (sfn * FRAME_PERIOD_NS) + (slot * slot_duration_ns); // Find the number of complete SFN cycles since GPS epoch // We'll use the reference time to determine which SFN cycle we're in uint64_t cycles_since_epoch = reference_gps_ns / SFN_CYCLE_NS; // Calculate the base time for the current SFN cycle uint64_t current_cycle_base_ns = cycles_since_epoch * SFN_CYCLE_NS; // Calculate the target time within this cycle uint64_t gps_time_ns = current_cycle_base_ns + offset_in_cycle_ns; // Check if the GPS time is too far in the future (more than 1 second) // If so, it probably occurred in the previous cycle if (gps_time_ns > reference_gps_ns + NS_PER_SEC) { gps_time_ns -= SFN_CYCLE_NS; } // Check if the target is too far in the past (more than 9.24 seconds) // If so, it probably occurs in the next cycle if (gps_time_ns < reference_gps_ns - (SFN_CYCLE_NS - NS_PER_SEC)) { gps_time_ns += SFN_CYCLE_NS; } return gps_time_ns; } void calculate_sfn_slot_from_gps(uint64_t gps_time_ns, int mu, int *sfn, int *slot) { uint64_t phase_ns = gps_time_ns % SFN_CYCLE_NS; *sfn = phase_ns / FRAME_PERIOD_NS; // Truncate to integer uint64_t position_in_frame_ns = phase_ns % FRAME_PERIOD_NS; // Remainder uint64_t slot_duration_ns = get_slot_duration_ns(mu); *slot = position_in_frame_ns / slot_duration_ns; if (*sfn >= SFN_MAX) *sfn = SFN_MAX - 1; int max_slot = get_slots_per_frame(mu) - 1; if (*slot > max_slot) *slot = max_slot; } void calculate_sfn_slot_from_unix(uint64_t unix_time_ns, int mu, int *sfn, int *slot) { uint64_t gps_time_ns = unix_to_gps_ns(unix_time_ns); calculate_sfn_slot_from_gps(gps_time_ns, mu, sfn, slot); } void usage(void) { printf( "options:\n" " -d this option is mandatory\n" " -on turn log ON for given GROUP or ID\n" " -off turn log OFF for given GROUP or ID\n" " -ON turn all logs ON\n" " -OFF turn all logs OFF\n" " note: you may pass several -on/-off/-ON/-OFF,\n" " they will be processed in order\n" " by default, all is off\n" " -ip connect to given IP address (default %s)\n" " -p connect to given port (default %d)\n" " -ch-host ClickHouse host (default %s)\n" " -ch-port ClickHouse native port (default %d)\n" " -ch-db ClickHouse database name (default %s)\n" " -ch-user ClickHouse user (optional)\n" " -ch-pass ClickHouse password (optional)\n" " -ch-droptables drop the ClickHouse database before run\n" " -debug enable debug logging\n", DEFAULT_REMOTE_IP, DEFAULT_REMOTE_PORT, DEFAULT_CLICKHOUSE_HOST, DEFAULT_CLICKHOUSE_PORT, DEFAULT_CLICKHOUSE_DB); exit(1); } volatile int run = 1; static int socket_fd = -1; void force_stop(int x) { logi("gently quit %d", x); close(socket_fd); socket_fd = -1; run = 0; } struct clickhouse_config_t { std::string host; int port; std::string database; std::string user; std::string password; std::unique_ptr client; int drop_tables; }; // Buffer management structures struct DataBuffer { uint8_t *buffer; // Large preallocated buffer size_t buffer_size; // Total size of buffer size_t current_offset; // Current write position in buffer std::shared_ptr inner_col; // Reusable inner column for ClickHouse std::shared_ptr offsets_col; // Reusable offsets column for ClickHouse (cumulative end offsets) bool insert_now; DataBuffer(size_t size) : buffer_size(size - BUFFER_MARGIN), current_offset(0), insert_now(false) { buffer = (uint8_t *)malloc(size); if (!buffer) { throw std::bad_alloc(); } // Create and reserve ClickHouse columns for reuse inner_col = std::make_shared(); auto &inner_data = inner_col->GetWritableData(); inner_data.reserve(size); offsets_col = std::make_shared(); offsets_col->Reserve(BATCH_SIZE); } ~DataBuffer() { if (buffer) { free(buffer); buffer = nullptr; } } // Disable copy constructor and assignment operator DataBuffer(const DataBuffer &) = delete; DataBuffer &operator=(const DataBuffer &) = delete; // Copy data into buffer and return offset size_t append(const void *data, size_t length) { if (current_offset + length > buffer_size) { insert_now = true; // If this puts the buffer into the margin, insert it immediately if (length > BUFFER_MARGIN) { loge("DataBuffer full: current_offset={} length={} buffer_size={}", current_offset, length, buffer_size); return (size_t)-1; } // Else we have margin } size_t offset = current_offset; memcpy(buffer + current_offset, data, length); current_offset += length; offsets_col->Append(current_offset); return offset; } // Get pointer to data at a specific offset const uint8_t *get_data(size_t offset) const { if (offset >= current_offset) { return nullptr; } return buffer + offset; } // Clear buffer for reuse void clear() { current_offset = 0; insert_now = false; inner_col->Clear(); offsets_col->Clear(); } // Get number of entries size_t entry_count() const { return offsets_col->Size(); } // Get current usage size_t usage() const { return current_offset; } }; struct EventBuffer { std::vector columns; // Ordered list of columns std::vector column_names; // Column names in same order std::string event_table_name; size_t row_count; bool insert_now; std::chrono::steady_clock::time_point last_insert_time; database_event_format format; std::string event_name; bool has_frame_slot; std::unordered_map> data_buffers; // Cached typed column pointers to avoid expensive As<> casts on every insert std::shared_ptr ts_sw_col; std::shared_ptr ts_tx_col; std::vector> int_cols; std::vector> ulong_cols; std::vector> string_cols; std::unordered_map field_idx_to_typed_col_idx; // Maps format field index to typed column index // Performance metrics uint64_t last_column_build_duration_ns; uint64_t last_block_append_duration_ns; uint64_t last_insertion_duration_ns; // Statistics tracking uint64_t total_rows; // Total rows inserted since start uint64_t rows_since_print; // Rows since last print EventBuffer() : row_count(0), insert_now(false), last_insert_time(std::chrono::steady_clock::now()), has_frame_slot(false), last_column_build_duration_ns(0), last_block_append_duration_ns(0), last_insertion_duration_ns(0), total_rows(0), rows_since_print(0) { } }; // Global buffer map: event_id -> EventBuffer std::unordered_map g_event_buffers; /* Convert T format type to ClickHouse type */ const char *get_clickhouse_type(const char *t_type) { if (strcmp(t_type, "int") == 0) return "Int32"; if (strcmp(t_type, "ulong") == 0) return "UInt64"; if (strcmp(t_type, "string") == 0) return "String"; if (strcmp(t_type, "buffer") == 0) return "Array(UInt8)"; // Store as byte array if (strncmp(t_type, "int", 3) == 0) return "Int32"; return "String"; // default } /* Execute ClickHouse query */ int clickhouse_execute(clickhouse_config_t *ch, const char *query) { try { ch->client->Execute(query); return 0; } catch (const std::exception &e) { loge("ClickHouse query failed: {}", e.what()); return -1; } } /* Initialize ClickHouse connection and create database */ int clickhouse_init(clickhouse_config_t *ch) { char query[1024]; try { // Set connection options ch::ClientOptions options; options.SetHost(ch->host); options.SetPort(ch->port); if (!ch->user.empty()) { options.SetUser(ch->user); } if (!ch->password.empty()) { options.SetPassword(ch->password); } // Create client ch->client = std::make_unique(options); /* Handle drop database option */ if (ch->drop_tables) { logi("Dropping database: {}", ch->database.c_str()); snprintf(query, sizeof(query), "DROP DATABASE IF EXISTS %s", ch->database.c_str()); if (clickhouse_execute(ch, query) != 0) { loge("Failed to drop database {}", ch->database); exit(1); } } // Create database if not exists snprintf(query, sizeof(query), "CREATE DATABASE IF NOT EXISTS %s", ch->database.c_str()); if (clickhouse_execute(ch, query) != 0) { loge("Failed to create database"); return -1; } logi("ClickHouse connection initialized"); return 0; } catch (const std::exception &e) { loge("Failed to create ClickHouse client: {}", e.what()); return -1; } } /* Create table schema from database format */ char *create_table_schema(char *schema_buf, const char *event_name, database_event_format format, const char *database) { char *p = schema_buf; bool has_frame = false; bool has_slot = false; int i; // Start CREATE TABLE statement p += snprintf(p, MAX_QUERY_SIZE - (p - schema_buf), "CREATE TABLE IF NOT EXISTS %s.%s (\n TsSwNs DateTime64(9) DEFAULT now64(9)", database, event_name); for (i = 0; i < format.count; i++) { if (strcmp(format.name[i], "frame") == 0) has_frame = true; if (strcmp(format.name[i], "slot") == 0) has_slot = true; if (strcmp(format.name[i], "subframe") == 0) has_slot = true; } if (has_frame && has_slot) { p += snprintf(p, MAX_QUERY_SIZE - (p - schema_buf), ",\n TsTxUtcNs DateTime64(9)"); uint64_t timestamp_ns = std::chrono::system_clock::now().time_since_epoch().count() / NS_PER_SEC; if (timestamp_ns > 1861920000) { // 1861920000 -> 2029-01-01 00:00:00 logw("WARNING: Linux time {} is greater than 2029-01-01 00:00:00.", timestamp_ns); logw(" Check if a negative leap second has been announced and change UTC_TO_GPS_OFFSET_NS accordingly.", timestamp_ns); } } // Add columns from format for (i = 0; i < format.count; i++) { const char *ch_type = get_clickhouse_type(format.type[i]); p += snprintf(p, MAX_QUERY_SIZE - (p - schema_buf), ",\n %s %s", format.name[i], ch_type); } p += snprintf(p, MAX_QUERY_SIZE - (p - schema_buf), "\n) ENGINE = Memory();"); #ifdef DB_DEBUG logd("schema: {}", schema_buf); #endif return schema_buf; } /* Initialize buffer for an event */ void init_event_buffer(int event_id, void *database, const char *database_name) { char *event_name = event_name_from_id(database, event_id); database_event_format format = get_format(database, event_id); if (!event_name) return; EventBuffer &buf = g_event_buffers[event_id]; buf.event_name = std::string(event_name); buf.event_table_name = std::string(database_name) + "." + event_name; buf.format = format; buf.row_count = 0; buf.last_insert_time = std::chrono::steady_clock::now(); // Check if this event has frame/slot fields buf.has_frame_slot = false; bool has_frame = false; bool has_slot = false; for (int i = 0; i < format.count; i++) { if (strcmp(format.name[i], "frame") == 0) has_frame = true; if (strcmp(format.name[i], "slot") == 0 || strcmp(format.name[i], "subframe") == 0) has_slot = true; } buf.has_frame_slot = has_frame && has_slot; // Create TsSwNs column auto ts_col = std::make_shared(9); ts_col->Reserve(BATCH_SIZE); buf.columns.push_back(ts_col); buf.column_names.push_back("TsSwNs"); buf.ts_sw_col = ts_col; // Cache typed pointer // Add data columns for (int i = 0; i < format.count; i++) { if (strcmp(format.type[i], "int") == 0) { auto col = std::make_shared(); col->Reserve(BATCH_SIZE); buf.columns.push_back(col); buf.column_names.push_back(format.name[i]); buf.field_idx_to_typed_col_idx[i] = buf.int_cols.size(); buf.int_cols.push_back(col); } else if (strcmp(format.type[i], "ulong") == 0) { auto col = std::make_shared(); col->Reserve(BATCH_SIZE); buf.columns.push_back(col); buf.column_names.push_back(format.name[i]); buf.field_idx_to_typed_col_idx[i] = buf.ulong_cols.size(); buf.ulong_cols.push_back(col); } else if (strcmp(format.type[i], "buffer") == 0) { buf.data_buffers[i] = std::make_unique(BUFFER_SIZE); // Placeholder - array column will be created from DataBuffer at flush time buf.columns.push_back(nullptr); buf.column_names.push_back(format.name[i]); } else if (strcmp(format.type[i], "string") == 0) { auto col = std::make_shared(); col->Reserve(BATCH_SIZE); buf.columns.push_back(col); buf.column_names.push_back(format.name[i]); buf.field_idx_to_typed_col_idx[i] = buf.string_cols.size(); buf.string_cols.push_back(col); } else { // Default: treat as int auto col = std::make_shared(); col->Reserve(BATCH_SIZE); buf.columns.push_back(col); buf.column_names.push_back(format.name[i]); buf.field_idx_to_typed_col_idx[i] = buf.int_cols.size(); buf.int_cols.push_back(col); } } // Add TsTxUtcNs column if event has frame/slot if (buf.has_frame_slot) { auto gps_col = std::make_shared(9); gps_col->Reserve(BATCH_SIZE); buf.columns.push_back(gps_col); buf.column_names.push_back("TsTxUtcNs"); buf.ts_tx_col = gps_col; // Cache typed pointer } logi("Initialized buffer for event_id:{:<4} name:{:<31} has_frame_slot:{} columns:{}", event_id, event_name, buf.has_frame_slot, buf.columns.size()); // Print sizes of buffer fields for (int i = 0; i < format.count; i++) { if (strcmp(format.type[i], "buffer") == 0) { logd(" Buffer field '{}' size={} MB", format.name[i], BUFFER_SIZE / (1024 * 1024)); } } } /* Create tables for enabled events */ int create_tables(clickhouse_config_t *ch, void *database, int *is_on, int number_of_events) { int i; size_t longest_table_name = 0; for (i = 0; i < number_of_events; i++) { if (!is_on[i]) continue; char *event_name = event_name_from_id(database, i); database_event_format format = get_format(database, i); if (strlen(event_name) > longest_table_name) longest_table_name = strlen(event_name); if (!event_name) continue; logd("Creating table for event: {:<31}", event_name); char schema[MAX_QUERY_SIZE]; create_table_schema(schema, event_name, format, ch->database.c_str()); if (clickhouse_execute(ch, schema) != 0) { loge("Failed to create table {}", event_name); return -1; } // Initialize buffer for this event init_event_buffer(i, database, ch->database.c_str()); } return (int)longest_table_name; } int insert_buffer(clickhouse_config_t *ch, int event_id) { auto it = g_event_buffers.find(event_id); if (it == g_event_buffers.end() || it->second.row_count == 0) { return 0; // Nothing to flush } EventBuffer &buf = it->second; buf.insert_now = false; auto t_reconstruct_start = std::chrono::high_resolution_clock::now(); size_t total_data_size = 0; for (auto &dbuf_pair : buf.data_buffers) { int field_idx = dbuf_pair.first; DataBuffer *dbuf = dbuf_pair.second.get(); int col_idx = field_idx + 1; // +1 because TsSwNs is at index 0 // Build the array column from the DataBuffer size_t num_entries = dbuf->offsets_col->Size(); if (num_entries != buf.row_count) { loge("DataBuffer entry count mismatch for field '{}': {} entries vs {} rows", buf.format.name[field_idx], num_entries, buf.row_count); } // Copy all data to the DataBuffer's inner column (space already reserved in constructor) if (dbuf->current_offset > 0) { auto &inner_data = dbuf->inner_col->GetWritableData(); inner_data.resize(dbuf->current_offset); // Set size (doesn't reallocate since already reserved) memcpy(inner_data.data(), dbuf->buffer, dbuf->current_offset); } // Create the array column from DataBuffer's columns and store it auto array_col = std::make_shared>(dbuf->inner_col, dbuf->offsets_col); buf.columns[col_idx] = array_col; total_data_size += dbuf->current_offset; } auto t_reconstruct_end = std::chrono::high_resolution_clock::now(); ch::Block block; for (size_t i = 0; i < buf.columns.size(); i++) { if (buf.columns[i]) { block.AppendColumn(buf.column_names[i], buf.columns[i]); } else { loge("Column '{}' at index {} is null when creating block", buf.column_names[i], i); exit(1); } } try { auto t_insert_start = std::chrono::high_resolution_clock::now(); ch->client->Insert(buf.event_table_name.c_str(), block); auto t_insert_end = std::chrono::high_resolution_clock::now(); buf.last_column_build_duration_ns = DURATION_NS(t_reconstruct_start, t_reconstruct_end); buf.last_block_append_duration_ns = DURATION_NS(t_reconstruct_end, t_insert_start); buf.last_insertion_duration_ns = DURATION_NS(t_insert_start, t_insert_end); // Clear all columns and re-reserve (skip buffer-type columns which are rebuilt each time) for (size_t i = 0; i < buf.columns.size(); i++) { if (buf.columns[i]) { // Skip nullptr placeholders for buffer-type columns auto col = std::const_pointer_cast(buf.columns[i]); col->Clear(); col->Reserve(BATCH_SIZE); } } // Reset buffer-type columns back to nullptr for (auto &dbuf_pair : buf.data_buffers) { int field_idx = dbuf_pair.first; int col_idx = field_idx + 1; buf.columns[col_idx] = nullptr; } // Clear all DataBuffers for (auto &pair : buf.data_buffers) { pair.second->clear(); } int rows = buf.row_count; buf.row_count = 0; buf.last_insert_time = std::chrono::steady_clock::now(); // Update statistics buf.total_rows += rows; buf.rows_since_print += rows; return rows; } catch (const std::exception &e) { loge("Failed to insert buffer for event {}: {}", buf.event_name, e.what()); return -1; } } /* Flush all buffers to ClickHouse */ int insert_all_buffers(clickhouse_config_t *ch) { int errors = 0; for (auto &pair : g_event_buffers) { if (insert_buffer(ch, pair.first) <= 0) { errors++; } } return errors > 0 ? -1 : 0; } /* Check if buffer should be inserted based on size or time */ uint8_t should_insert(EventBuffer &buf) { if (buf.row_count == 0) { return 0; } if (buf.row_count >= BATCH_SIZE) { return 1; } if (static_cast(DURATION_MS(buf.last_insert_time, std::chrono::steady_clock::now())) >= INSERT_INTERVAL_MS) { return 2; } if (buf.insert_now) { return 3; } return 0; } int insert_event(clickhouse_config_t *ch, int event_id, const char *event_data, int data_length) { auto t_fn_start = std::chrono::high_resolution_clock::now(); // Get buffer for this event auto it = g_event_buffers.find(event_id); if (it == g_event_buffers.end()) { loge("Buffer not found for event_id {}", event_id); return -1; } EventBuffer &buf = it->second; database_event_format format = buf.format; const char *event_name = buf.event_name.c_str(); auto t_names_done = std::chrono::high_resolution_clock::now(); int16_t frame = -1; int16_t slot = -1; try { const char *data_ptr = event_data; int remaining = data_length; int buf_len = 0; int i; auto t_append_start = std::chrono::high_resolution_clock::now(); // Append to TsSwNs column using cached pointer buf.ts_sw_col->Append(std::chrono::system_clock::now().time_since_epoch().count()); // Process data columns for (i = 0; i < format.count && remaining > 0; i++) { if (strcmp(format.type[i], "int") == 0) { int val = 0; if (remaining >= 4) { memcpy(&val, data_ptr, 4); if (strcmp(format.name[i], "frame") == 0) frame = val; else if (strcmp(format.name[i], "slot") == 0) slot = val; else if (strcmp(format.name[i], "subframe") == 0) slot = val; data_ptr += 4; remaining -= 4; } int typed_col_idx = buf.field_idx_to_typed_col_idx[i]; buf.int_cols[typed_col_idx]->Append(val); } else if (strcmp(format.type[i], "ulong") == 0) { uint64_t val = 0; if (remaining >= 8) { memcpy(&val, data_ptr, 8); data_ptr += 8; remaining -= 8; } int typed_col_idx = buf.field_idx_to_typed_col_idx[i]; buf.ulong_cols[typed_col_idx]->Append(val); } else if (strcmp(format.type[i], "buffer") == 0) { buf_len = 0; const char *buf_data = nullptr; if (remaining >= 4) { memcpy(&buf_len, data_ptr, 4); data_ptr += 4; remaining -= 4; if (buf_len > remaining) buf_len = remaining; if (buf_len > 0) buf_data = data_ptr; data_ptr += buf_len; remaining -= buf_len; } auto it_dbuf = buf.data_buffers.find(i); if (it_dbuf != buf.data_buffers.end()) { size_t offset = it_dbuf->second->append(buf_data, buf_len); buf.insert_now |= it_dbuf->second->insert_now; if (offset == (size_t)-1) { loge("DataBuffer full for field '{}', cannot append {} bytes", format.name[i], buf_len); // Handle dropping tail for other columns and insert } } } else if (strcmp(format.type[i], "string") == 0) { std::string str_val; if (remaining >= 4) { int str_len; memcpy(&str_len, data_ptr, 4); data_ptr += 4; remaining -= 4; if (str_len > remaining) str_len = remaining; if (str_len > 0) str_val = std::string(data_ptr, str_len); data_ptr += str_len; remaining -= str_len; } int typed_col_idx = buf.field_idx_to_typed_col_idx[i]; buf.string_cols[typed_col_idx]->Append(str_val); } else { // Default: treat as int int val = 0; if (remaining >= 4) { memcpy(&val, data_ptr, 4); data_ptr += 4; remaining -= 4; } int typed_col_idx = buf.field_idx_to_typed_col_idx[i]; buf.int_cols[typed_col_idx]->Append(val); } } auto t_append_data_end = std::chrono::high_resolution_clock::now(); // Add TsTxUtcNs column if event has frame/slot if (buf.has_frame_slot) { uint64_t timestamp_ns = std::chrono::system_clock::now().time_since_epoch().count(); uint64_t gps_elapsed_ns; uint64_t transmit_time_in_utc_ns; auto t_time_calc_start = std::chrono::high_resolution_clock::now(); if (frame == -1 || slot == -1) { // nr_ue_decode_BCCH_DL_SCH sets frame and slot to -1 transmit_time_in_utc_ns = timestamp_ns; } else { gps_elapsed_ns = calculate_sfn_slot_gps_time(frame, slot, 1, timestamp_ns); transmit_time_in_utc_ns = gps_to_utc_ns(gps_elapsed_ns); if (0) { int check_frame, check_slot; calculate_sfn_slot_from_unix(transmit_time_in_utc_ns, 1, &check_frame, &check_slot); if (check_frame != frame || check_slot != slot) { loge("ERROR1: sfn/slot check failed: {} {} {} {}", event_name, frame, slot, check_frame, check_slot); } } auto t_time_calc_end = std::chrono::high_resolution_clock::now(); int64_t ref_to_t0_offset_ns = (int64_t)timestamp_ns - (int64_t)transmit_time_in_utc_ns; // Handle sign separately to properly display negative fractional seconds const char *sign = (ref_to_t0_offset_ns < 0) ? "-" : " "; int64_t abs_offset = (ref_to_t0_offset_ns < 0) ? -ref_to_t0_offset_ns : ref_to_t0_offset_ns; int64_t offset_sec = abs_offset / NS_PER_SEC; int64_t offset_ns = abs_offset % NS_PER_SEC; if (abs_offset > 50'000'000) { // 50ms logi("{:<31} {:4d}.{:2d} TsSwNs={}.{:09} TsTxUtcNs={}.{:09} delta={}{}.{:09d}, {}", event_name, frame, slot, timestamp_ns / NS_PER_SEC, timestamp_ns % NS_PER_SEC, transmit_time_in_utc_ns / NS_PER_SEC, transmit_time_in_utc_ns % NS_PER_SEC, sign, offset_sec, offset_ns, DURATION_NS(t_time_calc_start, t_time_calc_end)); } } // Append to TsTxUtcNs column using cached pointer buf.ts_tx_col->Append(transmit_time_in_utc_ns); } auto t_append_ts_end = std::chrono::high_resolution_clock::now(); // Increment row count buf.row_count++; // Check if we should insert this buffer int rows = 0; auto t_insert_start = std::chrono::high_resolution_clock::now(); uint8_t insert = should_insert(buf); auto t_insert_should_insert_end = std::chrono::high_resolution_clock::now(); if (insert) { rows = insert_buffer(ch, event_id); } auto t_insert_end = std::chrono::high_resolution_clock::now(); if (insert) { if (DURATION_MS(t_insert_start, t_insert_end) > 5) { logi("Slow Insert: {:<31} {:4d}.{:2d}: {:3d} {:3d} {:5d} {:4d} {:5d} {:4d} {:8d} (ns) {:3d} (ms) rows:{:3d} reason: {}", event_name, frame, slot, DURATION_NS(t_fn_start, t_names_done), DURATION_NS(t_names_done, t_append_start), DURATION_NS(t_append_start, t_append_data_end), DURATION_NS(t_append_data_end, t_append_ts_end), buf.last_column_build_duration_ns, buf.last_block_append_duration_ns, buf.last_insertion_duration_ns, DURATION_MS(t_insert_start, t_insert_end), rows, insert); } } else if (DURATION_US(t_fn_start, t_insert_end) > 50) { logd("Slow saving data: {:<31} {:4d}.{:2d}: {:3d} {:3d} {:5d} {:4d} {:5d} {:4d} {:8d} (ns) buf_len:{:3d} rows:{:3d} ---", event_name, frame, slot, DURATION_NS(t_fn_start, t_names_done), DURATION_NS(t_names_done, t_append_start), DURATION_NS(t_append_start, t_append_data_end), DURATION_NS(t_append_data_end, t_append_ts_end), DURATION_NS(t_append_ts_end, t_insert_start), DURATION_NS(t_insert_start, t_insert_should_insert_end), DURATION_NS(t_insert_should_insert_end, t_insert_end), buf_len, buf.row_count); } return 0; } catch (const std::exception &e) { loge("Failed to insert event {}: {}", event_name, e.what()); return -1; } } int main(int n, char **v) { const char *default_database_filename = "T_messages.txt"; char *database_filename = NULL; void *database; const char *ip = DEFAULT_REMOTE_IP; int port = DEFAULT_REMOTE_PORT; char **on_off_name; int *on_off_action; int on_off_n = 0; int *is_on; int number_of_events; int i; char mt; int debug_mode = 0; clickhouse_config_t ch_config; ch_config.drop_tables = 0; ch_config.host = DEFAULT_CLICKHOUSE_HOST; ch_config.port = DEFAULT_CLICKHOUSE_PORT; ch_config.database = DEFAULT_CLICKHOUSE_DB; /* write on a socket fails if the other end is closed and we get SIGPIPE */ if (signal(SIGPIPE, SIG_IGN) == SIG_ERR) abort(); on_off_name = (char **)malloc(n * sizeof(char *)); if (on_off_name == NULL) abort(); on_off_action = (int *)malloc(n * sizeof(int)); if (on_off_action == NULL) abort(); for (i = 1; i < n; i++) { if (!strcmp(v[i], "-h") || !strcmp(v[i], "--help")) usage(); if (!strcmp(v[i], "-d")) { if (i > n - 2) usage(); database_filename = v[++i]; continue; } if (!strcmp(v[i], "-ip")) { if (i > n - 2) usage(); ip = v[++i]; continue; } if (!strcmp(v[i], "-p")) { if (i > n - 2) usage(); port = atoi(v[++i]); continue; } if (!strcmp(v[i], "-ch-host")) { if (i > n - 2) usage(); ch_config.host = v[++i]; continue; } if (!strcmp(v[i], "-ch-port")) { if (i > n - 2) usage(); ch_config.port = atoi(v[++i]); continue; } if (!strcmp(v[i], "-ch-db")) { if (i > n - 2) usage(); ch_config.database = v[++i]; continue; } if (!strcmp(v[i], "-ch-user")) { if (i > n - 2) usage(); ch_config.user = v[++i]; continue; } if (!strcmp(v[i], "-ch-pass")) { if (i > n - 2) usage(); ch_config.password = v[++i]; continue; } if (!strcmp(v[i], "-ch-droptables")) { ch_config.drop_tables = 1; continue; } if (!strcmp(v[i], "-debug")) { debug_mode = 1; continue; } if (!strcmp(v[i], "-on")) { if (i > n - 2) usage(); on_off_name[on_off_n] = v[++i]; on_off_action[on_off_n++] = 1; logi("on: item: {}, on_off_name: {}, on_off_action: {}", v[i], on_off_name[on_off_n - 1], on_off_action[on_off_n - 1]); continue; } if (!strcmp(v[i], "-off")) { if (i > n - 2) usage(); on_off_name[on_off_n] = v[++i]; on_off_action[on_off_n++] = 0; continue; } if (!strcmp(v[i], "-ON")) { on_off_name[on_off_n] = NULL; on_off_action[on_off_n++] = 1; continue; } if (!strcmp(v[i], "-OFF")) { on_off_name[on_off_n] = NULL; on_off_action[on_off_n++] = 0; continue; } usage(); } if (database_filename == NULL) { logi("No database file provided, using default: {}", default_database_filename); database_filename = strdup(default_database_filename); } database = parse_database(database_filename); load_config_file(database_filename); number_of_events = number_of_ids(database); logi("Number of events: {}", number_of_events); is_on = (int *)calloc(number_of_events, sizeof(int)); if (is_on == NULL) { loge("aborting"); abort(); } for (i = 0; i < on_off_n; i++) { on_off(database, on_off_name[i], is_on, on_off_action[i]); } /* Initialize fmtlog for benchmarking */ fmtlog::setLogLevel(debug_mode ? fmtlog::DBG : fmtlog::INF); fmtlog::setThreadName("main"); /* Initialize ClickHouse */ if (clickhouse_init(&ch_config) != 0) { loge("Failed to initialize ClickHouse connection"); exit(1); } /* Create tables for enabled events */ int longest_table_name = create_tables(&ch_config, database, is_on, number_of_events); if (longest_table_name < 0) { loge("Failed to create tables"); exit(1); } socket_fd = connect_to(const_cast(ip), port); /* activate selected traces */ mt = 1; if (socket_send(socket_fd, &mt, 1) == -1 || socket_send(socket_fd, &number_of_events, sizeof(int)) == -1 || socket_send(socket_fd, is_on, number_of_events * sizeof(int)) == -1) abort(); /* exit on ctrl+c and ctrl+z */ if (signal(SIGQUIT, force_stop) == SIG_ERR) abort(); if (signal(SIGINT, force_stop) == SIG_ERR) abort(); if (signal(SIGTSTP, force_stop) == SIG_ERR) abort(); OBUF ebuf = {.osize = 0, .omaxsize = 0, .obuf = NULL}; /* read messages */ logi("Tables created, waiting for messages..."); int poll_count = 0; auto last_periodic_insert = std::chrono::steady_clock::now(); auto last_stats_print = std::chrono::steady_clock::now(); const uint64_t STATS_PRINT_INTERVAL_MS = 5000; // Print stats every 5 seconds while (run) { int type; int32_t length; char *v; int vpos = 0; // Poll fmtlog periodically to insert buffered logs if (++poll_count % 10 == 0) { fmtlog::poll(); } // Periodic insert check (every 10 messages) if (poll_count % 10 == 0) { auto now = std::chrono::steady_clock::now(); auto elapsed_ms = static_cast(std::chrono::duration_cast(now - last_periodic_insert).count()); if (elapsed_ms >= INSERT_INTERVAL_MS) { for (auto &pair : g_event_buffers) { if (should_insert(pair.second)) { insert_buffer(&ch_config, pair.first); } } last_periodic_insert = now; } if (static_cast(DURATION_MS(last_stats_print, now)) >= STATS_PRINT_INTERVAL_MS) { for (auto &pair : g_event_buffers) { EventBuffer &buf = pair.second; if (buf.rows_since_print > 0) logi(" {:<31} rows: {:8d} total: {:10d}", buf.event_name, buf.rows_since_print, buf.total_rows); buf.rows_since_print = 0; } last_stats_print = now; logi(""); } } if (fullread(socket_fd, &length, 4) == -1) goto read_error; if (ebuf.omaxsize < length + 4) { ebuf.omaxsize = (length + 4 + 65535) & ~65535; ebuf.obuf = (char *)realloc(ebuf.obuf, ebuf.omaxsize); if (ebuf.obuf == NULL) { loge("out of memory"); exit(1); } } v = ebuf.obuf; memcpy(v + vpos, &length, 4); vpos += 4; #ifdef T_SEND_TIME if (length < (int32_t)sizeof(struct timespec)) goto read_error; if (fullread(socket_fd, v + vpos, sizeof(struct timespec)) == -1) goto read_error; // memcpy(v+vpos, &ts, sizeof(struct timespec)); vpos += sizeof(struct timespec); length -= sizeof(struct timespec); #endif if (length < (int32_t)sizeof(int)) goto read_error; if (fullread(socket_fd, &type, sizeof(int)) == -1) goto read_error; memcpy(v + vpos, &type, sizeof(int)); vpos += sizeof(int); length -= sizeof(int); if (fullread(socket_fd, v + vpos, length) == -1) goto read_error; if (type == -1) { append_received_config_chunk(v + vpos, length); } else if (type == -2) { verify_config(); } else if (type >= 0 && type < number_of_events && is_on[type]) { if (insert_event(&ch_config, type, v + vpos, length) != 0) { loge("Failed to insert event type {}", type); } } } read_error: // Flush all remaining buffers before exit logi("Inserting all buffers before exit..."); insert_all_buffers(&ch_config); // Print final statistics size_t total_rows = 0; for (const auto& pair : g_event_buffers) { total_rows += pair.second.row_count; } logi("Final buffer state: {} events with {} uninserted rows", g_event_buffers.size(), total_rows); // Client cleanup is automatic via std::unique_ptr logi("Exiting..."); // Flush and close fmtlog fmtlog::poll(); fmtlog::closeLogFile(); return 0; }