Fixed serious bug regarding timeouts. Improved logging for proxy.

diff --git a/include/yaz-proxy.h b/include/yaz-proxy.h
index 8fbbb71..128d3b7 100644 (file)
--- a/include/yaz-proxy.h
+++ b/include/yaz-proxy.h
@@ -3,7 +3,7 @@
  * See the file LICENSE for details.
  * Sebastian Hammer, Adam Dickmeiss
  * 
- * $Id: yaz-proxy.h,v 1.10 2000-07-04 13:48:49 adam Exp $
+ * $Id: yaz-proxy.h,v 1.11 2000-08-07 14:19:59 adam Exp $
  */
 
 #include <yaz-z-assoc.h>
@@ -50,6 +50,8 @@ class YAZ_EXPORT Yaz_Proxy : public Yaz_Z_Assoc {
     int m_max_clients;
     int m_keepalive;
     char *m_proxyTarget;
+    char *m_APDU_fname;
+    long m_seed;
  public:
     Yaz_Proxy(IYaz_PDU_Observable *the_PDU_Observable);
     ~Yaz_Proxy();

diff --git a/include/yaz-z-assoc.h b/include/yaz-z-assoc.h
index 4a47d68..fdca6b4 100644 (file)
--- a/include/yaz-z-assoc.h
+++ b/include/yaz-z-assoc.h
@@ -3,7 +3,7 @@
  * See the file LICENSE for details.
  * Sebastian Hammer, Adam Dickmeiss
  * 
- * $Id: yaz-z-assoc.h,v 1.6 2000-05-10 11:36:58 ian Exp $
+ * $Id: yaz-z-assoc.h,v 1.7 2000-08-07 14:19:59 adam Exp $
  */
 
 #include <yaz/proto.h>
@@ -51,6 +51,9 @@ class YAZ_EXPORT Yaz_Z_Assoc : public IYaz_PDU_Observer {
     ODR odr_decode ();
     ODR odr_print ();
 
+    void set_APDU_log(const char *fname);
+    const char *get_APDU_log();
+
     /// OtherInformation
     void get_otherInfoAPDU(Z_APDU *apdu, Z_OtherInformation ***oip);
     Z_OtherInformationUnit *update_otherInformation (
@@ -68,10 +71,11 @@ class YAZ_EXPORT Yaz_Z_Assoc : public IYaz_PDU_Observer {
        Z_APDU *apdu,
        int oidval, int categoryValue,
        const char *str);
-    void set_apdu_log(const char *file);
 
     Z_ReferenceId* getRefID(char* str);
 
+    const char *get_hostname();
+
  private:
     static int yaz_init_flag;
     static int yaz_init_func();
@@ -80,4 +84,7 @@ class YAZ_EXPORT Yaz_Z_Assoc : public IYaz_PDU_Observer {
     ODR m_odr_out;
     ODR m_odr_print;
     int m_log;
+    FILE *m_APDU_file;
+    char *m_APDU_fname;
+    char *m_hostname;
 };

diff --git a/src/yaz-proxy-main.cpp b/src/yaz-proxy-main.cpp
index 17d3eb1..6d98175 100644 (file)
--- a/src/yaz-proxy-main.cpp
+++ b/src/yaz-proxy-main.cpp
@@ -4,7 +4,10 @@
  * Sebastian Hammer, Adam Dickmeiss
  * 
  * $Log: yaz-proxy-main.cpp,v $
- * Revision 1.8  2000-07-04 13:48:49  adam
+ * Revision 1.9  2000-08-07 14:19:59  adam
+ * Fixed serious bug regarding timeouts. Improved logging for proxy.
+ *
+ * Revision 1.8  2000/07/04 13:48:49  adam
  * Implemented upper-limit on proxy-to-target sessions.
  *
  * Revision 1.7  1999/12/06 13:52:45  adam
@@ -42,7 +45,7 @@
 
 void usage(char *prog)
 {
-    fprintf (stderr, "%s: [-c num] [-v log] [-t target] @:port\n", prog);
+    fprintf (stderr, "%s: [-a log] [-c num] [-v level] [-t target] @:port\n", prog);
     exit (1);
 }
 
@@ -54,7 +57,7 @@ int args(Yaz_Proxy *proxy, int argc, char **argv)
     char *prog = argv[0];
     int ret;
 
-    while ((ret = options("t:v:c:", argv, argc, &arg)) != -2)
+    while ((ret = options("a:t:v:c:", argv, argc, &arg)) != -2)
     {
         switch (ret)
         {
@@ -66,6 +69,9 @@ int args(Yaz_Proxy *proxy, int argc, char **argv)
            }
            addr = arg;
             break;
+       case 'a':
+           proxy->set_APDU_log(arg);
+           break;
         case 't':
            proxy->set_proxyTarget(arg);
            break;

diff --git a/src/yaz-proxy.cpp b/src/yaz-proxy.cpp
index 7cdbe93..f97f485 100644 (file)
--- a/src/yaz-proxy.cpp
+++ b/src/yaz-proxy.cpp
@@ -4,7 +4,10 @@
  * Sebastian Hammer, Adam Dickmeiss
  * 
  * $Log: yaz-proxy.cpp,v $
- * Revision 1.12  2000-07-04 13:48:49  adam
+ * Revision 1.13  2000-08-07 14:19:59  adam
+ * Fixed serious bug regarding timeouts. Improved logging for proxy.
+ *
+ * Revision 1.12  2000/07/04 13:48:49  adam
  * Implemented upper-limit on proxy-to-target sessions.
  *
  * Revision 1.11  1999/12/06 13:52:45  adam
@@ -48,6 +51,7 @@
  */
 
 #include <assert.h>
+#include <time.h>
 
 #include <yaz/log.h>
 #include <yaz-proxy.h>
@@ -62,7 +66,9 @@ Yaz_Proxy::Yaz_Proxy(IYaz_PDU_Observable *the_PDU_Observable) :
     m_seqno = 1;
     m_keepalive = 1;
     m_proxyTarget = 0;
-    m_max_clients = 20;
+    m_max_clients = 50;
+    m_APDU_fname = 0;
+    m_seed = time(0);
 }
 
 Yaz_Proxy::~Yaz_Proxy()
@@ -70,7 +76,6 @@ Yaz_Proxy::~Yaz_Proxy()
     xfree (m_proxyTarget);
 }
 
-
 void Yaz_Proxy::set_proxyTarget(const char *target)
 {
     xfree (m_proxyTarget);
@@ -86,6 +91,7 @@ IYaz_PDU_Observer *Yaz_Proxy::clone(IYaz_PDU_Observable
     new_proxy->m_parent = this;
     new_proxy->timeout(120);
     new_proxy->set_proxyTarget(m_proxyTarget);
+    new_proxy->set_APDU_log(get_APDU_log());
     return new_proxy;
 }
 
@@ -140,7 +146,8 @@ Yaz_ProxyClient *Yaz_Proxy::get_client(Z_APDU *apdu)
            assert (*c->m_prev == c);
            if (!strcmp(cookie,c->m_cookie))
            {
-               logf (LOG_LOG, "Yaz_Proxy::get_client found cached target");
+               logf (LOG_LOG, "Yaz_Proxy::get_client cached %s",
+                     c->get_hostname());
                c->m_seqno = parent->m_seqno;
                return c;
            }
@@ -191,7 +198,8 @@ Yaz_ProxyClient *Yaz_Proxy::get_client(Z_APDU *apdu)
        }
        else
        {
-           logf (LOG_LOG, "Yaz_Proxy::get_client making new session");
+           logf (LOG_LOG, "Yaz_Proxy::get_client making session %d",
+                 parent->m_seqno);
            c = new Yaz_ProxyClient(m_PDU_Observable->clone());
            c->m_next = parent->m_clientPool;
            if (c->m_next)
@@ -199,8 +207,8 @@ Yaz_ProxyClient *Yaz_Proxy::get_client(Z_APDU *apdu)
            parent->m_clientPool = c;
            c->m_prev = &parent->m_clientPool;
        }
-       sprintf (c->m_cookie, "%d", parent->m_seqno);
-       logf (LOG_LOG, "Yaz_Proxy::get_client new session %s", c->m_cookie);
+       sprintf (c->m_cookie, "%lx.%d", m_seed, parent->m_seqno);
+       logf (LOG_LOG, "Yaz_Proxy::get_client connect to %s", m_proxyTarget);
        c->m_seqno = parent->m_seqno;
        c->client(m_proxyTarget);
        c->m_init_flag = 0;
@@ -234,6 +242,7 @@ Z_APDU *Yaz_Proxy::result_set_optimize(Z_APDU *apdu)
            m_client->m_last_resultCount < *sr->largeSetLowerBound)
        {
            // medium Set
+           logf (LOG_LOG, "Yaz_Proxy::result_set_optimize medium set");
            Z_APDU *new_apdu = create_Z_PDU(Z_APDU_presentRequest);
            Z_PresentRequest *pr = new_apdu->u.presentRequest;
            pr->referenceId = sr->referenceId;
@@ -254,6 +263,7 @@ Z_APDU *Yaz_Proxy::result_set_optimize(Z_APDU *apdu)
            m_client->m_last_resultCount == 0)
        {
            // large set
+           logf (LOG_LOG, "Yaz_Proxy::result_set_optimize large set");
            Z_APDU *new_apdu = create_Z_PDU(Z_APDU_searchResponse);
            new_apdu->u.searchResponse->referenceId = sr->referenceId;
            new_apdu->u.searchResponse->resultCount =
@@ -264,6 +274,7 @@ Z_APDU *Yaz_Proxy::result_set_optimize(Z_APDU *apdu)
        else
        {
            // small set
+           logf (LOG_LOG, "Yaz_Proxy::result_set_optimize small set");
            Z_APDU *new_apdu = create_Z_PDU(Z_APDU_presentRequest);
            Z_PresentRequest *pr = new_apdu->u.presentRequest;
            pr->referenceId = sr->referenceId;
@@ -283,7 +294,7 @@ Z_APDU *Yaz_Proxy::result_set_optimize(Z_APDU *apdu)
     }
     else
     {
-       logf (LOG_LOG, "query doesn't match");
+       logf (LOG_LOG, "Yaz_Proxy::result_set_optimize new set");
        delete m_client->m_last_query;
        m_client->m_last_query = this_query;
     }
@@ -325,7 +336,7 @@ void Yaz_Proxy::recv_Z_PDU(Z_APDU *apdu)
     if (!apdu)
        return;
 
-    logf (LOG_LOG, "Yaz_ProxyClient::send_Z_PDU");
+    logf (LOG_LOG, "Yaz_ProxyClient::send_Z_PDU %s", m_client->get_hostname());
     if (m_client->send_Z_PDU(apdu) < 0)
     {
        delete m_client;
@@ -355,7 +366,7 @@ void Yaz_Proxy::shutdown()
 
 void Yaz_ProxyClient::shutdown()
 {
-    logf (LOG_LOG, "shutdown (proxy to server)");
+    logf (LOG_LOG, "shutdown (proxy to server) %s", get_hostname());
     delete m_server;
     delete this;
 }
@@ -368,13 +379,13 @@ void Yaz_Proxy::failNotify()
 
 void Yaz_ProxyClient::failNotify()
 {
-    logf (LOG_LOG, "connection closed by target");
+    logf (LOG_LOG, "Yaz_ProxyClient connection closed by %s", get_hostname());
     shutdown();
 }
 
 void Yaz_ProxyClient::connectNotify()
 {
-    logf (LOG_LOG, "connection accepted by target");
+    logf (LOG_LOG, "Yaz_ProxyClient connection accept by %s", get_hostname());
 }
 
 IYaz_PDU_Observer *Yaz_ProxyClient::clone(IYaz_PDU_Observable
@@ -402,7 +413,7 @@ void Yaz_Proxy::timeoutNotify()
 
 void Yaz_ProxyClient::timeoutNotify()
 {
-    logf (LOG_LOG, "timeout (proxy to target)");
+    logf (LOG_LOG, "timeout (proxy to target) %s", get_hostname());
     shutdown();
 }
 
@@ -420,7 +431,7 @@ Yaz_ProxyClient::Yaz_ProxyClient(IYaz_PDU_Observable *the_PDU_Observable) :
 
 void Yaz_ProxyClient::recv_Z_PDU(Z_APDU *apdu)
 {
-    logf (LOG_LOG, "Yaz_ProxyClient::recv_Z_PDU");
+    logf (LOG_LOG, "Yaz_ProxyClient::recv_Z_PDU %s", get_hostname());
     if (apdu->which == Z_APDU_searchResponse)
        m_last_resultCount = *apdu->u.searchResponse->resultCount;
     if (apdu->which == Z_APDU_presentResponse && m_sr_transform)

diff --git a/src/yaz-socket-manager.cpp b/src/yaz-socket-manager.cpp
index 099ec76..dd61fb1 100644 (file)
--- a/src/yaz-socket-manager.cpp
+++ b/src/yaz-socket-manager.cpp
@@ -4,7 +4,10 @@
  * Sebastian Hammer, Adam Dickmeiss
  * 
  * $Log: yaz-socket-manager.cpp,v $
- * Revision 1.8  1999-12-06 13:52:45  adam
+ * Revision 1.9  2000-08-07 14:19:59  adam
+ * Fixed serious bug regarding timeouts. Improved logging for proxy.
+ *
+ * Revision 1.8  1999/12/06 13:52:45  adam
  * Modified for new location of YAZ header files. Experimental threaded
  * operation.
  *
@@ -206,9 +209,12 @@ int Yaz_SocketManager::processEvent()
            event->event = mask;
            putEvent (event);
        }
-       else if (p->timeout && now >= p->last_activity + (int) (p->timeout))
+       else if (p->timeout && p->last_activity && 
+                now >= p->last_activity + (int) (p->timeout))
        {
            YazSocketEvent *event = new YazSocketEvent;
+           logf (LOG_LOG, "timeout now = %ld last_activity=%ld timeout=%d",
+                 now, p->last_activity, p->timeout);
            p->last_activity = now;
            event->observer = p->observer;
            event->event = YAZ_SOCKET_OBSERVE_TIMEOUT;

diff --git a/src/yaz-z-assoc.cpp b/src/yaz-z-assoc.cpp
index 198a3f3..c3ffcf7 100644 (file)
--- a/src/yaz-z-assoc.cpp
+++ b/src/yaz-z-assoc.cpp
@@ -4,7 +4,10 @@
  * Sebastian Hammer, Adam Dickmeiss
  * 
  * $Log: yaz-z-assoc.cpp,v $
- * Revision 1.7  2000-05-10 11:36:58  ian
+ * Revision 1.8  2000-08-07 14:19:59  adam
+ * Fixed serious bug regarding timeouts. Improved logging for proxy.
+ *
+ * Revision 1.7  2000/05/10 11:36:58  ian
  * Added default parameters for refid to request functions.
  * Added default parameter for result set name to search and present request.
  * Commented out forced logging of PDU contents.
@@ -55,6 +58,37 @@ Yaz_Z_Assoc::Yaz_Z_Assoc(IYaz_PDU_Observable *the_PDU_Observable)
     m_odr_out = odr_createmem (ODR_ENCODE);
     m_odr_print = odr_createmem (ODR_PRINT);
     m_log = LOG_DEBUG;
+    m_APDU_file = 0;
+    m_APDU_fname = 0;
+    m_hostname = 0;
+}
+
+void Yaz_Z_Assoc::set_APDU_log(const char *fname)
+{
+    if (m_APDU_file && m_APDU_file != stderr)
+       fclose (m_APDU_file);
+    m_APDU_file = 0;
+    delete [] m_APDU_fname;
+    m_APDU_fname = 0;
+
+    if (fname)
+    {
+       m_APDU_fname = new char[strlen(fname)+1];
+       strcpy (m_APDU_fname, fname);
+    }
+    if (fname)
+    {
+       if (*fname)
+           m_APDU_file = fopen (fname, "a");
+       else
+           m_APDU_file = stderr;
+       odr_setprint(m_odr_print, m_APDU_file);
+    }
+}
+
+const char *Yaz_Z_Assoc::get_APDU_log()
+{
+    return m_APDU_fname;
 }
 
 Yaz_Z_Assoc::~Yaz_Z_Assoc()
@@ -64,6 +98,10 @@ Yaz_Z_Assoc::~Yaz_Z_Assoc()
     odr_destroy (m_odr_print);
     odr_destroy (m_odr_out);
     odr_destroy (m_odr_in);
+    delete [] m_APDU_fname;
+    if (m_APDU_file && m_APDU_file != stderr)
+       fclose (m_APDU_file);
+    delete [] m_hostname;
 }
 
 void Yaz_Z_Assoc::recv_PDU(const char *buf, int len)
@@ -117,7 +155,8 @@ Z_APDU *Yaz_Z_Assoc::decode_Z_PDU(const char *buf, int len)
     }
     else
     {
-       // z_APDU(m_odr_print, &apdu, 0, "decode");
+       if (m_APDU_file)
+           z_APDU(m_odr_print, &apdu, 0, "decode");
         return apdu;
     }
 }
@@ -129,14 +168,23 @@ int Yaz_Z_Assoc::encode_Z_PDU(Z_APDU *apdu, char **buf, int *len)
        logf (LOG_LOG, "yaz_Z_Assoc::encode_Z_PDU failed");
         return -1;
     }
-    // z_APDU(m_odr_print, &apdu, 0, "encode");
+    if (m_APDU_file)
+       z_APDU(m_odr_print, &apdu, 0, "encode");
     *buf = odr_getbuf (m_odr_out, len, 0);
     odr_reset (m_odr_out);
     return *len;
 }
 
+const char *Yaz_Z_Assoc::get_hostname()
+{
+    return m_hostname;
+}
+
 void Yaz_Z_Assoc::client(const char *addr)
 {
+    delete [] m_hostname;
+    m_hostname = new char[strlen(addr)+1];
+    strcpy (m_hostname, addr);
     m_PDU_Observable->connect (this, addr);
 }
 
@@ -147,6 +195,9 @@ void Yaz_Z_Assoc::close()
 
 void Yaz_Z_Assoc::server(const char *addr)
 {
+    delete [] m_hostname;
+    m_hostname = new char[strlen(addr)+1];
+    strcpy (m_hostname, addr);
     m_PDU_Observable->listen (this, addr);
 }
 
@@ -169,7 +220,6 @@ void Yaz_Z_Assoc::timeout(int timeout)
     m_PDU_Observable->idleTime(timeout);
 }
 
-
 void Yaz_Z_Assoc::get_otherInfoAPDU(Z_APDU *apdu, Z_OtherInformation ***oip)
 {
     switch (apdu->which)