{"id":7901,"date":"2018-03-06T16:51:01","date_gmt":"2018-03-06T21:51:01","guid":{"rendered":"http:\/\/esr.ibiblio.org\/?p=7901"},"modified":"2018-03-07T10:39:22","modified_gmt":"2018-03-07T15:39:22","slug":"stop-logging-in-local-time","status":"publish","type":"post","link":"http:\/\/esr.ibiblio.org\/?p=7901","title":{"rendered":"Stop logging in local time!"},"content":{"rendered":"<p>Inertia is a powerful force. The computing world retains a lot of practices that are odd little dysfunctional relics of past stages of its technology. The one I&#8217;m here to talk about today looks like this:<\/p>\n<p>Mar 6 15:11:07 snark postfix\/qmgr[3927]: 0422513A6C53: removed<\/p>\n<p>That&#8217;s a log message hot&#8217;n&#8217;fresh from my \/var\/log\/mail.log file. It&#8217;s entirely typical of traditional log formats on Unix systems, and these things offend the bejeezus out of me every time I see them. Now let me show you how this would look in a sane universe:<\/p>\n<p><!--more--><\/p>\n<p>2018-03-06T15:11:07Z snark.thyrsus.com postfix\/qmgr[3927]: 0422513A6C53: removed<\/p>\n<p>Logging events in local time (and with only local hostnames, but that&#8217;s not the subject of today&#8217;s rant) is a dysfunctional remnant of the time before wide-area networks. It means that log timestamps aren&#8217;t directly comparable across hosts in different time zones. This is death on diagnostics for a large class of network-transaction bugs.<\/p>\n<p>Actually it can mean a lot worse than that, even locally. An A&amp;D regular who wishes to remain nameless recently told me of once having to help troubleshoot a medical-records system at a major hospital. It was unusable &#8211; they had to plan around this and retreat to a paper backup system &#8211; for two hours a year. Those two hours were just adjacent to daylight-saving-time changes. Yes, that&#8217;s right, stamp collisions due to logging in local time <em>crashed their multi-megabuck investment.<\/em><\/p>\n<p>Another place logging and displaying in local time is a bad mistake is in distributed version-control systems. I&#8217;ve never seen a case in which it was not more important to know the relative time of a sequence of commits than to know the, er, &#8220;absolute&#8221; local time of any of them. And, of course, committers may be scattered across multiple timezones. Thus, the way to reduce cognitive friction on people browsing the history is to refer (display, and not just storage of) all commit timestamps to common timebase.<\/p>\n<p>Yes, git does get this wrong. Git timestamps are stored in UTC but displayed in the committer&#8217;s local time in git log and elsewhere. To accomplish this git has to keep a local time zone offset with each date, a pointless &#8220;feature&#8221; that often causes me chronic problems too tedious to explain when I do repository conversions.<\/p>\n<p>You know who got this right first? Military and civil aviation. Long before Internet traffic routinely crossed timezones, airplanes did. Requiring pilots and ground controllers to constantly track everybody&#8217;s timezones and do conversions on the fly would be confusing and dangerous, so&#8230;Zulu time for everybody. Loss-of-life risk is lower where we play (except maybe at that hospital?) but the underlying logic for ditching local time is the same.<\/p>\n<p>EDIT: It has been pointed out to me that radio and telegraph operators faced similar situational stresses as far back as the mid-1800s. It&#8217;s not clear, however, how soon GMT became on-air standard time after it was formalized in 1847.<\/p>\n<p>So next time you have to choose a time stamp format, cut the crap and go straight to <a href=\"https:\/\/www.ietf.org\/rfc\/rfc3339.txt\">RFC3339<\/a> (<em>with<\/em> the T in the middle, thank you). It has many advantages. It&#8217;s unambiguous, compact, compares correctly no matter where it came from, constant length, sorts lexicographically the same as its time order, and parses out of text as a single token that is easy to distinguish from anything <em>but<\/em> an RC3339 timestamp (that&#8217;s why you want to leave the T in the middle).<\/p>\n<p>(But in case you&#8217;re tempted to think about Zulu for <em>all<\/em> purposes&#8230;bad idea. See also <a href=\"http:\/\/esr.ibiblio.org\/?p=7041\">In defense of calendrical irregularity.<\/a>)<\/p>\n<p>And now, to conclude this public-service announcement, a filk I composed for the occasion. Take the tune from <a href=\"https:\/\/www.youtube.com\/watch?v=6UD0c58nNCQ\">this<\/a> and superimpose these lyrics:<\/p>\n<pre>Baby you'll come knockin' on my firewall\r\nJust as I'm dealin' with a system stall\r\nI said yeah, well, what'm I supposed to do?\r\nI don't need no cracker gettin' in too.\r\n\r\nNANOG says they have some trouble in town\r\nNow you're shutting some daemons down\r\n\r\nStop logging in...\r\nStop logging in...\r\nStop logging in local time.\r\n\r\nIt's hard to know where the intruders came from\r\nIt's hard to know just what we've lost\r\nThis doesn't have to be the big net meltdown\r\nThis doesn't have to be anything at all.\r\n\r\nI know you really want to tell me good-bye\r\nI know you really want to run your own show\r\n\r\nBaby you could never look me in the eye\r\nYeah you buckle with the weight of the words\r\n\r\nStop logging in...\r\nStop logging in...\r\nStop logging in local time.\r\n\r\nThere's people running 'round loose in the world\r\nAin't got nothing better to do\r\nThan make a meal of some P.F.Y.\r\nYou need someone looking after you\r\n\r\nI know you really want to tell me good-bye\r\nI know you really want to run your own show\r\n\r\nBaby you could never look me in the eye\r\nYeah you buckle with the weight of the words\r\n\r\nStop logging in...\r\nStop logging in...\r\nStop logging in local time.\r\n\r\nStop logging in local time!\r\n<\/pre>\n","protected":false},"excerpt":{"rendered":"<p>Inertia is a powerful force. The computing world retains a lot of practices that are odd little dysfunctional relics of past stages of its technology. The one I&#8217;m here to talk about today looks like this: Mar 6 15:11:07 snark postfix\/qmgr[3927]: 0422513A6C53: removed That&#8217;s a log message hot&#8217;n&#8217;fresh from my \/var\/log\/mail.log file. It&#8217;s entirely typical&hellip; <a class=\"more-link\" href=\"http:\/\/esr.ibiblio.org\/?p=7901\">Continue reading <span class=\"screen-reader-text\">Stop logging in local time!<\/span><\/a><\/p>\n","protected":false},"author":2,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[13],"tags":[],"class_list":["post-7901","post","type-post","status-publish","format-standard","hentry","category-software","entry"],"_links":{"self":[{"href":"http:\/\/esr.ibiblio.org\/index.php?rest_route=\/wp\/v2\/posts\/7901","targetHints":{"allow":["GET"]}}],"collection":[{"href":"http:\/\/esr.ibiblio.org\/index.php?rest_route=\/wp\/v2\/posts"}],"about":[{"href":"http:\/\/esr.ibiblio.org\/index.php?rest_route=\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"http:\/\/esr.ibiblio.org\/index.php?rest_route=\/wp\/v2\/users\/2"}],"replies":[{"embeddable":true,"href":"http:\/\/esr.ibiblio.org\/index.php?rest_route=%2Fwp%2Fv2%2Fcomments&post=7901"}],"version-history":[{"count":14,"href":"http:\/\/esr.ibiblio.org\/index.php?rest_route=\/wp\/v2\/posts\/7901\/revisions"}],"predecessor-version":[{"id":7916,"href":"http:\/\/esr.ibiblio.org\/index.php?rest_route=\/wp\/v2\/posts\/7901\/revisions\/7916"}],"wp:attachment":[{"href":"http:\/\/esr.ibiblio.org\/index.php?rest_route=%2Fwp%2Fv2%2Fmedia&parent=7901"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"http:\/\/esr.ibiblio.org\/index.php?rest_route=%2Fwp%2Fv2%2Fcategories&post=7901"},{"taxonomy":"post_tag","embeddable":true,"href":"http:\/\/esr.ibiblio.org\/index.php?rest_route=%2Fwp%2Fv2%2Ftags&post=7901"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}