Intermittent JSP Caching/Compiling Issue while under load

classic Classic list List threaded Threaded
26 messages Options
12
Reply | Threaded
Open this post in threaded view
|

Intermittent JSP Caching/Compiling Issue while under load

Tim K
I'm on Tomcat 9.0.21 on Linux.  I have Jsps that get updated while
Tomcat is running.  I believe development mode is set to true by
default, I do not have it set to true or false in the
$CATALINA_BASE/conf/web.xml for the Jsp servlet init-params.  I have a
cluster of 4-8 servers across different envs.  I'm noticing an
intermittent issue where 1 or more of my tomcat instances do not
always compile the latest Jsp content while the server is under load.
I've tried debugging the org.apache.jasper.compiler, it appears that
the class/java files of the tomcat work directory are getting
deleted/regenerated (get a new timestamp as well) but occasionally the
contents of the Jsp becomes out of sync in the generated class file
within the tomcat work directory.  I've tried different combinations
of development mode, checkInterval, modificationTestInterval but none
seem to help resolve this issue.  This only seems to be an issue when
the server is under a load.  I was able to reproduce in my lower env
(4 server cluster) while hitting the Jsp every 1 seconds while
changing the jsp contents.  I can make a subsequent change and the Jsp
content likely get's picked up by the same server(s) which previous
didn't pick it up.

Thanks in advance,
Tim

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: Intermittent JSP Caching/Compiling Issue while under load

markt


On 29/10/2019 14:31, Tim K wrote:

> I'm on Tomcat 9.0.21 on Linux.  I have Jsps that get updated while
> Tomcat is running.  I believe development mode is set to true by
> default, I do not have it set to true or false in the
> $CATALINA_BASE/conf/web.xml for the Jsp servlet init-params.  I have a
> cluster of 4-8 servers across different envs.  I'm noticing an
> intermittent issue where 1 or more of my tomcat instances do not
> always compile the latest Jsp content while the server is under load.
> I've tried debugging the org.apache.jasper.compiler, it appears that
> the class/java files of the tomcat work directory are getting
> deleted/regenerated (get a new timestamp as well) but occasionally the
> contents of the Jsp becomes out of sync in the generated class file
> within the tomcat work directory.  I've tried different combinations
> of development mode, checkInterval, modificationTestInterval but none
> seem to help resolve this issue.  This only seems to be an issue when
> the server is under a load.  I was able to reproduce in my lower env
> (4 server cluster) while hitting the Jsp every 1 seconds while
> changing the jsp contents.  I can make a subsequent change and the Jsp
> content likely get's picked up by the same server(s) which previous
> didn't pick it up.

That you see the issue when hitting the JSP once a second makes me think
it is something to do with timestamp resolution. Are you making
modifications within a similarly short time-frame? Or do you still see
the issue when the modifications are, say, minutes apart?

Mark


---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: Intermittent JSP Caching/Compiling Issue while under load

markt
On 31/10/2019 22:07, Mark Thomas wrote:

>
>
> On 29/10/2019 14:31, Tim K wrote:
>> I'm on Tomcat 9.0.21 on Linux.  I have Jsps that get updated while
>> Tomcat is running.  I believe development mode is set to true by
>> default, I do not have it set to true or false in the
>> $CATALINA_BASE/conf/web.xml for the Jsp servlet init-params.  I have a
>> cluster of 4-8 servers across different envs.  I'm noticing an
>> intermittent issue where 1 or more of my tomcat instances do not
>> always compile the latest Jsp content while the server is under load.
>> I've tried debugging the org.apache.jasper.compiler, it appears that
>> the class/java files of the tomcat work directory are getting
>> deleted/regenerated (get a new timestamp as well) but occasionally the
>> contents of the Jsp becomes out of sync in the generated class file
>> within the tomcat work directory.  I've tried different combinations
>> of development mode, checkInterval, modificationTestInterval but none
>> seem to help resolve this issue.  This only seems to be an issue when
>> the server is under a load.  I was able to reproduce in my lower env
>> (4 server cluster) while hitting the Jsp every 1 seconds while
>> changing the jsp contents.  I can make a subsequent change and the Jsp
>> content likely get's picked up by the same server(s) which previous
>> didn't pick it up.
>
> That you see the issue when hitting the JSP once a second makes me think
> it is something to do with timestamp resolution. Are you making
> modifications within a similarly short time-frame? Or do you still see
> the issue when the modifications are, say, minutes apart?

Could this be the issue:
https://bz.apache.org/bugzilla/show_bug.cgi?id=63897

Mark


---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: Intermittent JSP Caching/Compiling Issue while under load

Tim K
On Fri, Nov 1, 2019, 3:11 AM Mark Thomas <[hidden email]> wrote:

> On 31/10/2019 22:07, Mark Thomas wrote:
> >
> >
> > On 29/10/2019 14:31, Tim K wrote:
> >> I'm on Tomcat 9.0.21 on Linux.  I have Jsps that get updated while
> >> Tomcat is running.  I believe development mode is set to true by
> >> default, I do not have it set to true or false in the
> >> $CATALINA_BASE/conf/web.xml for the Jsp servlet init-params.  I have a
> >> cluster of 4-8 servers across different envs.  I'm noticing an
> >> intermittent issue where 1 or more of my tomcat instances do not
> >> always compile the latest Jsp content while the server is under load.
> >> I've tried debugging the org.apache.jasper.compiler, it appears that
> >> the class/java files of the tomcat work directory are getting
> >> deleted/regenerated (get a new timestamp as well) but occasionally the
> >> contents of the Jsp becomes out of sync in the generated class file
> >> within the tomcat work directory.  I've tried different combinations
> >> of development mode, checkInterval, modificationTestInterval but none
> >> seem to help resolve this issue.  This only seems to be an issue when
> >> the server is under a load.  I was able to reproduce in my lower env
> >> (4 server cluster) while hitting the Jsp every 1 seconds while
> >> changing the jsp contents.  I can make a subsequent change and the Jsp
> >> content likely get's picked up by the same server(s) which previous
> >> didn't pick it up.
> >
> > That you see the issue when hitting the JSP once a second makes me think
> > it is something to do with timestamp resolution. Are you making
> > modifications within a similarly short time-frame? Or do you still see
> > the issue when the modifications are, say, minutes apart?
>
> Could this be the issue:
> https://bz.apache.org/bugzilla/show_bug.cgi?id=63897
>
> Mark
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [hidden email]
> For additional commands, e-mail: [hidden email]


In my tests when hitting it every second, I make a few changes and it works
fine (all within the same min).  Then I'll let it go for a few mins, make a
change and more often than not, one or more of the servers gets stuck on
the previous jsp change... I'm pretty sure the class/java timestamps get
updated but the content does not.
Reply | Threaded
Open this post in threaded view
|

Re: Intermittent JSP Caching/Compiling Issue while under load

Tim K
>
> In my tests when hitting it every second, I make a few changes and it
> works fine (all within the same min).  Then I'll let it go for a few mins,
> make a change and more often than not, one or more of the servers gets
> stuck on the previous jsp change... I'm pretty sure the class/java
> timestamps get updated but the content does not.
>

This morning I made one single change to the JSP which appeared the get
stuck on all 4 of my servers, as shown below:

https://pasteboard.co/IF8nrEG.jpg

Also, with additional logging, it appears that Tomcat sees the change and
regenerates the java and class files but yet it still serves the former JSP
content.  If I manual delete the class/java files under the work dir, it
will successfully pick up the latest.

04-Nov-2019 07:30:30.646 FINE [Catalina-utility-2]
org.apache.jasper.compiler.Compiler.isOutDated Compiler: outdated:
/apache-tomcat-9.0.21/work/Catalina/localhost/context-root/org/apache/jsp/abcxyz/test_jsp.class
1572443847000

04-Nov-2019 07:30:30.646 FINE [Catalina-utility-2]
org.apache.jasper.compiler.Compiler.removeGeneratedClassFiles Deleting
/apache-tomcat-9.0.21/work/Catalina/localhost/context-root/org/apache/jsp/abcxyz/test_jsp.class

04-Nov-2019 07:30:30.647 FINE [Catalina-utility-2]
org.apache.jasper.compiler.Compiler.removeGeneratedFiles Deleting
/apache-tomcat-9.0.21/work/Catalina/localhost/context-root/org/apache/jsp/abcxyz/test_jsp.java

04-Nov-2019 07:30:30.652 FINE [Catalina-utility-2]
org.apache.jasper.compiler.Compiler.generateJava Generated
/apache-tomcat-9.0.21/work/Catalina/localhost/context-root/org/apache/jsp/abcxyz/test_jsp.java
total=4 generate=1 validate=3

04-Nov-2019 07:30:30.718 FINE [Catalina-utility-2]
org.apache.jasper.compiler.JDTCompiler.generateClass Compiled
/apache-tomcat-9.0.21/work/Catalina/localhost/context-root/org/apache/jsp/abcxyz/test_jsp.java
59ms
Reply | Threaded
Open this post in threaded view
|

Re: Intermittent JSP Caching/Compiling Issue while under load

markt
On 04/11/2019 13:55, Tim K wrote:

>>
>> In my tests when hitting it every second, I make a few changes and it
>> works fine (all within the same min).  Then I'll let it go for a few mins,
>> make a change and more often than not, one or more of the servers gets
>> stuck on the previous jsp change... I'm pretty sure the class/java
>> timestamps get updated but the content does not.
>>
>
> This morning I made one single change to the JSP which appeared the get
> stuck on all 4 of my servers, as shown below:

How are you distributing the updates to the JSP to all 4 servers?

Is there a shared file system involved? If yes, exactly what is shared
between the instances?

Mark


>
> https://pasteboard.co/IF8nrEG.jpg
>
> Also, with additional logging, it appears that Tomcat sees the change and
> regenerates the java and class files but yet it still serves the former JSP
> content.  If I manual delete the class/java files under the work dir, it
> will successfully pick up the latest.
>
> 04-Nov-2019 07:30:30.646 FINE [Catalina-utility-2]
> org.apache.jasper.compiler.Compiler.isOutDated Compiler: outdated:
> /apache-tomcat-9.0.21/work/Catalina/localhost/context-root/org/apache/jsp/abcxyz/test_jsp.class
> 1572443847000
>
> 04-Nov-2019 07:30:30.646 FINE [Catalina-utility-2]
> org.apache.jasper.compiler.Compiler.removeGeneratedClassFiles Deleting
> /apache-tomcat-9.0.21/work/Catalina/localhost/context-root/org/apache/jsp/abcxyz/test_jsp.class
>
> 04-Nov-2019 07:30:30.647 FINE [Catalina-utility-2]
> org.apache.jasper.compiler.Compiler.removeGeneratedFiles Deleting
> /apache-tomcat-9.0.21/work/Catalina/localhost/context-root/org/apache/jsp/abcxyz/test_jsp.java
>
> 04-Nov-2019 07:30:30.652 FINE [Catalina-utility-2]
> org.apache.jasper.compiler.Compiler.generateJava Generated
> /apache-tomcat-9.0.21/work/Catalina/localhost/context-root/org/apache/jsp/abcxyz/test_jsp.java
> total=4 generate=1 validate=3
>
> 04-Nov-2019 07:30:30.718 FINE [Catalina-utility-2]
> org.apache.jasper.compiler.JDTCompiler.generateClass Compiled
> /apache-tomcat-9.0.21/work/Catalina/localhost/context-root/org/apache/jsp/abcxyz/test_jsp.java
> 59ms
>


---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: Intermittent JSP Caching/Compiling Issue while under load

Tim K
On Mon, Nov 4, 2019, 10:06 AM Mark Thomas <[hidden email]> wrote:

>
> How are you distributing the updates to the JSP to all 4 servers?
>
> Is there a shared file system involved? If yes, exactly what is shared
> between the instances?
>
> Mark
>

Common NFS storage included via <PreResources> (DirResourceSet) within the
<Context> of my clustered application.  But to rule out any issue with
that, I tried using local storage within the war directory itself and
updated the JSP on local storage exactly at the same time and the problem
still persisted.

>
Reply | Threaded
Open this post in threaded view
|

Re: Intermittent JSP Caching/Compiling Issue while under load

markt
On 04/11/2019 15:11, Tim K wrote:

> On Mon, Nov 4, 2019, 10:06 AM Mark Thomas <[hidden email]> wrote:
>
>>
>> How are you distributing the updates to the JSP to all 4 servers?
>>
>> Is there a shared file system involved? If yes, exactly what is shared
>> between the instances?
>>
>> Mark
>>
>
> Common NFS storage included via <PreResources> (DirResourceSet) within the
> <Context> of my clustered application.  But to rule out any issue with
> that, I tried using local storage within the war directory itself and
> updated the JSP on local storage exactly at the same time and the problem
> still persisted.

Thanks. That helps as it means the issue should be reproducible on a
single, stand-alone instance.

Mark

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: Intermittent JSP Caching/Compiling Issue while under load

markt
On 04/11/2019 15:30, Mark Thomas wrote:

> On 04/11/2019 15:11, Tim K wrote:
>> On Mon, Nov 4, 2019, 10:06 AM Mark Thomas <[hidden email]> wrote:
>>
>>>
>>> How are you distributing the updates to the JSP to all 4 servers?
>>>
>>> Is there a shared file system involved? If yes, exactly what is shared
>>> between the instances?
>>>
>>> Mark
>>>
>>
>> Common NFS storage included via <PreResources> (DirResourceSet) within the
>> <Context> of my clustered application.  But to rule out any issue with
>> that, I tried using local storage within the war directory itself and
>> updated the JSP on local storage exactly at the same time and the problem
>> still persisted.
>
> Thanks. That helps as it means the issue should be reproducible on a
> single, stand-alone instance.

Hmm. I have a theory but it is one that I can't easily reproduce because
the root cause is using non-volatile fields across multiple threads.

How plausible is it that there would be two concurrent requests for that
modified JSP?

Mark

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: Intermittent JSP Caching/Compiling Issue while under load

Christopher Schultz-2
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Mark,

On 11/4/19 11:56, Mark Thomas wrote:

> On 04/11/2019 15:30, Mark Thomas wrote:
>> On 04/11/2019 15:11, Tim K wrote:
>>> On Mon, Nov 4, 2019, 10:06 AM Mark Thomas <[hidden email]>
>>> wrote:
>>>
>>>>
>>>> How are you distributing the updates to the JSP to all 4
>>>> servers?
>>>>
>>>> Is there a shared file system involved? If yes, exactly what
>>>> is shared between the instances?
>>>>
>>>> Mark
>>>>
>>>
>>> Common NFS storage included via <PreResources> (DirResourceSet)
>>> within the <Context> of my clustered application.  But to rule
>>> out any issue with that, I tried using local storage within the
>>> war directory itself and updated the JSP on local storage
>>> exactly at the same time and the problem still persisted.
>>
>> Thanks. That helps as it means the issue should be reproducible
>> on a single, stand-alone instance.
>
> Hmm. I have a theory but it is one that I can't easily reproduce
> because the root cause is using non-volatile fields across multiple
> threads.
>
> How plausible is it that there would be two concurrent requests for
> that modified JSP?

Pretty plausible IMHO. Imagine /index.jsp being updated and everybody
hits that.

Especially in these days of "there is only one page in the whole site
and you only request it once" web applications. (*grump*)

- -chris
-----BEGIN PGP SIGNATURE-----
Comment: Using GnuPG with Thunderbird - https://www.enigmail.net/

iQIzBAEBCAAdFiEEMmKgYcQvxMe7tcJcHPApP6U8pFgFAl3AcwoACgkQHPApP6U8
pFiHVxAAvV1yfHGQZbuZ4y+kllROBrrvlm8o2mlxY6GqMWJWIrkfwG2E1y1PveXm
r6CR310V8/gK2N9uK7rbhT42rMfMUN+zWy3O6qI6jEwidknh26uYvok75a5rnpx1
f/Gk/PfbFCECownrvuGIG7Tgecdw6eWCR2yT2ZMDNdkM0UG8T0mb5XdSUEhm6sm3
EJvA8uYFY3mIb+6uXzTYotUfA1Ij41+K+/mzFjXr/upWu0QYfugckjW4cOG1daT6
h1B8LLZmi8cAqjDInWSYuuKyudsqfoxlyIdD98AQSEt5DnhvbqQazEcWI3eOJ+Qc
ikltp5clIwT+fDYZkzBDMlDwfyDtx33Y0FXBrzgA8hetfr3PV563fmHgNqewUbLU
HZWbaKW8TDuZEasLaHnTPRi5oJCGGIa0YK7dY0kWIGgT0sOOjyFRqFOr+gF/+tnf
m8GYzKistvpWe4Sf8WSYpOeghBrMfBUoBYLjHx3IGJW7r8lFQCIXvvjz4bm2krIy
vYegeUT3UEQ7P7I/0Aug7m+LTiyfH3N4fcxOFgRBoqUIt0oXLyarCZF1y4eDZiqM
3htPudHP8K5qHNbu7Zvt73B9pye5cUdSt0HU9QO6CwjrJa3qSl0EMsPzPOJcecar
omN0NA2Q6w46LwDMzDiq8E+zNgfSw/mSPkSWvO9aGmvzxy/OHKA=
=d7q8
-----END PGP SIGNATURE-----

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: Intermittent JSP Caching/Compiling Issue while under load

Tim K
In reply to this post by markt
On Mon, Nov 4, 2019, 10:30 AM Mark Thomas <[hidden email]> wrote:

>
> Thanks. That helps as it means the issue should be reproducible on a
> single, stand-alone instance.
>
> Mark
>

I was able to reproduce this behavior with a single server running a
vanilla 9.0.21 using the example hello.jsp file...  I was hitting the url
every 0.5 seconds.

>
Reply | Threaded
Open this post in threaded view
|

Re: Intermittent JSP Caching/Compiling Issue while under load

Alex O'Ree
Sounds a lot like the issue I reported a few months ago....

On Mon, Nov 4, 2019, 3:12 PM Tim K <[hidden email]> wrote:

> On Mon, Nov 4, 2019, 10:30 AM Mark Thomas <[hidden email]> wrote:
>
> >
> > Thanks. That helps as it means the issue should be reproducible on a
> > single, stand-alone instance.
> >
> > Mark
> >
>
> I was able to reproduce this behavior with a single server running a
> vanilla 9.0.21 using the example hello.jsp file...  I was hitting the url
> every 0.5 seconds.
>
> >
>
Reply | Threaded
Open this post in threaded view
|

Re: Intermittent JSP Caching/Compiling Issue while under load

M. Manna
I’m just trying to understand, is there really a plausible solution here ?
Unless we have loadbalanced tomcat instances, can we truly ever stop such
behaviour (or more importantly, does it make sense to do so)?

For my use case, We do it in production almost every other day for
patching, but we do it on our 60 servers over a duration of 15-20 minutes
(and by rolling 1-by-1). That said, this may not be an acceptable
delay/solution for others. Also, if it happens to be a critical piece
(index.jsp or something more client-faces), you may not be able to wait
that long.

It’s be good to know what others think.

Regards,


On Mon, 4 Nov 2019 at 22:55, Alex O'Ree <[hidden email]> wrote:

> Sounds a lot like the issue I reported a few months ago....
>
> On Mon, Nov 4, 2019, 3:12 PM Tim K <[hidden email]> wrote:
>
> > On Mon, Nov 4, 2019, 10:30 AM Mark Thomas <[hidden email]> wrote:
> >
> > >
> > > Thanks. That helps as it means the issue should be reproducible on a
> > > single, stand-alone instance.
> > >
> > > Mark
> > >
> >
> > I was able to reproduce this behavior with a single server running a
> > vanilla 9.0.21 using the example hello.jsp file...  I was hitting the url
> > every 0.5 seconds.
> >
> > >
> >
>
Reply | Threaded
Open this post in threaded view
|

Re: Intermittent JSP Caching/Compiling Issue while under load

Tim K
On Mon, Nov 4, 2019, 6:19 PM M. Manna <[hidden email]> wrote:

> I’m just trying to understand, is there really a plausible solution here ?
> Unless we have loadbalanced tomcat instances, can we truly ever stop such
> behaviour (or more importantly, does it make sense to do so)?
>
> For my use case, We do it in production almost every other day for
> patching, but we do it on our 60 servers over a duration of 15-20 minutes
> (and by rolling 1-by-1). That said, this may not be an acceptable
> delay/solution for others. Also, if it happens to be a critical piece
> (index.jsp or something more client-faces), you may not be able to wait
> that long.
>
> It’s be good to know what others think.
>
> Regards,
>

The cached JSP actually survives a tomcat restart because the work
directory still contains the cached JSP content even though the timestamp
of the class/java files appear to match that of the latest JSP file's
content.

>
Reply | Threaded
Open this post in threaded view
|

Re: Intermittent JSP Caching/Compiling Issue while under load

markt
On 05/11/2019 02:51, Tim K wrote:

<snip/>

> The cached JSP actually survives a tomcat restart because the work
> directory still contains the cached JSP content even though the timestamp
> of the class/java files appear to match that of the latest JSP file's
> content.

Ah. That is useful new information. It rules out the non-volatile field
issue I found yesterday as the root cause (the issue has been fixed
anyway for the next round of releases). I'll take another look at the
source.

This looks like some sort of concurrency issue. In your test
environment, how likely is it that:
- there are concurrent (or at least very close together) changes to a
  JSP
- that there are concurrent requests for a modified JSP?

Also, what process are you using to update the JSP content?

Mark

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: Intermittent JSP Caching/Compiling Issue while under load

Tim K
On Tue, Nov 5, 2019 at 3:01 AM Mark Thomas <[hidden email]> wrote:
> This looks like some sort of concurrency issue. In your test
> environment, how likely is it that:
> - there are concurrent (or at least very close together) changes to a
>   JSP
> - that there are concurrent requests for a modified JSP?

In my test env, I am the sole person making changes to the JSP.  Also,
in production, its only 1 single person making changes to a particular
JSP.

It is very likely that there are concurrent requests for the modified
JSP.  That is exactly how I am reproducing this, I basically have a
curl command being executed every 0.5-1 seconds for that modified JSP
when this intermittent issue occurs.  With high production traffic,
it's very possible that one or more users are hitting a modified JSP.

> Also, what process are you using to update the JSP content?

In my tests, I'm simply using VIM, in production, it's using a content
management system which likely just copies the new JSP over, similar
to an rsync or cp command.  The issue is reproducible in both cases,
as long as there are active requests for the modified JSP.

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: Intermittent JSP Caching/Compiling Issue while under load

markt
I've found the root cause.

When checking the timestamps of JSPs, the JSP engine (because it has to
access all resources via the Servlet API) requests a URL for the JSP,
opens a connection to the URL and then checks the last modified time.
This goes directly to the on-disk file.

When reading the content, the request goes via the static resource cache
because we can intercept the call to ServletContext.getResourceAsStream()

The problem is the following sequence:
- request for JSP
  - no change in JSP timestamp found
  - cache re-validated (for 5s by default)
- JSP is modified (within 5s)
- request for JSP (within 5s)
  - change in JSP timestamp found
  - JSP content read (sees cached version rather than new version)

So we end up with the old version of the JSP content with the updated
last modification time.

I'm currently looking at options to return a URL for the resource where
we can intercept the call to URLConnection.getLastModified().

Mark

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: Intermittent JSP Caching/Compiling Issue while under load

markt
On 06/11/2019 20:04, Mark Thomas wrote:

> I've found the root cause.
>
> When checking the timestamps of JSPs, the JSP engine (because it has to
> access all resources via the Servlet API) requests a URL for the JSP,
> opens a connection to the URL and then checks the last modified time.
> This goes directly to the on-disk file.
>
> When reading the content, the request goes via the static resource cache
> because we can intercept the call to ServletContext.getResourceAsStream()
>
> The problem is the following sequence:
> - request for JSP
>   - no change in JSP timestamp found
>   - cache re-validated (for 5s by default)
> - JSP is modified (within 5s)
> - request for JSP (within 5s)
>   - change in JSP timestamp found
>   - JSP content read (sees cached version rather than new version)
>
> So we end up with the old version of the JSP content with the updated
> last modification time.
>
> I'm currently looking at options to return a URL for the resource where
> we can intercept the call to URLConnection.getLastModified().

Fixed in:
- master for 9.0.28 onwards
- 8.5.x for 8.5.48 onwards

Mark

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: Intermittent JSP Caching/Compiling Issue while under load

Christopher Schultz-2
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Mark,

On 11/7/19 06:40, Mark Thomas wrote:

> On 06/11/2019 20:04, Mark Thomas wrote:
>> I've found the root cause.
>>
>> When checking the timestamps of JSPs, the JSP engine (because it
>> has to access all resources via the Servlet API) requests a URL
>> for the JSP, opens a connection to the URL and then checks the
>> last modified time. This goes directly to the on-disk file.
>>
>> When reading the content, the request goes via the static
>> resource cache because we can intercept the call to
>> ServletContext.getResourceAsStream()
>>
>> The problem is the following sequence: - request for JSP - no
>> change in JSP timestamp found - cache re-validated (for 5s by
>> default) - JSP is modified (within 5s) - request for JSP (within
>> 5s) - change in JSP timestamp found - JSP content read (sees
>> cached version rather than new version)
>>
>> So we end up with the old version of the JSP content with the
>> updated last modification time.
>>
>> I'm currently looking at options to return a URL for the resource
>> where we can intercept the call to
>> URLConnection.getLastModified().
>
> Fixed in: - master for 9.0.28 onwards - 8.5.x for 8.5.48 onwards

Would you mind checking similar logic for triggering the reloading of
a whole context?

I'm not sure it's happened to me in quite a while (I'm currently on
8.5.x), but in the past I know for a fact that I've been caught in a
loop where my context will reload many many times after what feels
like one single change (e.g. one set of class file updates, a new .jar
file, etc.). Usually, if I leave things alone for a while (maybe 2
minutes?) Tomcat will settle down and stop repeatedly reloading the
context, but I usually just kill it and restart the container because
all that reloading causes the service to perform really poorly. After
a restart, all is well.

Thanks,
- -chris
-----BEGIN PGP SIGNATURE-----
Comment: Using GnuPG with Thunderbird - https://www.enigmail.net/

iQIzBAEBCAAdFiEEMmKgYcQvxMe7tcJcHPApP6U8pFgFAl3EJR0ACgkQHPApP6U8
pFhjPg/+IhLbsElRysCanRnFKZ6JPMEFs2oPHLwWJxxBGunPQZ2k7fpm6b8q7RUE
ChLhwQifzgNRWuM76mB3lMqcv767jZ0mHCWTIcr1kzb+90QSBxVWziSWH9r7V9zj
+eCIu3Z2Oh+1vL5Yp1D3M7GzmNONx9TztuijiQXZnKQMEvBwfu5Y/r3kbOswLHFu
BOdWSwuxyzpkTBIB6wKxZnaSCWT1AO3/9VIzK5zxWBDikj6m7s85m9U7rP9zYg7g
EZKe87pNFGmI1w2kxAb9ghBMHHzYh/vjljFp+dEA+liNrgAa8g9Y7lDTP9fizC5z
C9Cjw++JGEFSZ8jMdkSbMMk5dbio0K36AgWakuUGKCPtRVMBOmIVtjgprwpxBQ8w
uyG8WczjKDmFgUSQHqFxE7geH73YoRj66xAdtqQRg9QaI8sn00vENvFSbV0m76nT
yTx8BBrIaCtPAjXkGQ9ve2uECgils3slkUhScx0aRAGOBRuDC9fTXyKoCmSy5RTm
BhjLcoRlp9pO1HPtpz6SQJW1gyMuag8LoArb2Dw/XRDNjzKhjSqU6qgqfDIiS2UL
xeDX9KRP3yJP76RDYNS1r6ty6YTZ4V2yk7Bmhe1xyVahWaLszPRZjCaar0mp85/I
kGpt5CY45UXKPXGKCCvNHLs6MQLIAMIl5mPSBF5cnSa8qf8bDOg=
=a7/B
-----END PGP SIGNATURE-----

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: Intermittent JSP Caching/Compiling Issue while under load

Tim K
In reply to this post by markt
On Thu, Nov 7, 2019, 6:40 AM Mark Thomas <[hidden email]> wrote:

> On 06/11/2019 20:04, Mark Thomas wrote:
> > I've found the root cause.
> >
> > When checking the timestamps of JSPs, the JSP engine (because it has to
> > access all resources via the Servlet API) requests a URL for the JSP,
> > opens a connection to the URL and then checks the last modified time.
> > This goes directly to the on-disk file.
> >
> > When reading the content, the request goes via the static resource cache
> > because we can intercept the call to ServletContext.getResourceAsStream()
> >
> > The problem is the following sequence:
> > - request for JSP
> >   - no change in JSP timestamp found
> >   - cache re-validated (for 5s by default)
> > - JSP is modified (within 5s)
> > - request for JSP (within 5s)
> >   - change in JSP timestamp found
> >   - JSP content read (sees cached version rather than new version)
> >
> > So we end up with the old version of the JSP content with the updated
> > last modification time.
> >
> > I'm currently looking at options to return a URL for the resource where
> > we can intercept the call to URLConnection.getLastModified().
>
> Fixed in:
> - master for 9.0.28 onwards
> - 8.5.x for 8.5.48 onwards
>
> Mark
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [hidden email]
> For additional commands, e-mail: [hidden email]


I pulled the latest code from GitHub, I see the commit related to this
email thread in the log, I built from master with ant (9.0.28-dev) and I'm
still experiencing the issue... I have a curl command executing every
second (via watch -n1) going to a JSP while making an edit to it.  I can
reproduce the cached issue every 2-3 edits.
12