From fc94f3546d759ddb144f879ca9e6fa60f13df292 Mon Sep 17 00:00:00 2001 From: Heikki Levanto Date: Thu, 4 Nov 2004 13:54:08 +0000 Subject: [PATCH] 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. --- rset/rset.c | 74 ++++++++++++++++++++++++++++----------------------- rset/rsisamb.c | 24 +++++++++++------ rset/rsisamc.c | 10 ++++--- rset/rsmultiandor.c | 21 ++++++++++----- rset/rstemp.c | 33 ++++++++++++++--------- 5 files changed, 98 insertions(+), 64 deletions(-) diff --git a/rset/rset.c b/rset/rset.c index 0691af1..a58d5f9 100644 --- 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 #include +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 --- 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 #include -#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 --- 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 --- 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; ino_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 --- 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); -- 1.7.10.4