server/seshigh.c

   1 /*
   2  * Copyright (c) 1995, Index Data
   3  * See the file LICENSE for details.
   4  * Sebastian Hammer, Adam Dickmeiss
   5  *
   6  * $Log: seshigh.c,v $
   7  * Revision 1.50  1995-10-25 16:58:32  quinn
   8  * Simple.
   9  *
  10  * Revision 1.49  1995/10/16  13:51:53  quinn
  11  * Changes to provide Especs to the backend.
  12  *
  13  * Revision 1.48  1995/10/06  08:51:20  quinn
  14  * Added Write-buffer.
  15  *
  16  * Revision 1.47  1995/08/29  14:24:16  quinn
  17  * Added second half of close-handshake
  18  *
  19  * Revision 1.46  1995/08/29  11:17:58  quinn
  20  * Added code to receive close
  21  *
  22  * Revision 1.45  1995/08/21  09:11:00  quinn
  23  * Smallish fixes to suppport new formats.
  24  *
  25  * Revision 1.44  1995/08/17  12:45:25  quinn
  26  * Fixed minor problems with GRS-1. Added support in c&s.
  27  *
  28  * Revision 1.43  1995/08/15  12:00:31  quinn
  29  * Updated External
  30  *
  31  * Revision 1.42  1995/08/15  11:16:50  quinn
  32  *
  33  * Revision 1.41  1995/08/02  10:23:06  quinn
  34  * Smallish
  35  *
  36  * Revision 1.40  1995/07/31  14:34:26  quinn
  37  * Fixed bug in process_searchResponse (numberOfRecordsReturned).
  38  *
  39  * Revision 1.39  1995/06/27  13:21:00  quinn
  40  * SUTRS support
  41  *
  42  * Revision 1.38  1995/06/19  12:39:11  quinn
  43  * Fixed bug in timeout code. Added BER dumper.
  44  *
  45  * Revision 1.37  1995/06/16  13:16:14  quinn
  46  * Fixed Defaultdiagformat.
  47  *
  48  * Revision 1.36  1995/06/16  10:31:36  quinn
  49  * Added session timeout.
  50  *
  51  * Revision 1.35  1995/06/15  07:45:14  quinn
  52  * Moving to v3.
  53  *
  54  * Revision 1.34  1995/06/14  15:26:46  quinn
  55  * *** empty log message ***
  56  *
  57  * Revision 1.33  1995/06/06  14:57:05  quinn
  58  * Better diagnostics.
  59  *
  60  * Revision 1.32  1995/06/06  08:41:44  quinn
  61  * Better diagnostics.
  62  *
  63  * Revision 1.31  1995/06/06  08:15:37  quinn
  64  * Cosmetic.
  65  *
  66  * Revision 1.30  1995/06/05  10:53:32  quinn
  67  * Added a better SCAN.
  68  *
  69  * Revision 1.29  1995/06/01  11:25:03  quinn
  70  * Smallish.
  71  *
  72  * Revision 1.28  1995/06/01  11:21:01  quinn
  73  * Attempting to fix a bug in pack-records. replaced break with continue
  74  * for large records, according to standard.
  75  *
  76  * Revision 1.27  1995/05/29  08:12:06  quinn
  77  * Moved oid to util
  78  *
  79  * Revision 1.26  1995/05/18  13:02:12  quinn
  80  * Smallish.
  81  *
  82  * Revision 1.25  1995/05/17  08:42:26  quinn
  83  * Transfer auth info to backend. Allow backend to reject init gracefully.
  84  *
  85  * Revision 1.24  1995/05/16  08:51:04  quinn
  86  * License, documentation, and memory fixes
  87  *
  88  * Revision 1.23  1995/05/15  13:25:10  quinn
  89  * Fixed memory bug.
  90  *
  91  * Revision 1.22  1995/05/15  11:56:39  quinn
  92  * Asynchronous facilities. Restructuring of seshigh code.
  93  *
  94  * Revision 1.21  1995/05/02  08:53:19  quinn
  95  * Trying in vain to fix comm with ISODE
  96  *
  97  * Revision 1.20  1995/04/20  15:13:00  quinn
  98  * Cosmetic
  99  *
 100  * Revision 1.19  1995/04/18  08:15:34  quinn
 101  * Added dynamic memory allocation on encoding (whew). Code is now somewhat
 102  * neater. We'll make the same change for decoding one day.
 103  *
 104  * Revision 1.18  1995/04/17  11:28:25  quinn
 105  * Smallish
 106  *
 107  * Revision 1.17  1995/04/10  10:23:36  quinn
 108  * Some work to add scan and other things.
 109  *
 110  * Revision 1.16  1995/03/31  09:18:55  quinn
 111  * Added logging.
 112  *
 113  * Revision 1.15  1995/03/30  14:03:23  quinn
 114  * Added RFC1006 as separate library
 115  *
 116  * Revision 1.14  1995/03/30  12:18:17  quinn
 117  * Fixed bug.
 118  *
 119  * Revision 1.13  1995/03/30  09:09:24  quinn
 120  * Added state-handle and some support for asynchronous activities.
 121  *
 122  * Revision 1.12  1995/03/29  15:40:16  quinn
 123  * Ongoing work. Statserv is now dynamic by default
 124  *
 125  * Revision 1.11  1995/03/28  09:16:21  quinn
 126  * Added record packing to the search request
 127  *
 128  * Revision 1.10  1995/03/27  08:34:24  quinn
 129  * Added dynamic server functionality.
 130  * Released bindings to session.c (is now redundant)
 131  *
 132  * Revision 1.9  1995/03/22  15:01:26  quinn
 133  * Adjusting record packing.
 134  *
 135  * Revision 1.8  1995/03/22  10:13:21  quinn
 136  * Working on record packer
 137  *
 138  * Revision 1.7  1995/03/21  15:53:31  quinn
 139  * Little changes.
 140  *
 141  * Revision 1.6  1995/03/21  12:30:09  quinn
 142  * Beginning to add support for record packing.
 143  *
 144  * Revision 1.5  1995/03/17  10:44:13  quinn
 145  * Added catch of null-string in makediagrec
 146  *
 147  * Revision 1.4  1995/03/17  10:18:08  quinn
 148  * Added memory management.
 149  *
 150  * Revision 1.3  1995/03/16  17:42:39  quinn
 151  * Little changes
 152  *
 153  * Revision 1.2  1995/03/16  13:29:01  quinn
 154  * Partitioned server.
 155  *
 156  * Revision 1.1  1995/03/15  16:02:10  quinn
 157  * Modded session.c to seshigh.c
 158  *
 159  */
 160
 161 /*
 162  * Frontend server logic.
 163  *
 164  * This code receives incoming APDUs, and handles client requests by means
 165  * of the backend API.
 166  *
 167  * Some of the code is getting quite involved, compared to simpler servers -
 168  * primarily because it is asynchronous both in the communication with
 169  * the user and the backend. We think the complexity will pay off in
 170  * the form of greater flexibility when more asynchronous facilities
 171  * are implemented.
 172  *
 173  * Memory management has become somewhat involved. In the simple case, where
 174  * only one PDU is pending at a time, it will simply reuse the same memory,
 175  * once it has found its working size. When we enable multiple concurrent
 176  * operations, perhaps even with multiple parallel calls to the backend, it
 177  * will maintain a pool of buffers for encoding and decoding, trying to
 178  * minimize memory allocation/deallocation during normal operation.
 179  *
 180  * TODOs include (and will be done in order of public interest):
 181  *
 182  * Support for EXPLAIN - provide simple meta-database system.
 183  * Support for access control.
 184  * Support for resource control.
 185  * Support for extended services - primarily Item Order.
 186  * Rest of Z39.50-1994
 187  *
 188  */
 189
 190 #include <stdlib.h>
 191 #include <stdio.h>
 192 #include <unistd.h>
 193 #include <assert.h>
 194 #include <sys/time.h>
 195
 196 #include <dmalloc.h>
 197 #include <comstack.h>
 198 #include <eventl.h>
 199 #include <session.h>
 200 #include <proto.h>
 201 #include <oid.h>
 202 #include <log.h>
 203 #include <statserv.h>
 204
 205 #include <backend.h>
 206
 207 static int process_request(association *assoc);
 208 void backend_response(IOCHAN i, int event);
 209 static int process_response(association *assoc, request *req, Z_APDU *res);
 210 static Z_APDU *process_initRequest(association *assoc, request *reqb);
 211 static Z_APDU *process_searchRequest(association *assoc, request *reqb,
 212     int *fd);
 213 static Z_APDU *response_searchRequest(association *assoc, request *reqb,
 214     bend_searchresult *bsrt, int *fd);
 215 static Z_APDU *process_presentRequest(association *assoc, request *reqb,
 216     int *fd);
 217 static Z_APDU *process_scanRequest(association *assoc, request *reqb, int *fd);
 218 static void process_close(association *assoc, request *reqb);
 219
 220 static FILE *apduf = 0; /* for use in static mode */
 221 static statserv_options_block *control_block = 0;
 222
 223 /*
 224  * Create and initialize a new association-handle.
 225  *  channel  : iochannel for the current line.
 226  *  link     : communications channel.
 227  * Returns: 0 or a new association handle.
 228  */
 229 association *create_association(IOCHAN channel, COMSTACK link)
 230 {
 231     association *new;
 232
 233     if (!control_block)
 234         control_block = statserv_getcontrol();
 235     if (!(new = malloc(sizeof(*new))))
 236         return 0;
 237     new->client_chan = channel;
 238     new->client_link = link;
 239     if (!(new->decode = odr_createmem(ODR_DECODE)) ||
 240         !(new->encode = odr_createmem(ODR_ENCODE)))
 241         return 0;
 242     if (*control_block->apdufile)
 243     {
 244         char filename[256];
 245         FILE *f;
 246
 247         strcpy(filename, control_block->apdufile);
 248         if (!(new->print = odr_createmem(ODR_PRINT)))
 249             return 0;
 250         if (*control_block->apdufile != '-')
 251         {
 252             strcpy(filename, control_block->apdufile);
 253             if (!control_block->dynamic)
 254             {
 255                 if (!apduf)
 256                 {
 257                     if (!(apduf = fopen(filename, "w")))
 258                     {
 259                         logf(LOG_WARN|LOG_ERRNO, "%s", filename);
 260                         return 0;
 261                     }
 262                     setvbuf(apduf, 0, _IONBF, 0);
 263                 }
 264                 f = apduf;
 265             }
 266             else
 267             {
 268                 sprintf(filename + strlen(filename), ".%d", getpid());
 269                 if (!(f = fopen(filename, "w")))
 270                 {
 271                     logf(LOG_WARN|LOG_ERRNO, "%s", filename);
 272                     return 0;
 273                 }
 274                 setvbuf(f, 0, _IONBF, 0);
 275             }
 276             odr_setprint(new->print, f);
 277         }
 278     }
 279     else
 280         new->print = 0;
 281     new->input_buffer = 0;
 282     new->input_buffer_len = 0;
 283     new->backend = 0;
 284     new->state = ASSOC_NEW;
 285     request_initq(&new->incoming);
 286     request_initq(&new->outgoing);
 287     new->proto = cs_getproto(link);
 288     return new;
 289 }
 290
 291 /*
 292  * Free association and release resources.
 293  */
 294 void destroy_association(association *h)
 295 {
 296     odr_destroy(h->decode);
 297     odr_destroy(h->encode);
 298     if (h->print)
 299         odr_destroy(h->print);
 300     if (h->input_buffer)
 301         free(h->input_buffer);
 302     if (h->backend)
 303         bend_close(h->backend);
 304     while (request_deq(&h->incoming));
 305     while (request_deq(&h->outgoing));
 306     free(h);
 307 }
 308
 309 static void do_close(association *a, int reason, char *message)
 310 {
 311     Z_APDU apdu;
 312     Z_Close *cls = zget_Close(a->encode);
 313     request *req = request_get();
 314
 315     /* Purge request queue */
 316     while (request_deq(&a->incoming));
 317     while (request_deq(&a->outgoing));
 318     if (a->version >= 3)
 319     {
 320         logf(LOG_DEBUG, "Generating Close PDU");
 321         apdu.which = Z_APDU_close;
 322         apdu.u.close = cls;
 323         *cls->closeReason = reason;
 324         cls->diagnosticInformation = message;
 325         process_response(a, req, &apdu);
 326         iochan_settimeout(a->client_chan, 60);
 327     }
 328     else
 329     {
 330         logf(LOG_DEBUG, "v2 client. No Close PDU");
 331         iochan_setevent(a->client_chan, EVENT_TIMEOUT); /* force imm close */
 332     }
 333     a->state = ASSOC_DEAD;
 334 }
 335
 336 /*
 337  * This is where PDUs from the client are read and the further
 338  * processing is initiated. Flow of control moves down through the
 339  * various process_* functions below, until the encoded result comes back up
 340  * to the output handler in here.
 341  *
 342  *  h     : the I/O channel that has an outstanding event.
 343  *  event : the current outstanding event.
 344  */
 345 void ir_session(IOCHAN h, int event)
 346 {
 347     int res;
 348     association *assoc = iochan_getdata(h);
 349     COMSTACK conn = assoc->client_link;
 350     request *req;
 351
 352     assert(h && conn && assoc);
 353     if (event == EVENT_TIMEOUT)
 354     {
 355         if (assoc->state != ASSOC_UP)
 356         {
 357             logf(LOG_LOG, "Final timeout - closing connection.");
 358             cs_close(conn);
 359             destroy_association(assoc);
 360             iochan_destroy(h);
 361         }
 362         else
 363         {
 364             logf(LOG_LOG, "Session idle too long. Sending close.");
 365             do_close(assoc, Z_Close_lackOfActivity, 0);
 366         }
 367         return;
 368     }
 369     if (event & EVENT_INPUT || event & EVENT_WORK) /* input */
 370     {
 371         if (event & EVENT_INPUT)
 372         {
 373             logf(LOG_DEBUG, "ir_session (input)");
 374             assert(assoc && conn);
 375             /* We aren't speaking to this fellow */
 376             if (assoc->state == ASSOC_DEAD)
 377             {
 378                 logf(LOG_LOG, "Closed connection after reject");
 379                 cs_close(conn);
 380                 destroy_association(assoc);
 381                 iochan_destroy(h);
 382                 return;
 383             }
 384             if ((res = cs_get(conn, &assoc->input_buffer,
 385                 &assoc->input_buffer_len)) <= 0)
 386             {
 387                 logf(LOG_LOG, "Connection closed by client");
 388                 cs_close(conn);
 389                 destroy_association(assoc);
 390                 iochan_destroy(h);
 391                 return;
 392             }
 393             else if (res == 1) /* incomplete read - wait for more  */
 394                 return;
 395             if (cs_more(conn)) /* more stuff - call us again later, please */
 396                 iochan_setevent(h, EVENT_INPUT);
 397
 398             /* we got a complete PDU. Let's decode it */
 399             logf(LOG_DEBUG, "Got PDU, %d bytes", res);
 400             req = request_get(); /* get a new request structure */
 401             odr_reset(assoc->decode);
 402             odr_setbuf(assoc->decode, assoc->input_buffer, res, 0);
 403             if (!z_APDU(assoc->decode, &req->request, 0))
 404             {
 405                 logf(LOG_LOG, "ODR error on incoming PDU: %s [near byte %d] ",
 406                     odr_errlist[odr_geterror(assoc->decode)],
 407                     odr_offset(assoc->decode));
 408                 logf(LOG_LOG, "PDU dump:");
 409                 odr_dumpBER(log_file(), assoc->input_buffer, res);
 410                 do_close(assoc, Z_Close_protocolError, "Malformed package");
 411                 return;
 412             }
 413             req->request_mem = odr_extract_mem(assoc->decode);
 414             if (assoc->print && !z_APDU(assoc->print, &req->request, 0))
 415             {
 416                 logf(LOG_WARN, "ODR print error: %s",
 417                     odr_errlist[odr_geterror(assoc->print)]);
 418                 odr_reset(assoc->print);
 419             }
 420             request_enq(&assoc->incoming, req);
 421         }
 422
 423         /* can we do something yet? */
 424         req = request_head(&assoc->incoming);
 425         if (req->state == REQUEST_IDLE)
 426             if (process_request(assoc) < 0)
 427                 do_close(assoc, Z_Close_systemProblem, "Unknown error");
 428     }
 429     if (event & EVENT_OUTPUT)
 430     {
 431         request *req = request_head(&assoc->outgoing);
 432
 433         logf(LOG_DEBUG, "ir_session (output)");
 434         req->state = REQUEST_PENDING;
 435         switch (res = cs_put(conn, req->response, req->len_response))
 436         {
 437             case -1:
 438                 logf(LOG_LOG, "Connection closed by client");
 439                 cs_close(conn);
 440                 destroy_association(assoc);
 441                 iochan_destroy(h);
 442                 break;
 443             case 0: /* all sent - release the request structure */
 444                 logf(LOG_DEBUG, "Wrote PDU, %d bytes", req->len_response);
 445                 odr_release_mem(req->request_mem);
 446                 request_deq(&assoc->outgoing);
 447                 request_release(req);
 448                 if (!request_head(&assoc->outgoing))
 449                     iochan_clearflag(h, EVENT_OUTPUT);
 450                 break;
 451             /* value of 1 -- partial send -- is simply ignored */
 452         }
 453     }
 454     if (event & EVENT_EXCEPT)
 455     {
 456         logf(LOG_DEBUG, "ir_session (exception)");
 457         cs_close(conn);
 458         destroy_association(assoc);
 459         iochan_destroy(h);
 460     }
 461 }
 462
 463 /*
 464  * Initiate request processing.
 465  */
 466 static int process_request(association *assoc)
 467 {
 468     request *req = request_head(&assoc->incoming);
 469     int fd = -1;
 470     Z_APDU *res;
 471
 472     logf(LOG_DEBUG, "process_request");
 473     assert(req && req->state == REQUEST_IDLE);
 474     switch (req->request->which)
 475     {
 476         case Z_APDU_initRequest:
 477             res = process_initRequest(assoc, req); break;
 478         case Z_APDU_searchRequest:
 479             res = process_searchRequest(assoc, req, &fd); break;
 480         case Z_APDU_presentRequest:
 481             res = process_presentRequest(assoc, req, &fd); break;
 482         case Z_APDU_scanRequest:
 483             res = process_scanRequest(assoc, req, &fd); break;
 484         case Z_APDU_close:
 485             process_close(assoc, req); return 0;
 486         default:
 487             logf(LOG_WARN, "Bad APDU received");
 488             return -1;
 489     }
 490     if (res)
 491     {
 492         logf(LOG_DEBUG, "  result immediately available");
 493         return process_response(assoc, req, res);
 494     }
 495     else if (fd < 0)
 496     {
 497         logf(LOG_WARN, "   bad result");
 498         return -1;
 499     }
 500     else /* no result yet - one will be provided later */
 501     {
 502         IOCHAN chan;
 503
 504         /* Set up an I/O handler for the fd supplied by the backend */
 505
 506         logf(LOG_DEBUG, "   establishing handler for result");
 507         req->state = REQUEST_PENDING;
 508         if (!(chan = iochan_create(fd, backend_response, EVENT_INPUT)))
 509             abort();
 510         iochan_setdata(chan, assoc);
 511         return 0;
 512     }
 513 }
 514
 515 /*
 516  * Handle message from the backend.
 517  */
 518 void backend_response(IOCHAN i, int event)
 519 {
 520     association *assoc = iochan_getdata(i);
 521     request *req = request_head(&assoc->incoming);
 522     Z_APDU *res;
 523     int fd;
 524
 525     logf(LOG_DEBUG, "backend_response");
 526     assert(assoc && req && req->state != REQUEST_IDLE);
 527     /* determine what it is we're waiting for */
 528     switch (req->request->which)
 529     {
 530         case Z_APDU_searchRequest:
 531             res = response_searchRequest(assoc, req, 0, &fd); break;
 532 #if 0
 533         case Z_APDU_presentRequest:
 534             res = response_presentRequest(assoc, req, 0, &fd); break;
 535         case Z_APDU_scanRequest:
 536             res = response_scanRequest(assoc, req, 0, &fd); break;
 537 #endif
 538         default:
 539             logf(LOG_WARN, "Serious programmer's lapse or bug");
 540             abort();
 541     }
 542     if ((res && process_response(assoc, req, res) < 0) || fd < 0)
 543     {
 544         logf(LOG_LOG, "Fatal error when talking to backend");
 545         do_close(assoc, Z_Close_systemProblem, 0);
 546         iochan_destroy(i);
 547         return;
 548     }
 549     else if (!res) /* no result yet - try again later */
 550     {
 551         logf(LOG_DEBUG, "   no result yet");
 552         iochan_setfd(i, fd); /* in case fd has changed */
 553     }
 554 }
 555
 556 /*
 557  * Encode response, and transfer the request structure to the outgoing queue.
 558  */
 559 static int process_response(association *assoc, request *req, Z_APDU *res)
 560 {
 561     odr_setbuf(assoc->encode, req->response, req->size_response, 1);
 562     if (!z_APDU(assoc->encode, &res, 0))
 563     {
 564         logf(LOG_WARN, "ODR error when encoding response: %s",
 565             odr_errlist[odr_geterror(assoc->decode)]);
 566         return -1;
 567     }
 568     req->response = odr_getbuf(assoc->encode, &req->len_response,
 569         &req->size_response);
 570     odr_setbuf(assoc->encode, 0, 0, 0); /* don't free if we abort later */
 571     odr_reset(assoc->encode);
 572     if (assoc->print && !z_APDU(assoc->print, &res, 0))
 573     {
 574         logf(LOG_WARN, "ODR print error: %s",
 575             odr_errlist[odr_geterror(assoc->print)]);
 576         odr_reset(assoc->print);
 577     }
 578     /* change this when we make the backend reentrant */
 579     if (req == request_head(&assoc->incoming))
 580     {
 581         req->state = REQUEST_IDLE;
 582         request_deq(&assoc->incoming);
 583     }
 584     request_enq(&assoc->outgoing, req);
 585     /* turn the work over to the ir_session handler */
 586     iochan_setflag(assoc->client_chan, EVENT_OUTPUT);
 587     /* Is there more work to be done? give that to the input handler too */
 588     if (request_head(&assoc->incoming))
 589         iochan_setevent(assoc->client_chan, EVENT_WORK);
 590     return 0;
 591 }
 592
 593 /*
 594  * Handle init request.
 595  * At the moment, we don't check the options
 596  * anywhere else in the code - we just try not to do anything that would
 597  * break a naive client. We'll toss 'em into the association block when
 598  * we need them there.
 599  */
 600 static Z_APDU *process_initRequest(association *assoc, request *reqb)
 601 {
 602     Z_InitRequest *req = reqb->request->u.initRequest;
 603     Z_APDU *apdu = zget_APDU(assoc->encode, Z_APDU_initResponse);
 604     Z_InitResponse *resp = apdu->u.initResponse;
 605     bend_initrequest binitreq;
 606     bend_initresult *binitres;
 607     char options[100];
 608
 609     logf(LOG_LOG, "Got initRequest");
 610     if (req->implementationId)
 611         logf(LOG_LOG, "Id:        %s", req->implementationId);
 612     if (req->implementationName)
 613         logf(LOG_LOG, "Name:      %s", req->implementationName);
 614     if (req->implementationVersion)
 615         logf(LOG_LOG, "Version:   %s", req->implementationVersion);
 616
 617     binitreq.configname = "default-config";
 618     binitreq.auth = req->idAuthentication;
 619     if (!(binitres = bend_init(&binitreq)))
 620     {
 621         logf(LOG_WARN, "Bad response from backend.");
 622         return 0;
 623     }
 624
 625     assoc->backend = binitres->handle;
 626     resp->referenceId = req->referenceId;
 627     *options = '\0';
 628     /* let's tell the client what we can do */
 629     if (ODR_MASK_GET(req->options, Z_Options_search))
 630     {
 631         ODR_MASK_SET(resp->options, Z_Options_search);
 632         strcat(options, "srch");
 633     }
 634     if (ODR_MASK_GET(req->options, Z_Options_present))
 635     {
 636         ODR_MASK_SET(resp->options, Z_Options_present);
 637         strcat(options, " prst");
 638     }
 639 #if 0
 640     if (ODR_MASK_GET(req->options, Z_Options_delSet))
 641     {
 642         ODR_MASK_SET(&options, Z_Options_delSet);
 643         strcat(options, " del");
 644     }
 645 #endif
 646     if (ODR_MASK_GET(req->options, Z_Options_namedResultSets))
 647     {
 648         ODR_MASK_SET(resp->options, Z_Options_namedResultSets);
 649         strcat(options, " namedresults");
 650     }
 651     if (ODR_MASK_GET(req->options, Z_Options_scan))
 652     {
 653         ODR_MASK_SET(resp->options, Z_Options_scan);
 654         strcat(options, " scan");
 655     }
 656     if (ODR_MASK_GET(req->options, Z_Options_concurrentOperations))
 657     {
 658         ODR_MASK_SET(resp->options, Z_Options_concurrentOperations);
 659         strcat(options, " concurop");
 660     }
 661
 662     if (ODR_MASK_GET(req->protocolVersion, Z_ProtocolVersion_1))
 663     {
 664         ODR_MASK_SET(resp->protocolVersion, Z_ProtocolVersion_1);
 665         assoc->version = 2; /* 1 & 2 are equivalent */
 666     }
 667     if (ODR_MASK_GET(req->protocolVersion, Z_ProtocolVersion_2))
 668     {
 669         ODR_MASK_SET(resp->protocolVersion, Z_ProtocolVersion_2);
 670         assoc->version = 2;
 671     }
 672     if (ODR_MASK_GET(req->protocolVersion, Z_ProtocolVersion_3))
 673     {
 674         ODR_MASK_SET(resp->protocolVersion, Z_ProtocolVersion_3);
 675         assoc->version = 3;
 676     }
 677     logf(LOG_LOG, "Negotiated to v%d: %s", assoc->version, options);
 678     assoc->maximumRecordSize = *req->maximumRecordSize;
 679     if (assoc->maximumRecordSize > control_block->maxrecordsize)
 680         assoc->maximumRecordSize = control_block->maxrecordsize;
 681     assoc->preferredMessageSize = *req->preferredMessageSize;
 682     if (assoc->preferredMessageSize > assoc->maximumRecordSize)
 683         assoc->preferredMessageSize = assoc->maximumRecordSize;
 684     resp->preferredMessageSize = &assoc->preferredMessageSize;
 685     resp->maximumRecordSize = &assoc->maximumRecordSize;
 686     resp->implementationName = "Index Data/YAZ Generic Frontend Server";
 687     if (binitres->errcode)
 688     {
 689         logf(LOG_LOG, "Connection rejected by backend.");
 690         *resp->result = 0;
 691         assoc->state = ASSOC_DEAD;
 692     }
 693     else
 694         assoc->state = ASSOC_UP;
 695     return apdu;
 696 }
 697
 698 /*
 699  * These functions should be merged.
 700  */
 701
 702 /*
 703  * nonsurrogate diagnostic record.
 704  */
 705 static Z_Records *diagrec(oid_proto proto, int error, char *addinfo)
 706 {
 707     static Z_Records rec;
 708     oident bib1;
 709     static int err;
 710 #ifdef Z_95
 711     static Z_DiagRec drec;
 712     static Z_DefaultDiagFormat dr;
 713 #else
 714     static Z_DiagRec dr;
 715 #endif
 716
 717     bib1.proto = proto;
 718     bib1.class = CLASS_DIAGSET;
 719     bib1.value = VAL_BIB1;
 720
 721     logf(LOG_DEBUG, "Diagnostic: %d -- %s", error, addinfo ? addinfo :
 722         "NULL");
 723     err = error;
 724     rec.which = Z_Records_NSD;
 725 #ifdef Z_95
 726     rec.u.nonSurrogateDiagnostic = &drec;
 727     drec.which = Z_DiagRec_defaultFormat;
 728     drec.u.defaultFormat = &dr;
 729 #else
 730     rec.u.nonSurrogateDiagnostic = &dr;
 731 #endif
 732     dr.diagnosticSetId = oid_getoidbyent(&bib1);
 733     dr.condition = &err;
 734     dr.which = Z_DiagForm_v2AddInfo;
 735     dr.addinfo = addinfo ? addinfo : "";
 736     return &rec;
 737 }
 738
 739 /*
 740  * surrogate diagnostic.
 741  */
 742 static Z_NamePlusRecord *surrogatediagrec(oid_proto proto, char *dbname,
 743                                             int error, char *addinfo)
 744 {
 745     static Z_NamePlusRecord rec;
 746     static int err;
 747     oident bib1;
 748 #ifdef Z_95
 749     static Z_DiagRec drec;
 750     static Z_DefaultDiagFormat dr;
 751 #else
 752     static Z_DiagRec dr;
 753 #endif
 754
 755     bib1.proto = proto;
 756     bib1.class = CLASS_DIAGSET;
 757     bib1.value = VAL_BIB1;
 758
 759     logf(LOG_DEBUG, "SurrogateDiagnotic: %d -- %s", error, addinfo);
 760     err = error;
 761     rec.databaseName = dbname;
 762     rec.which = Z_NamePlusRecord_surrogateDiagnostic;
 763 #ifdef Z_95
 764     rec.u.surrogateDiagnostic = &drec;
 765     drec.which = Z_DiagRec_defaultFormat;
 766     drec.u.defaultFormat = &dr;
 767 #else
 768     rec.u.surrogateDiagnostic = &dr;
 769 #endif
 770     dr.diagnosticSetId = oid_getoidbyent(&bib1);
 771     dr.condition = &err;
 772     dr.which = Z_DiagForm_v2AddInfo;
 773     dr.addinfo = addinfo ? addinfo : "";
 774     return &rec;
 775 }
 776
 777 /*
 778  * multiple nonsurrogate diagnostics.
 779  */
 780 static Z_DiagRecs *diagrecs(oid_proto proto, int error, char *addinfo)
 781 {
 782     static Z_DiagRecs recs;
 783     static int err;
 784     oident bib1;
 785 #ifdef Z_95
 786     static Z_DiagRec *recp[1], drec;
 787     static Z_DefaultDiagFormat rec;
 788 #else
 789     static Z_DiagRec *recp[1], rec;
 790 #endif
 791
 792     logf(LOG_DEBUG, "DiagRecs: %d -- %s", error, addinfo);
 793     bib1.proto = proto;
 794     bib1.class = CLASS_DIAGSET;
 795     bib1.value = VAL_BIB1;
 796
 797     err = error;
 798     recs.num_diagRecs = 1;
 799     recs.diagRecs = recp;
 800 #ifdef Z_95
 801     recp[0] = &drec;
 802     drec.which = Z_DiagRec_defaultFormat;
 803     drec.u.defaultFormat = &rec;
 804 #else
 805     recp[0] = &rec;
 806 #endif
 807     rec.diagnosticSetId = oid_getoidbyent(&bib1);
 808     rec.condition = &err;
 809     rec.which = Z_DiagForm_v2AddInfo;
 810     rec.addinfo = addinfo ? addinfo : "";
 811     return &recs;
 812 }
 813
 814 #define MAX_RECORDS 256
 815
 816 static Z_Records *pack_records(association *a, char *setname, int start,
 817                                 int *num, Z_RecordComposition *comp,
 818                                 int *next, int *pres, oid_value format)
 819 {
 820     int recno, total_length = 0, toget = *num;
 821     static Z_Records records;
 822     static Z_NamePlusRecordList reclist;
 823     static Z_NamePlusRecord *list[MAX_RECORDS];
 824     oident recform;
 825
 826     records.which = Z_Records_DBOSD;
 827     records.u.databaseOrSurDiagnostics = &reclist;
 828     reclist.num_records = 0;
 829     reclist.records = list;
 830     *pres = Z_PRES_SUCCESS;
 831     *num = 0;
 832     *next = 0;
 833
 834     logf(LOG_DEBUG, "Request to pack %d+%d", start, toget);
 835     logf(LOG_DEBUG, "pms=%d, mrs=%d", a->preferredMessageSize,
 836         a->maximumRecordSize);
 837     for (recno = start; reclist.num_records < toget; recno++)
 838     {
 839         bend_fetchrequest freq;
 840         bend_fetchresult *fres;
 841         Z_NamePlusRecord *thisrec;
 842         Z_DatabaseRecord *thisext;
 843         int this_length;
 844
 845         /*
 846          * we get the number of bytes allocated on the stream before any
 847          * allocation done by the backend - this should give us a reasonable
 848          * idea of the total size of the data so far.
 849          */
 850         total_length = odr_total(a->encode);
 851         if (reclist.num_records == MAX_RECORDS - 1)
 852         {
 853             *pres = Z_PRES_PARTIAL_2;
 854             break;
 855         }
 856         freq.setname = setname;
 857         freq.number = recno;
 858         freq.comp = comp;
 859         freq.format = format;
 860         freq.stream = a->encode;
 861         if (!(fres = bend_fetch(a->backend, &freq, 0)))
 862         {
 863             *pres = Z_PRES_FAILURE;
 864             return diagrec(a->proto, 2, "Backend interface problem");
 865         }
 866         /* backend should be able to signal whether error is system-wide
 867            or only pertaining to current record */
 868         if (fres->errcode)
 869         {
 870             *pres = Z_PRES_FAILURE;
 871             return diagrec(a->proto, fres->errcode, fres->errstring);
 872         }
 873         if (fres->len >= 0)
 874             this_length = fres->len;
 875         else
 876             this_length = odr_total(a->encode) - total_length;
 877         logf(LOG_DEBUG, "  fetched record, len=%d, total=%d",
 878             this_length, total_length);
 879         if (this_length + total_length > a->preferredMessageSize)
 880         {
 881             /* record is small enough, really */
 882             if (this_length <= a->preferredMessageSize)
 883             {
 884                 logf(LOG_DEBUG, "  Dropped last normal-sized record");
 885                 *pres = Z_PRES_PARTIAL_2;
 886                 break;
 887             }
 888             /* record can only be fetched by itself */
 889             if (this_length < a->maximumRecordSize)
 890             {
 891                 logf(LOG_DEBUG, "  Record > prefmsgsz");
 892                 if (toget > 1)
 893                 {
 894                     logf(LOG_DEBUG, "  Dropped it");
 895                     reclist.records[reclist.num_records] =
 896                          surrogatediagrec(a->proto, fres->basename, 16, 0);
 897                     reclist.num_records++;
 898                     continue;
 899                 }
 900             }
 901             else /* too big entirely */
 902             {
 903                 logf(LOG_DEBUG, "Record > maxrcdsz");
 904                 reclist.records[reclist.num_records] =
 905                     surrogatediagrec(a->proto, fres->basename, 17, 0);
 906                 reclist.num_records++;
 907                 continue;
 908             }
 909         }
 910         if (!(thisrec = odr_malloc(a->encode, sizeof(*thisrec))))
 911             return 0;
 912         if (!(thisrec->databaseName = odr_malloc(a->encode,
 913             strlen(fres->basename) + 1)))
 914             return 0;
 915         strcpy(thisrec->databaseName, fres->basename);
 916         thisrec->which = Z_NamePlusRecord_databaseRecord;
 917         if (!(thisrec->u.databaseRecord = thisext = odr_malloc(a->encode,
 918             sizeof(Z_DatabaseRecord))))
 919             return 0;
 920         recform.proto = a->proto;
 921         recform.class = CLASS_RECSYN;
 922         recform.value = fres->format;
 923         thisext->direct_reference = odr_oiddup(a->encode,
 924             oid_getoidbyent(&recform));
 925         thisext->indirect_reference = 0;
 926         thisext->descriptor = 0;
 927         if (fres->len < 0) /* Structured data */
 928         {
 929             switch (fres->format)
 930             {
 931                 case VAL_SUTRS: thisext->which = Z_External_sutrs; break;
 932                 case VAL_GRS1: thisext->which = Z_External_grs1; break;
 933                 case VAL_EXPLAIN: thisext->which = Z_External_explainRecord;
 934                     break;
 935
 936                 default:
 937                     logf(LOG_FATAL, "Unknown structured format from backend.");
 938                     return 0;
 939             }
 940
 941             /*
 942              * We cheat on the pointers here. Obviously, the record field
 943              * of the backend-fetch structure should have been a union for
 944              * correctness, but we're stuck with this for backwards
 945              * compatibility.
 946              */
 947             thisext->u.grs1 = (Z_GenericRecord*) fres->record;
 948         }
 949         else if (fres->format == VAL_SUTRS) /* SUTRS is a single-ASN.1-type */
 950         {
 951             Odr_oct *sutrs = odr_malloc(a->encode, sizeof(*sutrs));
 952
 953             thisext->which = Z_External_sutrs;
 954             thisext->u.sutrs = sutrs;
 955             sutrs->buf = odr_malloc(a->encode, fres->len);
 956             sutrs->len = sutrs->size = fres->len;
 957             memcpy(sutrs->buf, fres->record, fres->len);
 958         }
 959         else /* octet-aligned record. */
 960         {
 961             thisext->which = Z_External_octet;
 962             if (!(thisext->u.octet_aligned = odr_malloc(a->encode,
 963                 sizeof(Odr_oct))))
 964                 return 0;
 965             if (!(thisext->u.octet_aligned->buf = odr_malloc(a->encode,
 966                 fres->len)))
 967                 return 0;
 968             memcpy(thisext->u.octet_aligned->buf, fres->record, fres->len);
 969             thisext->u.octet_aligned->len = thisext->u.octet_aligned->size =
 970                 fres->len;
 971         }
 972         reclist.records[reclist.num_records] = thisrec;
 973         reclist.num_records++;
 974         *next = fres->last_in_set ? 0 : recno + 1;
 975     }
 976     *num = reclist.num_records;
 977     return &records;
 978 }
 979
 980 static Z_APDU *process_searchRequest(association *assoc, request *reqb,
 981     int *fd)
 982 {
 983     Z_SearchRequest *req = reqb->request->u.searchRequest;
 984     bend_searchrequest bsrq;
 985     bend_searchresult *bsrt;
 986
 987     logf(LOG_LOG, "Got SearchRequest.");
 988
 989     bsrq.setname = req->resultSetName;
 990     bsrq.replace_set = *req->replaceIndicator;
 991     bsrq.num_bases = req->num_databaseNames;
 992     bsrq.basenames = req->databaseNames;
 993     bsrq.query = req->query;
 994
 995     if (!(bsrt = bend_search(assoc->backend, &bsrq, fd)))
 996         return 0;
 997     return response_searchRequest(assoc, reqb, bsrt, fd);
 998 }
 999
1000 bend_searchresult *bend_searchresponse(void *handle) {return 0;}
1001
1002 /*
1003  * Prepare a searchresponse based on the backend results. We probably want
1004  * to look at making the fetching of records nonblocking as well, but
1005  * so far, we'll keep things simple.
1006  * If bsrt is null, that means we're called in response to a communications
1007  * event, and we'll have to get the response for ourselves.
1008  */
1009 static Z_APDU *response_searchRequest(association *assoc, request *reqb,
1010     bend_searchresult *bsrt, int *fd)
1011 {
1012     Z_SearchRequest *req = reqb->request->u.searchRequest;
1013     static Z_APDU apdu;
1014     static Z_SearchResponse resp;
1015     static int nulint = 0;
1016     static bool_t sr = 1;
1017     static int next = 0;
1018     static int none = Z_RES_NONE;
1019
1020     apdu.which = Z_APDU_searchResponse;
1021     apdu.u.searchResponse = &resp;
1022     resp.referenceId = req->referenceId;
1023 #ifdef Z_95
1024     resp.additionalSearchInfo = 0;
1025     resp.otherInfo = 0;
1026 #endif
1027     *fd = -1;
1028     if (!bsrt && !(bsrt = bend_searchresponse(assoc->backend)))
1029     {
1030         logf(LOG_FATAL, "Bad result from backend");
1031         return 0;
1032     }
1033     else if (bsrt->errcode)
1034     {
1035         resp.records = diagrec(assoc->proto, bsrt->errcode,
1036             bsrt->errstring);
1037         resp.resultCount = &nulint;
1038         resp.numberOfRecordsReturned = &nulint;
1039         resp.nextResultSetPosition = &nulint;
1040         resp.searchStatus = &nulint;
1041         resp.resultSetStatus = &none;
1042         resp.presentStatus = 0;
1043     }
1044     else
1045     {
1046         static int toget;
1047         Z_RecordComposition comp;
1048         static int presst = 0;
1049
1050         resp.records = 0;
1051         resp.resultCount = &bsrt->hits;
1052
1053         comp.which = Z_RecordComp_simple;
1054         /* how many records does the user agent want, then? */
1055         if (bsrt->hits <= *req->smallSetUpperBound)
1056         {
1057             toget = bsrt->hits;
1058             comp.u.simple = req->smallSetElementSetNames;
1059         }
1060         else if (bsrt->hits < *req->largeSetLowerBound)
1061         {
1062             toget = *req->mediumSetPresentNumber;
1063             if (toget > bsrt->hits)
1064                 toget = bsrt->hits;
1065             comp.u.simple = req->mediumSetElementSetNames;
1066         }
1067         else
1068             toget = 0;
1069
1070         if (toget && !resp.records)
1071         {
1072             oident *prefformat;
1073             oid_value form;
1074
1075             if (!(prefformat = oid_getentbyoid(req->preferredRecordSyntax)) ||
1076                 prefformat->class != CLASS_RECSYN)
1077                 form = VAL_NONE;
1078             else
1079                 form = prefformat->value;
1080             resp.records = pack_records(assoc, req->resultSetName, 1,
1081                 &toget, &comp, &next, &presst, form);
1082             if (!resp.records)
1083                 return 0;
1084             resp.numberOfRecordsReturned = &toget;
1085             resp.nextResultSetPosition = &next;
1086             resp.searchStatus = &sr;
1087             resp.resultSetStatus = 0;
1088             resp.presentStatus = &presst;
1089         }
1090         else
1091         {
1092             if (*resp.resultCount)
1093                 next = 1;
1094             resp.numberOfRecordsReturned = &nulint;
1095             resp.nextResultSetPosition = &next;
1096             resp.searchStatus = &sr;
1097             resp.resultSetStatus = 0;
1098             resp.presentStatus = 0;
1099         }
1100     }
1101     return &apdu;
1102 }
1103
1104 /*
1105  * Maybe we got a little over-friendly when we designed bend_fetch to
1106  * get only one record at a time. Some backends can optimise multiple-record
1107  * fetches, and at any rate, there is some overhead involved in
1108  * all that selecting and hopping around. Problem is, of course, that the
1109  * frontend can't know ahead of time how many records it'll need to
1110  * fill the negotiated PDU size. Annoying. Segmentation or not, Z/SR
1111  * is downright lousy as a bulk data transfer protocol.
1112  *
1113  * To start with, we'll do the fetching of records from the backend
1114  * in one operation: To save some trips in and out of the event-handler,
1115  * and to simplify the interface to pack_records. At any rate, asynch
1116  * operation is more fun in operations that have an unpredictable execution
1117  * speed - which is normally more true for search than for present.
1118  */
1119 static Z_APDU *process_presentRequest(association *assoc, request *reqb,
1120     int *fd)
1121 {
1122     Z_PresentRequest *req = reqb->request->u.presentRequest;
1123     static Z_APDU apdu;
1124     static Z_PresentResponse resp;
1125     static int presst, next, num;
1126     oident *prefformat;
1127     oid_value form;
1128
1129
1130     logf(LOG_LOG, "Got PresentRequest.");
1131     apdu.which = Z_APDU_presentResponse;
1132     apdu.u.presentResponse = &resp;
1133     resp.referenceId = req->referenceId;
1134 #ifdef Z_95
1135     resp.otherInfo = 0;
1136 #endif
1137
1138     if (!(prefformat = oid_getentbyoid(req->preferredRecordSyntax)) ||
1139         prefformat->class != CLASS_RECSYN)
1140         form = VAL_NONE;
1141     else
1142         form = prefformat->value;
1143     num = *req->numberOfRecordsRequested;
1144     resp.records = pack_records(assoc, req->resultSetId,
1145         *req->resultSetStartPoint, &num, req->recordComposition, &next,
1146         &presst, form);
1147     if (!resp.records)
1148         return 0;
1149     resp.numberOfRecordsReturned = &num;
1150     resp.presentStatus = &presst;
1151     resp.nextResultSetPosition = &next;
1152
1153     return &apdu;
1154 }
1155
1156 /*
1157  * Scan was implemented rather in a hurry, and with support for only the basic
1158  * elements of the service in the backend API. Suggestions are welcome.
1159  */
1160 static Z_APDU *process_scanRequest(association *assoc, request *reqb, int *fd)
1161 {
1162     Z_ScanRequest *req = reqb->request->u.scanRequest;
1163     static Z_APDU apdu;
1164     static Z_ScanResponse res;
1165     static int scanStatus = Z_Scan_failure;
1166     static int numberOfEntriesReturned = 0;
1167     oident *attent;
1168     static Z_ListEntries ents;
1169 #define SCAN_MAX_ENTRIES 200
1170     static Z_Entry *tab[SCAN_MAX_ENTRIES];
1171     bend_scanrequest srq;
1172     bend_scanresult *srs;
1173
1174     logf(LOG_LOG, "Got scanrequest");
1175     apdu.which = Z_APDU_scanResponse;
1176     apdu.u.scanResponse = &res;
1177     res.referenceId = req->referenceId;
1178     res.stepSize = 0;
1179     res.scanStatus = &scanStatus;
1180     res.numberOfEntriesReturned = &numberOfEntriesReturned;
1181     res.positionOfTerm = 0;
1182     res.entries = &ents;
1183     ents.which = Z_ListEntries_nonSurrogateDiagnostics;
1184     res.attributeSet = 0;
1185 #ifdef Z_95
1186     res.otherInfo = 0;
1187 #endif
1188
1189     if (req->attributeSet && (!(attent = oid_getentbyoid(req->attributeSet)) ||
1190         attent->class != CLASS_ATTSET || attent->value != VAL_BIB1))
1191         ents.u.nonSurrogateDiagnostics = diagrecs(assoc->proto, 121, 0);
1192     else if (req->stepSize && *req->stepSize > 0)
1193         ents.u.nonSurrogateDiagnostics = diagrecs(assoc->proto, 205, 0);
1194     else
1195     {
1196         if (req->termListAndStartPoint->term->which == Z_Term_general)
1197             logf(LOG_DEBUG, " term: '%.*s'",
1198                 req->termListAndStartPoint->term->u.general->len,
1199                 req->termListAndStartPoint->term->u.general->buf);
1200         srq.num_bases = req->num_databaseNames;
1201         srq.basenames = req->databaseNames;
1202         srq.num_entries = *req->numberOfTermsRequested;
1203         srq.term = req->termListAndStartPoint;
1204         srq.term_position = req->preferredPositionInResponse ?
1205             *req->preferredPositionInResponse : 1;
1206         if (!(srs = bend_scan(assoc->backend, &srq, 0)))
1207             ents.u.nonSurrogateDiagnostics = diagrecs(assoc->proto, 2, 0);
1208         else if (srs->errcode)
1209             ents.u.nonSurrogateDiagnostics = diagrecs(assoc->proto,
1210                 srs->errcode, srs->errstring);
1211         else
1212         {
1213             int i;
1214             static Z_Entries list;
1215
1216             if (srs->status == BEND_SCAN_PARTIAL)
1217                 scanStatus = Z_Scan_partial_5;
1218             else
1219                 scanStatus = Z_Scan_success;
1220             ents.which = Z_ListEntries_entries;
1221             ents.u.entries = &list;
1222             list.entries = tab;
1223             for (i = 0; i < srs->num_entries; i++)
1224             {
1225                 Z_Entry *e;
1226                 Z_TermInfo *t;
1227                 Odr_oct *o;
1228
1229                 if (i >= SCAN_MAX_ENTRIES)
1230                 {
1231                     scanStatus = Z_Scan_partial_4;
1232                     break;
1233                 }
1234                 list.entries[i] = e = odr_malloc(assoc->encode, sizeof(*e));
1235                 e->which = Z_Entry_termInfo;
1236                 e->u.termInfo = t = odr_malloc(assoc->encode, sizeof(*t));
1237                 t->suggestedAttributes = 0;
1238                 t->alternativeTerm = 0;
1239                 t->byAttributes = 0;
1240                 t->globalOccurrences = &srs->entries[i].occurrences;
1241                 t->term = odr_malloc(assoc->encode, sizeof(*t->term));
1242                 t->term->which = Z_Term_general;
1243                 t->term->u.general = o = odr_malloc(assoc->encode,
1244                     sizeof(Odr_oct));
1245                 o->buf = odr_malloc(assoc->encode, o->len = o->size =
1246                     strlen(srs->entries[i].term));
1247                 memcpy(o->buf, srs->entries[i].term, o->len);
1248                 logf(LOG_DEBUG, "  term #%d: '%s' (%d)", i,
1249                     srs->entries[i].term, srs->entries[i].occurrences);
1250             }
1251             list.num_entries = i;
1252             res.numberOfEntriesReturned = &list.num_entries;
1253             res.positionOfTerm = &srs->term_position;
1254         }
1255     }
1256
1257     return &apdu;
1258 }
1259
1260 static void process_close(association *assoc, request *reqb)
1261 {
1262     Z_Close *req = reqb->request->u.close;
1263     static char *reasons[] =
1264     {
1265         "finished",
1266         "shutdown",
1267         "systemProblem",
1268         "costLimit",
1269         "resources",
1270         "securityViolation",
1271         "protocolError",
1272         "lackOfActivity",
1273         "peerAbort",
1274         "unspecified"
1275     };
1276
1277     logf(LOG_LOG, "Got close, reason %s, message %s",
1278         reasons[*req->closeReason], req->diagnosticInformation ?
1279         req->diagnosticInformation : "NULL");
1280     if (assoc->version < 3) /* to make do_force respond with close */
1281         assoc->version = 3;
1282     do_close(assoc, Z_Close_finished, "Association terminated by client");
1283 }