Ticket #3513: log-tzinfo-3513.diff

File log-tzinfo-3513.diff, 14.1 KB (added by zseil, 8 years ago)

add timezone info support to LogFileObservers

  • twisted/python/log.py

     
    1111import sys
    1212import time
    1313import warnings
    14 from datetime import datetime
     14from datetime import datetime, timedelta, tzinfo
    1515import logging
    1616
    1717from zope.interface import Interface
     
    371371    return text
    372372
    373373
     374
     375class _NameAndOffsetInfo(tzinfo):
     376    """
     377    Represents a named, DST unaware, fixed offset time zone.
     378
     379    @type _name: C{str}
     380    @ivar _name: name of this time zone.
     381    @type _offset: C{datetime.timedelta}
     382    @ivar _offset: time zone offset from UTC. East is positive, west is
     383        negative.
     384    """
     385
     386    def __init__(self, name, offset):
     387        """
     388        @type name: C{str}
     389        @param name: name of this time zone.
     390        @type offset: C{datetime.timedelta}
     391        @param offset: timezone offset from UTC.
     392        """
     393        self._name = name
     394        self._offset = offset
     395
     396
     397    def utcoffset(self, dt):
     398        """
     399        Return offset of local time from UTC, in minutes east of UTC.
     400
     401        @rtype: C{datetime.timedelta}
     402        """
     403        return self._offset
     404
     405
     406    def dst(self, dt):
     407        """
     408        Return the daylight saving time adjustment for local time.
     409
     410        C{_NamedFixedOffset} objects are not aware of DST, so this always
     411        returns C{None}.
     412        """
     413        return None
     414
     415
     416    def tzname(self, dt):
     417        """
     418        Return this time zone's name.
     419        """
     420        return self._name
     421
     422
     423    def fromutc(self, dt):
     424        """
     425        Return an aware local C{datetime.datetime} object, equivalent to
     426        UTC C{datetime.datetime} object C{dt}.
     427        """
     428        return dt + self._offset
     429
     430
     431
    374432class FileLogObserver:
    375433    """
    376434    Log observer that writes to a file-like object.
     
    384442        self.write = f.write
    385443        self.flush = f.flush
    386444
     445
    387446    def getTimezoneOffset(self, when):
    388447        """
    389448        Return the current local timezone offset from UTC.
    390449
    391         @type when: C{int}
     450        @type when: C{float}
    392451        @param when: POSIX (ie, UTC) timestamp for which to find the offset.
    393452
    394453        @rtype: C{int}
     
    398457        offset = datetime.utcfromtimestamp(when) - datetime.fromtimestamp(when)
    399458        return offset.days * (60 * 60 * 24) + offset.seconds
    400459
     460
     461    def getTimezoneInfo(self, when):
     462        """
     463        Return timezone information coresponding to the C{when} timestamp.
     464
     465        @type when: C{float}
     466        @param when: POSIX (ie, UTC) timestamp for which to find the timezone
     467            information.
     468
     469        @rtype: C{datetime.tzinfo}
     470        @return: Timezone information for the given timestamp.
     471
     472        By default, the timezone information returned contains UTC offset
     473        information and the name of the local timezone at the C{when}
     474        moment in time.
     475
     476        You can overwrite this method if you want the logged time to be
     477        reported in a different timezone, e.g. if you want to always log in
     478        C{US/Eastern} time::
     479
     480            import pytz # a separate package
     481            from twisted.python import log
     482
     483            class EasternFileLogObserver(log.FileLogObserver):
     484
     485                def getTimezoneInfo(self, when):
     486                    return pytz.timezone("US/Eastern")
     487        """
     488        offset = self.getTimezoneOffset(when)
     489        isdst = time.localtime(when).tm_isdst
     490        name = time.tzname[isdst]
     491        return _NameAndOffsetInfo(name, timedelta(seconds=-offset))
     492
     493
    401494    def formatTime(self, when):
    402495        """
    403         Format the given UTC value as a string representing that time in the
    404         local timezone.
     496        Format the given UTC timestamp as a string representing that time in
     497        the C{self.getTimezoneInfo(when)} timezone.
    405498
    406499        By default it's formatted as a ISO8601-like string (ISO8601 date and
    407         ISO8601 time separated by a space). It can be customized using the
    408         C{timeFormat} attribute, which will be used as input for the underlying
    409         C{time.strftime} call.
     500        ISO8601 time separated by a space, followed by local timezone offset).
     501        It can be customized using the C{timeFormat} attribute, which will be
     502        used as input for the underlying C{datetime.strftime} call.
    410503
    411         @type when: C{int}
    412         @param when: POSIX (ie, UTC) timestamp for which to find the offset.
     504        @type when: C{float}
     505        @param when: POSIX (ie, UTC) timestamp to format.
    413506
    414507        @rtype: C{str}
    415508        """
    416         if self.timeFormat is not None:
    417             return time.strftime(self.timeFormat, time.localtime(when))
     509        info = self.getTimezoneInfo(when)
     510        awareDateTime = datetime.fromtimestamp(when, info)
     511        timeFormat = self.timeFormat
     512        if timeFormat is None:
     513            timeFormat = "%Y-%m-%d %H:%M:%S%z"
     514        return awareDateTime.strftime(timeFormat)
    418515
    419         tzOffset = -self.getTimezoneOffset(when)
    420         when = datetime.utcfromtimestamp(when + tzOffset)
    421         tzHour = abs(int(tzOffset / 60 / 60))
    422         tzMin = abs(int(tzOffset / 60 % 60))
    423         if tzOffset < 0:
    424             tzSign = '-'
    425         else:
    426             tzSign = '+'
    427         return '%d-%02d-%02d %02d:%02d:%02d%s%02d%02d' % (
    428             when.year, when.month, when.day,
    429             when.hour, when.minute, when.second,
    430             tzSign, tzHour, tzMin)
    431516
    432517    def emit(self, eventDict):
    433518        text = textFromEventDict(eventDict)
  • twisted/test/test_log.py

     
    55Tests for L{twisted.python.log}.
    66"""
    77
    8 import os, sys, time, logging, warnings
     8import os, sys, time, logging, warnings, datetime
    99from cStringIO import StringIO
    1010
    1111from twisted.trial import unittest
    1212
    13 from twisted.python import log, failure
     13from twisted.python import log, failure, util
    1414
    1515
    1616class FakeWarning(Warning):
     
    256256
    257257
    258258
     259def timezoneChangingTest(method):
     260    """
     261    Decorator for tests that want to change the local timezone.
     262
     263    It skips the test on platforms that don't support timezone changes and
     264    ensures that the old timezone is restored after the test is run.
     265    """
     266    if getattr(time, 'tzset', None) is None:
     267        method.skip = ("Platform cannot change timezone, cannot verify "
     268                       "correct offsets in well-known timezones.")
     269        return method
     270
     271    def wrapperMethod(self):
     272        originalTimezone = os.environ.get('TZ', None)
     273        try:
     274            method(self)
     275        finally:
     276            if originalTimezone is None:
     277                del os.environ['TZ']
     278            else:
     279                os.environ['TZ'] = originalTimezone
     280            time.tzset()
     281
     282    return util.mergeFunctionMetadata(method, wrapperMethod)
     283
     284
     285
    259286class FileObserverTestCase(LogPublisherTestCaseMixin, unittest.TestCase):
     287    """
     288    Tests for L{twisted.python.log.FileLogObserver}.
     289    """
     290
     291    def setTimezone(self, timezone):
     292        """
     293        Change the system's timezone, by changing the C{TZ} environment
     294        variable to the C{timezone} zoneinfo database file.
     295
     296        This method should only be called from tests decorated with
     297        L{timezoneChangingTest}.
     298        """
     299        os.environ['TZ'] = timezone
     300        time.tzset()
     301
     302
     303    def assertFormat(self, format, when, expected):
     304        """
     305        Assert that when L{FileLogObserver.timeFormat} equals C{format},
     306        and L{FileLogObserver.formatTime} is called with C{when}, a string
     307        equal to C{expected} is returned.
     308        """
     309        oldFormat = self.flo.timeFormat
     310        self.flo.timeFormat = format
     311        try:
     312            self.assertEqual(self.flo.formatTime(when), expected)
     313        finally:
     314            self.flo.timeFormat = oldFormat
     315
     316
    260317    def test_getTimezoneOffset(self):
    261318        """
    262319        Attempt to verify that L{FileLogObserver.getTimezoneOffset} returns
     
    269326        localStandardTuple = (2007, 1, 31, 0, 0, 0, 2, 31, 0)
    270327        utcStandardTimestamp = time.mktime(localStandardTuple)
    271328
    272         originalTimezone = os.environ.get('TZ', None)
    273         try:
    274             # Test something west of UTC
    275             os.environ['TZ'] = 'America/New_York'
    276             time.tzset()
    277             self.assertEqual(
    278                 self.flo.getTimezoneOffset(utcDaylightTimestamp),
    279                 14400)
    280             self.assertEqual(
    281                 self.flo.getTimezoneOffset(utcStandardTimestamp),
    282                 18000)
     329        # Test something west of UTC
     330        self.setTimezone('America/New_York')
     331        self.assertEqual(
     332            self.flo.getTimezoneOffset(utcDaylightTimestamp),
     333            14400)
     334        self.assertEqual(
     335            self.flo.getTimezoneOffset(utcStandardTimestamp),
     336            18000)
    283337
    284             # Test something east of UTC
    285             os.environ['TZ'] = 'Europe/Berlin'
    286             time.tzset()
    287             self.assertEqual(
    288                 self.flo.getTimezoneOffset(utcDaylightTimestamp),
    289                 -7200)
    290             self.assertEqual(
    291                 self.flo.getTimezoneOffset(utcStandardTimestamp),
    292                 -3600)
     338        # Test something east of UTC
     339        self.setTimezone('Europe/Berlin')
     340        self.assertEqual(
     341            self.flo.getTimezoneOffset(utcDaylightTimestamp),
     342            -7200)
     343        self.assertEqual(
     344            self.flo.getTimezoneOffset(utcStandardTimestamp),
     345            -3600)
    293346
    294             # Test a timezone that doesn't have DST
    295             os.environ['TZ'] = 'Africa/Johannesburg'
    296             time.tzset()
    297             self.assertEqual(
    298                 self.flo.getTimezoneOffset(utcDaylightTimestamp),
    299                 -7200)
    300             self.assertEqual(
    301                 self.flo.getTimezoneOffset(utcStandardTimestamp),
    302                 -7200)
    303         finally:
    304             if originalTimezone is None:
    305                 del os.environ['TZ']
    306             else:
    307                 os.environ['TZ'] = originalTimezone
    308             time.tzset()
    309     if getattr(time, 'tzset', None) is None:
    310         test_getTimezoneOffset.skip = (
    311             "Platform cannot change timezone, cannot verify correct offsets "
    312             "in well-known timezones.")
     347        # Test a timezone that doesn't have DST
     348        self.setTimezone('Africa/Johannesburg')
     349        self.assertEqual(
     350            self.flo.getTimezoneOffset(utcDaylightTimestamp),
     351            -7200)
     352        self.assertEqual(
     353            self.flo.getTimezoneOffset(utcStandardTimestamp),
     354            -7200)
     355    test_getTimezoneOffset = timezoneChangingTest(test_getTimezoneOffset)
    313356
    314357
     358    def test_defaultTimezoneInfo(self):
     359        """
     360        Test the default implementation of L{FileLogObserver.getTimezoneInfo}.
     361
     362        The C{datetime.tzinfo} object returned by C{getTimezoneInfo} should
     363        report the correct UTC offset and name for the local timezone. We test
     364        it by changing the local timezone and formatting a few timestamps with
     365        a custom format string.
     366        """
     367        localDaylightTuple = (2006, 6, 30, 0, 0, 0, 4, 181, 1)
     368        utcDaylightTimestamp = time.mktime(localDaylightTuple)
     369        localStandardTuple = (2007, 1, 31, 0, 0, 0, 2, 31, 0)
     370        utcStandardTimestamp = time.mktime(localStandardTuple)
     371
     372        # Test something west of UTC
     373        self.setTimezone('America/New_York')
     374        self.assertFormat("%z", utcDaylightTimestamp, "-0400")
     375        self.assertFormat("%Z", utcDaylightTimestamp, "EDT")
     376        self.assertFormat("%z", utcStandardTimestamp, "-0500")
     377        self.assertFormat("%Z", utcStandardTimestamp, "EST")
     378
     379        # Test something east of UTC
     380        self.setTimezone('Europe/Berlin')
     381        self.assertFormat("%z", utcDaylightTimestamp, "+0200")
     382        self.assertFormat("%Z", utcDaylightTimestamp, "CEST")
     383        self.assertFormat("%z", utcStandardTimestamp, "+0100")
     384        self.assertFormat("%Z", utcStandardTimestamp, "CET")
     385
     386        # Test a timezone that doesn't have DST
     387        self.setTimezone('Africa/Johannesburg')
     388        self.assertFormat("%z", utcDaylightTimestamp, "+0200")
     389        self.assertFormat("%Z", utcDaylightTimestamp, "SAST")
     390        self.assertFormat("%z", utcStandardTimestamp, "+0200")
     391        self.assertFormat("%Z", utcStandardTimestamp, "SAST")
     392    test_defaultTimezoneInfo = timezoneChangingTest(test_defaultTimezoneInfo)
     393
     394
     395    def test_customTimezoneInfo(self):
     396        """
     397        Test that the time logged by L{FileLogObserver} respects the desired
     398        local time, as specified by L{FileLogObserver.getTimezoneInfo}.
     399        """
     400        class SouthTarawaInfo(datetime.tzinfo):
     401            """
     402            A fictional timezone.
     403            """
     404            def utcoffset(self, dt):
     405                return datetime.timedelta(hours=11, minutes=32)
     406
     407            def dst(self, dt):
     408                return datetime.timedelta(0)
     409
     410            def tzname(self, dt):
     411                return "KCT"
     412
     413        when = time.mktime((2000, 1, 1, 0, 0, 0, 5, 1, 0)) - time.timezone
     414        self.flo.getTimezoneInfo = lambda when: SouthTarawaInfo()
     415        self.assertFormat(None, when, "2000-01-01 11:32:00+1132")
     416
     417
    315418    def test_timeFormatting(self):
    316419        """
    317420        Test the method of L{FileLogObserver} which turns a timestamp into a
     
    358461        self.assertEquals(self.flo.formatTime(when), '2001 02')
    359462
    360463
     464    def test_microsecondFormatting(self):
     465        """
     466        Test formatting with microsecond precision. Only works on
     467        Python 2.6 or newer.
     468        """
     469        # one day, to make sure that we don't underflow because of utcoffset,
     470        # plus 0.5, which is an 'exact' float and should not introduce any
     471        # rounding errors.
     472        when = 24 * 60 * 60 + 0.5
     473        self.assertFormat("%f", when, "500000")
     474    if sys.version_info < (2, 6):
     475        test_microsecondFormatting.skip = ("%f format code for strftime is "
     476                                           "only available in Python 2.6")
     477
     478
    361479    def test_loggingAnObjectWithBroken__str__(self):
    362480        #HELLO, MCFLY
    363481        self.lp.msg(EvilStr())