Allow client-ip to be logged for each log entry. Speciy
[yazproxy-moved-to-github.git] / src / yaz-proxy.cpp
index 07b8b45..a6930ea 100644 (file)
@@ -1,7 +1,7 @@
-/* $Id: yaz-proxy.cpp,v 1.44 2006-03-25 10:59:14 adam Exp $
-   Copyright (c) 1998-2005, Index Data.
+/* $Id: yaz-proxy.cpp,v 1.50 2006-04-06 12:04:20 adam Exp $
+   Copyright (c) 1998-2006, Index Data.
 
-This file is part of the yaz-proxy.
+This file is part of the yazproxy.
 
 YAZ proxy is free software; you can redistribute it and/or modify it under
 the terms of the GNU General Public License as published by the Free
@@ -62,7 +62,7 @@ using namespace yazpp_1;
 #define USE_AUTH_MSG 1
 
 #if USE_AUTH_MSG
-class Auth_Msg : public IMsg_Thread {
+class YAZ_EXPORT Auth_Msg : public IMsg_Thread {
 public:
     int m_ret;
     IMsg_Thread *handle();
@@ -87,7 +87,6 @@ Auth_Msg::~Auth_Msg()
 
 IMsg_Thread *Auth_Msg::handle()
 {
-    yaz_log(YLOG_LOG, "Auth_Msg:handle begin");
     ODR decode = odr_createmem(ODR_DECODE);
     Z_APDU *apdu;
 
@@ -101,26 +100,22 @@ IMsg_Thread *Auth_Msg::handle()
     {
         m_ret = m_proxy->handle_authentication(apdu);
     }
-    yaz_log(YLOG_LOG, "Auth_Msg:handle end");
     odr_destroy(decode);
     return this;
 }
 
 void Auth_Msg::result()
 {
-    yaz_log(YLOG_LOG, "Auth_Msg:result proxy ok buf=%p len=%d",
-            m_apdu_buf, m_apdu_len);
     if (m_proxy->dec_ref(false))
+    {
         yaz_log(YLOG_LOG, "Auth_Msg::proxy deleted meanwhile");
+    }
     else
     {
-        yaz_log(YLOG_LOG, "Auth_Msg::proxy still alive");
         odr_setbuf(m_proxy->odr_decode(), m_apdu_buf, m_apdu_len, 0);
         Z_APDU *apdu = 0;
         int r = z_APDU(m_proxy->odr_decode(), &apdu, 0, 0);
-        if (r)
-            yaz_log(YLOG_LOG, "Auth_Msg::result z_APDU OK");
-        else
+        if (!r)
             yaz_log(YLOG_LOG, "Auth_Msg::result z_APDU failed");
         m_proxy->result_authentication(apdu, m_ret);
     }
@@ -207,7 +202,8 @@ Yaz_Proxy::Yaz_Proxy(IPDU_Observable *the_PDU_Observable,
                      ISocketObservable *the_socket_observable,
                      Yaz_Proxy *parent)
     :
-    Z_Assoc(the_PDU_Observable), m_bw_stat(60), m_pdu_stat(60)
+    Z_Assoc(the_PDU_Observable),
+    m_bw_stat(60), m_pdu_stat(60), m_search_stat(60)
 {
     m_PDU_Observable = the_PDU_Observable;
     m_socket_observable = the_socket_observable;
@@ -237,6 +233,7 @@ Yaz_Proxy::Yaz_Proxy(IPDU_Observable *the_PDU_Observable,
     m_pdu_max = 0;
     m_search_max = 0;
     m_connect_max = 0;
+    m_limit_connect = 0;
     m_timeout_mode = timeout_normal;
     m_timeout_gdu = 0;
     m_max_record_retrieve = 0;
@@ -296,6 +293,7 @@ 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()
@@ -356,7 +354,8 @@ int Yaz_Proxy::set_config(const char *config)
     m_config_fname = xstrdup(config);
     int r = m_config->read_xml(config);
     if (!r)
-        m_config->get_generic_info(&m_log_mask, &m_max_clients);
+        m_config->get_generic_info(&m_log_mask, &m_max_clients,
+                                   &m_connect_max, &m_limit_connect);
     return r;
 }
 
@@ -407,7 +406,8 @@ Yaz_ProxyConfig *Yaz_Proxy::check_reconfigure()
             else
             {
                 m_log_mask = 0;
-                cfg->get_generic_info(&m_log_mask, &m_max_clients);
+                cfg->get_generic_info(&m_log_mask, &m_max_clients,
+                                      &m_connect_max, &m_limit_connect);
             }
         }
         else
@@ -421,8 +421,39 @@ IPDU_Observer *Yaz_Proxy::sessionNotify(IPDU_Observable
                                         *the_PDU_Observable, int fd)
 {
     check_reconfigure();
+
+    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);
+    else
+        sprintf(session_str, "%ld:%d 0 ",
+                (long) time(0), m_session_no);        
+    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_connect_max;
+    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);
@@ -435,11 +466,8 @@ IPDU_Observer *Yaz_Proxy::sessionNotify(IPDU_Observable
         new_proxy->set_APDU_yazlog(1);
     else
         new_proxy->set_APDU_yazlog(0);
-    sprintf(new_proxy->m_session_str, "%ld:%d ", (long) time(0), m_session_no);
-    m_session_no++;
-    new_proxy->m_peername = xstrdup(the_PDU_Observable->getpeername());
-    yaz_log (YLOG_LOG, "%sNew session %s", new_proxy->m_session_str,
-             new_proxy->m_peername);
+    strcpy(new_proxy->m_session_str, session_str);
+    new_proxy->m_peername = xstrdup(peername);
     new_proxy->set_proxy_negotiation(m_proxy_negotiation_charset,
         m_proxy_negotiation_lang, m_proxy_negotiation_default_charset);
     // create thread object the first time we get an incoming connection
@@ -561,7 +589,7 @@ Yaz_ProxyClient *Yaz_Proxy::get_client(Z_APDU *apdu, const char *cookie,
             int pre_init = 0;
             cfg->get_target_info(proxy_host, url, &m_bw_max,
                                  &m_pdu_max, &m_max_record_retrieve,
-                                 &m_search_max, &m_connect_max,
+                                 &m_search_max,
                                  &m_target_idletime, &client_idletime,
                                  &parent->m_max_clients,
                                  &m_keepalive_limit_bw,
@@ -971,7 +999,6 @@ void Yaz_Proxy::convert_to_frontend_type(Z_NamePlusRecordList *p)
 void Yaz_Proxy::convert_records_charset(Z_NamePlusRecordList *p,
                                         const char *backend_charset)
 {
-    yaz_log(YLOG_LOG, "%sconvert_to_marc", m_session_str);
     int sel =   m_charset_converter->get_client_charset_selected();
     const char *client_record_charset =
         m_charset_converter->get_client_query_charset();
@@ -1030,10 +1057,6 @@ void Yaz_Proxy::convert_records_charset(Z_NamePlusRecordList *p,
             yaz_iconv_close(cd);
         yaz_marc_destroy(mt);
     }
-    else
-    {
-        yaz_log(YLOG_LOG, "%sSkipping marc convert", m_session_str);
-    }
 }
 
 void Yaz_Proxy::convert_to_marcxml(Z_NamePlusRecordList *p,
@@ -1811,9 +1834,12 @@ Z_APDU *Yaz_Proxy::result_set_optimize(Z_APDU *apdu)
 
 void Yaz_Proxy::inc_request_no()
 {
-    char *cp = strchr(m_session_str, ' ');
-    m_request_no++;
-    if (cp)
+    char *cp = m_session_str + strlen(m_session_str)-1;
+    if (*cp == ' ')
+        cp--;
+    while (*cp && *cp != ' ')
+        cp--;
+    if (*cp)
         sprintf(cp+1, "%d ", m_request_no);
 }
 
@@ -1841,20 +1867,20 @@ void Yaz_Proxy::recv_GDU(Z_GDU *apdu, int len)
 
 void Yaz_Proxy::recv_GDU_reduce(GDU *gdu)
 {
+    int reduce = m_initial_reduce; // initial reduce from connect phase..
+    m_initial_reduce = 0;  // reset it..
+
     int bw_total = m_bw_stat.get_total();
     int pdu_total = m_pdu_stat.get_total();
-    int reduce = 0;
+    int search_total = m_search_stat.get_total();
 
     assert(m_timeout_mode == timeout_busy);
     assert(m_timeout_gdu == 0);
 
+    if (m_search_max)
+        reduce += search_total / m_search_max;
     if (m_bw_max)
-    {
-        if (bw_total > m_bw_max)
-        {
-            reduce = (bw_total/m_bw_max);
-        }
-    }
+        reduce += (bw_total/m_bw_max);
     if (m_pdu_max)
     {
         if (pdu_total > m_pdu_max)
@@ -1874,9 +1900,9 @@ void Yaz_Proxy::recv_GDU_reduce(GDU *gdu)
 #endif
     if (reduce)
     {
-        yaz_log(YLOG_LOG, "%sdelay=%d bw=%d pdu=%d limit-bw=%d limit-pdu=%d",
-                m_session_str, reduce, bw_total, pdu_total,
-                m_bw_max, m_pdu_max);
+        yaz_log(YLOG_LOG, "%sdelay=%d bw=%d pdu=%d search=%d limit-bw=%d limit-pdu=%d limit-search=%d",
+                m_session_str, reduce, bw_total, pdu_total, search_total,
+                m_bw_max, m_pdu_max, m_search_max);
 
         m_timeout_mode = timeout_reduce;
         m_timeout_gdu = gdu;
@@ -1928,8 +1954,6 @@ void Yaz_Proxy::handle_charset_lang_negotiation(Z_APDU *apdu)
 {
     if (apdu->which == Z_APDU_initRequest)
     {
-        yaz_log(YLOG_LOG, "%shandle_charset_lang_negotiation",
-                m_session_str);
         if (m_initRequest_options &&
             !ODR_MASK_GET(m_initRequest_options, Z_Options_negotiationModel) &&
             (m_proxy_negotiation_charset || m_proxy_negotiation_lang))
@@ -2458,39 +2482,45 @@ int Yaz_Proxy::file_access(Z_HTTP_Request *hreq)
     if (strcmp(hreq->method, "GET"))
         return 0;
     if (hreq->path[0] != '/')
-    {
-        yaz_log(YLOG_WARN, "Bad path: %s", hreq->path);
         return 0;
-    }
     const char *cp = hreq->path;
     while (*cp)
     {
         if (*cp == '/' && strchr("/.", cp[1]))
         {
-            yaz_log(YLOG_WARN, "Bad path: %s", hreq->path);
+            yaz_log(YLOG_LOG, "%sRejecting path %s", m_session_str,
+                    hreq->path);
             return 0;
         }
         cp++;
     }
+
+    Yaz_ProxyConfig *cfg = check_reconfigure();
+
+    if (!cfg->get_file_access_info(hreq->path+1))
+        return 0;
+
     const char *fname = hreq->path+1;
     if (stat(fname, &sbuf))
     {
-        yaz_log(YLOG_WARN|YLOG_ERRNO, "%s: stat failed", fname);
+        yaz_log(YLOG_LOG|YLOG_ERRNO, "%sstat failed for %s", m_session_str,
+                fname);
         return 0;
     }
     if ((sbuf.st_mode & S_IFMT) != S_IFREG)
     {
-        yaz_log(YLOG_WARN, "%s: not a regular file", fname);
+        yaz_log(YLOG_LOG, "%sNot a regular file %s", m_session_str, fname);
         return 0;
     }
     if (sbuf.st_size > (off_t) 1000000)
     {
-        yaz_log(YLOG_WARN, "%s: too large for transfer", fname);
+        yaz_log(YLOG_WARN, "%sFile %s too large for transfer", m_session_str,
+                fname);
         return 0;
     }
 
     ODR o = odr_encode();
-    Yaz_ProxyConfig *cfg = check_reconfigure();
+
     const char *ctype = cfg->check_mime_type(fname);
     Z_GDU *gdu = z_get_HTTP_Response(o, 200);
     Z_HTTP_Response *hres = gdu->u.HTTP_Response;
@@ -2608,6 +2638,7 @@ void Yaz_Proxy::handle_incoming_HTTP(Z_HTTP_Request *hreq)
 
         if (srw_pdu->which == Z_SRW_searchRetrieve_request)
         {
+
             Z_SRW_searchRetrieveRequest *srw_req = srw_pdu->u.request;
 
             const char *backend_db = srw_req->database;
@@ -2978,7 +3009,6 @@ void Yaz_Proxy::handle_init(Z_APDU *apdu)
     m_client->m_init_flag = 1;
 
 #if USE_AUTH_MSG
-    yaz_log(YLOG_LOG, "%suse_auth_msg", m_session_str);
     Auth_Msg *m = new Auth_Msg;
     m->m_proxy = this;
     z_APDU(odr_encode(), &apdu, 0, "encode");
@@ -3019,6 +3049,9 @@ void Yaz_Proxy::handle_incoming_Z_PDU(Z_APDU *apdu)
         apdu = m_initRequest_apdu;     // but throw an init to the target
     }
 
+    if (apdu->which == Z_APDU_searchRequest)
+        m_search_stat.add_bytes(1);
+
     // Determine our client.
     Z_OtherInformation **oi;
     get_otherInfoAPDU(apdu, &oi);
@@ -3149,8 +3182,6 @@ void Yaz_Proxy::releaseClient()
 
 bool Yaz_Proxy::dec_ref(bool main_ptr)
 {
-    yaz_log(YLOG_LOG, "%sdec_ref count=%d", m_session_str, m_ref_count);
-
     assert(m_ref_count > 0);
     if (main_ptr)
     {
@@ -3202,7 +3233,6 @@ void Yaz_Proxy::failNotify()
 
 void Yaz_Proxy::send_response_fail_client(const char *addr)
 {
-    yaz_log(YLOG_LOG, "%ssend_close_response", get_session_str());
     if (m_http_version)
     {
         Z_SRW_diagnostic *diagnostic = 0;
@@ -3291,7 +3321,7 @@ void Yaz_Proxy::pre_init()
     int i;
     const char *name = 0;
     const char *zurl_in_use[MAX_ZURL_PLEX];
-    int limit_bw, limit_pdu, limit_req, limit_search, limit_connect;
+    int limit_bw, limit_pdu, limit_req, limit_search;
     int target_idletime, client_idletime;
     int max_clients;
     int keepalive_limit_bw, keepalive_limit_pdu;
@@ -3312,7 +3342,7 @@ void Yaz_Proxy::pre_init()
 
     for (i = 0; cfg && cfg->get_target_no(i, &name, zurl_in_use,
                                           &limit_bw, &limit_pdu, &limit_req,
-                                          &limit_search, &limit_connect,
+                                          &limit_search,
                                           &target_idletime, &client_idletime,
                                           &max_clients,
                                           &keepalive_limit_bw,