From 03e2fc2fbd11931ca4183c3f1fb678f09eb5403e Mon Sep 17 00:00:00 2001 From: Adam Dickmeiss Date: Wed, 27 Feb 2008 11:08:48 +0000 Subject: [PATCH] Custom time format for log filter using strftime. The log filter now uses strftime to format a date+time for a log entry similar to that used in YAZ' log utility. The Boost date-time library is no longer used. --- buildconf.sh | 5 +- configure.ac | 5 +- debian/control | 2 +- doc/book.xml | 4 +- etc/config0.xml | 4 +- etc/config5.xml | 10 ++- src/Makefile.am | 6 +- src/filter_load_balance.cpp | 11 +-- src/filter_log.cpp | 183 ++++++++++++++++++++++++------------------- src/test_boost_time.cpp | 77 ------------------ xml/schema/metaproxy.rnc | 5 +- 11 files changed, 122 insertions(+), 190 deletions(-) delete mode 100644 src/test_boost_time.cpp diff --git a/buildconf.sh b/buildconf.sh index cce50d5..2a68146 100755 --- a/buildconf.sh +++ b/buildconf.sh @@ -1,5 +1,5 @@ #!/bin/sh -# $Id: buildconf.sh,v 1.13 2006-10-13 10:31:54 adam Exp $ +# $Id: buildconf.sh,v 1.14 2008-02-27 11:08:48 adam Exp $ automake=automake aclocal=aclocal @@ -91,8 +91,7 @@ When building from a CVS checkout, you need these Debian tools: autoconf, automake, libtool, gcc, g++, make, xsltproc, docbook, docbook-xml, docbook-xsl, trang, libxslt1-dev, libyazpp-dev, - libboost-thread-dev, libboost-date-time-dev, - libboost-program-options-dev, libboost-test-dev + libboost-thread-dev, libboost-test-dev and for the image-processing needed to build the documentation: inkscape diff --git a/configure.ac b/configure.ac index 3ca8491..65207ef 100644 --- a/configure.ac +++ b/configure.ac @@ -35,6 +35,8 @@ fi AC_CHECK_LIB(dl,dlopen) AC_CHECK_LIB(m,main) +AC_CHECK_FUNCS([localtime_r]) + ## YAZPP checks YAZPP_INIT([threads],[1.1.0]) if test -z "$YAZPPLIB"; then @@ -49,9 +51,6 @@ AX_BOOST([1.32]) if test "$ax_cv_boost_base" = "no"; then AC_MSG_ERROR([install libboost-dev or similar]) fi -if test "$ax_cv_boost_date_time" = "no"; then - AC_MSG_ERROR([install libboost-date-time-dev or similar]) -fi if test "$ax_cv_boost_thread" = "no"; then AC_MSG_ERROR([install libboost-thread-dev or similar]) fi diff --git a/debian/control b/debian/control index 7c8d6d5..875a62b 100644 --- a/debian/control +++ b/debian/control @@ -3,7 +3,7 @@ Section: devel Standards-Version: 3.6.2 Maintainer: Marc Cromme Priority: extra -Build-Depends: debhelper (>= 4), libyaz3-dev, libyazpp3-dev (>= 1.1.0), libxslt1-dev, libboost-dev, libboost-thread-dev, libboost-date-time-dev, libboost-test-dev +Build-Depends: debhelper (>= 4), libyaz3-dev, libyazpp3-dev (>= 1.1.0), libxslt1-dev, libboost-dev, libboost-thread-dev, libboost-test-dev Package: metaproxy Section: net diff --git a/doc/book.xml b/doc/book.xml index 6732851..fb39a87 100644 --- a/doc/book.xml +++ b/doc/book.xml @@ -18,7 +18,7 @@ --> ]> - + Metaproxy - User's Guide and Reference @@ -279,8 +279,6 @@ apt-get install libyazpp2-dev apt-get install libboost-dev apt-get install libboost-thread-dev - apt-get install libboost-date-time-dev - apt-get install libboost-program-options-dev apt-get install libboost-test-dev diff --git a/etc/config0.xml b/etc/config0.xml index a184c77..507bed8 100644 --- a/etc/config0.xml +++ b/etc/config0.xml @@ -1,5 +1,5 @@ - + @@ -10,7 +10,7 @@ - + diff --git a/etc/config5.xml b/etc/config5.xml index 074cf42..535f47f 100644 --- a/etc/config5.xml +++ b/etc/config5.xml @@ -1,5 +1,5 @@ - + @@ -13,6 +13,7 @@ F + %Y%m%d-%H%M%S my.log @@ -20,9 +21,10 @@ B - my.log - my.log + %Y%m%d-%H%M%S + diff --git a/src/Makefile.am b/src/Makefile.am index 0e634bd..4aca39e 100644 --- a/src/Makefile.am +++ b/src/Makefile.am @@ -1,4 +1,4 @@ -## $Id: Makefile.am,v 1.66 2007-11-02 17:25:33 adam Exp $ +## $Id: Makefile.am,v 1.67 2008-02-27 11:08:49 adam Exp $ MAINTAINERCLEANFILES = Makefile.in config.in config.hpp @@ -78,7 +78,7 @@ check_PROGRAMS = \ test_filter1 test_filter2 \ test_session1 test_session2 \ test_thread_pool_observer \ - test_boost_threads test_boost_time \ + test_boost_threads \ test_filter_auth_simple \ test_filter_factory \ test_filter_frontend_net \ @@ -103,7 +103,6 @@ test_filter2_SOURCES=test_filter2.cpp test_session1_SOURCES=test_session1.cpp test_session2_SOURCES=test_session2.cpp test_boost_threads_SOURCES=test_boost_threads.cpp -test_boost_time_SOURCES=test_boost_time.cpp test_thread_pool_observer_SOURCES = test_thread_pool_observer.cpp test_filter_auth_simple_SOURCES = test_filter_auth_simple.cpp test_filter_factory_SOURCES = test_filter_factory.cpp @@ -129,7 +128,6 @@ test_filter2_LDADD = $(TESTLDADD) test_session1_LDADD = $(TESTLDADD) test_session2_LDADD = $(TESTLDADD) test_boost_threads_LDADD = $(TESTLDADD) -test_boost_time_LDADD = $(TESTLDADD) test_filter_auth_simple_LDADD = $(TESTLDADD) test_filter_factory_LDADD = $(TESTLDADD) test_filter_frontend_net_LDADD = $(TESTLDADD) diff --git a/src/filter_load_balance.cpp b/src/filter_load_balance.cpp index c91791b..af934f3 100644 --- a/src/filter_load_balance.cpp +++ b/src/filter_load_balance.cpp @@ -1,4 +1,4 @@ -/* $Id: filter_load_balance.cpp,v 1.10 2008-02-20 15:07:52 adam Exp $ +/* $Id: filter_load_balance.cpp,v 1.11 2008-02-27 11:08:49 adam Exp $ Copyright (c) 2005-2007, Index Data. This file is part of Metaproxy. @@ -28,7 +28,6 @@ Free Software Foundation, 59 Temple Place - Suite 330, Boston, MA #include -#include #include @@ -248,14 +247,6 @@ void yf::LoadBalance::Impl::process(mp::Package &package) } } -// getting timestamp for receiving of package -//boost::posix_time::ptime receive_time -// = boost::posix_time::microsec_clock::local_time(); -// //<< receive_time << " " -// //<< to_iso_string(receive_time) << " " -//<< to_iso_extended_string(receive_time) << " " - - // statistic manipulating functions, void yf::LoadBalance::Impl::add_dead(unsigned long session_id){ diff --git a/src/filter_log.cpp b/src/filter_log.cpp index cbaef88..c595d6c 100644 --- a/src/filter_log.cpp +++ b/src/filter_log.cpp @@ -1,5 +1,5 @@ -/* $Id: filter_log.cpp,v 1.34 2008-02-26 23:56:28 adam Exp $ - Copyright (c) 2005-2007, Index Data. +/* $Id: filter_log.cpp,v 1.35 2008-02-27 11:08:49 adam Exp $ + Copyright (c) 2005-2008, Index Data. This file is part of Metaproxy. @@ -25,8 +25,8 @@ Free Software Foundation, 59 Temple Place - Suite 330, Boston, MA #include #include +#include #include -#include #include "gduutil.hpp" #include "util.hpp" @@ -36,8 +36,9 @@ Free Software Foundation, 59 Temple Place - Suite 330, Boston, MA #include #include #include +#include #include - +#include namespace mp = metaproxy_1; namespace yf = metaproxy_1::filter; @@ -71,7 +72,8 @@ namespace metaproxy_1 { bool m_res_session; bool m_init_options; LFilePtr m_file; - // Only used during configure stage (no threading), + std::string m_time_format; + // Only used during confiqgure stage (no threading), // for performance avoid opening files which other log filter // instances already have opened static std::list filter_log_files; @@ -88,6 +90,9 @@ namespace metaproxy_1 { ~LFile(); LFile(std::string fname); LFile(std::string fname, FILE *outf); + void log(const std::string &date_format, + std::ostringstream &os); + void flush(); }; } @@ -118,23 +123,10 @@ void yf::Log::process(mp::Package &package) const } -// define Implementation stuff - // static initialization std::list yf::Log::Impl::filter_log_files; -// yf::Log::Impl::Impl() -// { -// m_access = true; -// m_req_apdu = false; -// m_res_apdu = false; -// m_req_session = false; -// m_res_session = false; -// m_init_options = false; -// openfile(""); -// } - yf::Log::Impl::Impl(const std::string &x) : m_msg_config(x), m_access(true), @@ -143,7 +135,8 @@ yf::Log::Impl::Impl(const std::string &x) m_res_apdu(false), m_req_session(false), m_res_session(false), - m_init_options(false) + m_init_options(false), + m_time_format("%H:%M:%S-%d/%m") { openfile(""); } @@ -167,6 +160,10 @@ void yf::Log::Impl::configure(const xmlNode *ptr) std::string fname = mp::xml::get_text(ptr); openfile(fname); } + else if (!strcmp((const char *) ptr->name, "time-format")) + { + m_time_format = mp::xml::get_text(ptr); + } else if (!strcmp((const char *) ptr->name, "category")) { const struct _xmlAttr *attr; @@ -204,6 +201,10 @@ void yf::Log::Impl::configure(const xmlNode *ptr) "init-options")) m_init_options = mp::xml::get_bool(attr->children, true); + else if (!strcmp((const char *) attr->name, + "init-options")) + m_init_options = + mp::xml::get_bool(attr->children, true); else throw mp::filter::FilterException( "Bad attribute " + std::string((const char *) @@ -224,9 +225,7 @@ void yf::Log::Impl::process(mp::Package &package) Z_GDU *gdu = package.request().get(); std::string user("-"); - // getting timestamp for receiving of package - boost::posix_time::ptime receive_time - = boost::posix_time::microsec_clock::local_time(); + yaz_timing_t timer = yaz_timing_create(); // scope for session lock { @@ -260,19 +259,18 @@ void yf::Log::Impl::process(mp::Package &package) } // scope for locking Ostream { - std::ostringstream os; boost::mutex::scoped_lock scoped_lock(m_file->m_mutex); if (m_access) { if (gdu) { - os << to_iso_extended_string(receive_time) << " " - << m_msg_config << " " + std::ostringstream os; + os << m_msg_config << " " << package << " " - << "000000.000000" << " " - << *gdu - << "\n"; + << "0.000000" << " " + << *gdu; + m_file->log(m_time_format, os); } } @@ -280,22 +278,23 @@ void yf::Log::Impl::process(mp::Package &package) { if (gdu) { - os << to_iso_extended_string(receive_time) << " " - << m_msg_config << " " << user << " " + std::ostringstream os; + os << m_msg_config << " " << user << " " << package << " " - << "000000.000000" << " " - << *gdu - << "\n"; + << "0.000000" << " " + << *gdu; + m_file->log(m_time_format, os); } } if (m_req_session) { - os << receive_time << " " << m_msg_config; + std::ostringstream os; + os << m_msg_config; os << " request id=" << package.session().id(); os << " close=" - << (package.session().is_closed() ? "yes" : "no") - << "\n"; + << (package.session().is_closed() ? "yes" : "no"); + m_file->log(m_time_format, os); } if (m_init_options) @@ -303,11 +302,11 @@ void yf::Log::Impl::process(mp::Package &package) if (gdu && gdu->which == Z_GDU_Z3950 && gdu->u.z3950->which == Z_APDU_initRequest) { - os << receive_time << " " << m_msg_config; - os << " init options:"; + std::ostringstream os; + os << m_msg_config << " init options:"; yaz_init_opt_decode(gdu->u.z3950->u.initRequest->options, - option_write, m_file->fhandle); - os << "\n"; + option_write, &os); + m_file->log(m_time_format, os); } } @@ -320,8 +319,6 @@ void yf::Log::Impl::process(mp::Package &package) z_GDU(odr, &gdu, 0, 0); } } - fputs(os.str().c_str(), m_file->fhandle); - fflush(m_file->fhandle); } // unlocked during move @@ -329,50 +326,49 @@ void yf::Log::Impl::process(mp::Package &package) gdu = package.response().get(); - // getting timestamp for sending of package - boost::posix_time::ptime send_time - = boost::posix_time::microsec_clock::local_time(); - - boost::posix_time::time_duration duration = send_time - receive_time; + yaz_timing_stop(timer); + double duration = yaz_timing_get_real(timer); // scope for locking Ostream { boost::mutex::scoped_lock scoped_lock(m_file->m_mutex); - std::ostringstream os; if (m_access) { if (gdu) { - os << to_iso_extended_string(send_time) << " " - << m_msg_config << " " + std::ostringstream os; + os << m_msg_config << " " << package << " " - << to_iso_string(duration) << " " - << *gdu - << "\n"; - } + << std::fixed << std::setprecision (6) << duration + << " " + << *gdu; + m_file->log(m_time_format, os); + } } if (m_user_access) { if (gdu) { - os << to_iso_extended_string(send_time) << " " - << m_msg_config << " " << user << " " + std::ostringstream os; + os << m_msg_config << " " << user << " " << package << " " - << to_iso_string(duration) << " " - << *gdu - << "\n"; + << std::fixed << std::setprecision (6) << duration << " " + << *gdu; + m_file->log(m_time_format, os); } } if (m_res_session) { - os << send_time << " " << m_msg_config; + std::ostringstream os; + os << m_msg_config; os << " response id=" << package.session().id(); os << " close=" - << (package.session().is_closed() ? "yes " : "no ") - << "duration=" << duration - << "\n"; + << (package.session().is_closed() ? "yes " : "no ") + << "duration=" + << std::fixed << std::setprecision (6) << duration; + m_file->log(m_time_format, os); } if (m_init_options) @@ -380,11 +376,12 @@ void yf::Log::Impl::process(mp::Package &package) if (gdu && gdu->which == Z_GDU_Z3950 && gdu->u.z3950->which == Z_APDU_initResponse) { - os << receive_time << " " << m_msg_config; + std::ostringstream os; + os << m_msg_config; os << " init options:"; yaz_init_opt_decode(gdu->u.z3950->u.initResponse->options, - option_write, m_file->fhandle); - os << "\n"; + option_write, &os); + m_file->log(m_time_format, os); } } @@ -397,9 +394,9 @@ void yf::Log::Impl::process(mp::Package &package) z_GDU(odr, &gdu, 0, 0); } } - fputs(os.str().c_str(), m_file->fhandle); - fflush(m_file->fhandle); } + m_file->flush(); + yaz_timing_destroy(&timer); } @@ -415,10 +412,7 @@ void yf::Log::Impl::openfile(const std::string &fname) return; } } - // open stdout for empty file - LFilePtr newfile(fname.length() == 0 - ? new LFile(fname, yaz_log_file()) - : new LFile(fname)); + LFilePtr newfile(new LFile(fname)); filter_log_files.push_back(newfile); m_file = newfile; } @@ -426,14 +420,14 @@ void yf::Log::Impl::openfile(const std::string &fname) void yf::Log::Impl::stream_write(ODR o, void *handle, int type, const char *buf, int len) { - FILE *fhandle = (FILE*) handle; - fwrite(buf, len, 1, fhandle); + FILE *f = (FILE*) handle; + fwrite(buf, len, 1, f ? f : yaz_log_file()); } void yf::Log::Impl::option_write(const char *name, void *handle) { - FILE *fhandle = (FILE*) handle; - fprintf(fhandle, " %s", name); + std::ostringstream *os = (std::ostringstream *) handle; + *os << " " << name; } @@ -441,19 +435,46 @@ yf::Log::Impl::LFile::LFile(std::string fname) : m_fname(fname) { - fhandle = fopen(fname.c_str(), "a"); + if (fname.c_str()) + fhandle = fopen(fname.c_str(), "a"); + else + fhandle = 0; } -yf::Log::Impl::LFile::LFile(std::string fname, FILE *outf) : - m_fname(fname) +yf::Log::Impl::LFile::~LFile() { - fhandle = outf; } -yf::Log::Impl::LFile::~LFile() +void yf::Log::Impl::LFile::log(const std::string &date_format, + std::ostringstream &os) { + if (fhandle) + { + char datestr[80]; + time_t ti = time(0); +#if HAVE_LOCALTIME_R + struct tm tm0, *tm = &tm0; + localtime_r(&ti, tm); +#else + struct tm *tm = localtime(&ti); +#endif + if (strftime(datestr, sizeof(datestr)-1, date_format.c_str(), tm)) + { + fputs(datestr, fhandle); + fputs(" ", fhandle); + } + fputs(os.str().c_str(), fhandle); + fputc('\n', fhandle); + } + else + yaz_log(YLOG_LOG, "%s", os.str().c_str()); } +void yf::Log::Impl::LFile::flush() +{ + if (fhandle) + fflush(fhandle); +} static mp::filter::Base* filter_creator() { diff --git a/src/test_boost_time.cpp b/src/test_boost_time.cpp deleted file mode 100644 index bbf275a..0000000 --- a/src/test_boost_time.cpp +++ /dev/null @@ -1,77 +0,0 @@ -/* $Id: test_boost_time.cpp,v 1.12 2007-11-02 17:47:41 adam Exp $ - Copyright (c) 2005-2007, Index Data. - -This file is part of Metaproxy. - -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 -Software Foundation; either version 2, or (at your option) any later -version. - -Metaproxy is distributed in the hope that it will be useful, but WITHOUT ANY -WARRANTY; without even the implied warranty of MERCHANTABILITY or -FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License -for more details. - -You should have received a copy of the GNU General Public License -along with Metaproxy; see the file LICENSE. If not, write to the -Free Software Foundation, 59 Temple Place - Suite 330, Boston, MA -02111-1307, USA. - */ - -#include - -#include "config.hpp" -#include "boost/date_time/posix_time/posix_time.hpp" - -#define BOOST_AUTO_TEST_MAIN -#define BOOST_TEST_DYN_LINK -#include - -using namespace boost::unit_test; - - - -BOOST_AUTO_TEST_CASE( testboosttime1 ) -{ - - // test session - try { - - boost::posix_time::ptime now - = boost::posix_time::microsec_clock::local_time(); - //std::cout << now << std::endl; - - sleep(1); - - boost::posix_time::ptime then - = boost::posix_time::microsec_clock::local_time(); - //std::cout << then << std::endl; - - boost::posix_time::time_period period(now, then); - //std::cout << period << std::endl; - - boost::posix_time::time_duration duration = then - now; - //std::cout << duration << std::endl; - - BOOST_CHECK (duration.total_seconds() >= 1); - BOOST_CHECK (duration.fractional_seconds() > 0); - - } - catch (std::exception &e) { - std::cout << e.what() << "\n"; - BOOST_CHECK (false); - } - catch (...) { - BOOST_CHECK (false); - } -} - -/* - * Local variables: - * c-basic-offset: 4 - * indent-tabs-mode: nil - * c-file-style: "stroustrup" - * End: - * vim: shiftwidth=4 tabstop=8 expandtab - */ diff --git a/xml/schema/metaproxy.rnc b/xml/schema/metaproxy.rnc index 2cb8e77..509a00e 100644 --- a/xml/schema/metaproxy.rnc +++ b/xml/schema/metaproxy.rnc @@ -1,7 +1,7 @@ # Metaproxy XML config file schemas -# $Id: metaproxy.rnc,v 1.21 2007-11-18 10:44:40 adam Exp $ +# $Id: metaproxy.rnc,v 1.22 2008-02-27 11:08:50 adam Exp $ # -# Copyright (c) 2005-2007, Index Data. +# Copyright (c) 2005-2008, Index Data. # # See the LICENSE file for details # @@ -122,6 +122,7 @@ filter_log = attribute name { xsd:NCName }?, element mp:message { xsd:string }?, element mp:filename { xsd:string }?, + element mp:time-format { xsd:string }?, element mp:category { attribute user-access { xsd:boolean }?, attribute access { xsd:boolean }?, -- 1.7.10.4