Bug 46982 - AccessLogValve reports correct time but incorrect offset following Spring DST transition.
Summary: AccessLogValve reports correct time but incorrect offset following Spring DST...
Status: RESOLVED FIXED
Alias: None
Product: Tomcat 5
Classification: Unclassified
Component: Catalina (show other bugs)
Version: 5.5.27
Hardware: PC Linux
: P2 normal (vote)
Target Milestone: ---
Assignee: Tomcat Developers Mailing List
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2009-04-07 07:32 UTC by Philip Pickett
Modified: 2009-06-04 07:34 UTC (History)
0 users



Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Philip Pickett 2009-04-07 07:32:55 UTC
This is a problem with AccessLogValve for tc5.5 as well as tc6.0 on all platforms.

With the system clock on my linux machine (Ubuntu in my case) to just before the US time change on March 8, I started Tomcat 5.5 and see the following messages in my Tomcat access log after accessing Tomcat JSP example pages at the time of DST transition:

-: - [08/Mar/2009:01:56:20 -0700] GET /jsp-examples/jsp2/simpletag/book.jsp HTTP/1.1 200 1738 1 - {http-8080-Processor24}
-: - [08/Mar/2009:03:01:22 -0700] GET /jsp-examples/jsp2/tagfiles/hello.jsp HTTP/1.1 200 2213 68 - {http-8080-Processor25}

Note the offset of "-0700" both before and after DST transition.  Following a Tomcat restart the offset is correct:

-: - [08/Mar/2009:03:19:42 -0600] GET /jsp-examples/jsp2/jspx/basic.jspx HTTP/1.1 200 1919 780 - {http-8080-Processor25}
-: - [08/Mar/2009:03:19:59 -0600] GET /jsp-examples/jsp2/jspx/svgexample.html HTTP/1.1 200 2239 4 - {http-8080-Processor25}
-: - [08/Mar/2009:03:19:59 -0600] GET /jsp-examples/jsp2/jspx/textRotate.jpg HTTP/1.1 200 26729 3 - {http-8080-Processor25}


BTW, I ran the tzupdater before my tests:

linwin01-512> java -jar tzupdater.jar -V
tzupdater version 1.3.12-b01
JRE time zone data version: tzdata2009a
Embedded time zone data version: tzdata2009a



The problem is in the org.apache.catalina.valves.AccessLogValve which contains the following in its start method:


// Initialize the timeZone, Date formatters, and currentDate
timezone = TimeZone.getDefault();
timeZoneNoDST = calculateTimeZoneOffset(timezone.getRawOffset());
Calendar calendar = Calendar.getInstance(timezone);
int offset = calendar.get(Calendar.DST_OFFSET);
timeZoneDST = calculateTimeZoneOffset(timezone.getRawOffset()+offset);


Based on what I’ve seen, “int offset = calendar.get(Calendar.DST_OFFSET);” returns 0 when the current time is not in Daylight savings time and (for my timezone) 3600000 (60 * 60 * 1000) when the current time is in Daylight Savings.  It looks like the code assumes this is always the offset for Daylight Savings for the current timezone.  I have no idea if there are some locations/timezones where Daylight Savings Time does not have a 1 hour offset.

Because of this, if in a non-DST time period, timeZoneDST and timeZoneNoDST are set to the same value.  If in a DST time period, I believe they are set correctly so that the transition in Autumn works correctly.  I think the only problem is when moving ahead in Springtime (unless the software has been running for 6 months or so which caused the offset to be set correctly).
Comment 1 Mark Thomas 2009-04-08 03:21:00 UTC
Thanks for the report. This has been fixed in trunk and proposed for 5.5.x and 6.0.x
Comment 2 Mark Thomas 2009-04-28 04:54:24 UTC
This has been fixed in 6.0.x and will be included in 6.0.20 onwards.
Comment 3 Mark Thomas 2009-04-28 04:55:15 UTC
Opps. Still open for 5.5.x
Comment 4 Mark Thomas 2009-06-04 07:34:00 UTC
This has been fixed for 5.5.x and will be included in 5.5.28 onwards.