src/filter_log.cpp

   1 /* $Id: filter_log.cpp,v 1.27 2006-09-29 12:24:49 marc Exp $
   2    Copyright (c) 2005-2006, Index Data.
   3
   4    See the LICENSE file for details
   5  */
   6
   7 #include "filter_log.hpp"
   8 #include "config.hpp"
   9 #include "package.hpp"
  10
  11 #include <string>
  12 #include <sstream>
  13 #include <boost/thread/mutex.hpp>
  14 #include <boost/date_time/posix_time/posix_time.hpp>
  15
  16 #include "gduutil.hpp"
  17 #include "util.hpp"
  18 #include "xmlutil.hpp"
  19
  20 #include <fstream>
  21 #include <yaz/zgdu.h>
  22 #include <yaz/wrbuf.h>
  23 #include <yaz/querytowrbuf.h>
  24
  25
  26 namespace mp = metaproxy_1;
  27 namespace yf = metaproxy_1::filter;
  28
  29 namespace metaproxy_1 {
  30     namespace filter {
  31
  32         class Log::Impl {
  33         public:
  34             class LFile;
  35             typedef boost::shared_ptr<Log::Impl::LFile> LFilePtr;
  36         public:
  37             //Impl();
  38             Impl(const std::string &x = "");
  39            ~Impl();
  40             void process(metaproxy_1::Package & package) const;
  41             void configure(const xmlNode * ptr);
  42         private:
  43             void openfile(const std::string &fname);
  44             // needs to be static to be called by C pointer-to-function-syntax
  45             static void stream_write(ODR o, void *handle, int type,
  46                               const char *buf, int len);
  47             // needs to be static to be called by C pointer-to-function-syntax
  48             static void option_write(const char *name, void *handle);
  49         private:
  50             std::string m_msg_config;
  51             bool m_access;
  52             bool m_req_apdu;
  53             bool m_res_apdu;
  54             bool m_req_session;
  55             bool m_res_session;
  56             bool m_init_options;
  57             LFilePtr m_file;
  58             // Only used during configure stage (no threading),
  59             // for performance avoid opening files which other log filter
  60             // instances already have opened
  61             static std::list<LFilePtr> filter_log_files;
  62        };
  63
  64         class Log::Impl::LFile {
  65         public:
  66             boost::mutex m_mutex;
  67             std::string m_fname;
  68             std::ofstream fout;
  69             std::ostream &out;
  70             LFile(std::string fname);
  71             LFile(std::string fname, std::ostream &use_this);
  72         };
  73
  74     }
  75 }
  76
  77 // define Pimpl wrapper forwarding to Impl
  78
  79 yf::Log::Log() : m_p(new Impl)
  80 {
  81 }
  82
  83 yf::Log::Log(const std::string &x) : m_p(new Impl(x))
  84 {
  85 }
  86
  87 yf::Log::~Log()
  88 {  // must have a destructor because of boost::scoped_ptr
  89 }
  90
  91 void yf::Log::configure(const xmlNode *xmlnode)
  92 {
  93     m_p->configure(xmlnode);
  94 }
  95
  96 void yf::Log::process(mp::Package &package) const
  97 {
  98     m_p->process(package);
  99 }
 100
 101
 102 // define Implementation stuff
 103
 104 // static initialization
 105 std::list<yf::Log::Impl::LFilePtr> yf::Log::Impl::filter_log_files;
 106
 107
 108 // yf::Log::Impl::Impl()
 109 // {
 110 //     m_access = true;
 111 //     m_req_apdu = false;
 112 //     m_res_apdu = false;
 113 //     m_req_session = false;
 114 //     m_res_session = false;
 115 //     m_init_options = false;
 116 //     openfile("");
 117 // }
 118
 119 yf::Log::Impl::Impl(const std::string &x)
 120     : m_msg_config(x),
 121       m_access(true),
 122       m_req_apdu(false),
 123       m_res_apdu(false),
 124       m_req_session(false),
 125       m_res_session(false),
 126       m_init_options(false)
 127 {
 128     openfile("");
 129 }
 130
 131
 132 yf::Log::Impl::~Impl()
 133 {
 134 }
 135
 136
 137 void yf::Log::Impl::configure(const xmlNode *ptr)
 138 {
 139     for (ptr = ptr->children; ptr; ptr = ptr->next)
 140     {
 141         if (ptr->type != XML_ELEMENT_NODE)
 142             continue;
 143         if (!strcmp((const char *) ptr->name, "message"))
 144             m_msg_config = mp::xml::get_text(ptr);
 145         else if (!strcmp((const char *) ptr->name, "filename"))
 146         {
 147             std::string fname = mp::xml::get_text(ptr);
 148             openfile(fname);
 149         }
 150         else if (!strcmp((const char *) ptr->name, "category"))
 151         {
 152             const struct _xmlAttr *attr;
 153             for (attr = ptr->properties; attr; attr = attr->next)
 154             {
 155                 if (!strcmp((const char *) attr->name,
 156                                  "access"))
 157                     m_access =
 158                         mp::xml::get_bool(attr->children, true);
 159                 else if (!strcmp((const char *) attr->name, "request-apdu"))
 160                     m_req_apdu = mp::xml::get_bool(attr->children, true);
 161                 else if (!strcmp((const char *) attr->name, "response-apdu"))
 162                     m_res_apdu = mp::xml::get_bool(attr->children, true);
 163                 else if (!strcmp((const char *) attr->name, "apdu"))
 164                 {
 165                     m_req_apdu = mp::xml::get_bool(attr->children, true);
 166                     m_res_apdu = m_req_apdu;
 167                 }
 168                 else if (!strcmp((const char *) attr->name,
 169                                  "request-session"))
 170                     m_req_session =
 171                         mp::xml::get_bool(attr->children, true);
 172                 else if (!strcmp((const char *) attr->name,
 173                                  "response-session"))
 174                     m_res_session =
 175                         mp::xml::get_bool(attr->children, true);
 176                 else if (!strcmp((const char *) attr->name,
 177                                  "session"))
 178                 {
 179                     m_req_session =
 180                         mp::xml::get_bool(attr->children, true);
 181                     m_res_session = m_req_session;
 182                 }
 183                 else if (!strcmp((const char *) attr->name,
 184                                  "init-options"))
 185                     m_init_options =
 186                         mp::xml::get_bool(attr->children, true);
 187                 else
 188                     throw mp::filter::FilterException(
 189                         "Bad attribute " + std::string((const char *)
 190                                                        attr->name));
 191             }
 192         }
 193         else
 194         {
 195             throw mp::filter::FilterException("Bad element "
 196                                                + std::string((const char *)
 197                                                              ptr->name));
 198         }
 199     }
 200 }
 201
 202 void yf::Log::Impl::process(mp::Package &package) const
 203 {
 204     Z_GDU *gdu;
 205
 206     // getting timestamp for receiving of package
 207     boost::posix_time::ptime receive_time
 208         = boost::posix_time::microsec_clock::local_time();
 209
 210
 211
 212     // scope for locking Ostream
 213     {
 214         boost::mutex::scoped_lock scoped_lock(m_file->m_mutex);
 215
 216
 217         if (m_access)
 218         {
 219             gdu = package.request().get();
 220             if (gdu)
 221             {
 222                 m_file->out
 223                     //<< receive_time << " "
 224                     //<< to_iso_string(receive_time) << " "
 225                     << to_iso_extended_string(receive_time) << " "
 226                     << m_msg_config << " "
 227                     << package << " "
 228                     << "000000.000000" << " "
 229                     << *gdu
 230                     << "\n";
 231             }
 232         }
 233
 234         if (m_req_session)
 235         {
 236             m_file->out << receive_time << " " << m_msg_config;
 237             m_file->out << " request id=" << package.session().id();
 238             m_file->out << " close="
 239                              << (package.session().is_closed() ? "yes" : "no")
 240                              << "\n";
 241         }
 242
 243         if (m_init_options)
 244         {
 245             gdu = package.request().get();
 246             if (gdu && gdu->which == Z_GDU_Z3950 &&
 247                 gdu->u.z3950->which == Z_APDU_initRequest)
 248             {
 249                 m_file->out << receive_time << " " << m_msg_config;
 250                 m_file->out << " init options:";
 251                 yaz_init_opt_decode(gdu->u.z3950->u.initRequest->options,
 252                                     option_write, m_file.get());
 253                 m_file->out << "\n";
 254             }
 255         }
 256
 257         if (m_req_apdu)
 258         {
 259             gdu = package.request().get();
 260             if (gdu)
 261             {
 262                 mp::odr odr(ODR_PRINT);
 263                 odr_set_stream(odr, m_file.get(), stream_write, 0);
 264                 z_GDU(odr, &gdu, 0, 0);
 265             }
 266         }
 267         m_file->out.flush();
 268     }
 269
 270     // unlocked during move
 271     package.move();
 272
 273     // getting timestamp for sending of package
 274     boost::posix_time::ptime send_time
 275         = boost::posix_time::microsec_clock::local_time();
 276
 277     boost::posix_time::time_duration duration = send_time - receive_time;
 278
 279     // scope for locking Ostream
 280     {
 281         boost::mutex::scoped_lock scoped_lock(m_file->m_mutex);
 282
 283         if (m_access)
 284         {
 285             gdu = package.response().get();
 286             if (gdu)
 287             {
 288                 m_file->out
 289                     //<< send_time << " "
 290                     //<< to_iso_string(send_time) << " "
 291                     << to_iso_extended_string(send_time) << " "
 292                     << m_msg_config << " "
 293                     << package << " "
 294                     << to_iso_string(duration) << " "
 295                     << *gdu
 296                     << "\n";
 297             }
 298         }
 299
 300         if (m_res_session)
 301         {
 302             m_file->out << send_time << " " << m_msg_config;
 303             m_file->out << " response id=" << package.session().id();
 304             m_file->out << " close="
 305                              << (package.session().is_closed() ? "yes " : "no ")
 306                              << "duration=" << duration
 307                              << "\n";
 308         }
 309
 310         if (m_init_options)
 311         {
 312             gdu = package.response().get();
 313             if (gdu && gdu->which == Z_GDU_Z3950 &&
 314                 gdu->u.z3950->which == Z_APDU_initResponse)
 315             {
 316                 m_file->out << receive_time << " " << m_msg_config;
 317                 m_file->out << " init options:";
 318                 yaz_init_opt_decode(gdu->u.z3950->u.initResponse->options,
 319                                     option_write, m_file.get());
 320                 m_file->out << "\n";
 321             }
 322         }
 323
 324         if (m_res_apdu)
 325         {
 326             gdu = package.response().get();
 327             if (gdu)
 328             {
 329                 mp::odr odr(ODR_PRINT);
 330                 odr_set_stream(odr, m_file.get(), stream_write, 0);
 331                 z_GDU(odr, &gdu, 0, 0);
 332             }
 333         }
 334
 335         m_file->out.flush();
 336     }
 337 }
 338
 339
 340 void yf::Log::Impl::openfile(const std::string &fname)
 341 {
 342     std::list<LFilePtr>::const_iterator it
 343         = filter_log_files.begin();
 344     for (; it != filter_log_files.end(); it++)
 345     {
 346         if ((*it)->m_fname == fname)
 347         {
 348             m_file = *it;
 349             return;
 350         }
 351     }
 352     // open stdout for empty file
 353     LFilePtr newfile(fname.length() == 0
 354                      ? new LFile(fname, std::cout)
 355                      : new LFile(fname));
 356     filter_log_files.push_back(newfile);
 357     m_file = newfile;
 358 }
 359
 360
 361 void yf::Log::Impl::stream_write(ODR o, void *handle, int type, const char *buf, int len)
 362 {
 363     yf::Log::Impl::LFile *lfile = (yf::Log::Impl::LFile*) handle;
 364     lfile->out.write(buf, len);
 365 }
 366
 367 void yf::Log::Impl::option_write(const char *name, void *handle)
 368 {
 369     yf::Log::Impl::LFile *lfile = (yf::Log::Impl::LFile*) handle;
 370     lfile->out << " " << name;
 371 }
 372
 373
 374 yf::Log::Impl::LFile::LFile(std::string fname) :
 375     m_fname(fname), fout(fname.c_str()), out(fout)
 376 {
 377 }
 378
 379 yf::Log::Impl::LFile::LFile(std::string fname, std::ostream &use_this) :
 380     m_fname(fname), out(use_this)
 381 {
 382 }
 383
 384
 385
 386
 387 static mp::filter::Base* filter_creator()
 388 {
 389     return new mp::filter::Log;
 390 }
 391
 392 extern "C" {
 393     struct metaproxy_1_filter_struct metaproxy_1_filter_log = {
 394         0,
 395         "log",
 396         filter_creator
 397     };
 398 }
 399
 400 /*
 401  * Local variables:
 402  * c-basic-offset: 4
 403  * indent-tabs-mode: nil
 404  * c-file-style: "stroustrup"
 405  * End:
 406  * vim: shiftwidth=4 tabstop=8 expandtab
 407  */