Closed Bug 603238 Opened 14 years ago Closed 13 years ago

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

Categories

(Release Engineering :: General, defect, P2)

defect

Tracking

(Not tracked)

RESOLVED FIXED

People

(Reporter: mozilla, Assigned: coop)

References

Details

(Whiteboard: [unittest])

Attachments

(4 files, 1 obsolete file)

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

Rebooting afterwards might be good too.
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.
Looks like this is only a while-running issue?
Still, putting the -profile in /builds would possibly get around the / full nagios warnings.
Priority: -- → P3
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.
See comment 0 :)
/home/cltbld/.mozilla/firefox/console.log
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.
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?
Summary: fuzzer builds should clean up their profiles after running → Huge, mysterious .mozilla/firefox/console.log created during fuzzer job
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}]
Hm, this may be a unittest thing, rather than fuzzer.
gLogConsoleErrors defaults to true in debug builds:
http://mxr.mozilla.org/mozilla-central/source/toolkit/xre/nsAppRunner.cpp#1056
So yeah debug builds of Firefox append to console.log every time they run.  On my laptop I had a 500MB file.
Summary: Huge, mysterious .mozilla/firefox/console.log created during fuzzer job → debug unittests should clean up their profiles after running
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.
Blocks: 291129
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.
/dev/null ? :)
console.log was 22.95GB on one of my mac minis, lol.
Summary: debug unittests should clean up their profiles after running → debug unittests should clean up console.log or prevent it from being written
Whiteboard: [unittest]
(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?
Happens on win32 too, file lives at
 /c/Documents and Setts/cltbld/Application Data/Mozilla/Firefox/console.log
(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.
Assignee: nobody → coop
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.
Status: NEW → ASSIGNED
Priority: P3 → P2
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.
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
Attachment #503962 - Flags: review?(dustin)
Attachment #503962 - Flags: review?(dustin) → review+
Comment on attachment 503962 [details] [diff] [review]
Add a cleanup class to the buildslave module

https://hg.mozilla.org/build/puppet-manifests/rev/66953af6585d
Attachment #503962 - Flags: checked-in+
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.
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).
Attachment #504715 - Flags: review?(dustin)
(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 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.
Attachment #504715 - Flags: review?(dustin) → review+
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.
Attachment #504715 - Flags: checked-in+
Summary: debug unittests should clean up console.log or prevent it from being written → Clean up console.log files (created by running debug firefox)
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
Attachment #507141 - Flags: review?(dustin)
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?
Attachment #507141 - Flags: review?(dustin) → review-
(In reply to comment #30)
> Would it be better to augment starttalos.bat with these commands?

Done.
Attachment #507141 - Attachment is obsolete: true
Attachment #507889 - Flags: review?(dustin)
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.
Attachment #507889 - Flags: review?(dustin) → review+
(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 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.
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.
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.
All slaves are updated.
Status: ASSIGNED → RESOLVED
Closed: 13 years ago
Resolution: --- → FIXED
Product: mozilla.org → Release Engineering
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: