LCOV - code coverage report
Current view: top level - zxid - zxlog.c (source / functions) Hit Total Coverage
Test: ZXID Code Coverage Lines: 248 326 76.1 %
Date: 2010-12-19 Functions: 11 11 100.0 %
Branches: 153 319 48.0 %

           Branch data     Line data    Source code
       1                 :            : /* zxlog.c  -  Liberty oriented logging facility with log signing and encryption
       2                 :            :  * Copyright (c) 2010 Sampo Kellomaki (sampo@iki.fi), All Rights Reserved.
       3                 :            :  * Copyright (c) 2006-2009 Symlabs (symlabs@symlabs.com), All Rights Reserved.
       4                 :            :  * Author: Sampo Kellomaki (sampo@iki.fi)
       5                 :            :  * This is confidential unpublished proprietary source code of the author.
       6                 :            :  * NO WARRANTY, not even implied warranties. Contains trade secrets.
       7                 :            :  * Distribution prohibited unless authorized in writing.
       8                 :            :  * Licensed under Apache License 2.0, see file COPYING.
       9                 :            :  * $Id: zxlog.c,v 1.32 2009-11-24 23:53:40 sampo Exp $
      10                 :            :  *
      11                 :            :  * 18.11.2006, created --Sampo
      12                 :            :  * 10.10.2007, added ipport --Sampo
      13                 :            :  * 7.10.2008,  added inline documentation --Sampo
      14                 :            :  * 29.8.2009,  added hmac chaining field --Sampo
      15                 :            :  * 12.3.2010,  added per user logging facility --Sampo
      16                 :            :  *
      17                 :            :  * See also: Logging chapter in README.zxid
      18                 :            :  */
      19                 :            : 
      20                 :            : #include "platform.h"  /* needed on Win32 for pthread_mutex_lock() et al. */
      21                 :            : 
      22                 :            : #include <fcntl.h>
      23                 :            : #include <string.h>
      24                 :            : #include <stdarg.h>
      25                 :            : #include <stdio.h>
      26                 :            : #include <stdlib.h>
      27                 :            : #include <errno.h>
      28                 :            : #include <time.h>
      29                 :            : #include <sys/types.h>
      30                 :            : #include <sys/stat.h>
      31                 :            : 
      32                 :            : #ifdef USE_OPENSSL
      33                 :            : #include <openssl/x509.h>
      34                 :            : #include <openssl/rsa.h>
      35                 :            : #include <openssl/evp.h>
      36                 :            : #include <openssl/aes.h>
      37                 :            : #endif
      38                 :            : 
      39                 :            : #include "errmac.h"
      40                 :            : #include "zxid.h"
      41                 :            : #include "zxidutil.h"  /* for zx_zlib_raw_deflate(), safe_basis_64, and name_from_path */
      42                 :            : #include "zxidconf.h"
      43                 :            : #include "c/zx-data.h"  /* Generated. If missing, run `make dep ENA_GEN=1' */
      44                 :            : 
      45                 :            : #define ZXID_LOG_DIR "log/"
      46                 :            : #define ZXLOG_TIME_FMT "%04d%02d%02d-%02d%02d%02d.%03ld"
      47                 :            : #define ZXLOG_TIME_ARG(t,usec) t.tm_year + 1900, t.tm_mon + 1, t.tm_mday, \
      48                 :            :                                t.tm_hour, t.tm_min, t.tm_sec, usec/1000
      49                 :            : 
      50                 :            : /*() Allocate memory for logging purpose.
      51                 :            :  * Generally memory allocation goes via zx_alloc() family of functions. However
      52                 :            :  * dues to special requirements of cryptographically implemeted logging,
      53                 :            :  * we maintain this special allocation function (which backends to zx_alloc()).
      54                 :            :  * Among the special features: This functin makes sure the buffer size is
      55                 :            :  * rounded up to multiple of nonce to accommodate block ciphers.
      56                 :            :  *
      57                 :            :  * This function is considered internal. Do not use unless you know what you are doing. */
      58                 :            : 
      59                 :            : /* Called by:  zxlog_write_line x3 */
      60                 :            : static char* zxlog_alloc_zbuf(zxid_conf* cf, int *zlen, char* zbuf, int len, char* sig, int nonce)
      61                 :          9 : {
      62                 :            :   char* p;
      63                 :          9 :   int siz = nonce + 2 + len + *zlen;
      64   [ +  +  +  - ]:          9 :   ROUND_UP(siz, nonce);        /* Round up to block size */
      65                 :          9 :   p = ZX_ALLOC(cf->ctx, siz);
      66         [ +  + ]:          9 :   if (nonce)
      67                 :          6 :     zx_rand(p, nonce);
      68                 :          9 :   p[nonce] = (len >> 8) & 0xff;
      69                 :          9 :   p[nonce+1] = len & 0xff;
      70         [ +  + ]:          9 :   if (len) {
      71                 :          6 :     memcpy(p+nonce+2, sig, len);
      72                 :          6 :     ZX_FREE(cf->ctx, sig);
      73                 :            :   }
      74                 :          9 :   memcpy(p+nonce+2+len, zbuf, *zlen);
      75                 :          9 :   ZX_FREE(cf->ctx, zbuf);
      76                 :          9 :   *zlen += nonce + 2 + len;
      77                 :          9 :   return p;
      78                 :            : }
      79                 :            : 
      80                 :            : /*() Write a line to a log, taking care of all formalities of locking and
      81                 :            : * observing all special options for signing and encryption of the logs.
      82                 :            : * Not usually called directly (but you can if you want to), this is the
      83                 :            : * work horse behind zxlog().
      84                 :            : *
      85                 :            : * cf::  ZXID configuration object, used for memory allocation.
      86                 :            : * c_path:: Path to the log file, as C string
      87                 :            : * encflags:: Encryption flags. See LOG_ERR or LOG_ACT configuration options in zxidconf.h
      88                 :            : * n:: length of log data
      89                 :            : * logbuf:: The data that should be logged
      90                 :            : */
      91                 :            : 
      92                 :            : /* Called by:  test_mode x12, zxlog_output x2 */
      93                 :            : void zxlog_write_line(zxid_conf* cf, char* c_path, int encflags, int n, const char* logbuf)
      94                 :       5575 : {
      95                 :            :   EVP_PKEY* log_sign_pkey;
      96                 :            :   struct rsa_st* rsa_pkey;
      97                 :            :   struct aes_key_st aes_key;
      98                 :       5575 :   int len = 0, blen, zlen;
      99                 :       5575 :   char sigletter = 'P';
     100                 :       5575 :   char encletter = 'P';
     101                 :            :   char* p;
     102                 :       5575 :   char* sig = 0;
     103                 :            :   char* zbuf;
     104                 :            :   char* b64;
     105                 :            :   char sigbuf[28+4];   /* Space for "SP " and sha1 */
     106                 :            :   char keybuf[16];
     107                 :            :   char ivec[16];
     108         [ +  + ]:       5575 :   if (n == -2)
     109                 :         12 :     n = strlen(logbuf);
     110         [ +  + ]:       5575 :   if (encflags & 0x70) {          /* Encrypt check */
     111                 :          9 :     zbuf = zx_zlib_raw_deflate(cf->ctx, n-1, logbuf, &zlen);
     112   [ +  +  -  + ]:          9 :     switch (encflags & 0x06) {     /* Sign check */
     113                 :            :     case 0x02:      /* Sx plain sha1 */
     114                 :          3 :       sigletter = 'S';
     115                 :          3 :       sig = ZX_ALLOC(cf->ctx, 20);
     116                 :          3 :       SHA1((unsigned char*)zbuf, zlen, (unsigned char*)sig);
     117                 :          3 :       len = 20;
     118                 :          3 :       break;
     119                 :            :     case 0x04:      /* Rx RSA-SHA1 signature */
     120                 :          3 :       sigletter = 'R';
     121   [ -  +  #  # ]:          3 :       LOCK(cf->mx, "logsign wrln");      
     122         [ -  + ]:          3 :       if (!(log_sign_pkey = cf->log_sign_pkey))
     123                 :          0 :         log_sign_pkey = cf->log_sign_pkey = zxid_read_private_key(cf, "logsign-nopw-cert.pem");
     124   [ -  +  #  # ]:          3 :       UNLOCK(cf->mx, "logsign wrln");      
     125         [ -  + ]:          3 :       if (!log_sign_pkey)
     126                 :          0 :         break;
     127                 :          3 :       len = zxsig_data(cf->ctx, zlen, zbuf, &sig, log_sign_pkey, "enc log line");
     128                 :          3 :       break;
     129                 :            :     case 0x06:      /* Dx DSA-SHA1 signature */
     130                 :          0 :       ERR("DSA-SHA1 sig not implemented in encrypted mode. Use RSA-SHA1 or none. %x", encflags);
     131                 :            :       break;
     132                 :            :     case 0: break;  /* Px no signing */
     133                 :            :     }
     134                 :            :     
     135   [ +  +  -  +  :          9 :     switch (encflags & 0x70) {
                   -  - ]
     136                 :            :     case 0x10:  /* xZ RFC1951 zip + safe base64 */
     137                 :          3 :       encletter = 'Z';
     138                 :          3 :       zbuf = zxlog_alloc_zbuf(cf, &zlen, zbuf, len, sig, 0);
     139                 :          3 :       break;
     140                 :            :     case 0x20:  /* xA RSA-AES */
     141                 :          3 :       encletter = 'A';
     142                 :          3 :       zbuf = zxlog_alloc_zbuf(cf, &zlen, zbuf, len, sig, 16);
     143                 :          3 :       zx_rand(keybuf, 16);
     144                 :          3 :       AES_set_encrypt_key((unsigned char*)keybuf, 128, &aes_key);
     145                 :          3 :       memcpy(ivec, zbuf, sizeof(ivec));
     146                 :          3 :       AES_cbc_encrypt((unsigned char*)zbuf+16, (unsigned char*)zbuf+16, zlen-16, &aes_key, (unsigned char*)ivec, 1);
     147         [ +  - ]:          3 :       ROUND_UP(zlen, 16);        /* Round up to block size */
     148                 :            : 
     149   [ -  +  #  # ]:          3 :       LOCK(cf->mx, "logenc wrln");
     150         [ -  + ]:          3 :       if (!cf->log_enc_cert)
     151                 :          0 :         cf->log_enc_cert = zxid_read_cert(cf, "logenc-nopw-cert.pem");
     152                 :          3 :       rsa_pkey = zx_get_rsa_pub_from_cert(cf->log_enc_cert, "log_enc_cert");
     153   [ -  +  #  # ]:          3 :       UNLOCK(cf->mx, "logenc wrln");
     154         [ -  + ]:          3 :       if (!rsa_pkey)
     155                 :          0 :         break;
     156                 :            :       
     157                 :          3 :       len = RSA_size(rsa_pkey);
     158                 :          3 :       sig = ZX_ALLOC(cf->ctx, len);
     159         [ -  + ]:          3 :       if (RSA_public_encrypt(16, (unsigned char*)keybuf, (unsigned char*)sig, rsa_pkey, RSA_PKCS1_OAEP_PADDING) < 0) {
     160                 :          0 :         ERR("RSA enc fail %x", encflags);
     161                 :          0 :         zx_report_openssl_error("zxlog rsa enc");
     162                 :          0 :         return;
     163                 :            :       }
     164                 :          3 :       p = ZX_ALLOC(cf->ctx, 2 + len + zlen);
     165                 :          3 :       p[0] = (len >> 8) & 0xff;
     166                 :          3 :       p[1] = len & 0xff;
     167                 :          3 :       memcpy(p+2, sig, len);
     168                 :          3 :       memcpy(p+2+len, zbuf, zlen);
     169                 :          3 :       ZX_FREE(cf->ctx, sig);
     170                 :          3 :       ZX_FREE(cf->ctx, zbuf);
     171                 :          3 :       zbuf = p;
     172                 :          3 :       zlen += 2 + len;
     173                 :          3 :       break;
     174                 :            :     case 0x30:  /* xT RSA-3DES */
     175                 :          0 :       encletter = 'T';
     176                 :          0 :       ERR("Enc not implemented %x", encflags);
     177                 :          0 :       break;
     178                 :            :     case 0x40:  /* xB AES */
     179                 :          3 :       encletter = 'B';
     180                 :          3 :       zbuf = zxlog_alloc_zbuf(cf, &zlen, zbuf, len, sig, 16);
     181         [ -  + ]:          3 :       if (!cf->log_symkey[0])
     182                 :          0 :         zx_get_symkey(cf, "logenc.key", cf->log_symkey);
     183                 :          3 :       AES_set_encrypt_key((unsigned char*)cf->log_symkey, 128, &aes_key);
     184                 :          3 :       memcpy(ivec, zbuf, sizeof(ivec));
     185                 :          3 :       AES_cbc_encrypt((unsigned char*)zbuf+16, (unsigned char*)zbuf+16, zlen-16, &aes_key, (unsigned char*)ivec, 1);
     186         [ +  - ]:          3 :       ROUND_UP(zlen, 16);        /* Round up to block size */
     187                 :          3 :       break;
     188                 :            :     case 0x50:  /* xU 3DES */
     189                 :          0 :       encletter = 'U';
     190                 :          0 :       ERR("Enc not implemented %x", encflags);
     191                 :          0 :       break;
     192                 :            :     default:
     193                 :          0 :       ERR("Enc not implemented %x", encflags);
     194                 :            :       break;
     195                 :            :     }
     196                 :            : 
     197                 :          9 :     blen = SIMPLE_BASE64_LEN(zlen) + 3 + 1;
     198                 :          9 :     b64 = ZX_ALLOC(cf->ctx, blen);
     199                 :          9 :     b64[0] = sigletter;
     200                 :          9 :     b64[1] = encletter;
     201                 :          9 :     b64[2] = ' ';
     202                 :          9 :     p = base64_fancy_raw(zbuf, zlen, b64+3, safe_basis_64, 1<<31, 0, 0, '.');
     203                 :          9 :     blen = p-b64 + 1;
     204                 :          9 :     *p = '\n';
     205                 :          9 :     write2_or_append_lock_c_path(c_path, 0, 0, blen, b64, "zxlog enc", SEEK_END, O_APPEND);
     206                 :          9 :     return;
     207                 :            :   }
     208                 :            : 
     209                 :            :   /* Plain text, possibly signed. */
     210                 :            : 
     211   [ +  +  -  +  :       5566 :   switch (encflags & 0x06) {
                      - ]
     212                 :            :   case 0x02:   /* SP plain sha1 */
     213                 :          1 :     strcpy(sigbuf, "SP ");
     214                 :          1 :     sha1_safe_base64(sigbuf+3, n-1, logbuf);
     215                 :          1 :     sigbuf[3+27] = ' ';
     216                 :          1 :     len = 3+27+1;
     217                 :          1 :     p = sigbuf;
     218                 :          1 :     break;
     219                 :            :   case 0x04:   /* RP RSA-SHA1 signature */
     220   [ -  +  #  # ]:          1 :     LOCK(cf->mx, "logsign wrln");      
     221         [ -  + ]:          1 :     if (!(log_sign_pkey = cf->log_sign_pkey))
     222                 :          0 :       log_sign_pkey = cf->log_sign_pkey = zxid_read_private_key(cf, "logsign-nopw-cert.pem");
     223   [ -  +  #  # ]:          1 :     UNLOCK(cf->mx, "logsign wrln");
     224         [ -  + ]:          1 :     if (!log_sign_pkey)
     225                 :          0 :       break;
     226                 :          1 :     zlen = zxsig_data(cf->ctx, n-1, logbuf, &zbuf, log_sign_pkey, "log line");
     227                 :          1 :     len = SIMPLE_BASE64_LEN(zlen) + 4;
     228                 :          1 :     sig = ZX_ALLOC(cf->ctx, len);
     229                 :          1 :     strcpy(sig, "RP ");
     230                 :          1 :     p = base64_fancy_raw(zbuf, zlen, sig+3, safe_basis_64, 1<<31, 0, 0, '.');
     231                 :          1 :     len = p-sig + 1;
     232                 :          1 :     *p = ' ';
     233                 :          1 :     p = sig;
     234                 :          1 :     break;
     235                 :            :   case 0x06:   /* DP DSA-SHA1 signature */
     236                 :          0 :     ERR("DSA-SHA1 signature not implemented %x", encflags);
     237                 :          0 :     break;
     238                 :            :   case 0:      /* Plain logging, no signing, no encryption. */
     239                 :       5564 :     len = 5;
     240                 :       5564 :     p = "PP - ";
     241                 :            :     break;
     242                 :            :   }
     243                 :       5566 :   write2_or_append_lock_c_path(c_path, len, p, n, logbuf, "zxlog sig", SEEK_END, O_APPEND);
     244         [ +  + ]:       5566 :   if (sig)
     245                 :          1 :     ZX_FREE(cf->ctx, sig);
     246                 :            : }
     247                 :            : 
     248                 :            : /*() Helper function for formatting all kinds of logs. */
     249                 :            : 
     250                 :            : static int zxlog_fmt(zxid_conf* cf,   /* 1 */
     251                 :            :                      int len, char* logbuf,
     252                 :            :                      struct timeval* ourts,  /* 2 null allowed, will use current time */
     253                 :            :                      struct timeval* srcts,  /* 3 null allowed, will use start of unix epoch... */
     254                 :            :                      const char* ipport,     /* 4 null allowed, -:- or cf->ipport if not given */
     255                 :            :                      struct zx_str* entid,   /* 5 null allowed, - if not given */
     256                 :            :                      struct zx_str* msgid,   /* 6 null allowed, - if not given */
     257                 :            :                      struct zx_str* a7nid,   /* 7 null allowed, - if not given */
     258                 :            :                      struct zx_str* nid,     /* 8 null allowed, - if not given */
     259                 :            :                      const char* sigval,     /* 9 null allowed, - if not given */
     260                 :            :                      const char* res,        /* 10 */
     261                 :            :                      const char* op,         /* 11 */
     262                 :            :                      const char* arg,        /* 12 null allowed, - if not given */
     263                 :            :                      const char* fmt,        /* 13 null allowed as format, ends the line */
     264                 :            :                      va_list ap)
     265                 :       3199 : {
     266                 :            :   int n;
     267                 :            :   char* p;
     268                 :            :   char sha1_name[28];
     269                 :            :   struct tm ot;
     270                 :            :   struct tm st;
     271                 :            :   struct timeval ourtsdefault;
     272                 :            :   struct timeval srctsdefault;
     273                 :            :   
     274                 :            :   /* Prepare values */
     275                 :            : 
     276         [ +  + ]:       3199 :   if (!ourts) {
     277                 :       1523 :     ourts = &ourtsdefault;
     278                 :       1523 :     GETTIMEOFDAY(ourts, 0);
     279                 :            :   }
     280         [ +  + ]:       3199 :   if (!srcts) {
     281                 :       1174 :     srcts = &srctsdefault;
     282                 :       1174 :     srctsdefault.tv_sec = 0;
     283                 :       1174 :     srctsdefault.tv_usec = 501000;
     284                 :            :   }
     285                 :       3199 :   GMTIME_R(ourts->tv_sec, ot);
     286                 :       3199 :   GMTIME_R(srcts->tv_sec, st);
     287                 :            :   
     288   [ +  +  +  -  :       5110 :   if (entid && entid->len && entid->s) {
                   +  - ]
     289                 :       1911 :     sha1_safe_base64(sha1_name, entid->len, entid->s);
     290                 :       1911 :     sha1_name[27] = 0;
     291                 :            :   } else {
     292                 :       1288 :     sha1_name[0] = '-';
     293                 :       1288 :     sha1_name[1] = 0;
     294                 :            :   }
     295                 :            :   
     296         [ +  + ]:       3199 :   if (!ipport) {
     297                 :       3012 :     ipport = cf->ipport;
     298         [ +  + ]:       3012 :     if (!ipport)
     299                 :        378 :       ipport = "-:-";
     300                 :            :   }
     301                 :            :   
     302                 :            :   /* Format */
     303                 :            :   
     304   [ +  +  +  +  :       3199 :   n = snprintf(logbuf, len-3, ZXLOG_TIME_FMT " " ZXLOG_TIME_FMT
          +  +  +  +  +  
          +  +  +  +  +  
                   +  + ]
     305                 :            :                " %s %s"  /* ipport  sha1_name-of-ent */
     306                 :            :                " %.*s"
     307                 :            :                " %.*s"
     308                 :            :                " %.*s"
     309                 :            :                " %s %s %s %s %s ",
     310                 :            :                ZXLOG_TIME_ARG(ot, ourts->tv_usec), ZXLOG_TIME_ARG(st, srcts->tv_usec),
     311                 :            :                ipport, sha1_name,
     312                 :            :                msgid?msgid->len:1, msgid?msgid->s:"-",
     313                 :            :                a7nid?a7nid->len:1, a7nid?a7nid->s:"-",
     314                 :            :                nid?nid->len:1,     nid?nid->s:"-",
     315                 :            :                zx_instance, STRNULLCHKD(sigval), res, op, arg?arg:"-");
     316                 :       3199 :   logbuf[len-1] = 0; /* must terminate manually as on win32 nul is not guaranteed */
     317   [ +  -  -  + ]:       3199 :   if (n <= 0 || n >= len-3) {
     318         [ #  # ]:          0 :     if (n < 0) {
     319                 :          0 :       perror("snprintf");
     320   [ #  #  #  # ]:          0 :       D("Broken snprintf? Impossible to compute length of string. Be sure to `export LANG=C' if you get errors about multibyte characters. Length returned: %d", n);
     321                 :            :     }
     322   [ #  #  #  # ]:          0 :     D("Log buffer too short: %d chars needed", n);
     323         [ #  # ]:          0 :     if (n <= 0)
     324                 :          0 :       n = 0;
     325                 :            :     else
     326                 :          0 :       n = len-3;
     327                 :            :   } else { /* Space left: try printing the format string as well! */
     328                 :       3199 :     p = logbuf+n;
     329   [ +  +  +  + ]:       3948 :     if (fmt && fmt[0]) {
     330                 :        749 :       n = vsnprintf(p, len-n-2, fmt, ap);
     331                 :        749 :       logbuf[len-1] = 0;  /* must terminate manually as on win32 nul term is not guaranteed */
     332   [ +  -  -  + ]:        749 :       if (n <= 0 || n >= len-(p-logbuf)-2) {
     333         [ #  # ]:          0 :         if (n < 0) {
     334                 :          0 :           perror("vsnprintf");
     335   [ #  #  #  # ]:          0 :           D("Broken vsnprintf? Impossible to compute length of string. Be sure to `export LANG=C' if you get errors about multibyte characters. Length returned: %d", n);
     336                 :            :         }
     337   [ #  #  #  # ]:          0 :         D("Log buffer truncated during format print: %d chars needed", n);
     338         [ #  # ]:          0 :         if (n <= 0)
     339                 :          0 :           n = p-logbuf;
     340                 :            :         else
     341                 :          0 :           n = len-(p-logbuf)-2;
     342                 :            :       } else
     343                 :        749 :         n += p-logbuf;
     344                 :            :     } else {
     345                 :       2450 :       logbuf[n++] = '-';
     346                 :            :     }
     347                 :            :   }
     348                 :       3199 :   logbuf[n++] = '\n';
     349                 :       3199 :   logbuf[n] = 0;
     350                 :            :   /*logbuf[len-1] = 0;*/
     351                 :       3199 :   return n;
     352                 :            : }
     353                 :            : 
     354                 :            : /*() Figure out which log file should receive the message */
     355                 :            : 
     356                 :            : /* Called by: */
     357                 :            : static int zxlog_output(zxid_conf* cf, int n, const char* logbuf, const char* res)
     358                 :       2364 : {
     359                 :            :   char c_path[ZXID_MAX_BUF];
     360                 :            :   DD("LOG(%.*s)", n-1, logbuf);
     361   [ -  +  #  #  :       2364 :   if ((cf->log_err_in_act || res[0] == 'K') && cf->log_act) {
                   +  - ]
     362                 :       2364 :     name_from_path(c_path, sizeof(c_path), "%s" ZXID_LOG_DIR "act", cf->path);
     363                 :       2364 :     zxlog_write_line(cf, c_path, cf->log_act, n, logbuf);
     364                 :            :   }
     365   [ +  -  -  +  :       2364 :   if (cf->log_err && (cf->log_act_in_err || res[0] != 'K')) {  /* If enabled, everything goes to err */
                   #  # ]
     366                 :       2364 :     name_from_path(c_path, sizeof(c_path), "%s" ZXID_LOG_DIR "err", cf->path);
     367                 :       2364 :     zxlog_write_line(cf, c_path, cf->log_err, n, logbuf);
     368                 :            :   }
     369                 :       2364 :   return 0;
     370                 :            : }
     371                 :            : 
     372                 :            : /*(i) Log to activity and/or error log depending on ~res~ and configuration settings.
     373                 :            :  * This is the main audit logging function you should call. Please see <<link:../../html/zxid-log.html: zxid-log.pd>>
     374                 :            :  * for detailed description of the log format and features. See <<link:../../html/zxid-conf.html: zxid-conf.pd>> for
     375                 :            :  * configuration options governing the logging. (*** check the links)
     376                 :            :  *
     377                 :            :  * Proper audit trail is essential for any high value transactions based on SSO. Also
     378                 :            :  * some SAML protocol Processing Rules, such as duplicate detection, depend on the
     379                 :            :  * logging.
     380                 :            :  *
     381                 :            :  * cf     (1)::  ZXID configuration object, used for configuration options and memory allocation
     382                 :            :  * ourts  (2)::  Timestamp as observed by localhost. Typically the wall clock
     383                 :            :  *     time. See gettimeofday(3)
     384                 :            :  * srcts  (3)::  Timestamp claimed by the message to which the log entry pertains
     385                 :            :  * ipport (4)::  IP address and port number from which the message appears to have originated
     386                 :            :  * entid  (5)::  Entity ID to which the message pertains, usually the issuer. Null ok.
     387                 :            :  * msgid  (6)::  Message ID, can be used for correlation to establish audit trail continuity
     388                 :            :  *     from request to response. Null ok.
     389                 :            :  * a7nid  (7)::  Assertion ID, if message contained assertion (outermost and first
     390                 :            :  *     assertion if there are multiple relevant assertions). Null ok.
     391                 :            :  * nid    (8)::  Name ID pertaining to the message
     392                 :            :  * sigval (9)::  Signature validation letters
     393                 :            :  * res   (10)::  Result letters
     394                 :            :  * op    (11)::  Operation code for the message
     395                 :            :  * arg   (12)::  Operation specific argument
     396                 :            :  * fmt, ...  ::  Free format message conveying additional information
     397                 :            :  * return:: 0 on success, nonzero on failure (often ignored as zxlog() is very
     398                 :            :  *     robust and rarely fails - and when it does, situation is so hopeless that
     399                 :            :  *     you would not be able to report its failure anyway)
     400                 :            :  */
     401                 :            : 
     402                 :            : /* Called by:  zxid_an_page_cf, zxid_anoint_sso_a7n, zxid_anoint_sso_resp, zxid_chk_sig, zxid_decode_redir_or_post x2, zxid_fed_mgmt_cf, zxid_get_ent_by_sha1_name, zxid_get_ent_ss, zxid_get_meta x2, zxid_idp_dispatch, zxid_idp_select_zxstr_cf_cgi, zxid_idp_soap_dispatch x2, zxid_idp_soap_parse, zxid_parse_conf_raw, zxid_parse_meta, zxid_saml_ok x2, zxid_simple_render_ses, zxid_simple_ses_active_cf, zxid_sp_anon_finalize, zxid_sp_deref_art x5, zxid_sp_dig_sso_a7n x2, zxid_sp_dispatch, zxid_sp_meta, zxid_sp_mni_redir, zxid_sp_mni_soap, zxid_sp_slo_redir, zxid_sp_slo_soap, zxid_sp_soap_dispatch x2, zxid_sp_soap_parse, zxid_sp_sso_finalize x2, zxid_start_sso_url x3 */
     403                 :            : int zxlog(zxid_conf* cf,   /* 1 */
     404                 :            :           struct timeval* ourts,  /* 2 null allowed, will use current time */
     405                 :            :           struct timeval* srcts,  /* 3 null allowed, will use start of unix epoch + 501 usec */
     406                 :            :           const char* ipport,     /* 4 null allowed, -:- or cf->ipport if not given */
     407                 :            :           struct zx_str* entid,   /* 5 null allowed, - if not given */
     408                 :            :           struct zx_str* msgid,   /* 6 null allowed, - if not given */
     409                 :            :           struct zx_str* a7nid,   /* 7 null allowed, - if not given */
     410                 :            :           struct zx_str* nid,     /* 8 null allowed, - if not given */
     411                 :            :           const char* sigval,     /* 9 null allowed, - if not given */
     412                 :            :           const char* res,        /* 10 */
     413                 :            :           const char* op,         /* 11 */
     414                 :            :           const char* arg,        /* 12 null allowed, - if not given */
     415                 :            :           const char* fmt, ...)   /* 13 null allowed as format, ends the line w/o further ado */
     416                 :       2165 : {
     417                 :            :   int n;
     418                 :            :   char logbuf[1024];
     419                 :            :   va_list ap;
     420                 :            :   
     421                 :            :   /* Avoid computation if logging is hopeless. */
     422                 :            :   
     423   [ -  +  #  #  :       2165 :   if (!((cf->log_err_in_act || res[0] == 'K') && cf->log_act)
          -  +  #  #  #  
                      # ]
     424                 :            :       && !(cf->log_err && res[0] != 'K')) {
     425                 :          0 :     return 0;
     426                 :            :   }
     427                 :            : 
     428                 :       2165 :   va_start(ap, fmt);
     429                 :       2165 :   n = zxlog_fmt(cf, sizeof(logbuf), logbuf,
     430                 :            :                 ourts, srcts, ipport, entid, msgid, a7nid, nid, sigval, res,
     431                 :            :                 op, arg, fmt, ap);
     432                 :       2165 :   va_end(ap);
     433                 :       2165 :   return zxlog_output(cf, n, logbuf, res);
     434                 :            : }
     435                 :            : 
     436                 :            : /*() Log to activity and/or error log depending on ~res~ and configuration settings.
     437                 :            :  * This variant uses the ses object to extract many of the log fields. These fields
     438                 :            :  * were populated to ses by zxid_wsp_validate()
     439                 :            :  */
     440                 :            : 
     441                 :            : int zxlogwsp(zxid_conf* cf,    /* 1 */
     442                 :            :              zxid_ses* ses,    /* 2 */
     443                 :            :              const char* res,  /* 3 */
     444                 :            :              const char* op,   /* 4 */
     445                 :            :              const char* arg,  /* 5 null allowed, - if not given */
     446                 :            :              const char* fmt, ...)   /* 13 null allowed as format, ends the line w/o further ado */
     447                 :        199 : {
     448                 :            :   int n;
     449                 :            :   char logbuf[1024];
     450                 :            :   va_list ap;
     451                 :            :   
     452                 :            :   /* Avoid computation if logging is hopeless. */
     453                 :            :   
     454   [ -  +  #  #  :        199 :   if (!((cf->log_err_in_act || res[0] == 'K') && cf->log_act)
          -  +  #  #  #  
                      # ]
     455                 :            :       && !(cf->log_err && res[0] != 'K')) {
     456                 :          0 :     return 0;
     457                 :            :   }
     458                 :            : 
     459                 :        199 :   va_start(ap, fmt);
     460   [ +  -  -  +  :        199 :   n = zxlog_fmt(cf, sizeof(logbuf), logbuf,
          +  -  +  +  +  
          -  +  -  +  -  
          +  +  +  -  +  
             -  +  -  +  
                      - ]
     461                 :            :                 0, ses?&ses->srcts:0, ses?ses->ipport:0,
     462                 :            :                 ses?ses->issuer:0, ses?ses->wsp_msgid:0,
     463                 :            :                 ses&&ses->a7n?&ses->a7n->ID->g:0,
     464                 :            :                 ses?ZX_GET_CONTENT(ses->nameid):0,
     465                 :            :                 ses&&ses->sigres?&ses->sigres:"-", res,
     466                 :            :                 op, arg, fmt, ap);
     467                 :        199 :   va_end(ap);
     468                 :        199 :   return zxlog_output(cf, n, logbuf, res);
     469                 :            : }
     470                 :            : 
     471                 :            : /*() Log user specific data */
     472                 :            : 
     473                 :            : int zxlogusr(zxid_conf* cf,   /* 1 */
     474                 :            :              const char* uid,
     475                 :            :              struct timeval* ourts,  /* 2 null allowed, will use current time */
     476                 :            :              struct timeval* srcts,  /* 3 null allowed, will use start of unix epoch + 501 usec */
     477                 :            :              const char* ipport,     /* 4 null allowed, -:- or cf->ipport if not given */
     478                 :            :              struct zx_str* entid,   /* 5 null allowed, - if not given */
     479                 :            :              struct zx_str* msgid,   /* 6 null allowed, - if not given */
     480                 :            :              struct zx_str* a7nid,   /* 7 null allowed, - if not given */
     481                 :            :              struct zx_str* nid,     /* 8 null allowed, - if not given */
     482                 :            :              const char* sigval,     /* 9 null allowed, - if not given */
     483                 :            :              const char* res,        /* 10 */
     484                 :            :              const char* op,         /* 11 */
     485                 :            :              const char* arg,        /* 12 null allowed, - if not given */
     486                 :            :              const char* fmt, ...)   /* 13 null allowed as format, ends the line w/o further ado */
     487                 :        835 : {
     488                 :            :   int n;
     489                 :            :   char logbuf[1024];
     490                 :            :   char c_path[ZXID_MAX_BUF];
     491                 :            :   va_list ap;
     492                 :            : 
     493         [ -  + ]:        835 :   if (!uid) {
     494                 :          0 :     ERR("NULL uid argument %p", cf);
     495                 :          0 :     return 1;
     496                 :            :   }
     497                 :            : 
     498                 :        835 :   va_start(ap, fmt);
     499                 :        835 :   n = zxlog_fmt(cf, sizeof(logbuf), logbuf,
     500                 :            :                 ourts, srcts, ipport, entid, msgid, a7nid, nid, sigval, res,
     501                 :            :                 op, arg, fmt, ap);
     502                 :        835 :   va_end(ap);
     503                 :            : 
     504                 :            :   /* Output stage */
     505                 :            :   
     506   [ +  -  -  + ]:        835 :   D("UID(%s) LOG(%.*s)", uid, n-1, logbuf);
     507                 :        835 :   name_from_path(c_path, sizeof(c_path), "%s" ZXID_UID_DIR "%s/.log", cf->path, uid);
     508                 :        835 :   zxlog_write_line(cf, c_path, cf->log_act, n, logbuf);
     509                 :        835 :   return 0;
     510                 :            : }
     511                 :            : 
     512                 :            : /*() Compute path for logging. Optionally attempt to create the necessary
     513                 :            :  * directories if they are missing (you should do `make dirs' rather than
     514                 :            :  * depend on this).
     515                 :            :  *
     516                 :            :  * cf::     ZXID configuration object uded for deternining root if the logging
     517                 :            :  *     hierarchy, see PATH configuration option. Also used for memory allocation.
     518                 :            :  * entid::  Issuer or target entity ID. For wire messages the URL.
     519                 :            :  * objid::  AssertionID or MessageID. For wire messages the payload.
     520                 :            :  * dir::    Directory prefix indicating branch of audit trail ("rely/" or "issue/")
     521                 :            :  * kind::   Kind of object, used as path component ("/a7n/" or "/msg/")
     522                 :            :  * create_dirs::  Flag: should creating directories be attempted. Usually 1 if intent
     523                 :            :  *     is to write a file to the computed path. Usually 0 if the intent is to read.
     524                 :            :  * return:: The path, as zx_str or 0 if failure */
     525                 :            : 
     526                 :            : /* Called by:  zxid_anoint_a7n, zxid_anoint_sso_resp, zxid_decode_redir_or_post x2, zxid_saml2_post_enc, zxid_saml2_redir_enc, zxid_soap_cgi_resp_body, zxid_sp_sso_finalize, zxid_wsc_valid_re_env, zxid_wsf_validate_a7n, zxid_wsp_validate */
     527                 :            : struct zx_str* zxlog_path(zxid_conf* cf,
     528                 :            :                           struct zx_str* entid,  /* issuer or target entity ID */
     529                 :            :                           struct zx_str* objid,  /* AssertionID or MessageID */
     530                 :            :                           const char* dir,       /* rely/ or issue/ */
     531                 :            :                           const char* kind,      /* /a7n/ or /msg/ */
     532                 :            :                           int create_dirs)
     533                 :       1060 : {
     534                 :            :   struct stat st;
     535                 :       1060 :   int dir_len = strlen(dir);
     536                 :       1060 :   int kind_len = strlen(kind);
     537                 :       1060 :   int len = cf->path_len + sizeof("log/")-1 + dir_len + 27 + kind_len + 27;
     538                 :       1060 :   char* s = ZX_ALLOC(cf->ctx, len+1);
     539                 :            :   char* p;
     540                 :            : 
     541         [ +  + ]:       1060 :   if (!entid) {
     542   [ +  -  +  - ]:         18 :     ERR("No EntityID supplied %p dir(%s) kind(%s)", objid, STRNULLCHK(dir), STRNULLCHK(kind));
     543                 :         18 :     ZX_FREE(cf->ctx, s);
     544                 :         18 :     return 0;
     545                 :            :   }
     546                 :            : 
     547                 :       1042 :   memcpy(s, cf->path, cf->path_len);
     548                 :       1042 :   p = s + cf->path_len;
     549                 :       1042 :   memcpy(p, "log/", sizeof("log/"));
     550                 :       1042 :   p += sizeof("log/")-1;
     551         [ -  + ]:       1042 :   if (stat(s, &st)) {
     552         [ #  # ]:          0 :     ERR("zxid log directory missing path(%s): giving up (%d %s)", s, errno, STRERROR(errno));
     553                 :          0 :     ZX_FREE(cf->ctx, s);
     554                 :          0 :     return 0;
     555                 :            :   }
     556                 :            :   
     557                 :       1042 :   memcpy(p, dir, dir_len+1);
     558                 :       1042 :   p += dir_len;
     559         [ -  + ]:       1042 :   if (stat(s, &st)) {
     560         [ #  # ]:          0 :     if (create_dirs) {
     561         [ #  # ]:          0 :       if (MKDIR(s, 0777)) {
     562         [ #  # ]:          0 :         ERR("mkdir path(%s) failed: %d %s", s, errno, STRERROR(errno));
     563                 :          0 :         ZX_FREE(cf->ctx, s);
     564                 :          0 :         return 0;       
     565                 :            :       }
     566                 :            :     } else {
     567         [ #  # ]:          0 :       ERR("directory missing path(%s) and no create_dirs (%d %s)", s, errno, STRERROR(errno));
     568                 :          0 :       ZX_FREE(cf->ctx, s);
     569                 :          0 :       return 0;
     570                 :            :     }
     571                 :            :   }
     572                 :            :   
     573                 :       1042 :   sha1_safe_base64(p, entid->len, entid->s);
     574                 :       1042 :   p[27] = 0;
     575                 :       1042 :   p+=27;
     576         [ -  + ]:       1042 :   if (stat(s, &st)) {
     577         [ #  # ]:          0 :     if (create_dirs) {
     578         [ #  # ]:          0 :       if (MKDIR(s, 0777)) {
     579         [ #  # ]:          0 :         ERR("mkdir path(%s) failed: %d %s", s, errno, STRERROR(errno));
     580                 :          0 :         ZX_FREE(cf->ctx, s);
     581                 :          0 :         return 0;       
     582                 :            :       }
     583                 :            :     } else {
     584         [ #  # ]:          0 :       ERR("directory missing path(%s) and no create_dirs (%d %s)", s, errno, STRERROR(errno));
     585                 :          0 :       ZX_FREE(cf->ctx, s);
     586                 :          0 :       return 0;
     587                 :            :     }
     588                 :            :   }
     589                 :            :   
     590                 :       1042 :   memcpy(p, kind, kind_len+1);
     591                 :       1042 :   p += kind_len;
     592         [ -  + ]:       1042 :   if (stat(s, &st)) {
     593         [ #  # ]:          0 :     if (create_dirs) {
     594         [ #  # ]:          0 :       if (MKDIR(s, 0777)) {
     595         [ #  # ]:          0 :         ERR("mkdir path(%s) failed: %d %s", s, errno, STRERROR(errno));
     596                 :          0 :         ZX_FREE(cf->ctx, s);
     597                 :          0 :         return 0;       
     598                 :            :       }
     599                 :            :     } else {
     600         [ #  # ]:          0 :       ERR("zxid directory missing path(%s) and no create_dirs (%d %s)", s, errno, STRERROR(errno));
     601                 :          0 :       ZX_FREE(cf->ctx, s);
     602                 :          0 :       return 0;
     603                 :            :     }
     604                 :            :   }
     605                 :            :   
     606                 :       1042 :   sha1_safe_base64(p, objid->len, objid->s);
     607                 :       1042 :   p[27] = 0;
     608                 :       1042 :   p+=27;
     609                 :       1042 :   return zx_ref_len_str(cf->ctx, len, s);
     610                 :            : }
     611                 :            : 
     612                 :            : /*() Check if file by path already exist.
     613                 :            :  * Since each uniquely ID'd object has unique path, mere existence of a file
     614                 :            :  * serves as duplicate ID check. This is used to satisfy some SAML processing rule
     615                 :            :  * requirements such as duplicate ID check for assertions.
     616                 :            :  *
     617                 :            :  * cf::      ZXID configuration object, used for memory allocation
     618                 :            :  * path::    Path where file is to be written, usually from zxlog_path()
     619                 :            :  * logkey::  String that will help to identify reason of failure
     620                 :            :  * return::  0 if no duplicate (success), 1 if duplicate (failure)
     621                 :            :  */
     622                 :            : 
     623                 :            : /* Called by:  zxid_anoint_a7n, zxid_anoint_sso_resp, zxid_decode_redir_or_post x2, zxid_saml2_post_enc, zxid_saml2_redir_enc, zxid_soap_cgi_resp_body, zxid_sp_sso_finalize, zxid_wsc_valid_re_env, zxid_wsf_validate_a7n, zxid_wsp_validate */
     624                 :            : int zxlog_dup_check(zxid_conf* cf, struct zx_str* path, const char* logkey)
     625                 :       1042 : {
     626                 :            :   struct stat st;
     627                 :            :   /* We need a c path, but get zx_str. However, the zx_str will come from zxlog_path()
     628                 :            :    * so we should be having the nul termination as needed. Just checking. */
     629   [ -  +  #  # ]:       1042 :   ASSERTOP(path->s[path->len], ==, 0);
     630         [ +  + ]:       1042 :   if (!stat(path->s, &st)) {
     631                 :         11 :     ERR("Duplicate %s path(%.*s)", logkey, path->len, path->s);
     632                 :         11 :     zxlog(cf, 0, 0, 0, 0, 0, 0, 0, "N", "C", "EDUP", path->s, "%s", logkey);
     633                 :         11 :     return 1;
     634                 :            :   }
     635                 :       1031 :   return 0;
     636                 :            : }
     637                 :            : 
     638                 :            : /*() Write a blob of content to log file according to logflag (see zxidconf.h). If
     639                 :            :  * the file already exists, i.e. there is a duplicate, the data is simply appended.
     640                 :            :  * When logging objects such as assertions, the duplicate check should be done
     641                 :            :  * as preprocessing step, see example below.
     642                 :            :  *
     643                 :            :  * cf::      ZXID configuration object, used for memory allocation
     644                 :            :  * logflag:: 0 if logging should not happen, 1 for normal logging, other values reserved
     645                 :            :  * path::    Path where file is to be written, usually from zxlog_path()
     646                 :            :  * blob::    The data to be logged.
     647                 :            :  * lk::      Log key. Indicates which part of the program invoked the logging function.
     648                 :            :  * return::  0 if no log written (failure or logflag false), 1 if log written. Often ignored.
     649                 :            :  *
     650                 :            :  * *Example*
     651                 :            :  *
     652                 :            :  *   logpath = zxlog_path(cf, issuer, a7n->ID, "rely/", "/a7n/", 1);
     653                 :            :  *   if (logpath) {
     654                 :            :  *     if (zxlog_dup_check(cf, logpath, "SSO assertion")) {
     655                 :            :  *       zxlog_blob(cf, cf->log_rely_a7n, logpath, zx_easy_enc_elem_sig(cf,&a7n->gg), "E");
     656                 :            :  *       goto erro;
     657                 :            :  *     }
     658                 :            :  *     zxlog_blob(cf, cf->log_rely_a7n, logpath, zx_easy_enc_elem_sig(cf, a7n), "OK");
     659                 :            :  *   }
     660                 :            :  *
     661                 :            :  * In the above example we determine the logpath and check for the duplicate and then log even
     662                 :            :  * if duplicate. The logic of this is that in case of duplicate, the audit trail
     663                 :            :  * captures both the original and the duplicate assertion (the logging is an append),
     664                 :            :  * which may have forensic value. */
     665                 :            : 
     666                 :            : /* Called by:  zxid_anoint_a7n x2, zxid_anoint_sso_resp x2, zxid_decode_redir_or_post x2, zxid_saml2_post_enc x2, zxid_saml2_redir_enc x2, zxid_soap_cgi_resp_body x2, zxid_sp_sso_finalize x2, zxid_wsc_valid_re_env x2, zxid_wsf_validate_a7n x2, zxid_wsp_validate x2 */
     667                 :            : int zxlog_blob(zxid_conf* cf, int logflag, struct zx_str* path, struct zx_str* blob, const char* lk)
     668                 :       1042 : {
     669   [ +  -  -  + ]:       1042 :   if (!logflag || !blob)
     670                 :          0 :     return 0;
     671         [ -  + ]:       1042 :   if (logflag != 1) {
     672                 :          0 :     ERR("Unimplemented blob logging format: %x", logflag);
     673                 :          0 :     return 0;
     674                 :            :   }
     675                 :            :   
     676                 :            :   /* We need a c path, but get zx_str. However, the zx_str will come from zxlog_path()
     677                 :            :    * so we should be having the nul termination as needed. Just checking. */
     678   [ +  +  -  + ]:       1042 :   D("%s: LOGBLOB15(%.*s) len=%d path(%.*s)", lk, MIN(blob->len,15), blob->s, blob->len, path->len, path->s);
     679                 :            :   DD("%s: LOGBLOB(%.*s)", lk, blob->len, blob->s);
     680   [ -  +  #  # ]:       1042 :   ASSERTOP(path->s[path->len], ==, 0);
     681         [ -  + ]:       1042 :   if (!write2_or_append_lock_c_path(path->s, blob->len, blob->s, 0, 0, "zxlog blob", SEEK_END,O_APPEND)) {
     682                 :          0 :     zxlog(cf, 0, 0, 0, 0, 0, 0, 0, "N", "S", "EFILE", 0, "Could not write blob. Permissions?");
     683                 :            :   }
     684                 :       1042 :   return 1;
     685                 :            : }
     686                 :            : 
     687                 :            : #define XML_LOG_FILE ZXID_PATH "log/xml.dbg"
     688                 :            : FILE* zx_xml_debug_log = 0;
     689                 :            : int zx_xml_debug_log_err = 0;
     690                 :            : int zxlog_seq = 0;
     691                 :            : 
     692                 :            : #if !defined(USE_STDIO) && !defined(MINGW)
     693                 :            : /* *** Static initialization of struct flock is suspect since man fcntl() documentation
     694                 :            :  * does not guarantee ordering of the fields, or that they would be the first fields.
     695                 :            :  * On Linux-2.4 and 2.6 as well as Solaris-8 the ordering is as follows, but this needs
     696                 :            :  * to be checked on other platforms.
     697                 :            :  *                       l_type,  l_whence, l_start, l_len */
     698                 :            : extern struct flock zx_rdlk; /* = { F_RDLCK, SEEK_SET, 0, 1 };*/
     699                 :            : extern struct flock zx_wrlk; /* = { F_WRLCK, SEEK_SET, 0, 1 };*/
     700                 :            : extern struct flock zx_unlk; /* = { F_UNLCK, SEEK_SET, 0, 1 };*/
     701                 :            : #endif
     702                 :            : 
     703                 :            : /*() Log a blob of XML data to auxiliary log file. This avoids
     704                 :            :  * mega clutter in the main debug logs. You are supposed
     705                 :            :  * to view this file with:
     706                 :            :  * tailf /var/zxid/log/xml.dbg | ./xml-pretty.pl */
     707                 :            : 
     708                 :            : /* Called by: */
     709                 :            : void zxlog_debug_xml_blob(zxid_conf* cf, const char* file, int line, const char* func, const char* lk, int len, const char* xml)
     710                 :       3840 : {
     711                 :            :   int bdy_len;
     712                 :            :   const char* bdy;
     713                 :            :   const char* p;
     714                 :            :   const char* q;
     715   [ +  +  +  -  :       3840 :   if (!zx_debug || len == -1 || !xml)
                   -  + ]
     716                 :        157 :     return;
     717         [ +  + ]:       3683 :   if (len == -2)
     718                 :        129 :     len = strlen(xml);
     719                 :            : 
     720                 :            :   /* Detect body */
     721                 :            : 
     722         [ +  - ]:       3686 :   for (p = xml; p; p+=4) {
     723                 :       3686 :     p = strstr(p, "Body");
     724         [ +  + ]:       3686 :     if (!p) {
     725                 :       3084 : nobody:
     726                 :       3084 :       bdy = xml;
     727                 :       3084 :       bdy_len = 40;
     728                 :       3084 :       goto print_it;
     729                 :            :     }
     730   [ +  -  +  -  :        602 :     if (p > xml && ONE_OF_2(p[-1], '<', ':') && ONE_OF_5(p[4], '>', ' ', '\t', '\r', '\n'))
          +  +  +  +  +  
          +  +  -  +  -  
                   +  - ]
     731                 :            :       break; /* Opening <Body> detected. */
     732                 :            :   }
     733         [ -  + ]:        599 :   if (!p)
     734                 :          0 :     goto nobody;
     735                 :            :   
     736                 :        599 :   p = strchr(p+4, '>');  /* Scan for close of opening <Body */
     737         [ -  + ]:        599 :   if (!p)
     738                 :          0 :     goto nobody;
     739                 :            :   
     740         [ +  - ]:        599 :   for (q = ++p; q; q+=5) {
     741                 :        599 :     q = strstr(q, "Body>");
     742         [ -  + ]:        599 :     if (!q)
     743                 :          0 :       goto nobody;  /* Missing closing </Body> tag */
     744   [ +  -  -  + ]:        599 :     if (ONE_OF_2(q[-1], '<', ':'))
     745                 :            :       break;
     746                 :            :   }
     747         [ +  + ]:        599 :   for (--q; *q != '<'; --q) ;  /* Scan for the start of </Body>, skipping any namespace prefix */
     748                 :        599 :   bdy = p;
     749                 :        599 :   bdy_len = MIN(q-p, 100);
     750                 :            : 
     751                 :       3683 : print_it:
     752                 :       3683 :   ++zxlog_seq;
     753                 :       3683 :   fprintf(stderr, "t %10s:%-3d %-16s %s d %s%s(%.*s) len=%d %d:%d\n", file, line, func, ERRMAC_INSTANCE, zx_indent, lk, bdy_len, bdy, len, getpid(), zxlog_seq);
     754                 :            : 
     755         [ +  + ]:       3683 :   if (!zx_xml_debug_log) {
     756         [ -  + ]:        171 :     if (zx_xml_debug_log_err)
     757                 :          0 :       return;
     758                 :        171 :     zx_xml_debug_log = fopen(XML_LOG_FILE, "a+");
     759         [ -  + ]:        171 :     if (!zx_xml_debug_log) {  /* If it did not work out, do not insist. */
     760                 :          0 :       perror(XML_LOG_FILE);
     761                 :          0 :       ERR("Can't open for appending %s: %d", XML_LOG_FILE, errno);
     762                 :          0 :       zx_xml_debug_log_err = 1;
     763                 :          0 :       return;
     764                 :            :     }
     765   [ +  -  -  + ]:        171 :     D("OPEN BLOB LOG: tailf %s | ./xml-pretty.pl", XML_LOG_FILE);
     766                 :            :   }
     767                 :            :   
     768         [ -  + ]:       3683 :   if (FLOCKEX(fileno(zx_xml_debug_log)) == -1) {
     769         [ #  # ]:          0 :     ERR("Locking exclusively file `%s' failed: %d %s. Check permissions and that the file system supports locking. euid=%d egid=%d", XML_LOG_FILE, errno, STRERROR(errno), geteuid(), getegid());
     770                 :            :     /* Fall thru to print without locking */
     771                 :            :   }
     772                 :       3683 :   ++zxlog_seq;
     773                 :       3683 :   fprintf(zx_xml_debug_log, "<!-- XMLBEG %d:%d %10s:%-3d %-16s %s d %s %s len=%d -->\n%.*s\n<!-- XMLEND %d:%d -->\n", getpid(), zxlog_seq, file, line, func, ERRMAC_INSTANCE, zx_indent, lk, len, len, xml, getpid(), zxlog_seq);
     774                 :       3683 :   fflush(zx_xml_debug_log);
     775                 :       3683 :   FUNLOCK(fileno(zx_xml_debug_log));
     776                 :            : }
     777                 :            : 
     778                 :            : /* EOF  --  zxlog.c */

Generated by: LCOV version 1.9