Fixed timeout bug for SRW/SRU operation : Could occur if XSLT
[yazproxy-moved-to-github.git] / src / yaz-proxy.cpp
index bf5fa4b..2c35be0 100644 (file)
@@ -1,4 +1,4 @@
-/* $Id: yaz-proxy.cpp,v 1.53 2006-04-12 11:30:52 adam Exp $
+/* $Id: yaz-proxy.cpp,v 1.63 2006-04-27 00:04:42 adam Exp $
    Copyright (c) 1998-2006, Index Data.
 
 This file is part of the yazproxy.
@@ -106,7 +106,7 @@ IMsg_Thread *Auth_Msg::handle()
 
 void Auth_Msg::result()
 {
-    if (m_proxy->dec_ref(false))
+    if (m_proxy->dec_ref())
     {
         yaz_log(YLOG_LOG, "Auth_Msg::proxy deleted meanwhile");
     }
@@ -131,7 +131,7 @@ void Yaz_Proxy::result_authentication(Z_APDU *apdu, int ret)
         Z_APDU *apdu_reject = zget_APDU(odr_encode(), Z_APDU_initResponse);
         *apdu_reject->u.initResponse->result = 0;
         send_to_client(apdu_reject);
-        dec_ref(false);
+        dec_ref();
     }
     else
     {
@@ -295,7 +295,6 @@ Yaz_Proxy::Yaz_Proxy(IPDU_Observable *the_PDU_Observable,
     m_ref_count = 1;
     m_main_ptr_dec = false;
     m_peername = 0;
-    m_initial_reduce = 0;
 }
 
 void Yaz_Proxy::inc_ref()
@@ -376,7 +375,7 @@ void Yaz_Proxy::set_default_target(const char *target)
 void Yaz_Proxy::set_proxy_negotiation (const char *charset, const char *lang,
                                        const char *default_charset)
 {
-    yaz_log(YLOG_LOG, "%sSet the proxy negotiation: charset to '%s', "
+    yaz_log(YLOG_DEBUG, "%sSet the proxy negotiation: charset to '%s', "
         "default charset to '%s', language to '%s'", m_session_str, 
         charset?charset:"none",
         default_charset?default_charset:"none",
@@ -434,35 +433,18 @@ IPDU_Observer *Yaz_Proxy::sessionNotify(IPDU_Observable
     char session_str[200];
     const char *peername = the_PDU_Observable->getpeername();
     if (m_log_mask & PROXY_LOG_IP_CLIENT)
-        sprintf(session_str, "%ld:%d %s 0 ",
-                (long) time(0), m_session_no, peername);
+        sprintf(session_str, "%ld:%d %.80s %d ",
+                (long) time(0), m_session_no, peername, 0);
     else
-        sprintf(session_str, "%ld:%d 0 ",
-                (long) time(0), m_session_no);        
+        sprintf(session_str, "%ld:%d %d ",
+                (long) time(0), m_session_no, 0);
     m_session_no++;
 
     yaz_log (YLOG_LOG, "%sNew session %s", session_str, peername);
 
-    m_connect.cleanup(false);
-    m_connect.add_connect(peername);
-
-    int connect_total = m_connect.get_total(peername);
-    int connect_max = m_max_connect;
-    if (connect_max && connect_total > connect_max)
-    {
-        yaz_log(YLOG_LOG, "%sconnect not accepted total=%d max=%d",
-                session_str, connect_total, connect_max);
-        return 0;
-    }
-    yaz_log(YLOG_LOG, "%sconnect accepted total=%d", session_str,
-            connect_total);
-    
     Yaz_Proxy *new_proxy = new Yaz_Proxy(the_PDU_Observable,
                                          m_socket_observable, this);
 
-    if (m_limit_connect)
-        new_proxy->m_initial_reduce = connect_total / m_limit_connect;
-
     new_proxy->m_config = 0;
     new_proxy->m_config_fname = 0;
     new_proxy->timeout(m_client_idletime);
@@ -470,8 +452,12 @@ IPDU_Observer *Yaz_Proxy::sessionNotify(IPDU_Observable
     new_proxy->set_default_target(m_default_target);
     new_proxy->m_max_clients = m_max_clients;
     new_proxy->m_log_mask = m_log_mask;
+
+    if (!strcmp(peername, "tcp:163.121.19.82")) // NIS GROUP
+        new_proxy->m_log_mask = 255;
+
     new_proxy->set_APDU_log(get_APDU_log());
-    if (m_log_mask & PROXY_LOG_APDU_CLIENT)
+    if (new_proxy->m_log_mask & PROXY_LOG_APDU_CLIENT)
         new_proxy->set_APDU_yazlog(1);
     else
         new_proxy->set_APDU_yazlog(0);
@@ -615,8 +601,14 @@ Yaz_ProxyClient *Yaz_Proxy::get_client(Z_APDU *apdu, const char *cookie,
             m_client_idletime = client_idletime;
             timeout(m_client_idletime);
         }
+
+        // get those FILE descriptors available 
+        m_parent->low_socket_close();
         if (cql2rpn_fname)
             m_cql2rpn.set_pqf_file(cql2rpn_fname);
+        // reserve them again
+        m_parent->low_socket_open();
+        
         if (negotiation_charset || negotiation_lang || default_client_query_charset)
         {
             set_proxy_negotiation(negotiation_charset,
@@ -748,7 +740,7 @@ Yaz_ProxyClient *Yaz_Proxy::get_client(Z_APDU *apdu, const char *cookie,
                 yaz_log (YLOG_LOG, "%sMAXCLIENTS %d Destroy %d",
                          m_session_str, parent->m_max_clients, c->m_seqno);
                 if (c->m_server && c->m_server != this)
-                    c->m_server->dec_ref(true);
+                    c->m_server->dec_ref();
             }
             else
             {
@@ -763,7 +755,7 @@ Yaz_ProxyClient *Yaz_Proxy::get_client(Z_APDU *apdu, const char *cookie,
                 if (c->m_server && c->m_server != this)
                 {
                     c->m_server->m_client = 0;
-                    c->m_server->dec_ref(true);
+                    c->m_server->dec_ref();
                 }
                 (parent->m_seqno)++;
                 c->m_target_idletime = m_target_idletime;
@@ -1625,8 +1617,21 @@ Z_APDU *Yaz_Proxy::result_set_optimize(Z_APDU *apdu)
         {
             Z_APDU *new_apdu = create_Z_PDU(Z_APDU_presentResponse);
             new_apdu->u.presentResponse->records =
-                create_nonSurrogateDiagnostics(odr_encode(), 30,
-                                               pr->resultSetId);
+                create_nonSurrogateDiagnostics(
+                    odr_encode(), 
+                    YAZ_BIB1_SPECIFIED_RESULT_SET_DOES_NOT_EXIST,
+                    pr->resultSetId);
+            send_to_client(new_apdu);
+            return 0;
+        }
+        if (start < 1 || toget < 0)
+        {
+            Z_APDU *new_apdu = create_Z_PDU(Z_APDU_presentResponse);
+            new_apdu->u.presentResponse->records =
+                create_nonSurrogateDiagnostics(
+                    odr_encode(), 
+                    YAZ_BIB1_PRESENT_REQUEST_OUT_OF_RANGE, 
+                    0);
             send_to_client(new_apdu);
             return 0;
         }
@@ -1636,7 +1641,10 @@ Z_APDU *Yaz_Proxy::result_set_optimize(Z_APDU *apdu)
             {
                 Z_APDU *new_apdu = create_Z_PDU(Z_APDU_presentResponse);
                 new_apdu->u.presentResponse->records =
-                    create_nonSurrogateDiagnostics(odr_encode(), 13, 0);
+                    create_nonSurrogateDiagnostics(
+                        odr_encode(), 
+                        YAZ_BIB1_PRESENT_REQUEST_OUT_OF_RANGE,
+                        0);
                 send_to_client(new_apdu);
                 return 0;
             }
@@ -1682,6 +1690,21 @@ Z_APDU *Yaz_Proxy::result_set_optimize(Z_APDU *apdu)
 
     this_query->set_Z_Query(sr->query);
 
+    // Check for non-negative piggyback params.
+    if (*sr->smallSetUpperBound < 0
+        || *sr->largeSetLowerBound < 0
+        || *sr->mediumSetPresentNumber < 0)
+    {
+        Z_APDU *new_apdu = create_Z_PDU(Z_APDU_searchResponse);
+        // Not a present request.. But can't find better diagnostic
+        new_apdu->u.searchResponse->records =
+            create_nonSurrogateDiagnostics(
+                odr_encode(), 
+                YAZ_BIB1_PRESENT_REQUEST_OUT_OF_RANGE, 0);
+        send_to_client(new_apdu);
+        return 0;
+    }
+
     char query_str[120];
     this_query->print(query_str, sizeof(query_str)-1);
     yaz_log(YLOG_LOG, "%sSearch %s", m_session_str, query_str);
@@ -1702,7 +1725,7 @@ Z_APDU *Yaz_Proxy::result_set_optimize(Z_APDU *apdu)
 
             if (toget > m_client->m_last_resultCount)
                 toget = m_client->m_last_resultCount;
-
+            
             if (sr->mediumSetElementSetNames)
             {
                 comp = (Z_RecordComposition *)
@@ -1842,6 +1865,7 @@ Z_APDU *Yaz_Proxy::result_set_optimize(Z_APDU *apdu)
 
 void Yaz_Proxy::inc_request_no()
 {
+    m_request_no++;
     char *cp = m_session_str + strlen(m_session_str)-1;
     if (*cp == ' ')
         cp--;
@@ -1861,6 +1885,25 @@ void Yaz_Proxy::recv_GDU(Z_GDU *apdu, int len)
         yaz_log (YLOG_LOG, "%sReceiving %s from client %d bytes",
                  m_session_str, gdu_name(apdu), len);
 
+#if 0
+    // try to make a _bad_ attribute set ID .. Don't enable this in prod.
+    if (apdu->which == Z_GDU_Z3950 
+        && apdu->u.z3950->which == Z_APDU_searchRequest)
+    {
+        Z_SearchRequest *req = apdu->u.z3950->u.searchRequest;
+        if (req->query && req->query->which == Z_Query_type_1)
+        {
+            Z_RPNQuery *rpnquery = req->query->u.type_1;
+            if (rpnquery->attributeSetId)
+            {
+                rpnquery->attributeSetId[0] = -2;
+                rpnquery->attributeSetId[1] = -1;
+                yaz_log(YLOG_WARN, "%sBAD FIXUP TEST", m_session_str);
+            }
+        }
+    }
+#endif
+
 #if HAVE_GETTIMEOFDAY
     gettimeofday((struct timeval *) m_time_tv, 0);
 #endif
@@ -1868,15 +1911,90 @@ void Yaz_Proxy::recv_GDU(Z_GDU *apdu, int len)
     m_pdu_stat.add_bytes(1);
 
     GDU *gdu = new GDU(apdu);
-    m_in_queue.enqueue(gdu);
 
+    if (gdu->get() == 0)
+    {
+        delete gdu;
+        yaz_log(YLOG_LOG, "%sUnable to encode package", m_session_str);
+        m_in_queue.clear();
+        dec_ref();
+        return;
+    }
+    m_in_queue.enqueue(gdu);
     recv_GDU_more(false);
 }
 
+void Yaz_Proxy::HTTP_Forwarded(Z_GDU *z_gdu)
+{
+    if (z_gdu->which == Z_GDU_HTTP_Request)
+    {
+        Z_HTTP_Request *hreq = z_gdu->u.HTTP_Request;
+        const char *x_forwarded_for =
+            z_HTTP_header_lookup(hreq->headers, "X-Forwarded-For");
+        if (x_forwarded_for)
+        {
+            xfree(m_peername);
+            m_peername = (char*) xmalloc(strlen(x_forwarded_for)+5);
+            sprintf(m_peername, "tcp:%s", x_forwarded_for);
+            
+            yaz_log(YLOG_LOG, "%sHTTP Forwarded from %s", m_session_str,
+                    m_peername);
+            if (m_log_mask & PROXY_LOG_IP_CLIENT)
+                sprintf(m_session_str, "%ld:%d %.80s %d ",
+                        (long) time(0), m_session_no, m_peername, m_request_no);
+            else
+                sprintf(m_session_str, "%ld:%d %d ",
+                        (long) time(0), m_session_no, m_request_no);
+        }
+    }
+}
+
+void Yaz_Proxy::connect_stat(bool &block, int &reduce)
+{
+
+    m_parent->m_connect.cleanup(false);
+    m_parent->m_connect.add_connect(m_peername);
+
+    int connect_total = m_parent->m_connect.get_total(m_peername);
+    int max_connect = m_parent->m_max_connect;
+
+    if (max_connect && connect_total > max_connect)
+    {
+        yaz_log(YLOG_LOG, "%sconnect not accepted total=%d max=%d",
+                m_session_str, connect_total, max_connect);
+        block = true;
+    }
+    else 
+        block = false;
+    yaz_log(YLOG_LOG, "%sconnect accepted total=%d", m_session_str,
+            connect_total);
+    
+    int limit_connect = m_parent->m_limit_connect;
+    if (limit_connect)
+        reduce = connect_total / limit_connect;
+    else
+        reduce = 0;
+}
+
 void Yaz_Proxy::recv_GDU_reduce(GDU *gdu)
 {
-    int reduce = m_initial_reduce; // initial reduce from connect phase..
-    m_initial_reduce = 0;  // reset it..
+    HTTP_Forwarded(gdu->get());
+
+    int reduce = 0;
+    
+    if (m_request_no == 1)
+    {
+        bool block = false;
+        
+        connect_stat(block, reduce);
+
+        if (block)
+        {
+            m_timeout_mode = timeout_busy;
+            timeout(0);
+            return;
+        }
+    }
 
     int bw_total = m_bw_stat.get_total();
     int pdu_total = m_pdu_stat.get_total();
@@ -1928,7 +2046,10 @@ void Yaz_Proxy::recv_GDU_more(bool normal)
     while (m_timeout_mode == timeout_normal && (g = m_in_queue.dequeue()))
     {
         m_timeout_mode = timeout_busy;
+        inc_ref();
         recv_GDU_reduce(g);
+        if (dec_ref())
+            break;
     }
 }
 
@@ -2495,11 +2616,7 @@ int Yaz_Proxy::file_access(Z_HTTP_Request *hreq)
     while (*cp)
     {
         if (*cp == '/' && strchr("/.", cp[1]))
-        {
-            yaz_log(YLOG_LOG, "%sRejecting path %s", m_session_str,
-                    hreq->path);
             return 0;
-        }
         cp++;
     }
 
@@ -2609,6 +2726,8 @@ void Yaz_Proxy::handle_incoming_HTTP(Z_HTTP_Request *hreq)
     Z_SRW_diagnostic *diagnostic = 0;
     int num_diagnostic = 0;
 
+    yaz_log(YLOG_LOG, "%s%s %s", m_session_str, hreq->method, hreq->path);
+
     if (file_access(hreq))
     {
         return;
@@ -3009,8 +3128,9 @@ void Yaz_Proxy::handle_init(Z_APDU *apdu)
 
             handle_charset_lang_negotiation(apdu2);
 
+           if (m_timeout_mode == timeout_busy)
+               m_timeout_mode = timeout_normal;
             send_to_client(apdu2);
-            m_timeout_mode = timeout_normal;
             return;
         }
     }
@@ -3188,16 +3308,8 @@ void Yaz_Proxy::releaseClient()
         m_parent->pre_init();
 }
 
-bool Yaz_Proxy::dec_ref(bool main_ptr)
+bool Yaz_Proxy::dec_ref()
 {
-    assert(m_ref_count > 0);
-    if (main_ptr)
-    {
-        if (m_main_ptr_dec)
-            return false;
-        m_main_ptr_dec = true;
-    }
-
     m_http_keepalive = 0;
 
     --m_ref_count;
@@ -3224,8 +3336,8 @@ void Yaz_ProxyClient::shutdown()
 
     if (m_server)
     {
-        m_waiting = 1;      // ensure it's released from Proxy in releaseClient
-        m_server->dec_ref(true);
+        m_waiting = 1;   // ensure it's released from Yaz_Proxy::releaseClient
+        m_server->dec_ref();
     }
     else
         delete this;
@@ -3234,9 +3346,8 @@ void Yaz_ProxyClient::shutdown()
 void Yaz_Proxy::failNotify()
 {
     inc_request_no();
-    yaz_log (YLOG_LOG, "%sConnection closed by client",
-             get_session_str());
-    dec_ref(true);
+    yaz_log (YLOG_LOG, "%sConnection closed by client", get_session_str());
+    dec_ref();
 }
 
 void Yaz_Proxy::send_response_fail_client(const char *addr)
@@ -3437,7 +3548,7 @@ void Yaz_Proxy::timeoutNotify()
             inc_request_no();
             m_in_queue.clear();
             yaz_log (YLOG_LOG, "%sTimeout (client to proxy)", m_session_str);
-            dec_ref(true);
+            dec_ref();
             break;
         case timeout_reduce:
             timeout(m_client_idletime);