Improved logging for record ingestion failures
[pazpar2-moved-to-github.git] / src / client.c
index 9033a34..c12b84f 100644 (file)
@@ -33,6 +33,9 @@ Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA  02110-1301  USA
 #if HAVE_UNISTD_H
 #include <unistd.h>
 #endif
+#ifdef WIN32
+#include <windows.h>
+#endif
 #include <signal.h>
 #include <assert.h>
 
@@ -579,17 +582,18 @@ static void client_record_ingest(struct client *cl)
     const char *msg, *addinfo;
     ZOOM_record rec = 0;
     ZOOM_resultset resultset = cl->resultset;
-    int offset = cl->record_offset;
-    if ((rec = ZOOM_resultset_record_immediate(resultset, offset)))
+    struct session *se = client_get_session(cl);
+
+    if ((rec = ZOOM_resultset_record_immediate(resultset, cl->record_offset)))
     {
-        cl->record_offset++;
+        int offset = ++cl->record_offset;
         if (cl->session == 0) {
             /* no operation */
         }
         else if (ZOOM_record_error(rec, &msg, &addinfo, 0))
         {
-            yaz_log(YLOG_WARN, "Record error %s (%s): %s (rec #%d)",
-                    msg, addinfo, client_get_id(cl), cl->record_offset);
+            session_log(se, YLOG_WARN, "Record error %s (%s): %s #%d",
+                        msg, addinfo, client_get_id(cl), offset);
         }
         else
         {
@@ -600,17 +604,33 @@ static void client_record_ingest(struct client *cl)
 
             const char *s = session_setting_oneval(sdb, PZ_NATIVESYNTAX);
             if (nativesyntax_to_type(s, type, rec))
-                yaz_log(YLOG_WARN, "Failed to determine record type");
+                session_log(se, YLOG_WARN, "Failed to determine record type");
             xmlrec = ZOOM_record_get(rec, type, NULL);
             if (!xmlrec)
-                yaz_log(YLOG_WARN, "ZOOM_record_get failed from %s",
-                        client_get_id(cl));
+            {
+                const char *rec_syn =  ZOOM_record_get(rec, "syntax", NULL);
+                session_log(se, YLOG_WARN, "ZOOM_record_get failed from %s #%d",
+                            client_get_id(cl), offset);
+                session_log(se, YLOG_LOG, "pz:nativesyntax=%s . "
+                            "ZOOM record type=%s . Actual record syntax=%s",
+                            s ? s : "null", type,
+                            rec_syn ? rec_syn : "null");
+            }
             else
             {
                 /* OK = 0, -1 = failure, -2 = Filtered */
                 int rc = ingest_record(cl, xmlrec, cl->record_offset, nmem);
                 if (rc == -1)
-                    yaz_log(YLOG_WARN, "Failed to ingest from %s", client_get_id(cl));
+                {
+                    const char *rec_syn =  ZOOM_record_get(rec, "syntax", NULL);
+                    session_log(se, YLOG_WARN,
+                                "Failed to ingest record from %s #%d",
+                                client_get_id(cl), offset);
+                    session_log(se, YLOG_LOG, "pz:nativesyntax=%s . "
+                                "ZOOM record type=%s . Actual record syntax=%s",
+                                s ? s : "null", type,
+                                rec_syn ? rec_syn : "null");
+                }
                 if (rc == -2)
                     cl->filtered += 1;
             }
@@ -619,7 +639,8 @@ static void client_record_ingest(struct client *cl)
     }
     else
     {
-        yaz_log(YLOG_WARN, "Expected record, but got NULL, offset=%d", offset);
+        session_log(se, YLOG_WARN, "Got NULL record from %s #%d",
+                    client_get_id(cl), cl->record_offset);
     }
 }
 
@@ -969,6 +990,8 @@ int client_destroy(struct client *c)
             xfree(c->addinfo);
             c->addinfo = 0;
             xfree(c->id);
+            xfree(c->sort_strategy);
+            xfree(c->sort_criteria);
             assert(!c->connection);
             facet_limits_destroy(c->facet_limits);
 
@@ -1224,8 +1247,9 @@ static int apply_limit(struct session_database *sdb,
 }
 
 // Parse the query given the settings specific to this client
-// return 0 if query is OK but different from before
-// return 1 if query is OK but same as before
+// client variable same_search is set as below as well as returned:
+// 0 if query is OK but different from before
+// 1 if query is OK but same as before
 // return -1 on query error
 // return -2 on limit error
 int client_parse_query(struct client *cl, const char *query,
@@ -1268,7 +1292,7 @@ int client_parse_query(struct client *cl, const char *query,
     facet_limits_destroy(cl->facet_limits);
     cl->facet_limits = facet_limits_dup(facet_limits);
 
-    yaz_log(YLOG_LOG, "Client %s: CCL query: %s limit: %s", client_get_id(cl), wrbuf_cstr(w_ccl), wrbuf_cstr(w_pdf));
+    yaz_log(YLOG_LOG, "Client %s: CCL query: %s limit: %s", client_get_id(cl), wrbuf_cstr(w_ccl), wrbuf_cstr(w_pqf));
     cn = ccl_find_str(ccl_map, wrbuf_cstr(w_ccl), &cerror, &cpos);
     ccl_qual_rm(&ccl_map);
     if (!cn)
@@ -1307,9 +1331,15 @@ int client_parse_query(struct client *cl, const char *query,
     /* Compares query and limit with old one. If different we need to research */
     if (!cl->pquery || strcmp(cl->pquery, wrbuf_cstr(w_pqf)))
     {
+        if (cl->pquery)
+            session_log(se, YLOG_LOG, "Client %s: Re-search due query/limit change: %s to %s", 
+                        client_get_id(cl), cl->pquery, wrbuf_cstr(w_pqf));
         xfree(cl->pquery);
         cl->pquery = xstrdup(wrbuf_cstr(w_pqf));
+        // return value is no longer used.
         ret_value = 0;
+        // Need to (re)search
+        cl->same_search= 0;
     }
     wrbuf_destroy(w_pqf);
 
@@ -1339,6 +1369,9 @@ int client_parse_query(struct client *cl, const char *query,
                 cl->cqlquery = make_cqlquery(cl, zquery);
             if (!cl->cqlquery)
                 ret_value = -1;
+            else
+                session_log(se, YLOG_LOG, "Client %s native query: %s (%s)",
+                            client_get_id(cl), cl->cqlquery, sru);
         }
     }
     odr_destroy(odr_out);
@@ -1359,14 +1392,11 @@ int client_parse_query(struct client *cl, const char *query,
 
 int client_parse_sort(struct client *cl, struct reclist_sortparms *sp)
 {
-    struct session *se = client_get_session(cl);
     if (sp)
-    {   /* first entry is current sorting ! */
+    {
         const char *sort_strategy_and_spec =
-            get_strategy_plus_sort(cl, se->sorted_results->name);
-
-        int increasing = se->sorted_results->increasing;
-        // int type = se->sorted_results->type;
+            get_strategy_plus_sort(cl, sp->name);
+        int increasing = sp->increasing;
         if (sort_strategy_and_spec && strlen(sort_strategy_and_spec) < 40)
         {
             char strategy[50], *p;
@@ -1388,23 +1418,29 @@ int client_parse_sort(struct client *cl, struct reclist_sortparms *sp)
                 if (!cl->sort_criteria || strcmp(cl->sort_criteria, p))
                     cl->same_search = 0;
                 if (cl->same_search == 0) {
-                    cl->sort_strategy  = nmem_strdup(se->nmem, strategy);
-                    cl->sort_criteria = nmem_strdup(se->nmem, p);
+                    xfree(cl->sort_strategy);
+                    cl->sort_strategy = xstrdup(strategy);
+                    xfree(cl->sort_criteria);
+                    cl->sort_criteria = xstrdup(p);
                 }
             }
             else {
                 yaz_log(YLOG_LOG, "Client %s: Invalid sort strategy and spec found %s", client_get_id(cl), sort_strategy_and_spec);
+                xfree(cl->sort_strategy);
                 cl->sort_strategy  = 0;
+                xfree(cl->sort_criteria);
                 cl->sort_criteria = 0;
             }
         } else {
-            yaz_log(YLOG_LOG, "Client %s: No sort strategy and spec found.", client_get_id(cl));
+            yaz_log(YLOG_DEBUG, "Client %s: No sort strategy and spec found.", client_get_id(cl));
+            xfree(cl->sort_strategy);
             cl->sort_strategy  = 0;
+            xfree(cl->sort_criteria);
             cl->sort_criteria = 0;
         }
 
     }
-    return cl->same_search;
+    return !cl->same_search;
 }
 
 void client_set_session(struct client *cl, struct session *se)