LCOV - code coverage report
Current view: top level - util/log - fd_log.c (source / functions) Hit Total Coverage
Test: cov.lcov Lines: 629 821 76.6 %
Date: 2025-07-05 04:47:39 Functions: 58 66 87.9 %

          Line data    Source code
       1             : #ifndef FD_LOG_STYLE
       2             : #if FD_HAS_HOSTED
       3             : #define FD_LOG_STYLE 0
       4             : #else
       5             : #error "Define FD_LOG_STYLE for this platform"
       6             : #endif
       7             : #endif
       8             : 
       9             : #if FD_LOG_STYLE==0 /* POSIX style */
      10             : 
      11             : #ifndef FD_HAS_BACKTRACE
      12             : #if __has_include( <execinfo.h> )
      13             : #define FD_HAS_BACKTRACE 1
      14             : #else
      15             : #define FD_HAS_BACKTRACE 0
      16             : #endif
      17             : #endif
      18             : 
      19             : /* FIXME: SANITIZE VARIOUS USER SET STRINGS */
      20             : 
      21             : #define _GNU_SOURCE
      22             : 
      23             : #include "fd_log.h"
      24             : 
      25             : #include <stdio.h>
      26             : #include <stdlib.h>
      27             : #include <stdarg.h>
      28             : #include <ctype.h>
      29             : #include <errno.h>
      30             : #include <fcntl.h>
      31             : #include <unistd.h>
      32             : #include <signal.h>
      33             : #include <sched.h>
      34             : #include <time.h>
      35             : #if defined(__linux__)
      36             : #include <syscall.h>
      37             : #endif
      38             : #include <sys/mman.h>
      39             : 
      40             : #if FD_HAS_BACKTRACE
      41             : #include <execinfo.h>
      42             : #endif
      43             : 
      44             : #if defined(__FreeBSD__)
      45             : #include <sys/stat.h> /* S_IRUSR */
      46             : #endif /* defined(__FreeBSD__) */
      47             : 
      48             : #include "../tile/fd_tile_private.h"
      49             : 
      50             : #ifdef __has_include
      51             : #if __has_include("../../app/fdctl/version.h")
      52             : #include "../../app/fdctl/version.h"
      53             : #endif
      54             : #endif
      55             : 
      56             : #ifndef FDCTL_MAJOR_VERSION
      57             : #define FDCTL_MAJOR_VERSION 0
      58             : #endif
      59             : #ifndef FDCTL_MINOR_VERSION
      60             : #define FDCTL_MINOR_VERSION 0
      61             : #endif
      62             : #ifndef FDCTL_PATCH_VERSION
      63             : #define FDCTL_PATCH_VERSION 0
      64             : #endif
      65             : 
      66             : #ifdef FD_BUILD_INFO
      67             : FD_IMPORT_CSTR( fd_log_build_info, FD_BUILD_INFO );
      68             : #else
      69             : char const  fd_log_build_info[1] __attribute__((aligned(1))) = { '\0' };
      70             : ulong const fd_log_build_info_sz                             = 1UL;
      71             : #endif
      72             : 
      73             : /* TEXT_* are quick-and-dirty color terminal hacks.  Probably should
      74             :    do something more robust longer term. */
      75             : 
      76       79576 : #define TEXT_NORMAL    "\033[0m"
      77             : #define TEXT_BOLD      "\033[1m"
      78             : #define TEXT_UNDERLINE "\033[4m"
      79             : #define TEXT_BLINK     "\033[5m"
      80             : 
      81        9947 : #define TEXT_BLUE      "\033[34m"
      82        9947 : #define TEXT_GREEN     "\033[32m"
      83        9947 : #define TEXT_YELLOW    "\033[93m"
      84       39788 : #define TEXT_RED       "\033[31m"
      85             : 
      86             : /* APPLICATION LOGICAL ID APIS ****************************************/
      87             : 
      88             : /* App id */
      89             : 
      90             : static ulong fd_log_private_app_id; /* 0 outside boot/halt, init on boot */
      91             : 
      92        2394 : void fd_log_private_app_id_set( ulong app_id ) { fd_log_private_app_id = app_id; }
      93             : 
      94    18004860 : ulong fd_log_app_id( void ) { return fd_log_private_app_id; }
      95             : 
      96             : /* App */
      97             : 
      98             : static char fd_log_private_app[ FD_LOG_NAME_MAX ]; /* "" outside boot/halt, init on boot */
      99             : 
     100             : void
     101        2394 : fd_log_private_app_set( char const * app ) {
     102        2394 :   if( FD_UNLIKELY( !app ) ) app = "[app]";
     103        2394 :   if( FD_LIKELY( app!=fd_log_private_app ) )
     104        2394 :     fd_cstr_fini( fd_cstr_append_cstr_safe( fd_cstr_init( fd_log_private_app ), app, FD_LOG_NAME_MAX-1UL ) );
     105        2394 : }
     106             : 
     107       97605 : char const * fd_log_app( void ) { return fd_log_private_app; }
     108             : 
     109             : /* Thread ID */
     110             : 
     111             : #if FD_HAS_THREADS
     112             : static ulong fd_log_private_thread_id_ctr; /* 0 outside boot/halt, init on boot */
     113             : 
     114             : static ulong
     115        2430 : fd_log_private_thread_id_next( void ) {
     116        2430 :   return FD_ATOMIC_FETCH_AND_ADD( &fd_log_private_thread_id_ctr, 1UL );
     117        2430 : }
     118             : #endif
     119             : 
     120             : static FD_TL ulong fd_log_private_thread_id;      /* 0 at thread start */
     121             : static FD_TL int   fd_log_private_thread_id_init; /* 0 at thread start */
     122             : 
     123             : void
     124        2430 : fd_log_private_thread_id_set( ulong thread_id ) {
     125        2430 :   fd_log_private_thread_id      = thread_id;
     126        2430 :   fd_log_private_thread_id_init = 1;
     127        2430 : }
     128             : 
     129             : ulong
     130    36926193 : fd_log_thread_id( void ) {
     131    36926193 : # if FD_HAS_THREADS
     132    36926193 :   if( FD_UNLIKELY( !fd_log_private_thread_id_init ) ) fd_log_private_thread_id_set( fd_log_private_thread_id_next() );
     133             : # else
     134             :   FD_COMPILER_MFENCE(); /* Work around FD_FN_CONST */
     135             : # endif
     136    36926193 :   return fd_log_private_thread_id;
     137    36926193 : }
     138             : 
     139             : /* Thread */
     140             : 
     141             : /* Initialize name to a reasonable default thread description (FIXME:
     142             :    WEEN THIS OFF STDLIB) */
     143             : 
     144             : static void
     145        2439 : fd_log_private_thread_default( char * name ) { /* FD_LOG_NAME_MAX bytes */
     146        2439 :   sprintf( name, "%lu", fd_log_thread_id() );
     147        2439 : }
     148             : 
     149             : static FD_TL char fd_log_private_thread[ FD_LOG_NAME_MAX ]; /* "" at thread start */
     150             : static FD_TL int  fd_log_private_thread_init;               /* 0 at thread start */
     151             : 
     152             : void
     153        2439 : fd_log_thread_set( char const * thread ) {
     154        2439 :   if( FD_UNLIKELY( !thread ) || FD_UNLIKELY( thread[0]=='\0') ) {
     155        2439 :     fd_log_private_thread_default( fd_log_private_thread );
     156        2439 :     fd_log_private_thread_init = 1;
     157        2439 :   } else if( FD_LIKELY( thread!=fd_log_private_thread ) ) {
     158           0 :     fd_cstr_fini( fd_cstr_append_cstr_safe( fd_cstr_init( fd_log_private_thread ), thread, FD_LOG_NAME_MAX-1UL ) );
     159           0 :     fd_log_private_thread_init = 1;
     160           0 :   }
     161        2439 : }
     162             : 
     163             : char const *
     164     1258892 : fd_log_thread( void ) {
     165     1258892 :   if( FD_UNLIKELY( !fd_log_private_thread_init ) ) fd_log_thread_set( NULL );
     166     1258892 :   return fd_log_private_thread;
     167     1258892 : }
     168             : 
     169             : /* APPLICATION PHYSICAL ID APIS ***************************************/
     170             : 
     171             : /* Host ID */
     172             : 
     173             : static ulong fd_log_private_host_id; /* 0 outside boot/halt, initialized on boot */
     174             : 
     175        2394 : void fd_log_private_host_id_set( ulong host_id ) { fd_log_private_host_id = host_id; }
     176             : 
     177        4824 : ulong fd_log_host_id( void ) { return fd_log_private_host_id; }
     178             : 
     179             : /* Host */
     180             : 
     181             : static char  fd_log_private_host[ FD_LOG_NAME_MAX ]; /* "" outside boot/halt, initialized on boot */
     182             : 
     183       97605 : char const * fd_log_host( void ) { return fd_log_private_host; }
     184             : 
     185             : void
     186        2394 : fd_log_private_host_set( char const * host ) {
     187        2394 :   if( FD_UNLIKELY( !host ) || FD_UNLIKELY( host[0]=='\0') ) host = "[host]";
     188        2394 :   if( FD_LIKELY( host!=fd_log_private_host ) )
     189        2394 :     fd_cstr_fini( fd_cstr_append_cstr_safe( fd_cstr_init( fd_log_private_host ), host, FD_LOG_NAME_MAX-1UL ) );
     190        2394 : }
     191             : 
     192             : /* CPU ID */
     193             : 
     194             : /* First CPU scheduled to run on or ULONG_MAX on failure */
     195             : 
     196             : ulong
     197        2394 : fd_log_private_cpu_id_default( void ) {
     198        2394 :   FD_CPUSET_DECL( cpu_set );
     199        2394 :   if( FD_UNLIKELY( fd_cpuset_getaffinity( (pid_t)0, cpu_set ) ) ) return ULONG_MAX;
     200        2394 :   ulong idx = fd_cpuset_first( cpu_set );
     201        2394 :         idx = fd_ulong_if( idx<FD_TILE_MAX, idx, ULONG_MAX );
     202        2394 :   return idx;
     203        2394 : }
     204             : 
     205             : static FD_TL ulong fd_log_private_cpu_id;      /* 0 at thread start */
     206             : static FD_TL int   fd_log_private_cpu_id_init; /* 0 at thread start */
     207             : 
     208             : void
     209        2403 : fd_log_private_cpu_id_set( ulong cpu_id ) {
     210        2403 :   fd_log_private_cpu_id      = cpu_id;
     211        2403 :   fd_log_private_cpu_id_init = 1;
     212        2403 : }
     213             : 
     214             : ulong
     215    18921336 : fd_log_cpu_id( void ) {
     216    18921336 :   if( FD_UNLIKELY( !fd_log_private_cpu_id_init ) ) fd_log_private_cpu_id_set( fd_log_private_cpu_id_default() );
     217    18921336 :   return fd_log_private_cpu_id;
     218    18921336 : }
     219             : 
     220             : /* CPU */
     221             : 
     222             : /* Initialize name to a reasonable default CPU description (FIXME: WEEN
     223             :    THIS OFF STDLIB) */
     224             : 
     225             : static void
     226        2439 : fd_log_private_cpu_default( char * name ) { /* FD_LOG_NAME_MAX bytes */
     227        2439 :   FD_CPUSET_DECL( set );
     228             : 
     229        2439 :   int err = fd_cpuset_getaffinity( (pid_t)0, set );
     230        2439 :   if( FD_UNLIKELY( err ) ) { sprintf( name, "e%i", err ); return; }
     231             : 
     232        2439 :   ulong cnt = fd_cpuset_cnt( set );
     233        2439 :   if( FD_UNLIKELY( !((0UL<cnt) & (cnt<=FD_TILE_MAX)) ) ) { sprintf( name, "ec" ); return; }
     234             : 
     235        2439 :   ulong idx = fd_cpuset_first( set );
     236        2439 :   sprintf( name, (cnt>1) ? "f%lu" : "%lu", idx );
     237        2439 : }
     238             : 
     239             : static FD_TL char fd_log_private_cpu[ FD_LOG_NAME_MAX ]; /* "" at thread start */
     240             : static FD_TL int  fd_log_private_cpu_init;               /* 0  at thread start */
     241             : 
     242             : void
     243        2439 : fd_log_cpu_set( char const * cpu ) {
     244        2439 :   if( FD_UNLIKELY( !cpu ) || FD_UNLIKELY( cpu[0]=='\0') ) {
     245        2439 :     fd_log_private_cpu_default( fd_log_private_cpu );
     246        2439 :     fd_log_private_cpu_init = 1;
     247        2439 :   } else if( FD_LIKELY( cpu!=fd_log_private_cpu ) ) {
     248           0 :     fd_cstr_fini( fd_cstr_append_cstr_safe( fd_cstr_init( fd_log_private_cpu ), cpu, FD_LOG_NAME_MAX-1UL ) );
     249           0 :     fd_log_private_cpu_init = 1;
     250           0 :   }
     251        2439 : }
     252             : 
     253             : char const *
     254     1258889 : fd_log_cpu( void ) {
     255     1258889 :   if( FD_UNLIKELY( !fd_log_private_cpu_init ) ) fd_log_cpu_set( NULL );
     256     1258889 :   return fd_log_private_cpu;
     257     1258889 : }
     258             : 
     259             : /* THREAD GROUP ID APIS ***********************************************/
     260             : 
     261             : /* Group id */
     262             : 
     263             : static ulong fd_log_private_group_id; /* 0 outside boot/halt, init on boot */
     264             : 
     265        2394 : void fd_log_private_group_id_set( ulong group_id ) { fd_log_private_group_id = group_id; }
     266             : 
     267   311395356 : ulong fd_log_group_id( void ) { return fd_log_private_group_id; }
     268             : 
     269             : /* Group */
     270             : 
     271             : static char fd_log_private_group[ FD_LOG_NAME_MAX ]; /* "" outside boot/halt, init on boot */
     272             : 
     273       97605 : char const * fd_log_group( void ) { return fd_log_private_group; }
     274             : 
     275             : void
     276        2394 : fd_log_private_group_set( char const * group ) {
     277        2394 :   if( FD_UNLIKELY( !group ) || FD_UNLIKELY( group[0]=='\0') ) group = "[group]";
     278        2394 :   if( FD_LIKELY( group!=fd_log_private_group ) )
     279        2394 :     fd_cstr_fini( fd_cstr_append_cstr_safe( fd_cstr_init( fd_log_private_group ), group, FD_LOG_NAME_MAX-1UL ) );
     280        2394 : }
     281             : 
     282             : /* System TID or ULONG_MAX on failure */
     283             : 
     284             : ulong
     285        2430 : fd_log_private_tid_default( void ) {
     286        2430 : # if defined(__linux__)
     287        2430 :   long tid = syscall( SYS_gettid );
     288             : # else
     289             :   long tid = getpid();
     290             : # endif
     291        2430 :   return fd_ulong_if( tid>0L, (ulong)tid, ULONG_MAX );
     292        2430 : }
     293             : 
     294             : static FD_TL ulong fd_log_private_tid;      /* 0 at thread start */
     295             : static FD_TL int   fd_log_private_tid_init; /* 0 at thread start */
     296             : 
     297             : void
     298        2430 : fd_log_private_tid_set( ulong tid ) {
     299        2430 :   fd_log_private_tid      = tid;
     300        2430 :   fd_log_private_tid_init = 1;
     301        2430 : }
     302             : 
     303             : ulong
     304     1261248 : fd_log_tid( void ) {
     305     1261248 :   if( FD_UNLIKELY( !fd_log_private_tid_init ) ) fd_log_private_tid_set( fd_log_private_tid_default() );
     306     1261248 :   return fd_log_private_tid;
     307     1261248 : }
     308             : 
     309             : /* User id */
     310             : 
     311             : static ulong
     312        2394 : fd_log_private_user_id_default( void ) {
     313        2394 :   return (ulong)getuid(); /* POSIX spec seems ambiguous as to whether or not this is a signed type */
     314        2394 : }
     315             : 
     316             : static ulong fd_log_private_user_id;      /* 0 outside boot/halt, init on boot */
     317             : static int   fd_log_private_user_id_init;
     318             : 
     319             : void
     320        2394 : fd_log_private_user_id_set( ulong user_id ) {
     321        2394 :   fd_log_private_user_id      = user_id;
     322        2394 :   fd_log_private_user_id_init = 1;
     323        2394 : }
     324             : 
     325             : ulong
     326        2430 : fd_log_user_id( void ) {
     327        2430 :   if( FD_UNLIKELY( !fd_log_private_user_id_init ) ) {
     328           0 :     fd_log_private_user_id      = fd_log_private_user_id_default();
     329           0 :     fd_log_private_user_id_init = 1;
     330           0 :   }
     331        2430 :   return fd_log_private_user_id;
     332        2430 : }
     333             : 
     334             : /* User */
     335             : 
     336             : static char  fd_log_private_user[ FD_LOG_NAME_MAX ]; /* "" outside boot/halt, init on boot */
     337             : 
     338       97605 : char const * fd_log_user( void ) { return fd_log_private_user; }
     339             : 
     340             : void
     341        2394 : fd_log_private_user_set( char const * user ) {
     342        2394 :   if( FD_UNLIKELY( !user ) || FD_UNLIKELY( user[0]=='\0') ) user = "[user]";
     343        2394 :   if( FD_LIKELY( user!=fd_log_private_user ) )
     344        2394 :     fd_cstr_fini( fd_cstr_append_cstr_safe( fd_cstr_init( fd_log_private_user ), user, FD_LOG_NAME_MAX-1UL ) );
     345        2394 : }
     346             : 
     347             : int
     348           0 : fd_log_group_id_query( ulong group_id ) {
     349           0 :   if( group_id==fd_log_group_id() ) return FD_LOG_GROUP_ID_QUERY_LIVE; /* Avoid O/S call for self queries */
     350           0 :   pid_t pid = (pid_t)group_id;
     351           0 :   if( FD_UNLIKELY( ((group_id!=(ulong)pid) | (pid<=(pid_t)0)) ) ) return FD_LOG_GROUP_ID_QUERY_INVAL;
     352           0 :   if( !kill( (pid_t)group_id, 0 ) ) return FD_LOG_GROUP_ID_QUERY_LIVE;
     353           0 :   if( FD_LIKELY( errno==ESRCH ) ) return FD_LOG_GROUP_ID_QUERY_DEAD;
     354           0 :   if( FD_LIKELY( errno==EPERM ) ) return FD_LOG_GROUP_ID_QUERY_PERM;
     355           0 :   return FD_LOG_GROUP_ID_QUERY_FAIL;
     356           0 : }
     357             : 
     358             : /* WALLCLOCK APIS *****************************************************/
     359             : 
     360             : long
     361   153257115 : fd_log_wallclock( void ) {
     362   153257115 :   struct timespec ts[1];
     363   153257115 :   clock_gettime( CLOCK_REALTIME, ts );
     364   153257115 :   return ((long)1e9)*((long)ts->tv_sec) + (long)ts->tv_nsec;
     365   153257115 : }
     366             : 
     367             : char *
     368             : fd_log_wallclock_cstr( long   now,
     369      102261 :                        char * buf ) {
     370      102261 :   uint  YYYY;
     371      102261 :   uint  MM;
     372      102261 :   uint  DD;
     373      102261 :   uint  hh;
     374      102261 :   uint  mm;
     375      102261 :   ulong ns;
     376      102261 :   int   tz;
     377             : 
     378      102261 :   static long const ns_per_m = 60000000000L;
     379      102261 :   static long const ns_per_s =  1000000000L;
     380             : 
     381      102261 :   static FD_TL long now_ref  = 1262325600000000000L; /* 2010-01-01 00:00:00.000000000 GMT-06 */
     382      102261 :   static FD_TL uint YYYY_ref = 2010U;                /* Initialized to what now0 corresponds to */
     383      102261 :   static FD_TL uint MM_ref   = 1U;                   /* " */
     384      102261 :   static FD_TL uint DD_ref   = 1U;                   /* " */
     385      102261 :   static FD_TL uint hh_ref   = 0U;                   /* " */
     386      102261 :   static FD_TL uint mm_ref   = 0U;                   /* " */
     387      102261 :   static FD_TL int  tz_ref   = -6;                   /* " */
     388             : 
     389      102261 :   if( FD_LIKELY( (now_ref<=now) & (now<(now_ref+ns_per_m)) ) ) {
     390             : 
     391             :     /* now is near the reference timestamp so we reuse the reference
     392             :        calculation timestamp. */
     393             : 
     394       99773 :     YYYY = YYYY_ref;
     395       99773 :     MM   = MM_ref;
     396       99773 :     DD   = DD_ref;
     397       99773 :     hh   = hh_ref;
     398       99773 :     mm   = mm_ref;
     399       99773 :     ns   = (ulong)(now - now_ref);
     400       99773 :     tz   = tz_ref;
     401             : 
     402       99773 :   } else {
     403             : 
     404        2488 :     long _t  = now / ns_per_s;
     405        2488 :     long _ns = now - ns_per_s*_t;
     406        2488 :     if( _ns<0L ) _ns += ns_per_s, _t--;
     407        2488 :     time_t t = (time_t)_t;
     408             : 
     409        2488 :     struct tm tm[1];
     410        2488 :     static FD_TL int localtime_broken = 0;
     411        2488 :     if( FD_UNLIKELY( !localtime_broken && !localtime_r( &t, tm ) ) ) localtime_broken = 1;
     412        2488 :     if( FD_UNLIKELY( localtime_broken ) ) { /* If localtime_r doesn't work, pretty print as a raw UNIX time */
     413             :       /* Note: These can all run in parallel */
     414           0 :       fd_cstr_append_fxp10_as_text( buf,    ' ', fd_char_if( now<0L, '-', '\0' ), 9UL, fd_long_abs( now ), 29UL );
     415           0 :       fd_cstr_append_text         ( buf+29, " s UNIX",                                                      7UL );
     416           0 :       fd_cstr_append_char         ( buf+36, '\0'                                                                );
     417           0 :       return buf;
     418           0 :     }
     419             : 
     420        2488 :     YYYY = (uint)(1900+tm->tm_year);
     421        2488 :     MM   = (uint)(   1+tm->tm_mon );
     422        2488 :     DD   = (uint)tm->tm_mday;
     423        2488 :     hh   = (uint)tm->tm_hour;
     424        2488 :     mm   = (uint)tm->tm_min;
     425        2488 :     ns   = ((ulong)((uint)tm->tm_sec))*((ulong)ns_per_s) + ((ulong)_ns);
     426        2488 : #   if defined(__linux__)
     427        2488 :     tz   = (int)(-timezone/3600L+(long)tm->tm_isdst);
     428             : #   else
     429             :     tz   = 0;
     430             : #   endif
     431             : 
     432        2488 :     now_ref  = now - (long)ns;
     433        2488 :     YYYY_ref = YYYY;
     434        2488 :     MM_ref   = MM;
     435        2488 :     DD_ref   = DD;
     436        2488 :     hh_ref   = hh;
     437        2488 :     mm_ref   = mm;
     438        2488 :     tz_ref   = tz;
     439             : 
     440        2488 :   }
     441             : 
     442             :   /* Note: These can all run in parallel! */
     443      102261 :   fd_cstr_append_uint_as_text ( buf,    '0', '\0',    YYYY,            4UL );
     444      102261 :   fd_cstr_append_char         ( buf+ 4, '-'                                );
     445      102261 :   fd_cstr_append_uint_as_text ( buf+ 5, '0', '\0',      MM,            2UL );
     446      102261 :   fd_cstr_append_char         ( buf+ 7, '-'                                );
     447      102261 :   fd_cstr_append_uint_as_text ( buf+ 8, '0', '\0',      DD,            2UL );
     448      102261 :   fd_cstr_append_char         ( buf+10, ' '                                );
     449      102261 :   fd_cstr_append_uint_as_text ( buf+11, '0', '\0',      hh,            2UL );
     450      102261 :   fd_cstr_append_char         ( buf+13, ':'                                );
     451      102261 :   fd_cstr_append_uint_as_text ( buf+14, '0', '\0',      mm,            2UL );
     452      102261 :   fd_cstr_append_char         ( buf+16, ':'                                );
     453      102261 :   fd_cstr_append_fxp10_as_text( buf+17, '0', '\0', 9UL, ns,           12UL );
     454      102261 :   fd_cstr_append_text         ( buf+29, " GMT",                        4UL );
     455      102261 :   fd_cstr_append_char         ( buf+33, fd_char_if( tz<0, '-', '+' )       );
     456      102261 :   fd_cstr_append_uint_as_text ( buf+34, '0', '\0', fd_int_abs( tz ),   2UL );
     457      102261 :   fd_cstr_append_char         ( buf+36, '\0'                               );
     458      102261 :   return buf;
     459      102261 : }
     460             : 
     461             : long
     462         501 : fd_log_sleep( long dt ) {
     463         501 :   if( FD_UNLIKELY( dt < 1L ) ) {
     464           0 :     sched_yield();
     465           0 :     return 0L;
     466           0 :   }
     467             : 
     468             :   /* dt is in [1,LONG_MAX] at this point */
     469         501 :   long ns_dt = fd_long_min( dt, (((long)1e9)<<31)-1L ); /* in [1,2^31*1e9) and <= dt at this point */
     470         501 :   dt -= ns_dt;
     471             : 
     472         501 :   struct timespec req[1];
     473         501 :   struct timespec rem[1];
     474         501 :   req->tv_sec  = (time_t)( ((ulong)ns_dt) / ((ulong)1e9) ); /* in [0,2^31-1] */
     475         501 :   req->tv_nsec = (long)  ( ((ulong)ns_dt) % ((ulong)1e9) ); /* in [0,1e9) */
     476         501 :   if( FD_UNLIKELY( nanosleep( req, rem ) ) && FD_LIKELY( errno==EINTR ) ) dt += ((long)1e9)*((long)rem->tv_sec) + rem->tv_nsec;
     477         501 :   return dt;
     478         501 : }
     479             : 
     480             : long
     481           0 : fd_log_wait_until( long then ) {
     482           0 :   long now;
     483           0 :   for(;;) {
     484           0 :     now = fd_log_wallclock();
     485           0 :     long rem = then - now;
     486           0 :     if( FD_LIKELY( rem<=0L ) ) break; /* we've waited long enough */
     487           0 :     if( FD_UNLIKELY( rem>(long)1e9 ) ) { /* long wait (over ~1 s) ... sleep until medium long */
     488           0 :       fd_log_sleep( rem-(long)0.1e9 );
     489           0 :       continue;
     490           0 :     }
     491           0 :     if( FD_UNLIKELY( rem>(long)0.1e9 ) ) { /* medium long wait (over ~0.1 s) ... yield */
     492           0 :       FD_YIELD();
     493           0 :       continue;
     494           0 :     }
     495           0 :     if( FD_UNLIKELY( rem>(long)1e3 ) ) { /* medium short wait (over ~1 us) ... hyperthreading friendly spin */
     496           0 :       FD_SPIN_PAUSE();
     497           0 :       continue;
     498           0 :     }
     499             :     /* short wait ... spin on fd_log_wallclock */
     500           0 :   }
     501           0 :   return now;
     502           0 : }
     503             : 
     504             : /* LOG APIS ***********************************************************/
     505             : 
     506             : char       fd_log_private_path[ 1024 ]; /* "" outside boot/halt, init at boot */
     507             : static int fd_log_private_fileno = -1;  /* -1 outside boot/halt, init at boot */
     508             : static int fd_log_private_dedup;        /*  0 outside boot/halt, init at boot */
     509             : 
     510             : void
     511        4317 : fd_log_flush( void ) {
     512        4317 :   int log_fileno = FD_VOLATILE_CONST( fd_log_private_fileno );
     513        4317 :   if( FD_LIKELY( log_fileno!=-1 ) ) fsync( log_fileno );
     514        4317 : }
     515             : 
     516             : static int fd_log_private_colorize;      /* 0 outside boot/halt, init at boot */
     517             : static int fd_log_private_level_logfile; /* 0 outside boot/halt, init at boot */
     518             : static int fd_log_private_level_stderr;  /* 0 outside boot/halt, init at boot */
     519             : static int fd_log_private_level_flush;   /* 0 outside boot/halt, init at boot */
     520             : static int fd_log_private_level_core;    /* 0 outside boot/halt, init at boot */
     521             : static int fd_log_private_unclean_exit;
     522             : 
     523        2394 : int fd_log_colorize     ( void ) { return FD_VOLATILE_CONST( fd_log_private_colorize      ); }
     524     1387213 : int fd_log_level_logfile( void ) { return FD_VOLATILE_CONST( fd_log_private_level_logfile ); }
     525     1258819 : int fd_log_level_stderr ( void ) { return FD_VOLATILE_CONST( fd_log_private_level_stderr  ); }
     526      104188 : int fd_log_level_flush  ( void ) { return FD_VOLATILE_CONST( fd_log_private_level_flush   ); }
     527        3519 : int fd_log_level_core   ( void ) { return FD_VOLATILE_CONST( fd_log_private_level_core    ); }
     528             : 
     529        2394 : void fd_log_colorize_set     ( int mode  ) { FD_VOLATILE( fd_log_private_colorize      ) = mode;  }
     530        2406 : void fd_log_level_logfile_set( int level ) { FD_VOLATILE( fd_log_private_level_logfile ) = level; }
     531        2409 : void fd_log_level_stderr_set ( int level ) { FD_VOLATILE( fd_log_private_level_stderr  ) = level; }
     532        2394 : void fd_log_level_flush_set  ( int level ) { FD_VOLATILE( fd_log_private_level_flush   ) = level; }
     533        2409 : void fd_log_level_core_set   ( int level ) { FD_VOLATILE( fd_log_private_level_core    ) = level; }
     534             : 
     535           0 : int fd_log_private_logfile_fd( void ) { return FD_VOLATILE_CONST( fd_log_private_fileno ); }
     536             : 
     537           0 : void fd_log_enable_unclean_exit( void ) { fd_log_private_unclean_exit = 1; }
     538             : 
     539             : /* Buffer size used for vsnprintf calls (this is also one more than the
     540             :    maximum size that this can passed to fd_io_write) */
     541             : 
     542     2977502 : #define FD_LOG_BUF_SZ (32UL*4096UL)
     543             : 
     544             : /* Lock to used by fd_log_private_fprintf_0 to sequence calls writes
     545             :    between different _processes_ that share the same fd. */
     546             : 
     547             : static int fd_log_private_shared_lock_local[1] __attribute__((aligned(128))); /* location of lock if boot mmap fails */
     548             :        int * fd_log_private_shared_lock  = fd_log_private_shared_lock_local;  /* Local lock outside boot/halt, init at boot */
     549             : 
     550             : void
     551             : fd_log_private_fprintf_0( int          fd,
     552      110125 :                           char const * fmt, ... ) {
     553             : 
     554             :   /* Note: while this function superficially looks vdprintf-ish, we don't
     555             :      use that as it can do all sorts of unpleasantness under the hood
     556             :      (fflush, mutex / futex on fd, non-AS-safe buffering, ...) that this
     557             :      function deliberately avoids.  Also, the function uses the shared
     558             :      lock to help keep messages generated from processes that share the
     559             :      same log fd sane. */
     560             : 
     561             :   /* TODO:
     562             :      - Consider moving to util/io as fd_io_printf or renaming to
     563             :        fd_log_printf?
     564             :      - Is msg better to have on stack or in thread local storage?
     565             :      - Is msg even necessary given shared lock? (probably still useful to
     566             :        keep the message write to be a single-system-call best effort)
     567             :      - Allow partial write to fd_io_write?  (e.g. src_min=0 such that
     568             :        the fd_io_write below is guaranteed to be a single system call) */
     569             : 
     570      110125 :   char msg[ FD_LOG_BUF_SZ ];
     571             : 
     572      110125 :   va_list ap;
     573      110125 :   va_start( ap, fmt );
     574      110125 :   int len = vsnprintf( msg, FD_LOG_BUF_SZ, fmt, ap );
     575      110125 :   if( len<0                        ) len = 0;                        /* cmov */
     576      110125 :   if( len>(int)(FD_LOG_BUF_SZ-1UL) ) len = (int)(FD_LOG_BUF_SZ-1UL); /* cmov */
     577      110125 :   msg[ len ] = '\0';
     578      110125 :   va_end( ap );
     579             : 
     580      110125 : # if FD_HAS_ATOMIC
     581      110125 :   FD_COMPILER_MFENCE();
     582      111459 :   while(( FD_LIKELY( FD_ATOMIC_CAS( fd_log_private_shared_lock, 0, 1 ) ) )) ;
     583      110125 :   FD_COMPILER_MFENCE();
     584      110125 : # endif
     585             : 
     586      110125 :   ulong wsz;
     587      110125 :   fd_io_write( fd, msg, (ulong)len, (ulong)len, &wsz ); /* Note: we ignore errors because what are we doing to do? log them? */
     588             : 
     589      110125 : # if FD_HAS_ATOMIC
     590      110125 :   FD_COMPILER_MFENCE();
     591      110125 :   FD_VOLATILE( *fd_log_private_shared_lock ) = 0;
     592      110125 :   FD_COMPILER_MFENCE();
     593      110125 : # endif
     594             : 
     595      110125 : }
     596             : 
     597             : /* This is the same as fd_log_private_fprintf_0 except that it does not try to
     598             :    take a lock when writing to the log file.  This should almost never be used
     599             :    except in exceptional cases when logging while the process is shutting down.
     600             : 
     601             :    It exists because if a child process dies while holding the lock, we may
     602             :    want to log some diagnostic messages when tearing down the process tree. */
     603             : void
     604             : fd_log_private_fprintf_nolock_0( int          fd,
     605           0 :                                  char const * fmt, ... ) {
     606             : 
     607             :   /* Note: while this function superficially looks vdprintf-ish, we don't
     608             :      use that as it can do all sorts of unpleasantness under the hood
     609             :      (fflush, mutex / futex on fd, non-AS-safe buffering, ...) that this
     610             :      function deliberately avoids.  Also, the function uses the shared
     611             :      lock to help keep messages generated from processes that share the
     612             :      same log fd sane. */
     613             : 
     614             :   /* TODO:
     615             :      - Consider moving to util/io as fd_io_printf or renaming to
     616             :        fd_log_printf?
     617             :      - Is msg better to have on stack or in thread local storage?
     618             :      - Is msg even necessary given shared lock? (probably still useful to
     619             :        keep the message write to be a single-system-call best effort)
     620             :      - Allow partial write to fd_io_write?  (e.g. src_min=0 such that
     621             :        the fd_io_write below is guaranteed to be a single system call) */
     622             : 
     623           0 :   char msg[ FD_LOG_BUF_SZ ];
     624             : 
     625           0 :   va_list ap;
     626           0 :   va_start( ap, fmt );
     627           0 :   int len = vsnprintf( msg, FD_LOG_BUF_SZ, fmt, ap );
     628           0 :   if( len<0                        ) len = 0;                        /* cmov */
     629           0 :   if( len>(int)(FD_LOG_BUF_SZ-1UL) ) len = (int)(FD_LOG_BUF_SZ-1UL); /* cmov */
     630           0 :   msg[ len ] = '\0';
     631           0 :   va_end( ap );
     632             : 
     633           0 :   ulong wsz;
     634           0 :   fd_io_write( fd, msg, (ulong)len, (ulong)len, &wsz ); /* Note: we ignore errors because what are we doing to do? log them? */
     635           0 : }
     636             : 
     637             : /* Log buffer used by fd_log_private_0 and fd_log_private_hexdump_msg */
     638             : 
     639             : static FD_TL char fd_log_private_log_msg[ FD_LOG_BUF_SZ ];
     640             : 
     641             : char const *
     642     1378626 : fd_log_private_0( char const * fmt, ... ) {
     643     1378626 :   va_list ap;
     644     1378626 :   va_start( ap, fmt );
     645     1378626 :   int len = vsnprintf( fd_log_private_log_msg, FD_LOG_BUF_SZ, fmt, ap );
     646     1378626 :   if( len<0                        ) len = 0;                        /* cmov */
     647     1378626 :   if( len>(int)(FD_LOG_BUF_SZ-1UL) ) len = (int)(FD_LOG_BUF_SZ-1UL); /* cmov */
     648     1378626 :   fd_log_private_log_msg[ len ] = '\0';
     649     1378626 :   va_end( ap );
     650     1378626 :   return fd_log_private_log_msg;
     651     1378626 : }
     652             : 
     653             : char const *
     654             : fd_log_private_hexdump_msg( char const * descr,
     655             :                             void const * mem,
     656        6189 :                             ulong        sz ) {
     657             : 
     658     3140541 : # define FD_LOG_HEXDUMP_BYTES_PER_LINE           (16UL)
     659        6189 : # define FD_LOG_HEXDUMP_BLOB_DESCRIPTION_MAX_LEN (32UL)
     660        6189 : # define FD_LOG_HEXDUMP_MAX_INPUT_BLOB_SZ        (1664UL) /* multiple of 128 >= 1542 */
     661             : 
     662     3538524 : # define FD_LOG_HEXDUMP_ADD_TO_LOG_BUF(...)  do { log_buf_ptr += fd_int_max( sprintf( log_buf_ptr, __VA_ARGS__ ), 0 ); } while(0)
     663        6189 :   char * log_buf_ptr = fd_log_private_log_msg; /* used by FD_LOG_HEXDUMP_ADD_TO_LOG_BUF macro */
     664             : 
     665             :   /* Print the hexdump header */
     666             :   /* FIXME: consider additional sanitization of descr or using compiler
     667             :      tricks to prevent user from passing a non-const-char string (i.e.
     668             :      data they got from somewhere else that might not be sanitized). */
     669             : 
     670        6189 :   if( FD_UNLIKELY( !descr ) ) {
     671             : 
     672           0 :     FD_LOG_HEXDUMP_ADD_TO_LOG_BUF( "HEXDUMP - (%lu bytes at 0x%lx)", sz, (ulong)mem );
     673             : 
     674        6189 :   } else if( FD_UNLIKELY( strlen( descr )>FD_LOG_HEXDUMP_BLOB_DESCRIPTION_MAX_LEN ) ) {
     675             : 
     676           0 :     char tmp[ FD_LOG_HEXDUMP_BLOB_DESCRIPTION_MAX_LEN + 1UL ];
     677           0 :     fd_cstr_fini( fd_cstr_append_text( fd_cstr_init( tmp ), descr, FD_LOG_HEXDUMP_BLOB_DESCRIPTION_MAX_LEN ) );
     678           0 :     FD_LOG_HEXDUMP_ADD_TO_LOG_BUF( "HEXDUMP \"%s\"... (%lu bytes at 0x%lx)", tmp, sz, (ulong)mem );
     679             : 
     680        6189 :   } else {
     681             : 
     682        6189 :     FD_LOG_HEXDUMP_ADD_TO_LOG_BUF( "HEXDUMP \"%s\" (%lu bytes at 0x%lx)", descr, sz, (ulong)mem );
     683             : 
     684        6189 :   }
     685             : 
     686        6189 :   if( FD_UNLIKELY( !sz ) ) return fd_log_private_log_msg;
     687             : 
     688        6189 :   FD_LOG_HEXDUMP_ADD_TO_LOG_BUF( "\n" );
     689             : 
     690        6189 :   if( FD_UNLIKELY( !mem ) ) {
     691           0 :     FD_LOG_HEXDUMP_ADD_TO_LOG_BUF( "\t... snip (unreadable memory) ..." );
     692           0 :     return fd_log_private_log_msg;
     693           0 :   }
     694             : 
     695        6189 :   char         line_buf[ FD_LOG_HEXDUMP_BYTES_PER_LINE+1 ];
     696        6189 :   char const * blob     = (char const *)mem;
     697        6189 :   ulong        blob_off = 0UL;
     698        6189 :   ulong        blob_sz  = fd_ulong_min( sz, FD_LOG_HEXDUMP_MAX_INPUT_BLOB_SZ );
     699             : 
     700     3140034 :   for( ; blob_off<blob_sz; blob_off++ ) {
     701     3133845 :     ulong col_idx = blob_off % FD_LOG_HEXDUMP_BYTES_PER_LINE;
     702             : 
     703             :     /* New line. Print previous line's ASCII representation and then print the offset. */
     704     3133845 :     if( FD_UNLIKELY( !col_idx ) ) {
     705      195897 :       if( FD_LIKELY( blob_off ) ) FD_LOG_HEXDUMP_ADD_TO_LOG_BUF( "  %s\n", line_buf );
     706      195897 :       FD_LOG_HEXDUMP_ADD_TO_LOG_BUF( "\t%04lx: ", blob_off );
     707      195897 :     }
     708             :     /* FIXME: consider extra space between col 7 and 8 to make easier
     709             :        for visual inspection */
     710             : 
     711     3133845 :     char c = blob[blob_off];
     712     3133845 :     FD_LOG_HEXDUMP_ADD_TO_LOG_BUF( " %02x", (uint)(uchar)c );
     713             : 
     714             :     /* If not a printable ASCII character, output a dot. */
     715     3133845 :     line_buf[ col_idx     ] = fd_char_if( fd_isalnum( (int)c ) | fd_ispunct( (int)c ) | (c==' '), c, '.' );
     716     3133845 :     line_buf[ col_idx+1UL ] = '\0';
     717     3133845 :   }
     718             : 
     719             :   /* Print the 2nd column of last blob line */
     720        6696 :   while( blob_off % FD_LOG_HEXDUMP_BYTES_PER_LINE ) {
     721         507 :     FD_LOG_HEXDUMP_ADD_TO_LOG_BUF( "   " );
     722         507 :     blob_off++;
     723         507 :   }
     724        6189 :   FD_LOG_HEXDUMP_ADD_TO_LOG_BUF( "  %s", line_buf );
     725             : 
     726        6189 :   if( FD_UNLIKELY( blob_sz < sz ) )
     727           0 :     FD_LOG_HEXDUMP_ADD_TO_LOG_BUF( "\n\t... snip (printed %lu bytes, omitted %lu bytes) ...", blob_sz, sz-blob_sz );
     728             : 
     729        6189 :   return fd_log_private_log_msg;
     730             : 
     731        6189 : # undef FD_LOG_HEXDUMP_BYTES_PER_LINE
     732        6189 : # undef FD_LOG_HEXDUMP_BLOB_DESCRIPTION_MAX_LEN
     733        6189 : # undef FD_LOG_HEXDUMP_MAX_INPUT_BLOB_SZ
     734        6189 : # undef FD_LOG_HEXDUMP_ADD_TO_LOG_BUF
     735        6189 : }
     736             : 
     737             : void
     738             : fd_log_private_1( int          level,
     739             :                   long         now,
     740             :                   char const * file,
     741             :                   int          line,
     742             :                   char const * func,
     743     1384816 :                   char const * msg ) {
     744             : 
     745     1384816 :   if( level<fd_log_level_logfile() ) return;
     746             : 
     747             :   /* These are thread init so we call them regardless of permanent log
     748             :      enabled to their initialization time is guaranteed independent of
     749             :      whether the permanent log is enabled. */
     750             : 
     751     1256428 :   char const * thread = fd_log_thread();
     752     1256428 :   char const * cpu    = fd_log_cpu();
     753     1256428 :   ulong        tid    = fd_log_tid();
     754             : 
     755     1256428 :   int log_fileno = FD_VOLATILE_CONST( fd_log_private_fileno );
     756     1256428 :   int to_logfile = (log_fileno!=-1);
     757     1256428 :   int to_stderr  = (level>=fd_log_level_stderr());
     758     1256428 :   if( !(to_logfile | to_stderr) ) return;
     759             : 
     760             :   /* Deduplicate the log if requested */
     761             : 
     762     1191082 :   if( fd_log_private_dedup ) {
     763             : 
     764             :     /* Compute if this message appears to be a recent duplicate of
     765             :        a previous log message */
     766             : 
     767     1191074 :     ulong hash = fd_cstr_hash_append( fd_cstr_hash_append( fd_cstr_hash_append( fd_ulong_hash(
     768     1191074 :                    (ulong)(8L*(long)line+(long)level) ), file ), func ), msg );
     769             : 
     770     1191074 :     static long const dedup_interval = 20000000L; /* 1/50 s */
     771             : 
     772     1191074 :     static FD_TL int   init;      /* 0   on thread start */
     773     1191074 :     static FD_TL ulong last_hash; /* 0UL on thread start */
     774     1191074 :     static FD_TL long  then;      /* 0L  on thread start */
     775             : 
     776     1191074 :     int is_dup = init & (hash==last_hash) & ((now-then)<dedup_interval);
     777     1191074 :     init = 1;
     778             : 
     779             :     /* Update how many messages from this thread in row have been
     780             :        duplicates */
     781             : 
     782     1191074 :     static FD_TL ulong dedup_cnt;   /* 0UL on thread start */
     783     1191074 :     static FD_TL int   in_dedup;    /* 0   on thread start */
     784             : 
     785     1191074 :     if( is_dup ) dedup_cnt++;
     786      101102 :     else {
     787      101102 :       if( in_dedup ) {
     788             : 
     789             :         /* This message appears to end a long string of duplicates.
     790             :            Log the end of the deduplication. */
     791             : 
     792         276 :         char then_cstr[ FD_LOG_WALLCLOCK_CSTR_BUF_SZ ];
     793         276 :         fd_log_wallclock_cstr( then, then_cstr );
     794             : 
     795         276 :         if( to_logfile )
     796         276 :           fd_log_private_fprintf_0( log_fileno, "SNIP    %s %6lu:%-6lu %s:%s:%-4s %s:%s:%-4s "
     797         276 :                                     "stopped repeating (%lu identical messages)\n",
     798         276 :                                     then_cstr, fd_log_group_id(),tid, fd_log_user(),fd_log_host(),cpu,
     799         276 :                                     fd_log_app(),fd_log_group(),thread, dedup_cnt+1UL );
     800             : 
     801         276 :         if( to_stderr ) {
     802         213 :           char * then_short_cstr = then_cstr+5; then_short_cstr[21] = '\0'; /* Lop off the year, ns resolution and timezone */
     803         213 :           fd_log_private_fprintf_0( STDERR_FILENO, "SNIP    %s %-6lu %-4s %-4s stopped repeating (%lu identical messages)\n",
     804         213 :                                     then_short_cstr, tid,cpu,thread, dedup_cnt+1UL );
     805         213 :         }
     806             : 
     807         276 :         in_dedup = 0;
     808         276 :       }
     809             : 
     810      101102 :       dedup_cnt = 0UL;
     811      101102 :     }
     812             : 
     813             :     /* dedup_cnt previous messages from this thread appear to be
     814             :        duplicates.  Decide whether to let the raw message print or
     815             :        deduplicate to the log.  FIXME: CONSIDER RANDOMIZING THE
     816             :        THROTTLE. */
     817             : 
     818     1191074 :     static ulong const dedup_thresh   = 3UL;         /* let initial dedup_thresh duplicates go out the door */
     819     1191074 :     static long  const dedup_throttle = 1000000000L; /* ~1s, how often to update status on current duplication */
     820             : 
     821     1191074 :     static FD_TL long dedup_last; /* 0L on thread start */
     822             : 
     823     1191074 :     if( dedup_cnt < dedup_thresh ) dedup_last = now;
     824     1089291 :     else {
     825     1089291 :       if( (now-dedup_last) >= dedup_throttle ) {
     826          36 :         char now_cstr[ FD_LOG_WALLCLOCK_CSTR_BUF_SZ ];
     827          36 :         fd_log_wallclock_cstr( now, now_cstr );
     828          36 :         if( to_logfile )
     829          36 :           fd_log_private_fprintf_0( log_fileno, "SNIP    %s %6lu:%-6lu %s:%s:%-4s %s:%s:%-4s repeating (%lu identical messages)\n",
     830          36 :                                     now_cstr, fd_log_group_id(),tid, fd_log_user(),fd_log_host(),cpu,
     831          36 :                                     fd_log_app(),fd_log_group(),thread, dedup_cnt+1UL );
     832          36 :         if( to_stderr ) {
     833          36 :           char * now_short_cstr = now_cstr+5; now_short_cstr[21] = '\0'; /* Lop off the year, ns resolution and timezone */
     834          36 :           fd_log_private_fprintf_0( STDERR_FILENO, "SNIP    %s %-6lu %-4s %-4s repeating (%lu identical messages)\n",
     835          36 :                                     now_short_cstr, tid,cpu,thread, dedup_cnt+1UL );
     836          36 :         }
     837          36 :         dedup_last = now;
     838          36 :       }
     839     1089291 :       in_dedup = 1;
     840     1089291 :     }
     841             : 
     842     1191074 :     last_hash = hash;
     843     1191074 :     then      = now;
     844             : 
     845     1191074 :     if( in_dedup ) return;
     846     1191074 :   }
     847             : 
     848      101791 :   char now_cstr[ FD_LOG_WALLCLOCK_CSTR_BUF_SZ ];
     849      101791 :   fd_log_wallclock_cstr( now, now_cstr );
     850             : 
     851      101791 :   static char const * level_cstr[] = {
     852      101791 :     /* 0 */ "DEBUG  ",
     853      101791 :     /* 1 */ "INFO   ",
     854      101791 :     /* 2 */ "NOTICE ",
     855      101791 :     /* 3 */ "WARNING",
     856      101791 :     /* 4 */ "ERR    ",
     857      101791 :     /* 5 */ "CRIT   ",
     858      101791 :     /* 6 */ "ALERT  ",
     859      101791 :     /* 7 */ "EMERG  "
     860      101791 :   };
     861             : 
     862      101791 :   if( to_logfile )
     863       94827 :     fd_log_private_fprintf_0( log_fileno, "%s %s %6lu:%-6lu %s:%s:%-4s %s:%s:%-4s %s(%i)[%s]: %s\n",
     864       94827 :                               level_cstr[level], now_cstr, fd_log_group_id(),tid, fd_log_user(),fd_log_host(),cpu,
     865       94827 :                               fd_log_app(),fd_log_group(),thread, file,line,func, msg );
     866             : 
     867      101791 :   if( to_stderr ) {
     868        9947 :     static char const * color_level_cstr[] = {
     869             :       /* 0 */ TEXT_NORMAL                                  "DEBUG  ",
     870             :       /* 1 */ TEXT_BLUE                                    "INFO   " TEXT_NORMAL,
     871             :       /* 2 */ TEXT_GREEN                                   "NOTICE " TEXT_NORMAL,
     872             :       /* 3 */ TEXT_YELLOW                                  "WARNING" TEXT_NORMAL,
     873             :       /* 4 */ TEXT_RED                                     "ERR    " TEXT_NORMAL,
     874             :       /* 5 */ TEXT_RED TEXT_BOLD                           "CRIT   " TEXT_NORMAL,
     875             :       /* 6 */ TEXT_RED TEXT_BOLD TEXT_UNDERLINE            "ALERT  " TEXT_NORMAL,
     876             :       /* 7 */ TEXT_RED TEXT_BOLD TEXT_UNDERLINE TEXT_BLINK "EMERG  " TEXT_NORMAL
     877        9947 :     };
     878        9947 :     char * now_short_cstr = now_cstr+5; now_short_cstr[21] = '\0'; /* Lop off the year, ns resolution and timezone */
     879        9947 :     fd_log_private_fprintf_0( STDERR_FILENO, "%s %s %-6lu %-4s %-4s %s(%i): %s\n",
     880        9947 :                               fd_log_private_colorize ? color_level_cstr[level] : level_cstr[level],
     881        9947 :                               now_short_cstr, tid,cpu,thread, file, line, msg );
     882        9947 :   }
     883             : 
     884      101791 :   if( level<fd_log_level_flush() ) return;
     885             : 
     886        4281 :   fd_log_flush();
     887        4281 : }
     888             : 
     889             : void
     890             : fd_log_private_2( int          level,
     891             :                   long         now,
     892             :                   char const * file,
     893             :                   int          line,
     894             :                   char const * func,
     895        1125 :                   char const * msg ) {
     896        1125 :   fd_log_private_1( level, now, file, line, func, msg );
     897             : 
     898        1125 :   if( level<fd_log_level_core() ) {
     899        1125 : #   if defined(__linux__)
     900        1125 :     if( fd_log_private_unclean_exit ) {
     901           0 :       syscall( SYS_exit_group, 1 );
     902           0 :     }
     903        1125 : #   endif /* defined(__linux__) */
     904        1125 :     exit(1); /* atexit will call fd_log_private_cleanup implicitly */
     905        1125 :   }
     906             : 
     907           0 :   abort();
     908        1125 : }
     909             : 
     910             : void
     911             : fd_log_private_raw_2( char const * file,
     912             :                       int          line,
     913             :                       char const * func,
     914           0 :                       char const * msg ) {
     915           0 :   fd_log_private_fprintf_nolock_0( STDERR_FILENO, "%s(%i)[%s]: %s\n", file, line, func, msg );
     916           0 : # if defined(__linux__)
     917           0 :   syscall( SYS_exit_group, 1 );
     918             : # else
     919             :   exit(1);
     920             : # endif
     921           0 :   abort();
     922           0 : }
     923             : 
     924             : /* BOOT/HALT APIS *****************************************************/
     925             : 
     926             : static void
     927        3648 : fd_log_private_cleanup( void ) {
     928             : 
     929             :   /* The atexit below means that all calls to "exit();" implicitly
     930             :      become "fd_log_private_cleanup(); exit();".  It also implies that
     931             :      programs that terminate via a top level return from main implicitly
     932             :      call fd_log_private_cleanup().
     933             : 
     934             :      As such it is possible that a thread other than the booter will
     935             :      trigger cleanup either by triggering this directly (e.g. calling
     936             :      exit) or indirectly (e.g. by logging a message with an exit
     937             :      triggering priority) and that the booter itself might call this
     938             :      more than once sequentially (e.g. fd_halt() calling cleanup
     939             :      explicitly followed by return from main triggering it again.
     940             : 
     941             :      Accordingly we protect this with a ONCE block so it only will
     942             :      execute once per program.  Further, if cleanup gets triggered by
     943             :      multiple threads concurrently, the ONCE block will prevent them
     944             :      from progressing until the first thread that hits the once block
     945             :      has completed cleanup. */
     946             : 
     947       12084 :   FD_ONCE_BEGIN {
     948        2394 :     int log_fileno = FD_VOLATILE_CONST( fd_log_private_fileno );
     949        2394 :     if(      log_fileno==-1                      ) fd_log_private_fprintf_0( STDERR_FILENO, "No log\n" );
     950         567 :     else if( !strcmp( fd_log_private_path, "-" ) ) fd_log_private_fprintf_0( STDERR_FILENO, "Log to stdout\n" );
     951         555 :     else {
     952         555 : #     if FD_HAS_THREADS
     953         555 :       if( fd_log_private_thread_id_ctr>1UL ) { /* There are potentially other log users running */
     954             :         /* Just closing the permanent log file is not multithreading
     955             :            safe in the case where other threads are still running
     956             :            normally and thus potentially logging to the permanent log.
     957             :            Such should not happen in a correctly written and functioning
     958             :            application but logging exists in large part to help
     959             :            understand when applications misbehave.  So we try to be as
     960             :            robust and informative as we can here.  FIXME: THE SECOND
     961             :            USLEEP IS AN UGLY HACK TO REDUCE (BUT NOT FULLY ELIMINATE)
     962             :            THE RISK OF USE AFTER CLOSE BY THOSE OTHER THREADS.  IT IS
     963             :            POSSIBLE WITH A MORE INVASIVE CHANGES TO FULLY ELIMINATE THIS
     964             :            RISK. */
     965           0 :         usleep( (useconds_t)40000 ); /* Give potentially concurrent users a chance to get their dying messages out */
     966           0 :         FD_COMPILER_MFENCE();
     967           0 :         FD_VOLATILE( fd_log_private_fileno ) = -1; /* Turn off the permanent log for concurrent users */
     968           0 :         FD_COMPILER_MFENCE();
     969           0 :         usleep( (useconds_t)40000 ); /* Give any concurrent log operations progress at turn off a chance to wrap */
     970           0 :       }
     971             : #     else
     972             :       FD_VOLATILE( fd_log_private_fileno ) = -1;
     973             : #     endif
     974             : 
     975         555 :       fsync( log_fileno );
     976         555 :       sync();
     977         555 :       fd_log_private_fprintf_0( STDERR_FILENO, "Log at \"%s\"\n", fd_log_private_path );
     978         555 :     }
     979        2394 :   } FD_ONCE_END;
     980        3648 : }
     981             : 
     982             : static void
     983             : fd_log_private_sig_abort( int         sig,
     984             :                           siginfo_t * info,
     985           0 :                           void *      context ) {
     986           0 :   (void)info; (void)context;
     987             : 
     988             :   /* Hopefully all out streams are idle now and we have flushed out
     989             :      all non-logging activity ... log a backtrace */
     990             : 
     991             : # if FD_HAS_BACKTRACE
     992             : 
     993             :   void * btrace[128];
     994             :   int btrace_cnt = backtrace( btrace, 128 );
     995             : 
     996             :   int log_fileno = FD_VOLATILE_CONST( fd_log_private_fileno );
     997             :   if( log_fileno!=-1 ) {
     998             :     fd_log_private_fprintf_0( log_fileno, "Caught signal %i, backtrace:\n", sig );
     999             :     backtrace_symbols_fd( btrace, btrace_cnt, log_fileno );
    1000             :     fsync( log_fileno );
    1001             :   }
    1002             : 
    1003             :   fd_log_private_fprintf_0( STDERR_FILENO, "\nCaught signal %i, backtrace:\n", sig );
    1004             :   backtrace_symbols_fd( btrace, btrace_cnt, STDERR_FILENO );
    1005             :   fsync( STDERR_FILENO );
    1006             : 
    1007             : # else /* !FD_HAS_BACKTRACE */
    1008             : 
    1009           0 :   int log_fileno = FD_VOLATILE_CONST( fd_log_private_fileno );
    1010           0 :   if( log_fileno!=-1 ) fd_log_private_fprintf_0( log_fileno, "Caught signal %i.\n", sig );
    1011             : 
    1012           0 :   fd_log_private_fprintf_0( STDERR_FILENO, "\nCaught signal %i.\n", sig );
    1013             : 
    1014           0 : # endif /* FD_HAS_BACKTRACE */
    1015             : 
    1016             :   /* Do final log cleanup */
    1017             : 
    1018           0 :   fd_log_private_cleanup();
    1019             : 
    1020           0 :   usleep( (useconds_t)1000000 ); /* Give some time to let streams drain */
    1021             : 
    1022           0 :   raise( sig ); /* Continue with the original handler (probably the default and that will produce the core) */
    1023           0 : }
    1024             : 
    1025             : static void
    1026       47520 : fd_log_private_sig_trap( int sig ) {
    1027       47520 :   struct sigaction act[1];
    1028             :   /* FIXME: CONSIDER NOT OVERRIDING IF THE SIGNAL HANDLER HAS ALREADY
    1029             :      BEEN SET BY THE USER. */
    1030       47520 :   act->sa_sigaction = fd_log_private_sig_abort;
    1031       47520 :   if( sigemptyset( &act->sa_mask ) ) FD_LOG_ERR(( "sigempty set failed" ));
    1032       47520 :   act->sa_flags = (int)(SA_SIGINFO | SA_RESETHAND);
    1033       47520 :   if( sigaction( sig, act, NULL ) ) FD_LOG_ERR(( "unable to override signal %i", sig ));
    1034       47520 : }
    1035             : 
    1036             : static int
    1037             : fd_log_private_open_path( int          cmdline,
    1038        2394 :                           char const * log_path ) {
    1039        2394 :   ulong        log_path_sz = log_path ? (strlen( log_path )+1UL) : 0UL;
    1040             : 
    1041        2394 :   if( !log_path_sz ) { /* Use default log path */
    1042           0 :     char tag[ FD_LOG_WALLCLOCK_CSTR_BUF_SZ ];
    1043           0 :     fd_log_wallclock_cstr( fd_log_wallclock(), tag );
    1044           0 :     for( ulong b=0UL; tag[b]; b++ ) if( tag[b]==' ' || tag[b]=='-' || tag[b]=='.' || tag[b]==':' ) tag[b] = '_';
    1045           0 :     ulong len; fd_cstr_printf( fd_log_private_path, 1024UL, &len, "/tmp/fd-%i.%i.%i_%lu_%s_%s_%s",
    1046           0 :                               FDCTL_MAJOR_VERSION, FDCTL_MINOR_VERSION, FDCTL_PATCH_VERSION,
    1047           0 :                               fd_log_group_id(), fd_log_user(), fd_log_host(), tag );
    1048           0 :     if( len==1023UL ) { fd_log_private_fprintf_0( STDERR_FILENO, "default log path too long; unable to boot\n" ); exit(1); }
    1049           0 :   }
    1050        2394 :   else if( log_path_sz==1UL    ) fd_log_private_path[0] = '\0'; /* User disabled */
    1051         567 :   else if( log_path_sz<=1024UL ) fd_memcpy( fd_log_private_path, log_path, log_path_sz ); /* User specified */
    1052           0 :   else                          { fd_log_private_fprintf_0( STDERR_FILENO, "log path too long; unable to boot\n" ); exit(1); } /* Invalid */
    1053             : 
    1054        2394 :   int log_fileno;
    1055        2394 :   if( fd_log_private_path[0]=='\0' ) {
    1056        1827 :     if( cmdline ) fd_log_private_fprintf_0( STDERR_FILENO, "--log-path \"\"\nNo log\n" );
    1057           0 :     else          fd_log_private_fprintf_0( STDERR_FILENO, "No log\n" );
    1058        1827 :     log_fileno = -1;
    1059        1827 :   } else if( !strcmp( fd_log_private_path, "-" ) ) {
    1060          12 :     if( cmdline ) fd_log_private_fprintf_0( STDERR_FILENO, "--log-path \"-\"\nLog to stdout\n" );
    1061           0 :     else          fd_log_private_fprintf_0( STDERR_FILENO, "Log to stdout\n" );
    1062          12 :     log_fileno = STDOUT_FILENO;
    1063         555 :   } else {
    1064         555 :     if( cmdline && !log_path_sz ) fd_log_private_fprintf_0( STDERR_FILENO, "--log-path not specified; using autogenerated path\n" );
    1065         555 :     log_fileno = open( fd_log_private_path, O_WRONLY | O_CREAT | O_APPEND, S_IRUSR | S_IWUSR | S_IRGRP | S_IWGRP | S_IROTH | S_IWOTH );
    1066         555 :     if( log_fileno==-1 ) {
    1067           0 :       fd_log_private_fprintf_0( STDERR_FILENO, "open failed (--log-path \"%s\"); unable to boot (%d-%s)\n", fd_log_private_path, errno, fd_io_strerror( errno ) );
    1068           0 :       exit(1);
    1069           0 :     }
    1070         555 :     fd_log_private_fprintf_0( STDERR_FILENO, "Log at \"%s\"\n", fd_log_private_path );
    1071         555 :   }
    1072        2394 :   return log_fileno;
    1073        2394 : }
    1074             : 
    1075             : void
    1076             : fd_log_private_boot( int  *   pargc,
    1077        2394 :                      char *** pargv ) {
    1078             : //FD_LOG_INFO(( "fd_log: booting" )); /* Log not online yet */
    1079             : 
    1080        2394 :   char buf[ FD_LOG_NAME_MAX ];
    1081             : 
    1082        2394 :   fd_log_private_shared_lock  = fd_log_private_shared_lock_local;
    1083             : 
    1084             :   /* Init our our application logical ids */
    1085             :   /* FIXME: CONSIDER EXPLICIT SPECIFICATION OF RANGE OF THREADS
    1086             :      INSTEAD OF ATOMIC COUNTER FROM BASE */
    1087             : 
    1088        2394 :   fd_log_private_app_id_set( fd_env_strip_cmdline_ulong( pargc, pargv, "--log-app-id", "FD_LOG_APP_ID", 0UL ) );
    1089             : 
    1090        2394 :   fd_log_private_app_set( fd_env_strip_cmdline_cstr( pargc, pargv, "--log-app", "FD_LOG_APP", NULL ) );
    1091             : 
    1092        2394 : # if FD_HAS_THREADS
    1093        2394 :   fd_log_private_thread_id_ctr = fd_env_strip_cmdline_ulong( pargc, pargv, "--log-thread-id", "FD_LOG_THREAD_ID", 0UL );
    1094        2394 :   ulong thread_id = fd_log_private_thread_id_next();
    1095             : # else
    1096             :   ulong thread_id = fd_env_strip_cmdline_ulong( pargc, pargv, "--log-thread-id", "FD_LOG_THREAD_ID", 0UL );
    1097             : # endif
    1098        2394 :   fd_log_private_thread_id_set( thread_id );
    1099             : 
    1100        2394 :   fd_log_thread_set( fd_env_strip_cmdline_cstr( pargc, pargv, "--log-thread", "FD_LOG_THREAD", NULL ) );
    1101             : 
    1102             :   /* Init our application physical ids */
    1103             :   /* We ignore any user specified cpu-id in favor of the actual core
    1104             :      assigned by the host OS.  We strip it from the command line so
    1105             :      downstream command line handling is identical from user's point of
    1106             :      view. */
    1107             : 
    1108        2394 :   fd_log_private_host_id_set( fd_env_strip_cmdline_ulong( pargc, pargv, "--log-host-id", "FD_LOG_HOST_ID", 0UL ) );
    1109             : 
    1110        2394 :   char const * host = fd_env_strip_cmdline_cstr( pargc, pargv, "--log-host", "FD_LOG_HOST", NULL );
    1111        2394 :   if( !host ) { if( !gethostname( buf, FD_LOG_NAME_MAX ) ) buf[ FD_LOG_NAME_MAX-1UL ] = '\0', host = buf; }
    1112        2394 :   fd_msan_unpoison( (void *)host, FD_LOG_NAME_MAX );
    1113        2394 :   fd_log_private_host_set( host );
    1114             : 
    1115        2394 :   fd_env_strip_cmdline_ulong( pargc, pargv, "--log-cpu-id", "FD_LOG_CPU_ID", 0UL ); /* FIXME: LOG IGNORING? */
    1116        2394 :   fd_log_private_cpu_id_set( fd_log_private_cpu_id_default() );
    1117             : 
    1118        2394 :   fd_log_cpu_set( fd_env_strip_cmdline_cstr( pargc, pargv, "--log-cpu", "FD_LOG_CPU", NULL ) );
    1119             : 
    1120             :   /* Init our thread group ids */
    1121             :   /* We ignore any user specified group id and tid in favor of the actual
    1122             :      group id and tid assigned by the host OS.  We strip it from the
    1123             :      command line so downstream command line handling is identical from
    1124             :      user's point of view. */
    1125             : 
    1126        2394 :   fd_env_strip_cmdline_ulong( pargc, pargv, "--log-group-id", "FD_LOG_GROUP_ID", 0UL ); /* FIXME: LOG IGNORING? */
    1127        2394 :   pid_t pid = getpid();
    1128        2394 :   fd_log_private_group_id_set( fd_ulong_if( pid>(pid_t)0, (ulong)pid, ULONG_MAX ) );
    1129             : 
    1130        2394 :   char const * group = fd_env_strip_cmdline_cstr( pargc, pargv, "--log-group", "FD_LOG_GROUP", NULL );
    1131        2394 : # if defined(__linux__)
    1132        2394 :   if( !group ) group = program_invocation_short_name;
    1133             : # elif defined(__FreeBSD__)
    1134             :   if( !group ) group = getprogname();
    1135             : # endif
    1136        2394 :   if( !group ) group = (pargc && pargv && (*pargc)>0) ? (*pargv)[0] : NULL;
    1137        2394 :   fd_log_private_group_set( group );
    1138             : 
    1139        2394 :   fd_env_strip_cmdline_ulong( pargc, pargv, "--log-tid", "FD_LOG_TID", 0UL ); /* FIXME: LOG IGNORING? */
    1140        2394 :   fd_log_private_tid_set( fd_log_private_tid_default() );
    1141             : 
    1142        2394 :   fd_env_strip_cmdline_ulong( pargc, pargv, "--log-user-id", "FD_LOG_USER_ID", 0UL ); /* FIXME: LOG IGNORING? */
    1143        2394 :   fd_log_private_user_id_set( fd_log_private_user_id_default() );
    1144             : 
    1145        2394 :   char const * user = fd_env_strip_cmdline_cstr( pargc, pargv, "--log-user", "FD_LOG_USER", NULL );
    1146        2394 :   if( !user )  user = getenv( "LOGNAME" );
    1147        2394 :   if( !user )  user = getlogin();
    1148        2394 :   fd_log_private_user_set( user );
    1149             : 
    1150             :   /* Configure the log */
    1151             : 
    1152        2394 :   fd_log_private_dedup = fd_env_strip_cmdline_int( pargc, pargv, "--log-dedup", "FD_LOG_DEDUP", 1 );
    1153             : 
    1154        2394 :   int colorize = 0;
    1155        2394 :   do {
    1156        2394 :     char const * cstr = fd_env_strip_cmdline_cstr( pargc, pargv, "--log-colorize", "FD_LOG_COLORIZE", NULL );
    1157        2394 :     if( cstr ) { colorize = fd_cstr_to_int( cstr ); break; }
    1158             : 
    1159        2394 :     cstr = fd_env_strip_cmdline_cstr( NULL, NULL, NULL, "COLORTERM", NULL );
    1160        2394 :     if( cstr && !strcmp( cstr, "truecolor" ) ) { colorize = 1; break; }
    1161             : 
    1162        2394 :     cstr = fd_env_strip_cmdline_cstr( NULL, NULL, NULL, "TERM", NULL );
    1163        2394 :     if( cstr && !strcmp( cstr, "xterm-256color" ) ) { colorize = 1; break; }
    1164             : 
    1165        2394 :   } while(0);
    1166           0 :   fd_log_colorize_set( colorize );
    1167             : 
    1168        2394 :   fd_log_level_logfile_set( fd_env_strip_cmdline_int( pargc, pargv, "--log-level-logfile", "FD_LOG_LEVEL_LOGFILE", 1 ) );
    1169        2394 :   fd_log_level_stderr_set ( fd_env_strip_cmdline_int( pargc, pargv, "--log-level-stderr",  "FD_LOG_LEVEL_STDERR",  2 ) );
    1170        2394 :   fd_log_level_flush_set  ( fd_env_strip_cmdline_int( pargc, pargv, "--log-level-flush",   "FD_LOG_LEVEL_FLUSH",   3 ) );
    1171        2394 :   fd_log_level_core_set   ( fd_env_strip_cmdline_int( pargc, pargv, "--log-level-core",    "FD_LOG_LEVEL_CORE",    5 ) );
    1172             : 
    1173             :   /* Hook up signal handlers */
    1174             : 
    1175        2394 :   int log_backtrace = fd_env_strip_cmdline_int( pargc, pargv, "--log-backtrace", "FD_LOG_BACKTRACE", 1 );
    1176        2394 :   if( log_backtrace ) {
    1177             : 
    1178             : #   if FD_HAS_BACKTRACE
    1179             :     /* If libgcc isn't already linked into the program when a trapped
    1180             :        signal is received by an application, calls to backtrace and
    1181             :        backtrace_symbols_fd within the signal handler can silently
    1182             :        invoke the dynamic linker, which in turn can do silent async
    1183             :        signal unsafe behavior behind our back.  We do dummy calls to
    1184             :        backtrace and backtrace_symbols_fd here to avoid dynamic linking
    1185             :        surprises in the signal handler.  (Hat tip to runtimeverification
    1186             :        for finding this.) */
    1187             : 
    1188             :     void * btrace[128];
    1189             :     int btrace_cnt = backtrace( btrace, 128 );
    1190             :     int fd = open( "/dev/null", O_WRONLY | O_APPEND );
    1191             :     if( FD_UNLIKELY( fd==-1 ) )
    1192             :       fd_log_private_fprintf_0( STDERR_FILENO,
    1193             :                                 "open( \"/dev/null\", O_WRONLY | O_APPEND ) failed (%i-%s); attempting to continue\n",
    1194             :                                 errno, fd_io_strerror( errno ) );
    1195             :     else {
    1196             :       backtrace_symbols_fd( btrace, btrace_cnt, fd );
    1197             :       if( FD_UNLIKELY( close( fd ) ) )
    1198             :         fd_log_private_fprintf_0( STDERR_FILENO,
    1199             :                                   "close( \"/dev/null\" ) failed (%i-%s); attempting to continue\n",
    1200             :                                   errno, fd_io_strerror( errno ) );
    1201             :     }
    1202             : #   endif /* FD_HAS_BACKTRACE */
    1203             : 
    1204             :     /* This is all overridable POSIX sigs whose default behavior is to
    1205             :        abort the program.  It will backtrace and then fallback to the
    1206             :        default behavior. */
    1207        2376 :     if( !fd_log_private_unclean_exit ) {
    1208        2376 :       fd_log_private_sig_trap( SIGABRT   );
    1209        2376 :       fd_log_private_sig_trap( SIGALRM   );
    1210        2376 :       fd_log_private_sig_trap( SIGFPE    );
    1211        2376 :       fd_log_private_sig_trap( SIGHUP    );
    1212        2376 :       fd_log_private_sig_trap( SIGILL    );
    1213        2376 :       fd_log_private_sig_trap( SIGINT    );
    1214        2376 :       fd_log_private_sig_trap( SIGQUIT   );
    1215        2376 :       fd_log_private_sig_trap( SIGPIPE   );
    1216        2376 :       fd_log_private_sig_trap( SIGSEGV   );
    1217        2376 :       fd_log_private_sig_trap( SIGTERM   );
    1218        2376 :       fd_log_private_sig_trap( SIGUSR1   );
    1219        2376 :       fd_log_private_sig_trap( SIGUSR2   );
    1220        2376 :       fd_log_private_sig_trap( SIGBUS    );
    1221        2376 :       fd_log_private_sig_trap( SIGPOLL   );
    1222        2376 :       fd_log_private_sig_trap( SIGPROF   );
    1223        2376 :       fd_log_private_sig_trap( SIGSYS    );
    1224        2376 :       fd_log_private_sig_trap( SIGTRAP   );
    1225        2376 :       fd_log_private_sig_trap( SIGVTALRM );
    1226        2376 :       fd_log_private_sig_trap( SIGXCPU   );
    1227        2376 :       fd_log_private_sig_trap( SIGXFSZ   );
    1228        2376 :     }
    1229        2376 :   }
    1230             : 
    1231             :   /* Hook up the permanent log */
    1232        2394 :   char const * log_path = fd_env_strip_cmdline_cstr( pargc, pargv, "--log-path", "FD_LOG_PATH", NULL );
    1233        2394 :   FD_VOLATILE( fd_log_private_fileno ) = fd_log_private_open_path( 1, log_path );
    1234             : 
    1235        2394 :   if( !fd_log_private_unclean_exit ) {
    1236        2394 :     if( atexit( fd_log_private_cleanup ) ) { fd_log_private_fprintf_0( STDERR_FILENO, "atexit failed; unable to boot\n" ); exit(1); }
    1237        2394 :   }
    1238             : 
    1239             :   /* At this point, logging online */
    1240        2394 :   if( fd_log_build_info_sz>1UL ) FD_LOG_INFO(( "fd_log: build info:\n%s", fd_log_build_info ));
    1241           0 :   else                           FD_LOG_INFO(( "fd_log: build info not available"           ));
    1242        2394 :   FD_LOG_INFO(( "fd_log: --log-path          %s",  fd_log_private_path    ));
    1243        2394 :   FD_LOG_INFO(( "fd_log: --log-dedup         %i",  fd_log_private_dedup   ));
    1244        2394 :   FD_LOG_INFO(( "fd_log: --log-colorize      %i",  fd_log_colorize()      ));
    1245        2394 :   FD_LOG_INFO(( "fd_log: --log-level-logfile %i",  fd_log_level_logfile() ));
    1246        2394 :   FD_LOG_INFO(( "fd_log: --log-level-stderr  %i",  fd_log_level_stderr()  ));
    1247        2394 :   FD_LOG_INFO(( "fd_log: --log-level-flush   %i",  fd_log_level_flush()   ));
    1248        2394 :   FD_LOG_INFO(( "fd_log: --log-level-core    %i",  fd_log_level_core()    ));
    1249        2394 :   FD_LOG_INFO(( "fd_log: --log-app-id        %lu", fd_log_app_id()        ));
    1250        2394 :   FD_LOG_INFO(( "fd_log: --log-app           %s",  fd_log_app()           ));
    1251        2394 :   FD_LOG_INFO(( "fd_log: --log-thread-id     %lu", fd_log_thread_id()     ));
    1252        2394 :   FD_LOG_INFO(( "fd_log: --log-thread        %s",  fd_log_thread()        ));
    1253        2394 :   FD_LOG_INFO(( "fd_log: --log-host-id       %lu", fd_log_host_id()       ));
    1254        2394 :   FD_LOG_INFO(( "fd_log: --log-host          %s",  fd_log_host()          ));
    1255        2394 :   FD_LOG_INFO(( "fd_log: --log-cpu-id        %lu", fd_log_cpu_id()        ));
    1256        2394 :   FD_LOG_INFO(( "fd_log: --log-cpu           %s",  fd_log_cpu()           ));
    1257        2394 :   FD_LOG_INFO(( "fd_log: --log-group-id      %lu", fd_log_group_id()      ));
    1258        2394 :   FD_LOG_INFO(( "fd_log: --log-group         %s",  fd_log_group()         ));
    1259        2394 :   FD_LOG_INFO(( "fd_log: --log-tid           %lu", fd_log_tid()           ));
    1260        2394 :   FD_LOG_INFO(( "fd_log: --log-user-id       %lu", fd_log_user_id()       ));
    1261        2394 :   FD_LOG_INFO(( "fd_log: --log-user          %s",  fd_log_user()          ));
    1262             : 
    1263        2394 :   FD_LOG_INFO(( "fd_log: boot success" ));
    1264        2394 : }
    1265             : 
    1266             : void
    1267             : fd_log_private_boot_custom( int *        lock,
    1268             :                             ulong        app_id,
    1269             :                             char const * app,
    1270             :                             ulong        thread_id,
    1271             :                             char const * thread,
    1272             :                             ulong        host_id,
    1273             :                             char const * host,
    1274             :                             ulong        cpu_id,
    1275             :                             char const * cpu,
    1276             :                             ulong        group_id,
    1277             :                             char const * group,
    1278             :                             ulong        tid,
    1279             :                             ulong        user_id,
    1280             :                             char const * user,
    1281             :                             int          dedup,
    1282             :                             int          colorize,
    1283             :                             int          level_logfile,
    1284             :                             int          level_stderr,
    1285             :                             int          level_flush,
    1286             :                             int          level_core,
    1287             :                             int          log_fd,
    1288           0 :                             char const * log_path ) {
    1289           0 :   fd_log_private_shared_lock  = lock;
    1290             : 
    1291           0 :   fd_log_private_app_id_set( app_id );
    1292           0 :   fd_log_private_app_set( app );
    1293           0 :   fd_log_private_thread_id_set( thread_id );
    1294           0 :   fd_log_thread_set( thread );
    1295           0 :   fd_log_private_host_id_set( host_id );
    1296           0 :   fd_log_private_host_set( host );
    1297           0 :   fd_log_private_cpu_id_set( cpu_id );
    1298           0 :   fd_log_cpu_set( cpu );
    1299           0 :   fd_log_private_group_id_set( group_id );
    1300           0 :   fd_log_private_group_set( group );
    1301           0 :   fd_log_private_tid_set( tid );
    1302           0 :   fd_log_private_user_id_set( user_id );
    1303           0 :   fd_log_private_user_set( user );
    1304             : 
    1305           0 :   fd_log_private_dedup = dedup;
    1306           0 :   fd_log_colorize_set( colorize );
    1307             : 
    1308           0 :   fd_log_level_logfile_set( level_logfile );
    1309           0 :   fd_log_level_stderr_set ( level_stderr );
    1310           0 :   fd_log_level_flush_set  ( level_flush );
    1311           0 :   fd_log_level_core_set   ( level_core );
    1312             : 
    1313             :   /* Hook up the permanent log */
    1314           0 :   if( -1!=log_fd ) {
    1315             :     /* Log file descriptor was set up before boot, user wishes to log there directly. */
    1316           0 :     fd_log_private_path[0] = '\0';
    1317           0 :     FD_VOLATILE( fd_log_private_fileno ) = log_fd;
    1318           0 :   } else {
    1319           0 :     FD_VOLATILE( fd_log_private_fileno ) = fd_log_private_open_path( 0, log_path );
    1320           0 :   }
    1321             : 
    1322             :   /* At this point, logging online */
    1323           0 :   if( fd_log_build_info_sz>1UL ) FD_LOG_INFO(( "fd_log: build info:\n%s", fd_log_build_info ));
    1324           0 :   else                           FD_LOG_INFO(( "fd_log: build info not available"           ));
    1325           0 :   FD_LOG_INFO(( "fd_log: --log-path          %s",  fd_log_private_path    ));
    1326           0 :   FD_LOG_INFO(( "fd_log: --log-dedup         %i",  fd_log_private_dedup   ));
    1327           0 :   FD_LOG_INFO(( "fd_log: --log-colorize      %i",  fd_log_colorize()      ));
    1328           0 :   FD_LOG_INFO(( "fd_log: --log-level-logfile %i",  fd_log_level_logfile() ));
    1329           0 :   FD_LOG_INFO(( "fd_log: --log-level-logfile %i",  fd_log_level_logfile() ));
    1330           0 :   FD_LOG_INFO(( "fd_log: --log-level-stderr  %i",  fd_log_level_stderr()  ));
    1331           0 :   FD_LOG_INFO(( "fd_log: --log-level-flush   %i",  fd_log_level_flush()   ));
    1332           0 :   FD_LOG_INFO(( "fd_log: --log-level-core    %i",  fd_log_level_core()    ));
    1333           0 :   FD_LOG_INFO(( "fd_log: --log-app-id        %lu", fd_log_app_id()        ));
    1334           0 :   FD_LOG_INFO(( "fd_log: --log-app           %s",  fd_log_app()           ));
    1335           0 :   FD_LOG_INFO(( "fd_log: --log-thread-id     %lu", fd_log_thread_id()     ));
    1336           0 :   FD_LOG_INFO(( "fd_log: --log-thread        %s",  fd_log_thread()        ));
    1337           0 :   FD_LOG_INFO(( "fd_log: --log-host-id       %lu", fd_log_host_id()       ));
    1338           0 :   FD_LOG_INFO(( "fd_log: --log-host          %s",  fd_log_host()          ));
    1339           0 :   FD_LOG_INFO(( "fd_log: --log-cpu-id        %lu", fd_log_cpu_id()        ));
    1340           0 :   FD_LOG_INFO(( "fd_log: --log-cpu           %s",  fd_log_cpu()           ));
    1341           0 :   FD_LOG_INFO(( "fd_log: --log-group-id      %lu", fd_log_group_id()      ));
    1342           0 :   FD_LOG_INFO(( "fd_log: --log-group         %s",  fd_log_group()         ));
    1343           0 :   FD_LOG_INFO(( "fd_log: --log-tid           %lu", fd_log_tid()           ));
    1344           0 :   FD_LOG_INFO(( "fd_log: --log-user-id       %lu", fd_log_user_id()       ));
    1345           0 :   FD_LOG_INFO(( "fd_log: --log-user          %s",  fd_log_user()          ));
    1346             : 
    1347           0 :   FD_LOG_INFO(( "fd_log: boot success" ));
    1348           0 : }
    1349             : 
    1350             : void
    1351        1254 : fd_log_private_halt( void ) {
    1352        1254 :   FD_LOG_INFO(( "fd_log: halting" ));
    1353             : 
    1354        1254 :   fd_log_private_cleanup();
    1355             : 
    1356             :   /* At this point, log is offline */
    1357             : 
    1358        1254 :   fd_log_private_path[0]        = '\0';
    1359             : //fd_log_private_fileno         = -1;   /* Already handled by cleanup */
    1360        1254 :   fd_log_private_dedup          = 0;
    1361             : 
    1362        1254 :   fd_log_private_level_core     = 0;
    1363        1254 :   fd_log_private_level_flush    = 0;
    1364        1254 :   fd_log_private_level_stderr   = 0;
    1365        1254 :   fd_log_private_level_logfile  = 0;
    1366        1254 :   fd_log_private_colorize       = 0;
    1367             : 
    1368        1254 :   fd_log_private_user[0]        = '\0';
    1369        1254 :   fd_log_private_user_id_init   = 0;
    1370        1254 :   fd_log_private_user_id        = 0UL;
    1371        1254 :   fd_log_private_tid_init       = 0;
    1372        1254 :   fd_log_private_tid            = 0UL;
    1373        1254 :   fd_log_private_group[0]       = '\0';
    1374        1254 :   fd_log_private_group_id       = 0UL;
    1375             : 
    1376        1254 :   fd_log_private_cpu_init       = 0;
    1377        1254 :   fd_log_private_cpu[0]         = '\0';
    1378        1254 :   fd_log_private_cpu_id_init    = 0;
    1379        1254 :   fd_log_private_cpu_id         = 0UL;
    1380        1254 :   fd_log_private_host[0]        = '\0';
    1381        1254 :   fd_log_private_host_id        = 0UL;
    1382             : 
    1383        1254 :   fd_log_private_thread_init    = 0;
    1384        1254 :   fd_log_private_thread[0]      = '\0';
    1385        1254 :   fd_log_private_thread_id_init = 0;
    1386        1254 :   fd_log_private_thread_id      = 0UL;
    1387        1254 : # if FD_HAS_THREADS
    1388        1254 :   fd_log_private_thread_id_ctr  = 0UL;
    1389        1254 : # endif
    1390        1254 :   fd_log_private_app[0]         = '\0';
    1391        1254 :   fd_log_private_app_id         = 0UL;
    1392             : 
    1393        1254 :   if( FD_LIKELY( fd_log_private_shared_lock!=fd_log_private_shared_lock_local ) ) {
    1394             :     /* Note: the below will not unmap this in any clones that also
    1395             :        inherited this mapping unless they were cloned with CLONE_VM.  In
    1396             :        cases like this, the caller is expected to handle the cleanup
    1397             :        semantics sanely (e.g. only have the parent do boot/halt and then
    1398             :        children only use log while parent has log booted). */
    1399           0 :     if( FD_UNLIKELY( munmap( fd_log_private_shared_lock, sizeof(int) ) ) )
    1400           0 :       fd_log_private_fprintf_0( STDERR_FILENO,
    1401           0 :                                 "munmap( fd_log_private_shared_lock, sizeof(int) ) failed (%i-%s); attempting to continue",
    1402           0 :                                 errno, fd_io_strerror( errno ) );
    1403           0 :   }
    1404        1254 :   fd_log_private_shared_lock = NULL;
    1405             : 
    1406             : //FD_LOG_INFO(( "fd_log: halt success" )); /* Log not online anymore */
    1407        1254 : }
    1408             : 
    1409             : #include <sys/resource.h>
    1410             : 
    1411             : ulong
    1412        2394 : fd_log_private_main_stack_sz( void ) {
    1413             : 
    1414             :   /* We are extra paranoid about what rlimit returns and we don't trust
    1415             :      environments that claim an unlimited stack size (because it just
    1416             :      isn't unlimited ... even if rlimit says otherwise ... which it will
    1417             :      if a user tries to be clever with a "ulimit -s unlimited" ... e.g.
    1418             :      tile0's stack highest address is at 128 TiB-4KiB typically on
    1419             :      modern Linux and grows down while the text / data / heap grow up
    1420             :      from 0B ... so stack size is practically always going to be << 128
    1421             :      TiB irrespective of any getrlimit claim).  TODO: It looks like
    1422             :      pthead_attr_getstack might be getrlimit based under the hood, so
    1423             :      maybe just use pthread_attr_getstack here too? */
    1424             : 
    1425        2394 :   struct rlimit rlim[1];
    1426        2394 :   int err = getrlimit( RLIMIT_STACK, rlim );
    1427        2394 :   if( FD_UNLIKELY( err ) ) {
    1428           0 :     FD_LOG_WARNING(( "fd_log: getrlimit failed (%i-%s)", errno, fd_io_strerror( errno ) ));
    1429           0 :     return 0UL;
    1430           0 :   }
    1431             : 
    1432        2394 :   ulong stack_sz = (ulong)rlim->rlim_cur;
    1433        2394 :   if( FD_UNLIKELY( (rlim->rlim_cur>rlim->rlim_max) | (rlim->rlim_max>RLIM_INFINITY    ) |
    1434        2394 :                    (rlim->rlim_cur==RLIM_INFINITY) | (rlim->rlim_cur!=(rlim_t)stack_sz) ) ) {
    1435           0 :     FD_LOG_WARNING(( "fd_log: unexpected stack limits (rlim_cur %lu, rlim_max %lu)",
    1436           0 :                      (ulong)rlim->rlim_cur, (ulong)rlim->rlim_max ));
    1437           0 :     return 0UL;
    1438           0 :   }
    1439             : 
    1440        2394 :   return stack_sz;
    1441        2394 : }
    1442             : 
    1443             : /* When pthread_setstack is not used to explicitly set the memory region
    1444             :    for a new thread's stack, pthread_create will create a memory region
    1445             :    (using either the requested size or a default size).  And, while
    1446             :    pthread allows us to set and get the size of the stack region it
    1447             :    creates and we can get a pointer into a thread's stack by just
    1448             :    declaring a stack variable in that thread and we obviously know where
    1449             :    a thread's stack is when we explicitly specify it to pthread create,
    1450             :    pthreads does not seem to provide a simple way to get the extents of
    1451             :    the stacks it creates.
    1452             : 
    1453             :    But the relationship between a pointer in the stack and the stack
    1454             :    extents is non-trival because pthreads will use some of the stack for
    1455             :    things like thread local storage (and it will not tell us how much
    1456             :    stack was used by that and this is practically only known after
    1457             :    linking is complete and then it is not simply exposed to the
    1458             :    application).
    1459             : 
    1460             :    Similar uncertainty applies to the first thread's stack.  We can
    1461             :    learn how large the stack is and get a pointer into the stack via a
    1462             :    stack variable but we have no simple way to get the extents.  And, in
    1463             :    this case on recent Linux, things like command line strings and
    1464             :    environment strings are typically allowed to consume up to 1/4 of
    1465             :    main's thread stack ... these are only known at application load
    1466             :    time.  (There is the additional caveat that the main stack might be
    1467             :    dynamically allocated such that the address space reserved for it
    1468             :    might not be backed by memory yet.)
    1469             : 
    1470             :    But, if we want to do useful run-time stack diagnostics (e.g. alloca
    1471             :    bounds checking / stack overflow prevention / etc), having explicit
    1472             :    knowledge of a thread's stack extents is very useful.  Hence the
    1473             :    below.  It would be nice if there was portable and non-horrific way
    1474             :    to do this (an even more horrific way is trigger seg faults by
    1475             :    scanning for the guard pages and then recover from the seg fault via
    1476             :    a longjmp ... shivers). */
    1477             : 
    1478             : void
    1479             : fd_log_private_stack_discover( ulong   stack_sz,
    1480             :                                ulong * _stack0,
    1481        2394 :                                ulong * _stack1 ) {
    1482             : 
    1483        2394 :   if( FD_UNLIKELY( !stack_sz ) ) {
    1484           0 :     *_stack0 = 0UL;
    1485           0 :     *_stack1 = 0UL;
    1486           0 :     return;
    1487           0 :   }
    1488             : 
    1489        2394 :   ulong stack0 = 0UL;
    1490        2394 :   ulong stack1 = 0UL;
    1491             : 
    1492             :   /* Create a variable on the caller's stack and scan the thread group's
    1493             :      memory map for the memory region holding the variable.  That should
    1494             :      be the caller's stack. */
    1495             : 
    1496        2394 :   uchar stack_mem[1];
    1497        2394 :   FD_VOLATILE( stack_mem[0] ) = (uchar)1; /* Paranoia to make sure compiler puts this in stack */
    1498        2394 :   ulong stack_addr = (ulong)stack_mem;
    1499             : 
    1500        2394 :   int filefd;
    1501        2394 :   if( FD_UNLIKELY( ( filefd = open( "/proc/self/maps", O_RDONLY ) ) < 0 ) ) {
    1502           0 :     FD_LOG_WARNING(( "open( \"/proc/self/maps\" ) failed (%i-%s)", errno, fd_io_strerror( errno ) ));
    1503           0 :     *_stack0 = 0UL;
    1504           0 :     *_stack1 = 0UL;
    1505           0 :     return;
    1506           0 :   }
    1507             : 
    1508        2394 :   char filebuf[1<<12];
    1509        2394 :   ulong filelen = 0;
    1510        2394 :   char * p = filebuf;
    1511        2394 :   int found = 0;
    1512      105382 :   while( !found ) {
    1513             : 
    1514             :     /* Scan a line */
    1515             : 
    1516      105382 :     int full_line = 0;
    1517      105382 :     char * nextp;
    1518     9846222 :     for( nextp = p; nextp < filebuf + filelen; ) {
    1519     9841503 :       if( *(nextp++) == '\n' ) {
    1520      100663 :         full_line = 1;
    1521      100663 :         break;
    1522      100663 :       }
    1523     9841503 :     }
    1524      105382 :     if( !full_line ) {
    1525             :       /* We need to read more data. First shift the old data down. */
    1526        4719 :       filelen = (ulong)((filebuf + filelen) - p);
    1527        4719 :       if( filelen )
    1528           0 :         memmove( filebuf, p, filelen );
    1529        4719 :       p = filebuf;
    1530             :       /* Now read data */
    1531        4719 :       ssize_t tlen;
    1532        4719 :       if( FD_UNLIKELY( ( tlen = read( filefd, filebuf + filelen, sizeof(filebuf)-1U-filelen ) ) < 0 ) ) {
    1533           0 :         FD_LOG_WARNING(( "read( \"/proc/self/maps\" ) failed (%i-%s)", errno, fd_io_strerror( errno ) ));
    1534           0 :         break;
    1535           0 :       }
    1536        4719 :       if( tlen == 0 ) break; /* End of file */
    1537        4719 :       filelen += (ulong)tlen;
    1538        4719 :       filebuf[filelen] = '\0'; /* For sscanf */
    1539        4719 :       continue;
    1540        4719 :     }
    1541             : 
    1542      100663 :     ulong m0;
    1543      100663 :     ulong m1;
    1544      100663 :     int r = sscanf( p, "%lx-%lx", &m0, &m1 );
    1545      100663 :     p = nextp;
    1546      100663 :     if( FD_UNLIKELY( r !=2 ) ) continue;
    1547             : 
    1548             :     /* Test if the stack allocation is in the discovered region */
    1549             : 
    1550      100663 :     if( FD_UNLIKELY( (m0<=stack_addr) & (stack_addr<m1) ) ) {
    1551        2394 :       found = 1;
    1552        2394 :       ulong msz = m1 - m0;
    1553        2394 :       if( msz==stack_sz ) { /* Memory region matches expectations */
    1554           0 :         stack0 = m0;
    1555           0 :         stack1 = m1;
    1556        2394 :       } else if( ((fd_log_group_id()==fd_log_tid()) & (msz<stack_sz)) ) {
    1557             :         /* This is the main thread, which, on recent Linux, seems to
    1558             :            just reserve address space for main's stack at program
    1559             :            start up to the application stack size limits then uses
    1560             :            page faults to dynamically back the stack with DRAM as the
    1561             :            stack grows (which is awful for performance, jitter and
    1562             :            reliability ... sigh).  This assumes stack grows down such
    1563             :            that m1 is the fixed value in this process. */
    1564        2394 :         stack0 = m1 - stack_sz;
    1565        2394 :         stack1 = m1;
    1566        2394 :       } else {
    1567           0 :         FD_LOG_WARNING(( "unexpected caller stack memory region size (got %lu bytes, expected %lu bytes)", msz, stack_sz ));
    1568             :         /* don't trust the discovered region */
    1569           0 :       }
    1570        2394 :       break;
    1571        2394 :     }
    1572             : 
    1573      100663 :   }
    1574        2394 :   if( !found )
    1575           0 :     FD_LOG_WARNING(( "unable to find stack size around address 0x%lx", stack_addr ));
    1576             : 
    1577        2394 :   close(filefd);
    1578             : 
    1579        2394 :   *_stack0 = stack0;
    1580        2394 :   *_stack1 = stack1;
    1581        2394 : }
    1582             : 
    1583             : #else
    1584             : #error "Unknown FD_LOG_STYLE"
    1585             : #endif

Generated by: LCOV version 1.14