log.cc 20.5 KB
Newer Older
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
// Copyright (C) 2011  Internet Systems Consortium, Inc. ("ISC")
//
// Permission to use, copy, modify, and/or distribute this software for any
// purpose with or without fee is hereby granted, provided that the above
// copyright notice and this permission notice appear in all copies.
//
// THE SOFTWARE IS PROVIDED "AS IS" AND ISC DISCLAIMS ALL WARRANTIES WITH
// REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF MERCHANTABILITY
// AND FITNESS.  IN NO EVENT SHALL ISC BE LIABLE FOR ANY SPECIAL, DIRECT,
// INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES WHATSOEVER RESULTING FROM
// LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION OF CONTRACT, NEGLIGENCE
// OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION WITH THE USE OR
// PERFORMANCE OF THIS SOFTWARE.

#define PY_SSIZE_T_CLEAN
#include <Python.h>
#include <structmember.h>

#include <config.h>

#include <log/message_dictionary.h>
22
#include <log/logger_manager.h>
23
#include <log/logger.h>
24

25
26
27
#include <string>
#include <boost/bind.hpp>

28
using namespace isc::log;
29
30
using std::string;
using boost::bind;
31

32
33
34
35
36
37
38
39
40
// We encountered a strange problem with Clang (clang version 2.8
// (tags/RELEASE_28 115909)) on OSX, where unwinding the stack
// segfaults the moment this exception was thrown and caught.
//
// Placing it in a named namespace instead of the original
// unnamed namespace appears to solve this, so as a temporary
// workaround, we create a local randomly named namespace here
// to solve this issue.
namespace clang_unnamed_namespace_workaround {
41
    // To propagate python exceptions through our code
42
43
44
45
    class InternalError {};
}
using namespace clang_unnamed_namespace_workaround;

46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
namespace {

// This is for testing only. The real module will have it always set as
// NULL and will use the global dictionary.
MessageDictionary* testDictionary = NULL;

PyObject*
setTestDictionary(PyObject*, PyObject* args) {
    PyObject* enableO;
    // The API doesn't seem to provide conversion to bool,
    // so we do it little bit manually
    if (!PyArg_ParseTuple(args, "O", &enableO)) {
        return (NULL);
    }
    int enableI(PyObject_IsTrue(enableO));
    if (enableI == -1) {
        return (NULL);
    }
    bool enable(enableI != 0);

    try {
67
68
        delete testDictionary;
        testDictionary = NULL;
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
        if (enable) {
            testDictionary = new MessageDictionary;
        }
    }
    catch (const std::exception& e) {
        PyErr_SetString(PyExc_RuntimeError, e.what());
        return (NULL);
    }
    catch (...) {
        PyErr_SetString(PyExc_RuntimeError, "Unknown C++ exception");
        return (NULL);
    }
    Py_RETURN_NONE;
}

PyObject*
createMessage(PyObject*, PyObject* args) {
    const char* mid;
    const char* text;
    // We parse the strings
    if (!PyArg_ParseTuple(args, "ss", &mid, &text)) {
        return (NULL);
    }
    PyObject* origMid;
    // And extract the original representation of the message
    // ID, so we can return it instead of creating another instance.
    // This call shouldn't fail if the previous suceeded.
    if (!PyArg_ParseTuple(args, "Os", &origMid, &text)) {
        return (NULL);
    }

    try {
        MessageDictionary* dict = testDictionary ? testDictionary :
            &MessageDictionary::globalDictionary();

        // We ignore the result, they will be in some kind of dupe list
        // if there's a problem
        dict->add(mid, text);
    }
    catch (const std::exception& e) {
        PyErr_SetString(PyExc_RuntimeError, e.what());
        return (NULL);
    }
    catch (...) {
        PyErr_SetString(PyExc_RuntimeError, "Unknown C++ exception");
        return (NULL);
    }

    // Return the ID
    Py_INCREF(origMid);
    return (origMid);
}

PyObject*
getMessage(PyObject*, PyObject* args) {
    const char* mid;
    if (!PyArg_ParseTuple(args, "s", &mid)) {
        return (NULL);
    }

    try {
        MessageDictionary* dict = testDictionary ? testDictionary :
            &MessageDictionary::globalDictionary();

        const std::string& result(dict->getText(mid));
        if (result.empty()) {
            Py_RETURN_NONE;
        } else {
            return (Py_BuildValue("s", result.c_str()));
        }
    }
    catch (const std::exception& e) {
        PyErr_SetString(PyExc_RuntimeError, e.what());
        return (NULL);
    }
    catch (...) {
        PyErr_SetString(PyExc_RuntimeError, "Unknown C++ exception");
        return (NULL);
    }
}

150
151
152
153
154
155
156
157
158
159
160
161
PyObject*
reset(PyObject*, PyObject*) {
    LoggerManager::reset();
    Py_RETURN_NONE;
}

PyObject*
init(PyObject*, PyObject* args) {
    const char* root;
    const char* file(NULL);
    const char* severity("INFO");
    int dbglevel(0);
162
    if (!PyArg_ParseTuple(args, "s|siz", &root, &severity, &dbglevel, &file)) {
163
164
165
166
        return (NULL);
    }

    try {
167
        LoggerManager::init(root, getSeverity(severity), dbglevel, file);
168
169
170
171
172
173
174
175
176
177
178
179
    }
    catch (const std::exception& e) {
        PyErr_SetString(PyExc_RuntimeError, e.what());
        return (NULL);
    }
    catch (...) {
        PyErr_SetString(PyExc_RuntimeError, "Unknown C++ exception");
        return (NULL);
    }
    Py_RETURN_NONE;
}

180
PyMethodDef methods[] = {
181
    {"set_test_dictionary", setTestDictionary, METH_VARARGS,
182
183
184
        "Set or unset testing mode for message dictionary. In testing, "
        "the create_message and get_message functions work on different "
        "than the logger-global dictionary, not polluting it."},
185
    {"create_message", createMessage, METH_VARARGS,
186
187
188
189
        "Creates a new message in the dictionary. You shouldn't need to "
        "call this directly, it should be called by the generated message "
        "file. Returns the identifier to be used in logging. The text "
        "shouldn't be empty."},
190
    {"get_message", getMessage, METH_VARARGS,
191
192
        "Get a message. This function is for testing purposes and you don't "
        "need to call it. It returns None if the message does not exist."},
193
    {"reset", reset, METH_NOARGS,
194
        "Reset all logging. For testing purposes only, do not use."},
195
    {"init", init, METH_VARARGS,
196
197
        "Run-time initialization. You need to call this before you do any "
        "logging, to configure the root logger name. You may also provide "
198
199
200
        "logging severity (one of 'DEBUG', 'INFO', 'WARN', 'ERROR' or "
        "'FATAL'), a debug level (integer in the range 0-99) and a file name "
        "of a dictionary with message text translations."},
201
202
203
    {NULL, NULL, 0, NULL}
};

204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
class LoggerWrapper : public PyObject {
// Everything is public here, as it is accessible only inside this .cc file.
public:
    Logger *logger_;
};

extern PyTypeObject logger_type;

int
Logger_init(LoggerWrapper* self, PyObject* args) {
    const char* name;
    if (!PyArg_ParseTuple(args, "s", &name)) {
        return (-1);
    }
    try {
        self->logger_ = new Logger(name);
        return (0);
    }
    catch (const std::exception& e) {
        PyErr_SetString(PyExc_RuntimeError, e.what());
        return (-1);
    }
    catch (...) {
        PyErr_SetString(PyExc_RuntimeError, "Unknown C++ exception");
        return (-1);
    }
}

void
Logger_destroy(LoggerWrapper* const self) {
    delete self->logger_;
    self->logger_ = NULL;
    Py_TYPE(self)->tp_free(self);
}

239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
// The isc::log doesn't contain function to convert this way
const char*
severityToText(const Severity& severity) {
    switch (severity) {
        case DEFAULT:
            return ("DEFAULT");
        case DEBUG:
            return ("DEBUG");
        case INFO:
            return ("INFO");
        case WARN:
            return ("WARN");
        case ERROR:
            return ("ERROR");
        case FATAL:
            return ("FATAL");
        default:
            return (NULL);
    }
}

PyObject*
Logger_getEffectiveSeverity(LoggerWrapper* self, PyObject*) {
    try {
        return (Py_BuildValue("s",
                              severityToText(
                                  self->logger_->getEffectiveSeverity())));
    }
    catch (const std::exception& e) {
        PyErr_SetString(PyExc_RuntimeError, e.what());
        return (NULL);
    }
    catch (...) {
        PyErr_SetString(PyExc_RuntimeError, "Unknown C++ exception");
        return (NULL);
    }
}

PyObject*
278
Logger_getEffectiveDebugLevel(LoggerWrapper* self, PyObject*) {
279
    try {
280
        return (Py_BuildValue("i", self->logger_->getEffectiveDebugLevel()));
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
    }
    catch (const std::exception& e) {
        PyErr_SetString(PyExc_RuntimeError, e.what());
        return (NULL);
    }
    catch (...) {
        PyErr_SetString(PyExc_RuntimeError, "Unknown C++ exception");
        return (NULL);
    }
}

PyObject*
Logger_setSeverity(LoggerWrapper* self, PyObject* args) {
    const char* severity;
    int dbgLevel = 0;
    if (!PyArg_ParseTuple(args, "z|i", &severity, &dbgLevel)) {
        return (NULL);
    }
    try {
        self->logger_->setSeverity((severity == NULL) ? DEFAULT :
                                   getSeverity(severity), dbgLevel);
    }
    catch (const std::exception& e) {
        PyErr_SetString(PyExc_RuntimeError, e.what());
        return (NULL);
    }
    catch (...) {
        PyErr_SetString(PyExc_RuntimeError, "Unknown C++ exception");
        return (NULL);
    }
    Py_RETURN_NONE;
}

314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
375
376
377
template<class FPtr> // Who should remember the pointer-to-method syntax
PyObject*
Logger_isLevelEnabled(LoggerWrapper* self, FPtr function) {
    try {
        if ((self->logger_->*function)()) {
            Py_RETURN_TRUE;
        } else {
            Py_RETURN_FALSE;
        }
    }
    catch (const std::exception& e) {
        PyErr_SetString(PyExc_RuntimeError, e.what());
        return (NULL);
    }
    catch (...) {
        PyErr_SetString(PyExc_RuntimeError, "Unknown C++ exception");
        return (NULL);
    }
}

PyObject*
Logger_isInfoEnabled(LoggerWrapper* self, PyObject*) {
    return (Logger_isLevelEnabled(self, &Logger::isInfoEnabled));
}

PyObject*
Logger_isWarnEnabled(LoggerWrapper* self, PyObject*) {
    return (Logger_isLevelEnabled(self, &Logger::isWarnEnabled));
}

PyObject*
Logger_isErrorEnabled(LoggerWrapper* self, PyObject*) {
    return (Logger_isLevelEnabled(self, &Logger::isErrorEnabled));
}

PyObject*
Logger_isFatalEnabled(LoggerWrapper* self, PyObject*) {
    return (Logger_isLevelEnabled(self, &Logger::isFatalEnabled));
}

PyObject*
Logger_isDebugEnabled(LoggerWrapper* self, PyObject* args) {
    int level = MIN_DEBUG_LEVEL;
    if (!PyArg_ParseTuple(args, "|i", &level)) {
        return (NULL);
    }

    try {
        if (self->logger_->isDebugEnabled(level)) {
            Py_RETURN_TRUE;
        } else {
            Py_RETURN_FALSE;
        }
    }
    catch (const std::exception& e) {
        PyErr_SetString(PyExc_RuntimeError, e.what());
        return (NULL);
    }
    catch (...) {
        PyErr_SetString(PyExc_RuntimeError, "Unknown C++ exception");
        return (NULL);
    }
}

378
379
380
381
382
383
384
385
386
387
388
389
390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
407
408
409
410
411
412
413
414
415
416
417
418
419
420
421
422
423
424
425
426
427
428
string
objectToStr(PyObject* object, bool convert) {
    PyObject* cleanup(NULL);
    if (convert) {
        object = cleanup = PyObject_Str(object);
        if (object == NULL) {
            throw InternalError();
        }
    }
    const char* value;
    PyObject* tuple(Py_BuildValue("(O)", object));
    if (tuple == NULL) {
        if (cleanup != NULL) {
            Py_DECREF(cleanup);
        }
        throw InternalError();
    }

    if (!PyArg_ParseTuple(tuple, "s", &value)) {
        Py_DECREF(tuple);
        if (cleanup != NULL) {
            Py_DECREF(cleanup);
        }
        throw InternalError();
    }
    string result(value);
    Py_DECREF(tuple);
    if (cleanup != NULL) {
        Py_DECREF(cleanup);
    }
    return (result);
}

// Generic function to output the logging message. Called by the real functions.
template<class Function>
PyObject*
Logger_performOutput(Function function, PyObject* args, bool dbgLevel) {
    try {
        Py_ssize_t number(PyObject_Length(args));
        if (number < 0) {
            return (NULL);
        }

        // Which argument is the first to format?
        size_t start(1);
        if (dbgLevel) {
            start ++;
        }

        if (number < start) {
            return (PyErr_Format(PyExc_TypeError, "Too few arguments to "
Jelte Jansen's avatar
Jelte Jansen committed
429
                                 "logging call, at least %zu needed and %zd "
430
431
432
433
434
435
436
437
438
439
440
441
442
443
444
445
446
447
448
449
450
451
                                 "given", start, number));
        }

        // Extract the fixed arguments
        PyObject *midO(PySequence_GetItem(args, start - 1));
        if (midO == NULL) {
            return (NULL);
        }
        string mid(objectToStr(midO, false));
        long dbg(0);
        if (dbgLevel) {
            PyObject *dbgO(PySequence_GetItem(args, 0));
            if (dbgO == NULL) {
                return (NULL);
            }
            dbg = PyLong_AsLong(dbgO);
            if (PyErr_Occurred()) {
                return (NULL);
            }
        }

        // We create the logging message right now. If we fail to convert a
Jelte Jansen's avatar
Jelte Jansen committed
452
        // parameter to string, at least the part that we already did will
453
454
455
456
457
458
459
460
461
462
463
464
465
466
467
468
469
470
471
472
473
474
475
476
477
478
479
480
481
482
483
484
485
486
487
488
489
490
491
492
493
494
495
496
497
498
499
500
501
502
503
504
505
506
507
508
509
510
511
        // be output
        Logger::Formatter formatter(function(dbg, mid.c_str()));

        // Now process the rest of parameters, convert each to string and put
        // into the formatter. It will print itself in the end.
        for (size_t i(start); i < number; ++ i) {
            PyObject* param(PySequence_GetItem(args, i));
            if (param == NULL) {
                return (NULL);
            }
            formatter = formatter.arg(objectToStr(param, true));
        }
        Py_RETURN_NONE;
    }
    catch (const InternalError&) {
        return (NULL);
    }
    catch (const std::exception& e) {
        PyErr_SetString(PyExc_RuntimeError, e.what());
        return (NULL);
    }
    catch (...) {
        PyErr_SetString(PyExc_RuntimeError, "Unknown C++ exception");
        return (NULL);
    }
}

// Now map the functions into the performOutput. I wish C++ could do
// functional programming.
PyObject*
Logger_debug(LoggerWrapper* self, PyObject* args) {
    return (Logger_performOutput(bind(&Logger::debug, self->logger_, _1, _2),
                                 args, true));
}

PyObject*
Logger_info(LoggerWrapper* self, PyObject* args) {
    return (Logger_performOutput(bind(&Logger::info, self->logger_, _2),
                                 args, false));
}

PyObject*
Logger_warn(LoggerWrapper* self, PyObject* args) {
    return (Logger_performOutput(bind(&Logger::warn, self->logger_, _2),
                                 args, false));
}

PyObject*
Logger_error(LoggerWrapper* self, PyObject* args) {
    return (Logger_performOutput(bind(&Logger::error, self->logger_, _2),
                                 args, false));
}

PyObject*
Logger_fatal(LoggerWrapper* self, PyObject* args) {
    return (Logger_performOutput(bind(&Logger::fatal, self->logger_, _2),
                                 args, false));
}

512
PyMethodDef loggerMethods[] = {
513
514
515
    { "get_effective_severity",
        reinterpret_cast<PyCFunction>(Logger_getEffectiveSeverity),
        METH_NOARGS, "Returns the effective logging severity as string" },
516
517
    { "get_effective_debug_level",
        reinterpret_cast<PyCFunction>(Logger_getEffectiveDebugLevel),
518
519
520
521
522
523
        METH_NOARGS, "Returns the current debug level." },
    { "set_severity",
        reinterpret_cast<PyCFunction>(Logger_setSeverity), METH_VARARGS,
        "Sets the severity of a logger. The parameters are severity as a "
        "string and, optionally, a debug level (integer in range 0-99). "
        "The severity may be NULL, in which case an inherited value is taken."
524
    },
525
526
    { "is_debug_enabled", reinterpret_cast<PyCFunction>(Logger_isDebugEnabled),
        METH_VARARGS, "Returns if the logger would log debug message now. "
527
            "You can provide a desired debug level." },
528
529
530
531
532
533
534
535
    { "is_info_enabled", reinterpret_cast<PyCFunction>(Logger_isInfoEnabled),
        METH_NOARGS, "Returns if the logger would log info message now." },
    { "is_warn_enabled", reinterpret_cast<PyCFunction>(Logger_isWarnEnabled),
        METH_NOARGS, "Returns if the logger would log warn message now." },
    { "is_error_enabled", reinterpret_cast<PyCFunction>(Logger_isErrorEnabled),
        METH_NOARGS, "Returns if the logger would log error message now." },
    { "is_fatal_enabled", reinterpret_cast<PyCFunction>(Logger_isFatalEnabled),
        METH_NOARGS, "Returns if the logger would log fatal message now." },
536
537
538
539
540
541
542
543
544
545
546
547
548
549
550
    { "debug", reinterpret_cast<PyCFunction>(Logger_debug), METH_VARARGS,
        "Logs a debug-severity message. It takes the debug level, message ID "
        "and any number of stringifiable arguments to the message." },
    { "info", reinterpret_cast<PyCFunction>(Logger_info), METH_VARARGS,
        "Logs a info-severity message. It taskes the message ID and any "
        "number of stringifiable arguments to the message." },
    { "warn", reinterpret_cast<PyCFunction>(Logger_warn), METH_VARARGS,
        "Logs a warn-severity message. It taskes the message ID and any "
        "number of stringifiable arguments to the message." },
    { "error", reinterpret_cast<PyCFunction>(Logger_error), METH_VARARGS,
        "Logs a error-severity message. It taskes the message ID and any "
        "number of stringifiable arguments to the message." },
    { "fatal", reinterpret_cast<PyCFunction>(Logger_fatal), METH_VARARGS,
        "Logs a fatal-severity message. It taskes the message ID and any "
        "number of stringifiable arguments to the message." },
551
552
553
554
555
556
557
558
559
560
561
562
563
564
565
566
567
568
569
570
571
572
573
574
575
576
577
578
579
580
581
582
583
584
585
586
587
588
589
590
591
592
593
594
595
596
597
598
599
600
601
602
603
604
    { NULL, NULL, 0, NULL }
};

PyTypeObject logger_type = {
    PyVarObject_HEAD_INIT(NULL, 0)
    "isc.log.Logger",
    sizeof(LoggerWrapper),                 // tp_basicsize
    0,                                  // tp_itemsize
    reinterpret_cast<destructor>(Logger_destroy),       // tp_dealloc
    NULL,                               // tp_print
    NULL,                               // tp_getattr
    NULL,                               // tp_setattr
    NULL,                               // tp_reserved
    NULL,                               // tp_repr
    NULL,                               // tp_as_number
    NULL,                               // tp_as_sequence
    NULL,                               // tp_as_mapping
    NULL,                               // tp_hash 
    NULL,                               // tp_call
    NULL,                               // tp_str
    NULL,                               // tp_getattro
    NULL,                               // tp_setattro
    NULL,                               // tp_as_buffer
    Py_TPFLAGS_DEFAULT,                 // tp_flags
    "Wrapper around the C++ isc::log::Logger class."
    "It is not complete, but everything important should be here.",
    NULL,                               // tp_traverse
    NULL,                               // tp_clear
    NULL,                               // tp_richcompare
    0,                                  // tp_weaklistoffset
    NULL,                               // tp_iter
    NULL,                               // tp_iternext
    loggerMethods,                      // tp_methods
    NULL,                               // tp_members
    NULL,                               // tp_getset
    NULL,                               // tp_base
    NULL,                               // tp_dict
    NULL,                               // tp_descr_get
    NULL,                               // tp_descr_set
    0,                                  // tp_dictoffset
    reinterpret_cast<initproc>(Logger_init),            // tp_init
    NULL,                               // tp_alloc
    PyType_GenericNew,                  // tp_new
    NULL,                               // tp_free
    NULL,                               // tp_is_gc
    NULL,                               // tp_bases
    NULL,                               // tp_mro
    NULL,                               // tp_cache
    NULL,                               // tp_subclasses
    NULL,                               // tp_weaklist
    NULL,                               // tp_del
    0                                   // tp_version_tag
};

605
606
607
608
609
610
611
612
613
614
615
616
617
618
PyModuleDef iscLog = {
    { PyObject_HEAD_INIT(NULL) NULL, 0, NULL},
    "log",
    "Python bindings for the classes in the isc::log namespace.\n\n"
    "These bindings are close match to the C++ API, but they are not complete "
    "(some parts are not needed) and some are done in more python-like ways.",
    -1,
    methods,
    NULL,
    NULL,
    NULL,
    NULL
};

Jelte Jansen's avatar
Jelte Jansen committed
619
} // end anonymous namespace
620
621
622
623
624
625
626
627

PyMODINIT_FUNC
PyInit_log(void) {
    PyObject* mod = PyModule_Create(&iscLog);
    if (mod == NULL) {
        return (NULL);
    }

628
629
630
631
632
633
634
635
636
637
638
    if (PyType_Ready(&logger_type) < 0) {
        return (NULL);
    }

    if (PyModule_AddObject(mod, "Logger",
                           static_cast<PyObject*>(static_cast<void*>(
                               &logger_type))) < 0) {
        return (NULL);
    }
    Py_INCREF(&logger_type);

639
640
    return (mod);
}