Bug 56438 - If jar scan does not find context config or TLD config, log a message
If jar scan does not find context config or TLD config, log a message
Status: NEW
Product: Tomcat 7
Classification: Unclassified
Component: Catalina
7.0.53
PC Linux
: P2 enhancement (vote)
: ---
Assigned To: Tomcat Developers Mailing List
:
Depends on:
Blocks:
  Show dependency tree
 
Reported: 2014-04-21 17:36 UTC by Justin Cranford
Modified: 2015-05-26 20:01 UTC (History)
2 users (show)



Attachments
Fix for Tomcat7 TldConfig and ContextConfig scan (9.46 KB, patch)
2015-04-09 07:28 UTC, VIN
Details | Diff
Fix for TLD scan in Tomcat7.0 (5.35 KB, patch)
2015-04-28 09:22 UTC, VIN
Details | Diff
Fix for adding debug log message for positive matches of tld-Tomcat7 (5.08 KB, patch)
2015-04-30 08:47 UTC, VIN
Details | Diff
Fix for adding debug log message for positive matches of tld-trunk (4.54 KB, patch)
2015-05-07 09:53 UTC, VIN
Details | Diff
Fix for adding debug log message for positive matches of tld-Tomcat8 (4.64 KB, patch)
2015-05-07 09:54 UTC, VIN
Details | Diff
Fix for printing log messages in case of contextconfig scan-trunk (15.62 KB, patch)
2015-05-21 05:44 UTC, VIN
Details | Diff
Fix for printing log messages in case of contextconfig scan-trunk (15.87 KB, patch)
2015-05-21 06:29 UTC, VIN
Details | Diff
Fix for printing log messages in case of contextconfig scan-Tomcat8 (15.86 KB, patch)
2015-05-21 09:03 UTC, VIN
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Justin Cranford 2014-04-21 17:36:50 UTC
I went through the same process as many others migrating to Tomcat 7. My simple war application took orders of magnitude longer to load than in Tomcat 3.3, and root cause was new Tomcat 7 / Servlet 3.0 jar scanning to look for context config fragments.

This is a very painful process. I had to use FINE log level, parse thousands of Tomcat log messages, and google the various messages. This was a waste of time. All Tomcat 7 needed to do was log a message when the jar scan did not find anything in a jar, and recommend adding that jar to one of the filters in catalina.properties.

  tomcat.util.scan.DefaultJarScanner.jarsToSkip
  org.apache.catalina.startup.ContextConfig.jarsToSkip
  org.apache.catalina.startup.TldConfig.jarsToSkip.


As an enhancement, please add a log message recommending adding a jar if scanning does not find anything. I would recommend setting the log level to FINE, and explicitly putting a logging.properties override for that message in logging.properties. Anyone new to Tomcat 7 can fix these messages by either following the recommendation, or commenting out the logging.properties override for the message.

This is low hanging fruit. It should be straight forward to add, and would be a huge help for anyone new to Tomcat 7 who are unaware of the performance impact of Servlet 3.0 jar scanning. It could even help Tomcat 7 veterans too, when they add/upgrade/replace existing jar files that unknowingly affect jar scanning performance.

Thank you.
Comment 1 Justin Cranford 2014-04-21 17:37:56 UTC
Correction: I migrated from Tomcat 5.5. I wrote Tomcat 3.3 which was a type-o.
Comment 2 Justin Cranford 2014-04-21 19:25:49 UTC
I manually added these two overrides in Tomcat 7 logging.properties to make is easy to diagnose and fix slow start performance. Consider adding these to the defaults, or even just add them as commented out. I think they would benefit a wider audience.

*** conf/logging.properties ***
   org.apache.tomcat.util.scan.StandardJarScanner.level = FINE
   org.apache.catalina.startup.Catalina.level = INFO


Regarding catalina.properties, these are the filters I had to add for my specific application. Note that some of them should have been filtered by Tomcat 7 default filters tomcat.util.scan.DefaultJarScanner.jarsToSkip. The first 4 should definitely be fixed in the default filters of Tomcat 7, and the rest you can consider on a case-by-case basis:

Various JARs
- jdom.jar (Default filter "jdom-*jar" missed this jar name)
- commons-discovery*.jar (Missing Apache Commons jar filter)
- commons-net*.jar (Missing Apache Commons jar filter)
- commons-el*.jar (Missing Apache Commons jar filter)
- quartz*.jar
- el-ri.jar
- kxml2.jar
- jsch-*.jar
- iText-*.jar
- jasperreports-*.jar
- httpcore-4.1.jar
- protomatter-*.jar
- stax-api-*.jar
- xpp3_min-*.jar
- xstream-*.jar
- openspml2-toolkit.jar
- vijava*.jar
- jt400.jar
- jsf-api-*.jar

Various JDBC JARs
- mysql-connector-*.jar
- ojdbc*.jar
- jtds*.jar
- h2-*.jar
- ha-jdbc-*.jar
- sqljdbc4.jar
- db2jcc4.jar

Various Application Clustering JARs
- jgroups-*.jar
- hazelcast-*.jar
Comment 3 VIN 2015-04-09 07:28:16 UTC
Created attachment 32639 [details]
Fix for Tomcat7 TldConfig and ContextConfig scan

Attached patch contains below fixes:
1) If any jar is scanned for TLDs and it does not contain any TLDs, add a debug message "No TLDs were found in JAR".  A overall summary INFO message is added to inform that "Atleast one JAR was scanned unnecessarily". 

2) If any JAR or FILE is scanned for fragments and it did not contain any fragment, add a debug message "No fragments were found in JAR/File". A overall summary INFO message is added to inform that "Atleast one JAR/File was scanned unnecessarily".

Please review my patch and let me know in case of any problems.
Comment 4 Justin Cranford 2015-04-09 13:11:49 UTC
The patch sounds great. Three small suggestions to make it just a little better:

1) Can you add a debug message to show positive matches? Logging negative matches is very useful since Tomcat's configuration uses exclusion filters, but in hindsight I think showing the positive matches too gives the developer more visibility into how many jars contain newer servlet 3.0 pieces. For example, if they notice multiple jars with fragments but offering similar functionality, they could decide to refactor their application to eliminate a few of those jars for a little more start up performance.

2) Is it possible to log a message at the end of scanning to show positive/negative match totals? I would recommend warning log level if either negative match total is >0, otherwise info or debug level. A warning seems appropriate here since unnecessary jar scanning has such a huge negative impact on startup performance. It would not overwhelm a new user, it gives them valuable feedback to optimize startup times using your new debug messages, and it would disappear automatically after they add all the necessary exclusion filters.

3) If you just added 1) and 2) that would be more than enough. However, you could go a step further and use your code to identify common jar files that should be filtered. If you added some of them to the default exclusion filters in catalina.properties then new users would get greater performance out of default installs.
Comment 5 Mark Thomas 2015-04-09 14:41:45 UTC
(In reply to VIN from comment #3)

> Please review my patch and let me know in case of any problems.

Part 1 looks generally OK. You need to use 4 spaces rather than tabs and I agree with the idea in comment #4 to delog log matches and non-matches. I'm less sure about a message with the counts. I think it is too noisy for info and it the summary is debug then why bother since the individual messages are there.

Part 2 needs works. Pluggability scans are more than just fragments and the patch needs to take that into account.

Also keep in mind the changes are made to trunk first and then back-ported so if the festure you are implementing isn't in trunk or 8.0.x then patches are required for those versions too.

You might find it easier to deal with part 1 first and then part 2.
Comment 6 VIN 2015-04-13 07:08:45 UTC
(In reply to Justin Cranford from comment #4)
> The patch sounds great. Three small suggestions to make it just a little
> better:
> 
> 1) Can you add a debug message to show positive matches? Logging negative
> matches is very useful since Tomcat's configuration uses exclusion filters,
> but in hindsight I think showing the positive matches too gives the
> developer more visibility into how many jars contain newer servlet 3.0
> pieces. For example, if they notice multiple jars with fragments but
> offering similar functionality, they could decide to refactor their
> application to eliminate a few of those jars for a little more start up
> performance.
> 
[Pravallika]: Do you mean "adding a log message to tell which JAR contains the fragments or TLDs"? If multiple JARs contains them, then too many log messages will be added to the log file which may also slow down the start time. Please think of and let me know so that i can add a INFO message for them.

> 2) Is it possible to log a message at the end of scanning to show
> positive/negative match totals? I would recommend warning log level if
> either negative match total is >0, otherwise info or debug level. A warning
> seems appropriate here since unnecessary jar scanning has such a huge
> negative impact on startup performance. It would not overwhelm a new user,
> it gives them valuable feedback to optimize startup times using your new
> debug messages, and it would disappear automatically after they add all the
> necessary exclusion filters.

> 
> 3) If you just added 1) and 2) that would be more than enough. However, you
> could go a step further and use your code to identify common jar files that
> should be filtered. If you added some of them to the default exclusion
> filters in catalina.properties then new users would get greater performance
> out of default installs.
[Pravallika]:  In the bug itself there are several JARs mentioned which does not contain any TLds or fragments. Hence i can add them in catalina.properties. Please let me know your opinion.
Comment 7 VIN 2015-04-13 07:29:08 UTC
(In reply to Mark Thomas from comment #5)
> (In reply to VIN from comment #3)
> 
> > Please review my patch and let me know in case of any problems.
> 
> Part 1 looks generally OK. You need to use 4 spaces rather than tabs and I
> agree with the idea in comment #4 to delog log matches and non-matches. I'm
> less sure about a message with the counts. I think it is too noisy for info
> and it the summary is debug then why bother since the individual messages
> are there.
[Pravallika]:  I have changed my eclipse settings in such a way that only spaces will be used rather tabs. Not sure why tabs are coming in patch.

I also felt that adding count gives too much info to the user.

> 
> Part 2 needs works. Pluggability scans are more than just fragments and the
> patch needs to take that into account.
[Pravallika]:  I assume other than JARs only folders will be scanned(.class files). Is it OK to add them to JARsToSkip property in catalina.properties? If yes, I may need your help to do that.


> Also keep in mind the changes are made to trunk first and then back-ported
> so if the festure you are implementing isn't in trunk or 8.0.x then patches
> are required for those versions too.
> 
> You might find it easier to deal with part 1 first and then part 2.
[Pravallika]:  Part1 (TLD scanning) is already available in 8.0 and recent trunks. Only 7.0 is not having. Part2 is not part of all 7, 8, 9 trunks. Based on your confirmation, i will give patch for Part1 to Tomcat7. Then i will giev individual patches for Part2 for all 3 versions.
Let me know if this is OK.
Comment 8 Mark Thomas 2015-04-23 15:32:35 UTC
A patch to bring Tomcat 7 in to line with 8.0.x and trunk for TLD scanning is a good first step. I'd suggest the second step is adding debug logging for TLD matches.

We can think about pluggability once the TLD aspects are fixed.
Comment 9 VIN 2015-04-28 09:22:44 UTC
Created attachment 32694 [details]
Fix for TLD scan in Tomcat7.0

This is the first patch to make Tomcat7.0 to make it in line with 8.0 and recent trunks. It has fix for only TLD scans. It does not include fix for context configs.
Comment 10 Mark Thomas 2015-04-28 21:23:56 UTC
Thanks for the patch. It has been applied to 7.0.x/trunk for 7.0.62 onwards with the following changes:
- renamed objCallBack to tldCallBack
- fixed TldJarScannerCallback so it only reported no TLD was found if it actually looked for a TLD and didn't find one.
Comment 11 VIN 2015-04-30 08:47:11 UTC
Created attachment 32702 [details]
Fix for adding debug log message for positive matches of tld-Tomcat7

This patch contains fix Tomcat7 for for below things:

1) Added debug log messages to print positive matches when tld files are found
2) Added info log message to print both negative and positive tld matches in tldScanResourcePaths(Web_Inf). But did not mention that "Consider adding this path to ...".  

Summary message "At least one resource path was scanned for TLDs yet contained no TLDs"  is also not added because 8.0 and trunk are not having this.
Comment 12 Mark Thomas 2015-05-01 10:51:56 UTC
All looks good. Since this is a new feature it needs to be added to trunk first and then back-ported so patches are required for trunk and 8.0.x as well.
Comment 13 VIN 2015-05-07 09:53:35 UTC
Created attachment 32719 [details]
Fix for adding debug log message for positive matches of tld-trunk

This patch contains fix for Tomcat recent trunk:

1) Added debug log message when positive tld match was found
2) Added debug log messages for both positive and negative matches of tld at resource path scan(previously it has only for JAR scanning). Summary message is not added.
3) Added debug log messages for both positive and negative matches of tld at directory level scan like Web-Inf/classes. Summary message is not added.

Please verify the fix and let me know.

Thanks,
Pravallika(VIN)
Comment 14 VIN 2015-05-07 09:54:23 UTC
Created attachment 32720 [details]
Fix for adding debug log message for positive matches of tld-Tomcat8

This patch contains fix for Tomcat8:

1) Added debug log message when positive tld match was found
2) Added debug log messages for both positive and negative matches of tld at resource path scan(previously it has only for JAR scanning). Summary message is not added.
3) Added debug log messages for both positive and negative matches of tld at directory level scan like Web-Inf/classes. Summary message is not added.

Please verify the fix and let me know.

Thanks,
Pravallika(VIN)
Comment 15 Mark Thomas 2015-05-11 09:27:57 UTC
I've applied the 9.0.x patch with some minor tweaks. Many thanks.
For reference, the minor tweaks were:
- removed trailing whitespace from one line to keep checkstyle happy
- made spacing around if/else blocks consistent with the rest of the code
- changed "if(!x){foo()}else{bar()}" to "if(x){bar()}else{foo()}"

I'll take a look at the 8.0.x patch next.
Comment 16 Mark Thomas 2015-05-11 09:49:15 UTC
8.0.x was a straight back-port of the 9.0.x commit so that has been applied to.
Comment 17 VIN 2015-05-11 09:58:45 UTC
Thanks Mark. 

Below are the pending items to close this bug:
1) Adding debug log messages for both negative and positive matches of Pluggbility scan for all 3 versions(as trunk/8.0/7.0 are not having this)
2) Identify the default jars that can be added to JarsToSkip property and add them under all 3 versions.

Please let me know if i miss any thing.

Thanks,
Pravallika(VIN)
Comment 18 VIN 2015-05-21 05:44:04 UTC
Created attachment 32746 [details]
Fix for printing log messages in case of contextconfig scan-trunk

This patch contain fixes for below:

1) Log positive and negative matches when Jars/files scanned for fragments. Add summary message if atleast one JAR or file is scanned unnecessarily(with out having fragments).

2) Log positive and negative matches when files/jars scanned for annotations
3) Log positive and negative matches when files/jars scanned for static resource paths

Did slight modification to TLDScanner as well to fix below:
Previously though Jars/files both are scanned, summary message used to print only for Jars. Now added fix to print summary message even when files are also scanned unnecessarily.

Please review the patch and let me know if any changes are required.

Thanks,
Pravallika(VIN)
Comment 19 VIN 2015-05-21 06:29:21 UTC
Created attachment 32747 [details]
Fix for printing log messages in case of contextconfig scan-trunk

Missed one line while creating the patch. Hence please check the attached one.
Comment 20 VIN 2015-05-21 09:03:29 UTC
Created attachment 32748 [details]
Fix for printing log messages in case of contextconfig scan-Tomcat8

Patch for Tomcat8 with below fixes:
1) Log positive and negative matches when Jars/files scanned for fragments. Add summary message if atleast one JAR or file is scanned unnecessarily(with out having fragments).

2) Log positive and negative matches when files/jars scanned for annotations
3) Log positive and negative matches when files/jars scanned for static resource paths

Did slight modification to TLDScanner as well to fix below:
Previously though Jars/files both are scanned, summary message used to print only for Jars. Now added fix to print summary message even when files are also scanned unnecessarily.

Please review the patch and let me know if any changes are required.

Thanks,
Pravallika(VIN)
Comment 21 Mark Thomas 2015-05-26 20:01:20 UTC
The proposed patch treats the annotation scan and the fragment scan as independent scans. Unfortunately this is not the case. The patch also ignores the scanning for @HandlesType matches.

Take a look at the comment at the start of ContextConfig.webConfig().

Some things to keep in mind:
- The annotation scan and the @HandleTypes scan are done at the same time.
- The annotation scan can be disabled via metadata-complete
- metadata-complete has no impact on @HandleTypes scan
- exclusion via absolute ordering excludes a JAR from all three scans

I think there are two options.

1. Log a message suggesting the JAR is skipped if it has no hits for all three scans.

2. As 1 but also log a message for JARs that have unnecessary annotation scans that they could use metadata-complete. (Your current patch pretty much does this already.)