Change return values for yaz_retrieval_request a bit and improve
[yaz-moved-to-github.git] / src / seshigh.c
index 1bdede6..f6dedb5 100644 (file)
@@ -1,11 +1,13 @@
 /*
- * Copyright (c) 1995-2004, Index Data
+ * Copyright (C) 1995-2005, Index Data ApS
  * See the file LICENSE for details.
  *
- * $Id: seshigh.c,v 1.23 2004-03-29 15:09:14 adam Exp $
+ * $Id: seshigh.c,v 1.79 2006-05-08 19:48:26 adam Exp $
  */
-
-/*
+/**
+ * \file seshigh.c
+ * \brief Implements GFS session logic.
+ *
  * Frontend server logic.
  *
  * This code receives incoming APDUs, and handles client requests by means
 
 #include <stdlib.h>
 #include <stdio.h>
+#include <assert.h>
+#include <ctype.h>
+
+#if HAVE_SYS_TYPES_H
 #include <sys/types.h>
+#endif
+#if HAVE_SYS_STAT_H
+#include <sys/stat.h>
+#endif
+
 #ifdef WIN32
 #include <io.h>
 #define S_ISREG(x) (x & _S_IFREG)
 #include <process.h>
-#include <sys/stat.h>
-#else
-#include <sys/stat.h>
+#endif
+
+#if HAVE_UNISTD_H
 #include <unistd.h>
 #endif
-#include <assert.h>
-#include <ctype.h>
+
+#if HAVE_XML2
+#include <libxml/parser.h>
+#include <libxml/tree.h>
+#endif
 
 #include <yaz/yconfig.h>
 #include <yaz/xmalloc.h>
 #include <yaz/comstack.h>
 #include "eventl.h"
 #include "session.h"
+#include "mime.h"
 #include <yaz/proto.h>
 #include <yaz/oid.h>
 #include <yaz/log.h>
 #include <yaz/logrpn.h>
+#include <yaz/querytowrbuf.h>
 #include <yaz/statserv.h>
 #include <yaz/diagbib1.h>
 #include <yaz/charneg.h>
@@ -66,7 +82,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,
@@ -81,78 +98,85 @@ static Z_APDU *process_deleteRequest(association *assoc, request *reqb,
     int *fd);
 static Z_APDU *process_segmentRequest (association *assoc, request *reqb);
 
-static FILE *apduf = 0; /* for use in static mode */
-static statserv_options_block *control_block = 0;
-
 static Z_APDU *process_ESRequest(association *assoc, request *reqb, int *fd);
 
+/* dynamic logging levels */
+static int logbits_set = 0;
+static int log_session = 0; 
+static int log_request = 0; /* one-line logs for requests */
+static int log_requestdetail = 0;  /* more detailed stuff */
+
+/** get_logbits sets global loglevel bits */
+static void get_logbits()
+{ /* needs to be called after parsing cmd-line args that can set loglevels!*/
+    if (!logbits_set)
+    {
+        logbits_set = 1;
+        log_session = yaz_log_module_level("session"); 
+        log_request = yaz_log_module_level("request"); 
+        log_requestdetail = yaz_log_module_level("requestdetail"); 
+    }
+}
+
+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.
  *  link     : communications channel.
  * Returns: 0 or a new association handle.
  */
-association *create_association(IOCHAN channel, COMSTACK link)
+association *create_association(IOCHAN channel, COMSTACK link,
+                                const char *apdufile)
 {
     association *anew;
 
-    if (!control_block)
-       control_block = statserv_getcontrol();
+    if (!logbits_set)
+        get_logbits();
     if (!(anew = (association *)xmalloc(sizeof(*anew))))
-       return 0;
+        return 0;
     anew->init = 0;
     anew->version = 0;
+    anew->last_control = 0;
     anew->client_chan = channel;
     anew->client_link = link;
     anew->cs_get_mask = 0;
     anew->cs_put_mask = 0;
     anew->cs_accept_mask = 0;
     if (!(anew->decode = odr_createmem(ODR_DECODE)) ||
-       !(anew->encode = odr_createmem(ODR_ENCODE)))
-       return 0;
-    if (*control_block->apdufile)
+        !(anew->encode = odr_createmem(ODR_ENCODE)))
+        return 0;
+    if (apdufile && *apdufile)
     {
-       char filename[256];
-       FILE *f;
+        FILE *f;
 
-       strcpy(filename, control_block->apdufile);
-       if (!(anew->print = odr_createmem(ODR_PRINT)))
-           return 0;
-       if (*control_block->apdufile == '@')
+        if (!(anew->print = odr_createmem(ODR_PRINT)))
+            return 0;
+        if (*apdufile == '@')
         {
-           odr_setprint(anew->print, yaz_log_file());
-       }       
-       else if (*control_block->apdufile != '-')
-       {
-           strcpy(filename, control_block->apdufile);
-           if (!control_block->dynamic)
-           {
-               if (!apduf)
-               {
-                   if (!(apduf = fopen(filename, "w")))
-                   {
-                       yaz_log(LOG_WARN|LOG_ERRNO, "%s", filename);
-                       return 0;
-                   }
-                   setvbuf(apduf, 0, _IONBF, 0);
-               }
-               f = apduf;
-           }
-           else 
-           {
-               sprintf(filename + strlen(filename), ".%d", getpid());
-               if (!(f = fopen(filename, "w")))
-               {
-                   yaz_log(LOG_WARN|LOG_ERRNO, "%s", filename);
-                   return 0;
-               }
-               setvbuf(f, 0, _IONBF, 0);
-           }
-           odr_setprint(anew->print, f);
-       }
+            odr_setprint(anew->print, yaz_log_file());
+        }       
+        else if (*apdufile != '-')
+        {
+            char filename[256];
+            sprintf(filename, "%.200s.%ld", apdufile, (long)getpid());
+            if (!(f = fopen(filename, "w")))
+            {
+                yaz_log(YLOG_WARN|YLOG_ERRNO, "%s", filename);
+                return 0;
+            }
+            setvbuf(f, 0, _IONBF, 0);
+            odr_setprint(anew->print, f);
+        }
     }
     else
-       anew->print = 0;
+        anew->print = 0;
     anew->input_buffer = 0;
     anew->input_buffer_len = 0;
     anew->backend = 0;
@@ -160,6 +184,7 @@ association *create_association(IOCHAN channel, COMSTACK link)
     request_initq(&anew->incoming);
     request_initq(&anew->outgoing);
     anew->proto = cs_getproto(link);
+    anew->server = 0;
     return anew;
 }
 
@@ -175,27 +200,27 @@ void destroy_association(association *h)
     odr_destroy(h->decode);
     odr_destroy(h->encode);
     if (h->print)
-       odr_destroy(h->print);
+        odr_destroy(h->print);
     if (h->input_buffer)
     xfree(h->input_buffer);
     if (h->backend)
-       (*cb->bend_close)(h->backend);
+        (*cb->bend_close)(h->backend);
     while ((req = request_deq(&h->incoming)))
-       request_release(req);
+        request_release(req);
     while ((req = request_deq(&h->outgoing)))
-       request_release(req);
+        request_release(req);
     request_delq(&h->incoming);
     request_delq(&h->outgoing);
     xfree(h);
     xmalloc_trav("session closed");
-    if (control_block && control_block->one_shot)
+    if (cb && cb->one_shot)
     {
-       exit (0);
+        exit (0);
     }
 }
 
 static void do_close_req(association *a, int reason, char *message,
-                        request *req)
+                         request *req)
 {
     Z_APDU apdu;
     Z_Close *cls = zget_Close(a->encode);
@@ -205,20 +230,21 @@ static void do_close_req(association *a, int reason, char *message,
     while (request_deq(&a->outgoing));
     if (a->version >= 3)
     {
-       yaz_log(LOG_LOG, "Sending Close PDU, reason=%d, message=%s",
-           reason, message ? message : "none");
-       apdu.which = Z_APDU_close;
-       apdu.u.close = cls;
-       *cls->closeReason = reason;
-       cls->diagnosticInformation = message;
-       process_z_response(a, req, &apdu);
-       iochan_settimeout(a->client_chan, 20);
+        yaz_log(log_requestdetail, "Sending Close PDU, reason=%d, message=%s",
+            reason, message ? message : "none");
+        apdu.which = Z_APDU_close;
+        apdu.u.close = cls;
+        *cls->closeReason = reason;
+        cls->diagnosticInformation = message;
+        process_z_response(a, req, &apdu);
+        iochan_settimeout(a->client_chan, 20);
     }
     else
     {
-       request_release(req);
-       yaz_log(LOG_DEBUG, "v2 client. No Close PDU");
-       iochan_setevent(a->client_chan, EVENT_TIMEOUT); /* force imm close */
+        request_release(req);
+        yaz_log(log_requestdetail, "v2 client. No Close PDU");
+        iochan_setevent(a->client_chan, EVENT_TIMEOUT); /* force imm close */
+        a->cs_put_mask = 0;
     }
     a->state = ASSOC_DEAD;
 }
@@ -248,100 +274,100 @@ void ir_session(IOCHAN h, int event)
     assert(h && conn && assoc);
     if (event == EVENT_TIMEOUT)
     {
-       if (assoc->state != ASSOC_UP)
-       {
-           yaz_log(LOG_LOG, "Final timeout - closing connection.");
-           cs_close(conn);
-           destroy_association(assoc);
-           iochan_destroy(h);
-       }
-       else
-       {
-           yaz_log(LOG_LOG, "Session idle too long. Sending close.");
-           do_close(assoc, Z_Close_lackOfActivity, 0);
-       }
-       return;
+        if (assoc->state != ASSOC_UP)
+        {
+            yaz_log(YLOG_DEBUG, "Final timeout - closing connection.");
+            /* do we need to lod this at all */
+            cs_close(conn);
+            destroy_association(assoc);
+            iochan_destroy(h);
+        }
+        else
+        {
+            yaz_log(log_session, "Session idle too long. Sending close.");
+            do_close(assoc, Z_Close_lackOfActivity, 0);
+        }
+        return;
     }
     if (event & assoc->cs_accept_mask)
     {
-       yaz_log (LOG_DEBUG, "ir_session (accept)");
-       if (!cs_accept (conn))
-       {
-           yaz_log (LOG_LOG, "accept failed");
-           destroy_association(assoc);
-           iochan_destroy(h);
-       }
-       iochan_clearflag (h, EVENT_OUTPUT);
-       if (conn->io_pending) 
-       {   /* cs_accept didn't complete */
-           assoc->cs_accept_mask = 
-               ((conn->io_pending & CS_WANT_WRITE) ? EVENT_OUTPUT : 0) |
-               ((conn->io_pending & CS_WANT_READ) ? EVENT_INPUT : 0);
-
-           iochan_setflag (h, assoc->cs_accept_mask);
-       }
-       else
-       {   /* cs_accept completed. Prepare for reading (cs_get) */
-           assoc->cs_accept_mask = 0;
-           assoc->cs_get_mask = EVENT_INPUT;
-           iochan_setflag (h, assoc->cs_get_mask);
-       }
-       return;
+        if (!cs_accept (conn))
+        {
+            yaz_log (YLOG_WARN, "accept failed");
+            destroy_association(assoc);
+            iochan_destroy(h);
+        }
+        iochan_clearflag (h, EVENT_OUTPUT);
+        if (conn->io_pending) 
+        {   /* cs_accept didn't complete */
+            assoc->cs_accept_mask = 
+                ((conn->io_pending & CS_WANT_WRITE) ? EVENT_OUTPUT : 0) |
+                ((conn->io_pending & CS_WANT_READ) ? EVENT_INPUT : 0);
+
+            iochan_setflag (h, assoc->cs_accept_mask);
+        }
+        else
+        {   /* cs_accept completed. Prepare for reading (cs_get) */
+            assoc->cs_accept_mask = 0;
+            assoc->cs_get_mask = EVENT_INPUT;
+            iochan_setflag (h, assoc->cs_get_mask);
+        }
+        return;
     }
     if ((event & assoc->cs_get_mask) || (event & EVENT_WORK)) /* input */
     {
-       if ((assoc->cs_put_mask & EVENT_INPUT) == 0 && (event & assoc->cs_get_mask))
-       {
-           yaz_log(LOG_DEBUG, "ir_session (input)");
-           /* We aren't speaking to this fellow */
-           if (assoc->state == ASSOC_DEAD)
-           {
-               yaz_log(LOG_LOG, "Connection closed - end of session");
-               cs_close(conn);
-               destroy_association(assoc);
-               iochan_destroy(h);
-               return;
-           }
-           assoc->cs_get_mask = EVENT_INPUT;
-           if ((res = cs_get(conn, &assoc->input_buffer,
-               &assoc->input_buffer_len)) <= 0)
-           {
-               yaz_log(LOG_LOG, "Connection closed by client");
-               cs_close(conn);
-               destroy_association(assoc);
-               iochan_destroy(h);
-               return;
-           }
-           else if (res == 1) /* incomplete read - wait for more  */
-           {
-               if (conn->io_pending & CS_WANT_WRITE)
-                   assoc->cs_get_mask |= EVENT_OUTPUT;
-               iochan_setflag(h, assoc->cs_get_mask);
-               return;
-           }
-           if (cs_more(conn)) /* more stuff - call us again later, please */
-               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,
-                           assoc->input_buffer[0] & 0xff,
-                           assoc->input_buffer[1] & 0xff,
-                           assoc->input_buffer[2] & 0xff);
-           req = request_get(&assoc->incoming); /* get a new request */
-           odr_reset(assoc->decode);
-           odr_setbuf(assoc->decode, assoc->input_buffer, res, 0);
-           if (!z_GDU(assoc->decode, &req->gdu_request, 0, 0))
-           {
-               yaz_log(LOG_LOG, "ODR error on incoming PDU: %s [element %s] "
-                        "[near byte %d] ",
-                       odr_errmsg(odr_geterror(assoc->decode)),
+        if ((assoc->cs_put_mask & EVENT_INPUT) == 0 && (event & assoc->cs_get_mask))
+        {
+            yaz_log(YLOG_DEBUG, "ir_session (input)");
+            /* We aren't speaking to this fellow */
+            if (assoc->state == ASSOC_DEAD)
+            {
+                yaz_log(log_session, "Connection closed - end of session");
+                cs_close(conn);
+                destroy_association(assoc);
+                iochan_destroy(h);
+                return;
+            }
+            assoc->cs_get_mask = EVENT_INPUT;
+            if ((res = cs_get(conn, &assoc->input_buffer,
+                &assoc->input_buffer_len)) <= 0)
+            {
+                yaz_log(log_session, "Connection closed by client");
+                cs_close(conn);
+                destroy_association(assoc);
+                iochan_destroy(h);
+                return;
+            }
+            else if (res == 1) /* incomplete read - wait for more  */
+            {
+                if (conn->io_pending & CS_WANT_WRITE)
+                    assoc->cs_get_mask |= EVENT_OUTPUT;
+                iochan_setflag(h, assoc->cs_get_mask);
+                return;
+            }
+            if (cs_more(conn)) /* more stuff - call us again later, please */
+                iochan_setevent(h, EVENT_INPUT);
+                
+            /* we got a complete PDU. Let's decode it */
+            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);
+            req = request_get(&assoc->incoming); /* get a new request */
+            odr_reset(assoc->decode);
+            odr_setbuf(assoc->decode, assoc->input_buffer, res, 0);
+            if (!z_GDU(assoc->decode, &req->gdu_request, 0, 0))
+            {
+                yaz_log(YLOG_WARN, "ODR error on incoming PDU: %s [element %s] "
+                        "[near byte %ld] ",
+                        odr_errmsg(odr_geterror(assoc->decode)),
                         odr_getelement(assoc->decode),
-                       odr_offset(assoc->decode));
+                        (long) odr_offset(assoc->decode));
                 if (assoc->decode->error != OHTTP)
                 {
-                    yaz_log(LOG_LOG, "PDU dump:");
+                    yaz_log(YLOG_WARN, "PDU dump:");
                     odr_dumpBER(yaz_log_file(), assoc->input_buffer, res);
-                   request_release(req);
+                    request_release(req);
                     do_close(assoc, Z_Close_protocolError,"Malformed package");
                 }
                 else
@@ -350,82 +376,83 @@ void ir_session(IOCHAN h, int event)
                     assoc->state = ASSOC_DEAD;
                     process_gdu_response(assoc, req, p);
                 }
-               return;
-           }
-           req->request_mem = odr_extract_mem(assoc->decode);
-           if (assoc->print) 
+                return;
+            }
+            req->request_mem = odr_extract_mem(assoc->decode);
+            if (assoc->print) 
             {
-               if (!z_GDU(assoc->print, &req->gdu_request, 0, 0))
-                   yaz_log(LOG_WARN, "ODR print error: %s", 
-                      odr_errmsg(odr_geterror(assoc->print)));
-               odr_reset(assoc->print);
-           }
-           request_enq(&assoc->incoming, req);
-       }
+                if (!z_GDU(assoc->print, &req->gdu_request, 0, 0))
+                    yaz_log(YLOG_WARN, "ODR print error: %s", 
+                       odr_errmsg(odr_geterror(assoc->print)));
+                odr_reset(assoc->print);
+            }
+            request_enq(&assoc->incoming, req);
+        }
 
-       /* can we do something yet? */
-       req = request_head(&assoc->incoming);
-       if (req->state == REQUEST_IDLE)
-       {
-           request_deq(&assoc->incoming);
-           process_gdu_request(assoc, req);
-       }
+        /* can we do something yet? */
+        req = request_head(&assoc->incoming);
+        if (req->state == REQUEST_IDLE)
+        {
+            request_deq(&assoc->incoming);
+            process_gdu_request(assoc, req);
+        }
     }
     if (event & assoc->cs_put_mask)
     {
-       request *req = request_head(&assoc->outgoing);
+        request *req = request_head(&assoc->outgoing);
 
-       assoc->cs_put_mask = 0;
-       yaz_log(LOG_DEBUG, "ir_session (output)");
+        assoc->cs_put_mask = 0;
+        yaz_log(YLOG_DEBUG, "ir_session (output)");
         req->state = REQUEST_PENDING;
-       switch (res = cs_put(conn, req->response, req->len_response))
-       {
-       case -1:
-           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 */
-           yaz_log(LOG_DEBUG, "Wrote PDU, %d bytes", req->len_response);
+        switch (res = cs_put(conn, req->response, req->len_response))
+        {
+        case -1:
+            yaz_log(log_session, "Connection closed by client");
+            cs_close(conn);
+            destroy_association(assoc);
+            iochan_destroy(h);
+            break;
+        case 0: /* all sent - release the request structure */
+            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);
-           request_deq(&assoc->outgoing);
-           request_release(req);
-           if (!request_head(&assoc->outgoing))
-           {   /* restore mask for cs_get operation ... */
-               iochan_clearflag(h, EVENT_OUTPUT|EVENT_INPUT);
-               iochan_setflag(h, assoc->cs_get_mask);
+            nmem_destroy(req->request_mem);
+            request_deq(&assoc->outgoing);
+            request_release(req);
+            if (!request_head(&assoc->outgoing))
+            {   /* restore mask for cs_get operation ... */
+                iochan_clearflag(h, EVENT_OUTPUT|EVENT_INPUT);
+                iochan_setflag(h, assoc->cs_get_mask);
                 if (assoc->state == ASSOC_DEAD)
                     iochan_setevent(assoc->client_chan, EVENT_TIMEOUT);
-           }
+            }
             else
             {
                 assoc->cs_put_mask = EVENT_OUTPUT;
             }
-           break;
-       default:
-           if (conn->io_pending & CS_WANT_WRITE)
-               assoc->cs_put_mask |= EVENT_OUTPUT;
-           if (conn->io_pending & CS_WANT_READ)
-               assoc->cs_put_mask |= EVENT_INPUT;
-           iochan_setflag(h, assoc->cs_put_mask);
-       }
+            break;
+        default:
+            if (conn->io_pending & CS_WANT_WRITE)
+                assoc->cs_put_mask |= EVENT_OUTPUT;
+            if (conn->io_pending & CS_WANT_READ)
+                assoc->cs_put_mask |= EVENT_INPUT;
+            iochan_setflag(h, assoc->cs_put_mask);
+        }
     }
     if (event & EVENT_EXCEPT)
     {
-       yaz_log(LOG_LOG, "ir_session (exception)");
-       cs_close(conn);
-       destroy_association(assoc);
-       iochan_destroy(h);
+        yaz_log(YLOG_WARN, "ir_session (exception)");
+        cs_close(conn);
+        destroy_association(assoc);
+        iochan_destroy(h);
     }
 }
 
 static int process_z_request(association *assoc, request *req, char **msg);
 
+
 static void assoc_init_reset(association *assoc)
 {
     xfree (assoc->init);
@@ -447,6 +474,8 @@ static void assoc_init_reset(association *assoc)
     assoc->init->bend_segment = NULL;
     assoc->init->bend_fetch = NULL;
     assoc->init->bend_explain = NULL;
+    assoc->init->bend_srw_scan = NULL;
+    assoc->init->bend_srw_update = NULL;
 
     assoc->init->charneg_request = NULL;
     assoc->init->charneg_response = NULL;
@@ -454,33 +483,202 @@ static void assoc_init_reset(association *assoc)
     assoc->init->decode = assoc->decode;
     assoc->init->peer_name = 
         odr_strdup (assoc->encode, cs_addrstr(assoc->client_link));
+
+    yaz_log(log_requestdetail, "peer %s", assoc->init->peer_name);
 }
 
-static int srw_bend_init(association *assoc)
+static int srw_bend_init(association *assoc, Z_SRW_diagnostic **d, int *num, Z_SRW_PDU *sr)
 {
-    const char *encoding = "UTF-8";
-    Z_External *ce;
-    bend_initresult *binitres;
     statserv_options_block *cb = statserv_getcontrol();
-    
-    assoc_init_reset(assoc);
+    if (!assoc->init)
+    {
+        const char *encoding = "UTF-8";
+        Z_External *ce;
+        bend_initresult *binitres;
+
+        yaz_log(YLOG_LOG, "srw_bend_init config=%s", cb->configname);
+        assoc_init_reset(assoc);
+        
+        assoc->maximumRecordSize = 3000000;
+        assoc->preferredMessageSize = 3000000;
+
+        if (sr->username)
+        {
+            Z_IdAuthentication *auth = odr_malloc(assoc->decode, sizeof(*auth));
+            int len;
+
+            len = strlen(sr->username) + 1;
+            if (sr->password) 
+                len += strlen(sr->password) + 2;
+            auth->which = Z_IdAuthentication_open;
+            auth->u.open = odr_malloc(assoc->decode, len);
+            strcpy(auth->u.open, sr->username);
+            if (sr->password && *sr->password)
+            {
+                strcat(auth->u.open, "/");
+                strcat(auth->u.open, sr->password);
+            }
+            assoc->init->auth = auth;
+        }
 
-    assoc->maximumRecordSize = 3000000;
-    assoc->preferredMessageSize = 3000000;
 #if 1
-    ce = yaz_set_proposal_charneg(assoc->decode, &encoding, 1, 0, 0, 1);
-    assoc->init->charneg_request = ce->u.charNeg3;
+        ce = yaz_set_proposal_charneg(assoc->decode, &encoding, 1, 0, 0, 1);
+        assoc->init->charneg_request = ce->u.charNeg3;
 #endif
-    assoc->backend = 0;
-    if (!(binitres = (*cb->bend_init)(assoc->init)))
-    {
-       yaz_log(LOG_WARN, "Bad response from backend.");
-       return 0;
+        assoc->backend = 0;
+        if (!(binitres = (*cb->bend_init)(assoc->init)))
+        {
+            assoc->state = ASSOC_DEAD;
+            yaz_add_srw_diagnostic(assoc->encode, d, num,
+                            YAZ_SRW_AUTHENTICATION_ERROR, 0);
+            return 0;
+        }
+        assoc->backend = binitres->handle;
+        assoc->init->auth = 0;
+        if (binitres->errcode)
+        {
+            int srw_code = yaz_diag_bib1_to_srw(binitres->errcode);
+            assoc->state = ASSOC_DEAD;
+            yaz_add_srw_diagnostic(assoc->encode, d, num, srw_code,
+                                   binitres->errstring);
+            return 0;
+        }
+        return 1;
     }
-    assoc->backend = binitres->handle;
     return 1;
 }
 
+static const char *get_esn(Z_RecordComposition *comp)
+{
+    if (comp && comp->which == Z_RecordComp_complex)
+    {
+        if (comp->u.complex->generic 
+            && comp->u.complex->generic->elementSpec
+            && (comp->u.complex->generic->elementSpec->which == 
+                Z_ElementSpec_elementSetName))
+            return comp->u.complex->generic->elementSpec->u.elementSetName;
+    }
+    else if (comp && comp->which == Z_RecordComp_simple &&
+             comp->u.simple->which == Z_ElementSetNames_generic)
+        return comp->u.simple->u.generic;
+    return 0;
+}
+
+static void set_esn(Z_RecordComposition **comp_p, const char *esn, NMEM nmem)
+{
+    Z_RecordComposition *comp = nmem_malloc(nmem, sizeof(*comp));
+    
+    comp->which = Z_RecordComp_simple;
+    comp->u.simple = nmem_malloc(nmem, sizeof(*comp->u.simple));
+    comp->u.simple->which = Z_ElementSetNames_generic;
+    comp->u.simple->u.generic = nmem_strdup(nmem, esn);
+    *comp_p = comp;
+}
+
+static int retrieve_fetch(association *assoc, bend_fetch_rr *rr)
+{
+#if HAVE_XML2
+    yaz_record_conv_t rc = 0;
+    const char *match_schema = 0;
+    int *match_syntax = 0;
+
+    if (assoc->server)
+    {
+        int r;
+        const char *input_schema = get_esn(rr->comp);
+        Odr_oid *input_syntax_raw = rr->request_format_raw;
+        
+        const char *backend_schema = 0;
+        Odr_oid *backend_syntax = 0;
+
+        r = yaz_retrieval_request(assoc->server->retrieval,
+                                  input_schema,
+                                  input_syntax_raw,
+                                  &match_schema,
+                                  &match_syntax,
+                                  &rc,
+                                  &backend_schema,
+                                  &backend_syntax);
+        yaz_log(YLOG_LOG, "yaz_retrieval_request r=%d", r);
+        if (r == -1) /* error ? */
+        {
+            const char *details = yaz_retrieval_get_error(
+                assoc->server->retrieval);
+
+            rr->errcode = YAZ_BIB1_SYSTEM_ERROR_IN_PRESENTING_RECORDS;
+            if (details)
+                rr->errstring = odr_strdup(rr->stream, details);
+            return -1;
+        }
+        else if (r == 1 || r == 3)
+        {
+            const char *details = input_schema;
+            rr->errcode =  YAZ_BIB1_ELEMENT_SET_NAMES_UNSUPP;
+            if (details)
+                rr->errstring = odr_strdup(rr->stream, details);
+            return -1;
+        }
+        else if (r == 2)
+        {
+            rr->errcode = YAZ_BIB1_RECORD_SYNTAX_UNSUPP;
+            if (input_syntax_raw)
+            {
+                char oidbuf[OID_STR_MAX];
+                oid_to_dotstring(input_syntax_raw, oidbuf);
+                rr->errstring = odr_strdup(rr->stream, oidbuf);
+            }
+            return -1;
+        }
+        if (backend_schema)
+        {
+            set_esn(&rr->comp, backend_schema, rr->stream->mem);
+        }
+        if (backend_syntax)
+        {
+            oident *oident_syntax = oid_getentbyoid(backend_syntax);
+
+            rr->request_format_raw = backend_syntax;
+            
+            if (oident_syntax)
+                rr->request_format = oident_syntax->value;
+            else
+                rr->request_format = VAL_NONE;
+        }
+    }
+    (*assoc->init->bend_fetch)(assoc->backend, rr);
+    if (rc && rr->record && rr->errcode == 0 && rr->len > 0)
+    {   /* post conversion must take place .. */
+        WRBUF output_record = wrbuf_alloc();
+        int r = yaz_record_conv_record(rc, rr->record, rr->len, output_record);
+        if (r)
+        {
+            const char *details = yaz_record_conv_get_error(rc);
+            rr->errcode = YAZ_BIB1_SYSTEM_ERROR_IN_PRESENTING_RECORDS;
+            if (details)
+                rr->errstring = odr_strdup(rr->stream, details);
+        }
+        else
+        {
+            rr->len = wrbuf_len(output_record);
+            rr->record = odr_malloc(rr->stream, rr->len);
+            memcpy(rr->record, wrbuf_buf(output_record), rr->len);
+        }
+        wrbuf_free(output_record, 1);
+    }
+    if (match_syntax)
+    {
+        struct oident *oi = oid_getentbyoid(match_syntax);
+        rr->output_format = oi ? oi->value : VAL_NONE;
+        rr->output_format_raw = match_syntax;
+    }
+    if (match_schema)
+        rr->schema = odr_strdup(rr->stream, match_schema);
+    return 0;
+#else
+    (*assoc->init->bend_fetch)(assoc->backend, rr);
+#endif
+}
+
 static int srw_bend_fetch(association *assoc, int pos,
                           Z_SRW_searchRetrieveRequest *srw_req,
                           Z_SRW_record *record)
@@ -496,10 +694,10 @@ static int srw_bend_fetch(association *assoc, int pos,
                                                    CLASS_TRANSYN,
                                                    VAL_TEXT_XML);
     rr.comp = (Z_RecordComposition *)
-           odr_malloc(assoc->decode, sizeof(*rr.comp));
+            odr_malloc(assoc->decode, sizeof(*rr.comp));
     rr.comp->which = Z_RecordComp_complex;
     rr.comp->u.complex = (Z_CompSpec *)
-           odr_malloc(assoc->decode, sizeof(Z_CompSpec));
+            odr_malloc(assoc->decode, sizeof(Z_CompSpec));
     rr.comp->u.complex->selectAlternativeSyntax = (bool_t *)
         odr_malloc(assoc->encode, sizeof(bool_t));
     *rr.comp->u.complex->selectAlternativeSyntax = 0;    
@@ -509,10 +707,23 @@ static int srw_bend_fetch(association *assoc, int pos,
     rr.comp->u.complex->recordSyntax = 0;
 
     rr.comp->u.complex->generic = (Z_Specification *) 
-           odr_malloc(assoc->decode, sizeof(Z_Specification));
+            odr_malloc(assoc->decode, sizeof(Z_Specification));
+
+    /* schema uri = recordSchema (or NULL if recordSchema is not given) */
     rr.comp->u.complex->generic->which = Z_Schema_uri;
     rr.comp->u.complex->generic->schema.uri = srw_req->recordSchema;
+
+    /* ESN = recordSchema if recordSchema is present */
     rr.comp->u.complex->generic->elementSpec = 0;
+    if (srw_req->recordSchema)
+    {
+        rr.comp->u.complex->generic->elementSpec = 
+            (Z_ElementSpec *) odr_malloc(assoc->encode, sizeof(Z_ElementSpec));
+        rr.comp->u.complex->generic->elementSpec->which = 
+            Z_ElementSpec_elementSetName;
+        rr.comp->u.complex->generic->elementSpec->u.elementSetName =
+            srw_req->recordSchema;
+    }
     
     rr.stream = assoc->encode;
     rr.print = assoc->print;
@@ -531,9 +742,37 @@ static int srw_bend_fetch(association *assoc, int pos,
     if (!assoc->init->bend_fetch)
         return 1;
 
-    (*assoc->init->bend_fetch)(assoc->backend, &rr);
+    retrieve_fetch(assoc, &rr);
+
+    if (rr.errcode && rr.surrogate_flag)
+    {
+        int code = yaz_diag_bib1_to_srw(rr.errcode);
+        const char *message = yaz_diag_srw_str(code);
+        int len = 200;
+        if (message)
+            len += strlen(message);
+        if (rr.errstring)
+            len += strlen(rr.errstring);
 
-    if (rr.len >= 0)
+        record->recordData_buf = odr_malloc(o, len);
+        
+        sprintf(record->recordData_buf, "<diagnostic "
+                "xmlns=\"http://www.loc.gov/zing/srw/diagnostic/\">\n"
+                " <uri>info:srw/diagnostic/1/%d</uri>\n", code);
+        if (rr.errstring)
+            sprintf(record->recordData_buf + strlen(record->recordData_buf),
+                    " <details>%s</details>\n", rr.errstring);
+        if (message)
+            sprintf(record->recordData_buf + strlen(record->recordData_buf),
+                    " <message>%s</message>\n", message);
+        sprintf(record->recordData_buf + strlen(record->recordData_buf),
+                "</diagnostic>\n");
+        record->recordData_len = strlen(record->recordData_buf);
+        record->recordPosition = odr_intdup(o, pos);
+        record->recordSchema = "info:srw/schema/1/diagnostics-v1.1";
+        return 0;
+    }
+    else if (rr.len >= 0)
     {
         record->recordData_buf = rr.record;
         record->recordData_len = rr.len;
@@ -546,229 +785,790 @@ static int srw_bend_fetch(association *assoc, int pos,
     return rr.errcode;
 }
 
-static void srw_bend_search(association *assoc, request *req,
-                            Z_SRW_searchRetrieveRequest *srw_req,
-                            Z_SRW_searchRetrieveResponse *srw_res,
-                           int *http_code)
+static int cql2pqf(ODR odr, const char *cql, cql_transform_t ct,
+                   Z_Query *query_result)
 {
-    int srw_error = 0;
-    bend_search_rr rr;
-    Z_External *ext;
-    
-    *http_code = 200;
-    yaz_log(LOG_LOG, "Got SRW SearchRetrieveRequest");
-    yaz_log(LOG_DEBUG, "srw_bend_search");
-    if (!assoc->init)
+    /* have a CQL query and  CQL to PQF transform .. */
+    CQL_parser cp = cql_parser_create();
+    int r;
+    int srw_errcode = 0;
+    const char *add = 0;
+    char rpn_buf[5120];
+            
+    r = cql_parser_string(cp, cql);
+    if (r)
     {
-        yaz_log(LOG_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);
-            return;
-        }
+        /* CQL syntax error */
+        srw_errcode = 10; 
     }
-    
-    rr.setname = "default";
-    rr.replace_set = 1;
-    rr.num_bases = 1;
-    rr.basenames = &srw_req->database;
-    rr.referenceId = 0;
-
-    rr.query = (Z_Query *) odr_malloc (assoc->decode, sizeof(*rr.query));
-
-    if (srw_req->query_type == Z_SRW_query_type_cql)
+    if (!r)
     {
-        ext = (Z_External *) odr_malloc(assoc->decode, sizeof(*ext));
-        ext->direct_reference = odr_getoidbystr(assoc->decode, 
-                                                "1.2.840.10003.16.2");
-        ext->indirect_reference = 0;
-        ext->descriptor = 0;
-        ext->which = Z_External_CQL;
-        ext->u.cql = srw_req->query.cql;
-
-        rr.query->which = Z_Query_type_104;
-        rr.query->u.type_104 =  ext;
+        /* Syntax OK */
+        r = cql_transform_buf(ct,
+                              cql_parser_result(cp),
+                              rpn_buf, sizeof(rpn_buf)-1);
+        if (r)
+            srw_errcode  = cql_transform_error(ct, &add);
     }
-    else if (srw_req->query_type == Z_SRW_query_type_pqf)
+    if (!r)
     {
-        Z_RPNQuery *RPNquery;
-        YAZ_PQF_Parser pqf_parser;
-
-        pqf_parser = yaz_pqf_create ();
-
-        RPNquery = yaz_pqf_parse (pqf_parser, assoc->decode,
-                                  srw_req->query.pqf);
-        if (!RPNquery)
+        /* Syntax & transform OK. */
+        /* Convert PQF string to Z39.50 to RPN query struct */
+        YAZ_PQF_Parser pp = yaz_pqf_create();
+        Z_RPNQuery *rpnquery = yaz_pqf_parse(pp, odr, rpn_buf);
+        if (!rpnquery)
         {
-            const char *pqf_msg;
             size_t off;
-            int code = yaz_pqf_error (pqf_parser, &pqf_msg, &off);
-            yaz_log(LOG_LOG, "%*s^\n", off+4, "");
-            yaz_log(LOG_LOG, "Bad PQF: %s (code %d)\n", pqf_msg, code);
-            
-            srw_error = 10;
+            const char *pqf_msg;
+            int code = yaz_pqf_error(pp, &pqf_msg, &off);
+            yaz_log(YLOG_WARN, "PQF Parser Error %s (code %d)",
+                    pqf_msg, code);
+            srw_errcode = 10;
         }
-
-        rr.query->which = Z_Query_type_1;
-        rr.query->u.type_1 =  RPNquery;
-
-        yaz_pqf_destroy (pqf_parser);
+        else
+        {
+            query_result->which = Z_Query_type_1;
+            query_result->u.type_1 = rpnquery;
+        }
+        yaz_pqf_destroy(pp);
     }
-    else
-        srw_error = 11;
-
-    if (!srw_error && srw_req->sort_type != Z_SRW_sort_type_none)
-        srw_error = 80;
-
-    if (!srw_error && !assoc->init->bend_search)
-        srw_error = 1;
+    cql_parser_destroy(cp);
+    return srw_errcode;
+}
 
+static int cql2pqf_scan(ODR odr, const char *cql, cql_transform_t ct,
+                        Z_AttributesPlusTerm *result)
+{
+    Z_Query query;
+    Z_RPNQuery *rpn;
+    int srw_error = cql2pqf(odr, cql, ct, &query);
     if (srw_error)
-    {
-        yaz_log(LOG_DEBUG, "srw_bend_search returned SRW error %d", srw_error);
-        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, srw_error, 0);
-        return;
-    }
+        return srw_error;
+    if (query.which != Z_Query_type_1 && query.which != Z_Query_type_101)
+        return 10; /* bad query type */
+    rpn = query.u.type_1;
+    if (!rpn->RPNStructure) 
+        return 10; /* must be structure */
+    if (rpn->RPNStructure->which != Z_RPNStructure_simple)
+        return 10; /* must be simple */
+    if (rpn->RPNStructure->u.simple->which != Z_Operand_APT)
+        return 10; /* must be attributes plus term node .. */
+    memcpy(result, rpn->RPNStructure->u.simple->u.attributesPlusTerm,
+           sizeof(*result));
+    return 0;
+}
+                   
+static void srw_bend_search(association *assoc, request *req,
+                            Z_SRW_PDU *sr,
+                            Z_SRW_searchRetrieveResponse *srw_res,
+                            int *http_code)
+{
+    int srw_error = 0;
+    Z_External *ext;
+    Z_SRW_searchRetrieveRequest *srw_req = sr->u.request;
     
-    rr.stream = assoc->encode;
-    rr.decode = assoc->decode;
-    rr.print = assoc->print;
-    rr.request = req;
-    rr.association = assoc;
-    rr.fd = 0;
-    rr.hits = 0;
-    rr.errcode = 0;
-    rr.errstring = 0;
-    rr.search_info = 0;
-    yaz_log_zquery(rr.query);
-    (assoc->init->bend_search)(assoc->backend, &rr);
-    srw_res->numberOfRecords = odr_intdup(assoc->encode, rr.hits);
-    if (rr.errcode)
-    {
-        yaz_log(LOG_DEBUG, "bend_search returned Bib-1 code %d", rr.errcode);
-       if (rr.errcode == 109) /* database unavailable */
-       {
-           *http_code = 404;
-           return;
-       }
-        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_DEBUG, "srw_bend_search returned SRW error %s",
-                srw_res->diagnostics[0].uri);
-    }
-    else
-    {
-        int number = srw_req->maximumRecords ? *srw_req->maximumRecords : 0;
-        int start = srw_req->startRecord ? *srw_req->startRecord : 1;
-
-        yaz_log(LOG_LOG, "Request to pack %d+%d out of %d",
-                start, number, rr.hits);
-
-        srw_res->numberOfRecords = odr_intdup(assoc->encode, rr.hits);
-        if (number > 0)
+    *http_code = 200;
+    yaz_log(log_requestdetail, "Got SRW SearchRetrieveRequest");
+    srw_bend_init(assoc, &srw_res->diagnostics, &srw_res->num_diagnostics, sr);
+    if (srw_res->num_diagnostics == 0 && assoc->init)
+    {
+        bend_search_rr rr;
+        rr.setname = "default";
+        rr.replace_set = 1;
+        rr.num_bases = 1;
+        rr.basenames = &srw_req->database;
+        rr.referenceId = 0;
+        rr.srw_sortKeys = 0;
+        rr.srw_setname = 0;
+        rr.srw_setnameIdleTime = 0;
+        rr.query = (Z_Query *) odr_malloc (assoc->decode, sizeof(*rr.query));
+        rr.query->u.type_1 = 0;
+        
+        if (srw_req->query_type == Z_SRW_query_type_cql)
         {
-            int i;
-
-            if (start > rr.hits)
+            if (assoc->server && assoc->server->cql_transform)
             {
-                yaz_log(LOG_LOG, "Request out or range");
+                int srw_errcode = cql2pqf(assoc->encode, srw_req->query.cql,
+                                          assoc->server->cql_transform,
+                                          rr.query);
+                if (srw_errcode)
+                {
+                    yaz_add_srw_diagnostic(assoc->encode,
+                                           &srw_res->diagnostics,
+                                           &srw_res->num_diagnostics,
+                                           srw_errcode, 0);
+                }
             }
             else
             {
-                int j = 0;
-                int packing = Z_SRW_recordPacking_string;
-                if (start + number > rr.hits)
-                    number = rr.hits - start + 1;
-                if (srw_req->recordPacking && 
-                    !strcmp(srw_req->recordPacking, "xml"))
-                    packing = Z_SRW_recordPacking_XML;
-                srw_res->records = (Z_SRW_record *)
-                    odr_malloc(assoc->encode,
-                               number * sizeof(*srw_res->records));
-                for (i = 0; i<number; i++)
+                /* CQL query to backend. Wrap it - Z39.50 style */
+                ext = (Z_External *) odr_malloc(assoc->decode, sizeof(*ext));
+                ext->direct_reference = odr_getoidbystr(assoc->decode, 
+                                                        "1.2.840.10003.16.2");
+                ext->indirect_reference = 0;
+                ext->descriptor = 0;
+                ext->which = Z_External_CQL;
+                ext->u.cql = srw_req->query.cql;
+                
+                rr.query->which = Z_Query_type_104;
+                rr.query->u.type_104 =  ext;
+            }
+        }
+        else if (srw_req->query_type == Z_SRW_query_type_pqf)
+        {
+            Z_RPNQuery *RPNquery;
+            YAZ_PQF_Parser pqf_parser;
+            
+            pqf_parser = yaz_pqf_create ();
+            
+            RPNquery = yaz_pqf_parse (pqf_parser, assoc->decode,
+                                      srw_req->query.pqf);
+            if (!RPNquery)
+            {
+                const char *pqf_msg;
+                size_t off;
+                int code = yaz_pqf_error (pqf_parser, &pqf_msg, &off);
+                yaz_log(log_requestdetail, "Parse error %d %s near offset %ld",
+                        code, pqf_msg, (long) off);
+                srw_error = YAZ_SRW_QUERY_SYNTAX_ERROR;
+            }
+            
+            rr.query->which = Z_Query_type_1;
+            rr.query->u.type_1 =  RPNquery;
+            
+            yaz_pqf_destroy (pqf_parser);
+        }
+        else
+        {
+            yaz_add_srw_diagnostic(assoc->encode, &srw_res->diagnostics,
+                                   &srw_res->num_diagnostics,
+                                   YAZ_SRW_UNSUPP_QUERY_TYPE, 0);
+        }
+        if (rr.query->u.type_1)
+        {
+            rr.stream = assoc->encode;
+            rr.decode = assoc->decode;
+            rr.print = assoc->print;
+            rr.request = req;
+            if ( srw_req->sort.sortKeys )
+                rr.srw_sortKeys = odr_strdup(assoc->encode, 
+                                             srw_req->sort.sortKeys );
+            rr.association = assoc;
+            rr.fd = 0;
+            rr.hits = 0;
+            rr.errcode = 0;
+            rr.errstring = 0;
+            rr.search_info = 0;
+            yaz_log_zquery_level(log_requestdetail,rr.query);
+            
+            (assoc->init->bend_search)(assoc->backend, &rr);
+            if (rr.errcode)
+            {
+                if (rr.errcode == YAZ_BIB1_DATABASE_UNAVAILABLE)
+                {
+                    *http_code = 404;
+                }
+                else
                 {
-                    int errcode;
+                    srw_error = yaz_diag_bib1_to_srw (rr.errcode);
+                    yaz_add_srw_diagnostic(assoc->encode,
+                                           &srw_res->diagnostics,
+                                           &srw_res->num_diagnostics,
+                                           srw_error, rr.errstring);
+                }
+            }
+            else
+            {
+                int number = srw_req->maximumRecords ? *srw_req->maximumRecords : 0;
+                int start = srw_req->startRecord ? *srw_req->startRecord : 1;
+                
+                yaz_log(log_requestdetail, "Request to pack %d+%d out of %d",
+                        start, number, rr.hits);
+                
+                srw_res->numberOfRecords = odr_intdup(assoc->encode, rr.hits);
+               if (rr.srw_setname)
+                {
+                    srw_res->resultSetId =
+                        odr_strdup(assoc->encode, rr.srw_setname );
+                    srw_res->resultSetIdleTime =
+                        odr_intdup(assoc->encode, *rr.srw_setnameIdleTime );
+               }
+                if (number > 0)
+                {
+                    int i;
                     
-                    srw_res->records[j].recordPacking = packing;
-                    srw_res->records[j].recordData_buf = 0;
-                    yaz_log(LOG_DEBUG, "srw_bend_fetch %d", i+start);
-                    errcode = srw_bend_fetch(assoc, i+start, srw_req,
-                                             srw_res->records + j);
-                    if (errcode)
+                    if (start > rr.hits)
+                    {
+                        yaz_add_srw_diagnostic(assoc->encode, &srw_res->diagnostics,
+                                               &srw_res->num_diagnostics,
+                                               YAZ_SRW_FIRST_RECORD_POSITION_OUT_OF_RANGE, 0);
+                    }
+                    else
                     {
-                        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 (errcode),
-                                             rr.errstring);
-                        break;
+                        int j = 0;
+                        int packing = Z_SRW_recordPacking_string;
+                        if (start + number > rr.hits)
+                            number = rr.hits - start + 1;
+                        if (srw_req->recordPacking){
+                            if (!strcmp(srw_req->recordPacking, "xml"))
+                                packing = Z_SRW_recordPacking_XML;
+                            if (!strcmp(srw_req->recordPacking, "url"))
+                                packing = Z_SRW_recordPacking_URL;
+                        }
+                        srw_res->records = (Z_SRW_record *)
+                            odr_malloc(assoc->encode,
+                                       number * sizeof(*srw_res->records));
+                        
+                        srw_res->extra_records = (Z_SRW_extra_record **)
+                            odr_malloc(assoc->encode,
+                                       number*sizeof(*srw_res->extra_records));
+
+                        for (i = 0; i<number; i++)
+                        {
+                            int errcode;
+                            
+                            srw_res->records[j].recordPacking = packing;
+                            srw_res->records[j].recordData_buf = 0;
+                            srw_res->extra_records[j] = 0;
+                            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)
+                            {
+                                yaz_add_srw_diagnostic(assoc->encode,
+                                                       &srw_res->diagnostics,
+                                                       &srw_res->num_diagnostics,
+                                                       yaz_diag_bib1_to_srw (errcode),
+                                                       rr.errstring);
+                                
+                                break;
+                            }
+                            if (srw_res->records[j].recordData_buf)
+                                j++;
+                        }
+                        srw_res->num_records = j;
+                        if (!j)
+                            srw_res->records = 0;
                     }
-                    if (srw_res->records[j].recordData_buf)
-                        j++;
                 }
-                srw_res->num_records = j;
-                if (!j)
-                    srw_res->records = 0;
             }
         }
     }
+    if (log_request)
+    {
+        const char *querystr = "?";
+        const char *querytype = "?";
+        WRBUF wr = wrbuf_alloc();
+
+        switch (srw_req->query_type)
+        {
+        case Z_SRW_query_type_cql:
+            querytype = "CQL";
+            querystr = srw_req->query.cql;
+            break;
+        case Z_SRW_query_type_pqf:
+            querytype = "PQF";
+            querystr = srw_req->query.pqf;
+            break;
+        }
+        wrbuf_printf(wr, "SRWSearch ");
+        if (srw_res->num_diagnostics)
+            wrbuf_printf(wr, "ERROR %s", srw_res->diagnostics[0].uri);
+        else if (*http_code != 200)
+            wrbuf_printf(wr, "ERROR info:http/%d", *http_code);
+        else if (srw_res->numberOfRecords)
+        {
+            wrbuf_printf(wr, "OK %d",
+                         (srw_res->numberOfRecords ?
+                          *srw_res->numberOfRecords : 0));
+        }
+        wrbuf_printf(wr, " %s %d+%d", 
+                     (srw_res->resultSetId ?
+                      srw_res->resultSetId : "-"),
+                     (srw_req->startRecord ? *srw_req->startRecord : 1), 
+                     srw_res->num_records);
+        yaz_log(log_request, "%s %s: %s", wrbuf_buf(wr), querytype, querystr);
+        wrbuf_free(wr, 1);
+    }
+}
+
+static char *srw_bend_explain_default(void *handle, bend_explain_rr *rr)
+{
+#if HAVE_XML2
+    xmlNodePtr ptr = rr->server_node_ptr;
+    if (!ptr)
+        return 0;
+    for (ptr = ptr->children; ptr; ptr = ptr->next)
+    {
+        if (ptr->type != XML_ELEMENT_NODE)
+            continue;
+        if (!strcmp((const char *) ptr->name, "explain"))
+        {
+            int len;
+            xmlDocPtr doc = xmlNewDoc(BAD_CAST "1.0");
+            xmlChar *buf_out;
+            char *content;
+
+            ptr = xmlCopyNode(ptr, 1);
+        
+            xmlDocSetRootElement(doc, ptr);
+            
+            xmlDocDumpMemory(doc, &buf_out, &len);
+            content = (char*) odr_malloc(rr->stream, 1+len);
+            memcpy(content, buf_out, len);
+            content[len] = '\0';
+            
+            xmlFree(buf_out);
+            xmlFreeDoc(doc);
+            rr->explain_buf = content;
+            return 0;
+        }
+    }
+#endif
+    return 0;
 }
 
 static void srw_bend_explain(association *assoc, request *req,
-                             Z_SRW_explainRequest *srw_req,
+                             Z_SRW_PDU *sr,
                              Z_SRW_explainResponse *srw_res,
-                            int *http_code)
+                             int *http_code)
 {
-    yaz_log(LOG_LOG, "Got SRW ExplainRequest");
+    Z_SRW_explainRequest *srw_req = sr->u.explain_request;
+    yaz_log(log_requestdetail, "Got SRW ExplainRequest");
     *http_code = 404;
-    if (!assoc->init)
-    {
-        yaz_log(LOG_DEBUG, "srw_bend_init");
-        if (!srw_bend_init(assoc))
-       {
-            return;
-       }
-    }
-    if (assoc->init && assoc->init->bend_explain)
+    srw_bend_init(assoc, &srw_res->diagnostics, &srw_res->num_diagnostics, sr);
+    if (assoc->init)
     {
         bend_explain_rr rr;
-
+        
         rr.stream = assoc->encode;
         rr.decode = assoc->decode;
         rr.print = assoc->print;
         rr.explain_buf = 0;
-       rr.database = srw_req->database;
-       rr.schema = "http://explain.z3950.org/dtd/2.0/";
-        (*assoc->init->bend_explain)(assoc->backend, &rr);
+        rr.database = srw_req->database;
+        if (assoc->server)
+            rr.server_node_ptr = assoc->server->server_node_ptr;
+        else
+            rr.server_node_ptr = 0;
+        rr.schema = "http://explain.z3950.org/dtd/2.0/";
+        if (assoc->init->bend_explain)
+            (*assoc->init->bend_explain)(assoc->backend, &rr);
+        else
+            srw_bend_explain_default(assoc->backend, &rr);
+
         if (rr.explain_buf)
         {
-           int packing = Z_SRW_recordPacking_string;
-           if (srw_req->recordPacking && 
-               !strcmp(srw_req->recordPacking, "xml"))
-               packing = Z_SRW_recordPacking_XML;
-           srw_res->record.recordSchema = 0;
-           srw_res->record.recordPacking = packing;
+            int packing = Z_SRW_recordPacking_string;
+            if (srw_req->recordPacking)
+            {
+                if (!strcmp(srw_req->recordPacking, "xml"))
+                    packing = Z_SRW_recordPacking_XML;
+                else if (!strcmp(srw_req->recordPacking, "url"))
+                    packing = Z_SRW_recordPacking_URL;
+            }
+            srw_res->record.recordSchema = rr.schema;
+            srw_res->record.recordPacking = packing;
             srw_res->record.recordData_buf = rr.explain_buf;
             srw_res->record.recordData_len = strlen(rr.explain_buf);
-           srw_res->record.recordPosition = 0;
-           *http_code = 200;
+            srw_res->record.recordPosition = 0;
+            *http_code = 200;
+        }
+    }
+}
+
+static void srw_bend_scan(association *assoc, request *req,
+                          Z_SRW_PDU *sr,
+                          Z_SRW_scanResponse *srw_res,
+                          int *http_code)
+{
+    Z_SRW_scanRequest *srw_req = sr->u.scan_request;
+    yaz_log(log_requestdetail, "Got SRW ScanRequest");
+
+    *http_code = 200;
+    srw_bend_init(assoc, &srw_res->diagnostics, &srw_res->num_diagnostics, sr);
+    if (srw_res->num_diagnostics == 0 && assoc->init)
+    {
+        struct scan_entry *save_entries;
+
+        bend_scan_rr *bsrr = (bend_scan_rr *)
+            odr_malloc (assoc->encode, sizeof(*bsrr));
+        bsrr->num_bases = 1;
+        bsrr->basenames = &srw_req->database;
+
+        bsrr->num_entries = srw_req->maximumTerms ?
+            *srw_req->maximumTerms : 10;
+        bsrr->term_position = srw_req->responsePosition ?
+            *srw_req->responsePosition : 1;
+
+        bsrr->errcode = 0;
+        bsrr->errstring = 0;
+        bsrr->referenceId = 0;
+        bsrr->stream = assoc->encode;
+        bsrr->print = assoc->print;
+        bsrr->step_size = odr_intdup(assoc->decode, 0);
+        bsrr->entries = 0;
+
+        if (bsrr->num_entries > 0) 
+        {
+            int i;
+            bsrr->entries = odr_malloc(assoc->decode, sizeof(*bsrr->entries) *
+                                       bsrr->num_entries);
+            for (i = 0; i<bsrr->num_entries; i++)
+            {
+                bsrr->entries[i].term = 0;
+                bsrr->entries[i].occurrences = 0;
+                bsrr->entries[i].errcode = 0;
+                bsrr->entries[i].errstring = 0;
+                bsrr->entries[i].display_term = 0;
+            }
+        }
+        save_entries = bsrr->entries;  /* save it so we can compare later */
+
+        if (srw_req->query_type == Z_SRW_query_type_pqf &&
+            assoc->init->bend_scan)
+        {
+            Odr_oid *scan_attributeSet = 0;
+            oident *attset;
+            YAZ_PQF_Parser pqf_parser = yaz_pqf_create();
+            
+            bsrr->term = yaz_pqf_scan(pqf_parser, assoc->decode,
+                                      &scan_attributeSet, 
+                                      srw_req->scanClause.pqf); 
+            if (scan_attributeSet &&
+                (attset = oid_getentbyoid(scan_attributeSet)) &&
+                (attset->oclass == CLASS_ATTSET ||
+                 attset->oclass == CLASS_GENERAL))
+                bsrr->attributeset = attset->value;
+            else
+                bsrr->attributeset = VAL_NONE;
+            yaz_pqf_destroy(pqf_parser);
+            bsrr->scanClause = 0;
+            ((int (*)(void *, bend_scan_rr *))
+             (*assoc->init->bend_scan))(assoc->backend, bsrr);
         }
+        else if (srw_req->query_type == Z_SRW_query_type_cql
+                 && assoc->init->bend_scan && assoc->server
+                 && assoc->server->cql_transform)
+        {
+            int srw_error;
+            bsrr->scanClause = 0;
+            bsrr->attributeset = VAL_NONE;
+            bsrr->term = odr_malloc(assoc->decode, sizeof(*bsrr->term));
+            srw_error = cql2pqf_scan(assoc->encode,
+                                     srw_req->scanClause.cql,
+                                     assoc->server->cql_transform,
+                                     bsrr->term);
+            if (srw_error)
+                yaz_add_srw_diagnostic(assoc->encode, &srw_res->diagnostics,
+                                       &srw_res->num_diagnostics,
+                                       srw_error, 0);
+            else
+            {
+                ((int (*)(void *, bend_scan_rr *))
+                 (*assoc->init->bend_scan))(assoc->backend, bsrr);
+            }
+        }
+        else if (srw_req->query_type == Z_SRW_query_type_cql
+                 && assoc->init->bend_srw_scan)
+        {
+            bsrr->term = 0;
+            bsrr->attributeset = VAL_NONE;
+            bsrr->scanClause = srw_req->scanClause.cql;
+            ((int (*)(void *, bend_scan_rr *))
+             (*assoc->init->bend_srw_scan))(assoc->backend, bsrr);
+        }
+        else
+        {
+            yaz_add_srw_diagnostic(assoc->encode, &srw_res->diagnostics,
+                                   &srw_res->num_diagnostics,
+                                   YAZ_SRW_UNSUPP_OPERATION, "scan");
+        }
+        if (bsrr->errcode)
+        {
+            int srw_error;
+            if (bsrr->errcode == YAZ_BIB1_DATABASE_UNAVAILABLE)
+            {
+                *http_code = 404;
+                return;
+            }
+            srw_error = yaz_diag_bib1_to_srw (bsrr->errcode);
+
+            yaz_add_srw_diagnostic(assoc->encode, &srw_res->diagnostics,
+                                   &srw_res->num_diagnostics,
+                                   srw_error, bsrr->errstring);
+        }
+        else if (srw_res->num_diagnostics == 0 && bsrr->num_entries)
+        {
+            int i;
+            srw_res->terms = (Z_SRW_scanTerm*)
+                odr_malloc(assoc->encode, sizeof(*srw_res->terms) *
+                           bsrr->num_entries);
+
+            srw_res->num_terms =  bsrr->num_entries;
+            for (i = 0; i<bsrr->num_entries; i++)
+            {
+                Z_SRW_scanTerm *t = srw_res->terms + i;
+                t->value = odr_strdup(assoc->encode, bsrr->entries[i].term);
+                t->numberOfRecords =
+                    odr_intdup(assoc->encode, bsrr->entries[i].occurrences);
+                t->displayTerm = 0;
+                if (save_entries == bsrr->entries && 
+                    bsrr->entries[i].display_term)
+                {
+                    /* the entries was _not_ set by the handler. So it's
+                       safe to test for new member display_term. It is
+                       NULL'ed by us.
+                    */
+                    t->displayTerm = odr_strdup(assoc->encode, 
+                                                bsrr->entries[i].display_term);
+                }
+                t->whereInList = 0;
+            }
+        }
+    }
+    if (log_request)
+    {
+        WRBUF wr = wrbuf_alloc();
+        const char *querytype = 0;
+        const char *querystr = 0;
+
+        switch(srw_req->query_type)
+        {
+        case Z_SRW_query_type_pqf:
+            querytype = "PQF";
+            querystr = srw_req->scanClause.pqf;
+            break;
+        case Z_SRW_query_type_cql:
+            querytype = "CQL";
+            querystr = srw_req->scanClause.cql;
+            break;
+        default:
+            querytype = "Unknown";
+            querystr = "";
+        }
+        wrbuf_printf(wr, "SRWScan %d+%d",
+                     (srw_req->responsePosition ? 
+                      *srw_req->responsePosition : 1),
+                     (srw_req->maximumTerms ?
+                      *srw_req->maximumTerms : 1));
+        if (srw_res->num_diagnostics)
+            wrbuf_printf(wr, " ERROR %s", srw_res->diagnostics[0].uri);
+        else
+            wrbuf_printf(wr, " OK -");
+        wrbuf_printf(wr, " %s: %s", querytype, querystr);
+        yaz_log(log_request, "%s", wrbuf_buf(wr) );
+        wrbuf_free(wr, 1);
     }
+
+}
+
+static void srw_bend_update(association *assoc, request *req,
+                           Z_SRW_PDU *sr,
+                           Z_SRW_updateResponse *srw_res,
+                           int *http_code)
+{
+    Z_SRW_updateRequest *srw_req = sr->u.update_request;
+    yaz_log(YLOG_DEBUG, "Got SRW UpdateRequest");
+    yaz_log(YLOG_DEBUG, "num_diag = %d", srw_res->num_diagnostics );
+    *http_code = 404;
+    srw_bend_init(assoc, &srw_res->diagnostics, &srw_res->num_diagnostics, sr);
+    if (assoc->init)
+    {
+       bend_update_rr rr;
+       
+       rr.stream = assoc->encode;
+       rr.print = assoc->print;
+        rr.num_bases = 1;
+        rr.basenames = &srw_req->database;
+       rr.operation = srw_req->operation;
+       rr.operation_status = "failed";
+       rr.record_id = 0;
+        rr.record_version = 0;
+        rr.record_checksum = 0;
+        rr.record_old_version = 0;
+        rr.record_packing = "xml";
+       rr.record_schema = 0;
+        rr.record_data = 0;
+        rr.request_extra_record = 0;
+        rr.response_extra_record = 0;
+        rr.extra_request_data = 0;
+        rr.extra_response_data = 0;
+        rr.errcode = 0;
+        rr.errstring = 0;
+
+        yaz_log(YLOG_DEBUG, "basename = %s", rr.basenames[0] );
+        yaz_log(YLOG_DEBUG, "Operation = %s", rr.operation );
+       if ( !strcmp( rr.operation, "delete" ) ){
+            if ( !srw_req->recordId ){
+                yaz_add_srw_diagnostic(assoc->encode, &srw_res->diagnostics,
+                                       &srw_res->num_diagnostics,
+                                       7, "recordId" );
+            }
+            else {
+                rr.record_id = srw_req->recordId;
+            }
+            if (  !srw_req->recordVersion ){
+                yaz_add_srw_diagnostic(assoc->encode, &srw_res->diagnostics,
+                                       &srw_res->num_diagnostics,
+                                       7, "recordVersion" );
+            }
+            else {
+                rr.record_version = odr_strdup( assoc->encode,
+                                                srw_req->recordVersion );
+                
+            }
+            if ( srw_req->recordOldVersion ){
+                rr.record_old_version = odr_strdup(assoc->encode,
+                                                   srw_req->recordOldVersion );
+            }
+            if ( srw_req->extraRequestData ){
+                rr.extra_request_data = odr_strdup(assoc->encode,
+                                                   srw_req->extraRequestData );
+            }
+       }
+       else if ( !strcmp( rr.operation, "replace" ) ){
+            if ( !srw_req->recordId ){
+                yaz_add_srw_diagnostic(assoc->encode, &srw_res->diagnostics,
+                                       &srw_res->num_diagnostics,
+                                       7, "recordId" );
+            }
+            else {
+                rr.record_id = srw_req->recordId;
+            }
+            if ( srw_req->record.recordSchema == 0 ){
+                yaz_add_srw_diagnostic(assoc->encode, &srw_res->diagnostics,
+                                       &srw_res->num_diagnostics,
+                                       7, "recordSchema" );
+            }
+            else {
+                rr.record_schema = odr_strdup(assoc->encode,
+                                              srw_req->record.recordSchema );
+            }
+            switch (srw_req->record.recordPacking)
+            {
+            case Z_SRW_recordPacking_string: 
+                rr.record_packing = "string";
+                break;
+            case Z_SRW_recordPacking_XML: 
+                rr.record_packing = "xml";
+                break;
+            case Z_SRW_recordPacking_URL: 
+                rr.record_packing = "url";
+                break;
+            }
+            if ( srw_req->record.recordData_len ){
+                rr.record_data = odr_strdupn(assoc->encode, 
+                                             srw_req->record.recordData_buf,
+                                             srw_req->record.recordData_len );
+                rr.request_extra_record = srw_req->extra_record;
+            }
+            else {
+                yaz_add_srw_diagnostic(assoc->encode, &srw_res->diagnostics,
+                                       &srw_res->num_diagnostics,
+                                       7, "recordData" );
+            }
+            if (srw_req->extraRequestData)
+                rr.extra_request_data = odr_strdup(assoc->encode,
+                                                   srw_req->extraRequestData );
+       }
+       else if ( !strcmp( rr.operation, "insert" ) )
+        {
+            if ( srw_req->record.recordSchema == 0 ){
+                yaz_add_srw_diagnostic(assoc->encode, &srw_res->diagnostics,
+                                       &srw_res->num_diagnostics,
+                                       7, "recordSchema" );
+            }
+            else {
+                rr.record_schema = odr_strdup(assoc->encode,
+                                              srw_req->record.recordSchema);
+            }
+            switch (srw_req->record.recordPacking)
+            {
+            case Z_SRW_recordPacking_string: 
+                rr.record_packing = "string";
+                break;
+            case Z_SRW_recordPacking_XML: 
+                rr.record_packing = "xml";
+                break;
+            case Z_SRW_recordPacking_URL: 
+                rr.record_packing = "url";
+                break;
+            }
+            
+            if (srw_req->record.recordData_len)
+            {
+                rr.record_data = odr_strdupn(assoc->encode, 
+                                             srw_req->record.recordData_buf,
+                                             srw_req->record.recordData_len );
+                rr.request_extra_record = srw_req->extra_record;
+            }
+            else
+                yaz_add_srw_diagnostic(assoc->encode, &srw_res->diagnostics,
+                                       &srw_res->num_diagnostics,
+                                       7, "recordData" );
+            if ( srw_req->extraRequestData )
+                rr.extra_request_data = odr_strdup(assoc->encode,
+                                                   srw_req->extraRequestData );
+       }
+        if (srw_res->num_diagnostics == 0)
+        {
+            if ( assoc->init->bend_srw_update)
+                (*assoc->init->bend_srw_update)(assoc->backend, &rr);
+            else {
+                yaz_log( YLOG_WARN, "Got No Update function!");
+                return;
+            }
+        }
+        if (rr.errcode)
+            yaz_add_srw_diagnostic(assoc->encode,
+                                   &srw_res->diagnostics,
+                                   &srw_res->num_diagnostics,
+                                   rr.errcode, rr.errstring);
+       srw_res->recordId = rr.record_id;
+       srw_res->operationStatus = rr.operation_status;
+       srw_res->recordVersion = rr.record_version;
+       srw_res->recordChecksum = rr.record_checksum;
+       srw_res->extraResponseData = rr.extra_response_data;
+        srw_res->record.recordPosition = 0;
+       if (srw_res->num_diagnostics == 0 && rr.record_data)
+       {
+            srw_res->record.recordSchema = rr.record_schema;
+            srw_res->record.recordPacking = srw_req->record.recordPacking;
+            srw_res->record.recordData_buf = rr.record_data;
+            srw_res->record.recordData_len = strlen(rr.record_data);
+            srw_res->extra_record = rr.response_extra_record;
+                
+       }
+       else
+            srw_res->record.recordData_len = 0;
+       *http_code = 200;
+    }
+}
+
+/* check if path is OK (1); BAD (0) */
+static int check_path(const char *path)
+{
+    if (*path != '/')
+        return 0;
+    if (strstr(path, ".."))
+        return 0;
+    return 1;
+}
+
+static char *read_file(const char *fname, ODR o, int *sz)
+{
+    char *buf;
+    FILE *inf = fopen(fname, "rb");
+    if (!inf)
+        return 0;
+
+    fseek(inf, 0L, SEEK_END);
+    *sz = ftell(inf);
+    rewind(inf);
+    buf = odr_malloc(o, *sz);
+    fread(buf, 1, *sz, inf);
+    fclose(inf);
+    return buf;     
 }
 
 static void process_http_request(association *assoc, request *req)
@@ -782,122 +1582,204 @@ static void process_http_request(association *assoc, request *req)
     char *charset = 0;
     Z_HTTP_Response *hres = 0;
     int keepalive = 1;
-    char *stylesheet = 0;
+    const char *stylesheet = 0; /* for now .. set later */
     Z_SRW_diagnostic *diagnostic = 0;
     int num_diagnostic = 0;
-
-    if (!strcmp(hreq->path, "/test")) 
-    {  
-       p = z_get_HTTP_Response(o, 200);
-       hres = p->u.HTTP_Response;
-       hres->content_buf = "1234567890\n";
-       hres->content_len = strlen(hres->content_buf);
-       r = 1;
+    const char *host = z_HTTP_header_lookup(hreq->headers, "Host");
+
+    if (!control_association(assoc, host, 0))
+    {
+        p = z_get_HTTP_Response(o, 404);
+        r = 1;
+    }
+    if (r == 2 && assoc->server && assoc->server->docpath
+        && hreq->path[0] == '/' 
+        && 
+        /* check if path is a proper prefix of documentroot */
+        strncmp(hreq->path+1, assoc->server->docpath,
+                strlen(assoc->server->docpath))
+        == 0)
+    {   
+        if (!check_path(hreq->path))
+        {
+            yaz_log(YLOG_LOG, "File %s access forbidden", hreq->path+1);
+            p = z_get_HTTP_Response(o, 404);
+        }
+        else
+        {
+            int content_size = 0;
+            char *content_buf = read_file(hreq->path+1, o, &content_size);
+            if (!content_buf)
+            {
+                yaz_log(YLOG_LOG, "File %s not found", hreq->path+1);
+                p = z_get_HTTP_Response(o, 404);
+            }
+            else
+            {
+                const char *ctype = 0;
+                yaz_mime_types types = yaz_mime_types_create();
+                
+                yaz_mime_types_add(types, "xsl", "application/xml");
+                yaz_mime_types_add(types, "xml", "application/xml");
+                yaz_mime_types_add(types, "css", "text/css");
+                yaz_mime_types_add(types, "html", "text/html");
+                yaz_mime_types_add(types, "htm", "text/html");
+                yaz_mime_types_add(types, "txt", "text/plain");
+                yaz_mime_types_add(types, "js", "application/x-javascript");
+                
+                yaz_mime_types_add(types, "gif", "image/gif");
+                yaz_mime_types_add(types, "png", "image/png");
+                yaz_mime_types_add(types, "jpg", "image/jpeg");
+                yaz_mime_types_add(types, "jpeg", "image/jpeg");
+                
+                ctype = yaz_mime_lookup_fname(types, hreq->path);
+                if (!ctype)
+                {
+                    yaz_log(YLOG_LOG, "No mime type for %s", hreq->path+1);
+                    p = z_get_HTTP_Response(o, 404);
+                }
+                else
+                {
+                    p = z_get_HTTP_Response(o, 200);
+                    hres = p->u.HTTP_Response;
+                    hres->content_buf = content_buf;
+                    hres->content_len = content_size;
+                    z_HTTP_header_add(o, &hres->headers, "Content-Type", ctype);
+                }
+                yaz_mime_types_destroy(types);
+            }
+        }
+        r = 1;
     }
+
     if (r == 2)
     {
-       r = yaz_srw_decode(hreq, &sr, &soap_package, assoc->decode, &charset);
-       yaz_log(LOG_DEBUG, "yaz_srw_decode returned %d", r);
+        r = yaz_srw_decode(hreq, &sr, &soap_package, assoc->decode, &charset);
+        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);
+        r = yaz_sru_decode(hreq, &sr, &soap_package, assoc->decode, &charset,
+                           &diagnostic, &num_diagnostic);
+        yaz_log(YLOG_DEBUG, "yaz_sru_decode returned %d", r);
     }
     if (r == 0)  /* decode SRW/SRU OK .. */
     {
-       int http_code = 200;
-       if (sr->which == Z_SRW_searchRetrieve_request)
-       {
-           Z_SRW_PDU *res =
-               yaz_srw_get(assoc->encode, Z_SRW_searchRetrieve_response);
-
-           stylesheet = sr->u.request->stylesheet;
-           if (num_diagnostic)
-           {
-               res->u.response->diagnostics = diagnostic;
-               res->u.response->num_diagnostics = num_diagnostic;
-           }
-           else
-           {
-               srw_bend_search(assoc, req, sr->u.request, res->u.response, 
-                               &http_code);
-           }
-           if (http_code == 200)
-               soap_package->u.generic->p = res;
-       }
-       else if (sr->which == Z_SRW_explain_request)
-       {
+        int http_code = 200;
+        if (sr->which == Z_SRW_searchRetrieve_request)
+        {
+            Z_SRW_PDU *res =
+                yaz_srw_get(assoc->encode, Z_SRW_searchRetrieve_response);
+
+            stylesheet = sr->u.request->stylesheet;
+            if (num_diagnostic)
+            {
+                res->u.response->diagnostics = diagnostic;
+                res->u.response->num_diagnostics = num_diagnostic;
+            }
+            else
+            {
+                srw_bend_search(assoc, req, sr, res->u.response, 
+                                &http_code);
+            }
+            if (http_code == 200)
+                soap_package->u.generic->p = res;
+        }
+        else if (sr->which == Z_SRW_explain_request)
+        {
             Z_SRW_PDU *res = yaz_srw_get(o, Z_SRW_explain_response);
-           stylesheet = sr->u.explain_request->stylesheet;
-           if (num_diagnostic)
-           {   
-               res->u.explain_response->diagnostics = diagnostic;
-               res->u.explain_response->num_diagnostics = num_diagnostic;
-           }
-           srw_bend_explain(assoc, req, sr->u.explain_request,
-                            res->u.explain_response, &http_code);
-           if (http_code == 200)
-               soap_package->u.generic->p = res;
-       }
-       else if (sr->which == Z_SRW_scan_request)
-       {
+            stylesheet = sr->u.explain_request->stylesheet;
+            if (num_diagnostic)
+            {   
+                res->u.explain_response->diagnostics = diagnostic;
+                res->u.explain_response->num_diagnostics = num_diagnostic;
+            }
+            srw_bend_explain(assoc, req, sr,
+                             res->u.explain_response, &http_code);
+            if (http_code == 200)
+                soap_package->u.generic->p = res;
+        }
+        else if (sr->which == Z_SRW_scan_request)
+        {
             Z_SRW_PDU *res = yaz_srw_get(o, Z_SRW_scan_response);
-           stylesheet = sr->u.scan_request->stylesheet;
-           if (num_diagnostic)
-           {   
-               res->u.scan_response->diagnostics = diagnostic;
-               res->u.scan_response->num_diagnostics = num_diagnostic;
-           }
-           yaz_add_srw_diagnostic(o, 
-                                  &res->u.scan_response->diagnostics,
-                                  &res->u.scan_response->num_diagnostics,
-                                  4, "scan");
-           if (http_code == 200)
-               soap_package->u.generic->p = res;
-       }
-       else
-       {
-                yaz_log(LOG_LOG, "generate soap error");
-           http_code = 500;
-           z_soap_error(assoc->encode, soap_package,
-                        "SOAP-ENV:Client", "Bad method", 0); 
-       }
-       if (http_code == 200 || http_code == 500)
-       {
-           static Z_SOAP_Handler soap_handlers[3] = {
+            stylesheet = sr->u.scan_request->stylesheet;
+            if (num_diagnostic)
+            {   
+                res->u.scan_response->diagnostics = diagnostic;
+                res->u.scan_response->num_diagnostics = num_diagnostic;
+            }
+            srw_bend_scan(assoc, req, sr,
+                          res->u.scan_response, &http_code);
+            if (http_code == 200)
+                soap_package->u.generic->p = res;
+        }
+        else if (sr->which == Z_SRW_update_request)
+        {
+            Z_SRW_PDU *res = yaz_srw_get(o, Z_SRW_update_response);
+            yaz_log(YLOG_DEBUG, "handling SRW UpdateRequest");
+            if (num_diagnostic)
+            {   
+                res->u.update_response->diagnostics = diagnostic;
+                res->u.update_response->num_diagnostics = num_diagnostic;
+            }
+            yaz_log(YLOG_DEBUG, "num_diag = %d", res->u.update_response->num_diagnostics );
+            srw_bend_update(assoc, req, sr,
+                            res->u.update_response, &http_code);
+            if (http_code == 200)
+                soap_package->u.generic->p = res;
+        }
+        else
+        {
+            yaz_log(log_request, "SOAP ERROR"); 
+            /* FIXME - what error, what query */
+            http_code = 500;
+            z_soap_error(assoc->encode, soap_package,
+                         "SOAP-ENV:Client", "Bad method", 0); 
+        }
+        if (http_code == 200 || http_code == 500)
+        {
+            static Z_SOAP_Handler soap_handlers[4] = {
 #if HAVE_XML2
-               {"http://www.loc.gov/zing/srw/", 0,
-                (Z_SOAP_fun) yaz_srw_codec},
+                {"http://www.loc.gov/zing/srw/", 0,
+                 (Z_SOAP_fun) yaz_srw_codec},
                 {"http://www.loc.gov/zing/srw/v1.0/", 0,
                  (Z_SOAP_fun) yaz_srw_codec},
+                {"http://www.loc.gov/zing/srw/update/", 0,
+                 (Z_SOAP_fun) yaz_ucp_codec},
 #endif
-               {0, 0, 0}
-           };
-           char ctype[60];
-           int ret;
-           p = z_get_HTTP_Response(o, 200);
-           hres = p->u.HTTP_Response;
-           ret = z_soap_codec_enc_xsl(assoc->encode, &soap_package,
-                                      &hres->content_buf, &hres->content_len,
-                                      soap_handlers, charset, stylesheet);
-           hres->code = http_code;
-
-           strcpy(ctype, "text/xml");
-           if (charset)
-           {
-               strcat(ctype, "; charset=");
-               strcat(ctype, charset);
-           }
-           z_HTTP_header_add(o, &hres->headers, "Content-Type", ctype);
-       }
-       else
-           p = z_get_HTTP_Response(o, http_code);
+                {0, 0, 0}
+            };
+            char ctype[60];
+            int ret;
+            p = z_get_HTTP_Response(o, 200);
+            hres = p->u.HTTP_Response;
+
+            if (!stylesheet && assoc->server)
+                stylesheet = assoc->server->stylesheet;
+
+            /* empty stylesheet means NO stylesheet */
+            if (stylesheet && *stylesheet == '\0')
+                stylesheet = 0;
+
+            ret = z_soap_codec_enc_xsl(assoc->encode, &soap_package,
+                                       &hres->content_buf, &hres->content_len,
+                                       soap_handlers, charset, stylesheet);
+            hres->code = http_code;
+
+            strcpy(ctype, "text/xml");
+            if (charset)
+            {
+                strcat(ctype, "; charset=");
+                strcat(ctype, charset);
+            }
+            z_HTTP_header_add(o, &hres->headers, "Content-Type", ctype);
+        }
+        else
+            p = z_get_HTTP_Response(o, http_code);
     }
 
     if (p == 0)
-       p = z_get_HTTP_Response(o, 500);
+        p = z_get_HTTP_Response(o, 500);
     hres = p->u.HTTP_Response;
     if (!strcmp(hreq->version, "1.0")) 
     {
@@ -921,14 +1803,14 @@ static void process_http_request(association *assoc, request *req)
     {
         z_HTTP_header_add(o, &hres->headers, "Connection", "close");
         assoc->state = ASSOC_DEAD;
-       assoc->cs_get_mask = 0;
+        assoc->cs_get_mask = 0;
     }
     else
     {
         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;
@@ -970,95 +1852,95 @@ static int process_z_request(association *assoc, request *req, char **msg)
     assert(req && req->state == REQUEST_IDLE);
     if (req->apdu_request->which != Z_APDU_initRequest && !assoc->init)
     {
-       *msg = "Missing InitRequest";
-       return -1;
+        *msg = "Missing InitRequest";
+        return -1;
     }
     switch (req->apdu_request->which)
     {
     case Z_APDU_initRequest:
-        iochan_settimeout(assoc->client_chan,
-                          statserv_getcontrol()->idle_timeout * 60);
-       res = process_initRequest(assoc, req); break;
+        res = process_initRequest(assoc, req); break;
     case Z_APDU_searchRequest:
-       res = process_searchRequest(assoc, req, &fd); break;
+        res = process_searchRequest(assoc, req, &fd); break;
     case Z_APDU_presentRequest:
-       res = process_presentRequest(assoc, req, &fd); break;
+        res = process_presentRequest(assoc, req, &fd); break;
     case Z_APDU_scanRequest:
-       if (assoc->init->bend_scan)
-           res = process_scanRequest(assoc, req, &fd);
-       else
-       {
-           *msg = "Cannot handle Scan APDU";
-           return -1;
-       }
-       break;
+        if (assoc->init->bend_scan)
+            res = process_scanRequest(assoc, req, &fd);
+        else
+        {
+            *msg = "Cannot handle Scan APDU";
+            return -1;
+        }
+        break;
     case Z_APDU_extendedServicesRequest:
-       if (assoc->init->bend_esrequest)
-           res = process_ESRequest(assoc, req, &fd);
-       else
-       {
-           *msg = "Cannot handle Extended Services APDU";
-           return -1;
-       }
-       break;
+        if (assoc->init->bend_esrequest)
+            res = process_ESRequest(assoc, req, &fd);
+        else
+        {
+            *msg = "Cannot handle Extended Services APDU";
+            return -1;
+        }
+        break;
     case Z_APDU_sortRequest:
-       if (assoc->init->bend_sort)
-           res = process_sortRequest(assoc, req, &fd);
-       else
-       {
-           *msg = "Cannot handle Sort APDU";
-           return -1;
-       }
-       break;
+        if (assoc->init->bend_sort)
+            res = process_sortRequest(assoc, req, &fd);
+        else
+        {
+            *msg = "Cannot handle Sort APDU";
+            return -1;
+        }
+        break;
     case Z_APDU_close:
-       process_close(assoc, req);
-       return 0;
+        process_close(assoc, req);
+        return 0;
     case Z_APDU_deleteResultSetRequest:
-       if (assoc->init->bend_delete)
-           res = process_deleteRequest(assoc, req, &fd);
-       else
-       {
-           *msg = "Cannot handle Delete APDU";
-           return -1;
-       }
-       break;
+        if (assoc->init->bend_delete)
+            res = process_deleteRequest(assoc, req, &fd);
+        else
+        {
+            *msg = "Cannot handle Delete APDU";
+            return -1;
+        }
+        break;
     case Z_APDU_segmentRequest:
-       if (assoc->init->bend_segment)
-       {
-           res = process_segmentRequest (assoc, req);
-       }
-       else
-       {
-           *msg = "Cannot handle Segment APDU";
-           return -1;
-       }
-       break;
+        if (assoc->init->bend_segment)
+        {
+            res = process_segmentRequest (assoc, req);
+        }
+        else
+        {
+            *msg = "Cannot handle Segment APDU";
+            return -1;
+        }
+        break;
+    case Z_APDU_triggerResourceControlRequest:
+        return 0;
     default:
-       *msg = "Bad APDU received";
-       return -1;
+        *msg = "Bad APDU received";
+        return -1;
     }
     if (res)
     {
-       yaz_log(LOG_DEBUG, "  result immediately available");
-       retval = process_z_response(assoc, req, res);
+        yaz_log(YLOG_DEBUG, "  result immediately available");
+        retval = process_z_response(assoc, req, res);
     }
     else if (fd < 0)
     {
-       yaz_log(LOG_DEBUG, "  result unavailble");
-       retval = 0;
+        yaz_log(YLOG_DEBUG, "  result unavailble");
+        retval = 0;
     }
     else /* no result yet - one will be provided later */
     {
-       IOCHAN chan;
+        IOCHAN chan;
 
-       /* Set up an I/O handler for the fd supplied by the backend */
+        /* Set up an I/O handler for the fd supplied by the backend */
 
-       yaz_log(LOG_DEBUG, "   establishing handler for result");
-       req->state = REQUEST_PENDING;
-       if (!(chan = iochan_create(fd, backend_response, EVENT_INPUT)))
-           abort();
-       iochan_setdata(chan, assoc);
-       retval = 0;
+        yaz_log(YLOG_DEBUG, "   establishing handler for result");
+        req->state = REQUEST_PENDING;
+        if (!(chan = iochan_create(fd, backend_response, EVENT_INPUT, 0)))
+            abort();
+        iochan_setdata(chan, assoc);
+        retval = 0;
     }
     return retval;
 }
@@ -1073,34 +1955,34 @@ 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)
     {
-       case Z_APDU_searchRequest:
-           res = response_searchRequest(assoc, req, 0, &fd); break;
+        case Z_APDU_searchRequest:
+            res = response_searchRequest(assoc, req, 0, &fd); break;
 #if 0
-       case Z_APDU_presentRequest:
-           res = response_presentRequest(assoc, req, 0, &fd); break;
-       case Z_APDU_scanRequest:
-           res = response_scanRequest(assoc, req, 0, &fd); break;
+        case Z_APDU_presentRequest:
+            res = response_presentRequest(assoc, req, 0, &fd); break;
+        case Z_APDU_scanRequest:
+            res = response_scanRequest(assoc, req, 0, &fd); break;
 #endif
-       default:
-           yaz_log(LOG_WARN, "Serious programmer's lapse or bug");
-           abort();
+        default:
+            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_LOG, "Fatal error when talking to backend");
-       do_close(assoc, Z_Close_systemProblem, 0);
-       iochan_destroy(i);
-       return;
+        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");
-       iochan_setfd(i, fd); /* in case fd has changed */
+        yaz_log(YLOG_DEBUG, "   no result yet");
+        iochan_setfd(i, fd); /* in case fd has changed */
     }
 }
 
@@ -1113,21 +1995,20 @@ 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", 
-               odr_errmsg(odr_geterror(assoc->print)));
-       odr_reset(assoc->print);
+        if (!z_GDU(assoc->print, &res, 0, 0))
+            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;
+        return -1;
     }
     req->response = odr_getbuf(assoc->encode, &req->len_response,
-       &req->size_response);
+        &req->size_response);
     odr_setbuf(assoc->encode, 0, 0, 0); /* don'txfree if we abort later */
     odr_reset(assoc->encode);
     req->state = REQUEST_IDLE;
@@ -1139,8 +2020,8 @@ 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");
-       iochan_setevent(assoc->client_chan, EVENT_WORK);
+        yaz_log (YLOG_DEBUG, "more work to be done");
+        iochan_setevent(assoc->client_chan, EVENT_WORK);
     }
 #endif
     return 0;
@@ -1158,6 +2039,10 @@ static int process_z_response(association *assoc, request *req, Z_APDU *res)
     return process_gdu_response(assoc, req, gres);
 }
 
+static char *get_vhost(Z_OtherInformation *otherInfo)
+{
+    return yaz_oi_get_string_oidval(&otherInfo, VAL_PROXY, 1, 0);
+}
 
 /*
  * Handle init request.
@@ -1168,22 +2053,31 @@ static int process_z_response(association *assoc, request *req, Z_APDU *res)
  */
 static Z_APDU *process_initRequest(association *assoc, request *reqb)
 {
-    statserv_options_block *cb = statserv_getcontrol();
     Z_InitRequest *req = reqb->apdu_request->u.initRequest;
     Z_APDU *apdu = zget_APDU(assoc->encode, Z_APDU_initResponse);
     Z_InitResponse *resp = apdu->u.initResponse;
     bend_initresult *binitres;
     char *version;
     char options[140];
+    statserv_options_block *cb = 0;  /* by default no control for backend */
+
+    if (control_association(assoc, get_vhost(req->otherInfo), 1))
+        cb = statserv_getcontrol();  /* got control block for backend */
 
-    yaz_log(LOG_LOG, "Got initRequest");
+    if (cb && assoc->backend)
+        (*cb->bend_close)(assoc->backend);
+
+    yaz_log(log_requestdetail, "Got initRequest");
     if (req->implementationId)
-       yaz_log(LOG_LOG, "Id:        %s", req->implementationId);
+        yaz_log(log_requestdetail, "Id:        %s",
+                req->implementationId);
     if (req->implementationName)
-       yaz_log(LOG_LOG, "Name:      %s", req->implementationName);
+        yaz_log(log_requestdetail, "Name:      %s",
+                req->implementationName);
     if (req->implementationVersion)
-       yaz_log(LOG_LOG, "Version:   %s", req->implementationVersion);
-
+        yaz_log(log_requestdetail, "Version:   %s",
+                req->implementationVersion);
+    
     assoc_init_reset(assoc);
 
     assoc->init->auth = req->idAuthentication;
@@ -1194,230 +2088,233 @@ static Z_APDU *process_initRequest(association *assoc, request *reqb)
         Z_CharSetandLanguageNegotiation *negotiation =
             yaz_get_charneg_record (req->otherInfo);
         if (negotiation &&
-           negotiation->which == Z_CharSetandLanguageNegotiation_proposal)
+            negotiation->which == Z_CharSetandLanguageNegotiation_proposal)
             assoc->init->charneg_request = negotiation;
     }
-    
+
     assoc->backend = 0;
-    if (!(binitres = (*cb->bend_init)(assoc->init)))
+    if (cb)
     {
-       yaz_log(LOG_WARN, "Bad response from backend.");
-       return 0;
+        if (req->implementationVersion)
+            yaz_log(log_requestdetail, "Config:    %s",
+                    cb->configname);
+    
+        iochan_settimeout(assoc->client_chan, cb->idle_timeout * 60);
+        
+        /* we have a backend control block, so call that init function */
+        if (!(binitres = (*cb->bend_init)(assoc->init)))
+        {
+            yaz_log(YLOG_WARN, "Bad response from backend.");
+            return 0;
+        }
+        assoc->backend = binitres->handle;
+    }
+    else
+    {
+        /* no backend. return error */
+        binitres = odr_malloc(assoc->encode, sizeof(*binitres));
+        binitres->errstring = 0;
+        binitres->errcode = YAZ_BIB1_PERMANENT_SYSTEM_ERROR;
+        iochan_settimeout(assoc->client_chan, 10);
     }
-
-    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';
     /* let's tell the client what we can do */
     if (ODR_MASK_GET(req->options, Z_Options_search))
     {
-       ODR_MASK_SET(resp->options, Z_Options_search);
-       strcat(options, "srch");
+        ODR_MASK_SET(resp->options, Z_Options_search);
+        strcat(options, "srch");
     }
     if (ODR_MASK_GET(req->options, Z_Options_present))
     {
-       ODR_MASK_SET(resp->options, Z_Options_present);
-       strcat(options, " prst");
+        ODR_MASK_SET(resp->options, Z_Options_present);
+        strcat(options, " prst");
     }
     if (ODR_MASK_GET(req->options, Z_Options_delSet) &&
-       assoc->init->bend_delete)
+        assoc->init->bend_delete)
     {
-       ODR_MASK_SET(resp->options, Z_Options_delSet);
-       strcat(options, " del");
+        ODR_MASK_SET(resp->options, Z_Options_delSet);
+        strcat(options, " del");
     }
     if (ODR_MASK_GET(req->options, Z_Options_extendedServices) &&
-       assoc->init->bend_esrequest)
+        assoc->init->bend_esrequest)
     {
-       ODR_MASK_SET(resp->options, Z_Options_extendedServices);
-       strcat (options, " extendedServices");
+        ODR_MASK_SET(resp->options, Z_Options_extendedServices);
+        strcat (options, " extendedServices");
     }
     if (ODR_MASK_GET(req->options, Z_Options_namedResultSets))
     {
-       ODR_MASK_SET(resp->options, Z_Options_namedResultSets);
-       strcat(options, " namedresults");
+        ODR_MASK_SET(resp->options, Z_Options_namedResultSets);
+        strcat(options, " namedresults");
     }
     if (ODR_MASK_GET(req->options, Z_Options_scan) && assoc->init->bend_scan)
     {
-       ODR_MASK_SET(resp->options, Z_Options_scan);
-       strcat(options, " scan");
+        ODR_MASK_SET(resp->options, Z_Options_scan);
+        strcat(options, " scan");
     }
     if (ODR_MASK_GET(req->options, Z_Options_concurrentOperations))
     {
-       ODR_MASK_SET(resp->options, Z_Options_concurrentOperations);
-       strcat(options, " concurrop");
+        ODR_MASK_SET(resp->options, Z_Options_concurrentOperations);
+        strcat(options, " concurrop");
     }
     if (ODR_MASK_GET(req->options, Z_Options_sort) && assoc->init->bend_sort)
     {
-       ODR_MASK_SET(resp->options, Z_Options_sort);
-       strcat(options, " sort");
+        ODR_MASK_SET(resp->options, Z_Options_sort);
+        strcat(options, " sort");
     }
 
     if (ODR_MASK_GET(req->options, Z_Options_negotiationModel)
         && assoc->init->charneg_response)
     {
-       Z_OtherInformation **p;
-       Z_OtherInformationUnit *p0;
-       
-       yaz_oi_APDU(apdu, &p);
-       
-       if ((p0=yaz_oi_update(p, assoc->encode, NULL, 0, 0))) {
+        Z_OtherInformation **p;
+        Z_OtherInformationUnit *p0;
+        
+        yaz_oi_APDU(apdu, &p);
+        
+        if ((p0=yaz_oi_update(p, assoc->encode, NULL, 0, 0))) {
             ODR_MASK_SET(resp->options, Z_Options_negotiationModel);
             
             p0->which = Z_OtherInfo_externallyDefinedInfo;
             p0->information.externallyDefinedInfo =
                 assoc->init->charneg_response;
         }
-       ODR_MASK_SET(resp->options, Z_Options_negotiationModel);
-       strcat(options, " negotiation");
+        ODR_MASK_SET(resp->options, Z_Options_negotiationModel);
+        strcat(options, " negotiation");
     }
+        
+    ODR_MASK_SET(resp->options, Z_Options_triggerResourceCtrl);
 
     if (ODR_MASK_GET(req->protocolVersion, Z_ProtocolVersion_1))
     {
-       ODR_MASK_SET(resp->protocolVersion, Z_ProtocolVersion_1);
-       assoc->version = 1; /* 1 & 2 are equivalent */
+        ODR_MASK_SET(resp->protocolVersion, Z_ProtocolVersion_1);
+        assoc->version = 1; /* 1 & 2 are equivalent */
     }
     if (ODR_MASK_GET(req->protocolVersion, Z_ProtocolVersion_2))
     {
-       ODR_MASK_SET(resp->protocolVersion, Z_ProtocolVersion_2);
-       assoc->version = 2;
+        ODR_MASK_SET(resp->protocolVersion, Z_ProtocolVersion_2);
+        assoc->version = 2;
     }
     if (ODR_MASK_GET(req->protocolVersion, Z_ProtocolVersion_3))
     {
-       ODR_MASK_SET(resp->protocolVersion, Z_ProtocolVersion_3);
-       assoc->version = 3;
+        ODR_MASK_SET(resp->protocolVersion, Z_ProtocolVersion_3);
+        assoc->version = 3;
     }
 
-    yaz_log(LOG_LOG, "Negotiated to v%d: %s", assoc->version, options);
+    yaz_log(log_requestdetail, "Negotiated to v%d: %s", assoc->version, options);
     assoc->maximumRecordSize = *req->maximumRecordSize;
-    if (assoc->maximumRecordSize > control_block->maxrecordsize)
-       assoc->maximumRecordSize = control_block->maxrecordsize;
+
+    if (cb && assoc->maximumRecordSize > cb->maxrecordsize)
+        assoc->maximumRecordSize = cb->maxrecordsize;
     assoc->preferredMessageSize = *req->preferredMessageSize;
     if (assoc->preferredMessageSize > assoc->maximumRecordSize)
-       assoc->preferredMessageSize = assoc->maximumRecordSize;
+        assoc->preferredMessageSize = assoc->maximumRecordSize;
 
     resp->preferredMessageSize = &assoc->preferredMessageSize;
     resp->maximumRecordSize = &assoc->maximumRecordSize;
 
     resp->implementationId = odr_prepend(assoc->encode,
-               assoc->init->implementation_id,
-               resp->implementationId);
+                assoc->init->implementation_id,
+                resp->implementationId);
 
     resp->implementationName = odr_prepend(assoc->encode,
-               assoc->init->implementation_name,
-               odr_prepend(assoc->encode, "GFS", resp->implementationName));
+                assoc->init->implementation_name,
+                odr_prepend(assoc->encode, "GFS", resp->implementationName));
 
-    version = odr_strdup(assoc->encode, "$Revision: 1.23 $");
-    if (strlen(version) > 10)  /* check for unexpanded CVS strings */
-       version[strlen(version)-2] = '\0';
+    version = odr_strdup(assoc->encode, "$Revision: 1.79 $");
+    if (strlen(version) > 10)   /* check for unexpanded CVS strings */
+        version[strlen(version)-2] = '\0';
     resp->implementationVersion = odr_prepend(assoc->encode,
-               assoc->init->implementation_version,
-               odr_prepend(assoc->encode, &version[11],
-                           resp->implementationVersion));
+                assoc->init->implementation_version,
+                odr_prepend(assoc->encode, &version[11],
+                            resp->implementationVersion));
 
     if (binitres->errcode)
     {
-       yaz_log(LOG_LOG, "Connection rejected by backend.");
-       *resp->result = 0;
-       assoc->state = ASSOC_DEAD;
-       resp->userInformationField = init_diagnostics(assoc->encode,
-                                                     binitres->errcode,
-                                                     binitres->errstring);
+        assoc->state = ASSOC_DEAD;
+        resp->userInformationField =
+            init_diagnostics(assoc->encode, binitres->errcode,
+                             binitres->errstring);
+        *resp->result = 0;
+    }
+    if (log_request)
+    {
+        if (!req->idAuthentication)
+            yaz_log(log_request, "Auth none");
+        else if (req->idAuthentication->which == Z_IdAuthentication_open)
+        {
+            const char *open = req->idAuthentication->u.open;
+            const char *slash = strchr(open, '/');
+            int len;
+            if (slash)
+                len = slash - open;
+            else
+                len = strlen(open);
+                yaz_log(log_request, "Auth open %.*s", len, open);
+        }
+        else if (req->idAuthentication->which == Z_IdAuthentication_idPass)
+        {
+            const char *user = req->idAuthentication->u.idPass->userId;
+            const char *group = req->idAuthentication->u.idPass->groupId;
+            yaz_log(log_request, "Auth idPass %s %s",
+                    user ? user : "-", group ? group : "-");
+        }
+        else if (req->idAuthentication->which 
+                 == Z_IdAuthentication_anonymous)
+        {
+            yaz_log(log_request, "Auth anonymous");
+        }
+        else
+        {
+            yaz_log(log_request, "Auth other");
+        }
+    }
+    if (log_request)
+    {
+        WRBUF wr = wrbuf_alloc();
+        wrbuf_printf(wr, "Init ");
+        if (binitres->errcode)
+            wrbuf_printf(wr, "ERROR %d", binitres->errcode);
+        else
+            wrbuf_printf(wr, "OK -");
+        wrbuf_printf(wr, " ID:%s Name:%s Version:%s",
+                     (req->implementationId ? req->implementationId :"-"), 
+                     (req->implementationName ?
+                      req->implementationName : "-"),
+                     (req->implementationVersion ?
+                      req->implementationVersion : "-")
+            );
+        yaz_log(log_request, "%s", wrbuf_buf(wr));
+        wrbuf_free(wr, 1);
     }
-    else
-       assoc->state = ASSOC_UP;
     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_LOG, "[%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
+ *      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);
 }
 
 /*
@@ -1425,205 +2322,181 @@ 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,
-                              int *num, Z_RecordComposition *comp,
-                              int *next, int *pres, oid_value format,
-                              Z_ReferenceId *referenceId,
-                              int *oid)
+                               int *num, Z_RecordComposition *comp,
+                               int *next, int *pres, oid_value format,
+                               Z_ReferenceId *referenceId,
+                               int *oid, int *errcode)
 {
     int recno, total_length = 0, toget = *num, dumped_records = 0;
     Z_Records *records =
-       (Z_Records *) odr_malloc (a->encode, sizeof(*records));
+        (Z_Records *) odr_malloc (a->encode, sizeof(*records));
     Z_NamePlusRecordList *reclist =
-       (Z_NamePlusRecordList *) odr_malloc (a->encode, sizeof(*reclist));
+        (Z_NamePlusRecordList *) odr_malloc (a->encode, sizeof(*reclist));
     Z_NamePlusRecord **list =
-       (Z_NamePlusRecord **) odr_malloc (a->encode, sizeof(*list) * toget);
+        (Z_NamePlusRecord **) odr_malloc (a->encode, sizeof(*list) * toget);
 
     records->which = Z_Records_DBOSD;
     records->u.databaseOrSurDiagnostics = reclist;
     reclist->num_records = 0;
     reclist->records = list;
-    *pres = Z_PRES_SUCCESS;
+    *pres = Z_PresentStatus_success;
     *num = 0;
     *next = 0;
 
-    yaz_log(LOG_LOG, "Request to pack %d+%d+%s", start, toget, setname);
-    yaz_log(LOG_DEBUG, "pms=%d, mrs=%d", a->preferredMessageSize,
-       a->maximumRecordSize);
+    yaz_log(log_requestdetail, "Request to pack %d+%d %s", start, toget, setname);
+    yaz_log(log_requestdetail, "pms=%d, mrs=%d", a->preferredMessageSize,
+        a->maximumRecordSize);
     for (recno = start; reclist->num_records < toget; recno++)
     {
-       bend_fetch_rr freq;
-       Z_NamePlusRecord *thisrec;
-       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
-        * idea of the total size of the data so far.
-        */
-       total_length = odr_total(a->encode) - dumped_records;
-       freq.errcode = 0;
-       freq.errstring = 0;
-       freq.basename = 0;
-       freq.len = 0;
-       freq.record = 0;
-       freq.last_in_set = 0;
-       freq.setname = setname;
-       freq.surrogate_flag = 0;
-       freq.number = recno;
-       freq.comp = comp;
-       freq.request_format = format;
-       freq.request_format_raw = oid;
-       freq.output_format = format;
-       freq.output_format_raw = 0;
-       freq.stream = a->encode;
-       freq.print = a->print;
-       freq.referenceId = referenceId;
+        bend_fetch_rr freq;
+        Z_NamePlusRecord *thisrec;
+        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
+         * idea of the total size of the data so far.
+         */
+        total_length = odr_total(a->encode) - dumped_records;
+        freq.errcode = 0;
+        freq.errstring = 0;
+        freq.basename = 0;
+        freq.len = 0;
+        freq.record = 0;
+        freq.last_in_set = 0;
+        freq.setname = setname;
+        freq.surrogate_flag = 0;
+        freq.number = recno;
+        freq.comp = comp;
+        freq.request_format = format;
+        freq.request_format_raw = oid;
+        freq.output_format = format;
+        freq.output_format_raw = 0;
+        freq.stream = a->encode;
+        freq.print = a->print;
+        freq.referenceId = referenceId;
         freq.schema = 0;
-       (*a->init->bend_fetch)(a->backend, &freq);
-       /* backend should be able to signal whether error is system-wide
-          or only pertaining to current record */
-       if (freq.errcode)
-       {
-           if (!freq.surrogate_flag)
-           {
-               char s[20];
-               *pres = Z_PRES_FAILURE;
-               /* for 'present request out of range',
+
+        retrieve_fetch(a, &freq);
+
+        *next = freq.last_in_set ? 0 : recno + 1;
+
+        /* backend should be able to signal whether error is system-wide
+           or only pertaining to current record */
+        if (freq.errcode)
+        {
+            if (!freq.surrogate_flag)
+            {
+                char s[20];
+                *pres = Z_PresentStatus_failure;
+                /* for 'present request out of range',
                    set addinfo to record position if not set */
-               if (freq.errcode == 13 && freq.errstring == 0)
-               {
-                   sprintf (s, "%d", recno);
-                   freq.errstring = s;
-               }
-               return diagrec(a, freq.errcode, freq.errstring);
-           }
-           reclist->records[reclist->num_records] =
-               surrogatediagrec(a, freq.basename, freq.errcode,
-                                freq.errstring);
-           reclist->num_records++;
-           *next = freq.last_in_set ? 0 : recno + 1;
-           continue;
-       }
-       if (freq.len >= 0)
-           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",
-           this_length, total_length, dumped_records);
-       if (a->preferredMessageSize > 0 &&
-               this_length + total_length > a->preferredMessageSize)
-       {
-           /* record is small enough, really */
-           if (this_length <= a->preferredMessageSize && recno > start)
-           {
-               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)
-           {
-               yaz_log(LOG_DEBUG, "  Record > prefmsgsz");
-               if (toget > 1)
-               {
-                   yaz_log(LOG_DEBUG, "  Dropped it");
-                   reclist->records[reclist->num_records] =
-                        surrogatediagrec(a, freq.basename, 16, 0);
-                   reclist->num_records++;
-                   *next = freq.last_in_set ? 0 : recno + 1;
-                   dumped_records += this_length;
-                   continue;
-               }
-           }
-           else /* too big entirely */
-           {
-               yaz_log(LOG_LOG, "Record > maxrcdsz this=%d max=%d", this_length, a->maximumRecordSize);
-               reclist->records[reclist->num_records] =
-                   surrogatediagrec(a, freq.basename, 17, 0);
-               reclist->num_records++;
-               *next = freq.last_in_set ? 0 : recno + 1;
-               dumped_records += this_length;
-               continue;
-           }
-       }
+                if (freq.errcode == YAZ_BIB1_PRESENT_REQUEST_OUT_OF_RANGE  && 
+                                freq.errstring == 0)
+                {
+                    sprintf (s, "%d", recno);
+                    freq.errstring = s;
+                }
+                if (errcode)
+                    *errcode = freq.errcode;
+                return diagrec(a, freq.errcode, freq.errstring);
+            }
+            reclist->records[reclist->num_records] =
+                surrogatediagrec(a, freq.basename, freq.errcode,
+                                 freq.errstring);
+            reclist->num_records++;
+            continue;
+        }
+        if (freq.record == 0)  /* no error and no record ? */
+        {
+            *next = 0;   /* signal end-of-set and stop */
+            break;
+        }
+        if (freq.len >= 0)
+            this_length = freq.len;
+        else
+            this_length = odr_total(a->encode) - total_length - dumped_records;
+        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)
+        {
+            /* record is small enough, really */
+            if (this_length <= a->preferredMessageSize && recno > start)
+            {
+                yaz_log(log_requestdetail, "  Dropped last normal-sized record");
+                *pres = Z_PresentStatus_partial_2;
+                break;
+            }
+            /* record can only be fetched by itself */
+            if (this_length < a->maximumRecordSize)
+            {
+                yaz_log(log_requestdetail, "  Record > prefmsgsz");
+                if (toget > 1)
+                {
+                    yaz_log(YLOG_DEBUG, "  Dropped it");
+                    reclist->records[reclist->num_records] =
+                         surrogatediagrec(a, freq.basename, 16, 0);
+                    reclist->num_records++;
+                    dumped_records += this_length;
+                    continue;
+                }
+            }
+            else /* too big entirely */
+            {
+                yaz_log(log_requestdetail, "Record > maxrcdsz this=%d max=%d",
+                        this_length, a->maximumRecordSize);
+                reclist->records[reclist->num_records] =
+                    surrogatediagrec(a, freq.basename, 17, 0);
+                reclist->num_records++;
+                dumped_records += this_length;
+                continue;
+            }
+        }
 
-       if (!(thisrec = (Z_NamePlusRecord *)
-             odr_malloc(a->encode, sizeof(*thisrec))))
-           return 0;
-       if (!(thisrec->databaseName = (char *)odr_malloc(a->encode,
-           strlen(freq.basename) + 1)))
-           return 0;
-       strcpy(thisrec->databaseName, freq.basename);
-       thisrec->which = Z_NamePlusRecord_databaseRecord;
+        if (!(thisrec = (Z_NamePlusRecord *)
+              odr_malloc(a->encode, sizeof(*thisrec))))
+            return 0;
+        if (freq.basename)
+            thisrec->databaseName = odr_strdup(a->encode, freq.basename);
+        else
+            thisrec->databaseName = 0;
+        thisrec->which = Z_NamePlusRecord_databaseRecord;
 
-       if (freq.output_format_raw)
-       {
-           struct oident *ident = oid_getentbyoid(freq.output_format_raw);
-           freq.output_format = ident->value;
-       }
-       thisrec->u.databaseRecord = z_ext_record(a->encode, freq.output_format,
-                                                freq.record, freq.len);
-       if (!thisrec->u.databaseRecord)
-           return 0;
-       reclist->records[reclist->num_records] = thisrec;
-       reclist->num_records++;
-       *next = freq.last_in_set ? 0 : recno + 1;
+        if (freq.output_format_raw)
+        {
+            struct oident *ident = oid_getentbyoid(freq.output_format_raw);
+            freq.output_format = ident->value;
+        }
+        thisrec->u.databaseRecord = z_ext_record(a->encode, freq.output_format,
+                                                 freq.record, freq.len);
+        if (!thisrec->u.databaseRecord)
+            return 0;
+        reclist->records[reclist->num_records] = thisrec;
+        reclist->num_records++;
     }
     *num = reclist->num_records;
     return records;
@@ -1634,42 +2507,64 @@ static Z_APDU *process_searchRequest(association *assoc, request *reqb,
 {
     Z_SearchRequest *req = reqb->apdu_request->u.searchRequest;
     bend_search_rr *bsrr = 
-       (bend_search_rr *)nmem_malloc (reqb->request_mem, sizeof(*bsrr));
+        (bend_search_rr *)nmem_malloc (reqb->request_mem, sizeof(*bsrr));
     
-    yaz_log(LOG_LOG, "Got SearchRequest.");
+    yaz_log(log_requestdetail, "Got SearchRequest.");
     bsrr->fd = fd;
     bsrr->request = reqb;
     bsrr->association = assoc;
     bsrr->referenceId = req->referenceId;
     save_referenceId (reqb, bsrr->referenceId);
+    bsrr->srw_sortKeys = 0;
+    bsrr->srw_setname = 0;
+    bsrr->srw_setnameIdleTime = 0;
 
-    yaz_log (LOG_LOG, "ResultSet '%s'", req->resultSetName);
+    yaz_log (log_requestdetail, "ResultSet '%s'", req->resultSetName);
     if (req->databaseNames)
     {
-       int i;
-       for (i = 0; i < req->num_databaseNames; i++)
-           yaz_log (LOG_LOG, "Database '%s'", req->databaseNames[i]);
+        int i;
+        for (i = 0; i < req->num_databaseNames; i++)
+            yaz_log (log_requestdetail, "Database '%s'", req->databaseNames[i]);
     }
-    yaz_log_zquery(req->query);
+
+    yaz_log_zquery_level(log_requestdetail,req->query);
 
     if (assoc->init->bend_search)
     {
-       bsrr->setname = req->resultSetName;
-       bsrr->replace_set = *req->replaceIndicator;
-       bsrr->num_bases = req->num_databaseNames;
-       bsrr->basenames = req->databaseNames;
-       bsrr->query = req->query;
-       bsrr->stream = assoc->encode;
-       nmem_transfer(bsrr->stream->mem, reqb->request_mem);
-       bsrr->decode = assoc->decode;
-       bsrr->print = assoc->print;
-       bsrr->errcode = 0;
-       bsrr->hits = 0;
-       bsrr->errstring = NULL;
+        bsrr->setname = req->resultSetName;
+        bsrr->replace_set = *req->replaceIndicator;
+        bsrr->num_bases = req->num_databaseNames;
+        bsrr->basenames = req->databaseNames;
+        bsrr->query = req->query;
+        bsrr->stream = assoc->encode;
+        nmem_transfer(bsrr->stream->mem, reqb->request_mem);
+        bsrr->decode = assoc->decode;
+        bsrr->print = assoc->print;
+        bsrr->hits = 0;
+        bsrr->errcode = 0;
+        bsrr->errstring = NULL;
         bsrr->search_info = NULL;
-       (assoc->init->bend_search)(assoc->backend, bsrr);
-       if (!bsrr->request)
-           return 0;
+
+        if (assoc->server && assoc->server->cql_transform 
+            && req->query->which == Z_Query_type_104
+            && req->query->u.type_104->which == Z_External_CQL)
+        {
+            /* have a CQL query and a CQL to PQF transform .. */
+            int srw_errcode = 
+                cql2pqf(bsrr->stream, req->query->u.type_104->u.cql,
+                        assoc->server->cql_transform, bsrr->query);
+            if (srw_errcode)
+                bsrr->errcode = yaz_diag_srw_to_bib1(srw_errcode);
+        }
+        if (!bsrr->errcode)
+            (assoc->init->bend_search)(assoc->backend, bsrr);
+        if (!bsrr->request)  /* backend not ready with the search response */
+            return 0;  /* should not be used any more */
+    }
+    else
+    { 
+        /* FIXME - make a diagnostic for it */
+        yaz_log(YLOG_WARN,"Search not supported ?!?!");
     }
     return response_searchRequest(assoc, reqb, bsrr, fd);
 }
@@ -1689,11 +2584,12 @@ static Z_APDU *response_searchRequest(association *assoc, request *reqb,
     Z_SearchRequest *req = reqb->apdu_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));
+        odr_malloc (assoc->encode, sizeof(*resp));
     int *nulint = odr_intdup (assoc->encode, 0);
     bool_t *sr = odr_intdup(assoc->encode, 1);
     int *next = odr_intdup(assoc->encode, 0);
-    int *none = odr_intdup(assoc->encode, Z_RES_NONE);
+    int *none = odr_intdup(assoc->encode, Z_SearchResponse_none);
+    int returnedrecs=0;
 
     apdu->which = Z_APDU_searchResponse;
     apdu->u.searchResponse = resp;
@@ -1703,81 +2599,97 @@ 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");
-       return 0;
+        yaz_log(YLOG_FATAL, "Bad result from backend");
+        return 0;
     }
     else if (bsrt->errcode)
     {
-       resp->records = diagrec(assoc, bsrt->errcode, bsrt->errstring);
-       resp->resultCount = nulint;
-       resp->numberOfRecordsReturned = nulint;
-       resp->nextResultSetPosition = nulint;
-       resp->searchStatus = nulint;
-       resp->resultSetStatus = none;
-       resp->presentStatus = 0;
+        resp->records = diagrec(assoc, bsrt->errcode, bsrt->errstring);
+        resp->resultCount = nulint;
+        resp->numberOfRecordsReturned = nulint;
+        resp->nextResultSetPosition = nulint;
+        resp->searchStatus = nulint;
+        resp->resultSetStatus = none;
+        resp->presentStatus = 0;
     }
     else
     {
-       int *toget = odr_intdup(assoc->encode, 0);
+        int *toget = odr_intdup(assoc->encode, 0);
         int *presst = odr_intdup(assoc->encode, 0);
-       Z_RecordComposition comp, *compp = 0;
+        Z_RecordComposition comp, *compp = 0;
 
-        yaz_log (LOG_LOG, "resultCount: %d", bsrt->hits);
+        yaz_log (log_requestdetail, "resultCount: %d", bsrt->hits);
 
-       resp->records = 0;
-       resp->resultCount = &bsrt->hits;
+        resp->records = 0;
+        resp->resultCount = &bsrt->hits;
 
-       comp.which = Z_RecordComp_simple;
-       /* how many records does the user agent want, then? */
-       if (bsrt->hits <= *req->smallSetUpperBound)
-       {
-           *toget = bsrt->hits;
-           if ((comp.u.simple = req->smallSetElementSetNames))
-               compp = &comp;
-       }
-       else if (bsrt->hits < *req->largeSetLowerBound)
-       {
-           *toget = *req->mediumSetPresentNumber;
-           if (*toget > bsrt->hits)
-               *toget = bsrt->hits;
-           if ((comp.u.simple = req->mediumSetElementSetNames))
-               compp = &comp;
-       }
-       else
-           *toget = 0;
+        comp.which = Z_RecordComp_simple;
+        /* how many records does the user agent want, then? */
+        if (bsrt->hits <= *req->smallSetUpperBound)
+        {
+            *toget = bsrt->hits;
+            if ((comp.u.simple = req->smallSetElementSetNames))
+                compp = &comp;
+        }
+        else if (bsrt->hits < *req->largeSetLowerBound)
+        {
+            *toget = *req->mediumSetPresentNumber;
+            if (*toget > bsrt->hits)
+                *toget = bsrt->hits;
+            if ((comp.u.simple = req->mediumSetElementSetNames))
+                compp = &comp;
+        }
+        else
+            *toget = 0;
 
-       if (*toget && !resp->records)
-       {
-           oident *prefformat;
-           oid_value form;
-
-           if (!(prefformat = oid_getentbyoid(req->preferredRecordSyntax)))
-               form = VAL_NONE;
-           else
-               form = prefformat->value;
-           resp->records = pack_records(assoc, req->resultSetName, 1,
-               toget, compp, next, presst, form, req->referenceId,
-                                        req->preferredRecordSyntax);
-           if (!resp->records)
-               return 0;
-           resp->numberOfRecordsReturned = toget;
-           resp->nextResultSetPosition = next;
-           resp->searchStatus = sr;
-           resp->resultSetStatus = 0;
-           resp->presentStatus = presst;
-       }
-       else
-       {
-           if (*resp->resultCount)
-               *next = 1;
-           resp->numberOfRecordsReturned = nulint;
-           resp->nextResultSetPosition = next;
-           resp->searchStatus = sr;
-           resp->resultSetStatus = 0;
-           resp->presentStatus = 0;
-       }
+        if (*toget && !resp->records)
+        {
+            oident *prefformat;
+            oid_value form;
+
+            if (!(prefformat = oid_getentbyoid(req->preferredRecordSyntax)))
+                form = VAL_NONE;
+            else
+                form = prefformat->value;
+            resp->records = pack_records(assoc, req->resultSetName, 1,
+                                         toget, compp, next, presst, form, req->referenceId,
+                                         req->preferredRecordSyntax, NULL);
+            if (!resp->records)
+                return 0;
+            resp->numberOfRecordsReturned = toget;
+            returnedrecs = *toget;
+            resp->nextResultSetPosition = next;
+            resp->searchStatus = sr;
+            resp->resultSetStatus = 0;
+            resp->presentStatus = presst;
+        }
+        else
+        {
+            if (*resp->resultCount)
+                *next = 1;
+            resp->numberOfRecordsReturned = nulint;
+            resp->nextResultSetPosition = next;
+            resp->searchStatus = sr;
+            resp->resultSetStatus = 0;
+            resp->presentStatus = 0;
+        }
     }
     resp->additionalSearchInfo = bsrt->search_info;
+
+    if (log_request)
+    {
+        WRBUF wr = wrbuf_alloc();
+        if (bsrt->errcode)
+            wrbuf_printf(wr, "ERROR %d", bsrt->errcode);
+        else
+            wrbuf_printf(wr, "OK %d", bsrt->hits);
+        wrbuf_printf(wr, " %s 1+%d ",
+                     req->resultSetName, returnedrecs);
+        yaz_query_to_wrbuf(wr, req->query);
+        
+        yaz_log(log_request, "Search %s", wrbuf_buf(wr));
+        wrbuf_free(wr, 1);
+    }
     return apdu;
 }
 
@@ -1797,7 +2709,7 @@ static Z_APDU *response_searchRequest(association *assoc, request *reqb,
  * speed - which is normally more true for search than for present.
  */
 static Z_APDU *process_presentRequest(association *assoc, request *reqb,
-                                     int *fd)
+                                      int *fd)
 {
     Z_PresentRequest *req = reqb->apdu_request->u.presentRequest;
     oident *prefformat;
@@ -1806,41 +2718,45 @@ static Z_APDU *process_presentRequest(association *assoc, request *reqb,
     Z_PresentResponse *resp;
     int *next;
     int *num;
+    int errcode = 0;
+    const char *errstring = 0;
 
-    yaz_log(LOG_LOG, "Got PresentRequest.");
+    yaz_log(log_requestdetail, "Got PresentRequest.");
 
     if (!(prefformat = oid_getentbyoid(req->preferredRecordSyntax)))
-       form = VAL_NONE;
+        form = VAL_NONE;
     else
-       form = prefformat->value;
+        form = prefformat->value;
     resp = (Z_PresentResponse *)odr_malloc (assoc->encode, sizeof(*resp));
     resp->records = 0;
     resp->presentStatus = odr_intdup(assoc->encode, 0);
     if (assoc->init->bend_present)
     {
-       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->print = assoc->print;
-       bprr->request = reqb;
-       bprr->association = assoc;
-       bprr->errcode = 0;
-       bprr->errstring = NULL;
-       (*assoc->init->bend_present)(assoc->backend, bprr);
-       
-       if (!bprr->request)
-           return 0;
-       if (bprr->errcode)
-       {
-           resp->records = diagrec(assoc, bprr->errcode, bprr->errstring);
-           *resp->presentStatus = Z_PRES_FAILURE;
-       }
+        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->print = assoc->print;
+        bprr->request = reqb;
+        bprr->association = assoc;
+        bprr->errcode = 0;
+        bprr->errstring = NULL;
+        (*assoc->init->bend_present)(assoc->backend, bprr);
+        
+        if (!bprr->request)
+            return 0; /* should not happen */
+        if (bprr->errcode)
+        {
+            resp->records = diagrec(assoc, bprr->errcode, bprr->errstring);
+            *resp->presentStatus = Z_PresentStatus_failure;
+            errcode = bprr->errcode;
+            errstring = bprr->errstring;
+        }
     }
     apdu = (Z_APDU *)odr_malloc (assoc->encode, sizeof(*apdu));
     next = odr_intdup(assoc->encode, 0);
@@ -1853,14 +2769,34 @@ static Z_APDU *process_presentRequest(association *assoc, request *reqb,
     
     if (!resp->records)
     {
-       *num = *req->numberOfRecordsRequested;
-       resp->records =
-           pack_records(assoc, req->resultSetId, *req->resultSetStartPoint,
-                    num, req->recordComposition, next, resp->presentStatus,
-                        form, req->referenceId, req->preferredRecordSyntax);
+        *num = *req->numberOfRecordsRequested;
+        resp->records =
+            pack_records(assoc, req->resultSetId, *req->resultSetStartPoint,
+                         num, req->recordComposition, next,
+                         resp->presentStatus,
+                         form, req->referenceId, req->preferredRecordSyntax, 
+                         &errcode);
+    }
+    if (log_request)
+    {
+        WRBUF wr = wrbuf_alloc();
+        wrbuf_printf(wr, "Present ");
+
+        if (*resp->presentStatus == Z_PresentStatus_failure)
+            wrbuf_printf(wr, "ERROR %d", errcode);
+        else if (*resp->presentStatus == Z_PresentStatus_success)
+            wrbuf_printf(wr, "OK -");
+        else
+            wrbuf_printf(wr, "Partial %d", *resp->presentStatus);
+
+        wrbuf_printf(wr, " %s %d+%d ",
+                req->resultSetId, *req->resultSetStartPoint,
+                *req->numberOfRecordsRequested);
+        yaz_log(log_request, "%s", wrbuf_buf(wr) );
+        wrbuf_free(wr, 1);
     }
     if (!resp->records)
-       return 0;
+        return 0;
     resp->numberOfRecordsReturned = num;
     resp->nextResultSetPosition = next;
     
@@ -1876,18 +2812,18 @@ static Z_APDU *process_scanRequest(association *assoc, request *reqb, int *fd)
     Z_ScanRequest *req = reqb->apdu_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));
+        odr_malloc (assoc->encode, sizeof(*res));
     int *scanStatus = odr_intdup(assoc->encode, Z_Scan_failure);
     int *numberOfEntriesReturned = odr_intdup(assoc->encode, 0);
     Z_ListEntries *ents = (Z_ListEntries *)
-       odr_malloc (assoc->encode, sizeof(*ents));
+        odr_malloc (assoc->encode, sizeof(*ents));
     Z_DiagRecs *diagrecs_p = NULL;
     oident *attset;
     bend_scan_rr *bsrr = (bend_scan_rr *)
         odr_malloc (assoc->encode, sizeof(*bsrr));
     struct scan_entry *save_entries;
 
-    yaz_log(LOG_LOG, "Got ScanRequest");
+    yaz_log(log_requestdetail, "Got ScanRequest");
 
     apdu->which = Z_APDU_scanResponse;
     apdu->u.scanResponse = res;
@@ -1896,7 +2832,7 @@ static Z_APDU *process_scanRequest(association *assoc, request *reqb, int *fd)
     /* if step is absent, set it to 0 */
     res->stepSize = odr_intdup(assoc->encode, 0);
     if (req->stepSize)
-       *res->stepSize = *req->stepSize;
+        *res->stepSize = *req->stepSize;
 
     res->scanStatus = scanStatus;
     res->numberOfEntriesReturned = numberOfEntriesReturned;
@@ -1913,8 +2849,11 @@ static Z_APDU *process_scanRequest(association *assoc, request *reqb, int *fd)
     {
         int i;
         for (i = 0; i < req->num_databaseNames; i++)
-            yaz_log (LOG_LOG, "Database '%s'", req->databaseNames[i]);
+            yaz_log (log_requestdetail, "Database '%s'", req->databaseNames[i]);
     }
+    bsrr->scanClause = 0;
+    bsrr->errcode = 0;
+    bsrr->errstring = 0;
     bsrr->num_bases = req->num_databaseNames;
     bsrr->basenames = req->databaseNames;
     bsrr->num_entries = *req->numberOfTermsRequested;
@@ -1924,10 +2863,12 @@ static Z_APDU *process_scanRequest(association *assoc, request *reqb, int *fd)
     bsrr->print = assoc->print;
     bsrr->step_size = res->stepSize;
     bsrr->entries = 0;
-    /* Note that version 2.0 of YAZ and older did not set entries .. 
-       We do now. And when we do it's easier to extend the scan entry 
-       We know that if the scan handler did set entries, it will
-       not know of new member display_term.
+    /* For YAZ 2.0 and earlier it was the backend handler that
+       initialized entries (member display_term did not exist)
+       YAZ 2.0 and later sets 'entries'  and initialize all members
+       including 'display_term'. If YAZ 2.0 or later sees that
+       entries was modified - we assume that it is an old handler and
+       that 'display_term' is _not_ set.
     */
     if (bsrr->num_entries > 0) 
     {
@@ -1951,13 +2892,17 @@ static Z_APDU *process_scanRequest(association *assoc, request *reqb, int *fd)
         bsrr->attributeset = attset->value;
     else
         bsrr->attributeset = VAL_NONE;
-    log_scan_term (req->termListAndStartPoint, bsrr->attributeset);
+    log_scan_term_level (log_requestdetail, req->termListAndStartPoint, 
+            bsrr->attributeset);
     bsrr->term_position = req->preferredPositionInResponse ?
         *req->preferredPositionInResponse : 1;
+
     ((int (*)(void *, bend_scan_rr *))
      (*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;
@@ -1970,7 +2915,7 @@ static Z_APDU *process_scanRequest(association *assoc, request *reqb, int *fd)
             *scanStatus = Z_Scan_success;
         ents->entries = tab;
         ents->num_entries = bsrr->num_entries;
-        res->numberOfEntriesReturned = &ents->num_entries;         
+        res->numberOfEntriesReturned = &ents->num_entries;          
         res->positionOfTerm = &bsrr->term_position;
         for (i = 0; i < bsrr->num_entries; i++)
         {
@@ -1989,7 +2934,7 @@ static Z_APDU *process_scanRequest(association *assoc, request *reqb, int *fd)
                 if (save_entries == bsrr->entries && 
                     bsrr->entries[i].display_term)
                 {
-                    /* the entries was NOT set by the handler. So it's
+                    /* the entries was _not_ set by the handler. So it's
                        safe to test for new member display_term. It is
                        NULL'ed by us.
                     */
@@ -2009,14 +2954,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,
-                        bsrr->entries[i].term, bsrr->entries[i].occurrences);
+                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]);
@@ -2026,8 +2971,28 @@ static Z_APDU *process_scanRequest(association *assoc, request *reqb, int *fd)
     }
     if (diagrecs_p)
     {
-       ents->num_nonsurrogateDiagnostics = diagrecs_p->num_diagRecs;
-       ents->nonsurrogateDiagnostics = diagrecs_p->diagRecs;
+        ents->num_nonsurrogateDiagnostics = diagrecs_p->num_diagRecs;
+        ents->nonsurrogateDiagnostics = diagrecs_p->diagRecs;
+    }
+    if (log_request)
+    {
+        WRBUF wr = wrbuf_alloc();
+        if (bsrr->errcode)
+            wr_diag(wr, bsrr->errcode, bsrr->errstring);
+        else if (*res->scanStatus == Z_Scan_success)
+            wrbuf_printf(wr, "OK");
+        else
+            wrbuf_printf(wr, "Partial");
+
+        wrbuf_printf(wr, " %d+%d %d ",
+                     (req->preferredPositionInResponse ?
+                      *req->preferredPositionInResponse : 1),
+                     *req->numberOfTermsRequested,
+                     (res->stepSize ? *res->stepSize : 0));
+        yaz_scan_to_wrbuf(wr, req->termListAndStartPoint, 
+                          bsrr->attributeset);
+        yaz_log(log_request, "Scan %s", wrbuf_buf(wr) );
+        wrbuf_free(wr, 1);
     }
     return apdu;
 }
@@ -2035,25 +3000,32 @@ static Z_APDU *process_scanRequest(association *assoc, request *reqb, int *fd)
 static Z_APDU *process_sortRequest(association *assoc, request *reqb,
     int *fd)
 {
+    int i;
     Z_SortRequest *req = reqb->apdu_request->u.sortRequest;
     Z_SortResponse *res = (Z_SortResponse *)
-       odr_malloc (assoc->encode, sizeof(*res));
+        odr_malloc (assoc->encode, sizeof(*res));
     bend_sort_rr *bsrr = (bend_sort_rr *)
-       odr_malloc (assoc->encode, sizeof(*bsrr));
+        odr_malloc (assoc->encode, sizeof(*bsrr));
 
     Z_APDU *apdu = (Z_APDU *)odr_malloc (assoc->encode, sizeof(*apdu));
 
-    yaz_log(LOG_LOG, "Got SortRequest.");
+    yaz_log(log_requestdetail, "Got SortRequest.");
 
     bsrr->num_input_setnames = req->num_inputResultSetNames;
+    for (i=0;i<req->num_inputResultSetNames;i++)
+        yaz_log(log_requestdetail, "Input resultset: '%s'",
+                req->inputResultSetNames[i]);
     bsrr->input_setnames = req->inputResultSetNames;
     bsrr->referenceId = req->referenceId;
     bsrr->output_setname = req->sortedResultSetName;
+    yaz_log(log_requestdetail, "Output resultset: '%s'",
+                req->sortedResultSetName);
     bsrr->sort_sequence = req->sortSequence;
+       /*FIXME - dump those sequences too */
     bsrr->stream = assoc->encode;
     bsrr->print = assoc->print;
 
-    bsrr->sort_status = Z_SortStatus_failure;
+    bsrr->sort_status = Z_SortResponse_failure;
     bsrr->errcode = 0;
     bsrr->errstring = 0;
     
@@ -2064,38 +3036,63 @@ static Z_APDU *process_sortRequest(association *assoc, request *reqb,
     res->resultSetStatus = 0;
     if (bsrr->errcode)
     {
-       Z_DiagRecs *dr = diagrecs (assoc, bsrr->errcode, bsrr->errstring);
-       res->diagnostics = dr->diagRecs;
-       res->num_diagnostics = dr->num_diagRecs;
+        Z_DiagRecs *dr = zget_DiagRecs(assoc->encode,
+                                       bsrr->errcode, bsrr->errstring);
+        res->diagnostics = dr->diagRecs;
+        res->num_diagnostics = dr->num_diagRecs;
     }
     else
     {
-       res->num_diagnostics = 0;
-       res->diagnostics = 0;
+        res->num_diagnostics = 0;
+        res->diagnostics = 0;
     }
     res->resultCount = 0;
     res->otherInfo = 0;
 
     apdu->which = Z_APDU_sortResponse;
     apdu->u.sortResponse = res;
+    if (log_request)
+    {
+        WRBUF wr = wrbuf_alloc();
+        wrbuf_printf(wr, "Sort ");
+        if (bsrr->errcode)
+            wrbuf_printf(wr, " ERROR %d", bsrr->errcode);
+        else
+            wrbuf_printf(wr,  "OK -");
+        wrbuf_printf(wr, " (");
+        for (i = 0; i<req->num_inputResultSetNames; i++)
+        {
+            if (i)
+                wrbuf_printf(wr, ",");
+            wrbuf_printf(wr, req->inputResultSetNames[i]);
+        }
+        wrbuf_printf(wr, ")->%s ",req->sortedResultSetName);
+
+        yaz_log(log_request, "%s", wrbuf_buf(wr) );
+        wrbuf_free(wr, 1);
+    }
     return apdu;
 }
 
 static Z_APDU *process_deleteRequest(association *assoc, request *reqb,
     int *fd)
 {
+    int i;
     Z_DeleteResultSetRequest *req =
         reqb->apdu_request->u.deleteResultSetRequest;
     Z_DeleteResultSetResponse *res = (Z_DeleteResultSetResponse *)
-       odr_malloc (assoc->encode, sizeof(*res));
+        odr_malloc (assoc->encode, sizeof(*res));
     bend_delete_rr *bdrr = (bend_delete_rr *)
-       odr_malloc (assoc->encode, sizeof(*bdrr));
+        odr_malloc (assoc->encode, sizeof(*bdrr));
     Z_APDU *apdu = (Z_APDU *)odr_malloc (assoc->encode, sizeof(*apdu));
 
-    yaz_log(LOG_LOG, "Got DeleteRequest.");
+    yaz_log(log_requestdetail, "Got DeleteRequest.");
 
     bdrr->num_setnames = req->num_resultSetList;
     bdrr->setnames = req->resultSetList;
+    for (i = 0; i<req->num_resultSetList; i++)
+        yaz_log(log_requestdetail, "resultset: '%s'",
+                req->resultSetList[i]);
     bdrr->stream = assoc->encode;
     bdrr->print = assoc->print;
     bdrr->function = *req->deleteFunction;
@@ -2103,12 +3100,11 @@ static Z_APDU *process_deleteRequest(association *assoc, request *reqb,
     bdrr->statuses = 0;
     if (bdrr->num_setnames > 0)
     {
-       int i;
-       bdrr->statuses = (int*) 
-           odr_malloc(assoc->encode, sizeof(*bdrr->statuses) *
-                      bdrr->num_setnames);
-       for (i = 0; i < bdrr->num_setnames; i++)
-           bdrr->statuses[i] = 0;
+        bdrr->statuses = (int*) 
+            odr_malloc(assoc->encode, sizeof(*bdrr->statuses) *
+                       bdrr->num_setnames);
+        for (i = 0; i < bdrr->num_setnames; i++)
+            bdrr->statuses[i] = 0;
     }
     (*assoc->init->bend_delete)(assoc->backend, bdrr);
     
@@ -2119,26 +3115,25 @@ static Z_APDU *process_deleteRequest(association *assoc, request *reqb,
     res->deleteListStatuses = 0;
     if (bdrr->num_setnames > 0)
     {
-       int i;
-       res->deleteListStatuses = (Z_ListStatuses *)
-           odr_malloc(assoc->encode, sizeof(*res->deleteListStatuses));
-       res->deleteListStatuses->num = bdrr->num_setnames;
-       res->deleteListStatuses->elements =
-           (Z_ListStatus **)
-           odr_malloc (assoc->encode, 
-                       sizeof(*res->deleteListStatuses->elements) *
-                       bdrr->num_setnames);
-       for (i = 0; i<bdrr->num_setnames; i++)
-       {
-           res->deleteListStatuses->elements[i] =
-               (Z_ListStatus *)
-               odr_malloc (assoc->encode,
-                           sizeof(**res->deleteListStatuses->elements));
-           res->deleteListStatuses->elements[i]->status = bdrr->statuses+i;
-           res->deleteListStatuses->elements[i]->id =
-               odr_strdup (assoc->encode, bdrr->setnames[i]);
-           
-       }
+        int i;
+        res->deleteListStatuses = (Z_ListStatuses *)
+            odr_malloc(assoc->encode, sizeof(*res->deleteListStatuses));
+        res->deleteListStatuses->num = bdrr->num_setnames;
+        res->deleteListStatuses->elements =
+            (Z_ListStatus **)
+            odr_malloc (assoc->encode, 
+                        sizeof(*res->deleteListStatuses->elements) *
+                        bdrr->num_setnames);
+        for (i = 0; i<bdrr->num_setnames; i++)
+        {
+            res->deleteListStatuses->elements[i] =
+                (Z_ListStatus *)
+                odr_malloc (assoc->encode,
+                            sizeof(**res->deleteListStatuses->elements));
+            res->deleteListStatuses->elements[i]->status = bdrr->statuses+i;
+            res->deleteListStatuses->elements[i]->id =
+                odr_strdup (assoc->encode, bdrr->setnames[i]);
+        }
     }
     res->numberNotDeleted = 0;
     res->bulkStatuses = 0;
@@ -2147,6 +3142,19 @@ static Z_APDU *process_deleteRequest(association *assoc, request *reqb,
 
     apdu->which = Z_APDU_deleteResultSetResponse;
     apdu->u.deleteResultSetResponse = res;
+    if (log_request)
+    {
+        WRBUF wr = wrbuf_alloc();
+        wrbuf_printf(wr, "Delete ");
+        if (bdrr->delete_status)
+            wrbuf_printf(wr, "ERROR %d", bdrr->delete_status);
+        else
+            wrbuf_printf(wr, "OK -");
+        for (i = 0; i<req->num_resultSetList; i++)
+            wrbuf_printf(wr, " %s ", req->resultSetList[i]);
+        yaz_log(log_request, "%s", wrbuf_buf(wr) );
+        wrbuf_free(wr, 1);
+    }
     return apdu;
 }
 
@@ -2155,39 +3163,40 @@ static void process_close(association *assoc, request *reqb)
     Z_Close *req = reqb->apdu_request->u.close;
     static char *reasons[] =
     {
-       "finished",
-       "shutdown",
-       "systemProblem",
-       "costLimit",
-       "resources",
-       "securityViolation",
-       "protocolError",
-       "lackOfActivity",
-       "peerAbort",
-       "unspecified"
+        "finished",
+        "shutdown",
+        "systemProblem",
+        "costLimit",
+        "resources",
+        "securityViolation",
+        "protocolError",
+        "lackOfActivity",
+        "peerAbort",
+        "unspecified"
     };
 
-    yaz_log(LOG_LOG, "Got Close, reason %s, message %s",
-       reasons[*req->closeReason], req->diagnosticInformation ?
-       req->diagnosticInformation : "NULL");
+    yaz_log(log_requestdetail, "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;
+        assoc->version = 3;
     do_close_req(assoc, Z_Close_finished,
-                "Association terminated by client", reqb);
+                 "Association terminated by client", reqb);
+    yaz_log(log_request,"Close OK");
 }
 
 void save_referenceId (request *reqb, Z_ReferenceId *refid)
 {
     if (refid)
     {
-       reqb->len_refid = refid->len;
-       reqb->refid = (char *)nmem_malloc (reqb->request_mem, refid->len);
-       memcpy (reqb->refid, refid->buf, refid->len);
+        reqb->len_refid = refid->len;
+        reqb->refid = (char *)nmem_malloc (reqb->request_mem, refid->len);
+        memcpy (reqb->refid, refid->buf, refid->len);
     }
     else
     {
-       reqb->len_refid = 0;
-       reqb->refid = NULL;
+        reqb->len_refid = 0;
+        reqb->refid = NULL;
     }
 }
 
@@ -2207,7 +3216,7 @@ Z_ReferenceId *bend_request_getid (ODR odr, bend_request req)
 {
     Z_ReferenceId *id;
     if (!req->refid)
-       return 0;
+        return 0;
     id = (Odr_oct *)odr_malloc (odr, sizeof(*odr));
     id->buf = (unsigned char *)odr_malloc (odr, req->len_refid);
     id->len = id->size = req->len_refid;
@@ -2228,7 +3237,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;
 }
 
@@ -2260,6 +3269,7 @@ static Z_APDU *process_segmentRequest (association *assoc, request *reqb)
 static Z_APDU *process_ESRequest(association *assoc, request *reqb, int *fd)
 {
     bend_esrequest_rr esrequest;
+    const char *ext_name = "unknown";
 
     Z_ExtendedServicesRequest *req =
         reqb->apdu_request->u.extendedServicesRequest;
@@ -2267,8 +3277,6 @@ static Z_APDU *process_ESRequest(association *assoc, request *reqb, int *fd)
 
     Z_ExtendedServicesResponse *resp = apdu->u.extendedServicesResponse;
 
-    yaz_log(LOG_DEBUG,"inside Process esRequest");
-
     esrequest.esr = reqb->apdu_request->u.extendedServicesRequest;
     esrequest.stream = assoc->encode;
     esrequest.decode = assoc->decode;
@@ -2279,7 +3287,24 @@ static Z_APDU *process_ESRequest(association *assoc, request *reqb, int *fd)
     esrequest.association = assoc;
     esrequest.taskPackage = 0;
     esrequest.referenceId = req->referenceId;
+
     
+    if (esrequest.esr && esrequest.esr->taskSpecificParameters)
+    {
+        switch(esrequest.esr->taskSpecificParameters->which)
+        {
+        case Z_External_itemOrder:
+            ext_name = "ItemOrder"; break;
+        case Z_External_update:
+            ext_name = "Update"; break;
+        case Z_External_update0:
+            ext_name = "Update0"; break;
+        case Z_External_ESAdmin:
+            ext_name = "Admin"; break;
+
+        }
+    }
+
     (*assoc->init->bend_esrequest)(assoc->backend, &esrequest);
     
     /* If the response is being delayed, return NULL */
@@ -2291,32 +3316,48 @@ static Z_APDU *process_ESRequest(association *assoc, request *reqb, int *fd)
     if (esrequest.errcode == -1)
     {
         /* Backend service indicates request will be processed */
-        yaz_log(LOG_DEBUG,"Request could be processed...Accepted !");
+        yaz_log(log_request, "Extended Service: %s (accepted)", ext_name);
         *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 !");
+        yaz_log(log_request, "Extended Service: %s (done)", ext_name);
         *resp->operationStatus = Z_ExtendedServicesResponse_done;
     }
     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(log_request, "Extended Service: %s (failed)", ext_name);
         *resp->operationStatus = Z_ExtendedServicesResponse_failure;
-       resp->num_diagnostics = diagRecs->num_diagRecs;
-       resp->diagnostics = diagRecs->diagRecs;
+        resp->num_diagnostics = diagRecs->num_diagRecs;
+        resp->diagnostics = diagRecs->diagRecs;
+        if (log_request)
+        {
+            WRBUF wr = wrbuf_alloc();
+            wrbuf_diags(wr, resp->num_diagnostics, resp->diagnostics);
+            yaz_log(log_request, "EsRequest %s", wrbuf_buf(wr) );
+            wrbuf_free(wr, 1);
+        }
+
     }
     /* Do something with the members of bend_extendedservice */
     if (esrequest.taskPackage)
-       resp->taskPackage = z_ext_record (assoc->encode, VAL_EXTENDED,
-                                        (const char *)  esrequest.taskPackage,
-                                         -1);
-    yaz_log(LOG_DEBUG,"Send the result apdu");
+        resp->taskPackage = z_ext_record (assoc->encode, VAL_EXTENDED,
+                                         (const char *)  esrequest.taskPackage,
+                                          -1);
+    yaz_log(YLOG_DEBUG,"Send the result apdu");
     return apdu;
 }
 
+/*
+ * Local variables:
+ * c-basic-offset: 4
+ * indent-tabs-mode: nil
+ * End:
+ * vim: shiftwidth=4 tabstop=8 expandtab
+ */
+