stats.c

Go to the documentation of this file.

 
#include <stdatomic.h>
#include <stdio.h>
#include <string.h>
#include <time.h>
#include "main.h"
#include "stats.h"
#include "client.h"
#include "render.h"
#include <ascii-chat/common.h>
#include <ascii-chat/common/buffer_sizes.h>
#include <ascii-chat/buffer_pool.h>
#include <ascii-chat/network/packet_queue.h>
#include <ascii-chat/debug/lock.h>
#include <ascii-chat/platform/init.h>
 
server_stats_t g_stats = {0};
 
mutex_t g_stats_mutex = {0};
 
static bool g_stats_mutex_initialized = false;
// Mutex to protect the initialization check (TOCTOU race prevention)
static static_mutex_t g_stats_init_check_mutex = STATIC_MUTEX_INIT;
 
int stats_init(void) {
  int ret = mutex_init(&g_stats_mutex);
  if (ret == 0) {
    g_stats_mutex_initialized = true;
  }
  return ret;
}
 
void stats_cleanup(void) {
  static_mutex_lock(&g_stats_init_check_mutex);
  if (g_stats_mutex_initialized) {
    g_stats_mutex_initialized = false; // Clear flag before destroying mutex
    static_mutex_unlock(&g_stats_init_check_mutex);
    mutex_destroy(&g_stats_mutex);
  } else {
    static_mutex_unlock(&g_stats_init_check_mutex);
  }
}
 
/* ============================================================================
 * Statistics Collection and Reporting Thread
 * ============================================================================
 */
 
void *stats_logger_thread(void *arg) {
  (void)arg;
 
  while (!atomic_load(&g_server_should_exit)) {
    // Log buffer pool statistics every 10 seconds with fast exit checking (10ms intervals)
    for (int i = 0; i < 1000 && !atomic_load(&g_server_should_exit); i++) {
      platform_sleep_us(10 * US_PER_MS_INT); // 10ms sleep
    }
 
    // Check exit condition before proceeding with statistics logging
    // Check multiple times to avoid accessing freed resources during shutdown.
    if (atomic_load(&g_server_should_exit)) {
      break;
    }
 
    // Collect all statistics data first
#ifndef NDEBUG
    char lock_debug_info[BUFFER_SIZE_MEDIUM] = {0};
    // Check exit condition again before accessing lock_debug.
    // lock_debug might be destroyed during shutdown
    if (!atomic_load(&g_server_should_exit) && lock_debug_is_initialized()) {
      uint64_t total_acquired = 0, total_released = 0;
      uint32_t currently_held = 0;
      lock_debug_get_stats(&total_acquired, &total_released, &currently_held);
 
      safe_snprintf(lock_debug_info, sizeof(lock_debug_info),
                    "Historical Mutex/RWLock Statistics:\n"
                    "  Total locks acquired: %llu\n"
                    "  Total locks released: %llu\n"
                    "  Currently held: %u\n"
                    "  Net locks (acquired - released): %lld",
                    (unsigned long long)total_acquired, (unsigned long long)total_released, currently_held,
                    (long long)total_acquired - (long long)total_released);
    }
#endif
 
    // Collect client statistics
    // Check exit condition again before accessing rwlock.
    // rwlock might be destroyed during shutdown.
    if (atomic_load(&g_server_should_exit)) {
      break;
    }
 
    rwlock_rdlock(&g_client_manager_rwlock);
    int active_clients = 0;
    int clients_with_audio = 0;
    int clients_with_video = 0;
    char client_details[BUFFER_SIZE_XLARGE] = {0};
    int client_details_len = 0;
 
    for (int i = 0; i < MAX_CLIENTS; i++) {
      if (atomic_load(&g_client_manager.clients[i].active)) {
        active_clients++;
        if (g_client_manager.clients[i].audio_queue) {
          clients_with_audio++;
        }
        if (g_client_manager.clients[i].outgoing_video_buffer) {
          clients_with_video++;
        }
      }
    }
 
    // Collect per-client details
    for (int i = 0; i < MAX_CLIENTS; i++) {
      client_info_t *client = &g_client_manager.clients[i];
      bool is_active = atomic_load(&client->active);
      uint32_t client_id_snapshot = atomic_load(&client->client_id);
 
      if (is_active && client_id_snapshot != 0) {
        // Check audio queue stats
        if (client->audio_queue) {
          uint64_t enqueued, dequeued, dropped;
          packet_queue_get_stats(client->audio_queue, &enqueued, &dequeued, &dropped);
          if (enqueued > 0 || dequeued > 0 || dropped > 0) {
            int len =
                safe_snprintf(client_details + client_details_len, sizeof(client_details) - client_details_len,
                              "  Client %u audio queue: %llu enqueued, %llu dequeued, %llu dropped", client_id_snapshot,
                              (unsigned long long)enqueued, (unsigned long long)dequeued, (unsigned long long)dropped);
            if (len > 0 && client_details_len + len < (int)sizeof(client_details)) {
              client_details_len += len;
            }
          }
        }
        // Check video buffer stats
        if (client->outgoing_video_buffer) {
          video_frame_stats_t stats;
          video_frame_get_stats(client->outgoing_video_buffer, &stats);
          if (stats.total_frames > 0) {
            int len = safe_snprintf(client_details + client_details_len, sizeof(client_details) - client_details_len,
                                    "  Client %u video buffer: %llu frames, %llu dropped (%.1f%% drop rate)",
                                    client_id_snapshot, (unsigned long long)stats.total_frames,
                                    (unsigned long long)stats.dropped_frames, stats.drop_rate * 100.0f);
            if (len > 0 && client_details_len + len < (int)sizeof(client_details)) {
              client_details_len += len;
            }
          }
        }
      }
    }
    rwlock_rdunlock(&g_client_manager_rwlock);
 
    // Single comprehensive log statement
    if (client_details_len > 0) {
      log_info("Stats: Clients: %d, Audio: %d, Video: %d\n%s", active_clients, clients_with_audio, clients_with_video,
               client_details);
    }
  }
 
  log_server_stats();
 
  asciichat_error_stats_print();
 
  // Clean up thread-local error context before exit
  asciichat_errno_destroy();
 
  return NULL;
}
 
void update_server_stats(void) {
  // Aggregate statistics from all active clients
  uint64_t total_frames_sent = 0;
  uint64_t total_frames_dropped = 0;
 
  // Read-lock to safely iterate over all clients
  rwlock_rdlock(&g_client_manager_rwlock);
 
  for (int i = 0; i < MAX_CLIENTS; i++) {
    client_info_t *client = &g_client_manager.clients[i];
    if (atomic_load(&client->client_id) != 0 && atomic_load(&client->active)) {
      // Aggregate frames sent to all clients
      total_frames_sent += client->frames_sent;
 
      // Get dropped frame statistics from outgoing video buffer
      if (client->outgoing_video_buffer) {
        video_frame_stats_t stats;
        video_frame_get_stats(client->outgoing_video_buffer, &stats);
        total_frames_dropped += stats.dropped_frames;
      }
    }
  }
 
  rwlock_rdunlock(&g_client_manager_rwlock);
 
  // Update global statistics atomically
  mutex_lock(&g_stats_mutex);
  g_stats.frames_sent = total_frames_sent;
  g_stats.frames_dropped = total_frames_dropped;
 
  // Calculate frames_captured from frames_sent and frames_dropped
  // frames_captured = frames_sent + frames_dropped (total output frames)
  if (total_frames_sent > 0 || total_frames_dropped > 0) {
    g_stats.frames_captured = total_frames_sent + total_frames_dropped;
  }
 
  mutex_unlock(&g_stats_mutex);
}
 
void log_server_stats(void) {
  // Use static_mutex to protect initialization check (TOCTOU race prevention)
  // In debug builds, stats_init() may not be called (it's guarded by #ifdef NDEBUG)
  // Use lock to prevent cleanup from destroying mutex while we're about to lock it
  static_mutex_lock(&g_stats_init_check_mutex);
  if (!g_stats_mutex_initialized) {
    static_mutex_unlock(&g_stats_init_check_mutex);
    return; // Mutex not initialized, skip logging
  }
  static_mutex_unlock(&g_stats_init_check_mutex);
 
  // Now safe to use the mutex (it was initialized and not being cleaned up)
  mutex_lock(&g_stats_mutex);
  log_info("Server Statistics:\n"
           "  frames_captured=%llu\n"
           "  frames_sent=%llu\n"
           "  frames_dropped=%llu\n"
           "  Average FPS: capture=%.2f, send=%.2f",
           (unsigned long long)g_stats.frames_captured, (unsigned long long)g_stats.frames_sent,
           (unsigned long long)g_stats.frames_dropped, g_stats.avg_capture_fps, g_stats.avg_send_fps);
  mutex_unlock(&g_stats_mutex);
}