Pazpar2 1.4.4-2 for squeeze
[pazpar2-moved-to-github.git] / src / http_command.c
index c800b62..a905750 100644 (file)
@@ -33,6 +33,7 @@ Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA  02110-1301  USA
 #include <yaz/snprintf.h>
 #include <yaz/yaz-util.h>
 
+#include "ppmutex.h"
 #include "eventl.h"
 #include "parameters.h"
 #include "session.h"
@@ -60,6 +61,7 @@ struct http_session {
 struct http_sessions {
     struct http_session *session_list;
     YAZ_MUTEX mutex;
+    int log_level;
 };
 
 http_sessions_t http_sessions_create(void)
@@ -67,7 +69,8 @@ http_sessions_t http_sessions_create(void)
     http_sessions_t hs = xmalloc(sizeof(*hs));
     hs->session_list = 0;
     hs->mutex = 0;
-    yaz_mutex_create(&hs->mutex);
+    pazpar2_mutex_create(&hs->mutex, "http_sessions");
+    hs->log_level = yaz_log_module_level("HTTP");
     return hs;
 }
 
@@ -98,16 +101,19 @@ static void session_timeout(IOCHAN i, int event)
 }
 
 struct http_session *http_session_create(struct conf_service *service,
-                                         http_sessions_t http_sessions)
+                                         http_sessions_t http_sessions,
+                                         unsigned int sesid)
 {
     NMEM nmem = nmem_create();
     struct http_session *r = nmem_malloc(nmem, sizeof(*r));
+    char tmp_str[50];
 
-    r->psession = new_session(nmem, service);
-    r->session_id = 0;
+    sprintf(tmp_str, "session#%u", sesid);
+    r->psession = new_session(nmem, service, tmp_str);
+    r->session_id = sesid;
     r->timestamp = 0;
     r->nmem = nmem;
-    r->destroy_counter = r->activity_counter;
+    r->destroy_counter = r->activity_counter = 0;
     r->http_sessions = http_sessions;
 
     yaz_mutex_enter(http_sessions->mutex);
@@ -115,9 +121,9 @@ struct http_session *http_session_create(struct conf_service *service,
     http_sessions->session_list = r;
     yaz_mutex_leave(http_sessions->mutex);
 
-    r->timeout_iochan = iochan_create(-1, session_timeout, 0);
+    r->timeout_iochan = iochan_create(-1, session_timeout, 0, "http_session_timeout");
     iochan_setdata(r->timeout_iochan, r);
-    yaz_log(YLOG_LOG, "timeout=%d", service->session_timeout);
+    yaz_log(http_sessions->log_level, "%p Session %u created. timeout chan=%p timeout=%d", r, sesid, r->timeout_iochan, service->session_timeout);
     iochan_settimeout(r->timeout_iochan, service->session_timeout);
 
     iochan_add(service->server->iochan_man, r->timeout_iochan);
@@ -126,27 +132,16 @@ struct http_session *http_session_create(struct conf_service *service,
 
 void http_session_destroy(struct http_session *s)
 {
-    int must_destroy = 1;
+    int must_destroy = 0;
 
     http_sessions_t http_sessions = s->http_sessions;
 
-    yaz_log(YLOG_LOG, "http_session_destroy %u", s->session_id);
+    yaz_log(http_sessions->log_level, "%p Session %u destroyed", s, s->session_id);
     yaz_mutex_enter(http_sessions->mutex);
-
-    /* only if http_session destroy was already called, we will allow it
-       to be destroyed */
-    if (s->destroy_counter != s->activity_counter)
-        must_destroy = 0;
-
-    /* only if there are no active Z39.50 clients we will allow it to be
-       destroyed */
-    if (session_active_clients(s->psession))
-        must_destroy = 0;
-
-    s->destroy_counter = s->activity_counter = 0;
-    if (must_destroy)
-    {
+    /* only if http_session has no active http sessions on it can be destroyed */
+    if (s->destroy_counter == s->activity_counter) {
         struct http_session **p = 0;
+        must_destroy = 1;
         for (p = &http_sessions->session_list; *p; p = &(*p)->next)
             if (*p == s)
             {
@@ -157,11 +152,16 @@ void http_session_destroy(struct http_session *s)
     yaz_mutex_leave(http_sessions->mutex);
     if (must_destroy)
     {   /* destroying for real */
-        yaz_log(YLOG_LOG, "Destroying session %u", s->session_id);
+        yaz_log(http_sessions->log_level, "%p Session %u destroyed", s, s->session_id);
         iochan_destroy(s->timeout_iochan);
         destroy_session(s->psession);
         nmem_destroy(s->nmem);
     }
+    else {
+        yaz_log(http_sessions->log_level, "%p Session %u destroyed delayed. Active clients (%d-%d). Waiting for new timeout.", 
+                s, s->session_id, s->activity_counter, s->destroy_counter);
+    }
+
 }
 
 static const char *get_msg(enum pazpar2_error_code code)
@@ -279,6 +279,15 @@ static struct http_session *locate_session(struct http_channel *c)
     return p;
 }
 
+// Call after use of locate_session, in order to increment the destroy_counter
+static void release_session(struct http_channel *c, struct http_session *session) {
+    http_sessions_t http_sessions = c->http_sessions;
+    yaz_mutex_enter(http_sessions->mutex);
+    if (session)
+        session->destroy_counter++;
+    yaz_mutex_leave(http_sessions->mutex);
+}
+
 // Decode settings parameters and apply to session
 // Syntax: setting[target]=value
 static int process_settings(struct session *se, struct http_request *rq,
@@ -356,21 +365,20 @@ static void cmd_init(struct http_channel *c)
             return;
         }
     }
-    s = http_session_create(service, c->http_sessions);
+    sesid = make_sessionid();
+    s = http_session_create(service, c->http_sessions, sesid);
     
-    yaz_log(YLOG_DEBUG, "HTTP Session init");
+    yaz_log(c->http_sessions->log_level, "%p Session init %u ", s, sesid);
     if (!clear || *clear == '0')
         session_init_databases(s->psession);
     else
-        yaz_log(YLOG_LOG, "No databases preloaded");
+        yaz_log(YLOG_LOG, "HTTP Session %u init: No databases preloaded", sesid);
     
-    sesid = make_sessionid();
-    s->session_id = sesid;
     if (process_settings(s->psession, c->request, c->response) < 0)
         return;
     
     sprintf(buf, HTTP_COMMAND_RESPONSE_PREFIX 
-            "<init><status>OK</status><session>%u", sesid);
+            "<init><status>OK</status><session>%d", sesid);
     if (c->server->server_id)
     {
         strcat(buf, ".");
@@ -418,10 +426,13 @@ static void cmd_settings(struct http_channel *c)
 
         xmlFreeDoc(doc);
     }
-    if (process_settings(s->psession, rq, rs) < 0)
+    if (process_settings(s->psession, rq, rs) < 0) {
+        release_session(c,s);
         return;
+    }
     rs->payload = HTTP_COMMAND_RESPONSE_PREFIX "<settings><status>OK</status></settings>";
     http_send_response(c);
+    release_session(c,s);
 }
 
 // Compares two hitsbytarget nodes by hitcount
@@ -433,7 +444,7 @@ static int cmp_ht(const void *p1, const void *p2)
 }
 
 // This implements functionality somewhat similar to 'bytarget', but in a termlist form
-static void targets_termlist(WRBUF wrbuf, struct session *se, int num,
+static int targets_termlist(WRBUF wrbuf, struct session *se, int num,
                              NMEM nmem)
 {
     struct hitsbytarget *ht;
@@ -470,6 +481,7 @@ static void targets_termlist(WRBUF wrbuf, struct session *se, int num,
                      ht[i].diagnostic);
         wrbuf_puts(wrbuf, "</term>\n");
     }
+    return count;
 }
 
 static void cmd_termlist(struct http_channel *c)
@@ -484,6 +496,7 @@ static void cmd_termlist(struct http_channel *c)
     const char *nums = http_argbyname(rq, "num");
     int num = 15;
     int status;
+    WRBUF debug_log = wrbuf_alloc();
 
     if (!s)
         return;
@@ -510,16 +523,19 @@ static void cmd_termlist(struct http_channel *c)
             tp = name + strlen(name);
         strncpy(tname, name, tp - name);
         tname[tp - name] = '\0';
-
         wrbuf_puts(c->wrbuf, "<list name=\"");
         wrbuf_xmlputs(c->wrbuf, tname);
         wrbuf_puts(c->wrbuf, "\">\n");
-        if (!strcmp(tname, "xtargets"))
-            targets_termlist(c->wrbuf, s->psession, num, c->nmem);
+        if (!strcmp(tname, "xtargets")) {
+            int targets = targets_termlist(c->wrbuf, s->psession, num, c->nmem);
+            wrbuf_printf(debug_log, " xtargets: %d", targets);
+        }
         else
         {
             p = termlist(s->psession, tname, &len);
-            if (p)
+            if (p && len)
+                wrbuf_printf(debug_log, " %s: %d", tname, len);
+            if (p) {
                 for (i = 0; i < len && i < num; i++){
                     // prevnt sending empty term elements
                     if (!p[i]->term || !p[i]->term[0])
@@ -535,6 +551,7 @@ static void cmd_termlist(struct http_channel *c)
                                  p[i]->frequency);
                     wrbuf_puts(c->wrbuf, "</term>\n");
                }
+            }
         }
         wrbuf_puts(c->wrbuf, "</list>\n");
         name = tp;
@@ -542,8 +559,11 @@ static void cmd_termlist(struct http_channel *c)
             name++;
     }
     wrbuf_puts(c->wrbuf, "</termlist>\n");
+    yaz_log(YLOG_DEBUG, "termlist response: %s ", wrbuf_cstr(debug_log));
+    wrbuf_destroy(debug_log);
     rs->payload = nmem_strdup(rq->channel->nmem, wrbuf_cstr(c->wrbuf));
     http_send_response(c);
+    release_session(c,s);
 }
 
 
@@ -597,6 +617,7 @@ static void cmd_bytarget(struct http_channel *c)
     wrbuf_puts(c->wrbuf, "</bytarget>");
     rs->payload = nmem_strdup(c->nmem, wrbuf_cstr(c->wrbuf));
     http_send_response(c);
+    release_session(c,s);
 }
 
 static void write_metadata(WRBUF w, struct conf_service *service,
@@ -739,6 +760,7 @@ static void cmd_record(struct http_channel *c)
         {
             error(rs, PAZPAR2_RECORD_MISSING, idstr);
         }
+        release_session(c, s);
         return;
     }
     if (offsetstr)
@@ -806,6 +828,7 @@ static void cmd_record(struct http_channel *c)
         http_send_response(c);
     }
     show_single_stop(s->psession, rec);
+    release_session(c, s);
 }
 
 static void cmd_record_ready(void *data)
@@ -847,6 +870,7 @@ static void show_records(struct http_channel *c, int active)
     if (!(sp = reclist_parse_sortparms(c->nmem, sort, s->psession->service)))
     {
         error(rs, PAZPAR2_MALFORMED_PARAMETER_VALUE, "sort");
+        release_session(c, s);
         return;
     }
 
@@ -888,6 +912,7 @@ static void show_records(struct http_channel *c, int active)
     wrbuf_puts(c->wrbuf, "</show>\n");
     rs->payload = nmem_strdup(c->nmem, wrbuf_cstr(c->wrbuf));
     http_send_response(c);
+    release_session(c, s);
 }
 
 static void show_records_ready(void *data)
@@ -917,13 +942,14 @@ static void cmd_show(struct http_channel *c)
             if (session_set_watch(s->psession, SESSION_WATCH_SHOW,
                                   show_records_ready, c, c) != 0)
             {
-                yaz_log(YLOG_DEBUG, "Blocking on cmd_show");
+                yaz_log(c->http_sessions->log_level, "%p Session %u: Blocking on cmd_show", s, s->session_id);
             }
+            release_session(c,s);
             return;
         }
     }
-
     show_records(c, status);
+    release_session(c,s);
 }
 
 static void cmd_ping(struct http_channel *c)
@@ -934,6 +960,7 @@ static void cmd_ping(struct http_channel *c)
         return;
     rs->payload = HTTP_COMMAND_RESPONSE_PREFIX "<ping><status>OK</status></ping>";
     http_send_response(c);
+    release_session(c, s);
 }
 
 static int utf_8_valid(const char *str)
@@ -978,21 +1005,25 @@ static void cmd_search(struct http_channel *c)
     if (!query)
     {
         error(rs, PAZPAR2_MISSING_PARAMETER, "query");
+        release_session(c,s);
         return;
     }
     if (!utf_8_valid(query))
     {
         error(rs, PAZPAR2_MALFORMED_PARAMETER_ENCODING, "query");
+        release_session(c,s);
         return;
     }
     code = search(s->psession, query, startrecs, maxrecs, filter, &addinfo);
     if (code)
     {
         error(rs, code, addinfo);
+        release_session(c,s);
         return;
     }
     rs->payload = HTTP_COMMAND_RESPONSE_PREFIX "<search><status>OK</status></search>";
     http_send_response(c);
+    release_session(c,s);
 }
 
 
@@ -1031,6 +1062,7 @@ static void cmd_stat(struct http_channel *c)
     wrbuf_puts(c->wrbuf, "</stat>");
     rs->payload = nmem_strdup(c->nmem, wrbuf_cstr(c->wrbuf));
     http_send_response(c);
+    release_session(c,s);
 }
 
 static void cmd_info(struct http_channel *c)