difficulties with resources plugins in production

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

difficulties with resources plugins in production

micahcraig
Hi,

I recently set up bundled resources for my application using the resources, cached-resources, and zipped-resources plugins.  Everything seemed to work fine in development, and when deployed to Tomcat/mod_jk/Apache for low volume QA testing.  Things continued to look good initially after promoting the build to production, but after some time in deployment under modest load, problems began to crop up.

Essentially, it appeared that my pages were being delivered without all their <link> and <script> tags.  More specifically, it appeared that my first call to <r:layoutResources/> was no longer producing any output in the page, and so my "disposition:'head'" were no longer being referenced in the page.

Restarting my app server repaired the problem, but only temporarily.  It re-occurred several hours later.  At that point I had to role out an emergency fix build with all of the resource plugins removed and my original <link> and <script> tags restored to my layouts.


Obviously, this is a tricky issue to debug, since it only seems to happen after time and under load, and the only environment in which I've observed the issue is actively serving production data, so cannot be kept in a less than fully operational state.  My question is whether or not anyone else has seen any similar behavior with the Resources plugin, or knows of any reason why I might be seeing this behavior in my app?  I'm sure I might have done something wrong in the configuration, though I'm not sure why a problem with configuration wouldn't show up right away, instead of hours later.  It might also have to do somehow with my Apache or mod_jk configurations, which had previously been setup to serve static resources directly from the web server, without needing to bother the app server for them.

So, any suggestions on how I might proceed on this would be hugely appreciated.  I'm sorry for the general vagueness of my descriptions: I had to roll back the configuration in some haste once we started seeing problems in production, and that was a couple weeks and several fires ago.  Happy to provide any details that might be helpful in getting to the bottom of this.  Thanks,

  -micah
Reply | Threaded
Open this post in threaded view
|

Re: difficulties with resources plugins in production

Marc Palmer

On 5 Apr 2011, at 23:59, micahcraig [via Grails Plugins] wrote:

> Hi,
>
> I recently set up bundled resources for my application using the resources, cached-resources, and zipped-resources plugins.  Everything seemed to work fine in development, and when deployed to Tomcat/mod_jk/Apache for low volume QA testing.  Things continued to look good initially after promoting the build to production, but after some time in deployment under modest load, problems began to crop up.
>
> Essentially, it appeared that my pages were being delivered without all their <link> and <script> tags.  More specifically, it appeared that my first call to <r:layoutResources/> was no longer producing any output in the page, and so my "disposition:'head'" were no longer being referenced in the page.
>
> Restarting my app server repaired the problem, but only temporarily.  It re-occurred several hours later.  At that point I had to role out an emergency fix build with all of the resource plugins removed and my original <link> and <script> tags restored to my layouts.
>
>
> Obviously, this is a tricky issue to debug, since it only seems to happen after time and under load, and the only environment in which I've observed the issue is actively serving production data, so cannot be kept in a less than fully operational state.  My question is whether or not anyone else has seen any similar behavior with the Resources plugin, or knows of any reason why I might be seeing this behavior in my app?  I'm sure I might have done something wrong in the configuration, though I'm not sure why a problem with configuration wouldn't show up right away, instead of hours later.  It might also have to do somehow with my Apache or mod_jk configurations, which had previously been setup to serve static resources directly from the web server, without needing to bother the app server for them.
>
> So, any suggestions on how I might proceed on this would be hugely appreciated.  I'm sorry for the general vagueness of my descriptions: I had to roll back the configuration in some haste once we started seeing problems in production, and that was a couple weeks and several fires ago.  Happy to provide any details that might be helpful in getting to the bottom of this.  Thanks,

Hi Micah,

Can you give a few more details such as:

- How are you running your app - as a WAR I presume?
- What version of resources plugin are you using
- What version of grails are you using.

I can't see why this would happen at the moment. If the resource data gets "lost" (could only happen with a resource service reload) you would get errors about missing modules.


~ ~ ~
Marc Palmer
Freelancer (Grails/Groovy/Java)

Founder of   > http://noticelocal.com
Developer of > http://weceem.org
Twitter      > http://twitter.com/wangjammer5
Resumé       > http://www.anyware.co.uk/marc/
Blog         > http://www.anyware.co.uk
Grails Rocks > http://www.grailsrocks.com

Reply | Threaded
Open this post in threaded view
|

Re: difficulties with resources plugins in production

micahcraig
Hi Marc,

I've done a bit more investigation of my logs, which may or may not help shed some light on the situation.

I am deployed as a WAR, running Grails 1.3.6.  Plugin versions as follows:
  plugins.resources=1.0-RC1b
  plugins.zipped-resources=1.0-RC1
  plugins.cached-resources=1.0-alpha6

In my logs, I see some errors of the form:

2011-03-22 12:05:20,303 [TP-Processor25] ERROR resource.ResourceService  - Resource not found: /images/demo when preparing resource <org.grails.plugin.resource.ResourceMeta@15f63d35 id=null module=org.grails.plugin.resource.ResourceModule@73df2a56 workDir=<TOMCAT HOME>/work/Catalina/localhost/_/grails-resources originalUrl=/images/demo sourceUrl=/images/demo sourceUrlExtension=null queryParams=null actualUrl=null linkOverride=null bundle=null contentType=null disposition=null delegate=null processedFile=null originalLastMod=0 attributes=[:] tagAttributes=[:] prePostWrapper=null requestProcessors=[] _linkUrl=null>

(My excuse, err, explanation for this is that previous to it's current incarnation as a Grails apps, we hosted a more traditionally content oriented site on the same domain. We still field some traffic from spiders looking for resources located at locations that the content site referred to them at, despite having served 302 redirects on the content pages for nearly a year.)

Somewhat more troublingly, I see some errors in my logs such as:
2011-03-24 06:31:35,961 [TP-Processor27] ERROR resource.ResourceService  - Resource not found: /sq7houttaasvdyojkfkba0zthhpb3yc3p8fgqgfp65f.js when preparing resource <org.grails.plugin.resource.ResourceMeta@4316d50a id=null module=org.grails.plugin.resource.ResourceModule@4c93d828 workDir=<TOMCAT HOME>/work/Catalina/localhost/_/grails-resources originalUrl=/sq7houttaasvdyojkfkba0zthhpb3yc3p8fgqgfp65f.js sourceUrl=/sq7houttaasvdyojkfkba0zthhpb3yc3p8fgqgfp65f.js sourceUrlExtension=js queryParams=null actualUrl=null linkOverride=null bundle=null contentType=null disposition=null delegate=null processedFile=null originalLastMod=0 attributes=[:] tagAttributes=[:] prePostWrapper=null requestProcessors=[] _linkUrl=null>

This at least looks as though it's a legitimate reference from the <r:layoutResources/> tag.

Finally, and only once, almost immediately after my last attempt at a server restart and before the deployment of my rolled back build, I have:
2011-03-24 16:58:48,284 [TP-Processor2] ERROR resource.ResourceService  - Resource not found: /11qQx9lxabD3oLDCoOHHkHKBfyvlYqWHkHhzwZQ6kga.css when preparing resource <org.grails.plugin.resource.ResourceMeta@2d54ba39 id=null module=org.grails.plugin.resource.ResourceModule@2090af77 workDir=<TOMCAT HOME>/work/Catalina/localhost/_/grails-resources originalUrl=/11qQx9lxabD3oLDCoOHHkHKBfyvlYqWHkHhzwZQ6kga.css sourceUrl=/11qQx9lxabD3oLDCoOHHkHKBfyvlYqWHkHhzwZQ6kga.css sourceUrlExtension=css queryParams=null actualUrl=null linkOverride=null bundle=null contentType=null disposition=null delegate=null processedFile=null originalLastMod=0 attributes=[:] tagAttributes=[:] prePostWrapper=null requestProcessors=[] _linkUrl=null>
2011-03-24 16:58:48,349 [TP-Processor2] ERROR errors.GrailsExceptionResolver  - Exception occurred when processing request: [GET] /user/activity/2 - parameters:
activityId: 59
Stacktrace follows:
org.codehaus.groovy.grails.web.taglib.exceptions.GrailsTagException: Error executing tag <r:layoutResources>: java.io.FileNotFoundException: Cannot locate resource [/11qQx9lxabD3oLDCoOHHkHKBfyvlYqWHkHhzwZQ6kga.css] at /WEB-INF/grails-app/views/layouts/main.gsp:8
        at gsp_sowo_layoutsmain_gsp$_run_closure1.doCall(gsp_sowo_layoutsmain_gsp.groovy:28)
        at gsp_sowo_layoutsmain_gsp$_run_closure1.doCall(gsp_sowo_layoutsmain_gsp.groovy)
        at gsp_sowo_layoutsmain_gsp.run(gsp_sowo_layoutsmain_gsp.groovy:37)
        at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190)
        at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:291)
        at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:769)
        at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:698)
        at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:891)
        at java.lang.Thread.run(Thread.java:619)
Caused by: org.codehaus.groovy.runtime.InvokerInvocationException: java.io.FileNotFoundException: Cannot locate resource [/11qQx9lxabD3oLDCoOHHkHKBfyvlYqWHkHhzwZQ6kga.css]
        ... 9 more
Caused by: java.io.FileNotFoundException: Cannot locate resource [/11qQx9lxabD3oLDCoOHHkHKBfyvlYqWHkHhzwZQ6kga.css]
        at org.grails.plugin.resource.ResourceService.prepareResource(ResourceService.groovy:380)
        at org.grails.plugin.resource.ResourceService$prepareResource.callCurrent(Unknown Source)
        at org.grails.plugin.resource.ResourceService.getResourceMetaForURI(ResourceService.groovy:295)
        at org.grails.plugin.resource.ResourceService$getResourceMetaForURI.call(Unknown Source)
        at org.grails.plugin.resource.ResourceTagLib.resolveResourceAndURI(ResourceTagLib.groovy:397)
        at org.grails.plugin.resource.ResourceTagLib$_closure1.doCall(ResourceTagLib.groovy:168)
        at org.grails.plugin.resource.ResourceTagLib$_closure5_closure17.doCall(ResourceTagLib.groovy:346)
        at org.grails.plugin.resource.ResourceTagLib$_closure5.doCall(ResourceTagLib.groovy:330)
        at org.grails.plugin.resource.ResourceTagLib.invokeMethod(ResourceTagLib.groovy)
        at org.grails.plugin.resource.ResourceTagLib$_closure3_closure14.doCall(ResourceTagLib.groovy:240)
        at org.grails.plugin.resource.ResourceTagLib$_closure3.doCall(ResourceTagLib.groovy:239)
        ... 9 more

The only other activity I noticed in the log from the plugin is the full reload INFO message immediately upon server startup.

I wouldn't entirely discount the possibility that files could be disappearing from my file system, though I'd be hard pressed to offer an explanation as to exactly why.  But just presuming that were the case, would it explain why the tags no were longer being written into the page output?

Thanks for your help.

  -micah

Marc Palmer wrote
[snip]

- How are you running your app - as a WAR I presume?
- What version of resources plugin are you using
- What version of grails are you using.

I can't see why this would happen at the moment. If the resource data gets "lost" (could only happen with a resource service reload) you would get errors about missing modules.
Reply | Threaded
Open this post in threaded view
|

Re: difficulties with resources plugins in production

Marc Palmer
Hi Micah,

I just releases resources 1.0-RC2, can you please try that version.

I'm still pretty without clue here except... is it possible your temp dir (where the static resources are being stored after processing) on your server is being wiped periodically?

You can specify the location of the work files with grails.resources.work.dir - you should specify a reliable location for this.

Marc

~ ~ ~
Marc Palmer
Freelancer (Grails/Groovy/Java)

Founder of   > http://noticelocal.com
Developer of > http://weceem.org
Twitter      > http://twitter.com/wangjammer5
Resumé       > http://www.anyware.co.uk/marc/
Blog         > http://www.anyware.co.uk
Grails Rocks > http://www.grailsrocks.com

Reply | Threaded
Open this post in threaded view
|

Re: difficulties with resources plugins in production

micahcraig
Hi Marc,

I've re-integrated the resources plugin on version 1.0-RC2 and added a runtime kill switch so I can revert my configuration without redeploying if I start to see problems again.  I should be promoting that change to production today or Monday, so I'll let you know what I see.


I do have some reason to be suspicious of the reliability of this file system, but that's mostly based on supposition and superstition.  I'm going to have inotifywait log delete events in the work directory, which will at least tell me exactly when files are being removed, if they're being removed.


Thanks again for your help.  I'll report back when I have more information.


  -micah
Reply | Threaded
Open this post in threaded view
|

Re: difficulties with resources plugins in production

Marc Palmer

On 8 Apr 2011, at 18:10, micahcraig [via Grails Plugins] wrote:

> Hi Marc,
>
> I've re-integrated the resources plugin on version 1.0-RC2 and added a runtime kill switch so I can revert my configuration without redeploying if I start to see problems again.  I should be promoting that change to production today or Monday, so I'll let you know what I see.
>
>
> I do have some reason to be suspicious of the reliability of this file system, but that's mostly based on supposition and superstition.  I'm going to have inotifywait log delete events in the work directory, which will at least tell me exactly when files are being removed, if they're being removed.
>
>
> Thanks again for your help.  I'll report back when I have more information.
>

FWIW, I added an SMTP log appender to my production system (for errors) and that is showing some similar failures every now and again. However I don't know why yet. It looks like a possible concurrency issue, but I cannot reproduce it locally yet.

Marc

~ ~ ~
Marc Palmer
Freelancer (Grails/Groovy/Java)

Founder of   > http://noticelocal.com
Developer of > http://weceem.org
Twitter      > http://twitter.com/wangjammer5
Resumé       > http://www.anyware.co.uk/marc/
Blog         > http://www.anyware.co.uk
Grails Rocks > http://www.grailsrocks.com

Reply | Threaded
Open this post in threaded view
|

Re: difficulties with resources plugins in production

micahcraig
Quick update:
I've had RC2 in production since Monday, though receiving somewhat less traffic than the last time.  I've not seen the sort of total failure that I did last time.  I do have evidence of some files being deleted from inside the grails-resources work directory, though they seem to have been recreated by the time I check on them.  I can't find any correlation in my server logs to the times when the files were deleted.  The one bit of evidence I can derive from the deletion log is that the deletions often happen in sets of files at the same time, when they happen.  eg:

13/04/11 09:38:48 apache-tomcat-6.0.26/work/Catalina/localhost/_/grails-resources/css/ admin.css.tmp-DELETE
13/04/11 09:38:48 apache-tomcat-6.0.26/work/Catalina/localhost/_/grails-resources/ 4sYb3BukJyzoFcWgzTTkmDjz0tKAmc4rvRYjYBwoAEd.css-DELETE
13/04/11 09:38:48 apache-tomcat-6.0.26/work/Catalina/localhost/_/grails-resources/ 4sYb3BukJyzoFcWgzTTkmDjz0tKAmc4rvRYjYBwoAEd.css.tmp-DELETE

So, not sure. Is RC2 failing safer than RC1?

  -micah
Reply | Threaded
Open this post in threaded view
|

Re: difficulties with resources plugins in production

Marc Palmer

On 13 Apr 2011, at 16:05, micahcraig [via Grails Plugins] wrote:

> Quick update:
> I've had RC2 in production since Monday, though receiving somewhat less traffic than the last time.  I've not seen the sort of total failure that I did last time.  I do have evidence of some files being deleted from inside the grails-resources work directory, though they seem to have been recreated by the time I check on them.  I can't find any correlation in my server logs to the times when the files were deleted.  The one bit of evidence I can derive from the deletion log is that the deletions often happen in sets of files at the same time, when they happen.  eg:
>
> 13/04/11 09:38:48 apache-tomcat-6.0.26/work/Catalina/localhost/_/grails-resources/css/ admin.css.tmp-DELETE
> 13/04/11 09:38:48 apache-tomcat-6.0.26/work/Catalina/localhost/_/grails-resources/ 4sYb3BukJyzoFcWgzTTkmDjz0tKAmc4rvRYjYBwoAEd.css-DELETE
> 13/04/11 09:38:48 apache-tomcat-6.0.26/work/Catalina/localhost/_/grails-resources/ 4sYb3BukJyzoFcWgzTTkmDjz0tKAmc4rvRYjYBwoAEd.css.tmp-DELETE
>
> So, not sure. Is RC2 failing safer than RC1?

What is deleting those files? It looks like Tomcat is. Resources only deletes files when initially processing and never renames them like that.

Configure resources with grails.resources.work.dir to use a folder outside of your webapp and this will not happen.

Marc



~ ~ ~
Marc Palmer
Freelancer (Grails/Groovy/Java)

Founder of   > http://noticelocal.com
Developer of > http://weceem.org
Twitter      > http://twitter.com/wangjammer5
Resumé       > http://www.anyware.co.uk/marc/
Blog         > http://www.anyware.co.uk
Grails Rocks > http://www.grailsrocks.com

Reply | Threaded
Open this post in threaded view
|

Re: difficulties with resources plugins in production

Marc Palmer
In reply to this post by micahcraig

On 13 Apr 2011, at 16:05, micahcraig [via Grails Plugins] wrote:

> Quick update:
> I've had RC2 in production since Monday, though receiving somewhat less traffic than the last time.  I've not seen the sort of total failure that I did last time.  I do have evidence of some files being deleted from inside the grails-resources work directory, though they seem to have been recreated by the time I check on them.  I can't find any correlation in my server logs to the times when the files were deleted.  The one bit of evidence I can derive from the deletion log is that the deletions often happen in sets of files at the same time, when they happen.  eg:
>
> 13/04/11 09:38:48 apache-tomcat-6.0.26/work/Catalina/localhost/_/grails-resources/css/ admin.css.tmp-DELETE
> 13/04/11 09:38:48 apache-tomcat-6.0.26/work/Catalina/localhost/_/grails-resources/ 4sYb3BukJyzoFcWgzTTkmDjz0tKAmc4rvRYjYBwoAEd.css-DELETE
> 13/04/11 09:38:48 apache-tomcat-6.0.26/work/Catalina/localhost/_/grails-resources/ 4sYb3BukJyzoFcWgzTTkmDjz0tKAmc4rvRYjYBwoAEd.css.tmp-DELETE
>
> So, not sure. Is RC2 failing safer than RC1?
>

A quick thought.

The only reason I can think that Tomcat would think it safe to delete those tempfiles is if tomcat is restarted / the app stopped and started.

I imagine that is causing your problem. Again, grails.resources.work.dir will fix that for you.

Marc


Reply | Threaded
Open this post in threaded view
|

Re: difficulties with resources plugins in production

nardhar
Hey, same problem here, i added grails.resources.work.dir = "another-dir" in BuildConfig.groovy and created "another-dir" outside web-app and the problem is still there

I'm kinda newbie in grails so maybe i'm just doing something wrong.

Oh, almost forgot, i'm using grails 1.3.6, lesscss-resources-0.1, resources-1.0-RC2; trying to deploy on jBoss 6

Thx in advance

Nardhar

Reply | Threaded
Open this post in threaded view
|

Re: difficulties with resources plugins in production

Marc Palmer

On 13 Apr 2011, at 17:22, Nardhar [via Grails Plugins] wrote:

> Hey, same problem here, i added grails.resources.work.dir = "another-dir" in BuildConfig.groovy and created "another-dir" outside web-app and the problem is still there
>
> I'm kinda newbie in grails so maybe i'm just doing something wrong.
>
> Oh, almost forgot, i'm using grails 1.3.6, lesscss-resources-0.1, resources-1.0-RC2; trying to deploy on jBoss 6

Can you confirm where your files are being written? i.e. find them on the filesystem?

I have a hard time believing Resources is deleting the files - there are a couple of different issues we're seeing, and deleting I think is only one of them.

Marc

Reply | Threaded
Open this post in threaded view
|

Re: difficulties with resources plugins in production

nardhar
Well, i'm using grails war and inside there is not the "another-dir" dir, trying to create the dir on JBoss6\server\default\deploy and nothing there, maybe i'm creating the dir somewhere else.

One thing else, in development i find the bundle_style.css file (in the grails-resources dir), but in the generated war there seems to be no such file (only the .less file)
Reply | Threaded
Open this post in threaded view
|

Re: difficulties with resources plugins in production

micahcraig
In reply to this post by Marc Palmer
Marc,

I am concerned with what is causing these file deletions, but I strongly suspect that whatever is causing it is specific to my environment and/or configuration.  However, my primary concern is how the Resource plugin behaves when the file system is not in the expected state.  At the moment, it seems to be smoothly recovering (regenerating?) when it finds missing files, but in my initial production deployment on RC1 it seemed as though it was not recovering.

Generally, the Resource plugin seems to be relatively unforgiving of things like files referenced in CSS that don't actually exist and unexpected conditions on the file system.  I appreciate the strictness in that it helps me identify what could be real problems in my application, but usually I'd expect these things to be warnings, not errors, and for them to generally not impact un-related operations.

  -micah

ps. I know what a bear concurrent file access is to handle, so I really appreciate the plugin taking on the heavy lifting on this stuff.
Reply | Threaded
Open this post in threaded view
|

Re: difficulties with resources plugins in production

Marc Palmer
In reply to this post by nardhar

On 13 Apr 2011, at 20:24, nardhar [via Grails Plugins] wrote:

> Well, i'm using grails war and inside there is not the "another-dir" dir, trying to create the dir on JBoss6\server\default\deploy and nothing there, maybe i'm creating the dir somewhere else.
>

Find out where JBoss stores application temp files. e.g. in Tomcat it creates folders under <tomcat>/work-dir/

> One thing else, in development i find the bundle_style.css file (in the grails-resources dir), but in the generated war there seems to be no such file (only the .less file)

This is because the files are processed at runtime, and stored in a temporary directory (if you do not set grails.resources.work.dir) provided by your servlet container.

Set this config variable to a trusted writable and permanent file location.

Resources cannot work if this folder or files in it is destroyed while the app is running.

Marc

~ ~ ~
Marc Palmer
Freelancer (Grails/Groovy/Java)

Founder of   > http://noticelocal.com
Developer of > http://weceem.org
Twitter      > http://twitter.com/wangjammer5
Resumé       > http://www.anyware.co.uk/marc/
Blog         > http://www.anyware.co.uk
Grails Rocks > http://www.grailsrocks.com

Reply | Threaded
Open this post in threaded view
|

Re: difficulties with resources plugins in production

Marc Palmer
In reply to this post by micahcraig

On 13 Apr 2011, at 20:26, micahcraig [via Grails Plugins] wrote:

> Marc,
>
> I am concerned with what is causing these file deletions, but I strongly suspect that whatever is causing it is specific to my environment and/or configuration.  However, my primary concern is how the Resource plugin behaves when the file system is not in the expected state.  At the moment, it seems to be smoothly recovering (regenerating?) when it finds missing files, but in my initial production deployment on RC1 it seemed as though it was not recovering.
>
> Generally, the Resource plugin seems to be relatively unforgiving of things like files referenced in CSS that don't actually exist and unexpected conditions on the file system.  I appreciate the strictness in that it helps me identify what could be real problems in my application, but usually I'd expect these things to be warnings, not errors, and for them to generally not impact un-related operations.
>
>   -micah
>
> ps. I know what a bear concurrent file access is to handle, so I really appreciate the plugin taking on the heavy lifting on this stuff.

I don't think missing files are causing the problem. I'm seeing 404s come for static resource URIs, which when I check the URI, the document is there, so something is up in certain cases.

It should not regenerate files after startup even if they are deleted, because it has internal memory structures that indicate if it has already done this work. Only "ad hoc" resources (those not declared in the DSL) are processed after initial startup.

I'm guessing that something here is coming into play - I do believe you guys are seeing temp files being deleted because you haven't set grails.resources.work.dir - you *must* do this.

I think there may then be a lingering issue with concurrent requests for previously unrequested ad hoc resources, which fail first time and then succeed. This is a guess.

I haven't found a way to reproduce this problem locally yet, though I am seeing it myself in production - but I have never seen the site fail to load a resource in my browser.

~ ~ ~
Marc Palmer
Freelancer (Grails/Groovy/Java)

Founder of   > http://noticelocal.com
Developer of > http://weceem.org
Twitter      > http://twitter.com/wangjammer5
Resumé       > http://www.anyware.co.uk/marc/
Blog         > http://www.anyware.co.uk
Grails Rocks > http://www.grailsrocks.com