Dynamic logging and minor cleaning

  -v rset,rsisamb,rsisamc,rsmultiandor,rstemp
mostly changed existing logs. Better logs needed when debugging something
in these modules, but not yet.

diff --git a/rset/rset.c b/rset/rset.c
index 0691af1..a58d5f9 100644 (file)
--- a/rset/rset.c
+++ b/rset/rset.c
@@ -1,4 +1,4 @@
-/* $Id: rset.c,v 1.38 2004-10-22 11:33:29 heikki Exp $
+/* $Id: rset.c,v 1.39 2004-11-04 13:54:08 heikki Exp $
    Copyright (C) 1995,1996,1997,1998,1999,2000,2001,2002,2003,2004
    Index Data Aps
 
@@ -29,26 +29,37 @@ Free Software Foundation, 59 Temple Place - Suite 330, Boston, MA
 #include <yaz/nmem.h>
 #include <rset.h>
 
+static int log_level=0;
+static int log_level_initialized=0;
 
-/* creates an rfd. Either allocates a new one, in which case the priv */
-/* pointer is null, and will have to be filled in, or picks up one */
-/* from the freelist, in which case the priv is already allocated, */
-/* and presumably everything that hangs from it as well */
+/**
+ * creates an rfd. Either allocates a new one, in which case the priv 
+ * pointer is null, and will have to be filled in, or picks up one 
+ * from the freelist, in which case the priv is already allocated,
+ * and presumably everything that hangs from it as well 
+ */
 
 RSFD rfd_create_base(RSET rs)
 {
+    if (!log_level_initialized) 
+    {
+        log_level=yaz_log_module_level("rset");
+        log_level_initialized=1;
+    }
+
     RSFD rnew=rs->free_list;
-    if (rnew) {
+    if (rnew) 
+    {
         rs->free_list=rnew->next;
         assert(rnew->rset==rs);
-  /*    logf(LOG_DEBUG,"rfd-create_base (fl): rfd=%p rs=%p fl=%p priv=%p", 
-                       rnew, rs, rs->free_list, rnew->priv); */
+        logf(log_level,"rfd-create_base (fl): rfd=%p rs=%p fl=%p priv=%p", 
+                       rnew, rs, rs->free_list, rnew->priv); 
     } else {
         rnew=nmem_malloc(rs->nmem, sizeof(*rnew));
         rnew->priv=NULL;
         rnew->rset=rs;
-  /*    logf(LOG_DEBUG,"rfd_create_base (new): rfd=%p rs=%p fl=%p priv=%p", 
-                       rnew, rs, rs->free_list, rnew->priv); */
+        logf(log_level,"rfd_create_base (new): rfd=%p rs=%p fl=%p priv=%p", 
+                       rnew, rs, rs->free_list, rnew->priv); 
     }
     rnew->next=NULL; /* not part of any (free?) list */
     return rnew;
@@ -59,8 +70,8 @@ RSFD rfd_create_base(RSET rs)
 void rfd_delete_base(RSFD rfd) 
 {
     RSET rs=rfd->rset;
- /* logf(LOG_DEBUG,"rfd_delete_base: rfd=%p rs=%p priv=%p fl=%p",
-            rfd, rs, rfd->priv, rs->free_list); */
+    logf(log_level,"rfd_delete_base: rfd=%p rs=%p priv=%p fl=%p",
+            rfd, rs, rfd->priv, rs->free_list); 
     assert(NULL == rfd->next); 
     rfd->next=rs->free_list;
     rs->free_list=rfd;
@@ -79,7 +90,7 @@ RSET rset_create_base(const struct rset_control *sel,
     else
         M=nmem_create();
     rnew = (RSET) nmem_malloc(M,sizeof(*rnew));
- /* logf (LOG_DEBUG, "rs_create(%s) rs=%p (nm=%p)", sel->desc, rnew, nmem); */
+    logf (log_level, "rs_create(%s) rs=%p (nm=%p)", sel->desc, rnew, nmem); 
     rnew->nmem=M;
     if (nmem)
         rnew->my_nmem=0;
@@ -100,8 +111,8 @@ RSET rset_create_base(const struct rset_control *sel,
 void rset_delete (RSET rs)
 {
     (rs->count)--;
-/*  logf(LOG_DEBUG,"rs_delete(%s), rs=%p, count=%d",
-            rs->control->desc, rs, rs->count); */
+    logf(log_level,"rs_delete(%s), rs=%p, count=%d",
+            rs->control->desc, rs, rs->count); 
     if (!rs->count)
     {
         (*rs->control->f_delete)(rs);
@@ -113,46 +124,41 @@ void rset_delete (RSET rs)
 RSET rset_dup (RSET rs)
 {
     (rs->count)++;
+    logf(log_level,"rs_dup(%s), rs=%p, count=%d",
+            rs->control->desc, rs, rs->count); 
     return rs;
 }
 
-#if 0
-void rset_default_pos (RSFD rfd, double *current, double *total)
-{ /* This should never really be needed, but it is still used in */
-  /* those rsets that we don't really plan to use, like isam-s */
-    assert(rfd);
-    assert(current);
-    assert(total);
-    *current=-1; /* signal that pos is not implemented */
-    *total=-1;
-} /* rset_default_pos */
-#endif
-
 int rset_default_forward(RSFD rfd, void *buf, TERMID *term,
                            const void *untilbuf)
 {
     int more=1;
     int cmp=rfd->rset->scope;
-    logf (LOG_DEBUG, "rset_default_forward starting '%s' (ct=%p rfd=%p)",
+    if (log_level)
+    {
+        logf (log_level, "rset_default_forward starting '%s' (ct=%p rfd=%p)",
                     rfd->rset->control->desc, rfd->rset, rfd);
-    /* key_logdump(LOG_DEBUG, untilbuf); */
+        /* key_logdump(log_level, untilbuf); */
+    }
     while ( (cmp>=rfd->rset->scope) && (more))
     {
-        logf (LOG_DEBUG, "rset_default_forward looping m=%d c=%d",more,cmp);
+        if (log_level)  /* time-critical, check first */
+            logf(log_level,"rset_default_forward looping m=%d c=%d",more,cmp);
         more=rset_read(rfd, buf, term);
         if (more)
             cmp=(rfd->rset->keycontrol->cmp)(untilbuf,buf);
 /*        if (more)
-            key_logdump(LOG_DEBUG,buf); */
+            key_logdump(log_level,buf); */
     }
-    logf (LOG_DEBUG, "rset_default_forward exiting m=%d c=%d",more,cmp);
+    if (log_level)
+        logf (log_level, "rset_default_forward exiting m=%d c=%d",more,cmp);
 
     return more;
 }
 
 /** 
  * rset_count uses rset_pos to get the total and returns that.
- * This is ok for rsisamb, and for some other rsets, but in case of
+ * This is ok for rsisamb/c/s, and for some other rsets, but in case of
  * booleans etc it will give bad estimate, as nothing has been read
  * from that rset
  */
@@ -189,7 +195,7 @@ TERMID rset_term_create (const char *name, int length, const char *flags,
 
 {
     TERMID t;
-    logf (LOG_DEBUG, "term_create '%s' %d f=%s type=%d nmem=%p",
+    logf (log_level, "term_create '%s' %d f=%s type=%d nmem=%p",
             name, length, flags, type, nmem);
     t= (TERMID) nmem_malloc (nmem, sizeof(*t));
     if (!name)

diff --git a/rset/rsisamb.c b/rset/rsisamb.c
index 094ba85..ee0762a 100644 (file)
--- a/rset/rsisamb.c
+++ b/rset/rsisamb.c
@@ -1,4 +1,4 @@
-/* $Id: rsisamb.c,v 1.25 2004-10-22 10:12:52 heikki Exp $
+/* $Id: rsisamb.c,v 1.26 2004-11-04 13:54:08 heikki Exp $
    Copyright (C) 1995,1996,1997,1998,1999,2000,2001,2002,2003,2004
    Index Data Aps
 
@@ -26,9 +26,6 @@ Free Software Foundation, 59 Temple Place - Suite 330, Boston, MA
 #include <rset.h>
 #include <string.h>
 
-#ifndef RSET_DEBUG
-#define RSET_DEBUG 0
-#endif
 
 static RSFD r_open (RSET ct, int flag);
 static void r_close (RSFD rfd);
@@ -63,21 +60,30 @@ struct rset_isamb_info {
     ISAMB_P pos;
 };
 
+static int log_level=0;
+static int log_level_initialized=0;
+
 RSET rsisamb_create( NMEM nmem, const struct key_control *kcontrol, int scope,
             ISAMB is, ISAMB_P pos, TERMID term)
 {
     RSET rnew=rset_create_base(&control, nmem, kcontrol, scope, term);
     struct rset_isamb_info *info;
+    if (!log_level_initialized)
+    {
+        log_level=yaz_log_module_level("rsisamb");
+        log_level_initialized=1;
+    }
     info = (struct rset_isamb_info *) nmem_malloc(rnew->nmem,sizeof(*info));
     info->is=is;
     info->pos=pos;
     rnew->priv=info;
+    logf(log_level,"rsisamb_create");
     return rnew;
 }
 
 static void r_delete (RSET ct)
 {
-    logf (LOG_DEBUG, "rsisamb_delete");
+    logf (log_level, "rsisamb_delete");
 }
 
 RSFD r_open (RSET ct, int flag)
@@ -100,6 +106,7 @@ RSFD r_open (RSET ct, int flag)
         rfd->priv=ptinfo;
     }
     ptinfo->pt = isamb_pp_open (info->is, info->pos, ct->scope );
+    logf(log_level,"rsisamb_open");
     return rfd;
 }
 
@@ -108,6 +115,7 @@ static void r_close (RSFD rfd)
     struct rset_pp_info *ptinfo=(struct rset_pp_info *)(rfd->priv);
     isamb_pp_close (ptinfo->pt);
     rfd_delete_base(rfd);
+    logf(log_level,"rsisamb_close");
 }
 
 
@@ -118,6 +126,7 @@ static int r_forward(RSFD rfd, void *buf, TERMID *term, const void *untilbuf)
     rc=isamb_pp_forward(pinfo->pt, buf, untilbuf);
     if (rc && term)
         *term=rfd->rset->term;
+    logf(log_level,"rsisamb_forward");
     return rc; 
 }
 
@@ -126,10 +135,8 @@ static void r_pos (RSFD rfd, double *current, double *total)
     struct rset_pp_info *pinfo=(struct rset_pp_info *)(rfd->priv);
     assert(rfd);
     isamb_pp_pos(pinfo->pt, current, total);
-#if RSET_DEBUG
-    logf(LOG_DEBUG,"isamb.r_pos returning %0.1f/%0.1f",
+    logf(log_level,"isamb.r_pos returning %0.1f/%0.1f",
               *current, *total);
-#endif
 }
 
 static int r_read (RSFD rfd, void *buf, TERMID *term)
@@ -139,6 +146,7 @@ static int r_read (RSFD rfd, void *buf, TERMID *term)
     rc=isamb_pp_read(pinfo->pt, buf);
     if (rc && term)
         *term=rfd->rset->term;
+    logf(log_level,"isamb.r_read ");
     return rc;
 }
 

diff --git a/rset/rsisamc.c b/rset/rsisamc.c
index 2810487..6b833d6 100644 (file)
--- a/rset/rsisamc.c
+++ b/rset/rsisamc.c
@@ -1,4 +1,4 @@
-/* $Id: rsisamc.c,v 1.29 2004-11-04 13:11:51 heikki Exp $
+/* $Id: rsisamc.c,v 1.30 2004-11-04 13:54:08 heikki Exp $
    Copyright (C) 1995,1996,1997,1998,1999,2000,2001,2002,2003,2004
    Index Data Aps
 
@@ -61,15 +61,19 @@ struct rset_isamc_info {
     ISAMC_P pos;
 };
 
-static int log_level=-1;
+static int log_level=0;
+static int log_level_initialized=0;
 
 RSET rsisamc_create( NMEM nmem, const struct key_control *kcontrol, int scope,
                              ISAMC is, ISAMC_P pos, TERMID term)
 {
     RSET rnew=rset_create_base(&control, nmem, kcontrol, scope,term);
     struct rset_isamc_info *info;
-    if (log_level<0)
+    if (!log_level_initialized)
+    {
         log_level=yaz_log_module_level("rsisamc");
+        log_level_initialized=1;
+    }
     info = (struct rset_isamc_info *) nmem_malloc(rnew->nmem,sizeof(*info));
     info->is=is;
     info->pos=pos;

diff --git a/rset/rsmultiandor.c b/rset/rsmultiandor.c
index 9a88534..ac728b1 100644 (file)
--- a/rset/rsmultiandor.c
+++ b/rset/rsmultiandor.c
@@ -1,4 +1,4 @@
-/* $Id: rsmultiandor.c,v 1.8 2004-10-26 15:32:11 heikki Exp $
+/* $Id: rsmultiandor.c,v 1.9 2004-11-04 13:54:08 heikki Exp $
    Copyright (C) 1995,1996,1997,1998,1999,2000,2001,2002
    Index Data Aps
 
@@ -125,6 +125,10 @@ struct rset_multiandor_rfd {
     char *tailbits;
 };
 
+static int log_level=0;
+static int log_level_initialized=0;
+
+
 /* Heap functions ***********************/
 
 #if 0
@@ -133,13 +137,13 @@ static void heap_dump_item( HEAP h, int i, int level) {
     if (i>h->heapnum)
         return;
     (void)rset_pos(h->heap[i]->rset,h->heap[i]->fd, &cur, &tot);
-    logf(LOG_LOG," %d %*s i=%p buf=%p %0.1f/%0.1f",i, level, "",  
+    logf(log_level," %d %*s i=%p buf=%p %0.1f/%0.1f",i, level, "",  
                     &(h->heap[i]), h->heap[i]->buf, cur,tot );
     heap_dump_item(h, 2*i, level+1);
     heap_dump_item(h, 2*i+1, level+1);
 }
 static void heap_dump( HEAP h,char *msg) {
-    logf(LOG_LOG, "heap dump: %s num=%d max=%d",msg, h->heapnum, h->heapmax);
+    logf(log_level, "heap dump: %s num=%d max=%d",msg, h->heapnum, h->heapmax);
     heap_dump_item(h,1,1);
 }
 #endif
@@ -264,6 +268,11 @@ static RSET rsmulti_andor_create( NMEM nmem, const struct key_control *kcontrol,
 {
     RSET rnew=rset_create_base(ctrl, nmem,kcontrol, scope,0);
     struct rset_multiandor_info *info;
+    if (!log_level_initialized)
+    {
+        log_level=yaz_log_module_level("rsmultiandor");
+        log_level_initialized=1;
+    }
     info = (struct rset_multiandor_info *) nmem_malloc(rnew->nmem,sizeof(*info));
     info->no_rsets=no_rsets;
     info->rsets=(RSET*)nmem_malloc(rnew->nmem, no_rsets*sizeof(*rsets));
@@ -562,19 +571,19 @@ static void r_pos (RSFD rfd, double *current, double *total)
     int i;
     for (i=0; i<info->no_rsets; i++){
         rset_pos(mrfd->items[i].fd, &cur, &tot);
-        /*logf(LOG_LOG, "r_pos: %d %0.1f %0.1f", i, cur,tot); */
+        logf(log_level, "r_pos: %d %0.1f %0.1f", i, cur,tot); 
         scur += cur;
         stot += tot;
     }
     if (stot <1.0) { /* nothing there */
         *current=0;
         *total=0;
-        /* logf(LOG_LOG, "r_pos: NULL  %0.1f %0.1f",  *current, *total);*/
+        logf(log_level, "r_pos: NULL  %0.1f %0.1f",  *current, *total);
         return;
     }
     *current=mrfd->hits;
     *total=*current*stot/scur;
-    /*logf(LOG_LOG, "r_pos: =  %0.1f %0.1f",  *current, *total);*/
+    logf(log_level, "r_pos: =  %0.1f %0.1f",  *current, *total);
 }
 
 

diff --git a/rset/rstemp.c b/rset/rstemp.c
index 29d4ffc..984249b 100644 (file)
--- a/rset/rstemp.c
+++ b/rset/rstemp.c
@@ -1,4 +1,4 @@
-/* $Id: rstemp.c,v 1.53 2004-11-03 16:04:46 heikki Exp $
+/* $Id: rstemp.c,v 1.54 2004-11-04 13:54:08 heikki Exp $
    Copyright (C) 1995,1996,1997,1998,1999,2000,2001,2002,2003
    Index Data Aps
 
@@ -79,13 +79,20 @@ struct rset_temp_rfd {
     zint cur; /* number of the current hit */
 };
 
+static int log_level=0;
+static int log_level_initialized=0;
+
 RSET rstemp_create( NMEM nmem, const struct key_control *kcontrol,
                     int scope, 
                     const char *temp_path,TERMID term)
 {
     RSET rnew=rset_create_base(&control, nmem, kcontrol, scope,term);
     struct rset_temp_info *info;
-   
+    if (!log_level_initialized)
+    {
+        log_level=yaz_log_module_level("rstemp");
+        log_level_initialized=1;
+    }
     info = (struct rset_temp_info *) nmem_malloc(rnew->nmem, sizeof(*info));
     info->fd = -1;
     info->fname = NULL;
@@ -108,10 +115,10 @@ static void r_delete (RSET ct)
 {
     struct rset_temp_info *info = (struct rset_temp_info*) ct->priv;
 
-    logf (LOG_DEBUG, "r_delete: set size %ld", (long) info->pos_end);
+    logf (log_level, "r_delete: set size %ld", (long) info->pos_end);
     if (info->fname)
     {
-        logf (LOG_DEBUG, "r_delete: unlink %s", info->fname);
+        logf (log_level, "r_delete: unlink %s", info->fname);
         unlink (info->fname);
     }
 }
@@ -131,7 +138,7 @@ static RSFD r_open (RSET ct, int flag)
             info->fd = open (info->fname, O_BINARY|O_RDONLY);
         if (info->fd == -1)
         {
-            logf (LOG_FATAL|LOG_ERRNO, "open %s", info->fname);
+            logf (LOG_FATAL|LOG_ERRNO, "rstemp: open failed %s", info->fname);
             exit (1);
         }
     }
@@ -172,7 +179,7 @@ static void r_flush (RSFD rfd, int mk)
 
         if (info->fd == -1)
         {
-            logf (LOG_FATAL|LOG_ERRNO, "mkstemp %s", template);
+            logf (LOG_FATAL|LOG_ERRNO, "rstemp: mkstemp %s", template);
             exit (1);
         }
         info->fname= nmem_malloc(rfd->rset->nmem,strlen(template)+1);
@@ -182,11 +189,11 @@ static void r_flush (RSFD rfd, int mk)
         info->fname= nmem_malloc(rfd->rset->nmem,strlen(template)+1);
         strcpy (info->fname, s);
 
-        logf (LOG_DEBUG, "creating tempfile %s", info->fname);
+        logf (log_level, "creating tempfile %s", info->fname);
         info->fd = open (info->fname, O_BINARY|O_RDWR|O_CREAT, 0666);
         if (info->fd == -1)
         {
-            logf (LOG_FATAL|LOG_ERRNO, "open %s", info->fname);
+            logf (LOG_FATAL|LOG_ERRNO, "rstemp: open %s", info->fname);
             exit (1);
         }
 #endif
@@ -198,7 +205,7 @@ static void r_flush (RSFD rfd, int mk)
         
         if (lseek (info->fd, info->pos_buf, SEEK_SET) == -1)
         {
-            logf (LOG_FATAL|LOG_ERRNO, "lseek %s", info->fname);
+            logf (LOG_FATAL|LOG_ERRNO, "rstemp: lseek %s", info->fname);
             exit (1);
         }
         count = info->buf_size;
@@ -207,9 +214,9 @@ static void r_flush (RSFD rfd, int mk)
         if ((r = write (info->fd, info->buf_mem, count)) < (int) count)
         {
             if (r == -1)
-                logf (LOG_FATAL|LOG_ERRNO, "read %s", info->fname);
+                logf (LOG_FATAL|LOG_ERRNO, "rstemp: write %s", info->fname);
             else
-                logf (LOG_FATAL, "write of %ld but got %ld",
+                logf (LOG_FATAL, "rstemp: write of %ld but got %ld",
                       (long) count, (long) r);
             exit (1);
         }
@@ -254,13 +261,13 @@ static void r_reread (RSFD rfd)
         {
             if (lseek (info->fd, info->pos_buf, SEEK_SET) == -1)
             {
-                logf (LOG_FATAL|LOG_ERRNO, "lseek %s", info->fname);
+                logf (LOG_FATAL|LOG_ERRNO, "rstemp: lseek %s", info->fname);
                 exit (1);
             }
             if ((r = read (info->fd, info->buf_mem, count)) < (int) count)
             {
                 if (r == -1)
-                    logf (LOG_FATAL|LOG_ERRNO, "read %s", info->fname);
+                    logf (LOG_FATAL|LOG_ERRNO, "rstemp: read %s", info->fname);
                 else
                     logf (LOG_FATAL, "read of %ld but got %ld",
                           (long) count, (long) r);