Ticket #3513: log-tzinfo-3513.diff

File log-tzinfo-3513.diff, 14.1 KB (added by zseil, 6 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())