RE: Intermittent ClassNotFoundException in Jasper EL evaluation

2016-03-15 Thread jimi.hullegard
On Friday, March 11, 2016 10:03 PM, ma...@apache.org wrote:
> 
> Monday works. I might try experimenting with some ideas between now and then 
> anyway.

Hi again,

A bit shorter reply this time, because of time shortage. I preferred to focus 
the little time I managed to "break free" on testing the trunk version of 
Tomcat 8 :)

And... it looks really great! I have performed some JMeter tests now, and here 
are the results:

Tomcat 8.0.32
Average 2500 ms per request.

Tomcat 8 trunk (revision 81735040)
Average 360 ms per request

Tomcat 7.0.68
Average 290 ms per request


Test setup:
- Windows 8
- JMeter 2.13
- Tomcat with a custom webapp, on Escenic CMS
- JMeter running with one thread, and a throttle (Constant Throughput Timer) 
set to 12 samples per minute (ie 5 seconds between each request)
- Testing the start page (with lots of content)
- Tomcat started fresh, and the webapp visited a few times in the browser as a 
warmup
- Waited until CPU fan and CPU load settled down before starting the test
- No other traffic to Tomcat during the test
- No resource hungry program running except Tomcat and JMeter

So, all in all, I see a huge improvement with our site. Going from 2500 ms to 
360 ms. :)
As you can see, compared to Tomcat 7 it is still an increase with 70 ms, but 
for our site that is not a "deal breaker".

Regards
/Jimi

-
To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
For additional commands, e-mail: users-h...@tomcat.apache.org



RE: Intermittent ClassNotFoundException in Jasper EL evaluation

2016-03-11 Thread jimi.hullegard
On Friday, March 11, 2016 6:07 PM, ma...@apache.org wrote:
> 
> And a debug log message is unlikely to tell you any more than the thread dump 
> did. 

That depends on what is actually being logged. If the class name is printed, 
then one could immediately figure out the name of the EL variable (like 
"java.lang.myTempValue", then the EL parameter name is "myTempValue").

And the thread dump only gives me a snapshot, containing 0, 1 or more 
stacktraces with the ClassNotFoundException. Unless I take a threaddump every 
millisecond (or even more often), the thread dump method would miss some 
stacktraces. With logging, it would not miss any.


> If the same code keeps appearing in a thread dump it is a fair bet that time 
> is being spent in that code but you still need performance data - which you 
> can't get from debug logging or thread dumps - to be certain.

I'm wasn't talking about gathering information regarding performance. I was 
talking about gathering information about what jsp/tag code and what EL 
variable names are responsible for this, and how often it happens. In order to 
get a grasp of if it is feasible to solve by fixing the code. For example, if 
this log output showed me that 90% of the ClassNotFoundExceptions happen 
because of a handful of jsp/tag files, then I would just fix these and see how 
much that helped. But if the log output would indicate that this problem is 
spread out over too many jsp and tag files, then I wouldn't even try and fix it 
in the code, but would instead try some other approach (like disabling this 
feature, or reverting back to Tomcat 7).



> As for using it in production, you aren't going to be using a profiler unless 
> you have a problem. 
> I'd look at the risk (never seen an issue) of using a profiler against the 
> production system and 
> the quality of data / time to useful results vs debug logging and the longer 
> to get results / lower 
> quality of data and choose the profiler every time. YMMV.

Well, I guess you have a point. But the fact is that we don't have any profiler 
tool installed in production right now (and I suspect that is a quite common 
scenario for many users in general), and having one installed is not something 
that is done quickly. Enabling trace or debug logging in a specific class takes 
less than a minute, giving me much needed information more or less instantly.

But yes, if one would have followed common sense, and already had a profiler 
installed (and have used it enough to know how to get it to output the needed 
information), then you would be right ;)



> At the point where you'd need to access the ServletContext to read the 
> configuration, the ServletContext isn't available.
> [...]
> Since I wrote the "configuration API" above, I did some more research and 
> found the route 
> via the ELContext. That is what the implemented solution uses. 

So, just to check if I understood you correctly... You *can* get access to the 
ServletContext, right? (Using page.getServletContext()...)



> It should be possible to hook up your proposed configuration option 
> to pass data via that as long as the code is careful.

OK. Sounds promising. Fingers crossed. :)


> And why would it not work for some users? I'm not saying it would magically 
> solve the problem for everyone. But it would solve the worst problems for 
> most people, and it wouldn't make it worse for anyone (ie, the fact that one 
> would have the *option* to turn it off, doesn't make the situation worse).


> Which is my point. The solution doesn't help those users that need imports 
> and 
> good performance. Greater granularity in configuration helps to a point but 
> there will be users that need imports and good performance on the same page 
> and per expression configuration is taking things a bit too far for my taste.

I'm sorry, but I don't follow you now. Are you saying that since there are 
people who wouldn't benefit from this (but not get hurt either), there is no 
reason to fix it for those that *would* benefit from it?



> Per page is certainly better than global but I still have concerns. In 
> addition to the large pages 
> needing imports and performance above, I'm concerned that there is no good 
> default for
> an option that disables import support. Disabling imports by default will 
> break pages that 
> use imports unless the developer adds the extra code. Not disabling them by 
> default means 
> having to add code to every page with a performance problem.

Well, I never said that it would solve the problem for everyone. But for people 
who don't use any EL imports at all (like everyone migrating from Tomcat 7), 
they would benefit from a global *off* option, and then they can systematically 
enable this feature slowly, page by page, as they add functionality that 
depends on it.

As for people who have pages that need both imports and performance, I still 
claim that this fix wouldn't make it any *worse* for them. In fact, I would 

RE: Intermittent ClassNotFoundException in Jasper EL evaluation

2016-03-11 Thread jimi.hullegard
On Thursday, March 10, 2016 10:44 PM, ma...@apache.org wrote:
> 
> We'll have to agree to disagree on that one. If you are concerned
> about a performance issue then you need to know where to look to
> enable debug logging. A profiler will tell you where to look and
> at that point you don't need the debug logging.

Well, first of all, I found this without knowing where to look. I just checked 
the thread dump, looked closer at the stack traces involving the 
ClassNotFoundExceptions, and found the try catch clause. If there would have 
been a log.debug(...) or log.trace(...) statement there, then I would know how 
to enable debug logging for this. All without knowing beforehand where to look, 
and all without anybody telling me where to look.

Secondly, not all problems are easily reproducible in a 
development/test/staging environment, especially if one depends on the nature 
of the production traffic to find all (or at least most) places in the code 
that experience problems. Not all organizations have the time and/or the money 
to replay/simulate live traffic in another environment. And I suspect that most 
IT departments and/or service providers would react with some suspicion or 
worry if one would try and get them to introduce a profiler in production, even 
though these tools have become more and more production friendly over the years.

Thirdly, even if profiling would be an option, if no profiling is setup already 
then it would take some time and money to do that. Compared to the trivial 
change of logging level for a specific class. And I can't really see how 
log.debug(...) or log.trace(...)  (possibly surrounded by a 
log.isDebugEnabled() or isTraceEnabled())would have any negative effect for 
anyone.

Just my two cents...


> The code in question is in the JSP API JAR and there is no 
> configuration API available. The only option would be 
> a system property which would make it a global configuration option.

I'm not sure I understand why the absence of a "configuration API" would stop 
you from simply checking for a specific init parameter in the servlet context 
(thus making it possible to configure it in the web.xml using a context-param). 
And when it comes to per jsp configuration, one could check for a page scoped 
attribute with the same name. Ideally this could be added as a new page 
directive attribute (like <%@ page disableELImports="true" %>), but I guess 
that would constitute a "configuration API" change that would have to be in the 
specification. But the init parameter or page scoped attribute could be fine 
interim solutions, until the specification is updated to add these 
configuration options the proper way.



> Um, no. See above. This would have to be a global option. It would work for 
> some users/pages but not for others.

Um, yes, see above. ;)

And why would it not work for some users? I'm not saying it would magically 
solve the problem for everyone. But it would solve the worst problems for most 
people, and it wouldn't make it worse for anyone (ie, the fact that one would 
have the *option* to turn it off, doesn't make the situation worse).


> Generally, the suggestions are reasonable. The control can't be as 
> fine-grained as you suggest but that isn't necessarily a show-stopper.

Well, the solution with the page scoped attribute in the jsp page would make it 
fine grained enough for most people, don't you think? :)

I would also be interested in hearing your thoughts about having an option to 
disable this class lookup for all names that doesn't start with a capital 
letter. Thus making ${Boolean.TRUE} work as normal, while skipping ${foo.bar}, 
even if they coexist in the same jsp page. I actually would think that would be 
the best solution to this, since the naming convention dictates that you should 
start class names with capital letter, and variables with lower case letters.

Basically, the code could look something like this, in 
ScopedAttributeELResolver.java:

if (importHandler != null) {
if (resolveClass) {
//disableELImportsForNamesNotStartingWithUpperCase is false by 
default,
//and can be configured using for example a web.xml init 
parameter
if (disableELImportsForNamesNotStartingWithUpperCase && 
!Character.isUpperCase(key.charAt(0))) {
resolveClass = false;
}
}
if (resolveClass) {
...
}
...



> The main disadvantage that these options have is that a 
> better solution is available. Follow the bug report from 
> my previous message in this thread for details.
> [...]
> In this case, I believe the root cause has been fixed.

That sounds great! And I saw now in the bug report page that your simple test 
case indicated a ~1ms performance gain per avoided ClassNotFoundException. That 
sounds very close to my own tests, where the start page takes about 2500 ms, 
and I counted about 2700 ClassNotFoundExceptions.


RE: Intermittent ClassNotFoundException in Jasper EL evaluation

2016-03-10 Thread jimi.hullegard
On Thursday, March 10, 2016 11:20 AM, ma...@apache.org wrote:
> 
> > 3. Why is the problem not limited to the first request for a jsp page? 
> 
> Because EL imports may be dynamic so the EL has to be evaluated on execution.

I'm not really sure I follow you now. Can you explain what you mean with 
dynamic imports in this regard? I can't see any mentioning of it in the specs 
(http://download.oracle.com/otn-pub/jcp/el-3_0-fr-eval-spec/EL3.0.FR.pdf).

Can you give a concrete example, where an EL expression element would need to 
be evaluated as a potential class, again and again for each request?

Because the way I see it, "foo" in ${foo.bar} in some jsp page only needs to be 
evaluated once. If "foo" corresponded to a class, matching one of the imports 
in the jsp, then this lookup will not change unless the jsp code changes. And 
the same is true if the lookup failes with a ClassNotFoundException. What am I 
missing?


> > 4. Why isn't the ClassNotFoundException logged by the ImportHandler?
> 
> Because it is expected and logging it provides no value to the user.

Well, I happen to disagree. :)
In our case, if we could see all these stacktraces in the log, by enabling 
DEBUG/TRACE log level on the ImportHandler class for example, then we would 
quickly see just how big this problem is (ie how often this happens), on what 
jsp pages it happens, and what EL expressions cause it.

On my local machine, I was able to "catch" the ClassNotFoundException using a 
debug breakpoint in my IDE, and using the breakpoint hit count I could see that 
this exception is thrown and handled (ie ignored) by the ImportHandler 2700 
times for a single request to the start page. 


> The JavaEE specs are very big on backwards compatibility. 
> Therefore, the chances of changing the spec syntax to fix this are zero.

OK. Fair enough. I agree with you that backwards compatibility is important. 
But there are ways to fix this while still keeping the backwards compatibility. 
For example by making it possible to turn off this feature (globally, per 
webapp, or per jsp), where the default is "on". Wouldn't you agree that such a 
change would be 100% backwards compatible? And at the same time it would more 
or less solve this problem completely. Because people who experience the 
mentioned problems could turn of this setting globally, and then only enable it 
for those specific jsp pages where it is needed (and these pages would then be 
cleaned up, so that no EL-references exist without specific scope unless they 
are known to never be null. Tada, problem solved! =)

Actually... this wouldn't even need to be in the specifications... I can't see 
any harm in a EL implementation introducing such settings on its own, before 
the specifications can "catch up". That way you could basically introduce this 
fix in trunk right now, and have it tested and out in a stable release in no 
time =)



On Thursday, March 10, 2016 1:24 PM, ma...@apache.org wrote:
> 
> The issue is in ScopedAttributeELResolver.
> 
> ScopedAttributeELResolver checks the page/request/session/application context
> first and only if it doesn't find the attribute there does it try loading the 
> class.

When debugging this in my IDE, I could see this in action. I also noticed that 
the ImportHandler that performs the class lookup is fetched from the ELContext 
object. So if I could wrap that object, I could simply return null in the 
method getImportHandler(), thus disabling this functionallity and therefore 
solving the performance problem for us. But I couldn't find any way to wrap the 
ELContext, for some reason. Can it be done, using standard code or config? Or 
can this "import logic" be disabled some other way?

There really should be a way for users to disable this, if the functionallity 
is not used and it just is causing problems. And, like I said above, that could 
be done without breaking the specs. And an alternative way to the way above, 
could be like I mentioned before, to add a configuration option that forces the 
class name to begin with a capital letter. That way ${Boolean.TRUE}, 
${Integer.MAX_VALUE} and ${MyClass.myStaticField} would still work, while 
${foo.bar} etc would simply be ignored. As long as the configuration option 
would default to false (ie lower case first letter is allowed, as per the 
specification) it wouldn't break the specification unless the user deliberately 
told it to (which is fine, right?).

It would be really nice to get your input on these suggestions. And if you 
don't like them, could you explain why? If your opinion is "We need to stick 
100% to the specification, and never ever give even the expert user any way to 
override this, ever", then I would say that such a view causes more harm than 
good. :)

Regards
/Jimi

-
To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
For additional commands, e-mail: users-h...@tomcat.apache.org



RE: Intermittent ClassNotFoundException in Jasper EL evaluation

2016-03-10 Thread jimi.hullegard
On Wednesday, March 9, 2016 8:22 PM, ma...@apache.org wrote:
> It is a known 'feature' of the new EL requirements added in 3.0. The EL 
> parser can't differentiate 
> between an attribute without a scope and a reference to an static field.
> 
> See https://bz.apache.org/bugzilla/show_bug.cgi?id=57583

Interesting. I can see how that in a way could explain the the performance 
regression. But what I don't understand is:

1. Why would this cause a ClassNotFoundException? What class exactly is it 
trying to load?
2. Why is this happening seemingly intermittently, with different EL variables 
each time?
3. Why is the problem not limited to the first request for a jsp page? We see 
this problem even days after a restart, for jsp-pages that definitely have been 
used multiple times already, with the same state for it's variables.
4. Why isn't the ClassNotFoundException logged by the ImportHandler?
5. Why would this change between Tomcat 7 and Tomcat 8, with the exact same 
webapp war with the exact same web.xml?
6. In our web.xml we specify version="2.5". Wouldn't that mean EL version 2.1? 
(http://tomcat.apache.org/whichversion.html)

> The way to avoid it is to always add an explicit scope (page, request, 
> application, session) to your attributes.

Is this an official recommendation, stemming from the EL 3.0 specifications? If 
so, can you point me to that paragraph in the specification document, or some 
other paper of similar nature? Because when I look at the 3.0 specification 
document, all I see is examples without scope.

Or is this just a pragmatic response to the Tomcat/Jasper implementation of the 
specifications?

The reason I ask is that a simple search in our code base show that we have 
about 10.000 potential candidates for the change you are suggesting, spread out 
in hundreds of jsp files in our project. And on top of that, the CMS that we 
use have their own jsp files, and a quick check indicates thousands of 
potential candidates for the change there as well. So not only would we have to 
perform a monumental task in our own code (because we would need to determine 
the scope manually, for each and every variable), we also would need to ask the 
CMS company to perform the same task.

> Suggestions for improvements to the default ImportHandler implementation to 
> make this faster are welcome.

Well, I am quite pragmatic in my thinking. Is this EL implementation the only 
implementation with this problem? Then surely one can look at the other 
implementations, and what they did to avoid this problem. But one thing off the 
top of my head would be to atleast avoid doing that class lookup in cases where 
it couldn't be a static field reference (like ${name}, since there is no dot 
after "name", there is no reason to check if "name" is a class reference, 
right?). 

Otherwise, if more or less all implementations suffer from this problem, then 
maybe it is the specification that is to blame. Maybe, when introducing the new 
concept of EL references to static fields, they could use a special prefix, 
like ${static.Boolean.True}, or they could have had this feature turned off by 
default, with the possibility to turn it on either per jsp page (using some 
page directive like <%@ page staticElReferences="true" %>) or webapp-globally 
in the web.xml. Or, they could simply include the requirement that the class 
name must start with a capital letter, thus only causing problems for people 
who break the coding standard (ie either having a class name starting with a 
lower case letter, or having a variable name starting with an upper case 
letter).

/Jimi

-
To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
For additional commands, e-mail: users-h...@tomcat.apache.org



Intermittent ClassNotFoundException in Jasper EL evaluation

2016-03-09 Thread jimi.hullegard
Hi,

We recently upgraded Tomcat from version 7 to version 8 (8.0.32 to be precise), 
and we immediately noticed a deterioration in the performance. Page load time 
increased from about 500ms to 2500-5000 ms.

One thing we noticed when we looked at some thread dumps, is that quite often a 
ClassNotFoundException can be seen. I found that a bit interesting, because it 
didn't correspond to any ClassNotFoundException in the log file. However, when 
troubleshooting this I noticed that the exception is caught and ignored.

Here is an example stacktrace from one thread dump:

"http-apr-8080-exec-33" Id=282 in RUNNABLE
at java.lang.Throwable.fillInStackTrace(Native Method)
at java.lang.Throwable.fillInStackTrace(Throwable.java:783)
  - locked java.lang.ClassNotFoundException@26bef633
at java.lang.Throwable.(Throwable.java:287)
at java.lang.Exception.(Exception.java:84)
at 
java.lang.ReflectiveOperationException.(ReflectiveOperationException.java:75)
   at java.lang.ClassNotFoundException.(ClassNotFoundException.java:82)
at java.net.URLClassLoader$1.run(URLClassLoader.java:372)
at java.net.URLClassLoader$1.run(URLClassLoader.java:361)
at java.security.AccessController.doPrivileged(Native Method)
at java.net.URLClassLoader.findClass(URLClassLoader.java:360)
at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
  - locked java.lang.Object@2ca91dd5
at java.lang.ClassLoader.loadClass(ClassLoader.java:411)
  - locked java.lang.Object@64a0e12a
at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:308)
at java.lang.ClassLoader.loadClass(ClassLoader.java:411)
  - locked java.lang.Object@1b5f6952
at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
at java.lang.Class.forName0(Native Method)
at java.lang.Class.forName(Class.java:344)
at 
org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1285)
  - locked org.apache.catalina.loader.WebappClassLoader@254b720a
at 
org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1167)
at javax.el.ImportHandler.findClass(ImportHandler.java:195)
at javax.el.ImportHandler.resolveClass(ImportHandler.java:164)
at 
javax.servlet.jsp.el.ScopedAttributeELResolver.getValue(ScopedAttributeELResolver.java:62)
at org.apache.jasper.el.JasperELResolver.getValue(JasperELResolver.java:110)
at org.apache.el.parser.AstIdentifier.getValue(AstIdentifier.java:80)
at org.apache.el.parser.AstEmpty.getValue(AstEmpty.java:46)
at org.apache.el.parser.AstNot.getValue(AstNot.java:43)
at org.apache.el.ValueExpressionImpl.getValue(ValueExpressionImpl.java:184)
at 
org.apache.jasper.runtime.PageContextImpl.proprietaryEvaluate(PageContextImpl.java:943)
at 
org.apache.jsp.template.framework.common.elements.sectionText.sectionText_jsp._jspx_meth_c_005fif_005f3(sectionText_jsp.java:460)


Here is the code on line 460 in sectionText_jsp.java:

_jspx_th_c_005fif_005f3.setTest(((java.lang.Boolean) 
org.apache.jasper.runtime.PageContextImpl.proprietaryEvaluate("${not empty 
leadtext}", boolean.class, (javax.servlet.jsp.PageContext)_jspx_page_context, 
null)).booleanValue());


And here is the corresponding line in sectionText.jsp:




I cannot for the life of me understand how this simple EL expression can result 
in a ClassNotFoundException.

Also, this problem doesn't occur just with this specific jsp file. In fact, it 
seems to be a different jsp file involved each time. And it doesn't happen 
every time. The fact is that in order for me to recreate the problem in my 
local environment, I had to perform quite a few page requests in the browser, 
and still it only happened once in a while (with different jsp file each time). 
So it is very intermittent, and seems to be something happening deep down in 
the core of Tomcat itself. I'm not claiming it is a Tomcat bug, it could very 
well be some erroneous configuration that we are using. But the error doesn't 
really seem to be related to our code base, or our third party jars.

Has anyone seen this problem before? What could be the cause of it?

Regards
/Jimi


RE: Detect shutdown when in common/global classpath?

2015-12-02 Thread jimi.hullegard
Mark wrote:
> On 30/11/2015 15:51, jimi.hulleg...@svensktnaringsliv.se wrote:
> > Hi,
> > 
> > When running code in a webapp, I know it is possible to detect an undeploy 
> > of the webapp, or shutdown of Tomcat, using a ServletContextListener. But 
> > how about code running outside the webapp?
> > 
> > The background for this is that we have written a plugin to a CMS, and this 
> > plugin exists in the common/global classpath. The CMS calls the plugin on 
> > certain occasions, triggered by some custom scheduling logic, and if we are 
> > unlucky our plugin gets called during a shutdown of Tomcat giving us 
> > strange  errors that result in an unnecessary error report email being 
> > sent. So what I would like to do is to add some check in our plugin, to 
> > avoid doing anything if Tomcat is in the process of shutting down. But is 
> > this possible, without some ugly hack?
> 
> Use a LifecycleListener that notifies your plug-in when Tomcat is shutting 
> down. See org.apache.catalina.startup.VersionLoggerListener for an example.

Thanks Mark, that was exactly what I was looking for!

/Jimi

-
To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
For additional commands, e-mail: users-h...@tomcat.apache.org



Detect shutdown when in common/global classpath?

2015-11-30 Thread jimi.hullegard
Hi,

When running code in a webapp, I know it is possible to detect an undeploy of 
the webapp, or shutdown of Tomcat, using a ServletContextListener. But how 
about code running outside the webapp?

The background for this is that we have written a plugin to a CMS, and this 
plugin exists in the common/global classpath. The CMS calls the plugin on 
certain occasions, triggered by some custom scheduling logic, and if we are 
unlucky our plugin gets called during a shutdown of Tomcat giving us strange  
errors that result in an unnecessary error report email being sent. So what I 
would like to do is to add some check in our plugin, to avoid doing anything if 
Tomcat is in the process of shutting down. But is this possible, without some 
ugly hack?

Regards
/Jimi