Renamed logf function to yaz_log. Removed VC++ project files.
[yaz-moved-to-github.git] / server / seshigh.c
index 113b258..d56264f 100644 (file)
@@ -1,10 +1,40 @@
 /*
- * Copyright (c) 1995-1998, Index Data
+ * Copyright (c) 1995-1999, Index Data
  * See the file LICENSE for details.
  * Sebastian Hammer, Adam Dickmeiss
  *
  * $Log: seshigh.c,v $
- * Revision 1.85  1998-11-17 09:52:59  adam
+ * Revision 1.94  1999-08-27 09:40:32  adam
+ * Renamed logf function to yaz_log. Removed VC++ project files.
+ *
+ * Revision 1.93  1999/07/06 12:17:15  adam
+ * Added option -1 that runs server once (for profiling purposes).
+ *
+ * Revision 1.92  1999/06/17 10:54:45  adam
+ * Added facility to specify implementation version - and name
+ * for server.
+ *
+ * Revision 1.91  1999/06/01 14:29:12  adam
+ * Work on Extended Services.
+ *
+ * Revision 1.90  1999/05/27 13:02:20  adam
+ * Assigned OID for old DB Update (VAL_DBUPDATE0).
+ *
+ * Revision 1.89  1999/05/26 15:24:26  adam
+ * Fixed minor bugs regarding DB Update (introduced by previous commit).
+ *
+ * Revision 1.88  1999/04/20 09:56:48  adam
+ * Added 'name' paramter to encoder/decoder routines (typedef Odr_fun).
+ * Modified all encoders/decoders to reflect this change.
+ *
+ * Revision 1.87  1999/03/31 11:18:25  adam
+ * Implemented odr_strdup. Added Reference ID to backend server API.
+ *
+ * Revision 1.86  1999/02/02 13:57:38  adam
+ * Uses preprocessor define WIN32 instead of WINDOWS to build code
+ * for Microsoft WIN32.
+ *
+ * Revision 1.85  1998/11/17 09:52:59  adam
  * Fixed minor bug (introduced by previous commit).
  *
  * Revision 1.84  1998/11/16 16:02:32  adam
 #include <yconfig.h>
 #include <stdlib.h>
 #include <stdio.h>
-#ifdef WINDOWS
+#ifdef WIN32
 #include <process.h>
 #else
 #include <unistd.h>
@@ -377,7 +407,7 @@ association *create_association(IOCHAN channel, COMSTACK link)
                {
                    if (!(apduf = fopen(filename, "w")))
                    {
-                       logf(LOG_WARN|LOG_ERRNO, "%s", filename);
+                       yaz_log(LOG_WARN|LOG_ERRNO, "%s", filename);
                        return 0;
                    }
                    setvbuf(apduf, 0, _IONBF, 0);
@@ -389,7 +419,7 @@ association *create_association(IOCHAN channel, COMSTACK link)
                sprintf(filename + strlen(filename), ".%d", getpid());
                if (!(f = fopen(filename, "w")))
                {
-                   logf(LOG_WARN|LOG_ERRNO, "%s", filename);
+                   yaz_log(LOG_WARN|LOG_ERRNO, "%s", filename);
                    return 0;
                }
                setvbuf(f, 0, _IONBF, 0);
@@ -427,6 +457,8 @@ void destroy_association(association *h)
     request_delq(&h->incoming);
     request_delq(&h->outgoing);
     xfree(h);
+    if (control_block && control_block->one_shot)
+       exit (0);
 }
 
 static void do_close_req(association *a, int reason, char *message,
@@ -440,7 +472,7 @@ static void do_close_req(association *a, int reason, char *message,
     while (request_deq(&a->outgoing));
     if (a->version >= 3)
     {
-       logf(LOG_LOG, "Sending Close PDU, reason=%d, message=%s",
+       yaz_log(LOG_LOG, "Sending Close PDU, reason=%d, message=%s",
            reason, message ? message : "none");
        apdu.which = Z_APDU_close;
        apdu.u.close = cls;
@@ -451,7 +483,7 @@ static void do_close_req(association *a, int reason, char *message,
     }
     else
     {
-       logf(LOG_DEBUG, "v2 client. No Close PDU");
+       yaz_log(LOG_DEBUG, "v2 client. No Close PDU");
        iochan_setevent(a->client_chan, EVENT_TIMEOUT); /* force imm close */
     }
     a->state = ASSOC_DEAD;
@@ -483,14 +515,14 @@ void ir_session(IOCHAN h, int event)
     {
        if (assoc->state != ASSOC_UP)
        {
-           logf(LOG_LOG, "Final timeout - closing connection.");
+           yaz_log(LOG_LOG, "Final timeout - closing connection.");
            cs_close(conn);
            destroy_association(assoc);
            iochan_destroy(h);
        }
        else
        {
-           logf(LOG_LOG, "Session idle too long. Sending close.");
+           yaz_log(LOG_LOG, "Session idle too long. Sending close.");
            do_close(assoc, Z_Close_lackOfActivity, 0);
        }
        return;
@@ -499,12 +531,12 @@ void ir_session(IOCHAN h, int event)
     {
        if (event & EVENT_INPUT)
        {
-           logf(LOG_DEBUG, "ir_session (input)");
+           yaz_log(LOG_DEBUG, "ir_session (input)");
            assert(assoc && conn);
            /* We aren't speaking to this fellow */
            if (assoc->state == ASSOC_DEAD)
            {
-               logf(LOG_LOG, "Closed connection after reject");
+               yaz_log(LOG_LOG, "Closed connection after reject");
                cs_close(conn);
                destroy_association(assoc);
                iochan_destroy(h);
@@ -513,7 +545,7 @@ void ir_session(IOCHAN h, int event)
            if ((res = cs_get(conn, &assoc->input_buffer,
                &assoc->input_buffer_len)) <= 0)
            {
-               logf(LOG_LOG, "Connection closed by client");
+               yaz_log(LOG_LOG, "Connection closed by client");
                cs_close(conn);
                destroy_association(assoc);
                iochan_destroy(h);
@@ -525,24 +557,24 @@ void ir_session(IOCHAN h, int event)
                iochan_setevent(h, EVENT_INPUT);
                
            /* we got a complete PDU. Let's decode it */
-           logf(LOG_DEBUG, "Got PDU, %d bytes", res);
+           yaz_log(LOG_DEBUG, "Got PDU, %d bytes", res);
            req = request_get(&assoc->incoming); /* get a new request structure */
            odr_reset(assoc->decode);
            odr_setbuf(assoc->decode, assoc->input_buffer, res, 0);
-           if (!z_APDU(assoc->decode, &req->request, 0))
+           if (!z_APDU(assoc->decode, &req->request, 0, 0))
            {
-               logf(LOG_LOG, "ODR error on incoming PDU: %s [near byte %d] ",
+               yaz_log(LOG_LOG, "ODR error on incoming PDU: %s [near byte %d] ",
                    odr_errmsg(odr_geterror(assoc->decode)),
                    odr_offset(assoc->decode));
-               logf(LOG_LOG, "PDU dump:");
+               yaz_log(LOG_LOG, "PDU dump:");
                odr_dumpBER(log_file(), assoc->input_buffer, res);
                do_close(assoc, Z_Close_protocolError, "Malformed package");
                return;
            }
            req->request_mem = odr_extract_mem(assoc->decode);
-           if (assoc->print && !z_APDU(assoc->print, &req->request, 0))
+           if (assoc->print && !z_APDU(assoc->print, &req->request, 0, 0))
            {
-               logf(LOG_WARN, "ODR print error: %s", 
+               yaz_log(LOG_WARN, "ODR print error: %s", 
                    odr_errmsg(odr_geterror(assoc->print)));
                odr_reset(assoc->print);
            }
@@ -563,18 +595,18 @@ void ir_session(IOCHAN h, int event)
     {
        request *req = request_head(&assoc->outgoing);
 
-       logf(LOG_DEBUG, "ir_session (output)");
+       yaz_log(LOG_DEBUG, "ir_session (output)");
        req->state = REQUEST_PENDING;
        switch (res = cs_put(conn, req->response, req->len_response))
        {
            case -1:
-               logf(LOG_LOG, "Connection closed by client");
+               yaz_log(LOG_LOG, "Connection closed by client");
                cs_close(conn);
                destroy_association(assoc);
                iochan_destroy(h);
                break;
            case 0: /* all sent - release the request structure */
-               logf(LOG_DEBUG, "Wrote PDU, %d bytes", req->len_response);
+               yaz_log(LOG_DEBUG, "Wrote PDU, %d bytes", req->len_response);
                nmem_destroy(req->request_mem);
                request_deq(&assoc->outgoing);
                request_release(req);
@@ -586,7 +618,7 @@ void ir_session(IOCHAN h, int event)
     }
     if (event & EVENT_EXCEPT)
     {
-       logf(LOG_DEBUG, "ir_session (exception)");
+       yaz_log(LOG_DEBUG, "ir_session (exception)");
        cs_close(conn);
        destroy_association(assoc);
        iochan_destroy(h);
@@ -618,7 +650,7 @@ static int process_request(association *assoc, request *req)
                res = process_ESRequest(assoc, req, &fd);
            else
            {
-               logf(LOG_WARN, "Cannot handle EXTENDED SERVICES APDU");
+               yaz_log(LOG_WARN, "Cannot handle EXTENDED SERVICES APDU");
                return -1;
            }
            break;
@@ -627,7 +659,7 @@ static int process_request(association *assoc, request *req)
                res = process_sortRequest(assoc, req, &fd);
            else
            {
-               logf(LOG_WARN, "Cannot handle SORT APDU");
+               yaz_log(LOG_WARN, "Cannot handle SORT APDU");
                return -1;
            }
            break;
@@ -638,22 +670,22 @@ static int process_request(association *assoc, request *req)
                res = process_deleteRequest(assoc, req, &fd);
            else
            {
-               logf (LOG_WARN, "Cannot handle Delete APDU");
+               yaz_log (LOG_WARN, "Cannot handle Delete APDU");
                return -1;
            }
            break;
        default:
-           logf(LOG_WARN, "Bad APDU received");
+           yaz_log(LOG_WARN, "Bad APDU received");
            return -1;
     }
     if (res)
     {
-       logf(LOG_DEBUG, "  result immediately available");
+       yaz_log(LOG_DEBUG, "  result immediately available");
        retval = process_response(assoc, req, res);
     }
     else if (fd < 0)
     {
-       logf(LOG_DEBUG, "  result unavailble");
+       yaz_log(LOG_DEBUG, "  result unavailble");
        retval = 0;
     }
     else /* no result yet - one will be provided later */
@@ -662,7 +694,7 @@ static int process_request(association *assoc, request *req)
 
        /* Set up an I/O handler for the fd supplied by the backend */
 
-       logf(LOG_DEBUG, "   establishing handler for result");
+       yaz_log(LOG_DEBUG, "   establishing handler for result");
        req->state = REQUEST_PENDING;
        if (!(chan = iochan_create(fd, backend_response, EVENT_INPUT)))
            abort();
@@ -682,7 +714,7 @@ void backend_response(IOCHAN i, int event)
     Z_APDU *res;
     int fd;
 
-    logf(LOG_DEBUG, "backend_response");
+    yaz_log(LOG_DEBUG, "backend_response");
     assert(assoc && req && req->state != REQUEST_IDLE);
     /* determine what it is we're waiting for */
     switch (req->request->which)
@@ -696,19 +728,19 @@ void backend_response(IOCHAN i, int event)
            res = response_scanRequest(assoc, req, 0, &fd); break;
 #endif
        default:
-           logf(LOG_WARN, "Serious programmer's lapse or bug");
+           yaz_log(LOG_WARN, "Serious programmer's lapse or bug");
            abort();
     }
     if ((res && process_response(assoc, req, res) < 0) || fd < 0)
     {
-       logf(LOG_LOG, "Fatal error when talking to backend");
+       yaz_log(LOG_LOG, "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 */
     {
-       logf(LOG_DEBUG, "   no result yet");
+       yaz_log(LOG_DEBUG, "   no result yet");
        iochan_setfd(i, fd); /* in case fd has changed */
     }
 }
@@ -719,9 +751,9 @@ void backend_response(IOCHAN i, int event)
 static int process_response(association *assoc, request *req, Z_APDU *res)
 {
     odr_setbuf(assoc->encode, req->response, req->size_response, 1);
-    if (!z_APDU(assoc->encode, &res, 0))
+    if (!z_APDU(assoc->encode, &res, 0, 0))
     {
-       logf(LOG_WARN, "ODR error when encoding response: %s",
+       yaz_log(LOG_WARN, "ODR error when encoding response: %s",
            odr_errmsg(odr_geterror(assoc->decode)));
        odr_reset(assoc->encode);
        return -1;
@@ -729,9 +761,9 @@ static int process_response(association *assoc, request *req, Z_APDU *res)
     req->response = odr_getbuf(assoc->encode, &req->len_response,
        &req->size_response);
     odr_setbuf(assoc->encode, 0, 0, 0); /* don'txfree if we abort later */
-    if (assoc->print && !z_APDU(assoc->print, &res, 0))
+    if (assoc->print && !z_APDU(assoc->print, &res, 0, 0))
     {
-       logf(LOG_WARN, "ODR print error: %s", 
+       yaz_log(LOG_WARN, "ODR print error: %s", 
            odr_errmsg(odr_geterror(assoc->print)));
        odr_reset(assoc->print);
     }
@@ -744,7 +776,7 @@ static int process_response(association *assoc, request *req, Z_APDU *res)
 #if 1
     if (request_head(&assoc->incoming))
     {
-       logf (LOG_DEBUG, "more work to be done");
+       yaz_log (LOG_DEBUG, "more work to be done");
        iochan_setevent(assoc->client_chan, EVENT_WORK);
     }
 #endif
@@ -767,17 +799,20 @@ static Z_APDU *process_initRequest(association *assoc, request *reqb)
     bend_initresult *binitres;
     char options[100];
 
-    logf(LOG_LOG, "Got initRequest");
+    yaz_log(LOG_LOG, "Got initRequest");
     if (req->implementationId)
-       logf(LOG_LOG, "Id:        %s", req->implementationId);
+       yaz_log(LOG_LOG, "Id:        %s", req->implementationId);
     if (req->implementationName)
-       logf(LOG_LOG, "Name:      %s", req->implementationName);
+       yaz_log(LOG_LOG, "Name:      %s", req->implementationName);
     if (req->implementationVersion)
-       logf(LOG_LOG, "Version:   %s", req->implementationVersion);
+       yaz_log(LOG_LOG, "Version:   %s", req->implementationVersion);
 
     binitreq.stream = assoc->encode;
     binitreq.configname = "default-config";
     binitreq.auth = req->idAuthentication;
+    binitreq.referenceId = req->referenceId;
+    binitreq.implementation_version = 0;
+    binitreq.implementation_name = 0;
     binitreq.bend_sort = NULL;
     binitreq.bend_search = NULL;
     binitreq.bend_present = NULL;
@@ -785,21 +820,21 @@ static Z_APDU *process_initRequest(association *assoc, request *reqb)
     binitreq.bend_delete = NULL;
     if (!(binitres = bend_init(&binitreq)))
     {
-       logf(LOG_WARN, "Bad response from backend.");
+       yaz_log(LOG_WARN, "Bad response from backend.");
        return 0;
     }
 
     assoc->backend = binitres->handle;
     if ((assoc->bend_sort = (int (*)())binitreq.bend_sort))
-       logf (LOG_DEBUG, "Sort handler installed");
+       yaz_log (LOG_DEBUG, "Sort handler installed");
     if ((assoc->bend_search = (int (*)())binitreq.bend_search))
-       logf (LOG_DEBUG, "Search handler installed");
+       yaz_log (LOG_DEBUG, "Search handler installed");
     if ((assoc->bend_present = (int (*)())binitreq.bend_present))
-       logf (LOG_DEBUG, "Present handler installed");   
+       yaz_log (LOG_DEBUG, "Present handler installed");   
     if ((assoc->bend_esrequest = (int (*)())binitreq.bend_esrequest))
-       logf (LOG_DEBUG, "ESRequest handler installed");   
+       yaz_log (LOG_DEBUG, "ESRequest handler installed");   
     if ((assoc->bend_delete = (int (*)())binitreq.bend_delete))
-       logf (LOG_DEBUG, "Delete handler installed");   
+       yaz_log (LOG_DEBUG, "Delete handler installed");   
     
     resp->referenceId = req->referenceId;
     *options = '\0';
@@ -860,7 +895,7 @@ static Z_APDU *process_initRequest(association *assoc, request *reqb)
        ODR_MASK_SET(resp->protocolVersion, Z_ProtocolVersion_3);
        assoc->version = 3;
     }
-    logf(LOG_LOG, "Negotiated to v%d: %s", assoc->version, options);
+    yaz_log(LOG_LOG, "Negotiated to v%d: %s", assoc->version, options);
     assoc->maximumRecordSize = *req->maximumRecordSize;
     if (assoc->maximumRecordSize > control_block->maxrecordsize)
        assoc->maximumRecordSize = control_block->maxrecordsize;
@@ -869,10 +904,33 @@ static Z_APDU *process_initRequest(association *assoc, request *reqb)
        assoc->preferredMessageSize = assoc->maximumRecordSize;
     resp->preferredMessageSize = &assoc->preferredMessageSize;
     resp->maximumRecordSize = &assoc->maximumRecordSize;
+
     resp->implementationName = "Index Data/YAZ Generic Frontend Server";
+
+    if (binitreq.implementation_name)
+    {
+       char *nv = (char *)
+           odr_malloc (assoc->encode,
+                       strlen(binitreq.implementation_name) + 3 + 
+                              strlen(resp->implementationName));
+       sprintf (nv, "%s %s",
+                resp->implementationName, binitreq.implementation_name);
+        resp->implementationName = nv;
+    }
+    if (binitreq.implementation_version)
+    {
+       char *nv = (char *)
+           odr_malloc (assoc->encode,
+                       strlen(binitreq.implementation_version) + 3 + 
+                              strlen(resp->implementationVersion));
+       sprintf (nv, "%s %s",
+                resp->implementationVersion, binitreq.implementation_version);
+        resp->implementationVersion = nv;
+    }
+
     if (binitres->errcode)
     {
-       logf(LOG_LOG, "Connection rejected by backend.");
+       yaz_log(LOG_LOG, "Connection rejected by backend.");
        *resp->result = 0;
        assoc->state = ASSOC_DEAD;
     }
@@ -916,23 +974,19 @@ static Z_Records *diagrec(association *assoc, int error, char *addinfo)
     bib1.oclass = CLASS_DIAGSET;
     bib1.value = VAL_BIB1;
 
-    logf(LOG_DEBUG, "Diagnostic: %d -- %s", error, addinfo ? addinfo :
+    yaz_log(LOG_DEBUG, "Diagnostic: %d -- %s", error, addinfo ? addinfo :
        "NULL");
     *err = error;
     rec->which = Z_Records_NSD;
 #if ASN_COMPILED
     rec->u.nonSurrogateDiagnostic = dr;
 #else
-#ifdef Z_95
     rec->u.nonSurrogateDiagnostic = drec;
     drec->which = Z_DiagRec_defaultFormat;
     drec->u.defaultFormat = dr;
-#else
-    rec->u.nonSurrogateDiagnostic = dr;
-#endif
 #endif
-    dr->diagnosticSetId = odr_oiddup (assoc->encode,
-                                      oid_ent_to_oid(&bib1, oid));
+    dr->diagnosticSetId =
+       odr_oiddup (assoc->encode, oid_ent_to_oid(&bib1, oid));
     dr->condition = err;
     set_addinfo (dr, addinfo);
     return rec;
@@ -945,17 +999,19 @@ static Z_NamePlusRecord *surrogatediagrec(association *assoc, char *dbname,
                                          int error, char *addinfo)
 {
     int oid[OID_SIZE];
-    Z_NamePlusRecord *rec = (Z_NamePlusRecord *)odr_malloc (assoc->encode, sizeof(*rec));
+    Z_NamePlusRecord *rec = (Z_NamePlusRecord *)
+       odr_malloc (assoc->encode, sizeof(*rec));
     int *err = (int *)odr_malloc (assoc->encode, sizeof(*err));
     oident bib1;
     Z_DiagRec *drec = (Z_DiagRec *)odr_malloc (assoc->encode, sizeof(*drec));
-    Z_DefaultDiagFormat *dr = (Z_DefaultDiagFormat *)odr_malloc (assoc->encode, sizeof(*dr));
-
+    Z_DefaultDiagFormat *dr = (Z_DefaultDiagFormat *)
+       odr_malloc (assoc->encode, sizeof(*dr));
+    
     bib1.proto = assoc->proto;
     bib1.oclass = CLASS_DIAGSET;
     bib1.value = VAL_BIB1;
 
-    logf(LOG_DEBUG, "SurrogateDiagnotic: %d -- %s", error, addinfo);
+    yaz_log(LOG_DEBUG, "SurrogateDiagnotic: %d -- %s", error, addinfo);
     *err = error;
     rec->databaseName = dbname;
     rec->which = Z_NamePlusRecord_surrogateDiagnostic;
@@ -983,7 +1039,7 @@ static Z_DiagRecs *diagrecs(association *assoc, int error, char *addinfo)
     Z_DiagRec *drec = (Z_DiagRec *)odr_malloc (assoc->encode, sizeof(*drec));
     Z_DefaultDiagFormat *rec = (Z_DefaultDiagFormat *)odr_malloc (assoc->encode, sizeof(*rec));
 
-    logf(LOG_DEBUG, "DiagRecs: %d -- %s", error, addinfo ? addinfo : "");
+    yaz_log(LOG_DEBUG, "DiagRecs: %d -- %s", error, addinfo ? addinfo : "");
     bib1.proto = assoc->proto;
     bib1.oclass = CLASS_DIAGSET;
     bib1.value = VAL_BIB1;
@@ -1011,9 +1067,9 @@ static Z_DiagRecs *diagrecs(association *assoc, int error, char *addinfo)
 
 static Z_Records *pack_records(association *a, char *setname, int start,
                                int *num, Z_RecordComposition *comp,
-                               int *next, int *pres, oid_value format)
+                               int *next, int *pres, oid_value format,
+                               Z_ReferenceId *referenceId)
 {
-    int oid[OID_SIZE];
     int recno, total_length = 0, toget = *num, dumped_records = 0;
     Z_Records *records =
        (Z_Records *) odr_malloc (a->encode, sizeof(*records));
@@ -1021,7 +1077,6 @@ static Z_Records *pack_records(association *a, char *setname, int start,
        (Z_NamePlusRecordList *) odr_malloc (a->encode, sizeof(*reclist));
     Z_NamePlusRecord **list =
        (Z_NamePlusRecord **) odr_malloc (a->encode, sizeof(*list) * toget);
-    oident recform;
 
     records->which = Z_Records_DBOSD;
     records->u.databaseOrSurDiagnostics = reclist;
@@ -1031,17 +1086,15 @@ static Z_Records *pack_records(association *a, char *setname, int start,
     *num = 0;
     *next = 0;
 
-    logf(LOG_LOG, "Request to pack %d+%d", start, toget);
-    logf(LOG_DEBUG, "pms=%d, mrs=%d", a->preferredMessageSize,
+    yaz_log(LOG_LOG, "Request to pack %d+%d", start, toget);
+    yaz_log(LOG_DEBUG, "pms=%d, mrs=%d", a->preferredMessageSize,
        a->maximumRecordSize);
     for (recno = start; reclist->num_records < toget; recno++)
     {
        bend_fetchrequest freq;
        bend_fetchresult *fres;
        Z_NamePlusRecord *thisrec;
-       Z_DatabaseRecord *thisext;
        int this_length = 0;
-
        /*
         * we get the number of bytes allocated on the stream before any
         * allocation done by the backend - this should give us a reasonable
@@ -1054,6 +1107,7 @@ static Z_Records *pack_records(association *a, char *setname, int start,
        freq.format = format;
        freq.stream = a->encode;
        freq.surrogate_flag = 0;
+       freq.referenceId = referenceId;
        if (!(fres = bend_fetch(a->backend, &freq, 0)))
        {
            *pres = Z_PRES_FAILURE;
@@ -1079,24 +1133,24 @@ static Z_Records *pack_records(association *a, char *setname, int start,
            this_length = fres->len;
        else
            this_length = odr_total(a->encode) - total_length;
-       logf(LOG_DEBUG, "  fetched record, len=%d, total=%d",
+       yaz_log(LOG_DEBUG, "  fetched record, len=%d, total=%d",
            this_length, total_length);
        if (this_length + total_length > a->preferredMessageSize)
        {
            /* record is small enough, really */
            if (this_length <= a->preferredMessageSize)
            {
-               logf(LOG_DEBUG, "  Dropped last normal-sized record");
+               yaz_log(LOG_DEBUG, "  Dropped last normal-sized record");
                *pres = Z_PRES_PARTIAL_2;
                break;
            }
            /* record can only be fetched by itself */
            if (this_length < a->maximumRecordSize)
            {
-               logf(LOG_DEBUG, "  Record > prefmsgsz");
+               yaz_log(LOG_DEBUG, "  Record > prefmsgsz");
                if (toget > 1)
                {
-                   logf(LOG_DEBUG, "  Dropped it");
+                   yaz_log(LOG_DEBUG, "  Dropped it");
                    reclist->records[reclist->num_records] =
                         surrogatediagrec(a, fres->basename, 16, 0);
                    reclist->num_records++;
@@ -1107,7 +1161,7 @@ static Z_Records *pack_records(association *a, char *setname, int start,
            }
            else /* too big entirely */
            {
-               logf(LOG_DEBUG, "Record > maxrcdsz");
+               yaz_log(LOG_DEBUG, "Record > maxrcdsz");
                reclist->records[reclist->num_records] =
                    surrogatediagrec(a, fres->basename, 17, 0);
                reclist->num_records++;
@@ -1117,77 +1171,18 @@ static Z_Records *pack_records(association *a, char *setname, int start,
            }
        }
 
-       if (!(thisrec = (Z_NamePlusRecord *)odr_malloc(a->encode, sizeof(*thisrec))))
+       if (!(thisrec = (Z_NamePlusRecord *)
+             odr_malloc(a->encode, sizeof(*thisrec))))
            return 0;
        if (!(thisrec->databaseName = (char *)odr_malloc(a->encode,
            strlen(fres->basename) + 1)))
            return 0;
        strcpy(thisrec->databaseName, fres->basename);
        thisrec->which = Z_NamePlusRecord_databaseRecord;
-       if (!(thisrec->u.databaseRecord = thisext = (Z_External *)odr_malloc(a->encode,
-           sizeof(Z_DatabaseRecord))))
+       thisrec->u.databaseRecord = z_ext_record(a->encode, fres->format,
+                                                fres->record, fres->len);
+       if (!thisrec->u.databaseRecord)
            return 0;
-       recform.proto = a->proto;
-       recform.oclass = CLASS_RECSYN;
-       recform.value = fres->format;
-       thisext->direct_reference = odr_oiddup(a->encode,
-                                              oid_ent_to_oid(&recform, oid));
-       thisext->indirect_reference = 0;
-       thisext->descriptor = 0;
-       if (fres->len < 0) /* Structured data */
-       {
-           switch (fres->format)
-           {
-               case VAL_SUTRS: thisext->which = Z_External_sutrs; break;
-               case VAL_GRS1: thisext->which = Z_External_grs1; break;
-               case VAL_EXPLAIN: thisext->which = Z_External_explainRecord;
-                   break;
-               case VAL_SUMMARY: thisext->which = Z_External_summary; break;
-               case VAL_OPAC: thisext->which = Z_External_OPAC; break;
-
-               default:
-                   logf(LOG_FATAL, "Unknown structured format from backend.");
-                   return 0;
-           }
-
-           /*
-            * We cheat on the pointers here. Obviously, the record field
-            * of the backend-fetch structure should have been a union for
-            * correctness, but we're stuck with this for backwards
-            * compatibility.
-            */
-           thisext->u.grs1 = (Z_GenericRecord*) fres->record;
-       }
-       else if (fres->format == VAL_SUTRS) /* SUTRS is a single-ASN.1-type */
-       {
-#if 0
-           Z_SUTRS *sutrs = (Z_SUTRS *)odr_malloc(a->encode, 1+fres->len);
-            
-           memcpy(sutrs, fres->record, fres->len);
-           sutrs[fres->len] = '\0';
-#else
-           Odr_oct *sutrs = (Odr_oct *)odr_malloc(a->encode, sizeof(*sutrs));
-
-           thisext->which = Z_External_sutrs;
-           thisext->u.sutrs = sutrs;
-           sutrs->buf = (unsigned char *)odr_malloc(a->encode, fres->len);
-           sutrs->len = sutrs->size = fres->len;
-           memcpy(sutrs->buf, fres->record, fres->len);
-#endif
-       }
-       else /* octet-aligned record. */
-       {
-           thisext->which = Z_External_octet;
-           if (!(thisext->u.octet_aligned = (Odr_oct *)odr_malloc(a->encode,
-               sizeof(Odr_oct))))
-               return 0;
-           if (!(thisext->u.octet_aligned->buf = (unsigned char *)odr_malloc(a->encode,
-               fres->len)))
-               return 0;
-           memcpy(thisext->u.octet_aligned->buf, fres->record, fres->len);
-           thisext->u.octet_aligned->len = thisext->u.octet_aligned->size =
-               fres->len;
-       }
        reclist->records[reclist->num_records] = thisrec;
        reclist->num_records++;
        *next = fres->last_in_set ? 0 : recno + 1;
@@ -1203,19 +1198,19 @@ static Z_APDU *process_searchRequest(association *assoc, request *reqb,
     bend_search_rr *bsrr = 
        (bend_search_rr *)nmem_malloc (reqb->request_mem, sizeof(*bsrr));
     
-    logf(LOG_LOG, "Got SearchRequest.");
-    save_referenceId (reqb, req->referenceId);
-    /* store ref id in request */
+    yaz_log(LOG_LOG, "Got SearchRequest.");
     bsrr->fd = fd;
     bsrr->request = reqb;
     bsrr->association = assoc;
+    bsrr->referenceId = req->referenceId;
+    save_referenceId (reqb, bsrr->referenceId);
 
-    logf (LOG_LOG, "ResultSet '%s'", req->resultSetName);
+    yaz_log (LOG_LOG, "ResultSet '%s'", req->resultSetName);
     if (req->databaseNames)
     {
        int i;
        for (i = 0; i < req->num_databaseNames; i++)
-           logf (LOG_LOG, "Database '%s'", req->databaseNames[i]);
+           yaz_log (LOG_LOG, "Database '%s'", req->databaseNames[i]);
     }
     switch (req->query->which)
     {
@@ -1249,9 +1244,10 @@ static Z_APDU *process_searchRequest(association *assoc, request *reqb,
        bsrq.num_bases = req->num_databaseNames;
        bsrq.basenames = req->databaseNames;
        bsrq.query = req->query;
+        bsrq.referenceId = req->referenceId;
        bsrq.stream = assoc->encode;
        bsrq.decode = assoc->decode;
-       if (!(bsrt = bend_search(assoc->backend, &bsrq, fd)))
+       if (!(bsrt = bend_search (assoc->backend, &bsrq, fd)))
            return 0;
        bsrr->hits = bsrt->hits;
        bsrr->errcode = bsrt->errcode;
@@ -1274,7 +1270,8 @@ static Z_APDU *response_searchRequest(association *assoc, request *reqb,
 {
     Z_SearchRequest *req = reqb->request->u.searchRequest;
     Z_APDU *apdu = (Z_APDU *)odr_malloc (assoc->encode, sizeof(*apdu));
-    Z_SearchResponse *resp = (Z_SearchResponse *)odr_malloc (assoc->encode, sizeof(*resp));
+    Z_SearchResponse *resp = (Z_SearchResponse *)
+       odr_malloc (assoc->encode, sizeof(*resp));
     int *nulint = (int *)odr_malloc (assoc->encode, sizeof(*nulint));
     bool_t *sr = (bool_t *)odr_malloc (assoc->encode, sizeof(*sr));
     int *next = (int *)odr_malloc (assoc->encode, sizeof(*next));
@@ -1293,7 +1290,7 @@ static Z_APDU *response_searchRequest(association *assoc, request *reqb,
     *fd = -1;
     if (!bsrt && !bend_searchresponse(assoc->backend, bsrt))
     {
-       logf(LOG_FATAL, "Bad result from backend");
+       yaz_log(LOG_FATAL, "Bad result from backend");
        return 0;
     }
     else if (bsrt->errcode)
@@ -1347,7 +1344,7 @@ 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);
+               toget, compp, next, presst, form, req->referenceId);
            if (!resp->records)
                return 0;
            resp->numberOfRecordsReturned = toget;
@@ -1397,7 +1394,7 @@ static Z_APDU *process_presentRequest(association *assoc, request *reqb,
     int *next;
     int *num;
 
-    logf(LOG_LOG, "Got PresentRequest.");
+    yaz_log(LOG_LOG, "Got PresentRequest.");
 
     if (!(prefformat = oid_getentbyoid(req->preferredRecordSyntax)) ||
        prefformat->oclass != CLASS_RECSYN)
@@ -1406,19 +1403,22 @@ static Z_APDU *process_presentRequest(association *assoc, request *reqb,
        form = prefformat->value;
     if (assoc->bend_present)
     {
-       bend_present_rr *bprr = (bend_present_rr *)nmem_malloc (reqb->request_mem, sizeof(*bprr));
+       bend_present_rr *bprr = (bend_present_rr *)
+           nmem_malloc (reqb->request_mem, sizeof(*bprr));
        bprr->setname = req->resultSetId;
        bprr->start = *req->resultSetStartPoint;
        bprr->number = *req->numberOfRecordsRequested;
        bprr->format = form;
        bprr->comp = req->recordComposition;
+       bprr->referenceId = req->referenceId;
        bprr->stream = assoc->encode;
        bprr->request = reqb;
        bprr->association = assoc;
        bprr->errcode = 0;
        bprr->errstring = NULL;
-       ((int (*)(void *, bend_present_rr *))(*assoc->bend_present))(assoc->backend, bprr);
-
+       ((int (*)(void *, bend_present_rr *))(*assoc->bend_present))(
+           assoc->backend, bprr);
+       
        if (!bprr->request)
            return 0;
     }
@@ -1438,7 +1438,8 @@ static Z_APDU *process_presentRequest(association *assoc, request *reqb,
     
     resp->records =
        pack_records(assoc, req->resultSetId, *req->resultSetStartPoint,
-                    num, req->recordComposition, next, presst, form);
+                    num, req->recordComposition, next, presst, form,
+                     req->referenceId);
     if (!resp->records)
        return 0;
     resp->numberOfRecordsReturned = num;
@@ -1456,18 +1457,21 @@ static Z_APDU *process_scanRequest(association *assoc, request *reqb, int *fd)
 {
     Z_ScanRequest *req = reqb->request->u.scanRequest;
     Z_APDU *apdu = (Z_APDU *)odr_malloc (assoc->encode, sizeof(*apdu));
-    Z_ScanResponse *res = (Z_ScanResponse *)odr_malloc (assoc->encode, sizeof(*res));
-    int *scanStatus = (int *)odr_malloc (assoc->encode, sizeof(*scanStatus));
-    int *numberOfEntriesReturned =
-         (int *)odr_malloc (assoc->encode, sizeof(*numberOfEntriesReturned));
-    Z_ListEntries *ents = (Z_ListEntries *)odr_malloc (assoc->encode, sizeof(*ents));
+    Z_ScanResponse *res = (Z_ScanResponse *)
+       odr_malloc (assoc->encode, sizeof(*res));
+    int *scanStatus = (int *)
+       odr_malloc (assoc->encode, sizeof(*scanStatus));
+    int *numberOfEntriesReturned = (int *)
+       odr_malloc (assoc->encode, sizeof(*numberOfEntriesReturned));
+    Z_ListEntries *ents = (Z_ListEntries *)
+       odr_malloc (assoc->encode, sizeof(*ents));
     Z_DiagRecs *diagrecs_p = NULL;
     oident *attent;
     bend_scanrequest srq;
     bend_scanresult *srs;
     oident *attset;
 
-    logf(LOG_LOG, "Got ScanRequest");
+    yaz_log(LOG_LOG, "Got ScanRequest");
     *scanStatus = Z_Scan_failure;
     *numberOfEntriesReturned = 0;
 
@@ -1498,12 +1502,13 @@ static Z_APDU *process_scanRequest(association *assoc, request *reqb, int *fd)
        {
            int i;
            for (i = 0; i < req->num_databaseNames; i++)
-               logf (LOG_LOG, "Database '%s'", req->databaseNames[i]);
+               yaz_log (LOG_LOG, "Database '%s'", req->databaseNames[i]);
        }
        srq.num_bases = req->num_databaseNames;
        srq.basenames = req->databaseNames;
        srq.num_entries = *req->numberOfTermsRequested;
        srq.term = req->termListAndStartPoint;
+       srq.referenceId = req->referenceId;
        srq.stream = assoc->encode;
        if (!(attset = oid_getentbyoid(req->attributeSet)) ||
            attset->oclass != CLASS_RECSYN)
@@ -1558,7 +1563,7 @@ static Z_APDU *process_scanRequest(association *assoc, request *reqb, int *fd)
                        odr_malloc(assoc->encode, o->len = o->size =
                                   strlen(srs->entries[i].term));
                    memcpy(o->buf, srs->entries[i].term, o->len);
-                   logf(LOG_DEBUG, "  term #%d: '%s' (%d)", i,
+                   yaz_log(LOG_DEBUG, "  term #%d: '%s' (%d)", i,
                         srs->entries[i].term, srs->entries[i].occurrences);
                }
                else
@@ -1586,12 +1591,14 @@ static Z_APDU *process_sortRequest(association *assoc, request *reqb,
     int *fd)
 {
     Z_SortRequest *req = reqb->request->u.sortRequest;
-    Z_SortResponse *res = (Z_SortResponse *)odr_malloc (assoc->encode, sizeof(*res));
-    bend_sort_rr *bsrr = (bend_sort_rr *)odr_malloc (assoc->encode, sizeof(*bsrr));
+    Z_SortResponse *res = (Z_SortResponse *)
+       odr_malloc (assoc->encode, sizeof(*res));
+    bend_sort_rr *bsrr = (bend_sort_rr *)
+       odr_malloc (assoc->encode, sizeof(*bsrr));
 
     Z_APDU *apdu = (Z_APDU *)odr_malloc (assoc->encode, sizeof(*apdu));
 
-    logf(LOG_LOG, "Got SortRequest.");
+    yaz_log(LOG_LOG, "Got SortRequest.");
 
 #ifdef ASN_COMPILED
     bsrr->num_input_setnames = req->num_inputResultSetNames;
@@ -1600,6 +1607,7 @@ static Z_APDU *process_sortRequest(association *assoc, request *reqb,
     bsrr->num_input_setnames = req->inputResultSetNames->num_strings;
     bsrr->input_setnames = req->inputResultSetNames->strings;
 #endif
+    bsrr->referenceId = req->referenceId;
     bsrr->output_setname = req->sortedResultSetName;
     bsrr->sort_sequence = req->sortSequence;
     bsrr->stream = assoc->encode;
@@ -1607,11 +1615,13 @@ static Z_APDU *process_sortRequest(association *assoc, request *reqb,
     bsrr->sort_status = Z_SortStatus_failure;
     bsrr->errcode = 0;
     bsrr->errstring = 0;
-
-    ((int (*)(void *, bend_sort_rr *))(*assoc->bend_sort))(assoc->backend, bsrr);
-
-    res->referenceId = req->referenceId;
-    res->sortStatus = (int *)odr_malloc (assoc->encode, sizeof(*res->sortStatus));
+    
+    ((int (*)(void *, bend_sort_rr *))(*assoc->bend_sort))(assoc->backend,
+                                                          bsrr);
+    
+    res->referenceId = bsrr->referenceId;
+    res->sortStatus = (int *)
+       odr_malloc (assoc->encode, sizeof(*res->sortStatus));
     *res->sortStatus = bsrr->sort_status;
     res->resultSetStatus = 0;
     if (bsrr->errcode)
@@ -1648,12 +1658,13 @@ static Z_APDU *process_deleteRequest(association *assoc, request *reqb,
        odr_malloc (assoc->encode, sizeof(*bdrr));
     Z_APDU *apdu = (Z_APDU *)odr_malloc (assoc->encode, sizeof(*apdu));
 
-    logf(LOG_LOG, "Got DeleteRequest.");
+    yaz_log(LOG_LOG, "Got DeleteRequest.");
 
     bdrr->num_setnames = req->num_resultSetList;
     bdrr->setnames = req->resultSetList;
     bdrr->stream = assoc->encode;
     bdrr->function = *req->deleteFunction;
+    bdrr->referenceId = req->referenceId;
 
     ((int (*)(void *, bend_delete_rr *))
      (*assoc->bend_delete))(assoc->backend, bdrr);
@@ -1692,13 +1703,13 @@ static void process_close(association *assoc, request *reqb)
        "unspecified"
     };
 
-    logf(LOG_LOG, "Got Close, reason %s, message %s",
+    yaz_log(LOG_LOG, "Got Close, reason %s, message %s",
        reasons[*req->closeReason], req->diagnosticInformation ?
        req->diagnosticInformation : "NULL");
     if (assoc->version < 3) /* to make do_force respond with close */
        assoc->version = 3;
-    do_close_req(assoc, Z_Close_finished, "Association terminated by client",
-                reqb);
+    do_close_req(assoc, Z_Close_finished,
+                "Association terminated by client", reqb);
 }
 
 void save_referenceId (request *reqb, Z_ReferenceId *refid)
@@ -1762,7 +1773,6 @@ void *bend_request_getdata(bend_request r)
     return r->clientData;
 }
 
-/* Chas: Added in from DALI */
 static Z_APDU *process_ESRequest(association *assoc, request *reqb, int *fd)
 {
     bend_esrequest_rr esrequest;
@@ -1772,7 +1782,7 @@ static Z_APDU *process_ESRequest(association *assoc, request *reqb, int *fd)
 
     Z_ExtendedServicesResponse *resp = apdu->u.extendedServicesResponse;
 
-    logf(LOG_DEBUG,"inside Process esRequest");
+    yaz_log(LOG_DEBUG,"inside Process esRequest");
 
     esrequest.esr = reqb->request->u.extendedServicesRequest;
     esrequest.stream = assoc->encode;
@@ -1780,9 +1790,10 @@ static Z_APDU *process_ESRequest(association *assoc, request *reqb, int *fd)
     esrequest.errstring = NULL;
     esrequest.request = reqb;
     esrequest.association = assoc;
+    esrequest.referenceId = req->referenceId;
     
-    ((int (*)(void *, bend_esrequest_rr *))(*assoc->bend_esrequest))(assoc->backend,
-                                                                  &esrequest);
+    ((int (*)(void *, bend_esrequest_rr *))(*assoc->bend_esrequest))
+       (assoc->backend, &esrequest);
     
     /* If the response is being delayed, return NULL */
     if (esrequest.request == NULL)
@@ -1790,23 +1801,31 @@ static Z_APDU *process_ESRequest(association *assoc, request *reqb, int *fd)
 
     resp->referenceId = req->referenceId;
 
-    if ( esrequest.errcode == 0 )
+    if (esrequest.errcode == -1)
     {
         /* Backend service indicates request will be processed */
-        logf(LOG_DEBUG,"Request will be processed...Good !");
+        yaz_log(LOG_DEBUG,"Request could be processed...Accepted !");
+        *resp->operationStatus = Z_ExtendedServicesResponse_accepted;
+    }
+    else if (esrequest.errcode == 0)
+    {
+        /* Backend service indicates request will be processed */
+        yaz_log(LOG_DEBUG,"Request could be processed...Done !");
         *resp->operationStatus = Z_ExtendedServicesResponse_done;
     }
     else
     {
+       Z_DiagRecs *diagRecs = diagrecs (assoc, esrequest.errcode,
+                                        esrequest.errstring);
+
         /* Backend indicates error, request will not be processed */
-        logf(LOG_DEBUG,"Request will not be processed...BAD !");
+        yaz_log(LOG_DEBUG,"Request could not be processed...failure !");
         *resp->operationStatus = Z_ExtendedServicesResponse_failure;
+       resp->num_diagnostics = diagRecs->num_diagRecs;
+       resp->diagnostics = diagRecs->diagRecs;
     }
     /* Do something with the members of bend_extendedservice */
 
-    logf(LOG_DEBUG,"Send the result apdu");
-
+    yaz_log(LOG_DEBUG,"Send the result apdu");
     return apdu;
 }
-
-/* Chas: End of addition from DALI */