pcloudcc-lneely/pclsync/pdbg.c

#include <pthread.h>
#include <signal.h>
#include <stdarg.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <strings.h>
#include <time.h>
#include <fcntl.h>
#include <unistd.h>

#include "pdbg.h"
#include "pmem.h"
#include "ppath.h"
#include "putil.h"

extern PSYNC_THREAD const char *psync_thread_name;

static FILE *log_file = NULL;
static FILE *fs_event_log = NULL;
static int fs_event_log_initialized = 0;
static pthread_mutex_t log_mutex = PTHREAD_MUTEX_INITIALIZER;
static volatile sig_atomic_t log_reopen_requested = 0;

/* Runtime debug level - defaults to D_INFO */
unsigned int pdbg_runtime_level = D_INFO;
static int pdbg_level_initialized = 0;

/* Forward declaration */
static void do_reopen_log(void);

/* Initialize debug level from environment variable */
static void pdbg_init_level(void) {
    if (pdbg_level_initialized)
        return;

    pdbg_level_initialized = 1;

    const char *level_str = getenv("PCLOUD_LOG_LEVEL");
    if (!level_str || level_str[0] == '\0') {
        __atomic_store_n(&pdbg_runtime_level, D_INFO, __ATOMIC_RELAXED);
        return;
    }

    unsigned int level;
    /* Parse log level string (case-insensitive) */
    if (strcasecmp(level_str, "NONE") == 0) {
        level = D_NONE;
    } else if (strcasecmp(level_str, "BUG") == 0 || strcasecmp(level_str, "DEBUG") == 0) {
        level = D_BUG;
    } else if (strcasecmp(level_str, "CRITICAL") == 0) {
        level = D_CRITICAL;
    } else if (strcasecmp(level_str, "ERROR") == 0) {
        level = D_ERROR;
    } else if (strcasecmp(level_str, "WARNING") == 0 || strcasecmp(level_str, "WARN") == 0) {
        level = D_WARNING;
    } else if (strcasecmp(level_str, "INFO") == 0) {
        level = D_INFO;
    } else if (strcasecmp(level_str, "NOTICE") == 0) {
        level = D_NOTICE;
    } else {
        /* Invalid level, default to INFO */
        level = D_INFO;
    }
    __atomic_store_n(&pdbg_runtime_level, level, __ATOMIC_RELAXED);
}

/* Returns 1 if path is safe to use as a log file, 0 otherwise.
 * Safe means: absolute, no '..' components, and under HOME or /tmp. */
static int pdbg_path_is_safe(const char *path) {
    const char *home;
    const char *p;

    /* Must be an absolute path */
    if (!path || path[0] != '/')
        return 0;

    /* Reject any '..' path component to prevent directory traversal */
    p = path;
    while (*p) {
        while (*p == '/') p++;
        if (p[0] == '.' && p[1] == '.' && (p[2] == '/' || p[2] == '\0'))
            return 0;
        while (*p && *p != '/') p++;
    }

    /* Must resolve within the user home directory */
    home = getenv("HOME");
    if (home && home[0] == '/') {
        size_t hlen = strlen(home);
        if (strncmp(path, home, hlen) == 0 &&
            (path[hlen] == '/' || path[hlen] == '\0'))
            return 1;
    }

    /* Or within /tmp */
    if (strncmp(path, "/tmp/", 5) == 0)
        return 1;

    return 0;
}

char *psync_debug_path() {
    const char *custom_path = getenv("PCLOUD_LOG_PATH");
    if (custom_path && custom_path[0] != '\0') {
        if (!pdbg_path_is_safe(custom_path)) {
            /* Invalid path: reject and fall through to default */
            fprintf(stderr,
                    "pdbg: PCLOUD_LOG_PATH '%s' rejected"
                    " (must be absolute, under HOME or /tmp, no '..' components);"
                    " using default log path\n",
                    custom_path);
        } else {
            size_t len = strlen(custom_path) + 1;
            char *path = (char *)pmem_malloc(PMEM_SUBSYS_OTHER, len);
            if (!path) {
                return NULL;
            }
            snprintf(path, len, "%s", custom_path);
            return path;
        }
    }

    char *home = ppath_home();
    if (!home) {
        return NULL;
    }

    const char *subdir = "/.pcloud/debug.log";
    size_t len = strlen(home) + strlen(subdir) + 1;
    char *sockpath = (char *)pmem_malloc(PMEM_SUBSYS_OTHER, len);
    if (!sockpath) {
        pmem_free(PMEM_SUBSYS_OTHER, home);
        return NULL;
    }

    snprintf(sockpath, len, "%s%s", home, subdir);
    pmem_free(PMEM_SUBSYS_OTHER, home);
    return sockpath;
}

char *pfs_event_log_path() {
    const char *custom_path = getenv("PCLOUD_FS_EVENT_LOG");
    if (custom_path && custom_path[0] != '\0') {
        size_t len = strlen(custom_path) + 1;
        char *path = (char *)pmem_malloc(PMEM_SUBSYS_OTHER, len);
        if (!path) {
            return NULL;
        }
        snprintf(path, len, "%s", custom_path);
        return path;
    }
    return NULL;
}

int pdbg_printf(const char *file, const char *function, int unsigned line, int unsigned level, const char *fmt, ...) {
  /* Recursion guard */
  static __thread int in_pdbg_printf = 0;
  if (in_pdbg_printf)
    return 1;
  in_pdbg_printf = 1;

  /* Initialize debug level from environment on first call */
  pdbg_init_level();

  if (!IS_DEBUG) {
    in_pdbg_printf = 0;
    return 1;
  }

  static const struct {
    unsigned long level;
    const char *name;
  } debug_levels[] = DEBUG_LEVELS;
  struct timespec ts;
  char dttime[36], format[512];
  va_list ap;
  const char *errname;
  unsigned long i;
  unsigned int u;
  pthread_t threadid;
  errname = "BAD_ERROR_CODE";
  for (i = 0; i < ARRAY_SIZE(debug_levels); i++)
    if (debug_levels[i].level == level) {
      errname = debug_levels[i].name;
      break;
    }

  pthread_mutex_lock(&log_mutex);

  /* Check if log rotation was requested via signal */
  if (unlikely(log_reopen_requested)) {
    log_reopen_requested = 0;
    do_reopen_log();
  }

  if (unlikely(!log_file)) {
    char *path = psync_debug_path();
    int fd = open(path, O_WRONLY | O_CREAT | O_APPEND, 0600);
    if (fd == -1) {
      pmem_free(PMEM_SUBSYS_OTHER, path);
      pthread_mutex_unlock(&log_mutex);
      return 1;
    }
    log_file = fdopen(fd, "a");
    pmem_free(PMEM_SUBSYS_OTHER, path);
    if (!log_file) {
      close(fd);
      pthread_mutex_unlock(&log_mutex);
      return 1;
    }
  }

  /* Create empty fs event log file on first call if configured */
  if (unlikely(!fs_event_log_initialized)) {
    fs_event_log_initialized = 1;
    char *path = pfs_event_log_path();
    if (path) {
      /* Create empty file if it doesn't exist, or open existing */
      int fd = open(path, O_WRONLY | O_CREAT | O_APPEND, 0600);
      if (fd != -1) {
        close(fd);
      }
      pmem_free(PMEM_SUBSYS_OTHER, path);
    }
  }

  clock_gettime(CLOCK_REALTIME, &ts);
  putil_time_format(ts.tv_sec, ts.tv_nsec, dttime);
  threadid = pthread_self();
  memcpy(&u, &threadid, sizeof(u));
  snprintf(format, sizeof(format), "%s %u %s %s: %s:%u (function %s): %s\n",
           dttime, u, psync_thread_name, errname, file, line, function, fmt);
  format[sizeof(format) - 1] = 0;
  va_start(ap, fmt);
  vfprintf(log_file, format, ap);
  va_end(ap);
  fflush(log_file);
  pthread_mutex_unlock(&log_mutex);
  in_pdbg_printf = 0;
  return 1;
}

/* Called from signal handler - must be signal-safe (no malloc/file ops) */
void pdbg_reopen_log() {
  log_reopen_requested = 1;
}

/* Internal function to actually reopen the log - called from safe context */
static void do_reopen_log() {
  char *path;
  FILE *new_log;
  int fd;

  /* Close existing log file if open */
  if (log_file) {
    fclose(log_file);
    log_file = NULL;
  }

  /* Open new log file */
  path = psync_debug_path();
  if (path) {
    fd = open(path, O_WRONLY | O_CREAT | O_APPEND, 0600);
    pmem_free(PMEM_SUBSYS_OTHER, path);
    if (fd != -1) {
      new_log = fdopen(fd, "a");
      if (new_log) {
        log_file = new_log;
        /* Log a message about the rotation */
        fprintf(log_file, "Log file reopened for rotation\n");
        fflush(log_file);
      } else {
        close(fd);
      }
    }
  }

  /* Also reopen fs event log if it was open */
  if (fs_event_log) {
    fclose(fs_event_log);
    fs_event_log = NULL;

    path = pfs_event_log_path();
    if (path) {
      fd = open(path, O_WRONLY | O_CREAT | O_APPEND, 0600);
      pmem_free(PMEM_SUBSYS_OTHER, path);
      if (fd != -1) {
        new_log = fdopen(fd, "a");
        if (new_log) {
          fs_event_log = new_log;
        } else {
          close(fd);
        }
      }
    }
  }
}

/* Write a filesystem event to the fs-event log with timestamp */
void pdbg_write_fs_event(const char *fmt, ...) {
  struct timespec ts;
  char dttime[36];
  va_list ap;

  pthread_mutex_lock(&log_mutex);

  /* Check if log rotation was requested */
  if (unlikely(log_reopen_requested)) {
    log_reopen_requested = 0;
    do_reopen_log();
  }

  /* Open fs event log if not already open */
  if (unlikely(!fs_event_log)) {
    char *path = pfs_event_log_path();
    if (!path) {
      /* FS event log not configured, skip */
      pthread_mutex_unlock(&log_mutex);
      return;
    }
    int fd = open(path, O_WRONLY | O_CREAT | O_APPEND, 0600);
    pmem_free(PMEM_SUBSYS_OTHER, path);
    if (fd == -1) {
      pthread_mutex_unlock(&log_mutex);
      return;
    }
    fs_event_log = fdopen(fd, "a");
    if (!fs_event_log) {
      close(fd);
      pthread_mutex_unlock(&log_mutex);
      return;
    }
  }

  /* Get timestamp */
  clock_gettime(CLOCK_REALTIME, &ts);
  putil_time_format(ts.tv_sec, ts.tv_nsec, dttime);

  /* Write timestamp followed by event message */
  fprintf(fs_event_log, "%s ", dttime);
  va_start(ap, fmt);
  vfprintf(fs_event_log, fmt, ap);
  va_end(ap);
  fprintf(fs_event_log, "\n");
  fflush(fs_event_log);

  pthread_mutex_unlock(&log_mutex);
}