search

changcheng / wro4j

Automatically exported from code.google.com/p/wro4j
0 stars 0 forks source link

Too verbose logging on missing resources when resourceWatcher is enabled #512

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago 
a continuation of issue #479

Will duplicate last 2 comments here:

I would like to reopen this one as with version 1.4.8 and

resourceWatcherUpdatePeriod=1
ignoreMissingResources=true

I get lots of noise in logs every second:

INFO ResourceWatcherRunnable:66 - ResourceWatcher started...
WARN ResourceWatcherRunnable:127 - Cannot check 
ro.isdc.wro.model.resource.Resource@1984e990[CSS,/some.css,true] resource 
(Exception message: Exception while reading resource from /some.css). Assuming 
it is unchanged...
WARN ResourceWatcherRunnable:127 - Cannot check 
ro.isdc.wro.model.resource.Resource@55456c99[CSS,/someother.css,true] resource 
(Exception message: Exception while reading resource from /someother.css). 
Assuming it is unchanged...

Those warnings are useless in case when we do ignore missing resources:
ignoreMissingResources=true

and maybe useful if not.

Pertaining 
INFO ResourceWatcherRunnable:66 - ResourceWatcher started...
it is just spammy (every sec) so maybe better to use DEBUG here?

Optional, but it would be nice when:
ignoreMissingResources=false
those warn messages were logged only once when the state changed e.g. some new 
resources become missing.
That would require to keep that state somewhere in cache.

Original issue reported on code.google.com by lystoc...@gmail.com on 10 Aug 2012 at 9:33

GoogleCodeExporter commented 9 years ago 
Alex.O replied:

I would rather open a new issue, since it concerns a different part of the 
code. This also simplify the tracking.

Regarding your mentions:
- Set the resourceWatcherUpdatePeriod to something like 10 (seconds). 1 second 
is too often.
- ResourceWatcher is intended to be used in development, so it worth knowing 
that something is happening in the background. But I'm open to change this if 
you don't agree.
- Warn about missing resources when ignoreMissingResources is set to true, does 
make sense. Will fix that.
- When a resource has changed, the change is reported in the logs the same way 
the missing resource is reported. The state is kept in a map inside the 
ResourceWatcher. I'm not really sure what do you mean by your last suggestion.

Original comment by lystoc...@gmail.com on 10 Aug 2012 at 9:33

GoogleCodeExporter commented 9 years ago 
Would like to hear more feedback regarding logging level for resource watcher. 
Does anybody finds it useful? Would switching it to DEBUG level make you less 
aware about what is happening in the background?

Original comment by alex.obj...@gmail.com on 10 Aug 2012 at 9:39

GoogleCodeExporter commented 9 years ago 
> - Set the resourceWatcherUpdatePeriod to something like 10 (seconds). 1 
second is too often.
- I've replied about resourceWatcherUpdatePeriod=10 in issue #459 it is just to 
long to wait and anyway too spammy.

> - ResourceWatcher is intended to be used in development, so it worth knowing 
that something is happening in the background. But I'm open to change this if 
you don't agree.
I can see that ResourceWatcher could be useful even in production if set to 
some bigger values e.g. 5-10 mins so that there is no need to restart server if 
there is some css change needed. But even in development if it is set to low 
values (rapid development :)) it makes the console very dirty. I would at least 
lower it to DEBUG level so that developer who turns debug on can ignore it in 
logger settings.

> - When a resource has changed, the change is reported in the logs the same 
way the missing resource is reported. The state is kept in a map inside the 
ResourceWatcher. I'm not really sure what do you mean by your last suggestion.

Currently it logs:

WARN ResourceWatcherRunnable:127 - Cannot check 
ro.isdc.wro.model.resource.Resource@1984e990[CSS,/some.css,true] resource 
(Exception message: Exception while reading resource from /some.css). Assuming 
it is unchanged...

on each start of watcher (e.g. every sec) it can even show duplicate message in 
the same watcher run, but as state 'missing' didn't change between watcher 
restarts I think that showing message again is duplicate information.

For example when the resource state is changed (e.g. file modified) it indeed 
prints the message once, e.g:

INFO ResourceWatcherRunnable:158 - Detected change for /some.css resource. 
Invalidating group: login.

Which is good.

So it is not a problem when INFO is logged when it happens only when state 
changes.
DEBUG is better when it may happen to often.

Original comment by lystoc...@gmail.com on 11 Aug 2012 at 12:08

GoogleCodeExporter commented 9 years ago 
I'll just change the logging level to DEBUG for all the cases. I would like to 
avoid keeping the state of resources between requests... it just add extra 
complexity without any real benefit.

Original comment by alex.obj...@gmail.com on 11 Aug 2012 at 5:12

GoogleCodeExporter commented 9 years ago

Original comment by alex.obj...@gmail.com on 11 Aug 2012 at 5:12

GoogleCodeExporter commented 9 years ago 
Fixed in branch 1.4.x
Logging level of ResourceWatcher was changed to DEBUG.

Original comment by alex.obj...@gmail.com on 12 Aug 2012 at 9:31

GoogleCodeExporter commented 9 years ago

Original comment by alex.obj...@gmail.com on 12 Aug 2012 at 6:56