* Copyright (C) 1995-2005, Index Data ApS
* See the file LICENSE for details.
*
- * $Id: zoom-c.c,v 1.42 2005-06-06 10:29:33 adam Exp $
+ * $Id: zoom-c.c,v 1.43 2005-06-06 12:23:47 adam Exp $
*/
/**
* \file zoom-c.c
#include <winsock.h>
#endif
-static int log_level = 0;
-static int log_level_initialized = 0;
+static int log_api = 0;
+static int log_details = 0;
typedef enum {
zoom_pending,
static zoom_ret ZOOM_connection_send_init (ZOOM_connection c);
static zoom_ret do_write_ex (ZOOM_connection c, char *buf_out, int len_out);
+static void initlog()
+{
+ static int log_level_initialized = 0;
+ if (!log_level_initialized)
+ {
+ log_api = yaz_log_module_level("zoom");
+ log_details = yaz_log_module_level("zoomdetails");
+ log_level_initialized = 1;
+ }
+}
+
static ZOOM_Event ZOOM_Event_create (int kind)
{
ZOOM_Event event = (ZOOM_Event) xmalloc (sizeof(*event));
const char *addinfo, const char *addinfo2)
{
char *cp;
- if (!log_level_initialized)
- {
- log_level = yaz_log_module_level("zoom");
- log_level_initialized = 1;
- }
xfree (c->addinfo);
c->addinfo = 0;
else if (addinfo)
c->addinfo = xstrdup(addinfo);
if (error)
- yaz_log(log_level, "Error %s %s:%d %s %s",
- c->host_port ? c->host_port : "<>", dset, error,
+ yaz_log(log_api, "%p set_dset_error %s %s:%d %s %s",
+ c, c->host_port ? c->host_port : "<>", dset, error,
addinfo ? addinfo : "",
addinfo2 ? addinfo2 : "");
}
{
ZOOM_connection c = (ZOOM_connection) xmalloc (sizeof(*c));
- if (!log_level_initialized)
- {
- log_level = yaz_log_module_level("zoom");
- log_level_initialized = 1;
- }
+ initlog();
+
+ yaz_log(log_api, "%p ZOOM_connection_create", c);
c->proto = PROTO_Z3950;
c->cs = 0;
const char *val;
ZOOM_task task;
- if (!log_level_initialized)
- {
- log_level = yaz_log_module_level("zoom");
- log_level_initialized = 1;
- }
+ initlog();
+
+ yaz_log(log_api, "%p ZOOM_connection_connect host=%s portnum=%d",
+ c, host, portnum);
if (c->cs)
{
- yaz_log (log_level, "reconnect");
+ yaz_log(log_details, "%p ZOOM_connection_connect reconnect ok", c);
c->reconnect_ok = 1;
return;
}
- yaz_log(log_level, "connect");
+ yaz_log(log_details, "%p ZOOM_connection_connect connect", c);
xfree (c->proxy);
val = ZOOM_options_get (c->options, "proxy");
if (val && *val)
+ {
+ yaz_log(log_details, "%p ZOOM_connection_connect proxy=%s", c, val);
c->proxy = xstrdup (val);
+ }
else
c->proxy = 0;
xfree (c->charset);
val = ZOOM_options_get (c->options, "charset");
if (val && *val)
+ {
+ yaz_log(log_details, "%p ZOOM_connection_connect charset=%s", c, val);
c->charset = xstrdup (val);
+ }
else
c->charset = 0;
xfree (c->lang);
val = ZOOM_options_get (c->options, "lang");
if (val && *val)
+ {
+ yaz_log(log_details, "%p ZOOM_connection_connect lang=%s", c, val);
c->lang = xstrdup (val);
+ }
else
c->lang = 0;
val = ZOOM_options_get (c->options, "cookie");
if (val && *val)
- c->cookie_out = xstrdup (val);
+ {
+ yaz_log(log_details, "%p ZOOM_connection_connect cookie=%s", c, val);
+ c->cookie_out = xstrdup (val);
+ }
val = ZOOM_options_get (c->options, "clientIP");
if (val && *val)
+ {
+ yaz_log(log_details, "%p ZOOM_connection_connect clientIP=%s",
+ c, val);
c->client_IP = xstrdup (val);
+ }
c->async = ZOOM_options_get_bool (c->options, "async", 0);
+ yaz_log(log_details, "%p ZOOM_connection_connect async=%d", c, c->async);
set_ZOOM_error(c, ZOOM_ERROR_NONE, 0);
{
ZOOM_query s = (ZOOM_query) xmalloc (sizeof(*s));
+ yaz_log(log_details, "%p ZOOM_query_create", s);
s->refcount = 1;
s->z_query = 0;
s->sort_spec = 0;
return;
(s->refcount)--;
- yaz_log (log_level, "ZOOM_query_destroy count=%d", s->refcount);
+ yaz_log(log_details, "%p ZOOM_query_destroy count=%d", s, s->refcount);
if (s->refcount == 0)
{
odr_destroy (s->odr);
s->z_query->u.type_1 = p_query_rpn(s->odr, PROTO_Z3950, str);
if (!s->z_query->u.type_1)
{
+ yaz_log(log_details, "%p ZOOM_query_prefix str=%s failed", s, str);
s->z_query = 0;
return -1;
}
+ yaz_log(log_details, "%p ZOOM_query_prefix str=%s", s, str);
return 0;
}
s->z_query->which = Z_Query_type_104;
s->z_query->u.type_104 = ext;
+ yaz_log(log_details, "%p ZOOM_query_cql str=%s", s, str);
+
return 0;
}
{
s->sort_spec = yaz_sort_spec (s->odr, criteria);
if (!s->sort_spec)
+ {
+ yaz_log(log_details, "%p ZOOM_query_sortby criteria=%s failed",
+ s, criteria);
return -1;
+ }
+ yaz_log(log_details, "%p ZOOM_query_sortby criteria=%s", s, criteria);
return 0;
}
ZOOM_resultset r;
if (!c)
return;
+ yaz_log(log_api, "%p ZOOM_connection_destroy", c);
if (c->cs)
cs_close (c->cs);
for (r = c->resultsets; r; r = r->next)
if (r)
{
(r->refcount)++;
- yaz_log (log_level, "ZOOM_resultset_addref r=%p count=%d",
- r, r->refcount);
+ yaz_log(log_details, "%p ZOOM_resultset_addref count=%d",
+ r, r->refcount);
}
}
{
ZOOM_resultset r = (ZOOM_resultset) xmalloc (sizeof(*r));
- if (!log_level_initialized)
- {
- log_level = yaz_log_module_level("zoom");
- log_level_initialized = 1;
- }
+ initlog();
- yaz_log (log_level, "ZOOM_resultset_create r = %p", r);
+ yaz_log(log_details, "%p ZOOM_resultset_create", r);
r->refcount = 1;
r->size = 0;
r->odr = odr_createmem (ODR_ENCODE);
ZOOM_task task;
const char *cp;
+ yaz_log(log_api, "%p ZOOM_connection_search set %p query %p", c, r, q);
r->r_sort_spec = q->sort_spec;
r->query = q;
{
if (!c->cs)
{
- yaz_log(log_level, "NO COMSTACK");
+ yaz_log(log_details, "ZOOM_connection_search: no comstack");
ZOOM_connection_add_task(c, ZOOM_TASK_CONNECT);
}
else
{
- yaz_log(log_level, "PREPARE FOR RECONNECT");
+ yaz_log(log_details, "ZOOM_connection_search: reconnect");
c->reconnect_ok = 1;
}
}
ZOOM_connection c = r->connection;
ZOOM_task task;
+ yaz_log(log_api, "%p ZOOM_resultset_sort r=%p sort_type=%s sort_spec=%s",
+ r, r, sort_type, sort_spec);
if (!c)
return;
{
if (!c->cs)
{
- yaz_log(log_level, "NO COMSTACK");
+ yaz_log(log_details, "%p ZOOM_resultset_sort: no comstack", r);
ZOOM_connection_add_task(c, ZOOM_TASK_CONNECT);
}
else
{
- yaz_log(log_level, "PREPARE FOR RECONNECT");
+ yaz_log(log_details, "%p ZOOM_resultset_sort: prepare reconnect",
+ r);
c->reconnect_ok = 1;
}
}
if (!r)
return;
(r->refcount)--;
- yaz_log (log_level, "ZOOM_resultset_destroy r = %p count=%d",
- r, r->refcount);
+ yaz_log(log_details, "%p ZOOM_resultset_destroy r=%p count=%d",
+ r, r, r->refcount);
if (r->refcount == 0)
{
ZOOM_resultset_cache_reset(r);
if (!r)
return;
+ yaz_log(log_details, "%p ZOOM_resultset_retrieve force_sync=%d start=%d"
+ " count=%d", r, force_sync, start, count);
c = r->connection;
if (!c)
return;
{
if (!c->cs)
{
- yaz_log(log_level, "NO COMSTACK");
+ yaz_log(log_details, "%p ZOOM_resultset_retrieve: no comstack", r);
ZOOM_connection_add_task(c, ZOOM_TASK_CONNECT);
}
else
{
- yaz_log(log_level, "PREPARE FOR RECONNECT");
+ yaz_log(log_details, "%p ZOOM_resultset_retrieve: prepare "
+ "reconnect", r);
c->reconnect_ok = 1;
}
}
if (!r)
return ;
+ yaz_log(log_api, "%p ZOOM_resultset_records r=%p start=%d count=%d",
+ r, r, start, count);
if (count && recs)
force_present = 1;
ZOOM_resultset_retrieve (r, force_present, start, count);
{
void *add;
const char *effective_host;
- if (!log_level_initialized)
- {
- log_level = yaz_log_module_level("zoom");
- log_level_initialized = 1;
- }
-
if (c->proxy)
effective_host = c->proxy;
else
effective_host = c->host_port;
- yaz_log (log_level, "do_connect host=%s", effective_host);
+ yaz_log(log_details, "%p do_connect effective_host=%s", c, effective_host);
if (c->cs)
cs_close(c->cs);
z_APDU(odr_pr, &a, 0, 0);
odr_destroy(odr_pr);
}
- yaz_log (log_level, "encoding failed");
+ yaz_log(log_api, "%p encoding_APDU: encoding failed", c);
set_ZOOM_error(c, ZOOM_ERROR_ENCODE, 0);
odr_reset(out);
return -1;
}
-
+ yaz_log(log_details, "%p encoding_APDU encoding OK", c);
return 0;
}
assert (a);
if (encode_APDU(c, a, c->odr_out))
return zoom_complete;
- yaz_log(log_level, "send APDU type=%d", a->which);
+ yaz_log(log_details, "%p send APDU type=%d", c, a->which);
c->buf_out = odr_getbuf(c->odr_out, &c->len_out, 0);
event = ZOOM_Event_create (ZOOM_EVENT_SEND_APDU);
ZOOM_connection_put_event (c, event);
ZOOM_options_get(c->options, "implementationName"),
odr_prepend(c->odr_out, "ZOOM-C", ireq->implementationName));
- version = odr_strdup(c->odr_out, "$Revision: 1.42 $");
+ version = odr_strdup(c->odr_out, "$Revision: 1.43 $");
if (strlen(version) > 10) /* check for unexpanded CVS strings */
version[strlen(version)-2] = '\0';
ireq->implementationVersion = odr_prepend(c->odr_out,
r = c->tasks->u.search.resultset;
+ yaz_log(log_details, "%p ZOOM_connection_send_search set=%p", c, r);
+
elementSetName =
ZOOM_options_get (r->options, "elementSetName");
smallSetElementSetName =
break;
}
r->setname = xstrdup (setname);
- yaz_log (log_level, "allocating set %s", r->setname);
+ yaz_log(log_details, "%p ZOOM_connection_send_search: allocating "
+ "set %s", c, r->setname);
}
else
+ {
+ yaz_log(log_details, "%p ZOOM_connection_send_search: using "
+ "default set", c);
r->setname = xstrdup ("default");
+ }
ZOOM_options_set (r->options, "setname", r->setname);
}
search_req->resultSetName = odr_strdup(c->odr_out, r->setname);
- /* send search request */
return send_APDU (c, apdu);
}
{
ZOOM_resultset resultset;
ZOOM_Event event;
-
- yaz_log (log_level, "got search response");
-
+
if (!c->tasks || c->tasks->which != ZOOM_TASK_SEARCH)
return ;
return zoom_complete;
}
-static zoom_ret send_present (ZOOM_connection c)
+static zoom_ret send_present(ZOOM_connection c)
{
Z_APDU *apdu = 0;
Z_PresentRequest *req = 0;
ZOOM_resultset resultset;
if (!c->tasks)
+ {
+ yaz_log(log_details, "%p send_present no tasks", c);
return zoom_complete;
-
+ }
switch (c->tasks->which)
{
case ZOOM_TASK_SEARCH:
resultset->count = c->tasks->u.retrieve.count;
if (resultset->start >= resultset->size)
+ {
+ yaz_log(log_details, "%p send_present start=%d >= size=%d",
+ c, resultset->start, resultset->size);
return zoom_complete;
+ }
if (resultset->start + resultset->count > resultset->size)
resultset->count = resultset->size - resultset->start;
break;
default:
return zoom_complete;
}
+ yaz_log(log_details, "%p send_present start=%d count=%d",
+ c, resultset->start, resultset->count);
syntax = ZOOM_resultset_option_get (resultset, "preferredRecordSyntax");
elementSetName = ZOOM_resultset_option_get (resultset, "elementSetName");
break;
}
if (i == resultset->count)
+ {
+ yaz_log(log_details, "%p send_present skip=%d no more to fetch", c, i);
return zoom_complete;
+ }
apdu = zget_APDU(c->odr_out, Z_APDU_presentRequest);
req = apdu->u.presentRequest;
resultset->start += i;
resultset->count -= i;
+
+ if (i)
+ yaz_log(log_details, "%p send_present skip=%d", c, i);
+
*req->resultSetStartPoint = resultset->start + 1;
*req->numberOfRecordsRequested = resultset->step>0 ?
resultset->step : resultset->count;
assert (*req->numberOfRecordsRequested > 0);
+
if (syntax && *syntax)
req->preferredRecordSyntax =
yaz_str_to_z3950oid (c->odr_out, CLASS_RECSYN, syntax);
static zoom_ret send_package (ZOOM_connection c)
{
ZOOM_Event event;
+
+ yaz_log(log_details, "%p send_package", c);
if (!c->tasks)
return zoom_complete;
assert (c->tasks->which == ZOOM_TASK_PACKAGE);
ZOOM_scanset scan;
Z_APDU *apdu = zget_APDU(c->odr_out, Z_APDU_scanRequest);
Z_ScanRequest *req = apdu->u.scanRequest;
+
+ yaz_log(log_details, "%p send_scan", c);
if (!c->tasks)
return zoom_complete;
assert (c->tasks->which == ZOOM_TASK_SCAN);
zoom_ret ret = zoom_complete;
if (!task)
- {
- yaz_log (log_level, "ZOOM_connection_exec_task task=<null>");
return 0;
- }
- yaz_log (log_level, "ZOOM_connection_exec_task type=%d run=%d",
- task->which, task->running);
+ yaz_log(log_details, "%p ZOOM_connection_exec_task type=%d run=%d",
+ c, task->which, task->running);
if (c->error != ZOOM_ERROR_NONE)
{
- yaz_log (log_level, "remove tasks because of error = %d", c->error);
+ yaz_log(log_details, "%p ZOOM_connection_exec_task "
+ "removing tasks because of error = %d", c, c->error);
ZOOM_connection_remove_tasks (c);
return 0;
}
if (task->running)
{
- yaz_log (log_level, "task already running");
+ yaz_log(log_details, "%p ZOOM_connection_exec_task "
+ "task already running", c);
return 0;
}
task->running = 1;
}
else
{
- yaz_log (log_level, "remove tasks because no connection exist");
+ yaz_log(log_details, "%p ZOOM_connection_exec_task "
+ "remove tasks because no connection exist", c);
ZOOM_connection_remove_tasks (c);
}
if (ret == zoom_complete)
{
- yaz_log (log_level, "task removed (complete)");
+ yaz_log(log_details, "%p ZOOM_connection_exec_task "
+ "task removed (complete)", c);
ZOOM_connection_remove_task (c);
return 0;
}
- yaz_log (log_level, "task pending");
+ yaz_log(log_details, "%p ZOOM_connection_exec_task "
+ "task pending", c);
return 1;
}
}
}
-static void handle_apdu (ZOOM_connection c, Z_APDU *apdu)
+static void recv_apdu (ZOOM_connection c, Z_APDU *apdu)
{
Z_InitResponse *initrs;
c->mask = 0;
- yaz_log (log_level, "recv APDU type=%d", apdu->which);
+ yaz_log(log_details, "%p recv_apdu apdu->which=%d", c, apdu->which);
switch(apdu->which)
{
case Z_APDU_initResponse:
+ yaz_log(log_api, "%p recv_apd: Received Init response", c);
initrs = apdu->u.initResponse;
ZOOM_connection_option_set(c, "serverImplementationId",
initrs->implementationId ?
int sel;
yaz_get_response_charneg(tmpmem, p, &charset, &lang, &sel);
- yaz_log(log_level, "Target accepted: charset %s, "
- "language %s, select %d",
+ yaz_log(log_details, "%p recv_apdu target accepted: "
+ "charset %s, language %s, select %d",
+ c,
charset ? charset : "none", lang ? lang : "none", sel);
if (charset)
ZOOM_connection_option_set (c, "negotiation-charset",
}
break;
case Z_APDU_searchResponse:
+ yaz_log(log_api, "%p recv_apdu Search response", c);
handle_search_response (c, apdu->u.searchResponse);
if (send_sort_present (c) == zoom_complete)
ZOOM_connection_remove_task (c);
break;
case Z_APDU_presentResponse:
+ yaz_log(log_api, "%p recv_apdu Present response", c);
handle_present_response (c, apdu->u.presentResponse);
if (send_present (c) == zoom_complete)
ZOOM_connection_remove_task (c);
break;
case Z_APDU_sortResponse:
+ yaz_log(log_api, "%p recv_apdu Sort response", c);
sort_response (c, apdu->u.sortResponse);
if (send_present (c) == zoom_complete)
ZOOM_connection_remove_task (c);
break;
case Z_APDU_scanResponse:
+ yaz_log(log_api, "%p recv_apdu Scan response", c);
scan_response (c, apdu->u.scanResponse);
ZOOM_connection_remove_task (c);
break;
case Z_APDU_extendedServicesResponse:
+ yaz_log(log_api, "%p recv_apdu Extended Services response", c);
es_response (c, apdu->u.extendedServicesResponse);
ZOOM_connection_remove_task (c);
break;
case Z_APDU_close:
+ yaz_log(log_api, "%p recv_apdu Close PDU", c);
if (c->reconnect_ok)
{
do_close(c);
}
break;
default:
+ yaz_log(log_api, "%p Received unknown PDU", c);
set_ZOOM_error(c, ZOOM_ERROR_DECODE, 0);
do_close(c);
}
resultset->size = 0;
- yaz_log(log_level, "got SRW response OK");
+ yaz_log(log_details, "%p handle_srw_response got SRW response OK", c);
if (res->numberOfRecords)
resultset->size = *res->numberOfRecords;
const char *connection_head = z_HTTP_header_lookup(hres->headers,
"Connection");
c->mask = 0;
- yaz_log (log_level, "handle_http");
+ yaz_log(log_details, "%p handle_http", c);
if (content_type && !yaz_strcmp_del("text/xml", content_type, "; "))
{
r = cs_get (c->cs, &c->buf_in, &c->len_in);
more = cs_more(c->cs);
- yaz_log (log_level, "do_read len=%d more=%d", r, more);
+ yaz_log(log_details, "%p do_read len=%d more=%d", c, r, more);
if (r == 1)
return 0;
if (r <= 0)
{
do_close (c);
c->reconnect_ok = 0;
- yaz_log (log_level, "reconnect read");
+ yaz_log(log_details, "%p do_read reconnect read", c);
c->tasks->running = 0;
ZOOM_connection_insert_task (c, ZOOM_TASK_CONNECT);
}
do_close (c);
}
else if (gdu->which == Z_GDU_Z3950)
- handle_apdu (c, gdu->u.z3950);
+ recv_apdu (c, gdu->u.z3950);
else if (gdu->which == Z_GDU_HTTP_Response)
{
#if HAVE_XML2
event = ZOOM_Event_create(ZOOM_EVENT_SEND_DATA);
ZOOM_connection_put_event (c, event);
- yaz_log (log_level, "do_write_ex len=%d", len_out);
+ yaz_log(log_details, "%p do_write_ex len=%d", c, len_out);
if ((r = cs_put(c->cs, buf_out, len_out)) < 0)
{
+ yaz_log(log_details, "%p do_write_ex write failed", c);
if (c->reconnect_ok)
{
do_close (c);
c->reconnect_ok = 0;
- yaz_log (log_level, "reconnect write");
+ yaz_log(log_details, "%p do_write_ex reconnect write", c);
c->tasks->running = 0;
ZOOM_connection_insert_task (c, ZOOM_TASK_CONNECT);
return zoom_pending;
c->mask += ZOOM_SELECT_WRITE;
if (c->cs->io_pending & CS_WANT_READ)
c->mask += ZOOM_SELECT_READ;
- yaz_log (log_level, "do_write_ex 1 mask=%d", c->mask);
+ yaz_log(log_details, "%p do_write_ex write incomplete mask=%d",
+ c, c->mask);
}
else
{
c->mask = ZOOM_SELECT_READ|ZOOM_SELECT_EXCEPT;
- yaz_log (log_level, "do_write_ex 2 mask=%d", c->mask);
+ yaz_log(log_details, "%p do_write_ex write complete mask=%d",
+ c, c->mask);
}
return zoom_pending;
}
{
ZOOM_Event event = 0;
int r = cs_look(c->cs);
- yaz_log (log_level, "ZOOM_connection_do_io c=%p mask=%d cs_look=%d",
+ yaz_log(log_details, "%p ZOOM_connection_do_io mask=%d cs_look=%d",
c, mask, r);
if (r == CS_NONE)
event = ZOOM_Event_create (ZOOM_EVENT_CONNECT);
ret = cs_rcvconnect (c->cs);
- yaz_log (log_level, "cs_rcvconnect returned %d", ret);
+ yaz_log(log_details, "%p ZOOM_connection_do_io "
+ "cs_rcvconnect returned %d", c, ret);
if (ret == 1)
{
c->mask = ZOOM_SELECT_EXCEPT;
#else
tv.tv_sec = timeout;
tv.tv_usec = 0;
- yaz_log (log_level, "select start");
r = select (max_fd+1, &input, &output, &except, (timeout == -1 ? 0 : &tv));
- yaz_log (log_level, "select stop, returned r=%d", r);
for (i = 0; i<no; i++)
{
ZOOM_connection c = cs[i];
/* timeout and this connection was waiting */
set_ZOOM_error(c, ZOOM_ERROR_TIMEOUT, 0);
do_close (c);
- yaz_log (log_level, "timeout");
ZOOM_connection_put_event(c, event);
}
}