Added a warning (always to stderr) when opening the log file fails
[yaz-moved-to-github.git] / src / seshigh.c
index c35787c..025b16f 100644 (file)
@@ -2,7 +2,7 @@
  * Copyright (c) 1995-2004, Index Data
  * See the file LICENSE for details.
  *
- * $Id: seshigh.c,v 1.34 2004-11-16 17:08:11 heikki Exp $
+ * $Id: seshigh.c,v 1.42 2004-12-30 00:25:33 adam Exp $
  */
 /**
  * \file seshigh.c
@@ -68,7 +68,8 @@ void backend_response(IOCHAN i, int event);
 static int process_gdu_response(association *assoc, request *req, Z_GDU *res);
 static int process_z_response(association *assoc, request *req, Z_APDU *res);
 static Z_APDU *process_initRequest(association *assoc, request *reqb);
-static Z_External *init_diagnostics(ODR odr, int errcode, char *errstring);
+static Z_External *init_diagnostics(ODR odr, int errcode,
+                                   const char *errstring);
 static Z_APDU *process_searchRequest(association *assoc, request *reqb,
     int *fd);
 static Z_APDU *response_searchRequest(association *assoc, request *reqb,
@@ -106,6 +107,14 @@ static void get_logbits()
     }
 }
 
+static void wr_diag(WRBUF w, int error, const char *addinfo)
+{
+    wrbuf_printf(w, "ERROR [%d] %s%s%s",
+                error, diagbib1_str(error),
+                addinfo ? "--" : "", addinfo ? addinfo : "");
+}
+
+
 /*
  * Create and initialize a new association-handle.
  *  channel  : iochannel for the current line.
@@ -153,7 +162,7 @@ association *create_association(IOCHAN channel, COMSTACK link)
                 {
                     if (!(apduf = fopen(filename, "w")))
                     {
-                        yaz_log(LOG_WARN|LOG_ERRNO, "can't open apdu dump %s", filename);
+                        yaz_log(YLOG_WARN|YLOG_ERRNO, "can't open apdu dump %s", filename);
                         return 0;
                     }
                     setvbuf(apduf, 0, _IONBF, 0);
@@ -162,10 +171,10 @@ association *create_association(IOCHAN channel, COMSTACK link)
             }
             else 
             {
-                sprintf(filename + strlen(filename), ".%d", getpid());
+                sprintf(filename + strlen(filename), ".%ld", (long)getpid());
                 if (!(f = fopen(filename, "w")))
                 {
-                    yaz_log(LOG_WARN|LOG_ERRNO, "%s", filename);
+                    yaz_log(YLOG_WARN|YLOG_ERRNO, "%s", filename);
                     return 0;
                 }
                 setvbuf(f, 0, _IONBF, 0);
@@ -272,7 +281,7 @@ void ir_session(IOCHAN h, int event)
     {
         if (assoc->state != ASSOC_UP)
         {
-            yaz_log(LOG_DEBUG, "Final timeout - closing connection.");
+            yaz_log(YLOG_DEBUG, "Final timeout - closing connection.");
             /* do we need to lod this at all */
             cs_close(conn);
             destroy_association(assoc);
@@ -287,10 +296,9 @@ void ir_session(IOCHAN h, int event)
     }
     if (event & assoc->cs_accept_mask)
     {
-        yaz_log (log_session, "ir_session (accept)");
         if (!cs_accept (conn))
         {
-            yaz_log (LOG_WARN, "accept failed");
+            yaz_log (YLOG_WARN, "accept failed");
             destroy_association(assoc);
             iochan_destroy(h);
         }
@@ -315,7 +323,7 @@ void ir_session(IOCHAN h, int event)
     {
         if ((assoc->cs_put_mask & EVENT_INPUT) == 0 && (event & assoc->cs_get_mask))
         {
-            yaz_log(LOG_DEBUG, "ir_session (input)");
+            yaz_log(YLOG_DEBUG, "ir_session (input)");
             /* We aren't speaking to this fellow */
             if (assoc->state == ASSOC_DEAD)
             {
@@ -346,7 +354,7 @@ void ir_session(IOCHAN h, int event)
                 iochan_setevent(h, EVENT_INPUT);
                 
             /* we got a complete PDU. Let's decode it */
-            yaz_log(LOG_DEBUG, "Got PDU, %d bytes: lead=%02X %02X %02X", res,
+            yaz_log(YLOG_DEBUG, "Got PDU, %d bytes: lead=%02X %02X %02X", res,
                             assoc->input_buffer[0] & 0xff,
                             assoc->input_buffer[1] & 0xff,
                             assoc->input_buffer[2] & 0xff);
@@ -355,14 +363,14 @@ void ir_session(IOCHAN h, int event)
             odr_setbuf(assoc->decode, assoc->input_buffer, res, 0);
             if (!z_GDU(assoc->decode, &req->gdu_request, 0, 0))
             {
-                yaz_log(LOG_WARN, "ODR error on incoming PDU: %s [element %s] "
+                yaz_log(YLOG_WARN, "ODR error on incoming PDU: %s [element %s] "
                         "[near byte %d] ",
                         odr_errmsg(odr_geterror(assoc->decode)),
                         odr_getelement(assoc->decode),
                         odr_offset(assoc->decode));
                 if (assoc->decode->error != OHTTP)
                 {
-                    yaz_log(LOG_WARN, "PDU dump:");
+                    yaz_log(YLOG_WARN, "PDU dump:");
                     odr_dumpBER(yaz_log_file(), assoc->input_buffer, res);
                     request_release(req);
                     do_close(assoc, Z_Close_protocolError,"Malformed package");
@@ -379,7 +387,7 @@ void ir_session(IOCHAN h, int event)
             if (assoc->print) 
             {
                 if (!z_GDU(assoc->print, &req->gdu_request, 0, 0))
-                    yaz_log(LOG_WARN, "ODR print error: %s", 
+                    yaz_log(YLOG_WARN, "ODR print error: %s", 
                        odr_errmsg(odr_geterror(assoc->print)));
                 odr_reset(assoc->print);
             }
@@ -399,7 +407,7 @@ void ir_session(IOCHAN h, int event)
         request *req = request_head(&assoc->outgoing);
 
         assoc->cs_put_mask = 0;
-        yaz_log(LOG_DEBUG, "ir_session (output)");
+        yaz_log(YLOG_DEBUG, "ir_session (output)");
         req->state = REQUEST_PENDING;
         switch (res = cs_put(conn, req->response, req->len_response))
         {
@@ -410,9 +418,9 @@ void ir_session(IOCHAN h, int event)
             iochan_destroy(h);
             break;
         case 0: /* all sent - release the request structure */
-            yaz_log(LOG_DEBUG, "Wrote PDU, %d bytes", req->len_response);
+            yaz_log(YLOG_DEBUG, "Wrote PDU, %d bytes", req->len_response);
 #if 0
-            yaz_log(LOG_DEBUG, "HTTP out:\n%.*s", req->len_response,
+            yaz_log(YLOG_DEBUG, "HTTP out:\n%.*s", req->len_response,
                     req->response);
 #endif
             nmem_destroy(req->request_mem);
@@ -440,7 +448,7 @@ void ir_session(IOCHAN h, int event)
     }
     if (event & EVENT_EXCEPT)
     {
-        yaz_log(LOG_WARN, "ir_session (exception)");
+        yaz_log(YLOG_WARN, "ir_session (exception)");
         cs_close(conn);
         destroy_association(assoc);
         iochan_destroy(h);
@@ -497,7 +505,7 @@ static int srw_bend_init(association *assoc)
     assoc->backend = 0;
     if (!(binitres = (*cb->bend_init)(assoc->init)))
     {
-        yaz_log(LOG_WARN, "Bad response from backend.");
+        yaz_log(YLOG_WARN, "Bad response from backend.");
         return 0;
     }
     assoc->backend = binitres->handle;
@@ -618,21 +626,22 @@ static void srw_bend_search(association *assoc, request *req,
     int srw_error = 0;
     bend_search_rr rr;
     Z_External *ext;
-    char *querystr="";
+    const char *querystr = 0;
+    const char *querytype = 0;
     
     *http_code = 200;
     yaz_log(log_requestdetail, "Got SRW SearchRetrieveRequest");
-    yaz_log(LOG_DEBUG, "srw_bend_search");
+    yaz_log(YLOG_DEBUG, "srw_bend_search");
     if (!assoc->init)
     {
-        yaz_log(LOG_DEBUG, "srw_bend_init");
+        yaz_log(YLOG_DEBUG, "srw_bend_init");
         if (!srw_bend_init(assoc))
         {
             srw_error = 3;  /* assume Authentication error */
 
             yaz_add_srw_diagnostic(assoc->encode, &srw_res->diagnostics,
                                    &srw_res->num_diagnostics, 1, 0);
-            yaz_log(log_request,"Search SRW: backend init failed");
+            yaz_log(log_request, "Search SRW: backend init failed");
             return;
         }
     }
@@ -654,7 +663,8 @@ static void srw_bend_search(association *assoc, request *req,
         ext->descriptor = 0;
         ext->which = Z_External_CQL;
         ext->u.cql = srw_req->query.cql;
-        querystr=srw_req->query.cql;
+        querystr = srw_req->query.cql;
+       querytype = "CQL";
 
         rr.query->which = Z_Query_type_104;
         rr.query->u.type_104 =  ext;
@@ -666,7 +676,8 @@ static void srw_bend_search(association *assoc, request *req,
 
         pqf_parser = yaz_pqf_create ();
 
-        querystr=srw_req->query.pqf;
+        querystr = srw_req->query.pqf;
+       querytype = "PQF";
         RPNquery = yaz_pqf_parse (pqf_parser, assoc->decode,
                                   srw_req->query.pqf);
         if (!RPNquery)
@@ -697,11 +708,11 @@ static void srw_bend_search(association *assoc, request *req,
     {
         if (log_request)
         {
-            WRBUF wr=wrbuf_alloc();
-            wrbuf_printf(wr, "Search: SRW: %s ",querystr);
-            wrbuf_printf(wr," ERROR %d ", srw_error);
-            yaz_log(log_request, "Search %s", wrbuf_buf(wr) );
-            wrbuf_free(wr,1);
+            WRBUF wr = wrbuf_alloc();
+            wrbuf_printf(wr, "Search: %s: %s ", querytype, querystr);
+            wrbuf_printf(wr, " ERROR %d ", srw_error);
+            yaz_log(log_request, "%s", wrbuf_buf(wr) );
+            wrbuf_free(wr, 1);
         }
         srw_res->num_diagnostics = 1;
         srw_res->diagnostics = (Z_SRW_diagnostic *)
@@ -726,20 +737,19 @@ static void srw_bend_search(association *assoc, request *req,
     (assoc->init->bend_search)(assoc->backend, &rr);
     if (rr.errcode)
     {
-        yaz_log(log_request, "bend_search returned Bib-1 code %d", rr.errcode);
+        yaz_log(log_request, "bend_search returned Bib-1 diagnostic %d",
+               rr.errcode);
         if (rr.errcode == 109) /* database unavailable */
         {
             *http_code = 404;
             return;
         }
+       srw_error = yaz_diag_bib1_to_srw (rr.errcode);
         srw_res->num_diagnostics = 1;
         srw_res->diagnostics = (Z_SRW_diagnostic *)
             odr_malloc(assoc->encode, sizeof(*srw_res->diagnostics));
         yaz_mk_std_diagnostic(assoc->encode, srw_res->diagnostics,
-                              yaz_diag_bib1_to_srw (rr.errcode),
-                              rr.errstring);
-        yaz_log(log_request, "srw_bend_search returned SRW error %s",
-                srw_res->diagnostics[0].uri);
+                             srw_error, rr.errstring);
     }
     else
     {
@@ -781,7 +791,7 @@ static void srw_bend_search(association *assoc, request *req,
                     
                     srw_res->records[j].recordPacking = packing;
                     srw_res->records[j].recordData_buf = 0;
-                    yaz_log(LOG_DEBUG, "srw_bend_fetch %d", i+start);
+                    yaz_log(YLOG_DEBUG, "srw_bend_fetch %d", i+start);
                     errcode = srw_bend_fetch(assoc, i+start, srw_req,
                                              srw_res->records + j);
                     if (errcode)
@@ -809,17 +819,17 @@ static void srw_bend_search(association *assoc, request *req,
     if (log_request)
     {
         WRBUF wr=wrbuf_alloc();
-        wrbuf_printf(wr,"SRW: %s",querystr );
+        wrbuf_printf(wr,"Search %s: %s", querytype, querystr);
         if (srw_error)
-            wrbuf_printf(wr," ERROR %d ", srw_error);
+            wrbuf_printf(wr, " ERROR %d", srw_error);
         else
         {
-            wrbuf_printf(wr," OK:%d hits ",rr.hits);
+            wrbuf_printf(wr, " OK:%d hits", rr.hits);
             if (srw_res->num_records)
-                wrbuf_printf(wr," Returned %d records", srw_res->num_records);
+                wrbuf_printf(wr, " %d records returned", srw_res->num_records);
         }
-        yaz_log(log_request, "Search %s", wrbuf_buf(wr) );
-        wrbuf_free(wr,1);
+        yaz_log(log_request, "%s", wrbuf_buf(wr) );
+        wrbuf_free(wr, 1);
     }
 }
 
@@ -832,7 +842,7 @@ static void srw_bend_explain(association *assoc, request *req,
     *http_code = 404;
     if (!assoc->init)
     {
-        yaz_log(LOG_DEBUG, "srw_bend_init");
+        yaz_log(YLOG_DEBUG, "srw_bend_init");
         if (!srw_bend_init(assoc))
         {
             return;
@@ -891,13 +901,13 @@ static void process_http_request(association *assoc, request *req)
     if (r == 2)
     {
         r = yaz_srw_decode(hreq, &sr, &soap_package, assoc->decode, &charset);
-        yaz_log(LOG_DEBUG, "yaz_srw_decode returned %d", r);
+        yaz_log(YLOG_DEBUG, "yaz_srw_decode returned %d", r);
     }
     if (r == 2)  /* not taken */
     {
         r = yaz_sru_decode(hreq, &sr, &soap_package, assoc->decode, &charset,
                            &diagnostic, &num_diagnostic);
-        yaz_log(LOG_DEBUG, "yaz_sru_decode returned %d", r);
+        yaz_log(YLOG_DEBUG, "yaz_sru_decode returned %d", r);
     }
     if (r == 0)  /* decode SRW/SRU OK .. */
     {
@@ -1023,7 +1033,7 @@ static void process_http_request(association *assoc, request *req)
         int t;
         const char *alive = z_HTTP_header_lookup(hreq->headers, "Keep-Alive");
 
-        if (alive && isdigit(*alive))
+        if (alive && isdigit(*(const unsigned char *) alive))
             t = atoi(alive);
         else
             t = 15;
@@ -1136,12 +1146,12 @@ static int process_z_request(association *assoc, request *req, char **msg)
     }
     if (res)
     {
-        yaz_log(LOG_DEBUG, "  result immediately available");
+        yaz_log(YLOG_DEBUG, "  result immediately available");
         retval = process_z_response(assoc, req, res);
     }
     else if (fd < 0)
     {
-        yaz_log(LOG_DEBUG, "  result unavailble");
+        yaz_log(YLOG_DEBUG, "  result unavailble");
         retval = 0;
     }
     else /* no result yet - one will be provided later */
@@ -1150,7 +1160,7 @@ static int process_z_request(association *assoc, request *req, char **msg)
 
         /* Set up an I/O handler for the fd supplied by the backend */
 
-        yaz_log(LOG_DEBUG, "   establishing handler for result");
+        yaz_log(YLOG_DEBUG, "   establishing handler for result");
         req->state = REQUEST_PENDING;
         if (!(chan = iochan_create(fd, backend_response, EVENT_INPUT)))
             abort();
@@ -1170,7 +1180,7 @@ void backend_response(IOCHAN i, int event)
     Z_APDU *res;
     int fd;
 
-    yaz_log(LOG_DEBUG, "backend_response");
+    yaz_log(YLOG_DEBUG, "backend_response");
     assert(assoc && req && req->state != REQUEST_IDLE);
     /* determine what it is we're waiting for */
     switch (req->apdu_request->which)
@@ -1184,19 +1194,19 @@ void backend_response(IOCHAN i, int event)
             res = response_scanRequest(assoc, req, 0, &fd); break;
 #endif
         default:
-            yaz_log(LOG_FATAL, "Serious programmer's lapse or bug");
+            yaz_log(YLOG_FATAL, "Serious programmer's lapse or bug");
             abort();
     }
     if ((res && process_z_response(assoc, req, res) < 0) || fd < 0)
     {
-        yaz_log(LOG_WARN, "Fatal error when talking to backend");
+        yaz_log(YLOG_WARN, "Fatal error when talking to backend");
         do_close(assoc, Z_Close_systemProblem, 0);
         iochan_destroy(i);
         return;
     }
     else if (!res) /* no result yet - try again later */
     {
-        yaz_log(LOG_DEBUG, "   no result yet");
+        yaz_log(YLOG_DEBUG, "   no result yet");
         iochan_setfd(i, fd); /* in case fd has changed */
     }
 }
@@ -1211,16 +1221,15 @@ static int process_gdu_response(association *assoc, request *req, Z_GDU *res)
     if (assoc->print)
     {
         if (!z_GDU(assoc->print, &res, 0, 0))
-            yaz_log(LOG_WARN, "ODR print error: %s", 
+            yaz_log(YLOG_WARN, "ODR print error: %s", 
                 odr_errmsg(odr_geterror(assoc->print)));
         odr_reset(assoc->print);
     }
     if (!z_GDU(assoc->encode, &res, 0, 0))
     {
-        yaz_log(LOG_WARN, "ODR error when encoding PDU: %s [element %s]",
+        yaz_log(YLOG_WARN, "ODR error when encoding PDU: %s [element %s]",
                 odr_errmsg(odr_geterror(assoc->decode)),
                 odr_getelement(assoc->decode));
-        request_release(req);
         return -1;
     }
     req->response = odr_getbuf(assoc->encode, &req->len_response,
@@ -1236,7 +1245,7 @@ static int process_gdu_response(association *assoc, request *req, Z_GDU *res)
 #if 1
     if (request_head(&assoc->incoming))
     {
-        yaz_log (LOG_DEBUG, "more work to be done");
+        yaz_log (YLOG_DEBUG, "more work to be done");
         iochan_setevent(assoc->client_chan, EVENT_WORK);
     }
 #endif
@@ -1298,25 +1307,25 @@ static Z_APDU *process_initRequest(association *assoc, request *reqb)
     assoc->backend = 0;
     if (!(binitres = (*cb->bend_init)(assoc->init)))
     {
-        yaz_log(LOG_WARN, "Bad response from backend.");
+        yaz_log(YLOG_WARN, "Bad response from backend.");
         return 0;
     }
 
     assoc->backend = binitres->handle;
     if ((assoc->init->bend_sort))
-        yaz_log (LOG_DEBUG, "Sort handler installed");
+        yaz_log (YLOG_DEBUG, "Sort handler installed");
     if ((assoc->init->bend_search))
-        yaz_log (LOG_DEBUG, "Search handler installed");
+        yaz_log (YLOG_DEBUG, "Search handler installed");
     if ((assoc->init->bend_present))
-        yaz_log (LOG_DEBUG, "Present handler installed");   
+        yaz_log (YLOG_DEBUG, "Present handler installed");   
     if ((assoc->init->bend_esrequest))
-        yaz_log (LOG_DEBUG, "ESRequest handler installed");   
+        yaz_log (YLOG_DEBUG, "ESRequest handler installed");   
     if ((assoc->init->bend_delete))
-        yaz_log (LOG_DEBUG, "Delete handler installed");   
+        yaz_log (YLOG_DEBUG, "Delete handler installed");   
     if ((assoc->init->bend_scan))
-        yaz_log (LOG_DEBUG, "Scan handler installed");   
+        yaz_log (YLOG_DEBUG, "Scan handler installed");   
     if ((assoc->init->bend_segment))
-        yaz_log (LOG_DEBUG, "Segment handler installed");   
+        yaz_log (YLOG_DEBUG, "Segment handler installed");   
     
     resp->referenceId = req->referenceId;
     *options = '\0';
@@ -1420,7 +1429,7 @@ static Z_APDU *process_initRequest(association *assoc, request *reqb)
                 assoc->init->implementation_name,
                 odr_prepend(assoc->encode, "GFS", resp->implementationName));
 
-    version = odr_strdup(assoc->encode, "$Revision: 1.34 $");
+    version = odr_strdup(assoc->encode, "$Revision: 1.42 $");
     if (strlen(version) > 10)   /* check for unexpanded CVS strings */
         version[strlen(version)-2] = '\0';
     resp->implementationVersion = odr_prepend(assoc->encode,
@@ -1430,105 +1439,43 @@ static Z_APDU *process_initRequest(association *assoc, request *reqb)
 
     if (binitres->errcode)
     {
-        yaz_log(LOG_DEBUG, "Connection rejected by backend.");
+       WRBUF wr = wrbuf_alloc();
         *resp->result = 0;
         assoc->state = ASSOC_DEAD;
-        resp->userInformationField = init_diagnostics(assoc->encode,
-                                                      binitres->errcode,
-                                                      binitres->errstring);
-        yaz_log(log_request,"Init from '%s' (%s) (ver %s) Error %d %s",
-            req->implementationName ? req->implementationName :"??",
-            req->implementationId ? req->implementationId :"?", 
-            req->implementationVersion ? req->implementationVersion: "?",
-            binitres->errcode,binitres->errstring );
+        resp->userInformationField =
+           init_diagnostics(assoc->encode, binitres->errcode,
+                            binitres->errstring);
+       wr_diag(wr, binitres->errcode, binitres->errstring);
+        yaz_log(log_request, "Init from '%s' (%s) (ver %s) %s",
+               req->implementationName ? req->implementationName :"??",
+               req->implementationId ? req->implementationId :"?", 
+               req->implementationVersion ? req->implementationVersion: "?",
+               wrbuf_buf(wr));
+       wrbuf_free(wr, 1);
     }
     else
     {
         assoc->state = ASSOC_UP;
-        yaz_log(log_request,"Init from '%s' (%s) (ver %s) OK",
-            req->implementationName ? req->implementationName :"??",
-            req->implementationId ? req->implementationId :"?", 
-            req->implementationVersion ? req->implementationVersion: "?");
+        yaz_log(log_request, "Init from '%s' (%s) (ver %s) OK",
+               req->implementationName ? req->implementationName :"??",
+               req->implementationId ? req->implementationId :"?", 
+               req->implementationVersion ? req->implementationVersion: "?");
     }
 
     return apdu;
 }
 
 /*
- * Diagnostic in default format, to be returned as either a surrogate
- * or non-surrogate diagnostic in the context of an open session, or
- * as User-information when an Init is refused.
- */
-static Z_DefaultDiagFormat *justdiag(ODR odr, int error, char *addinfo)
-{
-    int *err = odr_intdup(odr, error);
-    Z_DefaultDiagFormat *dr = (Z_DefaultDiagFormat *)
-        odr_malloc (odr, sizeof(*dr));
-
-    yaz_log(log_requestdetail, "[%d] %s%s%s", error, diagbib1_str(error),
-        addinfo ? " -- " : "", addinfo ? addinfo : "");
-
-    dr->diagnosticSetId =
-        yaz_oidval_to_z3950oid (odr, CLASS_DIAGSET, VAL_BIB1);
-    dr->condition = err;
-    dr->which = Z_DefaultDiagFormat_v2Addinfo;
-    dr->u.v2Addinfo = odr_strdup (odr, addinfo ? addinfo : "");
-    return dr;
-}
-
-/*
  * Set the specified `errcode' and `errstring' into a UserInfo-1
  * external to be returned to the client in accordance with Z35.90
  * Implementor Agreement 5 (Returning diagnostics in an InitResponse):
  *      http://lcweb.loc.gov/z3950/agency/agree/initdiag.html
  */
-static Z_External *init_diagnostics(ODR odr, int error, char *addinfo)
+static Z_External *init_diagnostics(ODR odr, int error, const char *addinfo)
 {
-    Z_External *x, *x2;
-    oident oid;
-    Z_OtherInformation *u;
-    Z_OtherInformationUnit *l;
-    Z_DiagnosticFormat *d;
-    Z_DiagnosticFormat_s *e;
-
-    x = (Z_External*) odr_malloc(odr, sizeof *x);
-    x->descriptor = 0;
-    x->indirect_reference = 0;  
-    oid.proto = PROTO_Z3950;
-    oid.oclass = CLASS_USERINFO;
-    oid.value = VAL_USERINFO1;
-    x->direct_reference = odr_oiddup(odr, oid_getoidbyent(&oid));
-    x->which = Z_External_userInfo1;
-
-    u = odr_malloc(odr, sizeof *u);
-    x->u.userInfo1 = u;
-    u->num_elements = 1;
-    u->list = (Z_OtherInformationUnit**) odr_malloc(odr, sizeof *u->list);
-    u->list[0] = (Z_OtherInformationUnit*) odr_malloc(odr, sizeof *u->list[0]);
-    l = u->list[0];
-    l->category = 0;
-    l->which = Z_OtherInfo_externallyDefinedInfo;
-
-    x2 = (Z_External*) odr_malloc(odr, sizeof *x);
-    l->information.externallyDefinedInfo = x2;
-    x2->descriptor = 0;
-    x2->indirect_reference = 0;
-    oid.oclass = CLASS_DIAGSET;
-    oid.value = VAL_DIAG1;
-    x2->direct_reference = odr_oiddup(odr, oid_getoidbyent(&oid));
-    x2->which = Z_External_diag1;
-
-    d = (Z_DiagnosticFormat*) odr_malloc(odr, sizeof *d);
-    x2->u.diag1 = d;
-    d->num = 1;
-    d->elements = (Z_DiagnosticFormat_s**) odr_malloc (odr, sizeof *d->elements);
-    d->elements[0] = (Z_DiagnosticFormat_s*) odr_malloc (odr, sizeof *d->elements[0]);
-    e = d->elements[0];
-
-    e->which = Z_DiagnosticFormat_s_defaultDiagRec;
-    e->u.defaultDiagRec = justdiag(odr, error, addinfo);
-    e->message = 0;
-    return x;
+    yaz_log(log_requestdetail, "[%d] %s%s%s", error, diagbib1_str(error),
+        addinfo ? " -- " : "", addinfo ? addinfo : "");
+    return zget_init_diagnostics(odr, error, addinfo);
 }
 
 /*
@@ -1536,60 +1483,27 @@ static Z_External *init_diagnostics(ODR odr, int error, char *addinfo)
  */
 static Z_Records *diagrec(association *assoc, int error, char *addinfo)
 {
-    Z_Records *rec = (Z_Records *)
-        odr_malloc (assoc->encode, sizeof(*rec));
-    rec->which = Z_Records_NSD;
-    rec->u.nonSurrogateDiagnostic = justdiag(assoc->encode, error, addinfo);
-    return rec;
-}
+    Z_Records *rec = (Z_Records *) odr_malloc (assoc->encode, sizeof(*rec));
 
-/*
- * surrogate diagnostic.
- */
-static Z_NamePlusRecord *surrogatediagrec(association *assoc, char *dbname,
-                                          int error, char *addinfo)
-{
-    Z_NamePlusRecord *rec = (Z_NamePlusRecord *)
-        odr_malloc (assoc->encode, sizeof(*rec));
-    Z_DiagRec *drec = (Z_DiagRec *)odr_malloc (assoc->encode, sizeof(*drec));
-    
-    yaz_log(LOG_DEBUG, "SurrogateDiagnotic: %d -- %s", error, addinfo);
-    rec->databaseName = dbname;
-    rec->which = Z_NamePlusRecord_surrogateDiagnostic;
-    rec->u.surrogateDiagnostic = drec;
-    drec->which = Z_DiagRec_defaultFormat;
-    drec->u.defaultFormat = justdiag(assoc->encode, error, addinfo);
+    yaz_log(log_requestdetail, "[%d] %s%s%s", error, diagbib1_str(error),
+           addinfo ? " -- " : "", addinfo ? addinfo : "");
 
+    rec->which = Z_Records_NSD;
+    rec->u.nonSurrogateDiagnostic = zget_DefaultDiagFormat(assoc->encode,
+                                                          error, addinfo);
     return rec;
 }
 
 /*
- * multiple nonsurrogate diagnostics.
+ * surrogate diagnostic.
  */
-static Z_DiagRecs *diagrecs(association *assoc, int error, char *addinfo)
+static Z_NamePlusRecord *surrogatediagrec(association *assoc, 
+                                         const char *dbname,
+                                          int error, const char *addinfo)
 {
-    Z_DiagRecs *recs = (Z_DiagRecs *)odr_malloc (assoc->encode, sizeof(*recs));
-    int *err = odr_intdup(assoc->encode, error);
-    Z_DiagRec **recp = (Z_DiagRec **)odr_malloc (assoc->encode, sizeof(*recp));
-    Z_DiagRec *drec = (Z_DiagRec *)odr_malloc (assoc->encode, sizeof(*drec));
-    Z_DefaultDiagFormat *rec = (Z_DefaultDiagFormat *)
-        odr_malloc (assoc->encode, sizeof(*rec));
-
-    yaz_log(LOG_DEBUG, "DiagRecs: %d -- %s", error, addinfo ? addinfo : "");
-
-    recs->num_diagRecs = 1;
-    recs->diagRecs = recp;
-    recp[0] = drec;
-    drec->which = Z_DiagRec_defaultFormat;
-    drec->u.defaultFormat = rec;
-
-    rec->diagnosticSetId =
-        yaz_oidval_to_z3950oid (assoc->encode, CLASS_DIAGSET, VAL_BIB1);
-    rec->condition = err;
-
-    rec->which = Z_DefaultDiagFormat_v2Addinfo;
-    rec->u.v2Addinfo = odr_strdup (assoc->encode, addinfo ? addinfo : "");
-    return recs;
+    yaz_log(log_requestdetail, "[%d] %s%s%s", error, diagbib1_str(error),
+           addinfo ? " -- " : "", addinfo ? addinfo : "");
+    return zget_surrogateDiagRec(assoc->encode, dbname, error, addinfo);
 }
 
 static Z_Records *pack_records(association *a, char *setname, int start,
@@ -1599,7 +1513,6 @@ static Z_Records *pack_records(association *a, char *setname, int start,
                                int *oid, int *errcode)
 {
     int recno, total_length = 0, toget = *num, dumped_records = 0;
-    *errcode=0;
     Z_Records *records =
         (Z_Records *) odr_malloc (a->encode, sizeof(*records));
     Z_NamePlusRecordList *reclist =
@@ -1664,7 +1577,7 @@ static Z_Records *pack_records(association *a, char *setname, int start,
                     freq.errstring = s;
                 }
                 if (errcode)
-                    *errcode=freq.errcode;
+                    *errcode = freq.errcode;
                 return diagrec(a, freq.errcode, freq.errstring);
             }
             reclist->records[reclist->num_records] =
@@ -1678,7 +1591,7 @@ static Z_Records *pack_records(association *a, char *setname, int start,
             this_length = freq.len;
         else
             this_length = odr_total(a->encode) - total_length - dumped_records;
-        yaz_log(LOG_DEBUG, "  fetched record, len=%d, total=%d dumped=%d",
+        yaz_log(YLOG_DEBUG, "  fetched record, len=%d, total=%d dumped=%d",
             this_length, total_length, dumped_records);
         if (a->preferredMessageSize > 0 &&
                 this_length + total_length > a->preferredMessageSize)
@@ -1696,7 +1609,7 @@ static Z_Records *pack_records(association *a, char *setname, int start,
                 yaz_log(log_requestdetail, "  Record > prefmsgsz");
                 if (toget > 1)
                 {
-                    yaz_log(LOG_DEBUG, "  Dropped it");
+                    yaz_log(YLOG_DEBUG, "  Dropped it");
                     reclist->records[reclist->num_records] =
                          surrogatediagrec(a, freq.basename, 16, 0);
                     reclist->num_records++;
@@ -1790,7 +1703,7 @@ static Z_APDU *process_searchRequest(association *assoc, request *reqb,
     else
     { 
         /* FIXME - make a diagnostic for it */
-        yaz_log(LOG_WARN,"Search not supported ?!?!");
+        yaz_log(YLOG_WARN,"Search not supported ?!?!");
     }
     return response_searchRequest(assoc, reqb, bsrr, fd);
 }
@@ -1825,7 +1738,7 @@ static Z_APDU *response_searchRequest(association *assoc, request *reqb,
     *fd = -1;
     if (!bsrt && !bend_searchresponse(assoc->backend, bsrt))
     {
-        yaz_log(LOG_FATAL, "Bad result from backend");
+        yaz_log(YLOG_FATAL, "Bad result from backend");
         return 0;
     }
     else if (bsrt->errcode)
@@ -1878,12 +1791,12 @@ static Z_APDU *response_searchRequest(association *assoc, request *reqb,
             else
                 form = prefformat->value;
             resp->records = pack_records(assoc, req->resultSetName, 1,
-                toget, compp, next, presst, form, req->referenceId,
-                               req->preferredRecordSyntax, NULL);
+                                        toget, compp, next, presst, form, req->referenceId,
+                                        req->preferredRecordSyntax, NULL);
             if (!resp->records)
                 return 0;
             resp->numberOfRecordsReturned = toget;
-            returnedrecs=*toget;
+            returnedrecs = *toget;
             resp->nextResultSetPosition = next;
             resp->searchStatus = sr;
             resp->resultSetStatus = 0;
@@ -1907,14 +1820,15 @@ static Z_APDU *response_searchRequest(association *assoc, request *reqb,
         WRBUF wr=wrbuf_alloc();
         wrbuf_put_zquery(wr, req->query);
         if (bsrt->errcode)
-            wrbuf_printf(wr," ERROR %d %s", bsrt->errcode, bsrt->errstring);
+           wr_diag(wr, bsrt->errcode, bsrt->errstring);
         else
         {
-            wrbuf_printf(wr," OK:%d hits ",bsrt->hits);
+            wrbuf_printf(wr," OK:%d hits", bsrt->hits);
             if (returnedrecs)
-                wrbuf_printf(wr," Returned %d records", returnedrecs);
+                wrbuf_printf(wr, " %d records returned", returnedrecs);
         }
-        yaz_log(log_request, "Search %s", wrbuf_buf(wr) );
+        yaz_log(log_request, "Search %s %s", req->resultSetName,
+               wrbuf_buf(wr));
         wrbuf_free(wr,1);
     }
     return apdu;
@@ -1945,7 +1859,8 @@ static Z_APDU *process_presentRequest(association *assoc, request *reqb,
     Z_PresentResponse *resp;
     int *next;
     int *num;
-    int errcode=0;
+    int errcode = 0;
+    const char *errstring = 0;
 
     yaz_log(log_requestdetail, "Got PresentRequest.");
 
@@ -1980,7 +1895,8 @@ static Z_APDU *process_presentRequest(association *assoc, request *reqb,
         {
             resp->records = diagrec(assoc, bprr->errcode, bprr->errstring);
             *resp->presentStatus = Z_PresentStatus_failure;
-            errcode=bprr->errcode;
+            errcode = bprr->errcode;
+           errstring = bprr->errstring;
         }
     }
     apdu = (Z_APDU *)odr_malloc (assoc->encode, sizeof(*apdu));
@@ -1997,32 +1913,31 @@ static Z_APDU *process_presentRequest(association *assoc, request *reqb,
         *num = *req->numberOfRecordsRequested;
         resp->records =
             pack_records(assoc, req->resultSetId, *req->resultSetStartPoint,
-                     num, req->recordComposition, next, resp->presentStatus,
+                        num, req->recordComposition, next,
+                        resp->presentStatus,
                          form, req->referenceId, req->preferredRecordSyntax, 
                          &errcode);
     }
-    if (!resp->records)
-        return 0;
-    resp->numberOfRecordsReturned = num;
-    resp->nextResultSetPosition = next;
     if (log_request)
     {
-        WRBUF wr=wrbuf_alloc();
-        wrbuf_printf(wr, "Present: [%s] %d+%d ",
+        WRBUF wr = wrbuf_alloc();
+        wrbuf_printf(wr, "Present %s %d+%d ",
                 req->resultSetId, *req->resultSetStartPoint,
                 *req->numberOfRecordsRequested);
         if (*resp->presentStatus == Z_PresentStatus_failure)
-        {
-            wrbuf_printf(wr," ERROR %d ", errcode);
-        }
+           wr_diag(wr, errcode, errstring);
         else if (*resp->presentStatus == Z_PresentStatus_success)
-            wrbuf_printf(wr," OK %d records returned ", *num);
+            wrbuf_printf(wr,"OK %d records returned ", *num);
         else
-            wrbuf_printf(wr," Partial (%d) OK %d records returned ", 
+            wrbuf_printf(wr,"Partial (%d) OK %d records returned ", 
                     *resp->presentStatus, *num);
         yaz_log(log_request, "%s", wrbuf_buf(wr) );
-        wrbuf_free(wr,1);
+        wrbuf_free(wr, 1);
     }
+    if (!resp->records)
+        return 0;
+    resp->numberOfRecordsReturned = num;
+    resp->nextResultSetPosition = next;
     
     return apdu;
 }
@@ -2123,7 +2038,8 @@ static Z_APDU *process_scanRequest(association *assoc, request *reqb, int *fd)
      (*assoc->init->bend_scan))(assoc->backend, bsrr);
 
     if (bsrr->errcode)
-        diagrecs_p = diagrecs(assoc, bsrr->errcode, bsrr->errstring);
+        diagrecs_p = zget_DiagRecs(assoc->encode,
+                                  bsrr->errcode, bsrr->errstring);
     else
     {
         int i;
@@ -2175,14 +2091,14 @@ static Z_APDU *process_scanRequest(association *assoc, request *reqb, int *fd)
                     odr_malloc(assoc->encode, o->len = o->size =
                                strlen(bsrr->entries[i].term));
                 memcpy(o->buf, bsrr->entries[i].term, o->len);
-                yaz_log(LOG_DEBUG, "  term #%d: '%s' (%d)", i,
+                yaz_log(YLOG_DEBUG, "  term #%d: '%s' (%d)", i,
                          bsrr->entries[i].term, bsrr->entries[i].occurrences);
             }
             else
             {
-                Z_DiagRecs *drecs = diagrecs (assoc,
-                                              bsrr->entries[i].errcode,
-                                              bsrr->entries[i].errstring);
+                Z_DiagRecs *drecs = zget_DiagRecs(assoc->encode,
+                                                 bsrr->entries[i].errcode,
+                                                 bsrr->entries[i].errstring);
                 assert (drecs->num_diagRecs == 1);
                 e->which = Z_Entry_surrogateDiagnostic;
                 assert (drecs->diagRecs[0]);
@@ -2257,7 +2173,8 @@ static Z_APDU *process_sortRequest(association *assoc, request *reqb,
     res->resultSetStatus = 0;
     if (bsrr->errcode)
     {
-        Z_DiagRecs *dr = diagrecs (assoc, bsrr->errcode, bsrr->errstring);
+        Z_DiagRecs *dr = zget_DiagRecs(assoc->encode,
+                                      bsrr->errcode, bsrr->errstring);
         res->diagnostics = dr->diagRecs;
         res->num_diagnostics = dr->num_diagRecs;
     }
@@ -2310,7 +2227,7 @@ static Z_APDU *process_deleteRequest(association *assoc, request *reqb,
 
     bdrr->num_setnames = req->num_resultSetList;
     bdrr->setnames = req->resultSetList;
-    for (i=0;i<req->num_resultSetList;i++)
+    for (i = 0; i<req->num_resultSetList; i++)
         yaz_log(log_requestdetail, "resultset: '%s'",
                 req->resultSetList[i]);
     bdrr->stream = assoc->encode;
@@ -2353,7 +2270,6 @@ static Z_APDU *process_deleteRequest(association *assoc, request *reqb,
             res->deleteListStatuses->elements[i]->status = bdrr->statuses+i;
             res->deleteListStatuses->elements[i]->id =
                 odr_strdup (assoc->encode, bdrr->setnames[i]);
-            
         }
     }
     res->numberNotDeleted = 0;
@@ -2367,7 +2283,7 @@ static Z_APDU *process_deleteRequest(association *assoc, request *reqb,
     {
         WRBUF wr=wrbuf_alloc();
         wrbuf_printf(wr, "Delete ");
-        for (i=0;i<req->num_resultSetList;i++)
+        for (i = 0; i<req->num_resultSetList; i++)
             wrbuf_printf(wr, " '%s' ", req->resultSetList[i]);
         if (bdrr->delete_status)
             wrbuf_printf(wr," ERROR %d", bdrr->delete_status);
@@ -2458,7 +2374,7 @@ int bend_backend_respond (bend_association a, bend_request req)
     int r;
     r = process_z_request (a, req, &msg);
     if (r < 0)
-        yaz_log (LOG_WARN, "%s", msg);
+        yaz_log (YLOG_WARN, "%s", msg);
     return r;
 }
 
@@ -2532,11 +2448,11 @@ static Z_APDU *process_ESRequest(association *assoc, request *reqb, int *fd)
     }
     else
     {
-        Z_DiagRecs *diagRecs = diagrecs (assoc, esrequest.errcode,
-                                         esrequest.errstring);
-
+        Z_DiagRecs *diagRecs =
+           zget_DiagRecs(assoc->encode, esrequest.errcode,
+                         esrequest.errstring);
         /* Backend indicates error, request will not be processed */
-        yaz_log(LOG_DEBUG,"Request could not be processed...failure !");
+        yaz_log(YLOG_DEBUG,"Request could not be processed...failure !");
         *resp->operationStatus = Z_ExtendedServicesResponse_failure;
         resp->num_diagnostics = diagRecs->num_diagRecs;
         resp->diagnostics = diagRecs->diagRecs;
@@ -2554,7 +2470,7 @@ static Z_APDU *process_ESRequest(association *assoc, request *reqb, int *fd)
         resp->taskPackage = z_ext_record (assoc->encode, VAL_EXTENDED,
                                          (const char *)  esrequest.taskPackage,
                                           -1);
-    yaz_log(LOG_DEBUG,"Send the result apdu");
+    yaz_log(YLOG_DEBUG,"Send the result apdu");
     return apdu;
 }