X-Git-Url: http://sru.miketaylor.org.uk/?a=blobdiff_plain;f=src%2Ffilter_log.cpp;h=88fd5d8e6b739913e2dee3c302735271e15c0778;hb=f1cc4b4b376376d19998f036e08cee76be3b7c54;hp=8ab01d33c9bef8bf66ea6db36432425e96c0082b;hpb=665559cbc22546e8df69be33a7d492294cab9fb1;p=metaproxy-moved-to-github.git diff --git a/src/filter_log.cpp b/src/filter_log.cpp index 8ab01d3..88fd5d8 100644 --- a/src/filter_log.cpp +++ b/src/filter_log.cpp @@ -1,5 +1,5 @@ /* This file is part of Metaproxy. - Copyright (C) 2005-2008 Index Data + Copyright (C) 2005-2012 Index Data Metaproxy 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 @@ -16,9 +16,9 @@ along with this program; if not, write to the Free Software Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA */ -#include "filter_log.hpp" #include "config.hpp" -#include "package.hpp" +#include "filter_log.hpp" +#include #include #include @@ -26,8 +26,8 @@ Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA #include #include "gduutil.hpp" -#include "util.hpp" -#include "xmlutil.hpp" +#include +#include #include #include @@ -61,6 +61,7 @@ namespace metaproxy_1 { static void option_write(const char *name, void *handle); private: std::string m_msg_config; + bool m_1line; bool m_access; bool m_user_access; bool m_req_apdu; @@ -109,7 +110,8 @@ yf::Log::~Log() { // must have a destructor because of boost::scoped_ptr } -void yf::Log::configure(const xmlNode *xmlnode, bool test_only) +void yf::Log::configure(const xmlNode *xmlnode, bool test_only, + const char *path) { m_p->configure(xmlnode); } @@ -126,6 +128,7 @@ std::list yf::Log::Impl::filter_log_files; yf::Log::Impl::Impl(const std::string &x) : m_msg_config(x), + m_1line(false), m_access(true), m_user_access(false), m_req_apdu(false), @@ -143,6 +146,202 @@ yf::Log::Impl::~Impl() { } +static void log_DefaultDiagFormat(WRBUF w, Z_DefaultDiagFormat *e) +{ + if (e->condition) + wrbuf_printf(w, ODR_INT_PRINTF " ",*e->condition); + else + wrbuf_puts(w, "?? "); + if (e->which == Z_DefaultDiagFormat_v2Addinfo && e->u.v2Addinfo) + wrbuf_puts(w, e->u.v2Addinfo); + else if (e->which == Z_DefaultDiagFormat_v3Addinfo && e->u.v3Addinfo) + wrbuf_puts(w, e->u.v3Addinfo); +} + +static void log_DiagRecs(WRBUF w, int num_diagRecs, Z_DiagRec **diags) +{ + if (diags[0]->which != Z_DiagRec_defaultFormat) + wrbuf_puts(w ,"(diag not in default format?)"); + else + { + Z_DefaultDiagFormat *e = diags[0]->u.defaultFormat; + log_DefaultDiagFormat(w, e); + } +} + +static void log_1_line(Z_APDU *z_req, Z_APDU *z_res, WRBUF w) +{ + switch (z_req->which) + { + case Z_APDU_initRequest: + if (z_res->which == Z_APDU_initResponse) + { + Z_InitRequest *req = z_req->u.initRequest; + Z_InitResponse *res = z_res->u.initResponse; + wrbuf_printf(w, "Init "); + if (res->result && *res->result) + wrbuf_printf(w, "OK -"); + else + { + Z_External *uif = res->userInformationField; + bool got_code = false; + wrbuf_printf(w, "ERROR "); + if (uif && uif->which == Z_External_userInfo1) + { + Z_OtherInformation *ui = uif->u.userInfo1; + if (ui->num_elements >= 1) + { + Z_OtherInformationUnit *unit = ui->list[0]; + if (unit->which == Z_OtherInfo_externallyDefinedInfo && + unit->information.externallyDefinedInfo && + unit->information.externallyDefinedInfo->which == + Z_External_diag1) + { + Z_DiagnosticFormat *diag = + unit->information.externallyDefinedInfo-> + u.diag1; + if (diag->num >= 1) + { + Z_DiagnosticFormat_s *ds = diag->elements[0]; + if (ds->which == + Z_DiagnosticFormat_s_defaultDiagRec) + { + log_DefaultDiagFormat(w, + ds->u.defaultDiagRec); + got_code = true; + } + } + + } + } + } + if (!got_code) + wrbuf_puts(w, "-"); + } + wrbuf_printf(w, " ID:%s Name:%s Version:%s", + req->implementationId ? req->implementationId :"-", + req->implementationName ?req->implementationName : "-", + req->implementationVersion ? + req->implementationVersion : "-"); + } + break; + case Z_APDU_searchRequest: + if (z_res->which == Z_APDU_searchResponse) + { + Z_SearchRequest *req = z_req->u.searchRequest; + Z_SearchResponse *res = z_res->u.searchResponse; + int i; + wrbuf_puts(w, "Search "); + for (i = 0 ; i < req->num_databaseNames; i++) + { + if (i) + wrbuf_printf(w, "+"); + wrbuf_puts(w, req->databaseNames[i]); + } + wrbuf_printf(w, " "); + if (!res->records) + { + wrbuf_printf(w, "OK " ODR_INT_PRINTF " %s", *res->resultCount, + req->resultSetName); + } + else if (res->records->which == Z_Records_DBOSD) + { + wrbuf_printf(w, "OK " ODR_INT_PRINTF " %s", *res->resultCount, + req->resultSetName); + } + else if (res->records->which == Z_Records_NSD) + { + wrbuf_puts(w, "ERROR "); + log_DefaultDiagFormat(w, + res->records->u.nonSurrogateDiagnostic); + } + else if (res->records->which == Z_Records_multipleNSD) + { + wrbuf_puts(w, "ERROR "); + log_DiagRecs( + w, + res->records->u.multipleNonSurDiagnostics->num_diagRecs, + res->records->u.multipleNonSurDiagnostics->diagRecs); + } + wrbuf_printf(w, " 1+" ODR_INT_PRINTF " ", + res->numberOfRecordsReturned + ? *res->numberOfRecordsReturned : 0); + yaz_query_to_wrbuf(w, req->query); + } + break; + case Z_APDU_presentRequest: + if (z_res->which == Z_APDU_presentResponse) + { + Z_PresentRequest *req = z_req->u.presentRequest; + Z_PresentResponse *res = z_res->u.presentResponse; + + wrbuf_printf(w, "Present "); + + if (!res->records) + { + wrbuf_printf(w, "OK"); + } + else if (res->records->which == Z_Records_DBOSD) + { + wrbuf_printf(w, "OK"); + } + else if (res->records->which == Z_Records_NSD) + { + wrbuf_puts(w, "ERROR "); + log_DefaultDiagFormat(w, + res->records->u.nonSurrogateDiagnostic); + } + else if (res->records->which == Z_Records_multipleNSD) + { + wrbuf_puts(w, "ERROR "); + log_DiagRecs( + w, + res->records->u.multipleNonSurDiagnostics->num_diagRecs, + res->records->u.multipleNonSurDiagnostics->diagRecs); + } + wrbuf_printf(w, " %s " ODR_INT_PRINTF "+" ODR_INT_PRINTF " ", + req->resultSetId, *req->resultSetStartPoint, + *req->numberOfRecordsRequested); + } + break; + case Z_APDU_scanRequest: + if (z_res->which == Z_APDU_scanResponse) + { + Z_ScanRequest *req = z_req->u.scanRequest; + Z_ScanResponse *res = z_res->u.scanResponse; + int i; + wrbuf_printf(w, "Scan "); + for (i = 0 ; i < req->num_databaseNames; i++) + { + if (i) + wrbuf_printf(w, "+"); + wrbuf_puts(w, req->databaseNames[i]); + } + wrbuf_puts(w, " "); + if (!res->scanStatus || *res->scanStatus == 0) + wrbuf_puts(w, "OK"); + else if (*res->scanStatus == 6) + wrbuf_puts(w, "FAIL"); + else + wrbuf_printf(w, "PARTIAL" ODR_INT_PRINTF, *res->scanStatus); + + wrbuf_printf(w, " " ODR_INT_PRINTF " " ODR_INT_PRINTF "+" + ODR_INT_PRINTF "+" ODR_INT_PRINTF " ", + res->numberOfEntriesReturned ? + *res->numberOfEntriesReturned : 0, + req->preferredPositionInResponse ? + *req->preferredPositionInResponse : 1, + *req->numberOfTermsRequested, + res->stepSize ? *res->stepSize : 1); + + yaz_scan_to_wrbuf(w, req->termListAndStartPoint, + req->attributeSet); + } + break; + default: + wrbuf_printf(w, "REQ=%d RES=%d", z_req->which, z_res->which); + } +} void yf::Log::Impl::configure(const xmlNode *ptr) { @@ -166,7 +365,9 @@ void yf::Log::Impl::configure(const xmlNode *ptr) const struct _xmlAttr *attr; for (attr = ptr->properties; attr; attr = attr->next) { - if (!strcmp((const char *) attr->name, "access")) + if (!strcmp((const char *) attr->name, "line")) + m_1line = mp::xml::get_bool(attr->children, true); + else if (!strcmp((const char *) attr->name, "access")) m_access = mp::xml::get_bool(attr->children, true); else if (!strcmp((const char *) attr->name, "user-access")) m_user_access = mp::xml::get_bool(attr->children, true); @@ -219,7 +420,7 @@ void yf::Log::Impl::configure(const xmlNode *ptr) void yf::Log::Impl::process(mp::Package &package) { - Z_GDU *gdu = package.request().get(); + Z_GDU *gdu_req = package.request().get(); std::string user("-"); yaz_timing_t timer = yaz_timing_create(); @@ -228,9 +429,9 @@ void yf::Log::Impl::process(mp::Package &package) { boost::mutex::scoped_lock scoped_lock(m_session_mutex); - if (gdu && gdu->which == Z_GDU_Z3950) + if (gdu_req && gdu_req->which == Z_GDU_Z3950) { - Z_APDU *apdu_req = gdu->u.z3950; + Z_APDU *apdu_req = gdu_req->u.z3950; if (apdu_req->which == Z_APDU_initRequest) { Z_InitRequest *req = apdu_req->u.initRequest; @@ -260,26 +461,26 @@ void yf::Log::Impl::process(mp::Package &package) if (m_access) { - if (gdu) + if (gdu_req) { std::ostringstream os; os << m_msg_config << " " << package << " " << "0.000000" << " " - << *gdu; + << *gdu_req; m_file->log(m_time_format, os); } } if (m_user_access) { - if (gdu) + if (gdu_req) { std::ostringstream os; os << m_msg_config << " " << user << " " << package << " " << "0.000000" << " " - << *gdu; + << *gdu_req; m_file->log(m_time_format, os); } } @@ -296,12 +497,12 @@ void yf::Log::Impl::process(mp::Package &package) if (m_init_options) { - if (gdu && gdu->which == Z_GDU_Z3950 && - gdu->u.z3950->which == Z_APDU_initRequest) + if (gdu_req && gdu_req->which == Z_GDU_Z3950 && + gdu_req->u.z3950->which == Z_APDU_initRequest) { std::ostringstream os; os << m_msg_config << " init options:"; - yaz_init_opt_decode(gdu->u.z3950->u.initRequest->options, + yaz_init_opt_decode(gdu_req->u.z3950->u.initRequest->options, option_write, &os); m_file->log(m_time_format, os); } @@ -309,11 +510,11 @@ void yf::Log::Impl::process(mp::Package &package) if (m_req_apdu) { - if (gdu) + if (gdu_req) { mp::odr odr(ODR_PRINT); odr_set_stream(odr, m_file->fhandle, stream_write, 0); - z_GDU(odr, &gdu, 0, 0); + z_GDU(odr, &gdu_req, 0, 0); } } } @@ -321,7 +522,7 @@ void yf::Log::Impl::process(mp::Package &package) // unlocked during move package.move(); - gdu = package.response().get(); + Z_GDU *gdu_res = package.response().get(); yaz_timing_stop(timer); double duration = yaz_timing_get_real(timer); @@ -329,29 +530,49 @@ void yf::Log::Impl::process(mp::Package &package) // scope for locking Ostream { boost::mutex::scoped_lock scoped_lock(m_file->m_mutex); + + if (m_1line) + { + if (gdu_req && gdu_res && gdu_req->which == Z_GDU_Z3950 + && gdu_res->which == Z_GDU_Z3950) + { + mp::wrbuf w; + + log_1_line(gdu_req->u.z3950, gdu_res->u.z3950, w); + const char *message = wrbuf_cstr(w); + + std::ostringstream os; + os << m_msg_config << " " + << package << " " + << std::fixed << std::setprecision (6) << duration + << " " + << message; + m_file->log(m_time_format, os); + } + } if (m_access) { - if (gdu) + if (gdu_res) { std::ostringstream os; os << m_msg_config << " " << package << " " << std::fixed << std::setprecision (6) << duration << " " - << *gdu; + << *gdu_res; m_file->log(m_time_format, os); } } if (m_user_access) { - if (gdu) + if (gdu_res) { std::ostringstream os; os << m_msg_config << " " << user << " " << package << " " << std::fixed << std::setprecision (6) << duration << " " - << *gdu; + << *gdu_res; m_file->log(m_time_format, os); } } @@ -370,13 +591,13 @@ void yf::Log::Impl::process(mp::Package &package) if (m_init_options) { - if (gdu && gdu->which == Z_GDU_Z3950 && - gdu->u.z3950->which == Z_APDU_initResponse) + if (gdu_res && gdu_res->which == Z_GDU_Z3950 && + gdu_res->u.z3950->which == Z_APDU_initResponse) { std::ostringstream os; os << m_msg_config; os << " init options:"; - yaz_init_opt_decode(gdu->u.z3950->u.initResponse->options, + yaz_init_opt_decode(gdu_res->u.z3950->u.initResponse->options, option_write, &os); m_file->log(m_time_format, os); } @@ -384,11 +605,11 @@ void yf::Log::Impl::process(mp::Package &package) if (m_res_apdu) { - if (gdu) + if (gdu_res) { mp::odr odr(ODR_PRINT); odr_set_stream(odr, m_file->fhandle, stream_write, 0); - z_GDU(odr, &gdu, 0, 0); + z_GDU(odr, &gdu_res, 0, 0); } } }