Europe/London TZ Goes back an Hour

[russellpierce]

I haven't been able to independently reproduce this issue, however, as I'm sure you are aware anytime is failing on R-devel for some platforms. I didn't see an open issue here, so I thought I'd open one such that I could track it. It could very well be a fault in R-devel as opposed to anytime per-se. However, given that I haven't been able to reproduce the issue, I'm in a tough place in terms of evaluating whether that is so. What are your thoughts/impressions?

[eddelbuettel]

I am not sure how having this issue helps.

[russellpierce]

I guess it doesn't. I was hoping I'd be able to replicate and track down the issue, and maybe submit a fix. So, I though it might serve as a placeholder in case you were already working on it. However, I'm still at no dice for replication, so I've closed the issue for now.

[eddelbuettel]

Yes, replicating would help.

The failing tests are, as it happens, on machines set up by Prof Ripley. I simply suspect something local. He may not set TZ. Or he may set TZ to something weird. I am not at all worried about the Fedora failures because these days we do have alternative with the r-hub builders. And there it seems to pass on all Linux flavours (or at least the ones I call regularly via rhub::check_for_cran()).

As for the Solaris builds, I'd fix it if I had infinite time or patience. On this planet, I have neither so I have not yet bothered with a VM for slowlaris. You are of course absolutely correct that either issue should be fixed. So I'd love to have PRs or resolution.

But I just had to snark that copying a bug report from one system to another does not it, by itself, help.

[russellpierce]

No PR or resolution yet, but progress on replication suggesting that perhaps the cause of the error is not entirely idiosyncratic or an issue with the TZ environmental variable per se. Recording here in case someone else picks this up.

I was able to replicate on a local system (OSX) using anytime 0.2.1. I haven't looked into rhub yet, but it looks like it lacks an OSX build option, so that might not help me support the other OSX user in my organization.

For reference, the machine is set to US/Central without an environmental variable.

> library(anytime)
> sessionInfo()
R Under development (unstable) (2017-02-10 r72157)
Platform: x86_64-apple-darwin13.4.0 (64-bit)
Running under: OS X El Capitan 10.11.6

locale:
[1] en_US.UTF-8/en_US.UTF-8/en_US.UTF-8/C/en_US.UTF-8/en_US.UTF-8

attached base packages:
[1] stats     graphics  grDevices utils     datasets  methods   base

other attached packages:
[1] anytime_0.2.1

loaded via a namespace (and not attached):
[1] compiler_3.4.0 Rcpp_0.12.9
> Sys.getenv("TZ")
[1] ""
> anytime(as.character(Sys.time())) == as.character(Sys.time())
[1] TRUE
> q()
Save workspace image? [y/n/c]: n

So, in US/Central / No TZ envir var, things are fine. Trying with an explicit set of TZ Europe/London

> Sys.setenv(TZ = "Europe/London")
> library(anytime)
> anytime(as.character(Sys.time())) == as.character(Sys.time())
[1] FALSE

Hrm, that shouldn't be. More exploration...

# New Session
> Sys.time()
[1] "2017-02-13 00:35:56 GMT"
> as.character(Sys.time())
[1] "2017-02-13 00:35:58"
> anytime(as.character(Sys.time()))
[1] "2017-02-12 23:36:14 GMT"
> anytime(Sys.time())
[1] "2017-02-13 00:36:23 GMT"

However, this is specific to TZ Europe/London so far. Things were fine under TZ = "Europe/Berlin" and "Etc/UTC". More mysteriously, Africa/Casablanca was also fine despite have the same UTC and DST offsets as Europe/London.

# New Session
> Sys.setenv(TZ = "Europe/Berlin")
> library(anytime)
> Sys.time()
[1] "2017-02-13 01:38:48 CET"
> as.character(Sys.time())
[1] "2017-02-13 01:38:53"
> anytime(as.character(Sys.time()))
[1] "2017-02-13 01:38:58 CET"
> anytime(Sys.time())
[1] "2017-02-13 01:39:03 CET"

As one might expect, links to Europe/London, e.g. Europe/Isle_of_Man, are affected in the same way as Europe/London

[eddelbuettel]

anytime(as.character(Sys.time())) == as.character(Sys.time())

is always false on my now system too. Did you mean

R> now <- Sys.time()
R> anytime(as.character(now)) == as.character(now)
[1] TRUE
R> 

As for the rest of your post, I am not sure I understand what it is you are trying to "prove".

[russellpierce]

I need to review what I wrote and what the system is doing with regards to the equality. It looks like you may be pointing to a conceptual error on my part there, and I'd like to think about that more.

The key result that seems odd to me ATM is that for 'anytime(as.character(Sys.time()))' the resulting time is printed as one hour earlier than 'Sys.time()' under Europe/London; however the results are printed identically under other settings for TZ. Clearly, that probably is the fault of something that anytime depends on rather than anytime itself.

I'm going to fork, get this under Travis, and investigate the tests. I'll avoid leaving another comment unless I have a solution in hand.

[eddelbuettel]

Look at some of the issue tickets. Such "we miss an hour damnit" issues have been discussed ad nauseum. I think I finally nixed them around 0.2.0 when I decided to convert to date internally.

Some of the unit tests are pretty explicitly looping over hundreds of TZ values checking this.

That said, I may of course have a thinko or design bug or code bug in there. So by all means go crazy.

But keep in mind at the tires have gotten kicked quite a bit too, so if something is funny it could also be on your side.

[eddelbuettel]

Suppose it was "Europe/London".

What minimal test case can we construct to lay the blame with Boost Date_Time, or R for that matter? Which is of the two sides is "wrong"? If it were R, should we see the error only on Windows as R generally relies on system timezone files on other operating systems.

[eddelbuettel]

So here is a more minimal replication, in a Docker container with current R and everything, and TZ set to 'Europe/London':

First, the R side:

> options("digits.secs"=6)
> ref <- format(as.POSIXct(c("2016-09-01 10:11:12", "2016-09-01 10:11:12.345678"), "%Y-%m-%d %H:%M:%0S"))
> ref
[1] "2016-09-01 10:11:12.000000" "2016-09-01 10:11:12.345678"
> 

Then the failing (only under Europe/London) side:

> format(anytime(c("2016-09-01 10:11:12", "2016-09-01 10:11:12.345678")))
[1] "2016-09-01 09:11:12.000000" "2016-09-01 09:11:12.345678"
> anytime(c("2016-09-01 10:11:12", "2016-09-01 10:11:12.345678"))
[1] "2016-09-01 09:11:12.000000 BST" "2016-09-01 09:11:12.345678 BST"
> 

Somehow Boost thinks it needs to take an hour off. I have no idea why. If you find why, or find a patch, you're my hero.

Until then it remains an open issue, seemingly affecting only Europe/London.

[eddelbuettel]

Also note the warnings in the R documentation about non-existing or bad TZ values. This seems saner:

root@745418a93e14:/tmp# r -lanytime -e'options(digits.secs=6); print(format(anytime(c("2016-09-01 10:11:12", "2016-09-01 10:11:12.345678"))))'
[1] "2016-09-01 10:11:12.000000" "2016-09-01 10:11:12.345678"
root@745418a93e14:/tmp# TZ=Europe/Berlin r -lanytime -e'options(digits.secs=6); print(format(anytime(c("2016-09-01 10:11:12", "2016-09-01 10:11:12.345678"))))'
[1] "2016-09-01 10:11:12.000000" "2016-09-01 10:11:12.345678"
root@745418a93e14:/tmp# TZ=GMT r -lanytime -e'options(digits.secs=6); print(format(anytime(c("2016-09-01 10:11:12", "2016-09-01 10:11:12.345678"))))'
[1] "2016-09-01 10:11:12.000000" "2016-09-01 10:11:12.345678"
root@745418a93e14:/tmp# TZ=UTC r -lanytime -e'options(digits.secs=6); print(format(anytime(c("2016-09-01 10:11:12", "2016-09-01 10:11:12.345678"))))'
[1] "2016-09-01 10:11:12.000000" "2016-09-01 10:11:12.345678"
root@745418a93e14:/tmp# 

These all work. So maybe the error is with ... Europe/London.

[eddelbuettel]

Why did you reopen it? It's still not an error in anytime apart from the fact that we chose to rely on Boost.

But I guess under the current title it is ok. I was thinking to at least add a note to the documentation to avoid 'Europe/London'.

We could even go nuclear and test for Europe/London on .onLoad and reset to TZ if we find it. Maybe a little harsh. Food for thought.

[russellpierce]

I reopened because I saw this as a confirmed 'issue' in so far as that a given input yields an unexpected output. I suspect that other users have no way of knowing this is Boost's problem unless they see this issue, and an open issue seems to me to be more visible than a closed issue. However, all of the above reflect a stylistic choice and I see it is inconsistent with what you decided to do with the Australia issue. So, go ahead and close, if that is your choice.

I'll leave some notes for future travelers:

anytime("1970-01-01 00:00:00") %>% unclass
[1] -3600

Shows that as far as Boost is concerned, epoch midnight in Europe/London is 3600 seconds before 0... and it would seem that R agrees.

as.POSIXct(-3600, origin = "1970-01-01")
[1] "1970-01-01 BST"

Notably the timezone is BST, British Summer Time... in the dead of winter (+1 UTC Offset). The British at the time were experimenting with keeping BST year-round, see the Wikipedia section on 'Periods of deviation'. So of course the seconds since epoch is -3600. We can see how this echoes forward to the date they abolished the experiment (coinciding with the regular end of BST), between October 31st and November 1st 1971.

anytime("1971-10-31 00:00:00")
[1] "1971-10-31 BST"
anytime("1971-11-01 00:00:00")
[1] "1971-10-31 23:00:00 GMT"

Watching the seconds since epoch by unclassing these 1971 results and examining the C++ variables as they work, you'll see that for both times dstadj is 0 in the C++ code. Moreover the seconds since epoch show only 24 hours elapsed between the two dates despite the timezone signifier changing in R. We can contrast this with the change from BST and GMT between October 30th and 31st in 2016 where a change in anytime's adjustment does occur and the seconds since epoch shows an elapse of 25 hours between the two dates.

Back to 1971, we can perhaps see the issue more starkly. In contrast to boost/anytime that believes 24 hours have elapsed between 1971-10-31 and 1971-11-01, R believes that 25 hours have elapsed.

difftime(as.POSIXct("1971-11-01 00:00:00"),as.POSIXct("1971-10-31 00:00:00"), units = "hours")
Time difference of 25 hours

Incidentally unclassing as.POSIXlt results will show that R too doesn't consider 1970-10-31 to be a DST.

[eddelbuettel]

Here is another simpler (?) look at the issue. It uses R and anytime() to parse the same input, under two TZ settings of UTC and Europe/London. They should be the same, but they are not. I think the bug is with Boost.

What are your thoughts?

edd@max:~/git/anytime(master)$ local/theMessWithLondon.sh 
[1] -3600 -3600
[1] 0 0
[1] 315532800 315529200     ## Problem
[1] 315532800 315532800
[1] 631152000 631148400     ## Problem
[1] 631152000 631152000
edd@max:~/git/anytime(master)$ 

(Oh, and I hacked that quickly on the way in on the train -- it uses littler and its /usr/bin/r. If you must, rewrite for RScript. Don;t think that needs another PR.)

[russellpierce]

I like that it is concise. Yours shows that there is a problem, mine I think shows pretty precisely where Boost went wrong. Specifically, they failed to count the extra hour that occurred when Europe/London reverted from year-long BST to GMT.

I see your name around StackOverflow on a fair number of Boost questions. It seems like a bug report from you would be better formatted and more likely to attract attention than one from me. Do you have time to submit one?

[eddelbuettel]

I just pinged a former colleague who, as I recall, has submitted to Boost before. I do think it is worth it.

But first things first: thanks the second set of eyes. You concur that R is 'correct' while 'Boost' seems to be off? In which case a bug report seems in order.

[eddelbuettel]

Obviously, I need to rewrite the little example in terms strptime() from libc and then Boost directly.

[eddelbuettel]

And as far as anytime is concerned: shall we 'catch' use of Europe/London and just a) warn (that I wrote as proof-of-concept) or b) convert to UTC or c) both?

[russellpierce]

I concur that R seems correct while Boost seems to be off.

In relationship to anytime, for now, I think warn (or even error) makes more sense than converting to UTC. Europe/London does engage in a DST UTC offset, so switching to UTC seems like it would just trade one problem for another.

[eddelbuettel]

It is not Boost. See the file london.cpp I added, it builds with a simple g++ -o london london.cpp (if you have Boost headers system-wide as I do, else add -I... as needed).

We don't link with Boost, and we don't give Boost its timezone information so it is the system. And epoch is simply BST:

edd@max:~/git/anytime/local(master)$ TZ=Europe/London ./london "1970-01-01 00:00:00"
Boost secs from epoch: -3600 Input: 1970-01-01 00:00:00 ptime: 1970-Jan-01 00:00:00
C library secs       : -3600 secs off: 3600 tmzone BST
edd@max:~/git/anytime/local(master)$ 

So in short maybe we see no bug, The epoch was after all at UTC. And Europse/London is BST.

[russellpierce]

To match your theMessWithLondon.sh consider:

➜  Downloads TZ=Europe/London ./london '1980-01-01 00:00:00'
Boost secs from epoch: 315529200 Input: 1980-01-01 00:00:00 ptime: 1980-Jan-01 00:00:00
C library secs       : 315532800 secs off: 0 tmzone GMT

I'm seeing a difference in seconds between the two approaches on my machine. Can you confirm? Or does the above not matter?

[eddelbuettel]

Run it repeatedly. There is something weird going on with the C library. On occasion I have seen the value flip.

edd@max:~/git/anytime/local(master)$ TZ=Europe/London ./london '1980-01-01 00:00:00'
Boost secs from epoch: 315529200 Input: 1980-01-01 00:00:00 ptime: 1980-Jan-01 00:00:00
C library secs       : 315529200 secs off: 0 tmzone GMT
edd@max:~/git/anytime/local(master)$ 

Now of course I can't reproduce it.

[russellpierce]

That's really odd. I wasn't able to reproduce instability on my end. I wonder what boost could be doing to possibly cause that? At the very least, it seems like the bug is still on Boost's end with the typical behavior being 'bugged'.

get_result <- function() {
  system("TZ=Europe/London ~/Downloads/london '1980-01-01 00:00:00'", intern = TRUE)
}

initial_result <- get_result()

for (i in 1:(24*60*60/2)) {
  new_result <- get_result()
  if (!identical(initial_result, new_result)) {
    stop("Dirk's Observation Confirmed")
  }
  Sys.sleep(runif(1))  
}
print(paste0("ending test @ ", Sys.time()))

[eddelbuettel]

Apologies for a screenshot, but I still had the terminal open on my (very standard) laptop (running Ubuntu 16.10):

It seems to flip somewhat randomly.

Not that there is little Boost in this (besides of course the templated headers):

edd@brad:~/git/anytime/local(master)$ ldd london
        linux-vdso.so.1 =>  (0x00007ffd38b7f000)
        libstdc++.so.6 => /usr/lib/x86_64-linux-gnu/libstdc++.so.6 (0x00007f8353462000)
        libgcc_s.so.1 => /lib/x86_64-linux-gnu/libgcc_s.so.1 (0x00007f835324b000)
        libc.so.6 => /lib/x86_64-linux-gnu/libc.so.6 (0x00007f8352e84000)
        libm.so.6 => /lib/x86_64-linux-gnu/libm.so.6 (0x00007f8352b7b000)
        /lib64/ld-linux-x86-64.so.2 (0x00005646e11ab000)
edd@brad:~/git/anytime/local(master)$ 

I think the timezone information comes straight from the system.

[eddelbuettel]

Also note that this post of yours shows flipping values whereas this post of yours says you do not see them.

[russellpierce]

I think we are miscommunicating.

I took 'flipping' to mean inconsistent results across runs. I.e., sometimes both programatic pathways in london.cpp yield the same result, sometimes they yield different results. I do not see inconsistent results across runs. Note that that test is just about whether the output from london.cpp stays the same, not about whether the outputs from the two pathways agree.

Although I do see is consistent results across runs, the consistent result is a disagreement between the two programatic pathways in london.cpp as shown here.

That being said, I'm using a Mac for this test and I'd wager you're on Debian, and so perhaps that is why you get flipping values and I do not. Regardless, the root of the problem is drifting pretty far out of my core competencies at this point. So, I am at a loss as to how to proceed.

[eddelbuettel]

Europe/London is BST which in Jan 1970 was an hour before UTC.

Maybe we concluded that there is no bug.

[eddelbuettel]

Wikipedia on British Standard Time, Section 2:

An inquiry during the winter of 1959–60, in which 180 national organisations were consulted, revealed a slight preference for a change to all-year GMT+1, but the length of summer time was extended as a trial rather than the domestic use of Greenwich Mean Time abolished.[9] A further inquiry during 1966–67 led the government of Harold Wilson to introduce the British Standard Time experiment, with Britain remaining on GMT+1 throughout the year. This took place between 27 October 1968 and 31 October 1971, when there was a reversion to the previous arrangement.

And that seems to pan out:

edd@max:~/git/anytime/local(master)$ TZ=Europe/London ./london  "1971-11-01 00:00:00"
Boost secs from epoch: 57798000 Input: 1971-11-01 00:00:00 ptime: 1971-Nov-01 00:00:00
C library secs       : 57798000 secs off: 0 tmzone GMT
edd@max:~/git/anytime/local(master)$ TZ=Europe/London ./london  "1971-10-31 00:00:00"
Boost secs from epoch: 57711600 Input: 1971-10-31 00:00:00 ptime: 1971-Oct-31 00:00:00
C library secs       : 57711600 secs off: 3600 tmzone BST
edd@max:~/git/anytime/local(master)$ 

On Oct 31 we do have an offset to GMT, and a BST timezone, on Nov 1 we do not.

[russellpierce]

Yes, the confusion /bug if one exists does seem to be related to the BST weirdness between 1970 and 1971.

To me it seems the 'trick' is that between midnight on October 31st (BST) and midnight November 1st (GMT), 25 hours elapse, not 24 (i.e. 86400 seconds). When you get the intermittent 'bad' result from the Boost pathway it'll look something like this:

➜  Downloads TZ=Europe/London ./london  "1971-10-31 00:00:00"
Boost secs from epoch: 57711600 Input: 1971-10-31 00:00:00 ptime: 1971-Oct-31 00:00:00
C library secs       : 57711600 secs off: 3600 tmzone BST
➜  Downloads TZ=Europe/London ./london  "1971-11-01 00:00:00"
Boost secs from epoch: 57798000 Input: 1971-11-01 00:00:00 ptime: 1971-Nov-01 00:00:00
C library secs       : 57801600 secs off: 0 tmzone GMT

For Boost seconds since epoch has a delta of 86400, 24 hours. For C seconds since epoch has a delta of 90000, 25 hours. IDK if it is relevant, but I'll also resurface that in my earlier ('yes') post, I noticed that Boost does not report 1970-10-31 as having a dst adjustment.

[eddelbuettel]

So I think a good summary is that is appears to be a bug on the Boost side:

$ TZ="Europe/London" Rscript -e 'print(anytime::anytime(c("1971-10-31 00:00:00", \
                                                          "1971-11-01 00:00:00")))'
[1] "1971-10-31 00:00:00 BST" "1971-10-31 23:00:00 GMT"
$ 

For any other time zone, the zero hour is preserved:

$ TZ="Europe/Berlin" Rscript -e 'print(anytime::anytime(c("1971-10-31 00:00:00", 
                                                          "1971-11-01 00:00:00")))'
[1] "1971-10-31 CET" "1971-11-01 CET"
$ 

[eddelbuettel]

I may have something now, due to the persistent nagging by @statquant and the excellent ground-work by @drknexus. I will commit a new branch in a second.

It passes this existing test now:

edd@brad:~/git/anytime(feature/bst_correction)$ TZ=Europe/London local/checkEuropeLondon.sh 
[1] -3600 -3600
[1] 0 0
[1] 315532800 315532800
[1] 315532800 315532800
[1] 631152000 631152000
[1] 631152000 631152000

A new file in tests/ is included too. All these must be executed under Europe/London for effect.

[eddelbuettel]

Here is what the new tests shows -- I think I got the cut-over point right but would really appreciate a second set of eyes:

edd@brad:~/git/anytime(feature/bst_correction)$ TZ="Europe/London" r tests/gh_issues_36_51.R
Using  57711600  ==  1971-10-31 00:00:00  parsed as  1971-10-31 00:00:00 
Using  57715200  ==  1971-10-31 01:00:00  parsed as  1971-10-31 01:00:00 
Using  57718800  ==  1971-10-31 02:00:00  parsed as  1971-10-31 02:00:00 
Using  57722400  ==  1971-10-31 02:00:00  parsed as  1971-10-31 02:00:00 
Using  57726000  ==  1971-10-31 03:00:00  parsed as  1971-10-31 03:00:00 
Using  57729600  ==  1971-10-31 04:00:00  parsed as  1971-10-31 04:00:00 
Using  57733200  ==  1971-10-31 05:00:00  parsed as  1971-10-31 05:00:00 
Using  57736800  ==  1971-10-31 06:00:00  parsed as  1971-10-31 06:00:00 
Using  57740400  ==  1971-10-31 07:00:00  parsed as  1971-10-31 07:00:00 
Using  57744000  ==  1971-10-31 08:00:00  parsed as  1971-10-31 08:00:00 
Using  57747600  ==  1971-10-31 09:00:00  parsed as  1971-10-31 09:00:00 
Using  57751200  ==  1971-10-31 10:00:00  parsed as  1971-10-31 10:00:00 
Using  57754800  ==  1971-10-31 11:00:00  parsed as  1971-10-31 11:00:00 
Using  57758400  ==  1971-10-31 12:00:00  parsed as  1971-10-31 12:00:00 
Using  57762000  ==  1971-10-31 13:00:00  parsed as  1971-10-31 13:00:00 
Using  57765600  ==  1971-10-31 14:00:00  parsed as  1971-10-31 14:00:00 
Using  57769200  ==  1971-10-31 15:00:00  parsed as  1971-10-31 15:00:00 
Using  57772800  ==  1971-10-31 16:00:00  parsed as  1971-10-31 16:00:00 
Using  57776400  ==  1971-10-31 17:00:00  parsed as  1971-10-31 17:00:00 
Using  57780000  ==  1971-10-31 18:00:00  parsed as  1971-10-31 18:00:00 
Using  57783600  ==  1971-10-31 19:00:00  parsed as  1971-10-31 19:00:00 
Using  57787200  ==  1971-10-31 20:00:00  parsed as  1971-10-31 20:00:00 
Using  57790800  ==  1971-10-31 21:00:00  parsed as  1971-10-31 21:00:00 
Using  57794400  ==  1971-10-31 22:00:00  parsed as  1971-10-31 22:00:00 
Using  57798000  ==  1971-10-31 23:00:00  parsed as  1971-10-31 23:00:00 
Using  57801600  ==  1971-11-01 00:00:00  parsed as  1971-11-01 00:00:00 
edd@brad:~/git/anytime(feature/bst_correction)$ 

[eddelbuettel]

No luck, though, as this leads to a failure with test/bulkTests.R for the Europe/London case.

[eddelbuettel]

Take two -- it is actually the setup timezone that matters as it is the one governing the Boost behavior. Now we compare to that one.

Looks better at Travis. This may actually work.