text: /* aklog.c  -  Application Black (K) Box Logging Library
   *
   * Copyright (c) 2006,2012 Sampo Kellomaki (sampo@iki.fi), All Rights Reserved.
   * This is unpublished proprietary source code. All dissemination
   * prohibited. Contains trade secrets. NO WARRANTY. See file COPYING.
   * Special grant: aktab.h may be used with zxid open source project under
   * same licensing terms as zxid itself.
   *
   * Application Black (K) Box provides a lock-less logging facility
   * using a circular memory buffer per thread. These buffers will
   * hold recent history of application and will be part of any core
   * dump that may happen, facilitating interpretation of such core. */
  
  #include "errmac.h"
  #include "akbox.h"
  
  #include <string.h>
  #include <stdarg.h>
  #include <stdio.h>
  #include <stdlib.h>
  #include <sys/time.h>
  #include <sys/types.h>
  #include <sys/stat.h>
  #ifndef MINGW
  #include <sys/utsname.h>
  #endif
  #include <fcntl.h>
  #include <unistd.h>
  
  #ifdef LINUX
  #include <sys/sysinfo.h>
  #endif
  #ifdef SUNOS
  #include <sys/systeminfo.h>
  #endif
  #ifdef AIXOS
  #include <sys/systemcfg.h>
  #include <nlist.h>
  #endif
  
  AKEXPORT pthread_key_t akmem_pool_key;
  
  /* AFR master block is statically intialized so its always available. */
  struct ak_master_rec ak_master =
    { AK_MASTER_STAMP, 0, AK_LOGKEY_MARK, AK_ENDIAN_MARK, __DATE__, __TIME__, PTHREAD_MUTEX_INITIALIZER, 0, 0, 0, 0 };
  
  /* pthread specific data key for locating the logging buffer */
  pthread_key_t ak_buf_key;
  
  /* Called by:  main, zxbusd_main, zxcachecli_main, zxcached_main */
  void ak_init(char* argv0) {
    char buf[8192];
    int x,n=0;
    fdtype f;
  #ifdef MINGW
    pthread_mutex_init(&ak_master.ak_mutex, 0);
  #endif
  #ifdef LINUX
    mallopt(M_MMAP_MAX, 0); /* Disable use of mmap(2) in malloc(3) as mmaps do not appear in core. */
  #endif
  
    ak_master.first_sec = time(0); /** Not used in linux, maybe in a future ...*/
    /** Adding Machine INFO **/
  #ifndef INTERIXOS 
  #ifndef MINGW  
    struct utsname os_info;
    int res;
  #ifdef LINUX
    struct sysinfo system_info;
    char mem[100];
    int copied_before = 0;
    FILE * file;
    /** Getting proc info from /proc/cpuinfo **/
    if ((file = fopen("/proc/cpuinfo","rt")) != NULL ) { /** /proc/cpuinfo found **/
      while (!feof(file)){
        fgets(mem,100,file);
        if (!strncmp(mem,"processor",9))
           ak_master.ProcNum++;
        if (!copied_before && !strncmp(mem,"model name",10)){
           int j = 10;
           copied_before = 1; /** Only one copy needed **/
           while ((mem[j] != ':') && (j<100)) j++;
           j+=2; /** jump over ':' and next space **/
           strncpy(ak_master.ModelName, &mem[j], MIN(strlen(&mem[j])+1, INFO_BUF));
           ak_master.ModelName[INFO_BUF]='\0'; 
        }
      }
      fclose(file);
    }
  
    res = sysinfo(&system_info); 
    ak_master.MaxMem = system_info.totalram;
    ak_master.MaxSwap = system_info.totalswap;
    ak_master.MemUnit = system_info.mem_unit;
  #endif
  #ifdef SUNOS /** SOLARIS **/
    long resp;
    resp = sysinfo (SI_ARCHITECTURE, ak_master.ModelName, INFO_BUF);
    ak_master.ProcNum = sysconf(_SC_NPROCESSORS_ONLN);
    ak_master.first_tick = gethrtime();
  #endif
  #ifdef AIXOS
    struct nlist info;
    int fd;
    info.n_name = "_system_configuration";
    fd = open("/dev/kmem",O_RDONLY);
    knlist(&info,1,sizeof(struct nlist));
    lseek(fd,info.n_value,0);
    read(fd,&_system_configuration,sizeof(_system_configuration));
    ak_master.ProcNum  = _system_configuration.ncpus;
    ak_master.MaxMem   = _system_configuration.physmem;
    ak_master.ProcImp  = _system_configuration.implementation;
    ak_master.ProcArch = _system_configuration.architecture;
    ak_master.ProcVer  = _system_configuration.version;
    ak_master.Width    = _system_configuration.width;
    close(fd);
  #endif /* AIXOS */
    ak_master.HostId = gethostid();
    res = uname(&os_info);
    if (!res){ /** Success **/
      strncpy(ak_master.nodename, os_info.nodename, MIN(strlen(os_info.nodename)+1 ,INFO_BUF));
      strncpy(ak_master.sysname, os_info.sysname, MIN(strlen(os_info.sysname)+1 ,INFO_BUF));
      strncpy(ak_master.os_release, os_info.release, MIN(strlen(os_info.release)+1 ,INFO_BUF));
      strncpy(ak_master.os_version, os_info.version, MIN(strlen(os_info.version)+1 ,INFO_BUF));
      strncpy(ak_master.machine, os_info.machine, MIN(strlen(os_info.machine)+1 ,INFO_BUF));
    }
  #endif /* MINGW */
  #endif /* INTERIXOS */
  
  /** Machine info for windows **/
  #ifdef MINGW
    SYSTEM_INFO system_info;
    DWORD dwVersion = 0;
    DWORD dwMajorVersion = 0;
    DWORD dwMinorVersion = 0;
    DWORD dwBuild = 0;
    LPDWORD siz = INFO_BUF;
  
    QueryPerformanceFrequency(&ak_master.ticksPerSecond);
    QueryPerformanceCounter(&ak_master.first_tick);
  
    GetSystemInfo(&system_info);
    ak_master.ProcNum      = system_info.dwNumberOfProcessors;
    ak_master.ProcArch     = system_info.wProcessorArchitecture;
    ak_master.ProcType     = system_info.dwProcessorType;
    ak_master.ProcLevel    = system_info.wProcessorLevel;
    ak_master.ProcRev      = system_info.wProcessorRevision;
    
    dwVersion = GetVersion();
    /** Get os version **/
    dwMajorVersion = (DWORD)(LOBYTE(LOWORD(dwVersion)));
    dwMinorVersion = (DWORD)(HIBYTE(LOWORD(dwVersion)));
    if (dwVersion < 0x80000000)              
       dwBuild = (DWORD)(HIWORD(dwVersion));
    sprintf(ak_master.os_version, "%d.%d (%d)", dwMajorVersion, dwMinorVersion, dwBuild);
    GetComputerName( &ak_master.sysname, &siz);
   
  #endif
  
    /** End of machine info **/
  
    pthread_key_create(&ak_buf_key, 0 /* no destructor */ );
    ak_master.self = &ak_master;   /* helps to compute (or double check) offset */
    /*fprintf(stderr, "logkey(%s)\n", STRNULLCHK(ak_master.lkmark));*/
  
  #ifndef  INTERIXOS 
  #ifndef MINGW  
    /* Copy the executable file into heap memory so it will be included in an eventual
     * core that may be generated. */
    realpath(argv0, ak_master.realpath);
    ak_master.realpath[sizeof(ak_master.realpath)-1] = 0;
    f = open(argv0, O_RDONLY);
    if (f < 0) goto bad;
    x = fstat(f, &ak_master.binary_st);
    if (x < 0) goto bad;
    ak_master.binary = malloc(ak_master.binary_st.st_size);
    if (!ak_master.binary) goto bad;
    while (n < ak_master.binary_st.st_size) {
      x = read(f, ak_master.binary + n, sizeof(buf));
      if (x <= 0) goto badio;
      n += x;
    }
    closefile(f);
  #endif
  #endif
  #ifdef MINGW
    DWORD pathlength;
    char argv0exe[strlen(argv0) + 4 + 1];
    if (strstr(argv0, ".exe") == 0) {
      /* the extension was not passed; not 100% certain... */
      strcpy(argv0exe, argv0);
      strcpy(argv0exe + strlen(argv0), ".exe");
      argv0exe[strlen(argv0) + 5] = '\0';
    } else {
      strcpy(argv0exe, argv0);
    }
    if ((pathlength = GetFullPathName(argv0exe, sizeof(ak_master.realpath), ak_master.realpath, 0)) == 0) {
      errno = GetLastError();
      goto bad;
    }
    ak_master.realpath[pathlength] = 0;
    f = openfile_ro(argv0exe);
    if (f == BADFD) goto bad;
    // need to change this to GetFileSizeEx()
    DWORD filesize;
    if ((filesize = GetFileSize(f, 0)) == INVALID_FILE_SIZE) {
      errno = GetLastError();
      goto bad;
    }
    ak_master.binary_st.st_size = filesize;
    ak_master.binary = malloc(ak_master.binary_st.st_size);
    if (!ak_master.binary) goto bad;
    DWORD got;
    int howMuchToRead = 0;
    while (n < ak_master.binary_st.st_size) {
      howMuchToRead = (sizeof(buf) > ak_master.binary_st.st_size - n) ? (ak_master.binary_st.st_size - n) : sizeof(buf);
      x = ReadFile(f, ak_master.binary + n, howMuchToRead, &got, 0);
      if (x == 0) {
        errno = GetLastError();
        goto badio;
      }
      n += got;
    }
    closefile(f);
  #endif /* MINGW */
  #ifdef AFRDBG
    fprintf(stderr,"Recorded executable: %s (%d).\n", argv0, (int)ak_master.binary_st.st_size);
  #endif
    return;
   badio:
    closefile(f);
    fprintf(stderr,"Read error on executable: %s (%x/%x/%x). This installation is not supported.\n",
  	  argv0, x, n, (int)ak_master.binary_st.st_size);
    return;
   bad:
    fprintf(stderr,"Failed to read executable: %s. This installation is not supported.\n", argv0);
  }
  
  /* Creates AFR buffer explicitly. You may want to call this directly if you need
   * a special buffer other than thread buffer. */
  
  /* Called by:  ak_add_thread */
  struct ak_buf* ak_add_buf(int afr_buffer_size, int flags, char* comment)
  {
    struct ak_buf* buf = 0;
    
    pthread_mutex_lock(&ak_master.ak_mutex);
    if (ak_master.n_threads >= AK_MAX_BUFS) goto out;
    
    buf = malloc(sizeof(struct ak_buf)+afr_buffer_size);
    if (!buf) goto out;
    if (flags == 2){
      ak_master.st_buf = buf;
      sprintf(buf->stamp, AK_ST_BUFFER_STAMP);
      buf->mem_pool = 0;
    }else{
      ak_master.bufs[ak_master.n_threads] = buf;
      sprintf(buf->stamp, AK_BUFFER_STAMP, ++ak_master.n_threads);
      buf->mem_pool = (unsigned int)pthread_getspecific(akmem_pool_key);
    }
    buf->p = buf->start;
    buf->lim = (struct ak_ts*)(((char*)(buf->start)) + afr_buffer_size);
    buf->flags = flags;
    buf->wrap_around = 0;
    if (comment)
      strncpy(buf->comment, comment, AK_COMMENT_SIZE);
    else
      buf->comment[0] = 0;
    
   out:
    pthread_mutex_unlock(&ak_master.ak_mutex);
    return buf;
  }
  
  /* ak_add_thread() should be called from each thread that wishes to
   * use AFR facilities. It allocates and registers the buffer and records
   * a pointer to it as thread specific data. If this thread specific data is not
   * found, then AFR logging functions do nothing, but are still safe to call.
   * The prefix forms an important part of the buffer comment. The first letter
   * of buffer comment is used as thread role prefix in displays. E.g:
   *   T=regular worket thread, W=witer thread, F=fe polling thead, f=fe consumer thread,
   *   B=backend poller thread, b=backedn consumer thread, S=shuffler, s=static, etc. */
  
  /* Called by:  main, opt x3, thread_loop x3 */
  void ak_add_thread(int afr_buffer_size, char* prefix, int flags)
  {
    struct ak_buf* buf;
    buf = ak_add_buf(afr_buffer_size, flags, 0);
    if (!buf) return;
    buf->tid = pthread_self();
    pthread_setspecific(ak_buf_key, buf);
    sprintf(buf->comment, "%s%d", prefix, buf->tid);
  }
  
  /* Allocate a new AFR line from the circular buffer */
  
  /* Called by:  ak_buf_err_va, ak_buf_ini, ak_buf_io, ak_buf_mem, ak_buf_pdu, ak_buf_pdu_arg, ak_buf_pdu_lite, ak_buf_report, ak_buf_run, ak_buf_trace, ak_buf_ts, ak_buf_tsa */
  struct ak_ts* ak_new_line(struct ak_buf* buf, int func, int line, char* logkey)
  {
    struct ak_ts* p;
    if (!buf) return 0;
    p = buf->p;
    ++buf->p;
    if (buf->p > buf->lim) {    /* did it fit? */
      p = buf->p = buf->start;  /* wrap around */
      ++buf->p;
      ++buf->wrap_around;
    }
    p->h.func = func;
    p->h.line = line;
    p->h.logkey = logkey;
  #ifdef MINGW
    QueryPerformanceCounter(&p->h.tv);
  #endif
  #ifdef SUNOS
    p->h.tv = gethrtime();
  #endif
  #if (!defined(SUNOS)&&!defined(MINGW))
    gettimeofday(&p->h.tv, 0);
  #endif
  #ifdef AFRDBG
    fprintf(stderr, "AFR %x:%x k(%x)\t", func, line, logkey);
  #endif
    return p;
  }
  
  /* -------------- R e p o r t i n g   f u n c t i o n s -------------- */
  
  /* Report an error. If error involved PDU or ses, they will be separately reported. */
  
  /* Called by:  ak_buf_errf, ak_err_va */
  void ak_buf_err_va(struct ak_buf* buf, int func, int line, int sev, int act, int err_code, int arg, char* format, va_list pv)
  {
    struct ak_err* p = (struct ak_err*)ak_new_line(buf, func, line, (char*)arg);
    if (!p) return;
    p->raz = AK_ERR_RAZ;
    p->severity = sev;
    p->action = act;
    p->error_code = err_code;
    vsnprintf(p->msg, sizeof(p->msg), format, pv);
  #ifdef AFRDBG
    fprintf(stderr, "ERR(%x,%x)=%d `%s'\n", sev, act, err_code, p->msg);
  #endif
  }
  
  /* Called by:  ak_errf */
  void ak_err_va(int func, int line, int sev, int act, int err_code, int arg, char* format, va_list pv)
  {
    ak_buf_err_va((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, sev, act, err_code, arg, format, pv);
  }
  
  /* Called by: */
  void ak_buf_errf(struct ak_buf* buf, int func, int line, int sev, int act, int err_code, int arg, char* format, ...)
  {
    va_list pv;
    va_start(pv, format);
    ak_buf_err_va(buf, func, line, sev, act, err_code, arg, format, pv);
    va_end(pv);  
  }
  
  /* Called by: */
  void ak_errf(int func, int line, int sev, int act, int err_code, int arg, char* format, ...)
  {
    va_list pv;
    va_start(pv, format);
    ak_err_va(func, line, sev, act, err_code, arg, format, pv);
    va_end(pv);
  }
  
  /** Included info **/
  
  /* Called by:  ak_ini */
  void ak_buf_ini(struct ak_buf* buf, uint32 size, char* md5v, int func, int line, int raz, char* logkey, char* msg)
  {
    struct ak_ini* p;
    p = (struct ak_ini*)ak_new_line(buf, func, line, logkey);
    if (!p) return;
    strncpy((char *)p->md5val, md5v, sizeof(p->md5val));
    p->size = size;
    p->raz = raz;
    if (msg){
      int len = strlen(msg);
      int siz;
      len = len - sizeof(p->msg)+1;
      if (len<0) len = 0;
      siz = MIN(sizeof(p->msg)-1, strlen(&msg[len]));
      strncpy(p->msg, &msg[len], siz);
      p->msg[siz] = '\0';
    }else
      p->msg[0] = 0;
  #ifdef AFRDBG
    fprintf(stderr, "INC(%x) `%s'\n", raz, msg);
  #endif
  }
  
  /* Called by: */
  void ak_ini(struct ak_buf* buf, uint32 size, char* md5v, int func, int line, int raz, char* logkey, char* message)
  {
    ak_buf_ini(buf, size, md5v, func, line, raz, logkey, message);
  }
  
  /* Simple message with timestamp. */
  
  /* Called by:  ak_buf_tsf, ak_ts_va */
  void ak_buf_ts_va(struct ak_buf* buf, int func, int line, int raz, char* logkey, char* format, va_list pv)
  {
    char b[64];
    vsnprintf(b, sizeof(b), format, pv);
    ak_buf_ts(buf, func, line, raz, logkey, b);
  }
  
  /* Called by:  ak_tsf */
  void ak_ts_va(int func, int line, int raz, char* logkey, char* format, va_list pv)
  {
    ak_buf_ts_va((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, raz, logkey, format, pv);
  }
  
  /* Called by: */
  void ak_buf_tsf(struct ak_buf* buf, int func, int line, int raz, char* logkey, char* format, ...)
  {
    va_list pv;
    va_start(pv, format);
    ak_buf_ts_va(buf, func, line, raz, logkey, format, pv);
    va_end(pv);
  }
  
  /* Called by: */
  void ak_tsf(int func, int line, int raz, char* logkey, char* format, ...)
  {
    va_list pv;
    va_start(pv, format);
    ak_ts_va(func, line, raz, logkey, format, pv);
    va_end(pv);
  }
  
  /* Called by:  ak_buf_ts_va, ak_ts */
  void ak_buf_ts(struct ak_buf* buf, int func, int line, int raz, char* logkey, char* msg)
  {
    struct ak_ts* p;
    p = ak_new_line(buf, func, line, logkey);
    /*printf("buf=%p raz=%x func=%x line=%d %s [%s]\n", buf, raz, func, line, msg, STRNULLCHK(logkey));*/
    if (!p) return;
    p->raz = raz;
    if (msg)
      strncpy(p->msg, msg, sizeof(p->msg));
    else
      p->msg[0] = 0;
  #ifdef AFRDBG
    fprintf(stderr, "TS(%x) `%s'\n", raz, msg); // this outputs too much...
  #endif
  }
  
  /* Called by: */
  void ak_ts(int func, int line, int raz, char* logkey, char* msg) {
    ak_buf_ts((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, raz, logkey, msg);
  }
  
  /* Called by:  ak_tsa */
  void ak_buf_tsa(struct ak_buf* buf, int func, int line, int raz, char* logkey, char* msg, void* arg)
  {
    struct ak_tsa* p;
    p = (struct ak_tsa*)ak_new_line(buf, func, line, logkey);
    /*printf("buf=%p raz=%x func=%x line=%d %s [%s]\n", buf, raz, func, line, msg, STRNULLCHK(logkey));*/
    if (!p) return;
    p->raz = raz;
    if (msg)
      strncpy(p->msg, msg, sizeof(p->msg));
    else
      p->msg[0] = 0;
    p->arg = arg;
  #ifdef AFRDBG
    fprintf(stderr, "TS(%x) `%s'\n", raz, msg); // this outputs too much...
  #endif
  }
  
  /* Called by: */
  void ak_tsa(int func, int line, int raz, char* logkey, char* msg, void* arg) {
    ak_buf_tsa((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, raz, logkey, msg, arg);
  }
  
  /* Analysis of FE */
  
  /* Called by:  ak_buf_io_full, ak_buf_io_va, ak_io */
  void ak_buf_io(struct ak_buf* buf, int func, int line, int raz, char* logkey, struct io* io, char* msg)
  {
    struct ak_io* p = (struct ak_io*)ak_new_line(buf, func, line, logkey);
    if (!p) return;
    p->raz = raz;
    if (msg)
      strncpy(p->msg, msg, sizeof(p->msg));
    else
      p->msg[0] = 0;
    p->io = io;
    if (!io) return;
    p->role = io->role;
    p->proto = io->proto;
    p->fd = io->fd;
    p->flags = io->ioflags; 
    switch (io->role) {
    case IO_ROLE_FE:           /* 0 */
      p->req_head = (((struct io_fe*)io)->req_head.pdunext != ANY_PDU(&((struct io_fe*)io)->req_tail)) ? ((struct io_fe*)io)->req_head.pdunext : 0;
      p->req_tail = (((struct io_fe*)io)->req_tail.pduprev != ANY_PDU(&((struct io_fe*)io)->req_head)) ? ((struct io_fe*)io)->req_tail.pduprev : 0;
      break;
    case IO_ROLE_BE:           /* 1 */
    case IO_ROLE_LISTENER:     /* 2 */
    case IO_ROLE_UDP_LISTENER: /* 3 */
    case IO_ROLE_SUPERVISOR:   /* 4 */
    case IO_ROLE_HOPELESS:     /* 5 */
    default:
      p->req_head = 0;
      p->req_tail = 0;
    }
  #ifdef AFRDBG
    fprintf(stderr, "IO(%x) io(%x.%p) `%s'\n", raz, io->fd, io, msg);
  #endif
  }
  
  /* Called by: */
  void ak_io(int func, int line, int raz, char* logkey, struct io* io, char* msg) {
    ak_buf_io((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, raz, logkey, io, msg);
  }
  
  /* Called by:  ak_buf_iof, ak_io_va */
  void ak_buf_io_va(struct ak_buf* buf, int func, int line, int raz, char* logkey, struct io* io, char* format, va_list pv)
  {
    char b[64];
    vsnprintf(b, sizeof(b), format, pv);
    ak_buf_io(buf, func, line, raz, logkey, io, b);
  }
  
  /* Called by:  ak_iof */
  void ak_io_va(int func, int line, int raz, char* logkey, struct io* io, char* msg, va_list pv)
  {
    ak_buf_io_va((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, raz, logkey, io, msg,pv);
  }
  
  /* Called by: */
  void ak_buf_iof(struct ak_buf* buf, int func, int line, int raz, char* logkey, struct io* io, char* format, ...)
  {
    va_list pv;
    va_start(pv, format);
    ak_buf_io_va(buf, func, line, raz, logkey, io, format, pv);
    va_end(pv);
  }
  
  /* Called by: */
  void ak_iof(int func, int line, int raz, char* logkey, struct io* io, char* format, ...)
  {
    va_list pv;
    va_start(pv, format);
    ak_io_va(func, line, raz, logkey, io, format, pv);
    va_end(pv);
  }
  
  /* Called by:  ak_io_full */
  void ak_buf_io_full(struct ak_buf* buf, int func, int line, int raz, char* logkey, struct io* io, char* msg)
  {
    ak_buf_io(buf, func, line, raz, logkey, io, msg);
    if (!io) return;
    if (!io->role) {
      if (((struct io_fe*)io)->req_head.pdunext != ANY_PDU(&((struct io_fe*)io)->req_tail))
        ak_buf_pdu(buf, func, line, AK_REQ_HEAD_RAZ, logkey, ((struct io_fe*)io)->req_head.pdunext, "rqhd");
      if (((struct io_fe*)io)->req_tail.pduprev != ANY_PDU(&((struct io_fe*)io)->req_head))
        ak_buf_pdu(buf, func, line, AK_REQ_TAIL_RAZ, logkey, ((struct io_fe*)io)->req_tail.pduprev, "rqtl");
    }
  }
  
  /* Called by: */
  void ak_io_full(int func, int line, int raz, char* logkey, struct io* io, char* msg) {
    ak_buf_io_full((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, raz, logkey, io, msg);
  }
  
  /* Lite analysis of PDU */
  
  /* Called by:  ak_buf_pdu_litef, ak_pdu_lite_va */
  void ak_buf_pdu_lite_va(struct ak_buf* buf, int func, int line, int raz, char* logkey, struct any_pdu* pdu, char* format, va_list pv)
  {
    char b[64];
    vsnprintf(b, sizeof(b), format, pv);
    ak_buf_pdu_lite(buf, func, line, raz, logkey, pdu, b);
  }
  
  /* Called by:  ak_pdu_litef */
  void ak_pdu_lite_va(int func, int line, int raz, char* logkey, struct any_pdu* pdu, char* msg, va_list pv)
  {
    ak_buf_pdu_lite_va((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, raz, logkey, pdu, msg,pv);
  }
  
  /* Called by: */
  void ak_buf_pdu_litef(struct ak_buf* buf, int func, int line, int raz, char* logkey, struct any_pdu* pdu, char* format, ...)
  {
    va_list pv;
    va_start(pv, format);
    ak_buf_pdu_lite_va(buf, func, line, raz, logkey, pdu, format, pv);
    va_end(pv);
  }
  
  /* Called by: */
  void ak_pdu_litef(int func, int line, int raz, char* logkey, struct any_pdu* pdu, char* format, ...)
  {
    va_list pv;
    va_start(pv, format);
    ak_pdu_lite_va(func, line, raz, logkey, pdu, format, pv);
    va_end(pv);
  }
  
  /* dSpRAiii
   *   d = dirty
   *   S = synth_done
   *   p = parent set (i.e. PDU is a sub)
   *   R = req set (i.e. PDU is a response)
   *   A = all seen set on request
   *   i = 3 bits of inthread - 16 info (zero means not in thread) */
  #define DIGEST_PDU_FLAGS(p) \
  (((p)->inthread == 0 ? 0 : \
    ((p)->inthread < PRIO_LAST_PRIO ? 1 : ((p)->inthread - 16) & 0x7 )) \
   | ((p)->noise.s<=SYNTH_PDU?0x80:0)  /* dirty flag */  \
   | ((p)->synth_done?0x40:0)          /* has synthesized a done flag */ \
   | ((p)->parent?0x20:0)              /* has parent flag */  \
   | ((p)->req || (p)->all_seen == DETACHED_RESP_MARK ? 0x10 : ((p)->all_seen ? 0x08 : 0 )))
  
  /* Called by:  ak_buf_pdu_lite_va, ak_pdu_lite */
  void ak_buf_pdu_lite(struct ak_buf* buf, int func, int line, int raz, char* logkey, struct any_pdu* pdu, char* msg)
  {
    struct ak_pdu_lite* p = (struct ak_pdu_lite*)ak_new_line(buf, func, line, logkey);
    if (!p) return;
    p->ph.raz = raz;
    if (msg)
      strncpy(p->msg, msg, sizeof(p->msg));
    else
      p->msg[0] = 0;
    p->ph.pdu = pdu;
    if (!pdu) return;
    p->ph.pdu_op = pdu->op;
    p->ph.pdu_flags = DIGEST_PDU_FLAGS(pdu);
    p->ph.pdu_mid = pdu->req ? ((struct ldap_pdu*)pdu)->new_mid : ((struct ldap_pdu*)pdu)->mid;
  #ifdef AFRDBG
    fprintf(stderr, "PDU_LITE(%x) pdu(%x:%p) `%s'\n", raz, pdu->op, pdu, msg);
  #endif
  }
  
  /* Called by: */
  void ak_pdu_lite(int func, int line, int raz, char* logkey, struct any_pdu* pdu, char* msg)
  {
    ak_buf_pdu_lite((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, raz, logkey, pdu, msg);
  }
  
  /* Analysis of PDU */
  
  /* Called by:  ak_buf_io_full x2, ak_pdu */
  void ak_buf_pdu(struct ak_buf* buf, int func, int line, int raz, char* logkey, struct any_pdu* pdu, char* msg)
  {
    struct ak_pdu* p = (struct ak_pdu*)ak_new_line(buf, func, line, logkey);
    if (!p) return;
    p->ph.raz = raz;
    if (msg)
      strncpy(p->msg, msg, sizeof(p->msg));
    else
      p->msg[0] = 0;
    p->ph.pdu = pdu;
    if (!pdu) return;
    memcpy(&p->pdunext, pdu, sizeof(void*)*8);
    p->ph.pdu_op = pdu->op;
    p->ph.pdu_flags = DIGEST_PDU_FLAGS(pdu);
    p->ph.pdu_mid = pdu->req ? ((struct ldap_pdu*)pdu)->new_mid : ((struct ldap_pdu*)pdu)->mid;
  #ifdef AFRDBG
    fprintf(stderr, "PDU(%x) pdu(%x:%p) `%s'\n", raz, pdu->op, pdu, msg);
  #endif
  }
  
  /* Called by: */
  void ak_pdu(int func, int line, int raz, char* logkey, struct any_pdu* pdu, char* msg) {
    ak_buf_pdu((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, raz, logkey, pdu, msg);
  }
  
  /* PDU with an argument instead of a message. */
  
  /* Called by:  ak_pdu_arg */
  void ak_buf_pdu_arg(struct ak_buf* buf, int func, int line, int raz, char* logkey, struct any_pdu* pdu, int arg)
  {
    struct ak_pdu_arg* p = (struct ak_pdu_arg*)ak_new_line(buf, func, line, logkey);
    if (!p) return;
    p->ph.raz = raz;
    p->arg = arg;
    p->ph.pdu = pdu;
    if (!pdu) return;
    memcpy(&p->pdunext, pdu, sizeof(void*)*8);
    p->ph.pdu_op = pdu->op;
    p->ph.pdu_flags = DIGEST_PDU_FLAGS(pdu);
    p->ph.pdu_mid = pdu->req ? ((struct ldap_pdu*)pdu)->new_mid : ((struct ldap_pdu*)pdu)->mid;
  #ifdef AFRDBG
    fprintf(stderr, "PDU(%x) pdu(%x:%p) arg(%x)\n", raz, pdu->op, pdu, arg);
  #endif
  }
  
  /* Called by: */
  void ak_pdu_arg(int func, int line, int raz, char* logkey, struct any_pdu* pdu, int arg) {
    ak_buf_pdu_arg((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, raz, logkey, pdu, arg);
  }
  
  /* run that may have a PDU */
  
  /* Called by:  ak_run */
  void ak_buf_run(struct ak_buf* buf, int func, int line, int raz, char* logkey, struct zx_run* run, char* msg)
  {
    struct ak_run* p = (struct ak_run*)ak_new_line(buf, func, line, logkey);
    if (!p) return;
    p->ph.raz = raz;
    if (msg)
      strncpy(p->msg, msg, sizeof(p->msg));
    else
      p->msg[0] = 0;
    p->run = run;
    if (!run) return; 
    p->ph.pdu = run->pdu;
    if (!run->pdu) return;
    p->ph.pdu_op = ANY_PDU(run->pdu)->op;
    p->ph.pdu_flags = DIGEST_PDU_FLAGS(ANY_PDU(run->pdu));
    p->ph.pdu_mid = ANY_PDU(run->pdu)->req
      ? ((struct ldap_pdu*)(run->pdu))->new_mid
      : ((struct ldap_pdu*)(run->pdu))->mid;
  #ifdef AFRDBG
    fprintf(stderr, "RUN(%x) run(%p) pdu(%x:%p) `%s'\n", raz, run, ANY_PDU(run->pdu)->op, run->pdu, msg);
  #endif
  }
  
  /* Called by: */
  void ak_run(int func, int line, int raz, char* logkey, struct zx_run* run, char* msg)
  {
    ak_buf_run((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, raz, logkey, run, msg);
  }
  
  /* low level memory allocator reporting */
  
  /* Called by:  ak_mem */
  void
  ak_buf_mem(struct ak_buf* buf, int func, int line, int raz, char* logkey, void* pool, void* mem, int len, char* msg)
  {
    struct ak_mem* p = (struct ak_mem*)ak_new_line(buf, func, line, logkey);
    if (!p) return;
    p->raz = raz;
    if (msg)
      strncpy(p->msg, msg, sizeof(p->msg));
    else
      p->msg[0] = 0;
    p->pool = pool;
    p->pool_blocks = pool?((struct mem_pool*)pool)->block_counter:0;
    p->mem = mem;
    p->len = len;
  #ifdef AFRDBG
    fprintf(stderr, "MEM(%x) `%s'\n", raz, msg);
  #endif
  }
  
  /* Called by: */
  void
  ak_mem(int func, int line, int raz, char* logkey, void* pool, void* mem, int len, char* msg)
  {
    ak_buf_mem((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, raz, logkey, pool, mem, len, msg);
  }
  
  /* Reporting memory leak counters. */
  
  /* Called by:  ak_report */
  void ak_buf_report(struct ak_buf* buf, int func, int line, int raz, char* logkey, struct mem_pool* pool, char* msg)
  {
    struct ak_report* p = (struct ak_report*)ak_new_line(buf, func, line, logkey);
    if (!p) return;
    p->raz = raz;
    if (msg)
      strncpy(p->msg, msg, sizeof(p->msg));
    else
      p->msg[0] = 0;
    p->block_size = pool->block_size;
    memcpy(&p->malloc_cnt, &pool->malloc_cnt, 6*sizeof(int));
  #ifdef AFRDBG
    fprintf(stderr, "REPORT(%x) `%s'\n", raz, msg);
  #endif
  }
  
  /* Called by: */
  void ak_report(int func, int line, int raz, char* logkey, struct mem_pool* pool, char* msg)
  {
    ak_buf_report((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, raz, logkey, pool, msg);
  }
  
  /* DirectoryScript Virtual Machine Tracing */
  
  #define AK_STR_TAIL_LEN 5  /* TUNE: How much of end of string to print if whole string does not fit. */
  
  /* Called by:  ak_buf_trace x8 */
  static void ak_cpy_to_msg(char* msg, int max_len, unsigned char* s, int len)
  {
    if (len > max_len) {  /* Too long. Print start and end. */
      memcpy(msg, s, max_len - AK_STR_TAIL_LEN - 1);
      msg[max_len - AK_STR_TAIL_LEN - 1] = '.';  /* Continuation indicator. */
      memcpy(msg + max_len - AK_STR_TAIL_LEN,
  	   s + len - AK_STR_TAIL_LEN, AK_STR_TAIL_LEN);
    } else {
      memcpy(msg, s, len);
      if (len < max_len)
        msg[len] = 0;
    }
  }
  
  /* Called by:  ak_trace */
  void ak_buf_trace(struct ak_buf* buf, int raz, struct zx_run* run,
  		     struct binid* id, struct val* SP, long* PC, long sum, int tag,
  		     long R0, int T0, long R1, int T1, long R2, int T2, long R3, int T3)
  {
    int len = 0, len2 = 0, file = 0, line = 0;
    struct ginfo* gi;
    struct ak_disasm* p;
    U8 *s = NULL, *s2 = NULL;
  
    gi = run->st->prog->gi;
    if (gi && (*PC != MCOB)) {  /* figure out script file and line, if available */
      gi = gi + (PC - run->st->prog->code);
      file = gi->file;
      line = gi->line;
    }
    
    p = (struct ak_disasm*)ak_new_line(buf, file, line, (char*)PC);
    if (!p) return;
    p->raz = raz;
  
    p->recurse = run->currecurse;
    p->cur_func = id;
    p->SP = SP;
    p->reg_B = sum;
    p->tag_B = tag;
  
    switch (raz) {
    case AK_TRACE_RAZ:
      if (PC) {
        switch (*PC & AMASK) {
        case REG_0: p->tag_A = T0; p->reg_A = R0; break;
        case REG_1: p->tag_A = T1; p->reg_A = R1; break;
        case REG_2: p->tag_A = T2; p->reg_A = R2; break;
        case REG_3: p->tag_A = T3; p->reg_A = R3; break;
        }
      }
      break;
    case AK_TRACE_CALL_RAZ: p->tag_A = T0; p->reg_A = R0; break;
    }
    
    /* Try to squeeze as much useful string data as possible into the message buffer. */
    
    if (ONE_OF_2(tag, VAL_STR, VAL_LSTR) && sum) {
      switch (tag) {
      case VAL_STR:	len = S_LEN(sum);   s = S_S(sum);  break;
      case VAL_LSTR:	len = LSTR_LEN(sum);  s = LSTR_S(sum); break;
      }
      
      if (ONE_OF_2(p->tag_A, VAL_STR, VAL_LSTR) && p->reg_A) {
        /* Both */
        switch (p->tag_A) {
        case VAL_STR:     len2 = DSS_LEN(p->reg_A);   s2 = S_S(p->reg_A);  break;
        case VAL_LSTR:    len2 = LSTR_LEN(p->reg_A);  s2 = LSTR_S(p->reg_A); break;
        }
        
        if (len + len2 + 1 > (int)sizeof(p->msg)) {
  	if (len < (int)sizeof(p->msg)/2) {
  	  ak_cpy_to_msg(p->msg, sizeof(p->msg) - len - 1, s2, len2);
  	  p->msg[sizeof(p->msg) - len - 1] = '.';
  	  ak_cpy_to_msg(p->msg + sizeof(p->msg) - len, len, s, len);
  	} else if (len2 < (int)sizeof(p->msg)/2) {
  	  ak_cpy_to_msg(p->msg, len2, s2, len2);
  	  p->msg[len2] = '.';
  	  ak_cpy_to_msg(p->msg + len2 + 1, sizeof(p->msg) - len2 - 1, s, len);
  	} else {
  	  ak_cpy_to_msg(p->msg, sizeof(p->msg)/2, s2, len2);
  	  p->msg[sizeof(p->msg)/2] = '.';
  	  ak_cpy_to_msg(p->msg + sizeof(p->msg)/2 + 1, sizeof(p->msg) - sizeof(p->msg)/2 - 1,
  			   s, len);
  	}
        } else {  /* Both fit */
  	memcpy(p->msg, s2, len2);
  	p->msg[len2] = '.';
  	memcpy(p->msg+len2+1, s, len);
  	if (len + len2 + 1 < (int)sizeof(p->msg))
  	  p->msg[len + len2 + 1] = 0;
        }
        
      } else {      /* B only */
        ak_cpy_to_msg(p->msg, sizeof(p->msg), s, len);
      }
  
    } else if (ONE_OF_2(p->tag_A, VAL_STR, VAL_LSTR) && p->reg_A) {    /* A only */
      switch (p->tag_A) {
      case VAL_STR:     len = S_LEN(p->reg_A);   s = S_S(p->reg_A);  break;
      case VAL_LSTR:    len = LSTR_LEN(p->reg_A);  s = LSTR_S(p->reg_A); break;
      }
      ak_cpy_to_msg(p->msg, sizeof(p->msg), s, len);
    } else {
      /* Neither was a string */
      p->msg[0] = 0;
    }
  #ifdef AFRDBG
    fprintf(stderr, "TRACE(%x)\n", raz);
  #endif
  }
  
  /* Called by: */
  void ak_trace(int raz, struct run* run,
  		 struct binid* id, struct val* SP, long* PC, long sum, int tag,
  		 long R0, int T0, long R1, int T1, long R2, int T2, long R3, int T3) {
    ak_buf_trace((struct ak_buf*)pthread_getspecific(ak_buf_key),
  		  raz, run, id, SP, PC, sum, tag, R0,T0, R1,T1, R2,T2, R3,T3);
  }
  
  /* ------------------------------------------------------------------ */
  
  #include "errmac.h"
  
  #ifdef AK_TEST
  /* gcc -g -Wall -fmessage-length=0 -Wno-unused-label -Wno-unknown-pragmas -fno-strict-aliasing -DAK_TEST -D_REENTRANT -o aktest aklog.c -lpthread */
  
  #define PRINT_SIZE(x) printf("%5d bytes sizeof(" #x ")\n", sizeof(x))
  
  char* vals[65536];
  int adhoc = 1;
  
  /* Called by: */
  int main(int argc, char** argv)
  {
    struct ds_run run;
    struct dsio io;
    struct any_pdu pdu;
    int x, coll = 0, n_func = 0;
    x = ("abc"[2]);
    printf("x=%d\n", x);
    printf("main=%x (self)\n", AK_FUNCNO(__FUNCTION__));
    printf("main=%x\n", AK_FUNCNO("main"));
    printf("main=%d\n", AK_FUNCNO("main"));
    printf("moin=%d\n", AK_FUNCNO("moin"));
    printf("mainn=%d\n", AK_FUNCNO("mainn"));
  
  #define FUNC_DEF(f,file)  x = AK_FUNCNO(f); printf("0x%04x %5d: %s\t\t\t\t%s\n", x, x, f, vals[x]?vals[x]:""); ++n_func; if (vals[x]) ++coll; vals[x] = f;
  
  #include "../function.list"
  
    printf("%d/%d function number collisions\n", coll, n_func);
  
    PRINT_SIZE(struct ak_header);
    PRINT_SIZE(struct ak_pdu_header);
    PRINT_SIZE(struct ak_ts);
    PRINT_SIZE(struct ak_err);
    PRINT_SIZE(struct ak_pdu_lite);
    PRINT_SIZE(struct ak_pdu);
    PRINT_SIZE(struct ak_pdu_arg);
    PRINT_SIZE(struct ak_io);
    PRINT_SIZE(struct ak_buf);
    PRINT_SIZE(struct ak_master_rec);
  
    D("foo %d",1);
    DD("bar",2);
    D("foo again %d",3);
    NEVER("never %d",4);
  
    memset(&io,  0, sizeof(io));
    memset(&run, 0, sizeof(run));
    memset(&pdu, 0, sizeof(pdu));
  
    ak_init(*argv);
    ak_add_thread(4096,1);
    AK_TS(TS,  0,0);
    AK_TS(TS,  "logkey0",0);
    AK_TS(TS,  "logkey1","test string here");
  
    AK_IO(FE,  "logkey2", &io, "test2");
    AK_IOF(FE, "logkey3", &io, "test3 string %d here", 3);
    AK_IO(FE,  "logkey4", 0, "test4 string here");
    AK_IOF(FE, "logkey5", 0, "test5 string %d here", 4);
  
    AK_PDU_LITE(PDU_LITE,  "logkey6", &pdu, "test6 string here");
    AK_PDU_LITEF(PDU_LITE, "logkey7", &pdu, "test7 string %d here", 7);
    AK_PDU_LITE(PDU_LITE,  "logkey8", 0,    "test8 string here");
  
    AK_PDU(PDU,      "logkey09", &pdu, "test09 string here");
    /*AK_PDU_FULL(PDU, "logkey10", &pdu, "test10 string here");*/
    AK_PDU(PDU,      "logkey11", 0, "test11 string here");
    /*AK_PDU_FULL(PDU, "logkey12", 0, "test12 string here");*/
  
    AK_TSF(TS,  "logkey13", "test12 string %d here", 13);
  
    AK_PDU_ARG(PDU, "func14_name", &pdu, 14);
    AK_PDU_ARG(PDU, "func15_name", 0,    15);
    AK_RUN(RUN_LOCK,  "logkey16", &run, "test16 string here");
  
  #if 0
    if (!argc) return 0;
    if (!strcmp(argv[0], "-f")) {
      --argc; ++argv;
      while (argc) {
        x = AK_FUNCNO(*argv);
        printf("%d: %s %s\n", x, *argv, vals[x]?vals[x]:"-");
        fflush(stdout);
        vals[x] = *argv;
        --argc; ++argv;
      }
    }
  #endif
  
    if (argc>1 && !strcmp(argv[1], "-t")) {
      printf("staying alive so you can attach, e.g. ./ak -p %d\n", getpid());
      x = 1;
      while (1) {
        AK_TSF(TS, "looping", "iter %d", x);
        printf(".");
        sleep(1);
        ++x;
      }
    }
    
    printf("provoking seg fault so you can analyze the core\n");
    fflush(stdout);
  
    NEVERNEVER("never never %d",4);
  
    *((int*)0xffffffff) = 1;
    return 0;
  }
  
  #endif
  
  /* EOF - aklog.c */
  