ResourceWatcher should allow check for changes asynchronously

[GoogleCodeExporter]

When working with large number of resources and resourceWatcher is enabled, it 
can take a not negligible time to compute the checksum, which causes the actual 
processing to be blocked. 

This can be improved, by invoking the checksum computation (check for changes) 
in an separate thread, making it asynchronous.

Original issue reported on code.google.com by alex.obj...@gmail.com on 3 Dec 2013 at 10:31

[GoogleCodeExporter]

Unfortunatelly there is a problem which prevents the checksum to be checked 
asynchronously. The problem is that during checksum, the Context is required 
(the object holding informations about current request). When computing 
checksum outside of the request cycle, the request is not available anymore and 
locators cannot perform its job properly. This is a limitation which probably 
could be avoided in the future by changing the way Context class implementation.

In the meantime, I think there is an alternative solution: invoking an http 
call asynchronously to an endpoint responsible for executing the checksum 
computation. This could be implemented using a RequestHandler. I will continue 
investigating this issue and hopefully will have a working solution soon.

Original comment by alex.obj...@gmail.com on 13 Dec 2013 at 10:10

[GoogleCodeExporter]

My apologies for nagging, but I have to do it... I'm getting a bit of pressure 
at my 9 to 5 about this issue. Do you have any sense as to when it may be 
addressed?

Thank you again!

Original comment by candrews...@gmail.com on 9 Jan 2014 at 4:53

[GoogleCodeExporter]

I'm working on it. This is the last issue I'm addressing before releasing
next version. Probably on end of this week or beginning of the next week
will be ready.

check for changes asynchronously

pressure at my 9 to 5 about this issue. Do you have any sense as to when it
may be addressed?

Original comment by alex.obj...@gmail.com on 9 Jan 2014 at 5:18

[GoogleCodeExporter]

Fixed in branch 1.7.x. 
@candrews could you build it locally and test in your environment? It would 
help some additional sanity check before releasing.

Original comment by alex.obj...@gmail.com on 13 Jan 2014 at 4:11

[GoogleCodeExporter]

Original comment by alex.obj...@gmail.com on 13 Jan 2014 at 4:12

• Changed state: Fixed

[GoogleCodeExporter]

@alex.objelean can you publish a snapshot to the snapshot repository at 
https://oss.sonatype.org/content/repositories/snapshots/ (or anywhere else)? 
(We can make Travis do that for us pretty easily too, I think)

Original comment by candrews...@gmail.com on 13 Jan 2014 at 8:22

[GoogleCodeExporter]

I just started the deploy of the 1.7.3-SNAPSHOT artifact on snapshot 
repository. It should be available soon. Let me know if you have any questions 
or feedback.

An important note regarding this issue: async check is disabled by default. To 
enable it, you have to add the following configuration:

resourceWatcherAsync=true

Original comment by alex.obj...@gmail.com on 13 Jan 2014 at 10:16

[GoogleCodeExporter]

I've committed the bump to 1.7.3-SNAPSHOT and set resourceWatcherAsync=true in 
my project, and it's being tested now. So far, so good...

BTW - can you update the wro4j .travis.yml to publish snapshots to Sonatype on 
a continuous basis?

Original comment by candrews...@gmail.com on 14 Jan 2014 at 9:27

[GoogleCodeExporter]

Yes, I could do that. 
If you don't find any issue with this feature, I'm ready to release 1.7.3.

Original comment by alex.obj...@gmail.com on 14 Jan 2014 at 9:31

[GoogleCodeExporter]

Can you release it tomorrow afternoon? I'd like to get in a few more hours of 
testing in if that's alright :)

Original comment by candrews...@gmail.com on 14 Jan 2014 at 9:34

[GoogleCodeExporter]

Sure, no problem. Just let me know when you have any feedback.

Original comment by alex.obj...@gmail.com on 14 Jan 2014 at 9:36

[GoogleCodeExporter]

Original comment by alex.obj...@gmail.com on 14 Jan 2014 at 10:09

• Changed title: ResourceWatcher should allow check for changes asynchronously

[GoogleCodeExporter]

I'm getting this error. I don't think I was getting it yesterday... so perhaps 
it's related to the new snapshots you're now publishing?

| Error 2014-01-15 17:52:55,714 
[wro4j-ro.isdc.wro.model.resource.support.change.ResourceWatcher-1-thread-1] 
ERROR change.ResourceWatcher  - Could not check the following cacheKey: 
ro.isdc.wro.cache.CacheKey@1d6b4bce[
  type=JS
  groupName=corelib
  minimize=true
  map={}
]
Message: Read timed out
    Line | Method
->>  150 | read           in java.net.SocketInputStream
- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - 
|    121 | read           in     ''
|    235 | fill . . . . . in java.io.BufferedInputStream
|    275 | read1          in     ''
|    334 | read . . . . . in     ''
|     83 | locate         in ro.isdc.wro.model.resource.locator.UrlUriLocator
|    119 | locateExternal in 
ro.isdc.wro.model.resource.locator.support.DispatcherStreamLocator
|     89 | getInputStream in     ''
|    143 | check . . . .  in 
ro.isdc.wro.http.handler.ResourceWatcherRequestHandler
|    148 | run            in 
ro.isdc.wro.model.resource.support.change.ResourceWatcher$2
|     34 | call . . . . . in 
ro.isdc.wro.config.support.ContextPropagatingCallable$1
|     31 | call           in     ''
|     58 | call . . . . . in 
ro.isdc.wro.config.support.ContextPropagatingCallable
|    334 | innerRun       in java.util.concurrent.FutureTask$Sync
|    166 | run . . . . .  in java.util.concurrent.FutureTask
|   1110 | runWorker      in java.util.concurrent.ThreadPoolExecutor
|    603 | run . . . . .  in java.util.concurrent.ThreadPoolExecutor$Worker
^    722 | run            in java.lang.Thread
| Error 2014-01-15 17:52:55,716 
[wro4j-ro.isdc.wro.model.resource.support.change.ResourceWatcher-1-thread-1] 
ERROR [/].[default]  - Servlet.service() for servlet default threw exception
Message: The requested resource (/grails/exceptions/wroAPI/resourceWatcher) is 
not available
    Line | Method
->>   77 | getInputStream in 
ro.isdc.wro.model.resource.locator.support.DispatcherStreamLocator
- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - 
|    143 | check          in 
ro.isdc.wro.http.handler.ResourceWatcherRequestHandler
|    148 | run . . . . .  in 
ro.isdc.wro.model.resource.support.change.ResourceWatcher$2
|     34 | call           in 
ro.isdc.wro.config.support.ContextPropagatingCallable$1
|     31 | call . . . . . in     ''
|     58 | call           in 
ro.isdc.wro.config.support.ContextPropagatingCallable
|    334 | innerRun . . . in java.util.concurrent.FutureTask$Sync
|    166 | run            in java.util.concurrent.FutureTask
|   1110 | runWorker . .  in java.util.concurrent.ThreadPoolExecutor
|    603 | run            in java.util.concurrent.ThreadPoolExecutor$Worker
^    722 | run . . . . .  in java.lang.Thread

Original comment by candrews...@gmail.com on 15 Jan 2014 at 11:25

[GoogleCodeExporter]

Actually there was no new snapshot deployed on sonatype (I get unauthorized 
error on travis). So the problem is something else. 

Could you provide more details? 
I see the following url being invoked 
"/grails/exceptions/wroAPI/resourceWatcher".
What exactly the "/grails/exceptions/" is used for? I'm trying to understand 
what is different for this test-case comparing to other which worked.

Thanks,
Alex

Original comment by alex.obj...@gmail.com on 16 Jan 2014 at 6:52

[GoogleCodeExporter]

I'm not sure - I set a breakpoint at ResourceWatcherRequestHandler:143, and I 
found that request.requestURI is "/grails/exceptions/error404.dispatch" so 
location comes out to 
"/grails/exceptions/wroAPI/resourceWatcher?group=ie8&resourceType=JS&auth=null"

I'm trying to trace back why the request URI is getting set that way, but I'm 
having a bit of trouble figuring out how the request gets set in the Context... 
I'm going to keep looking.

Original comment by candrews...@gmail.com on 16 Jan 2014 at 4:42

[GoogleCodeExporter]

I have a couple of changes which will be pushed soon. But the idea is that the 
ResourceWatcher creates a server-side request to an url exposed by wro4j which 
asynchronously triggers the resourceWatcher. 

The problem is that there is a timeout configured for this operation. As long 
as resourceWatch operation tooks longer than X seconds (2 by default), you'll 
get that error. One of the possible solution is to increase the 
connectionTimeout property to a bigger number.

Original comment by alex.obj...@gmail.com on 16 Jan 2014 at 4:48

[GoogleCodeExporter]

I'm curious, how long does the resourceWatch operation takes in your case? 
Also, how is the WroFilter mapped in web.xml?

Original comment by alex.obj...@gmail.com on 16 Jan 2014 at 4:49

[GoogleCodeExporter]

The filter configuration looks like this:
    <filter>
        <filter-name>wroFilter</filter-name>
        <filter-class>org.springframework.web.filter.DelegatingFilterProxy</filter-class>
        <init-param>
            <param-name>targetFilterLifecycle</param-name>
            <param-value>true</param-value>
        </init-param>
    </filter>
    <filter>
        <filter-name>wroContextFilter</filter-name>
        <filter-class>ro.isdc.wro.http.WroContextFilter</filter-class>
    </filter>
    <filter-mapping>
        <filter-name>wroFilter</filter-name>
        <url-pattern>/assets/wro/*</url-pattern>
        <dispatcher>REQUEST</dispatcher>
        <dispatcher>FORWARD</dispatcher>
        <dispatcher>ERROR</dispatcher>
    </filter-mapping>
    <filter-mapping>
        <filter-name>wroFilter</filter-name>
        <url-pattern>/wro/*</url-pattern>
        <dispatcher>REQUEST</dispatcher>
        <dispatcher>FORWARD</dispatcher>
        <dispatcher>ERROR</dispatcher>
    </filter-mapping>
    <filter-mapping>
        <filter-name>wroContextFilter</filter-name>
        <url-pattern>/*</url-pattern>
        <dispatcher>REQUEST</dispatcher>
        <dispatcher>FORWARD</dispatcher>
        <dispatcher>ERROR</dispatcher>
    </filter-mapping>
I dont' believe the problem is a timeout (although that's what's reported); I 
think the problem is that ResourceWatcher is trying to hit the wrong URL. I 
*think* that on ResourceWatcherRequestHandler:143, location should be:
/wro/wroAPI/resourceWatcher?group=corelib&resourceType=JS&auth=null
But it is:
/grails/pages/wroAPI/resourceWatcher?group=corelib&resourceType=JS&auth=null

The /grails/pages is coming from fullPath... I wonder if the logic:
fullPath = FilenameUtils.getFullPath(request.getServletPath());
is wrong?

Original comment by candrews...@gmail.com on 16 Jan 2014 at 5:10

[GoogleCodeExporter]

The url created by ResourceWatcherRequestHandler uses the original requestURL 
to compute the new url. I'm wondering why a request to /grails/exception was 
handled by WroFilter. 

Do you get this exception consistently or only on certain condition?

Original comment by alex.obj...@gmail.com on 16 Jan 2014 at 5:14

[GoogleCodeExporter]

Could you get the latest version from 1.7.x (I'm unable to deploy on nexus
snapshot right now), build it locally and set the timeout to some bigger
value? Let me know how it works.

Original comment by alex.obj...@gmail.com on 16 Jan 2014 at 5:21

[GoogleCodeExporter]

I have just deployed a new snapshot on sonatype repository, so you don't have 
to build the project. Please, let me know if you have anykind of feedback.

Original comment by alex.obj...@gmail.com on 16 Jan 2014 at 6:00

[GoogleCodeExporter]

Thanks for deploying the snapshot - it sure makes life a LOT easier for me!

I'm seeing the same behavior with the new snapshot.

"The url created by ResourceWatcherRequestHandler uses the original requestURL 
to compute the new url. I'm wondering why a request to /grails/exception was 
handled by WroFilter." - My understanding is that WroContextFilter needs to 
handle all requests (so it's mapped to /*). When I set a breakpoint in 
WroFilter, I can see it's never called.

Original comment by candrews...@gmail.com on 16 Jan 2014 at 6:35

[GoogleCodeExporter]

Still, do you see this problem always or only in particular situations?

Original comment by alex.obj...@gmail.com on 16 Jan 2014 at 6:38

[GoogleCodeExporter]

ResourceWatcher:299, location is:
"/grails/pages/wroAPI/resourceWatcher?group=base&resourceType=JS&auth=null"
But it should be:
"/wro/wroAPI/resourceWatcher?group=base&resourceType=JS&auth=null"

right?

Original comment by candrews...@gmail.com on 16 Jan 2014 at 6:42

[GoogleCodeExporter]

As far as I have been able to tell, it always happens.

Original comment by candrews...@gmail.com on 16 Jan 2014 at 6:43

[GoogleCodeExporter]

Yes, but I cannot assume how the WroFilter is mapped. This is why the
original request url is used to compute the resourceWatcher requestHandler
url.  The only question is why the original request url is
/grails/pages...  it might be related to forwarded or included requests,
but I'm not sure yet.
What is the value of resourceWatcherUpdatePeriod?

Original comment by alex.obj...@gmail.com on 16 Jan 2014 at 6:49

[GoogleCodeExporter]

I think I know the root cause of the problem. It is the WroContextFilter.
Are you sure you need it? If not, remove it. Otherwise I will have to apply
a fix before it will work with your config.

Original comment by alex.obj...@gmail.com on 16 Jan 2014 at 7:01

[GoogleCodeExporter]

I'm pretty sure I need it... what would I use instead?

Original comment by candrews...@gmail.com on 16 Jan 2014 at 7:05

[GoogleCodeExporter]

Nothing yet. At this point I can make only assumptions, since I
can'reproduce the problem. It would really help if you could provide a
quick start project.  I will be able to create a new snapshot tomorrow
which could help me log nore useful details.

You didn't answer my question regarding when this issue is reproduced.

Original comment by alex.obj...@gmail.com on 16 Jan 2014 at 7:10

[GoogleCodeExporter]

I don't have a simple test case, but I'll try to make one and upload the 
project demoing this problem. My project is big and complex, and I can't share 
it anyways :-( I know how frustrating not being able to reproduce a problem but 
trying to fix it anyways can be, and I really appreciate your help.

My project does do forward's.

resourceWatcherUpdatePeriod = 5. (Pretty quick, I know... project requirements 
state that JS/CSS update should apply "instantly")

Original comment by candrews...@gmail.com on 16 Jan 2014 at 7:22

[GoogleCodeExporter]

I don't need more than required to reproduce the problem. Probably a simple
project scheleton with web.xml configured should be enough.

Original comment by alex.obj...@gmail.com on 16 Jan 2014 at 7:33

[GoogleCodeExporter]

I'm attaching a Grails project that shows the error.
Get and extract 
http://dist.springframework.org.s3.amazonaws.com/release/GRAILS/grails-2.2.4.zip
Extract the issue822 bug report zip
Run "grails run-app" from the issue 822 bug report directory
Go to http://localhost:8080/issue822/testWro and you'll see the issue

To do this, I started with a base Grails project (created using grails 
create-app), added the wro4j grails plugin, then set:
wro.resourceWatcherAsync = true
wro.resourceWatcherUpdatePeriod = 5
in Config.groovy

Original comment by candrews...@gmail.com on 16 Jan 2014 at 9:29

Attachments:

• issue822-bug-report-16012014.zip

[GoogleCodeExporter]

web.xml that is generated in the aforementioned Grails project.

Original comment by candrews...@gmail.com on 16 Jan 2014 at 9:30

Attachments:

• web.xml

[GoogleCodeExporter]

If you'd rather I reproduced this using some other technology, just attach a 
simple getting-started project that you used for some other wro purpose, and 
I'm sure I can reproduce it there (I think the keys is the use of 
WroContextFilter).

Original comment by candrews...@gmail.com on 16 Jan 2014 at 9:31

[GoogleCodeExporter]

I think I have fixed the problem. I will deploy a snapshot later today and will 
let you know when it is available. Apparently the problem is somehow related to 
the wro tag you are using in your grails application. I didn't manage to find 
out how it is implemented, but I assume it uses the wro4j api when the request 
is not passed through WroFilter.

The fix will allow async check only for wro resources passed through WroFilter. 
This fix has one drawback: if the resourceWatcher check is triggered by a 
request which wasn't passed through WroFilter, it won't perform an async check 
but will fallback to  the sync check. 

Let me know what you think about this solution.

Original comment by alex.obj...@gmail.com on 17 Jan 2014 at 9:16

[GoogleCodeExporter]

The wro tag doesn't use the wro api; it just outputs "/wro/[group].[css|js]". 
You can see the implementation here: 
https://github.com/wro4j/wro4j-grails-plugin/blob/1.7.2/grails-app/taglib/wro4j/
grails/plugin/WroTagLib.groovy

I am eager to try your solution, though!

My application does use the wro API in its tag though (I need to update 
wro4j-grails-plugin to this too, this reminds me I need to get on that). Here's 
how my application does it:

    String wroUrl = { GroovyPageAttributes attrs ->
        boolean absolute = attrs.boolean("absolute", false);
        String group = attrs.group
        if(group == null) throw new IllegalArgumentException("group is required")
        ResourceType type = ResourceType.get(attrs.type);

        WroManager wroManager =
            new ServletContextAttributeHelper(
                ServletContextHolder.getServletContext()
            ).getManagerFactory().create()

        return "${g.resource(dir: '/', absolute: absolute)}/wro/${wroManager.encodeVersionIntoGroupPath(group, type, grailsApplication.config.mfc.wroMinimize)}"
    }

So are you saying that since my page (which runs in WroContextFilter, and not 
WroFilter) does wroManager.encodeVersionIntoGroupPath, the resource checking 
will be done synchronously?

If so, as an alternative, could you make it so if you're not in WroFilter, the 
resource check only happens if the resource has never been checked before (if 
it has ever been checked before, just use the last value)? That approach should 
solve all the problems, I think.

Original comment by candrews...@gmail.com on 17 Jan 2014 at 3:51

[GoogleCodeExporter]

[deleted comment]

[GoogleCodeExporter]

I think it should be possible to avoid the resourceWatch check at all when the 
request doesn't goes through WroFilter. 

I'm not sure if this approach is the best, but it is probably good enough for 
your particular use-case.

Original comment by alex.obj...@gmail.com on 17 Jan 2014 at 4:15

[GoogleCodeExporter]

Ok, the fix is ready in branch 1.7.x. I will deploy it to snapshot later today. 
I will let you know when it is available. 
If you want to test it sooner, just build the snapshot from branch 1.7.x

Original comment by alex.obj...@gmail.com on 17 Jan 2014 at 4:33

[GoogleCodeExporter]

I have deployed the latest version on nexus snapshot repository. Please let me 
know whey you have any feedback.

Original comment by alex.obj...@gmail.com on 17 Jan 2014 at 5:34

[GoogleCodeExporter]

It's a lot better now!

Using my example project from before, when I start the application and hit 
http://localhost:8080/issue822/testWro for the first time, I get this error 
logged:

| Error 2014-01-17 14:00:33,630 
[wro4j-ro.isdc.wro.model.resource.support.change.ResourceWatcher-1-thread-1] 
ERROR [/issue822].[default]  - Servlet.service() for servlet default threw 
exception
Message: The requested resource (/issue822/wro/all.js) is not available
    Line | Method
->>   79 | getInputStream in 
ro.isdc.wro.model.resource.locator.support.DispatcherStreamLocator
- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - 
|    320 | call           in 
ro.isdc.wro.model.resource.support.change.ResourceWatcher$4
|    315 | call . . . . . in     ''
|     60 | call           in 
ro.isdc.wro.config.support.ContextPropagatingCallable
|    334 | innerRun . . . in java.util.concurrent.FutureTask$Sync
|    166 | run            in java.util.concurrent.FutureTask
|   1110 | runWorker . .  in java.util.concurrent.ThreadPoolExecutor
|    603 | run            in java.util.concurrent.ThreadPoolExecutor$Worker
^    722 | run . . . . .  in java.lang.Thread

If I hit the page again (and therefore request 
http://localhost:8080/issue822/wro/all.js again) everything works fine.

Focusing just on the WRO URL of http://localhost:8080/issue822/wro/all.js if I 
repeated hit it, sometimes I get that error logged, sometimes not. I think it 
happens every time the resourceWatcherUpdatePeriod expires.

Original comment by candrews...@gmail.com on 17 Jan 2014 at 7:04

[GoogleCodeExporter]

Is this error critical or it can be ignored until next release? Could you
also post the entire stacktrace?

Original comment by alex.obj...@gmail.com on 17 Jan 2014 at 8:02

[GoogleCodeExporter]

What I posted is the whole stack trace - it happens in its own thread, so it's 
(pleasantly?) short. Is there something else I can get that would be helpful?

It's a pretty big deal to me, cause I really want resourceWatcherAsync=true and 
to be confident it works, and these errors are kinda worrisome. But, you've 
flagged in the docs as "experimental" so IMHO it would be totally fair of you 
to release 1.7.3 with this behavior - I'm just selfishly hoping that you don't 
:)

Original comment by candrews...@gmail.com on 17 Jan 2014 at 8:38

[GoogleCodeExporter]

I have deployed a new snapshot which should fix this issue and the one reported 
in issue831 

Could you take a look and let me know if you find any issues?

Original comment by alex.obj...@gmail.com on 18 Jan 2014 at 4:54

[GoogleCodeExporter]

Issue 831 has been merged into this issue.

Original comment by alex.obj...@gmail.com on 18 Jan 2014 at 4:55

[GoogleCodeExporter]

Unfortunately I'm still seeing the problem. I'm not near a computer, so I can't 
give full info right now, bit the Travis test for wro4j-grails-plugin hits this 
problem today the same as it did yesterday. You can see the result here: 
https://travis-ci.org/wro4j/wro4j-grails-plugin/builds/17149841 . if you 
publish a new snapshot you can just restart that build and see if it worked (or 
tomottow I'll be able to give you full info when I reproduce it on my computer).

Original comment by candrews...@gmail.com on 18 Jan 2014 at 5:57

[GoogleCodeExporter]

I have run the grails application locally before and was able to reproduce
the errors. Latest changes have fixed those. Not sure why it failed when
you have triggered the build.
I have triggered a new build and it is successful now:
https://travis-ci.org/wro4j/wro4j-grails-plugin/builds/17194638

Let me know tomorrow how it works for you.

Original comment by alex.obj...@gmail.com on 18 Jan 2014 at 8:27

[GoogleCodeExporter]

I just tested it again, and you're right - it's working great now. Thank you 
again for this great new feature; I'm really psyched to have it!

Original comment by candrews...@gmail.com on 20 Jan 2014 at 6:46

[GoogleCodeExporter]

@alex.objelean Unfortunately I spoke too soon. There is definitely a problem - 
it just doesn't always happen. It seems that sometimes, the first request fails 
with a 404. You can see that in Travis CI 
https://travis-ci.org/wro4j/wro4j-grails-plugin/builds/17555086 I noticed this 
as I'm trying to release version 1.7.3 of the wro4j-grails-plugin, but I can't 
get the build to successfully complete consistently. Earlier today, I got one 
build to succeed... but after that, despite not making any changes, I haven't 
gotten a success. There must be a race condition in here somewhere... I hope 
this gives you a hint, and at least there's an easily reproducible test.

Original comment by candrews...@gmail.com on 24 Jan 2014 at 11:25

• Changed state: Accepted

[GoogleCodeExporter]

I will open a new deffect and will close this issue.

Original comment by alex.obj...@gmail.com on 25 Jan 2014 at 5:37