Log filter writes by default to stdout again.
[metaproxy-moved-to-github.git] / src / filter_log.cpp
1 /* $Id: filter_log.cpp,v 1.21 2006-06-21 12:50:35 adam Exp $
2    Copyright (c) 2005-2006, Index Data.
3
4    See the LICENSE file for details
5  */
6
7 #include "config.hpp"
8
9 #include "package.hpp"
10
11 #include <string>
12 #include <boost/thread/mutex.hpp>
13 #include <boost/date_time/posix_time/posix_time.hpp>
14
15 #include "util.hpp"
16 #include "xmlutil.hpp"
17 #include "filter_log.hpp"
18
19 #include <fstream>
20 #include <yaz/zgdu.h>
21
22 namespace mp = metaproxy_1;
23 namespace yf = metaproxy_1::filter;
24
25 namespace metaproxy_1 {
26     namespace filter {
27         class Log::LFile {
28         public:
29             boost::mutex m_mutex;
30             std::string m_fname;
31             std::ofstream fout;
32             std::ostream &out;
33             LFile(std::string fname);
34             LFile(std::string fname, std::ostream &use_this);
35         };
36         typedef boost::shared_ptr<Log::LFile> LFilePtr;
37         class Log::Rep {
38             friend class Log;
39             Rep();
40             void openfile(const std::string &fname);
41             std::string m_msg;
42             LFilePtr m_file;
43             bool m_req_apdu;
44             bool m_res_apdu;
45             bool m_req_session;
46             bool m_res_session;
47             bool m_init_options;
48         };
49         // Only used during configure stage (no threading)
50         static std::list<LFilePtr> filter_log_files;
51     }
52 }
53
54 yf::Log::Rep::Rep()
55 {
56     m_req_apdu = true;
57     m_res_apdu = true;
58     m_req_session = true;
59     m_res_session = true;
60     m_init_options = false;
61     openfile("");
62 }
63
64 yf::Log::Log(const std::string &x) : m_p(new Rep)
65 {
66     m_p->m_msg = x;
67 }
68
69 yf::Log::Log() : m_p(new Rep)
70 {
71 }
72
73 yf::Log::~Log() {}
74
75 void stream_write(ODR o, void *handle, int type, const char *buf, int len)
76 {
77     yf::Log::LFile *lfile = (yf::Log::LFile*) handle;
78     lfile->out.write(buf, len);
79 }
80
81 void option_write(const char *name, void *handle)
82 {
83     yf::Log::LFile *lfile = (yf::Log::LFile*) handle;
84     lfile->out << " " << name;
85 }
86
87 void yf::Log::process(mp::Package &package) const
88 {
89     Z_GDU *gdu;
90
91     // getting timestamp for receiving of package
92     boost::posix_time::ptime receive_time
93         = boost::posix_time::microsec_clock::local_time();
94
95     // scope for locking Ostream 
96     { 
97         boost::mutex::scoped_lock scoped_lock(m_p->m_file->m_mutex);
98         
99         if (m_p->m_req_session)
100         {
101             m_p->m_file->out << receive_time << " " << m_p->m_msg;
102             m_p->m_file->out << " request id=" << package.session().id();
103             m_p->m_file->out << " close=" 
104                              << (package.session().is_closed() ? "yes" : "no")
105                              << "\n";
106         }
107         if (m_p->m_init_options)
108         {
109             gdu = package.request().get();
110             if (gdu && gdu->which == Z_GDU_Z3950 &&
111                 gdu->u.z3950->which == Z_APDU_initRequest)
112             {
113                 m_p->m_file->out << receive_time << " " << m_p->m_msg;
114                 m_p->m_file->out << " init options:";
115                 yaz_init_opt_decode(gdu->u.z3950->u.initRequest->options,
116                                     option_write, m_p->m_file.get());
117                 m_p->m_file->out << "\n";
118             }
119         }
120
121         if (m_p->m_req_apdu)
122         {
123             gdu = package.request().get();
124             if (gdu)
125             {
126                 mp::odr odr(ODR_PRINT);
127                 odr_set_stream(odr, m_p->m_file.get(), stream_write, 0);
128                 z_GDU(odr, &gdu, 0, 0);
129             }
130         }
131         m_p->m_file->out.flush();
132     }
133
134     // unlocked during move
135     package.move();
136
137     // getting timestamp for sending of package
138     boost::posix_time::ptime send_time
139         = boost::posix_time::microsec_clock::local_time();
140
141     boost::posix_time::time_duration duration = send_time - receive_time;
142
143     // scope for locking Ostream 
144     { 
145         boost::mutex::scoped_lock scoped_lock(m_p->m_file->m_mutex);
146         if (m_p->m_res_session)
147         {
148             m_p->m_file->out << send_time << " " << m_p->m_msg;
149             m_p->m_file->out << " response id=" << package.session().id();
150             m_p->m_file->out << " close=" 
151                              << (package.session().is_closed() ? "yes " : "no ")
152                              << "duration=" << duration      
153                              << "\n";
154         }
155         if (m_p->m_init_options)
156         {
157             gdu = package.response().get();
158             if (gdu && gdu->which == Z_GDU_Z3950 &&
159                 gdu->u.z3950->which == Z_APDU_initResponse)
160             {
161                 m_p->m_file->out << receive_time << " " << m_p->m_msg;
162                 m_p->m_file->out << " init options:";
163                 yaz_init_opt_decode(gdu->u.z3950->u.initResponse->options,
164                                     option_write, m_p->m_file.get());
165                 m_p->m_file->out << "\n";
166             }
167         }
168         if (m_p->m_res_apdu)
169         {
170             gdu = package.response().get();
171             if (gdu)
172             {
173                 mp::odr odr(ODR_PRINT);
174                 odr_set_stream(odr, m_p->m_file.get(), stream_write, 0);
175                 z_GDU(odr, &gdu, 0, 0);
176             }
177         }
178         m_p->m_file->out.flush();
179     }
180 }
181
182 yf::Log::LFile::LFile(std::string fname) : 
183     m_fname(fname), fout(fname.c_str()), out(fout)
184 {
185 }
186
187 yf::Log::LFile::LFile(std::string fname, std::ostream &use_this) : 
188     m_fname(fname), out(use_this)
189 {
190 }
191
192 void yf::Log::Rep::openfile(const std::string &fname)
193 {
194     std::list<LFilePtr>::const_iterator it = filter_log_files.begin();
195     for (; it != filter_log_files.end(); it++)
196     {
197         if ((*it)->m_fname == fname)
198         {
199             m_file = *it;
200             return;
201         }
202     }
203     // open stdout for empty file
204     LFilePtr newfile(fname.length() == 0 
205                      ? new LFile(fname, std::cout) 
206                      : new LFile(fname));
207     filter_log_files.push_back(newfile);
208     m_file = newfile;
209 }
210
211 void yf::Log::configure(const xmlNode *ptr)
212 {
213     for (ptr = ptr->children; ptr; ptr = ptr->next)
214     {
215         if (ptr->type != XML_ELEMENT_NODE)
216             continue;
217         if (!strcmp((const char *) ptr->name, "message"))
218             m_p->m_msg = mp::xml::get_text(ptr);
219         else if (!strcmp((const char *) ptr->name, "filename"))
220         {
221             std::string fname = mp::xml::get_text(ptr);
222             m_p->openfile(fname);
223         }
224         else if (!strcmp((const char *) ptr->name, "category"))
225         {
226             const struct _xmlAttr *attr;
227             for (attr = ptr->properties; attr; attr = attr->next)
228             {
229                 if (!strcmp((const char *) attr->name, "request-apdu"))
230                     m_p->m_req_apdu = mp::xml::get_bool(attr->children, true);
231                 else if (!strcmp((const char *) attr->name, "response-apdu"))
232                     m_p->m_res_apdu = mp::xml::get_bool(attr->children, true);
233                 else if (!strcmp((const char *) attr->name, "apdu"))
234                 {
235                     m_p->m_req_apdu = mp::xml::get_bool(attr->children, true);
236                     m_p->m_res_apdu = m_p->m_req_apdu;
237                 }
238                 else if (!strcmp((const char *) attr->name,
239                                  "request-session"))
240                     m_p->m_req_session = 
241                         mp::xml::get_bool(attr->children, true);
242                 else if (!strcmp((const char *) attr->name, 
243                                  "response-session"))
244                     m_p->m_res_session = 
245                         mp::xml::get_bool(attr->children, true);
246                 else if (!strcmp((const char *) attr->name,
247                                  "session"))
248                 {
249                     m_p->m_req_session = 
250                         mp::xml::get_bool(attr->children, true);
251                     m_p->m_res_session = m_p->m_req_session;
252                 }
253                 else if (!strcmp((const char *) attr->name, 
254                                  "init-options"))
255                     m_p->m_init_options = 
256                         mp::xml::get_bool(attr->children, true);
257                 else
258                     throw mp::filter::FilterException(
259                         "Bad attribute " + std::string((const char *)
260                                                        attr->name));
261             }
262         }
263         else
264         {
265             throw mp::filter::FilterException("Bad element " 
266                                                + std::string((const char *)
267                                                              ptr->name));
268         }
269     }
270 }
271
272 static mp::filter::Base* filter_creator()
273 {
274     return new mp::filter::Log;
275 }
276
277 extern "C" {
278     struct metaproxy_1_filter_struct metaproxy_1_filter_log = {
279         0,
280         "log",
281         filter_creator
282     };
283 }
284
285 /*
286  * Local variables:
287  * c-basic-offset: 4
288  * indent-tabs-mode: nil
289  * c-file-style: "stroustrup"
290  * End:
291  * vim: shiftwidth=4 tabstop=8 expandtab
292  */