summaryrefslogtreecommitdiff
path: root/tests/unittests/test_log.py
blob: 87c69dbbec0bb66e2ce7db350bda5a8a05810d5e (plain)
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
# This file is part of cloud-init. See LICENSE file for license information.

"""Tests for cloudinit.log """

import datetime
import io
import logging
import time

from cloudinit import log as ci_logging
from cloudinit.analyze.dump import CLOUD_INIT_ASCTIME_FMT
from tests.unittests.helpers import CiTestCase


class TestCloudInitLogger(CiTestCase):
    def setUp(self):
        # set up a logger like cloud-init does in setupLogging, but instead
        # of sys.stderr, we'll plug in a StringIO() object so we can see
        # what gets logged
        logging.Formatter.converter = time.gmtime
        self.ci_logs = io.StringIO()
        self.ci_root = logging.getLogger()
        console = logging.StreamHandler(self.ci_logs)
        console.setFormatter(logging.Formatter(ci_logging.DEF_CON_FORMAT))
        console.setLevel(ci_logging.DEBUG)
        self.ci_root.addHandler(console)
        self.ci_root.setLevel(ci_logging.DEBUG)
        self.LOG = logging.getLogger("test_cloudinit_logger")

    def test_logger_uses_gmtime(self):
        """Test that log message have timestamp in UTC (gmtime)"""

        # Log a message, extract the timestamp from the log entry
        # convert to datetime, and compare to a utc timestamp before
        # and after the logged message.

        # Due to loss of precision in the LOG timestamp, subtract and add
        # time to the utc stamps for comparison
        #
        # utc_before: 2017-08-23 14:19:42.569299
        # parsed dt : 2017-08-23 14:19:43.069000
        # utc_after : 2017-08-23 14:19:43.570064

        utc_before = datetime.datetime.utcnow() - datetime.timedelta(0, 0.5)
        self.LOG.error("Test message")
        utc_after = datetime.datetime.utcnow() + datetime.timedelta(0, 0.5)

        # extract timestamp from log:
        # 2017-08-23 14:19:43,069 - test_log.py[ERROR]: Test message
        logstr = self.ci_logs.getvalue().splitlines()[0]
        timestampstr = logstr.split(" - ")[0]
        parsed_dt = datetime.datetime.strptime(
            timestampstr, CLOUD_INIT_ASCTIME_FMT
        )

        self.assertLess(utc_before, parsed_dt)
        self.assertLess(parsed_dt, utc_after)
        self.assertLess(utc_before, utc_after)
        self.assertGreater(utc_after, parsed_dt)