Bug 61180 - Change log level of sessionIdGeneratorBase.createRandom to warn rather than info
Summary: Change log level of sessionIdGeneratorBase.createRandom to warn rather than info
Status: RESOLVED FIXED
Alias: None
Product: Tomcat 8
Classification: Unclassified
Component: Catalina (show other bugs)
Version: 8.0.x-trunk
Hardware: All All
: P2 trivial (vote)
Target Milestone: ----
Assignee: Tomcat Developers Mailing List
URL:
Keywords: Beginner
Depends on:
Blocks:
 
Reported: 2017-06-12 19:19 UTC by Coty Sutherland
Modified: 2017-06-18 20:42 UTC (History)
0 users



Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Coty Sutherland 2017-06-12 19:19:44 UTC
I was just asked a question in #tomcat about why a user's tomcat installation was taking ~36 minutes to start. After looking at their logging I immediately noticed:

INFO [localhost-startStop-1] org.apache.catalina.util.SessionIdGeneratorBase.createSecureRandom Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [2,157,784] milliseconds.

showing that the machine had low entropy. I knew that from experience, however the user had no idea that was the issue because the logging looked normal to them (no WARN or ERROR messages). Can we change the log level of the sessionIdGeneratorBase.createRandom message to WARN rather than INFO so if it takes longer than 100 ms to generate a random users are made aware? A WARN message will at least make them look twice at the error line and google it as a potential issue, which should yield the wiki page (https://wiki.apache.org/tomcat/HowTo/FasterStartUp#Entropy_Source).

Also, the wording in the wiki page makes this sound like it should be a warning anyway:

"You will see warning in the logs when this happens"
Comment 1 Coty Sutherland 2017-06-12 19:20:20 UTC
This is the definition of a "Beginner" issue IMO :)
Comment 2 Piotr Chlebda 2017-06-15 20:51:07 UTC
Hi,
I'm newby as a tomcat contributor and I'd like to take this issue.
Comment 3 Coty Sutherland 2017-06-16 01:42:02 UTC
Taking another look at the code around the info message I think we may need to add another check to see if the delay time is larger than 100 ms. If we make this a warning message as-is I think that everyone's log may have a warning in it. Should we print an info message if the delay is less than some number (like 30 seconds) and a warning if the delay is greater?
Comment 4 Mark Thomas 2017-06-18 19:57:55 UTC
I don't see the message on my new(ish) desktop nor my old(ish) laptop. If the threshold is too low for some systems, we can look at increasing it. My instinct is that 100ms will be plenty of time for that block of code unless there is an entropy problem,

I also took the opportunity to clean up some formatting and I added a changelog entry.

Thanks to Piotr Chlebda for the patch.
 
Fixed in:
- trunk for 9.0.0.M22 onwards
- 8.5.x for 8.5.16 onwards
- 8.0.x for 8.0.45 onwards
- 7.0.x for 7.0.79 onwards
Comment 5 Piotr Chlebda 2017-06-18 20:23:02 UTC
1) Would that be another bug for that ?
2)I'd like to make sure that my PR was ok, since it was only at trunk (version 9). Are there any requirments for PR for other version(8.5.x,8.0.x,7.0.x) ?
Comment 6 Mark Thomas 2017-06-18 20:28:31 UTC
(In reply to Piotr Chlebda from comment #5)
> 1) Would that be another bug for that ?

Maybe. We need to wait and see if we get any such reports. I'd be surprised to get such a report where there wasn't an underlying entropy problem.


> 2)I'd like to make sure that my PR was ok, since it was only at trunk
> (version 9). Are there any requirments for PR for other
> version(8.5.x,8.0.x,7.0.x) ?

Bug fixes to trunk are back-ported to earlier versions. The back-ports normally apply cleanly so no further work is required.

It would be helpful to include a changelog entry when you fix a bug. It saves the committers a few minutes writing it themselves.
Comment 7 Piotr Chlebda 2017-06-18 20:42:04 UTC
Thanks Mark Thomas for a quick response.