Bug 59871 - Impossible to change datetime format in OneLineFormatter/Use sane (sortable) format
Summary: Impossible to change datetime format in OneLineFormatter/Use sane (sortable) ...
Status: RESOLVED FIXED
Alias: None
Product: Tomcat 8
Classification: Unclassified
Component: Catalina (show other bugs)
Version: 8.5.3
Hardware: PC All
: P2 enhancement (vote)
Target Milestone: ----
Assignee: Tomcat Developers Mailing List
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2016-07-16 21:37 UTC by Michael Osipov
Modified: 2017-04-06 13:29 UTC (History)
0 users



Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Michael Osipov 2016-07-16 21:37:06 UTC
The OneLineFormatter is a tremendous improvement to the formatter shipped with default Java, though one cannot change the datetime format nor does it have a sane, standardized, sortable format. I don't want to write a custom formatter or fork this one just to change this property.

I would actually expect that the formatter would use wellknown ISO 8601 datetime for the default output: yyyy-MM-dd'T'HH:mm:ss.SSS. Alternatively, one can use String#format, though I do not know wether this will beat the benefit of the DateFormatCache.
Comment 1 Remy Maucherat 2016-07-18 12:19:43 UTC
There is no provision to be able to set properties on the fomatters, so it is more difficult to add this support. Adding your own formatter is not very difficult and is the way to go here, so you're going to have to do that.
Comment 2 Michael Osipov 2016-07-18 12:43:49 UTC
(In reply to Remy Maucherat from comment #1)
> There is no provision to be able to set properties on the fomatters, so it
> is more difficult to add this support. Adding your own formatter is not very
> difficult and is the way to go here, so you're going to have to do that.

That's a JULI shortcoming. Why not provision a standards format then?
Comment 3 Konstantin Kolinko 2016-07-18 14:16:00 UTC
(In reply to Remy Maucherat from comment #1)
> There is no provision to be able to set properties on the fomatters,

That is not true.
It is not documented, but formatters can be configured. It is the same as with other classes,  [<prefix>.]<classname>.<property>

The <prefix>. is either omitted (to be applied to all instances of a Formatter), or has to be the same as prefix of the Handler to which this formatter belongs.

See example in bug 55052

java.util.logging.SimpleFormatter is a bad class / bad example, as it can be configured only once and caches its configuration in a static variable.
Comment 4 Remy Maucherat 2016-07-18 14:27:54 UTC
Ok, I really don't understand how this works looking at the FileHandler code, but nice to know.
Comment 5 Mark Thomas 2016-08-02 21:32:53 UTC
This is now configurable in 9.0.x (for 9.0.0.M10 onwards) and 8.5.x (for 8.5.5) onwards.
Comment 6 Michael Osipov 2016-08-03 16:55:18 UTC
(In reply to Mark Thomas from comment #5)
> This is now configurable in 9.0.x (for 9.0.0.M10 onwards) and 8.5.x (for
> 8.5.5) onwards.

Thank for the fix. Though, there is absolutely no documentation. So people won't know about it at all :-(
Comment 7 Andrey Zykov 2017-04-06 08:10:42 UTC
(In reply to Mark Thomas from comment #5)
> This is now configurable in 9.0.x (for 9.0.0.M10 onwards) and 8.5.x (for
> 8.5.5) onwards.

Hello Mark! I'm trying to change timestamp for OneLineFormatter on my Tomcat 8.5.12 but get wrong format. Could you please check?

part of my logging.properties file:
java.util.logging.ConsoleHandler.formatter = org.apache.juli.OneLineFormatter
org.apache.juli.OneLineFormatter.timeFormat = yyyy-MM-dd'T'HH:mm:ss.SSSZ

But in log I get:

2017-04-06T10:02:23.###+0200.546 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.5.12

As you can see - there are ### instead of milliseconds, and milliseconds are at the end of timestamp.

I've tried set TimeFormat to "EEE, d MMM yyyy HH:mm:ss Z" and get:
Thu, 6 Apr 2017 10:06:20 +0200.842

Again - milliseconds are at the end of timestamp.
Comment 8 Michael Osipov 2017-04-06 09:53:12 UTC
(In reply to Andrey Zykov from comment #7)
> (In reply to Mark Thomas from comment #5)
> > This is now configurable in 9.0.x (for 9.0.0.M10 onwards) and 8.5.x (for
> > 8.5.5) onwards.
> 
> Hello Mark! I'm trying to change timestamp for OneLineFormatter on my Tomcat
> 8.5.12 but get wrong format. Could you please check?
> 
> part of my logging.properties file:
> java.util.logging.ConsoleHandler.formatter = org.apache.juli.OneLineFormatter
> org.apache.juli.OneLineFormatter.timeFormat = yyyy-MM-dd'T'HH:mm:ss.SSSZ
> 
> But in log I get:
> 
> 2017-04-06T10:02:23.###+0200.546 INFO [main]
> org.apache.catalina.core.StandardEngine.startInternal Starting Servlet
> Engine: Apache Tomcat/8.5.12
> 
> As you can see - there are ### instead of milliseconds, and milliseconds are
> at the end of timestamp.
> 
> I've tried set TimeFormat to "EEE, d MMM yyyy HH:mm:ss Z" and get:
> Thu, 6 Apr 2017 10:06:20 +0200.842
> 
> Again - milliseconds are at the end of timestamp.

I had the same issue, read he Javadoc: SSS is not supported. You wan't "yyyy-MM-dd'T'HH:mm:ss". Btw, never go for Z but for ZZZ only. Try "yyyy-MM-dd'T'HH:mm:ssZZZ".
Comment 9 Andrey Zykov 2017-04-06 10:20:41 UTC
(In reply to Michael Osipov from comment #8)
> 
> I had the same issue, read he Javadoc: SSS is not supported. You wan't
> "yyyy-MM-dd'T'HH:mm:ss". Btw, never go for Z but for ZZZ only. Try
> "yyyy-MM-dd'T'HH:mm:ssZZZ".

It still adds milliseconds at the end of timestamp:

2017-04-06T12:17:55+0200.574
Comment 10 Michael Osipov 2017-04-06 11:38:01 UTC
(In reply to Andrey Zykov from comment #9)
> (In reply to Michael Osipov from comment #8)
> > 
> > I had the same issue, read he Javadoc: SSS is not supported. You wan't
> > "yyyy-MM-dd'T'HH:mm:ss". Btw, never go for Z but for ZZZ only. Try
> > "yyyy-MM-dd'T'HH:mm:ssZZZ".
> 
> It still adds milliseconds at the end of timestamp:
> 
> 2017-04-06T12:17:55+0200.574

I got it now. Sorry, it has to be XXX instead of ZZZ for ISO-compliant offset. Anyway, the custom formatter assumes that nothing comes after the 'ss' as far as I can see and simply adds the fraction. You should file a separate issue for that.
Comment 11 Rainer Jung 2017-04-06 13:29:43 UTC
(In reply to Andrey Zykov from comment #7)
> java.util.logging.ConsoleHandler.formatter = org.apache.juli.OneLineFormatter
> org.apache.juli.OneLineFormatter.timeFormat = yyyy-MM-dd'T'HH:mm:ss.SSSZ
> 
> But in log I get:
> 
> 2017-04-06T10:02:23.###+0200.546 INFO [main]
> org.apache.catalina.core.StandardEngine.startInternal Starting Servlet
> Engine: Apache Tomcat/8.5.12
> 
> As you can see - there are ### instead of milliseconds, and milliseconds are
> at the end of timestamp.
> 
> I've tried set TimeFormat to "EEE, d MMM yyyy HH:mm:ss Z" and get:
> Thu, 6 Apr 2017 10:06:20 +0200.842
> 
> Again - milliseconds are at the end of timestamp.

The OneLineFormatter uses a cache for formatted time stamps with seconds granularity. That means the value formatted in the cache replaces "S" in the original format with "#" such that we get some reuse for the formatted patterns.

Now OneLineFormatter would need to replace the "#" characters in the results it gets from the cache with the sub seconds fraction of the current time. At the moment it does not do it and instead just appends them. If the format string does not contain any "S", no "#" will show up and you do not realize.

What we could do is check whether and how many "#" chars are in the formatted time and replace with the milliseconds. If we see exactly three "#" chars, that would be easy to do.

If the format string only has fixed size items in front of the milliseconds, and uses "SSS" for the milliseconds, then one could do it relatively efficient, since we could precalculate the correct offsets.

All in all I doubt that it is worth the effort and the performance risk. Maybe we should just document the behavior, that we do not support "S" in the timestamp format and always append the milliseconds separated by a dot to the end of the formatted time stamp.