603238 - Clean up console.log files (created by running debug firefox)

Status: RESOLVED FIXED

(Release Engineering :: General, defect, P2)

Description

[Aki Sasaki (not active)]

moz2-linux64-slave05:/home/cltbld/.mozilla/firefox/console.log is 1.8gb.

Rebooting afterwards might be good too.

Comment 1

[Aki Sasaki (not active)]

One way might be to launch firefox with -profile TMPDIR, where TMPDIR is underneath the build directory for fuzzer, which we can clobber per run.

Comment 2

[Aki Sasaki (not active)]

Looks like this is only a while-running issue?
Still, putting the -profile in /builds would possibly get around the / full nagios warnings.

Comment 3

[Jesse Ruderman]

What is this console.log file?  Based on the path it doesn't sound like something the fuzzer would create.  The fuzz profiles are created in /tmp with mkdtemp() and are cleaned up automatically.

Comment 4

[Aki Sasaki (not active)]

See comment 0 :)
/home/cltbld/.mozilla/firefox/console.log

Comment 5

[Nick Thomas [:nthomas] (UTC+12)]

The one on moz2-linux64-slave03 was last modified at Oct 18 20:35, when a fuzzer job was running. Do you have dump enabled or something ? Looks like Error Console output.

Comment 6

[Jesse Ruderman]

If gLogConsoleErrors somehow gets set to true, Firefox dumps a bunch of crap into a file named console.log in the UserAppDataDirectory (NOT the profile folder).  That seems to be exactly what's happening here.

What are the errors shown in the file?  Are they profile-related errors or DOM errors?  Is there any hint as to why gLogConsoleErrors became true?

Comment 7

[Aki Sasaki (not active)]

Sample output, looks like it's from running debug builds:

[JavaScript Error: "no element found" {file: "file:///builds/slave/mozilla-central-linux-debug-unittest-everythingelse/build/reftest/tests/layout/reftests/object/extra/malformed.xml" line: 2}]
[JavaScript Warning: "Error in parsing value for 'opacity'.  Declaration dropped." {file: "file:///builds/slave/mozilla-central-linux-debug-unittest-everythingelse/build/reftest/tests/layout/reftests/ogg-video/poster-2.html" line: 0}]
[JavaScript Error: "uncaught exception: [Exception... "Unknown or invalid type"  code: "0" nsresult: "0x80620000 (NS_ERROR_DOM_SVG_WRONG_TYPE_ERR)"  location: "file:///builds/slave/mozilla-central-linux-debug-unittest-everythingelse/build/reftest/tests/layout/reftests/svg/bugs/bug327709.svg Line: 9"]"]
[JavaScript Warning: "Unexpected value mutiply parsing mode attribute." {file: "file:///builds/slave/mozilla-central-linux-debug-unittest-everythingelse/build/reftest/tests/layout/reftests/svg/filters/feBlend-1.svg" line: 0}]
[JavaScript Warning: "Error in parsing value for 'fill'.  Declaration dropped." {file: "file:///builds/slave/mozilla-central-linux-debug-unittest-everythingelse/build/reftest/tests/layout/reftests/svg/text-style-01b.svg" line: 13}]
[JavaScript Warning: "Unexpected end of file while searching for closing } of declaration block." {file: "file:///builds/slave/mozilla-central-linux-debug-unittest-everythingelse/build/reftest/tests/layout/reftests/svg/text-style-01b.svg" line: 13}]
[JavaScript Warning: "Unexpected value userSpaceOnuse parsing clipPathUnits attribute." {file: "file:///builds/slave/mozilla-central-linux-debug-unittest-everythingelse/build/reftest/tests/layout/reftests/svg-integration/clipPath-html-03.xhtml" line: 0}]
[JavaScript Warning: "Unexpected value userSpaceOnuse parsing clipPathUnits attribute." {file: "file:///builds/slave/mozilla-central-linux-debug-unittest-everythingelse/build/reftest/tests/layout/reftests/svg-integration/clipPath-html-03.xhtml" line: 0}]
[JavaScript Warning: "Unexpected value userSpaceOnuse parsing clipPathUnits attribute." {file: "file:///builds/slave/mozilla-central-linux-debug-unittest-everythingelse/build/reftest/tests/layout/reftests/svg-integration/clipPath-html-04.xhtml" line: 0}]
[JavaScript Warning: "Unexpected value userSpaceOnuse parsing clipPathUnits attribute." {file: "file:///builds/slave/mozilla-central-linux-debug-unittest-everythingelse/build/reftest/tests/layout/reftests/svg-integration/clipPath-html-04.xhtml" line: 0}]
[JavaScript Warning: "Error in parsing value for '-moz-tab-size'.  Declaration dropped." {file: "file:///builds/slave/mozilla-central-linux-debug-unittest-everythingelse/build/reftest/tests/layout/reftests/tab-size/tab-size-negative.html" line: 0}]

Comment 8

[Aki Sasaki (not active)]

Hm, this may be a unittest thing, rather than fuzzer.

Comment 9

[Jesse Ruderman]

gLogConsoleErrors defaults to true in debug builds:
http://mxr.mozilla.org/mozilla-central/source/toolkit/xre/nsAppRunner.cpp#1056

Comment 10

[Jesse Ruderman]

So yeah debug builds of Firefox append to console.log every time they run.  On my laptop I had a 500MB file.

Comment 11

[Jesse Ruderman]

This "feature" was added in bug 291129.

We can either make buildbot delete console.log after every run (unit test or fuzz), or make debug Firefox not create the files. I'd rather make debug Firefox not create the files, since it also affects developer machines.

Comment 12

[Nick Thomas [:nthomas] (UTC+12)]

Looks like we can set XRE_CONSOLE_LOG in the environment to control where the log is created,
 http://mxr.mozilla.org/mozilla-central/source/toolkit/xre/nsConsoleWriter.cpp#58
If that were /builds/slave/<job>/build/console.log then each log would stay a manageable size and would get cleaned up periodically.

Comment 13

[Aki Sasaki (not active)]

/dev/null ? :)

Comment 14

[Jesse Ruderman]

console.log was 22.95GB on one of my mac minis, lol.

Comment 15

[John O'Duinn [:joduinn] (please use "needinfo?" flag)]

(In reply to comment #6)
> If gLogConsoleErrors somehow gets set to true, Firefox dumps a bunch of crap
> into a file named console.log in the UserAppDataDirectory (NOT the profile
> folder).  That seems to be exactly what's happening here.
> 
> What are the errors shown in the file?  Are they profile-related errors or DOM
> errors?  Is there any hint as to why gLogConsoleErrors became true?

clint: do you have any insight on 

a) why gLogConsoleErrors is being set? 
b) if its needed?

Comment 16

[Nick Thomas [:nthomas] (UTC+12)]

Happens on win32 too, file lives at
 /c/Documents and Setts/cltbld/Application Data/Mozilla/Firefox/console.log

Comment 18

[Chris Cooper [:coop] (he/him)]

(In reply to comment #12)
> Looks like we can set XRE_CONSOLE_LOG in the environment to control where the
> log is created,
> 
> http://mxr.mozilla.org/mozilla-central/source/toolkit/xre/nsConsoleWriter.cpp#58
> If that were /builds/slave/<job>/build/console.log then each log would stay a
> manageable size and would get cleaned up periodically.

I like this approach.

Comment 20

[Dustin J. Mitchell [:dustin] (he/him)]

Can we bump the priority on this?  We're getting lots of (legitimate) alerts about disk space, generally caused by this bug.  It's not so hard to blow away console.log manually on Linux, but it's a very slow trip through SSH on W32.

Comment 21

[Chris Cooper [:coop] (he/him)]

I'll be taking a two-pronged approach:

1) Creating puppet/OPSI packages that will try to remove existing console.log files from their current location (platform-specific profile dir) on every reboot.

2) Setting XRE_CONSOLE_LOG in the env for each platform so we can put this log somewhere where it will be automatically clobbered going forward. This will either be under the builddir or TMP, whichever is more feasible.

Comment 22

[Chris Cooper [:coop] (he/him)]

Attachment: Add a cleanup class to the buildslave module

The cleanup class removes the console.log, but I've also added a cleanup for /tmp files older than a day. Hopefully this will help with bug 605379.

I tested this on the following staging slaves:
* linux-ix-slave05
* moz2-darwin9-slave03
* moz2-darwin10-slave25
* moz2-linux-slave51
* talos-r3-fed-001
* talos-r3-fed64-002
* talos-r3-leopard-002
* talos-r3-snow-001

Comment 23

[Chris Cooper [:coop] (he/him)]

Comment on attachment 503962 [details] [diff] [review]
Add a cleanup class to the buildslave module

https://hg.mozilla.org/build/puppet-manifests/rev/66953af6585d

Comment 24

[Chris Cooper [:coop] (he/him)]

Comment on attachment 503962 [details] [diff] [review]
Add a cleanup class to the buildslave module

All the puppet masters have been restarted with this change now.

Comment 25

[Chris Cooper [:coop] (he/him)]

Attachment: OPSI package to remove console.log and cleanup Temp

I found the easiest way to empty Temp/ was to rmdir it and then recreate it.

This has been tested in staging on the following machines:

* mw32-ix-slave01
* talos-r3-xp-053
* win32-slave60

I'll roll a batch script with the same commands that we can install as a startup item and test it on those systems that aren't under OPSI control (e.g. w7).

Comment 26

[Chris Cooper [:coop] (he/him)]

(In reply to comment #25)
> I'll roll a batch script with the same commands that we can install as a
> startup item and test it on those systems that aren't under OPSI control (e.g.
> w7).

Can't find an existing console.log on the w7 staging slaves. Anyone know where this would live by default (my guess is C:\Users\cltbld\AppData\Local\Mozilla\Firefox) before I run an experiment?

Comment 27

[Dustin J. Mitchell [:dustin] (he/him)]

Comment on attachment 504715 [details] [diff] [review]
OPSI package to remove console.log and cleanup Temp

To the reasonable extent that I understand OPSI scripts, this looks good.

Comment 28

[Chris Cooper [:coop] (he/him)]

Comment on attachment 504715 [details] [diff] [review]
OPSI package to remove console.log and cleanup Temp

https://hg.mozilla.org/build/opsi-package-sources/rev/0f2f36a64c38

I've marked the production slaves to install this package.

Comment 29

[Chris Cooper [:coop] (he/him)]

Attachment: Batch file for cleaning up console.log/tmp files

Here's the batch file for performing the same cleanup on the w7 slaves that are not under OPSI control. I'm not married to file location I've chosen (buildfarm/maintenance), but it seems to make sense for now until we start using puppet (or something else).

Here are the steps to install this script to run on boot for w7:

* wget --no-check-certificate https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/maintenance/cleanup.bat
* Open Control Panel->Administrative Tools->Task Scheduler
* Create Basic Task...
** Set Name: Cleanup
** Set Description: Cleanup temporary files
* Trigger
** When	the computer starts
* Action
** Start a program
* C:\Users\cltbld\cleanup.bat
* Finish
* Open new script (Cleanup) from Task Scheduler Library
** Set: Stop the task if it runs longer than: 1 hour
** Set: If the running task does not end when requested, force it to stop

Comment 30

[Dustin J. Mitchell [:dustin] (he/him)]

Comment on attachment 507141 [details] [diff] [review]
Batch file for cleaning up console.log/tmp files

I worry that this script will still be running when a job is scheduled, thus affecting talos numbers.  Also, deleting and re-creating temp will most likely fail if a file is open in that directory, and it seems likely that would be the case as the login session is starting up.

Would it be better to augment starttalos.bat with these commands?

Comment 31

[Chris Cooper [:coop] (he/him)]

Attachment: Move cleanup calls into the startTalos.bat

(In reply to comment #30)
> Would it be better to augment starttalos.bat with these commands?

Done.

Comment 32

[Dustin J. Mitchell [:dustin] (he/him)]

Comment on attachment 507889 [details] [diff] [review]
Move cleanup calls into the startTalos.bat

LGTM, but my batch skills aren't as sharp as they used to be.  Does batch halt on an error, or does it ignore them unless explicitly handled like bash?  Is there a way to ignore the errors, if so?  Given that we don't monitor talos boxes, I'm worried that an open file of some sort will cause this to fail in some percentage of the cases, and take out the entire pool.

If this failure case is avoided, then I'm happy with the patch.

Comment 33

[Chris Cooper [:coop] (he/him)]

(In reply to comment #32)
> Comment on attachment 507889 [details] [diff] [review]
> Move cleanup calls into the startTalos.bat
> 
> LGTM, but my batch skills aren't as sharp as they used to be.  Does batch halt
> on an error, or does it ignore them unless explicitly handled like bash?  Is
> there a way to ignore the errors, if so?  Given that we don't monitor talos
> boxes, I'm worried that an open file of some sort will cause this to fail in
> some percentage of the cases, and take out the entire pool.

Error handling? On Windows? ;)

The batch script just plows ahead if it can't delete a file/dir for whatever reason (e.g. being held open by another process).

Comment 34

[Chris Cooper [:coop] (he/him)]

Comment on attachment 507889 [details] [diff] [review]
Move cleanup calls into the startTalos.bat

I've started deploying this using csshX.

talos-r3-w7-00[1-9] are done already.

Comment 35

[Chris Cooper [:coop] (he/him)]

Regular w7 slave are done with the following exceptions:

talos-r3-w7-011: reboots
talos-r3-w7-020: reboots
talos-r3-w7-036: reboots
talos-r3-w7-040: reboots

On to the w764 slave next.

Comment 36

[Chris Cooper [:coop] (he/him)]

Attachment: startTalos batch script for w764

The startTalos.bat script on the w764 is a little more convoluted, but essentially the same. Here's the updated version I put on those boxes (including ref image) for posterity.

Comment 37

[Chris Cooper [:coop] (he/him)]

All slaves are updated.