Remove extra space in request log output
[yaz-moved-to-github.git] / src / seshigh.c
1 /*
2  * Copyright (c) 1995-2004, Index Data
3  * See the file LICENSE for details.
4  *
5  * $Id: seshigh.c,v 1.41 2004-12-22 23:48:34 adam Exp $
6  */
7 /**
8  * \file seshigh.c
9  * \brief Implements GFS session logic.
10  *
11  * Frontend server logic.
12  *
13  * This code receives incoming APDUs, and handles client requests by means
14  * of the backend API.
15  *
16  * Some of the code is getting quite involved, compared to simpler servers -
17  * primarily because it is asynchronous both in the communication with
18  * the user and the backend. We think the complexity will pay off in
19  * the form of greater flexibility when more asynchronous facilities
20  * are implemented.
21  *
22  * Memory management has become somewhat involved. In the simple case, where
23  * only one PDU is pending at a time, it will simply reuse the same memory,
24  * once it has found its working size. When we enable multiple concurrent
25  * operations, perhaps even with multiple parallel calls to the backend, it
26  * will maintain a pool of buffers for encoding and decoding, trying to
27  * minimize memory allocation/deallocation during normal operation.
28  *
29  */
30
31 #include <stdlib.h>
32 #include <stdio.h>
33 #include <sys/types.h>
34 #ifdef WIN32
35 #include <io.h>
36 #define S_ISREG(x) (x & _S_IFREG)
37 #include <process.h>
38 #include <sys/stat.h>
39 #else
40 #include <sys/stat.h>
41 #include <unistd.h>
42 #endif
43 #include <assert.h>
44 #include <ctype.h>
45
46 #include <yaz/yconfig.h>
47 #include <yaz/xmalloc.h>
48 #include <yaz/comstack.h>
49 #include "eventl.h"
50 #include "session.h"
51 #include <yaz/proto.h>
52 #include <yaz/oid.h>
53 #include <yaz/log.h>
54 #include <yaz/logrpn.h>
55 #include <yaz/statserv.h>
56 #include <yaz/diagbib1.h>
57 #include <yaz/charneg.h>
58 #include <yaz/otherinfo.h>
59 #include <yaz/yaz-util.h>
60 #include <yaz/pquery.h>
61
62 #include <yaz/srw.h>
63 #include <yaz/backend.h>
64
65 static void process_gdu_request(association *assoc, request *req);
66 static int process_z_request(association *assoc, request *req, char **msg);
67 void backend_response(IOCHAN i, int event);
68 static int process_gdu_response(association *assoc, request *req, Z_GDU *res);
69 static int process_z_response(association *assoc, request *req, Z_APDU *res);
70 static Z_APDU *process_initRequest(association *assoc, request *reqb);
71 static Z_External *init_diagnostics(ODR odr, int errcode,
72                                     const char *errstring);
73 static Z_APDU *process_searchRequest(association *assoc, request *reqb,
74     int *fd);
75 static Z_APDU *response_searchRequest(association *assoc, request *reqb,
76     bend_search_rr *bsrr, int *fd);
77 static Z_APDU *process_presentRequest(association *assoc, request *reqb,
78     int *fd);
79 static Z_APDU *process_scanRequest(association *assoc, request *reqb, int *fd);
80 static Z_APDU *process_sortRequest(association *assoc, request *reqb, int *fd);
81 static void process_close(association *assoc, request *reqb);
82 void save_referenceId (request *reqb, Z_ReferenceId *refid);
83 static Z_APDU *process_deleteRequest(association *assoc, request *reqb,
84     int *fd);
85 static Z_APDU *process_segmentRequest (association *assoc, request *reqb);
86
87 static FILE *apduf = 0; /* for use in static mode */
88 static statserv_options_block *control_block = 0;
89
90 static Z_APDU *process_ESRequest(association *assoc, request *reqb, int *fd);
91
92 /* dynamic logging levels */
93 static int logbits_set=0;
94 static int log_session=0; 
95 static int log_request=0; /* one-line logs for requests */
96 static int log_requestdetail=0;  /* more detailed stuff */
97
98 /** get_logbits sets global loglevel bits */
99 static void get_logbits()
100 { /* needs to be called after parsing cmd-line args that can set loglevels!*/
101     if (!logbits_set)
102     {
103         logbits_set=1;
104         log_session=yaz_log_module_level("session"); 
105         log_request=yaz_log_module_level("request"); 
106         log_requestdetail=yaz_log_module_level("requestdetail"); 
107     }
108 }
109
110 static void wr_diag(WRBUF w, int error, const char *addinfo)
111 {
112     wrbuf_printf(w, "ERROR [%d] %s%s%s",
113                  error, diagbib1_str(error),
114                  addinfo ? "--" : "", addinfo ? addinfo : "");
115 }
116
117
118 /*
119  * Create and initialize a new association-handle.
120  *  channel  : iochannel for the current line.
121  *  link     : communications channel.
122  * Returns: 0 or a new association handle.
123  */
124 association *create_association(IOCHAN channel, COMSTACK link)
125 {
126     association *anew;
127
128     if (!logbits_set)
129         get_logbits();
130     if (!control_block)
131         control_block = statserv_getcontrol();
132     if (!(anew = (association *)xmalloc(sizeof(*anew))))
133         return 0;
134     anew->init = 0;
135     anew->version = 0;
136     anew->client_chan = channel;
137     anew->client_link = link;
138     anew->cs_get_mask = 0;
139     anew->cs_put_mask = 0;
140     anew->cs_accept_mask = 0;
141     if (!(anew->decode = odr_createmem(ODR_DECODE)) ||
142         !(anew->encode = odr_createmem(ODR_ENCODE)))
143         return 0;
144     if (*control_block->apdufile)
145     {
146         char filename[256];
147         FILE *f;
148
149         strcpy(filename, control_block->apdufile);
150         if (!(anew->print = odr_createmem(ODR_PRINT)))
151             return 0;
152         if (*control_block->apdufile == '@')
153         {
154             odr_setprint(anew->print, yaz_log_file());
155         }       
156         else if (*control_block->apdufile != '-')
157         {
158             strcpy(filename, control_block->apdufile);
159             if (!control_block->dynamic)
160             {
161                 if (!apduf)
162                 {
163                     if (!(apduf = fopen(filename, "w")))
164                     {
165                         yaz_log(YLOG_WARN|YLOG_ERRNO, "can't open apdu dump %s", filename);
166                         return 0;
167                     }
168                     setvbuf(apduf, 0, _IONBF, 0);
169                 }
170                 f = apduf;
171             }
172             else 
173             {
174                 sprintf(filename + strlen(filename), ".%d", getpid());
175                 if (!(f = fopen(filename, "w")))
176                 {
177                     yaz_log(YLOG_WARN|YLOG_ERRNO, "%s", filename);
178                     return 0;
179                 }
180                 setvbuf(f, 0, _IONBF, 0);
181             }
182             odr_setprint(anew->print, f);
183         }
184     }
185     else
186         anew->print = 0;
187     anew->input_buffer = 0;
188     anew->input_buffer_len = 0;
189     anew->backend = 0;
190     anew->state = ASSOC_NEW;
191     request_initq(&anew->incoming);
192     request_initq(&anew->outgoing);
193     anew->proto = cs_getproto(link);
194     return anew;
195 }
196
197 /*
198  * Free association and release resources.
199  */
200 void destroy_association(association *h)
201 {
202     statserv_options_block *cb = statserv_getcontrol();
203     request *req;
204
205     xfree(h->init);
206     odr_destroy(h->decode);
207     odr_destroy(h->encode);
208     if (h->print)
209         odr_destroy(h->print);
210     if (h->input_buffer)
211     xfree(h->input_buffer);
212     if (h->backend)
213         (*cb->bend_close)(h->backend);
214     while ((req = request_deq(&h->incoming)))
215         request_release(req);
216     while ((req = request_deq(&h->outgoing)))
217         request_release(req);
218     request_delq(&h->incoming);
219     request_delq(&h->outgoing);
220     xfree(h);
221     xmalloc_trav("session closed");
222     if (control_block && control_block->one_shot)
223     {
224         exit (0);
225     }
226 }
227
228 static void do_close_req(association *a, int reason, char *message,
229                          request *req)
230 {
231     Z_APDU apdu;
232     Z_Close *cls = zget_Close(a->encode);
233     
234     /* Purge request queue */
235     while (request_deq(&a->incoming));
236     while (request_deq(&a->outgoing));
237     if (a->version >= 3)
238     {
239         yaz_log(log_requestdetail, "Sending Close PDU, reason=%d, message=%s",
240             reason, message ? message : "none");
241         apdu.which = Z_APDU_close;
242         apdu.u.close = cls;
243         *cls->closeReason = reason;
244         cls->diagnosticInformation = message;
245         process_z_response(a, req, &apdu);
246         iochan_settimeout(a->client_chan, 20);
247     }
248     else
249     {
250         request_release(req);
251         yaz_log(log_requestdetail, "v2 client. No Close PDU");
252         iochan_setevent(a->client_chan, EVENT_TIMEOUT); /* force imm close */
253     }
254     a->state = ASSOC_DEAD;
255 }
256
257 static void do_close(association *a, int reason, char *message)
258 {
259     request *req = request_get(&a->outgoing);
260     do_close_req (a, reason, message, req);
261 }
262
263 /*
264  * This is where PDUs from the client are read and the further
265  * processing is initiated. Flow of control moves down through the
266  * various process_* functions below, until the encoded result comes back up
267  * to the output handler in here.
268  * 
269  *  h     : the I/O channel that has an outstanding event.
270  *  event : the current outstanding event.
271  */
272 void ir_session(IOCHAN h, int event)
273 {
274     int res;
275     association *assoc = (association *)iochan_getdata(h);
276     COMSTACK conn = assoc->client_link;
277     request *req;
278
279     assert(h && conn && assoc);
280     if (event == EVENT_TIMEOUT)
281     {
282         if (assoc->state != ASSOC_UP)
283         {
284             yaz_log(YLOG_DEBUG, "Final timeout - closing connection.");
285             /* do we need to lod this at all */
286             cs_close(conn);
287             destroy_association(assoc);
288             iochan_destroy(h);
289         }
290         else
291         {
292             yaz_log(log_session, "Session idle too long. Sending close.");
293             do_close(assoc, Z_Close_lackOfActivity, 0);
294         }
295         return;
296     }
297     if (event & assoc->cs_accept_mask)
298     {
299         if (!cs_accept (conn))
300         {
301             yaz_log (YLOG_WARN, "accept failed");
302             destroy_association(assoc);
303             iochan_destroy(h);
304         }
305         iochan_clearflag (h, EVENT_OUTPUT);
306         if (conn->io_pending) 
307         {   /* cs_accept didn't complete */
308             assoc->cs_accept_mask = 
309                 ((conn->io_pending & CS_WANT_WRITE) ? EVENT_OUTPUT : 0) |
310                 ((conn->io_pending & CS_WANT_READ) ? EVENT_INPUT : 0);
311
312             iochan_setflag (h, assoc->cs_accept_mask);
313         }
314         else
315         {   /* cs_accept completed. Prepare for reading (cs_get) */
316             assoc->cs_accept_mask = 0;
317             assoc->cs_get_mask = EVENT_INPUT;
318             iochan_setflag (h, assoc->cs_get_mask);
319         }
320         return;
321     }
322     if ((event & assoc->cs_get_mask) || (event & EVENT_WORK)) /* input */
323     {
324         if ((assoc->cs_put_mask & EVENT_INPUT) == 0 && (event & assoc->cs_get_mask))
325         {
326             yaz_log(YLOG_DEBUG, "ir_session (input)");
327             /* We aren't speaking to this fellow */
328             if (assoc->state == ASSOC_DEAD)
329             {
330                 yaz_log(log_session, "Connection closed - end of session");
331                 cs_close(conn);
332                 destroy_association(assoc);
333                 iochan_destroy(h);
334                 return;
335             }
336             assoc->cs_get_mask = EVENT_INPUT;
337             if ((res = cs_get(conn, &assoc->input_buffer,
338                 &assoc->input_buffer_len)) <= 0)
339             {
340                 yaz_log(log_session, "Connection closed by client");
341                 cs_close(conn);
342                 destroy_association(assoc);
343                 iochan_destroy(h);
344                 return;
345             }
346             else if (res == 1) /* incomplete read - wait for more  */
347             {
348                 if (conn->io_pending & CS_WANT_WRITE)
349                     assoc->cs_get_mask |= EVENT_OUTPUT;
350                 iochan_setflag(h, assoc->cs_get_mask);
351                 return;
352             }
353             if (cs_more(conn)) /* more stuff - call us again later, please */
354                 iochan_setevent(h, EVENT_INPUT);
355                 
356             /* we got a complete PDU. Let's decode it */
357             yaz_log(YLOG_DEBUG, "Got PDU, %d bytes: lead=%02X %02X %02X", res,
358                             assoc->input_buffer[0] & 0xff,
359                             assoc->input_buffer[1] & 0xff,
360                             assoc->input_buffer[2] & 0xff);
361             req = request_get(&assoc->incoming); /* get a new request */
362             odr_reset(assoc->decode);
363             odr_setbuf(assoc->decode, assoc->input_buffer, res, 0);
364             if (!z_GDU(assoc->decode, &req->gdu_request, 0, 0))
365             {
366                 yaz_log(YLOG_WARN, "ODR error on incoming PDU: %s [element %s] "
367                         "[near byte %d] ",
368                         odr_errmsg(odr_geterror(assoc->decode)),
369                         odr_getelement(assoc->decode),
370                         odr_offset(assoc->decode));
371                 if (assoc->decode->error != OHTTP)
372                 {
373                     yaz_log(YLOG_WARN, "PDU dump:");
374                     odr_dumpBER(yaz_log_file(), assoc->input_buffer, res);
375                     request_release(req);
376                     do_close(assoc, Z_Close_protocolError,"Malformed package");
377                 }
378                 else
379                 {
380                     Z_GDU *p = z_get_HTTP_Response(assoc->encode, 400);
381                     assoc->state = ASSOC_DEAD;
382                     process_gdu_response(assoc, req, p);
383                 }
384                 return;
385             }
386             req->request_mem = odr_extract_mem(assoc->decode);
387             if (assoc->print) 
388             {
389                 if (!z_GDU(assoc->print, &req->gdu_request, 0, 0))
390                     yaz_log(YLOG_WARN, "ODR print error: %s", 
391                        odr_errmsg(odr_geterror(assoc->print)));
392                 odr_reset(assoc->print);
393             }
394             request_enq(&assoc->incoming, req);
395         }
396
397         /* can we do something yet? */
398         req = request_head(&assoc->incoming);
399         if (req->state == REQUEST_IDLE)
400         {
401             request_deq(&assoc->incoming);
402             process_gdu_request(assoc, req);
403         }
404     }
405     if (event & assoc->cs_put_mask)
406     {
407         request *req = request_head(&assoc->outgoing);
408
409         assoc->cs_put_mask = 0;
410         yaz_log(YLOG_DEBUG, "ir_session (output)");
411         req->state = REQUEST_PENDING;
412         switch (res = cs_put(conn, req->response, req->len_response))
413         {
414         case -1:
415             yaz_log(log_session, "Connection closed by client");
416             cs_close(conn);
417             destroy_association(assoc);
418             iochan_destroy(h);
419             break;
420         case 0: /* all sent - release the request structure */
421             yaz_log(YLOG_DEBUG, "Wrote PDU, %d bytes", req->len_response);
422 #if 0
423             yaz_log(YLOG_DEBUG, "HTTP out:\n%.*s", req->len_response,
424                     req->response);
425 #endif
426             nmem_destroy(req->request_mem);
427             request_deq(&assoc->outgoing);
428             request_release(req);
429             if (!request_head(&assoc->outgoing))
430             {   /* restore mask for cs_get operation ... */
431                 iochan_clearflag(h, EVENT_OUTPUT|EVENT_INPUT);
432                 iochan_setflag(h, assoc->cs_get_mask);
433                 if (assoc->state == ASSOC_DEAD)
434                     iochan_setevent(assoc->client_chan, EVENT_TIMEOUT);
435             }
436             else
437             {
438                 assoc->cs_put_mask = EVENT_OUTPUT;
439             }
440             break;
441         default:
442             if (conn->io_pending & CS_WANT_WRITE)
443                 assoc->cs_put_mask |= EVENT_OUTPUT;
444             if (conn->io_pending & CS_WANT_READ)
445                 assoc->cs_put_mask |= EVENT_INPUT;
446             iochan_setflag(h, assoc->cs_put_mask);
447         }
448     }
449     if (event & EVENT_EXCEPT)
450     {
451         yaz_log(YLOG_WARN, "ir_session (exception)");
452         cs_close(conn);
453         destroy_association(assoc);
454         iochan_destroy(h);
455     }
456 }
457
458 static int process_z_request(association *assoc, request *req, char **msg);
459
460 static void assoc_init_reset(association *assoc)
461 {
462     xfree (assoc->init);
463     assoc->init = (bend_initrequest *) xmalloc (sizeof(*assoc->init));
464
465     assoc->init->stream = assoc->encode;
466     assoc->init->print = assoc->print;
467     assoc->init->auth = 0;
468     assoc->init->referenceId = 0;
469     assoc->init->implementation_version = 0;
470     assoc->init->implementation_id = 0;
471     assoc->init->implementation_name = 0;
472     assoc->init->bend_sort = NULL;
473     assoc->init->bend_search = NULL;
474     assoc->init->bend_present = NULL;
475     assoc->init->bend_esrequest = NULL;
476     assoc->init->bend_delete = NULL;
477     assoc->init->bend_scan = NULL;
478     assoc->init->bend_segment = NULL;
479     assoc->init->bend_fetch = NULL;
480     assoc->init->bend_explain = NULL;
481
482     assoc->init->charneg_request = NULL;
483     assoc->init->charneg_response = NULL;
484
485     assoc->init->decode = assoc->decode;
486     assoc->init->peer_name = 
487         odr_strdup (assoc->encode, cs_addrstr(assoc->client_link));
488 }
489
490 static int srw_bend_init(association *assoc)
491 {
492     const char *encoding = "UTF-8";
493     Z_External *ce;
494     bend_initresult *binitres;
495     statserv_options_block *cb = statserv_getcontrol();
496     
497     assoc_init_reset(assoc);
498
499     assoc->maximumRecordSize = 3000000;
500     assoc->preferredMessageSize = 3000000;
501 #if 1
502     ce = yaz_set_proposal_charneg(assoc->decode, &encoding, 1, 0, 0, 1);
503     assoc->init->charneg_request = ce->u.charNeg3;
504 #endif
505     assoc->backend = 0;
506     if (!(binitres = (*cb->bend_init)(assoc->init)))
507     {
508         yaz_log(YLOG_WARN, "Bad response from backend.");
509         return 0;
510     }
511     assoc->backend = binitres->handle;
512     return 1;
513 }
514
515 static int srw_bend_fetch(association *assoc, int pos,
516                           Z_SRW_searchRetrieveRequest *srw_req,
517                           Z_SRW_record *record)
518 {
519     bend_fetch_rr rr;
520     ODR o = assoc->encode;
521
522     rr.setname = "default";
523     rr.number = pos;
524     rr.referenceId = 0;
525     rr.request_format = VAL_TEXT_XML;
526     rr.request_format_raw = yaz_oidval_to_z3950oid(assoc->decode,
527                                                    CLASS_TRANSYN,
528                                                    VAL_TEXT_XML);
529     rr.comp = (Z_RecordComposition *)
530             odr_malloc(assoc->decode, sizeof(*rr.comp));
531     rr.comp->which = Z_RecordComp_complex;
532     rr.comp->u.complex = (Z_CompSpec *)
533             odr_malloc(assoc->decode, sizeof(Z_CompSpec));
534     rr.comp->u.complex->selectAlternativeSyntax = (bool_t *)
535         odr_malloc(assoc->encode, sizeof(bool_t));
536     *rr.comp->u.complex->selectAlternativeSyntax = 0;    
537     rr.comp->u.complex->num_dbSpecific = 0;
538     rr.comp->u.complex->dbSpecific = 0;
539     rr.comp->u.complex->num_recordSyntax = 0; 
540     rr.comp->u.complex->recordSyntax = 0;
541
542     rr.comp->u.complex->generic = (Z_Specification *) 
543             odr_malloc(assoc->decode, sizeof(Z_Specification));
544
545     /* schema uri = recordSchema (or NULL if recordSchema is not given) */
546     rr.comp->u.complex->generic->which = Z_Schema_uri;
547     rr.comp->u.complex->generic->schema.uri = srw_req->recordSchema;
548
549     /* ESN = recordSchema if recordSchema is present */
550     rr.comp->u.complex->generic->elementSpec = 0;
551     if (srw_req->recordSchema)
552     {
553         rr.comp->u.complex->generic->elementSpec = 
554             (Z_ElementSpec *) odr_malloc(assoc->encode, sizeof(Z_ElementSpec));
555         rr.comp->u.complex->generic->elementSpec->which = 
556             Z_ElementSpec_elementSetName;
557         rr.comp->u.complex->generic->elementSpec->u.elementSetName =
558             srw_req->recordSchema;
559     }
560     
561     rr.stream = assoc->encode;
562     rr.print = assoc->print;
563
564     rr.basename = 0;
565     rr.len = 0;
566     rr.record = 0;
567     rr.last_in_set = 0;
568     rr.output_format = VAL_TEXT_XML;
569     rr.output_format_raw = 0;
570     rr.errcode = 0;
571     rr.errstring = 0;
572     rr.surrogate_flag = 0;
573     rr.schema = srw_req->recordSchema;
574
575     if (!assoc->init->bend_fetch)
576         return 1;
577
578     (*assoc->init->bend_fetch)(assoc->backend, &rr);
579
580     if (rr.errcode && rr.surrogate_flag)
581     {
582         int code = yaz_diag_bib1_to_srw(rr.errcode);
583         const char *message = yaz_diag_srw_str(code);
584         int len = 200;
585         if (message)
586             len += strlen(message);
587         if (rr.errstring)
588             len += strlen(rr.errstring);
589
590         record->recordData_buf = odr_malloc(o, len);
591         
592         sprintf(record->recordData_buf, "<diagnostic "
593                 "xmlns=\"http://www.loc.gov/zing/srw/diagnostic/\">\n"
594                 " <uri>info:srw/diagnostic/1/%d</uri>\n", code);
595         if (rr.errstring)
596             sprintf(record->recordData_buf + strlen(record->recordData_buf),
597                     " <details>%s</details>\n", rr.errstring);
598         if (message)
599             sprintf(record->recordData_buf + strlen(record->recordData_buf),
600                     " <message>%s</message>\n", message);
601         sprintf(record->recordData_buf + strlen(record->recordData_buf),
602                 "</diagnostic>\n");
603         record->recordData_len = strlen(record->recordData_buf);
604         record->recordPosition = odr_intdup(o, pos);
605         record->recordSchema = "info:srw/schema/1/diagnostics-v1.1";
606         return 0;
607     }
608     else if (rr.len >= 0)
609     {
610         record->recordData_buf = rr.record;
611         record->recordData_len = rr.len;
612         record->recordPosition = odr_intdup(o, pos);
613         if (rr.schema)
614             record->recordSchema = odr_strdup(o, rr.schema);
615         else
616             record->recordSchema = 0;
617     }
618     return rr.errcode;
619 }
620
621 static void srw_bend_search(association *assoc, request *req,
622                             Z_SRW_searchRetrieveRequest *srw_req,
623                             Z_SRW_searchRetrieveResponse *srw_res,
624                             int *http_code)
625 {
626     int srw_error = 0;
627     bend_search_rr rr;
628     Z_External *ext;
629     const char *querystr = 0;
630     const char *querytype = 0;
631     
632     *http_code = 200;
633     yaz_log(log_requestdetail, "Got SRW SearchRetrieveRequest");
634     yaz_log(YLOG_DEBUG, "srw_bend_search");
635     if (!assoc->init)
636     {
637         yaz_log(YLOG_DEBUG, "srw_bend_init");
638         if (!srw_bend_init(assoc))
639         {
640             srw_error = 3;  /* assume Authentication error */
641
642             yaz_add_srw_diagnostic(assoc->encode, &srw_res->diagnostics,
643                                    &srw_res->num_diagnostics, 1, 0);
644             yaz_log(log_request, "Search SRW: backend init failed");
645             return;
646         }
647     }
648     
649     rr.setname = "default";
650     rr.replace_set = 1;
651     rr.num_bases = 1;
652     rr.basenames = &srw_req->database;
653     rr.referenceId = 0;
654
655     rr.query = (Z_Query *) odr_malloc (assoc->decode, sizeof(*rr.query));
656
657     if (srw_req->query_type == Z_SRW_query_type_cql)
658     {
659         ext = (Z_External *) odr_malloc(assoc->decode, sizeof(*ext));
660         ext->direct_reference = odr_getoidbystr(assoc->decode, 
661                                                 "1.2.840.10003.16.2");
662         ext->indirect_reference = 0;
663         ext->descriptor = 0;
664         ext->which = Z_External_CQL;
665         ext->u.cql = srw_req->query.cql;
666         querystr = srw_req->query.cql;
667         querytype = "CQL";
668
669         rr.query->which = Z_Query_type_104;
670         rr.query->u.type_104 =  ext;
671     }
672     else if (srw_req->query_type == Z_SRW_query_type_pqf)
673     {
674         Z_RPNQuery *RPNquery;
675         YAZ_PQF_Parser pqf_parser;
676
677         pqf_parser = yaz_pqf_create ();
678
679         querystr = srw_req->query.pqf;
680         querytype = "PQF";
681         RPNquery = yaz_pqf_parse (pqf_parser, assoc->decode,
682                                   srw_req->query.pqf);
683         if (!RPNquery)
684         {
685             const char *pqf_msg;
686             size_t off;
687             int code = yaz_pqf_error (pqf_parser, &pqf_msg, &off);
688             yaz_log(log_requestdetail, "Parse error %d %s near offset %d",
689                     code, pqf_msg, off);
690             srw_error = 10;
691         }
692
693         rr.query->which = Z_Query_type_1;
694         rr.query->u.type_1 =  RPNquery;
695
696         yaz_pqf_destroy (pqf_parser);
697     }
698     else
699         srw_error = 11;
700
701     if (!srw_error && srw_req->sort_type != Z_SRW_sort_type_none)
702         srw_error = 80;
703
704     if (!srw_error && !assoc->init->bend_search)
705         srw_error = 1;
706
707     if (srw_error)
708     {
709         if (log_request)
710         {
711             WRBUF wr = wrbuf_alloc();
712             wrbuf_printf(wr, "Search: %s: %s ", querytype, querystr);
713             wrbuf_printf(wr, " ERROR %d ", srw_error);
714             yaz_log(log_request, "%s", wrbuf_buf(wr) );
715             wrbuf_free(wr, 1);
716         }
717         srw_res->num_diagnostics = 1;
718         srw_res->diagnostics = (Z_SRW_diagnostic *)
719             odr_malloc(assoc->encode, sizeof(*srw_res->diagnostics));
720         yaz_mk_std_diagnostic(assoc->encode,
721                               srw_res->diagnostics, srw_error, 0);
722         return;
723     }
724     
725     rr.stream = assoc->encode;
726     rr.decode = assoc->decode;
727     rr.print = assoc->print;
728     rr.request = req;
729     rr.association = assoc;
730     rr.fd = 0;
731     rr.hits = 0;
732     rr.errcode = 0;
733     rr.errstring = 0;
734     rr.search_info = 0;
735     yaz_log_zquery_level(log_requestdetail,rr.query);
736
737     (assoc->init->bend_search)(assoc->backend, &rr);
738     if (rr.errcode)
739     {
740         yaz_log(log_request, "bend_search returned Bib-1 diagnostic %d",
741                 rr.errcode);
742         if (rr.errcode == 109) /* database unavailable */
743         {
744             *http_code = 404;
745             return;
746         }
747         srw_error = yaz_diag_bib1_to_srw (rr.errcode);
748         srw_res->num_diagnostics = 1;
749         srw_res->diagnostics = (Z_SRW_diagnostic *)
750             odr_malloc(assoc->encode, sizeof(*srw_res->diagnostics));
751         yaz_mk_std_diagnostic(assoc->encode, srw_res->diagnostics,
752                               srw_error, rr.errstring);
753     }
754     else
755     {
756         int number = srw_req->maximumRecords ? *srw_req->maximumRecords : 0;
757         int start = srw_req->startRecord ? *srw_req->startRecord : 1;
758
759         yaz_log(log_requestdetail, "Request to pack %d+%d out of %d",
760                 start, number, rr.hits);
761
762         srw_res->numberOfRecords = odr_intdup(assoc->encode, rr.hits);
763         if (number > 0)
764         {
765             int i;
766
767             if (start > rr.hits)
768             {
769                 srw_res->num_diagnostics = 1;
770                 srw_res->diagnostics = (Z_SRW_diagnostic *)
771                     odr_malloc(assoc->encode, 
772                                sizeof(*srw_res->diagnostics));
773                 yaz_mk_std_diagnostic(assoc->encode,  srw_res->diagnostics,
774                                       61, 0);
775             }
776             else
777             {
778                 int j = 0;
779                 int packing = Z_SRW_recordPacking_string;
780                 if (start + number > rr.hits)
781                     number = rr.hits - start + 1;
782                 if (srw_req->recordPacking && 
783                     !strcmp(srw_req->recordPacking, "xml"))
784                     packing = Z_SRW_recordPacking_XML;
785                 srw_res->records = (Z_SRW_record *)
786                     odr_malloc(assoc->encode,
787                                number * sizeof(*srw_res->records));
788                 for (i = 0; i<number; i++)
789                 {
790                     int errcode;
791                     
792                     srw_res->records[j].recordPacking = packing;
793                     srw_res->records[j].recordData_buf = 0;
794                     yaz_log(YLOG_DEBUG, "srw_bend_fetch %d", i+start);
795                     errcode = srw_bend_fetch(assoc, i+start, srw_req,
796                                              srw_res->records + j);
797                     if (errcode)
798                     {
799                         srw_res->num_diagnostics = 1;
800                         srw_res->diagnostics = (Z_SRW_diagnostic *)
801                             odr_malloc(assoc->encode, 
802                                        sizeof(*srw_res->diagnostics));
803
804                         yaz_mk_std_diagnostic(assoc->encode, 
805                                               srw_res->diagnostics,
806                                               yaz_diag_bib1_to_srw (errcode),
807                                               rr.errstring);
808                         break;
809                     }
810                     if (srw_res->records[j].recordData_buf)
811                         j++;
812                 }
813                 srw_res->num_records = j;
814                 if (!j)
815                     srw_res->records = 0;
816             }
817         }
818     }
819     if (log_request)
820     {
821         WRBUF wr=wrbuf_alloc();
822         wrbuf_printf(wr,"Search %s: %s", querytype, querystr);
823         if (srw_error)
824             wrbuf_printf(wr, " ERROR %d", srw_error);
825         else
826         {
827             wrbuf_printf(wr, " OK:%d hits", rr.hits);
828             if (srw_res->num_records)
829                 wrbuf_printf(wr, " %d records returned", srw_res->num_records);
830         }
831         yaz_log(log_request, "%s", wrbuf_buf(wr) );
832         wrbuf_free(wr, 1);
833     }
834 }
835
836 static void srw_bend_explain(association *assoc, request *req,
837                              Z_SRW_explainRequest *srw_req,
838                              Z_SRW_explainResponse *srw_res,
839                              int *http_code)
840 {
841     yaz_log(log_requestdetail, "Got SRW ExplainRequest");
842     *http_code = 404;
843     if (!assoc->init)
844     {
845         yaz_log(YLOG_DEBUG, "srw_bend_init");
846         if (!srw_bend_init(assoc))
847         {
848             return;
849         }
850     }
851     if (assoc->init && assoc->init->bend_explain)
852     {
853         bend_explain_rr rr;
854
855         rr.stream = assoc->encode;
856         rr.decode = assoc->decode;
857         rr.print = assoc->print;
858         rr.explain_buf = 0;
859         rr.database = srw_req->database;
860         rr.schema = "http://explain.z3950.org/dtd/2.0/";
861         (*assoc->init->bend_explain)(assoc->backend, &rr);
862         if (rr.explain_buf)
863         {
864             int packing = Z_SRW_recordPacking_string;
865             if (srw_req->recordPacking && 
866                 !strcmp(srw_req->recordPacking, "xml"))
867                 packing = Z_SRW_recordPacking_XML;
868             srw_res->record.recordSchema = rr.schema;
869             srw_res->record.recordPacking = packing;
870             srw_res->record.recordData_buf = rr.explain_buf;
871             srw_res->record.recordData_len = strlen(rr.explain_buf);
872             srw_res->record.recordPosition = 0;
873             *http_code = 200;
874         }
875     }
876 }
877
878 static void process_http_request(association *assoc, request *req)
879 {
880     Z_HTTP_Request *hreq = req->gdu_request->u.HTTP_Request;
881     ODR o = assoc->encode;
882     int r = 2;  /* 2=NOT TAKEN, 1=TAKEN, 0=SOAP TAKEN */
883     Z_SRW_PDU *sr = 0;
884     Z_SOAP *soap_package = 0;
885     Z_GDU *p = 0;
886     char *charset = 0;
887     Z_HTTP_Response *hres = 0;
888     int keepalive = 1;
889     char *stylesheet = 0;
890     Z_SRW_diagnostic *diagnostic = 0;
891     int num_diagnostic = 0;
892
893     if (!strcmp(hreq->path, "/test")) 
894     {   
895         p = z_get_HTTP_Response(o, 200);
896         hres = p->u.HTTP_Response;
897         hres->content_buf = "1234567890\n";
898         hres->content_len = strlen(hres->content_buf);
899         r = 1;
900     }
901     if (r == 2)
902     {
903         r = yaz_srw_decode(hreq, &sr, &soap_package, assoc->decode, &charset);
904         yaz_log(YLOG_DEBUG, "yaz_srw_decode returned %d", r);
905     }
906     if (r == 2)  /* not taken */
907     {
908         r = yaz_sru_decode(hreq, &sr, &soap_package, assoc->decode, &charset,
909                            &diagnostic, &num_diagnostic);
910         yaz_log(YLOG_DEBUG, "yaz_sru_decode returned %d", r);
911     }
912     if (r == 0)  /* decode SRW/SRU OK .. */
913     {
914         int http_code = 200;
915         if (sr->which == Z_SRW_searchRetrieve_request)
916         {
917             Z_SRW_PDU *res =
918                 yaz_srw_get(assoc->encode, Z_SRW_searchRetrieve_response);
919
920             stylesheet = sr->u.request->stylesheet;
921             if (num_diagnostic)
922             {
923                 res->u.response->diagnostics = diagnostic;
924                 res->u.response->num_diagnostics = num_diagnostic;
925             }
926             else
927             {
928                 srw_bend_search(assoc, req, sr->u.request, res->u.response, 
929                                 &http_code);
930             }
931             if (http_code == 200)
932                 soap_package->u.generic->p = res;
933         }
934         else if (sr->which == Z_SRW_explain_request)
935         {
936             Z_SRW_PDU *res = yaz_srw_get(o, Z_SRW_explain_response);
937             stylesheet = sr->u.explain_request->stylesheet;
938             if (num_diagnostic)
939             {   
940                 res->u.explain_response->diagnostics = diagnostic;
941                 res->u.explain_response->num_diagnostics = num_diagnostic;
942             }
943             srw_bend_explain(assoc, req, sr->u.explain_request,
944                              res->u.explain_response, &http_code);
945             if (http_code == 200)
946                 soap_package->u.generic->p = res;
947         }
948         else if (sr->which == Z_SRW_scan_request)
949         {
950             Z_SRW_PDU *res = yaz_srw_get(o, Z_SRW_scan_response);
951             stylesheet = sr->u.scan_request->stylesheet;
952             if (num_diagnostic)
953             {   
954                 res->u.scan_response->diagnostics = diagnostic;
955                 res->u.scan_response->num_diagnostics = num_diagnostic;
956             }
957             yaz_add_srw_diagnostic(o, 
958                                    &res->u.scan_response->diagnostics,
959                                    &res->u.scan_response->num_diagnostics,
960                                    4, "scan");
961             if (http_code == 200)
962                 soap_package->u.generic->p = res;
963         }
964         else
965         {
966             yaz_log(log_request, "generate soap error"); 
967                /* FIXME - what error, what query */
968             http_code = 500;
969             z_soap_error(assoc->encode, soap_package,
970                          "SOAP-ENV:Client", "Bad method", 0); 
971         }
972         if (http_code == 200 || http_code == 500)
973         {
974             static Z_SOAP_Handler soap_handlers[3] = {
975 #if HAVE_XML2
976                 {"http://www.loc.gov/zing/srw/", 0,
977                  (Z_SOAP_fun) yaz_srw_codec},
978                 {"http://www.loc.gov/zing/srw/v1.0/", 0,
979                  (Z_SOAP_fun) yaz_srw_codec},
980 #endif
981                 {0, 0, 0}
982             };
983             char ctype[60];
984             int ret;
985             p = z_get_HTTP_Response(o, 200);
986             hres = p->u.HTTP_Response;
987             ret = z_soap_codec_enc_xsl(assoc->encode, &soap_package,
988                                        &hres->content_buf, &hres->content_len,
989                                        soap_handlers, charset, stylesheet);
990             hres->code = http_code;
991
992             strcpy(ctype, "text/xml");
993             if (charset)
994             {
995                 strcat(ctype, "; charset=");
996                 strcat(ctype, charset);
997             }
998             z_HTTP_header_add(o, &hres->headers, "Content-Type", ctype);
999         }
1000         else
1001             p = z_get_HTTP_Response(o, http_code);
1002     }
1003
1004     if (p == 0)
1005         p = z_get_HTTP_Response(o, 500);
1006     hres = p->u.HTTP_Response;
1007     if (!strcmp(hreq->version, "1.0")) 
1008     {
1009         const char *v = z_HTTP_header_lookup(hreq->headers, "Connection");
1010         if (v && !strcmp(v, "Keep-Alive"))
1011             keepalive = 1;
1012         else
1013             keepalive = 0;
1014         hres->version = "1.0";
1015     }
1016     else
1017     {
1018         const char *v = z_HTTP_header_lookup(hreq->headers, "Connection");
1019         if (v && !strcmp(v, "close"))
1020             keepalive = 0;
1021         else
1022             keepalive = 1;
1023         hres->version = "1.1";
1024     }
1025     if (!keepalive)
1026     {
1027         z_HTTP_header_add(o, &hres->headers, "Connection", "close");
1028         assoc->state = ASSOC_DEAD;
1029         assoc->cs_get_mask = 0;
1030     }
1031     else
1032     {
1033         int t;
1034         const char *alive = z_HTTP_header_lookup(hreq->headers, "Keep-Alive");
1035
1036         if (alive && isdigit(*alive))
1037             t = atoi(alive);
1038         else
1039             t = 15;
1040         if (t < 0 || t > 3600)
1041             t = 3600;
1042         iochan_settimeout(assoc->client_chan,t);
1043         z_HTTP_header_add(o, &hres->headers, "Connection", "Keep-Alive");
1044     }
1045     process_gdu_response(assoc, req, p);
1046 }
1047
1048 static void process_gdu_request(association *assoc, request *req)
1049 {
1050     if (req->gdu_request->which == Z_GDU_Z3950)
1051     {
1052         char *msg = 0;
1053         req->apdu_request = req->gdu_request->u.z3950;
1054         if (process_z_request(assoc, req, &msg) < 0)
1055             do_close_req(assoc, Z_Close_systemProblem, msg, req);
1056     }
1057     else if (req->gdu_request->which == Z_GDU_HTTP_Request)
1058         process_http_request(assoc, req);
1059     else
1060     {
1061         do_close_req(assoc, Z_Close_systemProblem, "bad protocol packet", req);
1062     }
1063 }
1064
1065 /*
1066  * Initiate request processing.
1067  */
1068 static int process_z_request(association *assoc, request *req, char **msg)
1069 {
1070     int fd = -1;
1071     Z_APDU *res;
1072     int retval;
1073     
1074     *msg = "Unknown Error";
1075     assert(req && req->state == REQUEST_IDLE);
1076     if (req->apdu_request->which != Z_APDU_initRequest && !assoc->init)
1077     {
1078         *msg = "Missing InitRequest";
1079         return -1;
1080     }
1081     switch (req->apdu_request->which)
1082     {
1083     case Z_APDU_initRequest:
1084         iochan_settimeout(assoc->client_chan,
1085                           statserv_getcontrol()->idle_timeout * 60);
1086         res = process_initRequest(assoc, req); break;
1087     case Z_APDU_searchRequest:
1088         res = process_searchRequest(assoc, req, &fd); break;
1089     case Z_APDU_presentRequest:
1090         res = process_presentRequest(assoc, req, &fd); break;
1091     case Z_APDU_scanRequest:
1092         if (assoc->init->bend_scan)
1093             res = process_scanRequest(assoc, req, &fd);
1094         else
1095         {
1096             *msg = "Cannot handle Scan APDU";
1097             return -1;
1098         }
1099         break;
1100     case Z_APDU_extendedServicesRequest:
1101         if (assoc->init->bend_esrequest)
1102             res = process_ESRequest(assoc, req, &fd);
1103         else
1104         {
1105             *msg = "Cannot handle Extended Services APDU";
1106             return -1;
1107         }
1108         break;
1109     case Z_APDU_sortRequest:
1110         if (assoc->init->bend_sort)
1111             res = process_sortRequest(assoc, req, &fd);
1112         else
1113         {
1114             *msg = "Cannot handle Sort APDU";
1115             return -1;
1116         }
1117         break;
1118     case Z_APDU_close:
1119         process_close(assoc, req);
1120         return 0;
1121     case Z_APDU_deleteResultSetRequest:
1122         if (assoc->init->bend_delete)
1123             res = process_deleteRequest(assoc, req, &fd);
1124         else
1125         {
1126             *msg = "Cannot handle Delete APDU";
1127             return -1;
1128         }
1129         break;
1130     case Z_APDU_segmentRequest:
1131         if (assoc->init->bend_segment)
1132         {
1133             res = process_segmentRequest (assoc, req);
1134         }
1135         else
1136         {
1137             *msg = "Cannot handle Segment APDU";
1138             return -1;
1139         }
1140         break;
1141     case Z_APDU_triggerResourceControlRequest:
1142         return 0;
1143     default:
1144         *msg = "Bad APDU received";
1145         return -1;
1146     }
1147     if (res)
1148     {
1149         yaz_log(YLOG_DEBUG, "  result immediately available");
1150         retval = process_z_response(assoc, req, res);
1151     }
1152     else if (fd < 0)
1153     {
1154         yaz_log(YLOG_DEBUG, "  result unavailble");
1155         retval = 0;
1156     }
1157     else /* no result yet - one will be provided later */
1158     {
1159         IOCHAN chan;
1160
1161         /* Set up an I/O handler for the fd supplied by the backend */
1162
1163         yaz_log(YLOG_DEBUG, "   establishing handler for result");
1164         req->state = REQUEST_PENDING;
1165         if (!(chan = iochan_create(fd, backend_response, EVENT_INPUT)))
1166             abort();
1167         iochan_setdata(chan, assoc);
1168         retval = 0;
1169     }
1170     return retval;
1171 }
1172
1173 /*
1174  * Handle message from the backend.
1175  */
1176 void backend_response(IOCHAN i, int event)
1177 {
1178     association *assoc = (association *)iochan_getdata(i);
1179     request *req = request_head(&assoc->incoming);
1180     Z_APDU *res;
1181     int fd;
1182
1183     yaz_log(YLOG_DEBUG, "backend_response");
1184     assert(assoc && req && req->state != REQUEST_IDLE);
1185     /* determine what it is we're waiting for */
1186     switch (req->apdu_request->which)
1187     {
1188         case Z_APDU_searchRequest:
1189             res = response_searchRequest(assoc, req, 0, &fd); break;
1190 #if 0
1191         case Z_APDU_presentRequest:
1192             res = response_presentRequest(assoc, req, 0, &fd); break;
1193         case Z_APDU_scanRequest:
1194             res = response_scanRequest(assoc, req, 0, &fd); break;
1195 #endif
1196         default:
1197             yaz_log(YLOG_FATAL, "Serious programmer's lapse or bug");
1198             abort();
1199     }
1200     if ((res && process_z_response(assoc, req, res) < 0) || fd < 0)
1201     {
1202         yaz_log(YLOG_WARN, "Fatal error when talking to backend");
1203         do_close(assoc, Z_Close_systemProblem, 0);
1204         iochan_destroy(i);
1205         return;
1206     }
1207     else if (!res) /* no result yet - try again later */
1208     {
1209         yaz_log(YLOG_DEBUG, "   no result yet");
1210         iochan_setfd(i, fd); /* in case fd has changed */
1211     }
1212 }
1213
1214 /*
1215  * Encode response, and transfer the request structure to the outgoing queue.
1216  */
1217 static int process_gdu_response(association *assoc, request *req, Z_GDU *res)
1218 {
1219     odr_setbuf(assoc->encode, req->response, req->size_response, 1);
1220
1221     if (assoc->print)
1222     {
1223         if (!z_GDU(assoc->print, &res, 0, 0))
1224             yaz_log(YLOG_WARN, "ODR print error: %s", 
1225                 odr_errmsg(odr_geterror(assoc->print)));
1226         odr_reset(assoc->print);
1227     }
1228     if (!z_GDU(assoc->encode, &res, 0, 0))
1229     {
1230         yaz_log(YLOG_WARN, "ODR error when encoding PDU: %s [element %s]",
1231                 odr_errmsg(odr_geterror(assoc->decode)),
1232                 odr_getelement(assoc->decode));
1233         return -1;
1234     }
1235     req->response = odr_getbuf(assoc->encode, &req->len_response,
1236         &req->size_response);
1237     odr_setbuf(assoc->encode, 0, 0, 0); /* don'txfree if we abort later */
1238     odr_reset(assoc->encode);
1239     req->state = REQUEST_IDLE;
1240     request_enq(&assoc->outgoing, req);
1241     /* turn the work over to the ir_session handler */
1242     iochan_setflag(assoc->client_chan, EVENT_OUTPUT);
1243     assoc->cs_put_mask = EVENT_OUTPUT;
1244     /* Is there more work to be done? give that to the input handler too */
1245 #if 1
1246     if (request_head(&assoc->incoming))
1247     {
1248         yaz_log (YLOG_DEBUG, "more work to be done");
1249         iochan_setevent(assoc->client_chan, EVENT_WORK);
1250     }
1251 #endif
1252     return 0;
1253 }
1254
1255 /*
1256  * Encode response, and transfer the request structure to the outgoing queue.
1257  */
1258 static int process_z_response(association *assoc, request *req, Z_APDU *res)
1259 {
1260     Z_GDU *gres = (Z_GDU *) odr_malloc(assoc->encode, sizeof(*res));
1261     gres->which = Z_GDU_Z3950;
1262     gres->u.z3950 = res;
1263
1264     return process_gdu_response(assoc, req, gres);
1265 }
1266
1267
1268 /*
1269  * Handle init request.
1270  * At the moment, we don't check the options
1271  * anywhere else in the code - we just try not to do anything that would
1272  * break a naive client. We'll toss 'em into the association block when
1273  * we need them there.
1274  */
1275 static Z_APDU *process_initRequest(association *assoc, request *reqb)
1276 {
1277     statserv_options_block *cb = statserv_getcontrol();
1278     Z_InitRequest *req = reqb->apdu_request->u.initRequest;
1279     Z_APDU *apdu = zget_APDU(assoc->encode, Z_APDU_initResponse);
1280     Z_InitResponse *resp = apdu->u.initResponse;
1281     bend_initresult *binitres;
1282     char *version;
1283     char options[140];
1284
1285     yaz_log(log_requestdetail, "Got initRequest");
1286     if (req->implementationId)
1287         yaz_log(log_requestdetail, "Id:        %s", req->implementationId);
1288     if (req->implementationName)
1289         yaz_log(log_requestdetail, "Name:      %s", req->implementationName);
1290     if (req->implementationVersion)
1291         yaz_log(log_requestdetail, "Version:   %s", req->implementationVersion);
1292
1293     assoc_init_reset(assoc);
1294
1295     assoc->init->auth = req->idAuthentication;
1296     assoc->init->referenceId = req->referenceId;
1297
1298     if (ODR_MASK_GET(req->options, Z_Options_negotiationModel))
1299     {
1300         Z_CharSetandLanguageNegotiation *negotiation =
1301             yaz_get_charneg_record (req->otherInfo);
1302         if (negotiation &&
1303             negotiation->which == Z_CharSetandLanguageNegotiation_proposal)
1304             assoc->init->charneg_request = negotiation;
1305     }
1306     
1307     assoc->backend = 0;
1308     if (!(binitres = (*cb->bend_init)(assoc->init)))
1309     {
1310         yaz_log(YLOG_WARN, "Bad response from backend.");
1311         return 0;
1312     }
1313
1314     assoc->backend = binitres->handle;
1315     if ((assoc->init->bend_sort))
1316         yaz_log (YLOG_DEBUG, "Sort handler installed");
1317     if ((assoc->init->bend_search))
1318         yaz_log (YLOG_DEBUG, "Search handler installed");
1319     if ((assoc->init->bend_present))
1320         yaz_log (YLOG_DEBUG, "Present handler installed");   
1321     if ((assoc->init->bend_esrequest))
1322         yaz_log (YLOG_DEBUG, "ESRequest handler installed");   
1323     if ((assoc->init->bend_delete))
1324         yaz_log (YLOG_DEBUG, "Delete handler installed");   
1325     if ((assoc->init->bend_scan))
1326         yaz_log (YLOG_DEBUG, "Scan handler installed");   
1327     if ((assoc->init->bend_segment))
1328         yaz_log (YLOG_DEBUG, "Segment handler installed");   
1329     
1330     resp->referenceId = req->referenceId;
1331     *options = '\0';
1332     /* let's tell the client what we can do */
1333     if (ODR_MASK_GET(req->options, Z_Options_search))
1334     {
1335         ODR_MASK_SET(resp->options, Z_Options_search);
1336         strcat(options, "srch");
1337     }
1338     if (ODR_MASK_GET(req->options, Z_Options_present))
1339     {
1340         ODR_MASK_SET(resp->options, Z_Options_present);
1341         strcat(options, " prst");
1342     }
1343     if (ODR_MASK_GET(req->options, Z_Options_delSet) &&
1344         assoc->init->bend_delete)
1345     {
1346         ODR_MASK_SET(resp->options, Z_Options_delSet);
1347         strcat(options, " del");
1348     }
1349     if (ODR_MASK_GET(req->options, Z_Options_extendedServices) &&
1350         assoc->init->bend_esrequest)
1351     {
1352         ODR_MASK_SET(resp->options, Z_Options_extendedServices);
1353         strcat (options, " extendedServices");
1354     }
1355     if (ODR_MASK_GET(req->options, Z_Options_namedResultSets))
1356     {
1357         ODR_MASK_SET(resp->options, Z_Options_namedResultSets);
1358         strcat(options, " namedresults");
1359     }
1360     if (ODR_MASK_GET(req->options, Z_Options_scan) && assoc->init->bend_scan)
1361     {
1362         ODR_MASK_SET(resp->options, Z_Options_scan);
1363         strcat(options, " scan");
1364     }
1365     if (ODR_MASK_GET(req->options, Z_Options_concurrentOperations))
1366     {
1367         ODR_MASK_SET(resp->options, Z_Options_concurrentOperations);
1368         strcat(options, " concurrop");
1369     }
1370     if (ODR_MASK_GET(req->options, Z_Options_sort) && assoc->init->bend_sort)
1371     {
1372         ODR_MASK_SET(resp->options, Z_Options_sort);
1373         strcat(options, " sort");
1374     }
1375
1376     if (ODR_MASK_GET(req->options, Z_Options_negotiationModel)
1377         && assoc->init->charneg_response)
1378     {
1379         Z_OtherInformation **p;
1380         Z_OtherInformationUnit *p0;
1381         
1382         yaz_oi_APDU(apdu, &p);
1383         
1384         if ((p0=yaz_oi_update(p, assoc->encode, NULL, 0, 0))) {
1385             ODR_MASK_SET(resp->options, Z_Options_negotiationModel);
1386             
1387             p0->which = Z_OtherInfo_externallyDefinedInfo;
1388             p0->information.externallyDefinedInfo =
1389                 assoc->init->charneg_response;
1390         }
1391         ODR_MASK_SET(resp->options, Z_Options_negotiationModel);
1392         strcat(options, " negotiation");
1393     }
1394         
1395     ODR_MASK_SET(resp->options, Z_Options_triggerResourceCtrl);
1396
1397     if (ODR_MASK_GET(req->protocolVersion, Z_ProtocolVersion_1))
1398     {
1399         ODR_MASK_SET(resp->protocolVersion, Z_ProtocolVersion_1);
1400         assoc->version = 1; /* 1 & 2 are equivalent */
1401     }
1402     if (ODR_MASK_GET(req->protocolVersion, Z_ProtocolVersion_2))
1403     {
1404         ODR_MASK_SET(resp->protocolVersion, Z_ProtocolVersion_2);
1405         assoc->version = 2;
1406     }
1407     if (ODR_MASK_GET(req->protocolVersion, Z_ProtocolVersion_3))
1408     {
1409         ODR_MASK_SET(resp->protocolVersion, Z_ProtocolVersion_3);
1410         assoc->version = 3;
1411     }
1412
1413     yaz_log(log_requestdetail, "Negotiated to v%d: %s", assoc->version, options);
1414     assoc->maximumRecordSize = *req->maximumRecordSize;
1415     if (assoc->maximumRecordSize > control_block->maxrecordsize)
1416         assoc->maximumRecordSize = control_block->maxrecordsize;
1417     assoc->preferredMessageSize = *req->preferredMessageSize;
1418     if (assoc->preferredMessageSize > assoc->maximumRecordSize)
1419         assoc->preferredMessageSize = assoc->maximumRecordSize;
1420
1421     resp->preferredMessageSize = &assoc->preferredMessageSize;
1422     resp->maximumRecordSize = &assoc->maximumRecordSize;
1423
1424     resp->implementationId = odr_prepend(assoc->encode,
1425                 assoc->init->implementation_id,
1426                 resp->implementationId);
1427
1428     resp->implementationName = odr_prepend(assoc->encode,
1429                 assoc->init->implementation_name,
1430                 odr_prepend(assoc->encode, "GFS", resp->implementationName));
1431
1432     version = odr_strdup(assoc->encode, "$Revision: 1.41 $");
1433     if (strlen(version) > 10)   /* check for unexpanded CVS strings */
1434         version[strlen(version)-2] = '\0';
1435     resp->implementationVersion = odr_prepend(assoc->encode,
1436                 assoc->init->implementation_version,
1437                 odr_prepend(assoc->encode, &version[11],
1438                             resp->implementationVersion));
1439
1440     if (binitres->errcode)
1441     {
1442         WRBUF wr = wrbuf_alloc();
1443         *resp->result = 0;
1444         assoc->state = ASSOC_DEAD;
1445         resp->userInformationField =
1446             init_diagnostics(assoc->encode, binitres->errcode,
1447                              binitres->errstring);
1448         wr_diag(wr, binitres->errcode, binitres->errstring);
1449         yaz_log(log_request, "Init from '%s' (%s) (ver %s) %s",
1450                 req->implementationName ? req->implementationName :"??",
1451                 req->implementationId ? req->implementationId :"?", 
1452                 req->implementationVersion ? req->implementationVersion: "?",
1453                 wrbuf_buf(wr));
1454         wrbuf_free(wr, 1);
1455     }
1456     else
1457     {
1458         assoc->state = ASSOC_UP;
1459         yaz_log(log_request, "Init from '%s' (%s) (ver %s) OK",
1460                 req->implementationName ? req->implementationName :"??",
1461                 req->implementationId ? req->implementationId :"?", 
1462                 req->implementationVersion ? req->implementationVersion: "?");
1463     }
1464
1465     return apdu;
1466 }
1467
1468 /*
1469  * Set the specified `errcode' and `errstring' into a UserInfo-1
1470  * external to be returned to the client in accordance with Z35.90
1471  * Implementor Agreement 5 (Returning diagnostics in an InitResponse):
1472  *      http://lcweb.loc.gov/z3950/agency/agree/initdiag.html
1473  */
1474 static Z_External *init_diagnostics(ODR odr, int error, const char *addinfo)
1475 {
1476     yaz_log(log_requestdetail, "[%d] %s%s%s", error, diagbib1_str(error),
1477         addinfo ? " -- " : "", addinfo ? addinfo : "");
1478     return zget_init_diagnostics(odr, error, addinfo);
1479 }
1480
1481 /*
1482  * nonsurrogate diagnostic record.
1483  */
1484 static Z_Records *diagrec(association *assoc, int error, char *addinfo)
1485 {
1486     Z_Records *rec = (Z_Records *) odr_malloc (assoc->encode, sizeof(*rec));
1487
1488     yaz_log(log_requestdetail, "[%d] %s%s%s", error, diagbib1_str(error),
1489             addinfo ? " -- " : "", addinfo ? addinfo : "");
1490
1491     rec->which = Z_Records_NSD;
1492     rec->u.nonSurrogateDiagnostic = zget_DefaultDiagFormat(assoc->encode,
1493                                                            error, addinfo);
1494     return rec;
1495 }
1496
1497 /*
1498  * surrogate diagnostic.
1499  */
1500 static Z_NamePlusRecord *surrogatediagrec(association *assoc, 
1501                                           const char *dbname,
1502                                           int error, const char *addinfo)
1503 {
1504     yaz_log(log_requestdetail, "[%d] %s%s%s", error, diagbib1_str(error),
1505             addinfo ? " -- " : "", addinfo ? addinfo : "");
1506     return zget_surrogateDiagRec(assoc->encode, dbname, error, addinfo);
1507 }
1508
1509 static Z_Records *pack_records(association *a, char *setname, int start,
1510                                int *num, Z_RecordComposition *comp,
1511                                int *next, int *pres, oid_value format,
1512                                Z_ReferenceId *referenceId,
1513                                int *oid, int *errcode)
1514 {
1515     int recno, total_length = 0, toget = *num, dumped_records = 0;
1516     Z_Records *records =
1517         (Z_Records *) odr_malloc (a->encode, sizeof(*records));
1518     Z_NamePlusRecordList *reclist =
1519         (Z_NamePlusRecordList *) odr_malloc (a->encode, sizeof(*reclist));
1520     Z_NamePlusRecord **list =
1521         (Z_NamePlusRecord **) odr_malloc (a->encode, sizeof(*list) * toget);
1522
1523     records->which = Z_Records_DBOSD;
1524     records->u.databaseOrSurDiagnostics = reclist;
1525     reclist->num_records = 0;
1526     reclist->records = list;
1527     *pres = Z_PresentStatus_success;
1528     *num = 0;
1529     *next = 0;
1530
1531     yaz_log(log_requestdetail, "Request to pack %d+%d %s", start, toget, setname);
1532     yaz_log(log_requestdetail, "pms=%d, mrs=%d", a->preferredMessageSize,
1533         a->maximumRecordSize);
1534     for (recno = start; reclist->num_records < toget; recno++)
1535     {
1536         bend_fetch_rr freq;
1537         Z_NamePlusRecord *thisrec;
1538         int this_length = 0;
1539         /*
1540          * we get the number of bytes allocated on the stream before any
1541          * allocation done by the backend - this should give us a reasonable
1542          * idea of the total size of the data so far.
1543          */
1544         total_length = odr_total(a->encode) - dumped_records;
1545         freq.errcode = 0;
1546         freq.errstring = 0;
1547         freq.basename = 0;
1548         freq.len = 0;
1549         freq.record = 0;
1550         freq.last_in_set = 0;
1551         freq.setname = setname;
1552         freq.surrogate_flag = 0;
1553         freq.number = recno;
1554         freq.comp = comp;
1555         freq.request_format = format;
1556         freq.request_format_raw = oid;
1557         freq.output_format = format;
1558         freq.output_format_raw = 0;
1559         freq.stream = a->encode;
1560         freq.print = a->print;
1561         freq.referenceId = referenceId;
1562         freq.schema = 0;
1563         (*a->init->bend_fetch)(a->backend, &freq);
1564         /* backend should be able to signal whether error is system-wide
1565            or only pertaining to current record */
1566         if (freq.errcode)
1567         {
1568             if (!freq.surrogate_flag)
1569             {
1570                 char s[20];
1571                 *pres = Z_PresentStatus_failure;
1572                 /* for 'present request out of range',
1573                    set addinfo to record position if not set */
1574                 if (freq.errcode == 13 && freq.errstring == 0)
1575                 {
1576                     sprintf (s, "%d", recno);
1577                     freq.errstring = s;
1578                 }
1579                 if (errcode)
1580                     *errcode = freq.errcode;
1581                 return diagrec(a, freq.errcode, freq.errstring);
1582             }
1583             reclist->records[reclist->num_records] =
1584                 surrogatediagrec(a, freq.basename, freq.errcode,
1585                                  freq.errstring);
1586             reclist->num_records++;
1587             *next = freq.last_in_set ? 0 : recno + 1;
1588             continue;
1589         }
1590         if (freq.len >= 0)
1591             this_length = freq.len;
1592         else
1593             this_length = odr_total(a->encode) - total_length - dumped_records;
1594         yaz_log(YLOG_DEBUG, "  fetched record, len=%d, total=%d dumped=%d",
1595             this_length, total_length, dumped_records);
1596         if (a->preferredMessageSize > 0 &&
1597                 this_length + total_length > a->preferredMessageSize)
1598         {
1599             /* record is small enough, really */
1600             if (this_length <= a->preferredMessageSize && recno > start)
1601             {
1602                 yaz_log(log_requestdetail, "  Dropped last normal-sized record");
1603                 *pres = Z_PresentStatus_partial_2;
1604                 break;
1605             }
1606             /* record can only be fetched by itself */
1607             if (this_length < a->maximumRecordSize)
1608             {
1609                 yaz_log(log_requestdetail, "  Record > prefmsgsz");
1610                 if (toget > 1)
1611                 {
1612                     yaz_log(YLOG_DEBUG, "  Dropped it");
1613                     reclist->records[reclist->num_records] =
1614                          surrogatediagrec(a, freq.basename, 16, 0);
1615                     reclist->num_records++;
1616                     *next = freq.last_in_set ? 0 : recno + 1;
1617                     dumped_records += this_length;
1618                     continue;
1619                 }
1620             }
1621             else /* too big entirely */
1622             {
1623                 yaz_log(log_requestdetail, "Record > maxrcdsz this=%d max=%d",
1624                         this_length, a->maximumRecordSize);
1625                 reclist->records[reclist->num_records] =
1626                     surrogatediagrec(a, freq.basename, 17, 0);
1627                 reclist->num_records++;
1628                 *next = freq.last_in_set ? 0 : recno + 1;
1629                 dumped_records += this_length;
1630                 continue;
1631             }
1632         }
1633
1634         if (!(thisrec = (Z_NamePlusRecord *)
1635               odr_malloc(a->encode, sizeof(*thisrec))))
1636             return 0;
1637         if (!(thisrec->databaseName = (char *)odr_malloc(a->encode,
1638             strlen(freq.basename) + 1)))
1639             return 0;
1640         strcpy(thisrec->databaseName, freq.basename);
1641         thisrec->which = Z_NamePlusRecord_databaseRecord;
1642
1643         if (freq.output_format_raw)
1644         {
1645             struct oident *ident = oid_getentbyoid(freq.output_format_raw);
1646             freq.output_format = ident->value;
1647         }
1648         thisrec->u.databaseRecord = z_ext_record(a->encode, freq.output_format,
1649                                                  freq.record, freq.len);
1650         if (!thisrec->u.databaseRecord)
1651             return 0;
1652         reclist->records[reclist->num_records] = thisrec;
1653         reclist->num_records++;
1654         *next = freq.last_in_set ? 0 : recno + 1;
1655     }
1656     *num = reclist->num_records;
1657     return records;
1658 }
1659
1660 static Z_APDU *process_searchRequest(association *assoc, request *reqb,
1661     int *fd)
1662 {
1663     Z_SearchRequest *req = reqb->apdu_request->u.searchRequest;
1664     bend_search_rr *bsrr = 
1665         (bend_search_rr *)nmem_malloc (reqb->request_mem, sizeof(*bsrr));
1666     
1667     yaz_log(log_requestdetail, "Got SearchRequest.");
1668     bsrr->fd = fd;
1669     bsrr->request = reqb;
1670     bsrr->association = assoc;
1671     bsrr->referenceId = req->referenceId;
1672     save_referenceId (reqb, bsrr->referenceId);
1673
1674     yaz_log (log_requestdetail, "ResultSet '%s'", req->resultSetName);
1675     if (req->databaseNames)
1676     {
1677         int i;
1678         for (i = 0; i < req->num_databaseNames; i++)
1679             yaz_log (log_requestdetail, "Database '%s'", req->databaseNames[i]);
1680     }
1681
1682     yaz_log_zquery_level(log_requestdetail,req->query);
1683
1684     if (assoc->init->bend_search)
1685     {
1686         bsrr->setname = req->resultSetName;
1687         bsrr->replace_set = *req->replaceIndicator;
1688         bsrr->num_bases = req->num_databaseNames;
1689         bsrr->basenames = req->databaseNames;
1690         bsrr->query = req->query;
1691         bsrr->stream = assoc->encode;
1692         nmem_transfer(bsrr->stream->mem, reqb->request_mem);
1693         bsrr->decode = assoc->decode;
1694         bsrr->print = assoc->print;
1695         bsrr->errcode = 0;
1696         bsrr->hits = 0;
1697         bsrr->errstring = NULL;
1698         bsrr->search_info = NULL;
1699         (assoc->init->bend_search)(assoc->backend, bsrr);
1700         if (!bsrr->request)  /* backend not ready with the search response */
1701             return 0;  /* should not be used any more */
1702     }
1703     else
1704     { 
1705         /* FIXME - make a diagnostic for it */
1706         yaz_log(YLOG_WARN,"Search not supported ?!?!");
1707     }
1708     return response_searchRequest(assoc, reqb, bsrr, fd);
1709 }
1710
1711 int bend_searchresponse(void *handle, bend_search_rr *bsrr) {return 0;}
1712
1713 /*
1714  * Prepare a searchresponse based on the backend results. We probably want
1715  * to look at making the fetching of records nonblocking as well, but
1716  * so far, we'll keep things simple.
1717  * If bsrt is null, that means we're called in response to a communications
1718  * event, and we'll have to get the response for ourselves.
1719  */
1720 static Z_APDU *response_searchRequest(association *assoc, request *reqb,
1721     bend_search_rr *bsrt, int *fd)
1722 {
1723     Z_SearchRequest *req = reqb->apdu_request->u.searchRequest;
1724     Z_APDU *apdu = (Z_APDU *)odr_malloc (assoc->encode, sizeof(*apdu));
1725     Z_SearchResponse *resp = (Z_SearchResponse *)
1726         odr_malloc (assoc->encode, sizeof(*resp));
1727     int *nulint = odr_intdup (assoc->encode, 0);
1728     bool_t *sr = odr_intdup(assoc->encode, 1);
1729     int *next = odr_intdup(assoc->encode, 0);
1730     int *none = odr_intdup(assoc->encode, Z_SearchResponse_none);
1731     int returnedrecs=0;
1732
1733     apdu->which = Z_APDU_searchResponse;
1734     apdu->u.searchResponse = resp;
1735     resp->referenceId = req->referenceId;
1736     resp->additionalSearchInfo = 0;
1737     resp->otherInfo = 0;
1738     *fd = -1;
1739     if (!bsrt && !bend_searchresponse(assoc->backend, bsrt))
1740     {
1741         yaz_log(YLOG_FATAL, "Bad result from backend");
1742         return 0;
1743     }
1744     else if (bsrt->errcode)
1745     {
1746         resp->records = diagrec(assoc, bsrt->errcode, bsrt->errstring);
1747         resp->resultCount = nulint;
1748         resp->numberOfRecordsReturned = nulint;
1749         resp->nextResultSetPosition = nulint;
1750         resp->searchStatus = nulint;
1751         resp->resultSetStatus = none;
1752         resp->presentStatus = 0;
1753     }
1754     else
1755     {
1756         int *toget = odr_intdup(assoc->encode, 0);
1757         int *presst = odr_intdup(assoc->encode, 0);
1758         Z_RecordComposition comp, *compp = 0;
1759
1760         yaz_log (log_requestdetail, "resultCount: %d", bsrt->hits);
1761
1762         resp->records = 0;
1763         resp->resultCount = &bsrt->hits;
1764
1765         comp.which = Z_RecordComp_simple;
1766         /* how many records does the user agent want, then? */
1767         if (bsrt->hits <= *req->smallSetUpperBound)
1768         {
1769             *toget = bsrt->hits;
1770             if ((comp.u.simple = req->smallSetElementSetNames))
1771                 compp = &comp;
1772         }
1773         else if (bsrt->hits < *req->largeSetLowerBound)
1774         {
1775             *toget = *req->mediumSetPresentNumber;
1776             if (*toget > bsrt->hits)
1777                 *toget = bsrt->hits;
1778             if ((comp.u.simple = req->mediumSetElementSetNames))
1779                 compp = &comp;
1780         }
1781         else
1782             *toget = 0;
1783
1784         if (*toget && !resp->records)
1785         {
1786             oident *prefformat;
1787             oid_value form;
1788
1789             if (!(prefformat = oid_getentbyoid(req->preferredRecordSyntax)))
1790                 form = VAL_NONE;
1791             else
1792                 form = prefformat->value;
1793             resp->records = pack_records(assoc, req->resultSetName, 1,
1794                                          toget, compp, next, presst, form, req->referenceId,
1795                                          req->preferredRecordSyntax, NULL);
1796             if (!resp->records)
1797                 return 0;
1798             resp->numberOfRecordsReturned = toget;
1799             returnedrecs = *toget;
1800             resp->nextResultSetPosition = next;
1801             resp->searchStatus = sr;
1802             resp->resultSetStatus = 0;
1803             resp->presentStatus = presst;
1804         }
1805         else
1806         {
1807             if (*resp->resultCount)
1808                 *next = 1;
1809             resp->numberOfRecordsReturned = nulint;
1810             resp->nextResultSetPosition = next;
1811             resp->searchStatus = sr;
1812             resp->resultSetStatus = 0;
1813             resp->presentStatus = 0;
1814         }
1815     }
1816     resp->additionalSearchInfo = bsrt->search_info;
1817
1818     if (log_request)
1819     {
1820         WRBUF wr=wrbuf_alloc();
1821         wrbuf_put_zquery(wr, req->query);
1822         if (bsrt->errcode)
1823             wr_diag(wr, bsrt->errcode, bsrt->errstring);
1824         else
1825         {
1826             wrbuf_printf(wr," OK:%d hits", bsrt->hits);
1827             if (returnedrecs)
1828                 wrbuf_printf(wr, " %d records returned", returnedrecs);
1829         }
1830         yaz_log(log_request, "Search %s %s", req->resultSetName,
1831                 wrbuf_buf(wr));
1832         wrbuf_free(wr,1);
1833     }
1834     return apdu;
1835 }
1836
1837 /*
1838  * Maybe we got a little over-friendly when we designed bend_fetch to
1839  * get only one record at a time. Some backends can optimise multiple-record
1840  * fetches, and at any rate, there is some overhead involved in
1841  * all that selecting and hopping around. Problem is, of course, that the
1842  * frontend can't know ahead of time how many records it'll need to
1843  * fill the negotiated PDU size. Annoying. Segmentation or not, Z/SR
1844  * is downright lousy as a bulk data transfer protocol.
1845  *
1846  * To start with, we'll do the fetching of records from the backend
1847  * in one operation: To save some trips in and out of the event-handler,
1848  * and to simplify the interface to pack_records. At any rate, asynch
1849  * operation is more fun in operations that have an unpredictable execution
1850  * speed - which is normally more true for search than for present.
1851  */
1852 static Z_APDU *process_presentRequest(association *assoc, request *reqb,
1853                                       int *fd)
1854 {
1855     Z_PresentRequest *req = reqb->apdu_request->u.presentRequest;
1856     oident *prefformat;
1857     oid_value form;
1858     Z_APDU *apdu;
1859     Z_PresentResponse *resp;
1860     int *next;
1861     int *num;
1862     int errcode = 0;
1863     const char *errstring = 0;
1864
1865     yaz_log(log_requestdetail, "Got PresentRequest.");
1866
1867     if (!(prefformat = oid_getentbyoid(req->preferredRecordSyntax)))
1868         form = VAL_NONE;
1869     else
1870         form = prefformat->value;
1871     resp = (Z_PresentResponse *)odr_malloc (assoc->encode, sizeof(*resp));
1872     resp->records = 0;
1873     resp->presentStatus = odr_intdup(assoc->encode, 0);
1874     if (assoc->init->bend_present)
1875     {
1876         bend_present_rr *bprr = (bend_present_rr *)
1877             nmem_malloc (reqb->request_mem, sizeof(*bprr));
1878         bprr->setname = req->resultSetId;
1879         bprr->start = *req->resultSetStartPoint;
1880         bprr->number = *req->numberOfRecordsRequested;
1881         bprr->format = form;
1882         bprr->comp = req->recordComposition;
1883         bprr->referenceId = req->referenceId;
1884         bprr->stream = assoc->encode;
1885         bprr->print = assoc->print;
1886         bprr->request = reqb;
1887         bprr->association = assoc;
1888         bprr->errcode = 0;
1889         bprr->errstring = NULL;
1890         (*assoc->init->bend_present)(assoc->backend, bprr);
1891         
1892         if (!bprr->request)
1893             return 0; /* should not happen */
1894         if (bprr->errcode)
1895         {
1896             resp->records = diagrec(assoc, bprr->errcode, bprr->errstring);
1897             *resp->presentStatus = Z_PresentStatus_failure;
1898             errcode = bprr->errcode;
1899             errstring = bprr->errstring;
1900         }
1901     }
1902     apdu = (Z_APDU *)odr_malloc (assoc->encode, sizeof(*apdu));
1903     next = odr_intdup(assoc->encode, 0);
1904     num = odr_intdup(assoc->encode, 0);
1905     
1906     apdu->which = Z_APDU_presentResponse;
1907     apdu->u.presentResponse = resp;
1908     resp->referenceId = req->referenceId;
1909     resp->otherInfo = 0;
1910     
1911     if (!resp->records)
1912     {
1913         *num = *req->numberOfRecordsRequested;
1914         resp->records =
1915             pack_records(assoc, req->resultSetId, *req->resultSetStartPoint,
1916                          num, req->recordComposition, next,
1917                          resp->presentStatus,
1918                          form, req->referenceId, req->preferredRecordSyntax, 
1919                          &errcode);
1920     }
1921     if (log_request)
1922     {
1923         WRBUF wr = wrbuf_alloc();
1924         wrbuf_printf(wr, "Present %s %d+%d ",
1925                 req->resultSetId, *req->resultSetStartPoint,
1926                 *req->numberOfRecordsRequested);
1927         if (*resp->presentStatus == Z_PresentStatus_failure)
1928             wr_diag(wr, errcode, errstring);
1929         else if (*resp->presentStatus == Z_PresentStatus_success)
1930             wrbuf_printf(wr,"OK %d records returned ", *num);
1931         else
1932             wrbuf_printf(wr,"Partial (%d) OK %d records returned ", 
1933                     *resp->presentStatus, *num);
1934         yaz_log(log_request, "%s", wrbuf_buf(wr) );
1935         wrbuf_free(wr, 1);
1936     }
1937     if (!resp->records)
1938         return 0;
1939     resp->numberOfRecordsReturned = num;
1940     resp->nextResultSetPosition = next;
1941     
1942     return apdu;
1943 }
1944
1945 /*
1946  * Scan was implemented rather in a hurry, and with support for only the basic
1947  * elements of the service in the backend API. Suggestions are welcome.
1948  */
1949 static Z_APDU *process_scanRequest(association *assoc, request *reqb, int *fd)
1950 {
1951     Z_ScanRequest *req = reqb->apdu_request->u.scanRequest;
1952     Z_APDU *apdu = (Z_APDU *)odr_malloc (assoc->encode, sizeof(*apdu));
1953     Z_ScanResponse *res = (Z_ScanResponse *)
1954         odr_malloc (assoc->encode, sizeof(*res));
1955     int *scanStatus = odr_intdup(assoc->encode, Z_Scan_failure);
1956     int *numberOfEntriesReturned = odr_intdup(assoc->encode, 0);
1957     Z_ListEntries *ents = (Z_ListEntries *)
1958         odr_malloc (assoc->encode, sizeof(*ents));
1959     Z_DiagRecs *diagrecs_p = NULL;
1960     oident *attset;
1961     bend_scan_rr *bsrr = (bend_scan_rr *)
1962         odr_malloc (assoc->encode, sizeof(*bsrr));
1963     struct scan_entry *save_entries;
1964
1965     yaz_log(log_requestdetail, "Got ScanRequest");
1966
1967     apdu->which = Z_APDU_scanResponse;
1968     apdu->u.scanResponse = res;
1969     res->referenceId = req->referenceId;
1970
1971     /* if step is absent, set it to 0 */
1972     res->stepSize = odr_intdup(assoc->encode, 0);
1973     if (req->stepSize)
1974         *res->stepSize = *req->stepSize;
1975
1976     res->scanStatus = scanStatus;
1977     res->numberOfEntriesReturned = numberOfEntriesReturned;
1978     res->positionOfTerm = 0;
1979     res->entries = ents;
1980     ents->num_entries = 0;
1981     ents->entries = NULL;
1982     ents->num_nonsurrogateDiagnostics = 0;
1983     ents->nonsurrogateDiagnostics = NULL;
1984     res->attributeSet = 0;
1985     res->otherInfo = 0;
1986
1987     if (req->databaseNames)
1988     {
1989         int i;
1990         for (i = 0; i < req->num_databaseNames; i++)
1991             yaz_log (log_requestdetail, "Database '%s'", req->databaseNames[i]);
1992     }
1993     yaz_log(log_requestdetail, "pos %d  step %d  entries %d",
1994             *req->preferredPositionInResponse, *res->stepSize, 
1995             *req->numberOfTermsRequested);
1996     bsrr->num_bases = req->num_databaseNames;
1997     bsrr->basenames = req->databaseNames;
1998     bsrr->num_entries = *req->numberOfTermsRequested;
1999     bsrr->term = req->termListAndStartPoint;
2000     bsrr->referenceId = req->referenceId;
2001     bsrr->stream = assoc->encode;
2002     bsrr->print = assoc->print;
2003     bsrr->step_size = res->stepSize;
2004     bsrr->entries = 0;
2005     /* Note that version 2.0 of YAZ and older did not set entries .. 
2006        We do now. And when we do it's easier to extend the scan entry 
2007        We know that if the scan handler did set entries, it will
2008        not know of new member display_term.
2009     */
2010     if (bsrr->num_entries > 0) 
2011     {
2012         int i;
2013         bsrr->entries = odr_malloc(assoc->decode, sizeof(*bsrr->entries) *
2014                                    bsrr->num_entries);
2015         for (i = 0; i<bsrr->num_entries; i++)
2016         {
2017             bsrr->entries[i].term = 0;
2018             bsrr->entries[i].occurrences = 0;
2019             bsrr->entries[i].errcode = 0;
2020             bsrr->entries[i].errstring = 0;
2021             bsrr->entries[i].display_term = 0;
2022         }
2023     }
2024     save_entries = bsrr->entries;  /* save it so we can compare later */
2025
2026     if (req->attributeSet &&
2027         (attset = oid_getentbyoid(req->attributeSet)) &&
2028         (attset->oclass == CLASS_ATTSET || attset->oclass == CLASS_GENERAL))
2029         bsrr->attributeset = attset->value;
2030     else
2031         bsrr->attributeset = VAL_NONE;
2032     log_scan_term_level (log_requestdetail, req->termListAndStartPoint, 
2033             bsrr->attributeset);
2034     bsrr->term_position = req->preferredPositionInResponse ?
2035         *req->preferredPositionInResponse : 1;
2036
2037     ((int (*)(void *, bend_scan_rr *))
2038      (*assoc->init->bend_scan))(assoc->backend, bsrr);
2039
2040     if (bsrr->errcode)
2041         diagrecs_p = zget_DiagRecs(assoc->encode,
2042                                    bsrr->errcode, bsrr->errstring);
2043     else
2044     {
2045         int i;
2046         Z_Entry **tab = (Z_Entry **)
2047             odr_malloc (assoc->encode, sizeof(*tab) * bsrr->num_entries);
2048         
2049         if (bsrr->status == BEND_SCAN_PARTIAL)
2050             *scanStatus = Z_Scan_partial_5;
2051         else
2052             *scanStatus = Z_Scan_success;
2053         ents->entries = tab;
2054         ents->num_entries = bsrr->num_entries;
2055         res->numberOfEntriesReturned = &ents->num_entries;          
2056         res->positionOfTerm = &bsrr->term_position;
2057         for (i = 0; i < bsrr->num_entries; i++)
2058         {
2059             Z_Entry *e;
2060             Z_TermInfo *t;
2061             Odr_oct *o;
2062             
2063             tab[i] = e = (Z_Entry *)odr_malloc(assoc->encode, sizeof(*e));
2064             if (bsrr->entries[i].occurrences >= 0)
2065             {
2066                 e->which = Z_Entry_termInfo;
2067                 e->u.termInfo = t = (Z_TermInfo *)
2068                     odr_malloc(assoc->encode, sizeof(*t));
2069                 t->suggestedAttributes = 0;
2070                 t->displayTerm = 0;
2071                 if (save_entries == bsrr->entries && 
2072                     bsrr->entries[i].display_term)
2073                 {
2074                     /* the entries was NOT set by the handler. So it's
2075                        safe to test for new member display_term. It is
2076                        NULL'ed by us.
2077                     */
2078                     t->displayTerm = odr_strdup(assoc->encode,
2079                                                 bsrr->entries[i].display_term);
2080                 }
2081                 t->alternativeTerm = 0;
2082                 t->byAttributes = 0;
2083                 t->otherTermInfo = 0;
2084                 t->globalOccurrences = &bsrr->entries[i].occurrences;
2085                 t->term = (Z_Term *)
2086                     odr_malloc(assoc->encode, sizeof(*t->term));
2087                 t->term->which = Z_Term_general;
2088                 t->term->u.general = o =
2089                     (Odr_oct *)odr_malloc(assoc->encode, sizeof(Odr_oct));
2090                 o->buf = (unsigned char *)
2091                     odr_malloc(assoc->encode, o->len = o->size =
2092                                strlen(bsrr->entries[i].term));
2093                 memcpy(o->buf, bsrr->entries[i].term, o->len);
2094                 yaz_log(YLOG_DEBUG, "  term #%d: '%s' (%d)", i,
2095                          bsrr->entries[i].term, bsrr->entries[i].occurrences);
2096             }
2097             else
2098             {
2099                 Z_DiagRecs *drecs = zget_DiagRecs(assoc->encode,
2100                                                   bsrr->entries[i].errcode,
2101                                                   bsrr->entries[i].errstring);
2102                 assert (drecs->num_diagRecs == 1);
2103                 e->which = Z_Entry_surrogateDiagnostic;
2104                 assert (drecs->diagRecs[0]);
2105                 e->u.surrogateDiagnostic = drecs->diagRecs[0];
2106             }
2107         }
2108     }
2109     if (diagrecs_p)
2110     {
2111         ents->num_nonsurrogateDiagnostics = diagrecs_p->num_diagRecs;
2112         ents->nonsurrogateDiagnostics = diagrecs_p->diagRecs;
2113     }
2114     if (log_request)
2115     {
2116         WRBUF wr=wrbuf_alloc();
2117         wrbuf_printf(wr, "Scan  %d@%d ",
2118             *req->preferredPositionInResponse, 
2119             *req->numberOfTermsRequested);
2120         if (*res->stepSize)
2121             wrbuf_printf(wr, "(step %d) ",*res->stepSize);
2122         wrbuf_scan_term(wr, req->termListAndStartPoint, 
2123             bsrr->attributeset);
2124         
2125         if (*res->scanStatus == Z_Scan_success)
2126         {
2127             wrbuf_printf(wr," OK");
2128         }
2129         else 
2130             wrbuf_printf(wr," Error");
2131         yaz_log(log_request, "%s", wrbuf_buf(wr) );
2132         wrbuf_free(wr,1);
2133     }
2134     return apdu;
2135 }
2136
2137 static Z_APDU *process_sortRequest(association *assoc, request *reqb,
2138     int *fd)
2139 {
2140     int i;
2141     Z_SortRequest *req = reqb->apdu_request->u.sortRequest;
2142     Z_SortResponse *res = (Z_SortResponse *)
2143         odr_malloc (assoc->encode, sizeof(*res));
2144     bend_sort_rr *bsrr = (bend_sort_rr *)
2145         odr_malloc (assoc->encode, sizeof(*bsrr));
2146
2147     Z_APDU *apdu = (Z_APDU *)odr_malloc (assoc->encode, sizeof(*apdu));
2148
2149     yaz_log(log_requestdetail, "Got SortRequest.");
2150
2151     bsrr->num_input_setnames = req->num_inputResultSetNames;
2152     for (i=0;i<req->num_inputResultSetNames;i++)
2153         yaz_log(log_requestdetail, "Input resultset: '%s'",
2154                 req->inputResultSetNames[i]);
2155     bsrr->input_setnames = req->inputResultSetNames;
2156     bsrr->referenceId = req->referenceId;
2157     bsrr->output_setname = req->sortedResultSetName;
2158     yaz_log(log_requestdetail, "Output resultset: '%s'",
2159                 req->sortedResultSetName);
2160     bsrr->sort_sequence = req->sortSequence;
2161        /*FIXME - dump those sequences too */
2162     bsrr->stream = assoc->encode;
2163     bsrr->print = assoc->print;
2164
2165     bsrr->sort_status = Z_SortResponse_failure;
2166     bsrr->errcode = 0;
2167     bsrr->errstring = 0;
2168     
2169     (*assoc->init->bend_sort)(assoc->backend, bsrr);
2170     
2171     res->referenceId = bsrr->referenceId;
2172     res->sortStatus = odr_intdup(assoc->encode, bsrr->sort_status);
2173     res->resultSetStatus = 0;
2174     if (bsrr->errcode)
2175     {
2176         Z_DiagRecs *dr = zget_DiagRecs(assoc->encode,
2177                                        bsrr->errcode, bsrr->errstring);
2178         res->diagnostics = dr->diagRecs;
2179         res->num_diagnostics = dr->num_diagRecs;
2180     }
2181     else
2182     {
2183         res->num_diagnostics = 0;
2184         res->diagnostics = 0;
2185     }
2186     res->resultCount = 0;
2187     res->otherInfo = 0;
2188
2189     apdu->which = Z_APDU_sortResponse;
2190     apdu->u.sortResponse = res;
2191     if (log_request)
2192     {
2193         WRBUF wr=wrbuf_alloc();
2194         wrbuf_printf(wr, "Sort (");
2195         for (i=0;i<req->num_inputResultSetNames;i++)
2196         {
2197             if (i)
2198                 wrbuf_printf(wr,",");
2199             wrbuf_printf(wr, req->inputResultSetNames[i]);
2200         }
2201         wrbuf_printf(wr,")->%s ",req->sortedResultSetName);
2202
2203         /* FIXME - dump also the sort sequence */
2204         if (bsrr->errcode)
2205             wrbuf_diags(wr, res->num_diagnostics, res->diagnostics);
2206         else
2207             wrbuf_printf(wr," OK");
2208         yaz_log(log_request, "%s", wrbuf_buf(wr) );
2209         wrbuf_free(wr,1);
2210     }
2211     return apdu;
2212 }
2213
2214 static Z_APDU *process_deleteRequest(association *assoc, request *reqb,
2215     int *fd)
2216 {
2217     int i;
2218     Z_DeleteResultSetRequest *req =
2219         reqb->apdu_request->u.deleteResultSetRequest;
2220     Z_DeleteResultSetResponse *res = (Z_DeleteResultSetResponse *)
2221         odr_malloc (assoc->encode, sizeof(*res));
2222     bend_delete_rr *bdrr = (bend_delete_rr *)
2223         odr_malloc (assoc->encode, sizeof(*bdrr));
2224     Z_APDU *apdu = (Z_APDU *)odr_malloc (assoc->encode, sizeof(*apdu));
2225
2226     yaz_log(log_requestdetail, "Got DeleteRequest.");
2227
2228     bdrr->num_setnames = req->num_resultSetList;
2229     bdrr->setnames = req->resultSetList;
2230     for (i = 0; i<req->num_resultSetList; i++)
2231         yaz_log(log_requestdetail, "resultset: '%s'",
2232                 req->resultSetList[i]);
2233     bdrr->stream = assoc->encode;
2234     bdrr->print = assoc->print;
2235     bdrr->function = *req->deleteFunction;
2236     bdrr->referenceId = req->referenceId;
2237     bdrr->statuses = 0;
2238     if (bdrr->num_setnames > 0)
2239     {
2240         bdrr->statuses = (int*) 
2241             odr_malloc(assoc->encode, sizeof(*bdrr->statuses) *
2242                        bdrr->num_setnames);
2243         for (i = 0; i < bdrr->num_setnames; i++)
2244             bdrr->statuses[i] = 0;
2245     }
2246     (*assoc->init->bend_delete)(assoc->backend, bdrr);
2247     
2248     res->referenceId = req->referenceId;
2249
2250     res->deleteOperationStatus = odr_intdup(assoc->encode,bdrr->delete_status);
2251
2252     res->deleteListStatuses = 0;
2253     if (bdrr->num_setnames > 0)
2254     {
2255         int i;
2256         res->deleteListStatuses = (Z_ListStatuses *)
2257             odr_malloc(assoc->encode, sizeof(*res->deleteListStatuses));
2258         res->deleteListStatuses->num = bdrr->num_setnames;
2259         res->deleteListStatuses->elements =
2260             (Z_ListStatus **)
2261             odr_malloc (assoc->encode, 
2262                         sizeof(*res->deleteListStatuses->elements) *
2263                         bdrr->num_setnames);
2264         for (i = 0; i<bdrr->num_setnames; i++)
2265         {
2266             res->deleteListStatuses->elements[i] =
2267                 (Z_ListStatus *)
2268                 odr_malloc (assoc->encode,
2269                             sizeof(**res->deleteListStatuses->elements));
2270             res->deleteListStatuses->elements[i]->status = bdrr->statuses+i;
2271             res->deleteListStatuses->elements[i]->id =
2272                 odr_strdup (assoc->encode, bdrr->setnames[i]);
2273         }
2274     }
2275     res->numberNotDeleted = 0;
2276     res->bulkStatuses = 0;
2277     res->deleteMessage = 0;
2278     res->otherInfo = 0;
2279
2280     apdu->which = Z_APDU_deleteResultSetResponse;
2281     apdu->u.deleteResultSetResponse = res;
2282     if (log_request)
2283     {
2284         WRBUF wr=wrbuf_alloc();
2285         wrbuf_printf(wr, "Delete ");
2286         for (i = 0; i<req->num_resultSetList; i++)
2287             wrbuf_printf(wr, " '%s' ", req->resultSetList[i]);
2288         if (bdrr->delete_status)
2289             wrbuf_printf(wr," ERROR %d", bdrr->delete_status);
2290         else
2291             wrbuf_printf(wr,"OK");
2292         yaz_log(log_request, "%s", wrbuf_buf(wr) );
2293         wrbuf_free(wr,1);
2294     }
2295     return apdu;
2296 }
2297
2298 static void process_close(association *assoc, request *reqb)
2299 {
2300     Z_Close *req = reqb->apdu_request->u.close;
2301     static char *reasons[] =
2302     {
2303         "finished",
2304         "shutdown",
2305         "systemProblem",
2306         "costLimit",
2307         "resources",
2308         "securityViolation",
2309         "protocolError",
2310         "lackOfActivity",
2311         "peerAbort",
2312         "unspecified"
2313     };
2314
2315     yaz_log(log_requestdetail, "Got Close, reason %s, message %s",
2316         reasons[*req->closeReason], req->diagnosticInformation ?
2317         req->diagnosticInformation : "NULL");
2318     if (assoc->version < 3) /* to make do_force respond with close */
2319         assoc->version = 3;
2320     do_close_req(assoc, Z_Close_finished,
2321                  "Association terminated by client", reqb);
2322     yaz_log(log_request,"Close OK");
2323 }
2324
2325 void save_referenceId (request *reqb, Z_ReferenceId *refid)
2326 {
2327     if (refid)
2328     {
2329         reqb->len_refid = refid->len;
2330         reqb->refid = (char *)nmem_malloc (reqb->request_mem, refid->len);
2331         memcpy (reqb->refid, refid->buf, refid->len);
2332     }
2333     else
2334     {
2335         reqb->len_refid = 0;
2336         reqb->refid = NULL;
2337     }
2338 }
2339
2340 void bend_request_send (bend_association a, bend_request req, Z_APDU *res)
2341 {
2342     process_z_response (a, req, res);
2343 }
2344
2345 bend_request bend_request_mk (bend_association a)
2346 {
2347     request *nreq = request_get (&a->outgoing);
2348     nreq->request_mem = nmem_create ();
2349     return nreq;
2350 }
2351
2352 Z_ReferenceId *bend_request_getid (ODR odr, bend_request req)
2353 {
2354     Z_ReferenceId *id;
2355     if (!req->refid)
2356         return 0;
2357     id = (Odr_oct *)odr_malloc (odr, sizeof(*odr));
2358     id->buf = (unsigned char *)odr_malloc (odr, req->len_refid);
2359     id->len = id->size = req->len_refid;
2360     memcpy (id->buf, req->refid, req->len_refid);
2361     return id;
2362 }
2363
2364 void bend_request_destroy (bend_request *req)
2365 {
2366     nmem_destroy((*req)->request_mem);
2367     request_release(*req);
2368     *req = NULL;
2369 }
2370
2371 int bend_backend_respond (bend_association a, bend_request req)
2372 {
2373     char *msg;
2374     int r;
2375     r = process_z_request (a, req, &msg);
2376     if (r < 0)
2377         yaz_log (YLOG_WARN, "%s", msg);
2378     return r;
2379 }
2380
2381 void bend_request_setdata(bend_request r, void *p)
2382 {
2383     r->clientData = p;
2384 }
2385
2386 void *bend_request_getdata(bend_request r)
2387 {
2388     return r->clientData;
2389 }
2390
2391 static Z_APDU *process_segmentRequest (association *assoc, request *reqb)
2392 {
2393     bend_segment_rr req;
2394
2395     req.segment = reqb->apdu_request->u.segmentRequest;
2396     req.stream = assoc->encode;
2397     req.decode = assoc->decode;
2398     req.print = assoc->print;
2399     req.association = assoc;
2400     
2401     (*assoc->init->bend_segment)(assoc->backend, &req);
2402
2403     return 0;
2404 }
2405
2406 static Z_APDU *process_ESRequest(association *assoc, request *reqb, int *fd)
2407 {
2408     bend_esrequest_rr esrequest;
2409
2410     Z_ExtendedServicesRequest *req =
2411         reqb->apdu_request->u.extendedServicesRequest;
2412     Z_APDU *apdu = zget_APDU(assoc->encode, Z_APDU_extendedServicesResponse);
2413
2414     Z_ExtendedServicesResponse *resp = apdu->u.extendedServicesResponse;
2415
2416     yaz_log(log_requestdetail,"Got EsRequest");
2417
2418     esrequest.esr = reqb->apdu_request->u.extendedServicesRequest;
2419     esrequest.stream = assoc->encode;
2420     esrequest.decode = assoc->decode;
2421     esrequest.print = assoc->print;
2422     esrequest.errcode = 0;
2423     esrequest.errstring = NULL;
2424     esrequest.request = reqb;
2425     esrequest.association = assoc;
2426     esrequest.taskPackage = 0;
2427     esrequest.referenceId = req->referenceId;
2428     
2429     (*assoc->init->bend_esrequest)(assoc->backend, &esrequest);
2430     
2431     /* If the response is being delayed, return NULL */
2432     if (esrequest.request == NULL)
2433         return(NULL);
2434
2435     resp->referenceId = req->referenceId;
2436
2437     if (esrequest.errcode == -1)
2438     {
2439         /* Backend service indicates request will be processed */
2440         yaz_log(log_request,"EsRequest OK: Accepted !");
2441         *resp->operationStatus = Z_ExtendedServicesResponse_accepted;
2442     }
2443     else if (esrequest.errcode == 0)
2444     {
2445         /* Backend service indicates request will be processed */
2446         yaz_log(log_request,"EsRequest OK: Done !");
2447         *resp->operationStatus = Z_ExtendedServicesResponse_done;
2448     }
2449     else
2450     {
2451         Z_DiagRecs *diagRecs =
2452             zget_DiagRecs(assoc->encode, esrequest.errcode,
2453                           esrequest.errstring);
2454         /* Backend indicates error, request will not be processed */
2455         yaz_log(YLOG_DEBUG,"Request could not be processed...failure !");
2456         *resp->operationStatus = Z_ExtendedServicesResponse_failure;
2457         resp->num_diagnostics = diagRecs->num_diagRecs;
2458         resp->diagnostics = diagRecs->diagRecs;
2459         if (log_request)
2460         {
2461             WRBUF wr=wrbuf_alloc();
2462             wrbuf_diags(wr, resp->num_diagnostics, resp->diagnostics);
2463             yaz_log(log_request, "EsRequest %s", wrbuf_buf(wr) );
2464             wrbuf_free(wr,1);
2465         }
2466
2467     }
2468     /* Do something with the members of bend_extendedservice */
2469     if (esrequest.taskPackage)
2470         resp->taskPackage = z_ext_record (assoc->encode, VAL_EXTENDED,
2471                                          (const char *)  esrequest.taskPackage,
2472                                           -1);
2473     yaz_log(YLOG_DEBUG,"Send the result apdu");
2474     return apdu;
2475 }
2476