New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[error] "Shutting down mod_pagespeed child" after binary upgrade #567

Closed
GoogleCodeExporter opened this Issue Apr 6, 2015 · 8 comments

Comments

Projects
None yet
1 participant
@GoogleCodeExporter

GoogleCodeExporter commented Apr 6, 2015

What steps will reproduce the problem?
1. upgrade to 1.1.23.1-r2169 binary

What is the expected output?

No [error]'s in the Apache logs.

What do you see instead?

[Tue Nov 13 10:51:34 2012] [error] [mod_pagespeed 1.1.23.1-2169 @29929] 
Shutting down mod_pagespeed child
[Tue Nov 13 10:51:35 2012] [error] [mod_pagespeed 1.1.23.1-2169 @32135] 
Shutting down mod_pagespeed child
[Tue Nov 13 10:51:36 2012] [error] [mod_pagespeed 1.1.23.1-2169 @30753] 
Shutting down mod_pagespeed child
[Tue Nov 13 10:51:37 2012] [error] [mod_pagespeed 1.1.23.1-2169 @32114] 
Shutting down mod_pagespeed child
[Tue Nov 13 10:51:38 2012] [error] [mod_pagespeed 1.1.23.1-2169 @32389] 
Shutting down mod_pagespeed child

What version of the product are you using (please check X-Mod-Pagespeed header)?

- ModPagespeed 1.1.23.1-r2169
- Debian GNU/Linux 6.0.6
- Apache 2.2.16-6

Three (3) separate servers are logging the same errors, proportionate to 
load/traffic.

Creating a 'cache.flush' file results in [warn] level errors:

[Tue Nov 13 11:08:07 2012] [warn] [mod_pagespeed 1.1.23.1-2169 @5177] Cache 
Flush 0
[Tue Nov 13 11:08:08 2012] [warn] [mod_pagespeed 1.1.23.1-2169 @3209] Cache 
Flush 0
[Tue Nov 13 11:08:08 2012] [warn] [mod_pagespeed 1.1.23.1-2169 @5841] Cache 
Flush 0
[Tue Nov 13 11:08:09 2012] [warn] [mod_pagespeed 1.1.23.1-2169 @5087] Cache 
Flush 0
[Tue Nov 13 11:08:09 2012] [warn] [mod_pagespeed 1.1.23.1-2169 @5801] Cache 
Flush 0
...
[Tue Nov 13 11:12:27 2012] [warn] [mod_pagespeed 1.1.23.1-2169 @8107] Cache 
Flush 0
[Tue Nov 13 11:12:28 2012] [warn] [mod_pagespeed 1.1.23.1-2169 @8110] Cache 
Flush 0
[Tue Nov 13 11:12:28 2012] [warn] [mod_pagespeed 1.1.23.1-2169 @8111] Cache 
Flush 0
[Tue Nov 13 11:12:29 2012] [error] [mod_pagespeed 1.1.23.1-2169 @8112] Shutting 
down mod_pagespeed child
[Tue Nov 13 11:12:30 2012] [error] [mod_pagespeed 1.1.23.1-2169 @8113] Shutting 
down mod_pagespeed child
[Tue Nov 13 11:12:31 2012] [error] [mod_pagespeed 1.1.23.1-2169 @7746] Shutting 
down mod_pagespeed child
[Tue Nov 13 11:12:31 2012] [warn] [mod_pagespeed 1.1.23.1-2169 @7725] Cache 
Flush 0
[Tue Nov 13 11:12:32 2012] [error] [mod_pagespeed 1.1.23.1-2169 @7425] Shutting 
down mod_pagespeed child
[Tue Nov 13 11:12:33 2012] [error] [mod_pagespeed 1.1.23.1-2169 @8109] Shutting 
down mod_pagespeed child
[Tue Nov 13 11:12:34 2012] [warn] [mod_pagespeed 1.1.23.1-2169 @8017] Cache 
Flush 0

Which MPM?

prefork

URL of broken page: N/A all appear to be working normally

Original issue reported on code.google.com by dun...@chirp.com.au on 13 Nov 2012 at 9:18

@GoogleCodeExporter

This comment has been minimized.

GoogleCodeExporter commented Apr 6, 2015

While our main server is repeating "Cache Flush 0" ad infinitum (600+ already), 
another (VPS) server is counting up:

[Tue Nov 13 11:26:14 2012] [warn] [mod_pagespeed 1.1.23.1-2169 @19810] Cache 
Flush 21
[Tue Nov 13 11:26:17 2012] [warn] [mod_pagespeed 1.1.23.1-2169 @19813] Cache 
Flush 22
[Tue Nov 13 11:26:18 2012] [warn] [mod_pagespeed 1.1.23.1-2169 @19814] Cache 
Flush 23
[Tue Nov 13 11:26:28 2012] [error] [mod_pagespeed 1.1.23.1-2169 @19813] 
Shutting down mod_pagespeed child
[Tue Nov 13 11:26:32 2012] [error] [mod_pagespeed 1.1.23.1-2169 @19809] 
Shutting down mod_pagespeed child
[Tue Nov 13 11:26:33 2012] [error] [mod_pagespeed 1.1.23.1-2169 @19672] 
Shutting down mod_pagespeed child
[Tue Nov 13 11:26:34 2012] [error] [mod_pagespeed 1.1.23.1-2169 @19792] 
Shutting down mod_pagespeed child
[Tue Nov 13 11:26:35 2012] [error] [mod_pagespeed 1.1.23.1-2169 @19528] 
Shutting down mod_pagespeed child
[Tue Nov 13 11:26:38 2012] [warn] [mod_pagespeed 1.1.23.1-2169 @19807] Cache 
Flush 24
...
[Tue Nov 13 11:27:47 2012] [notice] caught SIGTERM, shutting down
[Tue Nov 13 11:27:48 2012] [notice] Apache/2.2.16 (Debian) configured -- 
resuming normal operations
[Tue Nov 13 11:27:53 2012] [warn] [mod_pagespeed 1.1.23.1-2169 @19864] Cache 
Flush 1
[Tue Nov 13 11:27:54 2012] [warn] [mod_pagespeed 1.1.23.1-2169 @19866] Cache 
Flush 2
[Tue Nov 13 11:28:01 2012] [warn] [mod_pagespeed 1.1.23.1-2169 @19867] Cache 
Flush 3

Original comment by dun...@chirp.com.au on 13 Nov 2012 at 9:31

@GoogleCodeExporter

This comment has been minimized.

GoogleCodeExporter commented Apr 6, 2015

RE "shutting down mod_pagespeed child": we will downgrade that to 'info' in a 
patch release prior to marking this stable.  I agree; we should not have been 
reporting an error for that as it happens frequently.

I'm going to split off the 'cache flush' issue as a separate bug.

Original comment by jmara...@google.com on 13 Nov 2012 at 1:44

@GoogleCodeExporter

This comment has been minimized.

GoogleCodeExporter commented Apr 6, 2015

Original comment by jmara...@google.com on 13 Nov 2012 at 1:46

  • Changed state: Started
@GoogleCodeExporter

This comment has been minimized.

GoogleCodeExporter commented Apr 6, 2015

cache-flush issue is in Issue 568

Original comment by jmara...@google.com on 13 Nov 2012 at 1:48

@GoogleCodeExporter

This comment has been minimized.

GoogleCodeExporter commented Apr 6, 2015

Original comment by jmara...@google.com on 13 Nov 2012 at 2:26

  • Added labels: Milestone-v23, release-note
@GoogleCodeExporter

This comment has been minimized.

GoogleCodeExporter commented Apr 6, 2015

Hey Duncan, do you also see warnings like this:

[Tue Nov 13 14:04:21 2012] [warn] [mod_pagespeed  @14164] 
[1113/140421:WARNING:queued_worker_pool.cc(425)] Canceling 10 functions on 
sequence Shutdown

And if so, do they annoy you?  Or are they OK?  Although in my working copy 
I've eliminated the child-shutdown error (made it an Info) we still print 
warnings if mod_pagespeed was in the middle of optimizing resources when it was 
told by Apache to shut down.

My guess is that these happen much less often, and are less likely to fill your 
logs, but I thought I'd check with you before closing this issue.

Original comment by jmara...@google.com on 13 Nov 2012 at 7:07

@GoogleCodeExporter

This comment has been minimized.

GoogleCodeExporter commented Apr 6, 2015

http://code.google.com/p/modpagespeed/source/detail?r=2182

Duncan -- if you are seeing too many those queued_worker_pool warnings I 
described above, please open another bug.  But it'd be useful to know that you 
are.  I admit I do see a few of them in my load tests, though not nearly as 
many as I saw the message about "child shutdown" and I think in a more normal 
site there should not be so many of those messages.

Original comment by jmara...@google.com on 14 Nov 2012 at 12:33

  • Changed state: Fixed
@GoogleCodeExporter

This comment has been minimized.

GoogleCodeExporter commented Apr 6, 2015

Here is a tally of for the current error.log (last 14 hours):

14,972 x [error] Shutting down mod_pagespeed child
4,405 x [warn] Cache Flush 0
30 x [warn] Fetch failed...
6 x [error] Failed to opendir...
3 x [warn] Fetch timed out...
3 x [error] Failed to rmdir...
1 x [error] Rejected absolute url reference...

There are also some issues with ICO files which I'll report separately.  
Otherwise nothing else is being reported at Apache LogLevel warn.

Original comment by dun...@chirp.com.au on 14 Nov 2012 at 7:12

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment