File: test_handler.py

package info (click to toggle)
graypy 2.1.0-3
  • links: PTS, VCS
  • area: main
  • in suites: forky, sid
  • size: 312 kB
  • sloc: python: 1,175; sh: 114; makefile: 3
file content (230 lines) | stat: -rw-r--r-- 7,921 bytes parent folder | download
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
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
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
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
#!/usr/bin/env python
# -*- coding: utf-8 -*-

"""pytests for the formatting and construction of GELF logs by the graypy
logging handlers

.. note::

    These tests mock sending to Graylog and do not require an active graylog
    instance to operate.
"""

import datetime
import json
import logging
import socket
import sys
import zlib

from unittest import mock
import pytest

from graypy.handler import BaseGELFHandler, GELFHTTPHandler, GELFTLSHandler

from tests.helper import handler, logger, formatted_logger
from tests.unit.helper import MOCK_LOG_RECORD, MOCK_LOG_RECORD_NAME

UNICODE_REPLACEMENT = u"\ufffd"


class TestClass(object):
    def __repr__(self):
        return "<TestClass>"


@pytest.yield_fixture
def mock_send(handler):
    try:
        with mock.patch.object(handler, "send") as mock_send:
            yield mock_send
    except Exception:
        with mock.patch.object(handler, "emit") as mock_send:
            yield mock_send


def get_mock_send_arg(mock_send):
    assert mock_send.call_args_list != []
    [[[arg], _]] = mock_send.call_args_list

    # TODO: this is inaccurate solution for mocking non-send handlers
    if isinstance(arg, logging.LogRecord):
        return json.loads(
            BaseGELFHandler(compress=False).makePickle(arg).decode("utf-8")
        )
    try:
        return json.loads(zlib.decompress(arg).decode("utf-8"))
    except zlib.error:  # we have a uncompress message
        try:
            return json.loads(arg.decode("utf-8"))
        except Exception:  # that is null terminated
            return json.loads(arg[:-1].decode("utf-8"))


@pytest.mark.parametrize(
    "message,expected",
    [
        (u"\u20AC", u"\u20AC"),
        (u"\u20AC".encode("utf-8"), u"\u20AC"),
        (b"\xc3", UNICODE_REPLACEMENT),
        (["a", b"\xc3"], ["a", UNICODE_REPLACEMENT]),
    ],
)
def test_pack(message, expected):
    assert expected == json.loads(
        BaseGELFHandler._pack_gelf_dict(message).decode("utf-8")
    )


def test_manual_exc_info_handler(logger, mock_send):
    """Check that a the ``full_message`` traceback info is passed when
    the ``exc_info=1`` flag is given within a log message"""
    try:
        raise SyntaxError("Syntax error")
    except SyntaxError:
        logger.error("Failed", exc_info=1)
    arg = get_mock_send_arg(mock_send)
    assert "Failed" == arg["short_message"]
    assert arg["full_message"].startswith("Traceback (most recent call last):")

    # GELFHTTPHandler mocking does not complete the stacktrace
    # thus a missing \n
    assert arg["full_message"].endswith("SyntaxError: Syntax error") or arg[
        "full_message"
    ].endswith("SyntaxError: Syntax error\n")


def test_normal_exception_handler(logger, mock_send):
    try:
        raise SyntaxError("Syntax error")
    except SyntaxError:
        logger.exception("Failed")
    arg = get_mock_send_arg(mock_send)
    assert "Failed" == arg["short_message"]
    assert arg["full_message"].startswith("Traceback (most recent call last):")

    # GELFHTTPHandler mocking does not complete the stacktrace
    # thus a missing \n
    assert arg["full_message"].endswith("SyntaxError: Syntax error") or arg[
        "full_message"
    ].endswith("SyntaxError: Syntax error\n")


def test_unicode(logger, mock_send):
    logger.error(u"Mensaje de registro espa\xf1ol")
    arg = get_mock_send_arg(mock_send)
    assert u"Mensaje de registro espa\xf1ol" == arg["short_message"]


@pytest.mark.skipif(sys.version_info[0] >= 3, reason="python2 only")
def test_broken_unicode_python2(logger, mock_send):
    # py3 record.getMessage() returns a binary string here
    # which is safely converted to unicode during the sanitization
    # process
    logger.error(b"Broken \xde log message")
    decoded = get_mock_send_arg(mock_send)
    assert u"Broken %s log message" % UNICODE_REPLACEMENT == decoded["short_message"]


@pytest.mark.skipif(sys.version_info[0] < 3, reason="python3 only")
def test_broken_unicode_python3(logger, mock_send):
    # py3 record.getMessage() returns somewhat broken "b"foo"" if the
    # message string is not a string, but a binary object: b"foo"
    logger.error(b"Broken \xde log message")
    decoded = get_mock_send_arg(mock_send)
    assert "b'Broken \\xde log message'" == decoded["short_message"]


def test_extra_field(logger, mock_send):
    logger.error("Log message", extra={"foo": "bar"})
    decoded = get_mock_send_arg(mock_send)
    assert "Log message" == decoded["short_message"]
    assert "bar" == decoded["_foo"]


def test_list(logger, mock_send):
    logger.error("Log message", extra={"foo": ["bar", "baz"]})
    decoded = get_mock_send_arg(mock_send)
    assert "Log message" == decoded["short_message"]
    assert ["bar", "baz"] == decoded["_foo"]


def test_arbitrary_object(logger, mock_send):
    logger.error("Log message", extra={"foo": TestClass()})
    decoded = get_mock_send_arg(mock_send)
    assert "Log message" == decoded["short_message"]
    assert "<TestClass>" == decoded["_foo"]


def test_message_to_pickle_serializes_datetime_objects_instead_of_blindly_repring_them(
    logger, mock_send
):
    timestamp = datetime.datetime(2001, 2, 3, 4, 5, 6, 7)
    logger.error("Log message", extra={"ts": timestamp})
    decoded = get_mock_send_arg(mock_send)
    assert "datetime.datetime" not in decoded["_ts"]
    assert timestamp.isoformat() == decoded["_ts"]


def test_status_field_issue(logger, mock_send):
    logger.error("Log message", extra={"status": "OK"})
    decoded = get_mock_send_arg(mock_send)
    assert "Log message" == decoded["short_message"]
    assert "OK" == decoded["_status"]


def test_add_level_name():
    gelf_dict = dict()
    BaseGELFHandler._add_level_names(gelf_dict, MOCK_LOG_RECORD)
    assert "INFO" == gelf_dict["level_name"]


def test_resolve_host():
    """Test all posible resolutions of :meth:`BaseGELFHandler._resolve_host`"""
    assert socket.gethostname() == BaseGELFHandler._resolve_host(False, None)
    assert socket.getfqdn() == BaseGELFHandler._resolve_host(True, None)
    assert socket.getfqdn() == BaseGELFHandler._resolve_host(True, "localhost")
    assert "localhost" == BaseGELFHandler._resolve_host(False, "localhost")
    assert "" == BaseGELFHandler._resolve_host(False, "")


def test_set_custom_facility():
    gelf_dict = dict()
    facility = "test facility"
    BaseGELFHandler._set_custom_facility(gelf_dict, facility, MOCK_LOG_RECORD)
    assert MOCK_LOG_RECORD_NAME == gelf_dict["_logger"]
    assert "test facility" == gelf_dict["facility"]


def test_formatted_logger(formatted_logger, mock_send):
    """Test the ability to set and modify the graypy handler's
    :class:`logging.Formatter` and have the resultant ``short_message`` be
    formatted by the set :class:`logging.Formatter`"""
    for handler in formatted_logger.handlers:
        if isinstance(handler, GELFHTTPHandler):
            pytest.skip("formatting not mocked for GELFHTTPHandler")
    formatted_logger.error("Log message")
    decoded = get_mock_send_arg(mock_send)
    assert "ERROR : Log message" == decoded["short_message"]


def test_invalid_fqdn_localhost():
    """Test constructing :class:`graypy.handler.BaseGELFHandler` with
    specifying conflicting arguments ``fqdn`` and ``localname``"""
    with pytest.raises(ValueError):
        BaseGELFHandler(fqdn=True, localname="localhost")


def test_invalid_ca_certs():
    """Test constructing :class:`graypy.handler.GELFTLSHandler` with
    incorrect arguments specifying server ca cert verification"""
    with pytest.raises(ValueError):
        GELFTLSHandler("127.0.0.1", validate=True)


def test_invalid_client_certs():
    """Test constructing :class:`graypy.handler.GELFTLSHandler` with
    incorrect arguments specifying client cert/key verification"""
    with pytest.raises(ValueError):
        # missing client cert
        GELFTLSHandler("127.0.0.1", keyfile="/dev/null")