Bug 765224 (logspam)

[Meta] Make job logs less verbose for non-failures

NEW
Unassigned

Status

defect
7 years ago
3 months ago

People

(Reporter: emorley, Unassigned)

Tracking

(Depends on 21 bugs, {meta, sheriffing-untriaged})

Trunk
Points:
---
1184675, 1184677, 1184803, 1197936, 1286026, 1289637, 1290290, 1290533, 1307237, 1330133, 1333162, 1333163, 1357215, 1366086, 1366112, 1384647, 1429935, 1429939, 1438996, 1438998, 1547108, 794453, 794458, 794467, 794790, 796328, 797637, 797645, 797649, 797827, 811286, 937181, 1164175, 1170642, 1171209, 1171294, 1171322, 1171440, 1171528, 1171555, 1171583, 1171586, 1171716, 1171722, 1172138, 1173858, 1175249, 1175530, 1175631, 1177541, 1177565, 1177578, 1177819, 1179048, 1179058, 1179069, 1179568, 1180036, 1180045, 1180048, 1183786, 1183824, 1183828, 1183845, 1183849, 1183873, 1183875, 1183879, 1183883, 1183888, 1183891, 1183893, 1183894, 1184242, 1184260, 1184275, 1184280, 1184282, 1184285, 1184289, 1184292, 1184293, 1184295, 1184298, 1184661, 1184665, 1184689, 1185793, 1186113, 1191291, 1191911, 1193527, 1194023, 1196855, 1196861, 1208584, 1208594, 1211046, 1212136, 1216288, 1219868, 1219992, 1230660, 1245364, 1249300, 1253040, 1253044, 1253054, 1255005, 1262930, 1262935, 1262942, 1262948, 1267879, 1269047, 1269448, 1278399, 1278412, 1279614, 1286024, 1286036, 1286041, 1286082, 1286084, 1286341, 1289233, 1289598, 1289614, 1289872, 1290288, 1290289, 1293374, 1293375, 1293376, 1293377, 1294577, 1297970, 1304195, 1304197, 1304199, 1307212, 1307216, 1307220, 1307223, 1307228, 1308993, 1309057, 1313440, 1316650, 1316652, 1316654, 1317464, 1318790, 1329784, 1329792, 1329794, 1330123, 1333164, 1333172, 1333174, 1333597, 1335477, 1340665, 1349805, 1350090, 1350091, 1354619, 1356575, 1357208, 1357219, 1357231, 1358259, 1366101, 1366103, 1366127, 1366147, 1374414, 1384638, 1384639, 1384641, 1384646, 1384650, 1388430, 1388433, 1398980, 1398981, 1398982, 1398983, 1398985, 1429941, 1429943, 1437173, 1437175, 1437188, 1437693, 1437991, 1437996, 1437998, 1438999, 1439002, 1515821, 1515827, 1515833, 1523340, 1524130, 1524355, 1524359, 1524361, 1524362, 1540283, 1540289, 1540292, 1540300, 1540879, 1542373, 1542374, 1542375
Dependency tree / graph

Firefox Tracking Flags

(Not tracked)

Details

Current log sizes for a couple of platforms (didn't intend for both to be OS X, but hey):
lion-debug_test-crashtest	 15,201K
lion-debug_test-jetpack	 197K
lion-debug_test-jsreftest	 15,918K
lion-debug_test-mochitest-other	 32,999K
lion-debug_test-mochitests-1	 28,559K
lion-debug_test-mochitests-2	 40,913K
lion-debug_test-mochitests-3	 6,229K
lion-debug_test-mochitests-4	 38,213K
lion-debug_test-mochitests-5	 3,183K
lion-debug_test-reftest	 11,258K
lion-debug_test-xpcshell	 805K
snowleopard-debug_test-crashtest	 15,046K
snowleopard-debug_test-jetpack	 166K
snowleopard-debug_test-jsreftest	 15,917K
snowleopard-debug_test-mochitest-other	 33,410K
snowleopard-debug_test-mochitests-1	 28,511K
snowleopard-debug_test-mochitests-2	 41,473K
snowleopard-debug_test-mochitests-3	 6,480K
snowleopard-debug_test-mochitests-4	 38,412K
snowleopard-debug_test-mochitests-5	 3,305K
snowleopard-debug_test-reftest	 11,247K
snowleopard-debug_test-xpcshell	 806K

This causes several problems:
1) Hangs every time someone opens the full log in the browser (ie bug 762710).
2) Logs to be truncated if they go over the 50MB limit. As much as someone whose name starts with 'A' would like to raise this limit; it's not the way forwards ;-)
3) Increases log storage requirements.
4) Increases time taken for TBPL to download/parse the logs.

I would like to:
1) Modify the handful of tests that are responsible for a disproportionate amount of the output.
2) Think about a more general 'elided entries' type solution, using an approach similar to bug 763169's part C patch.

Note: This would be to cut down on the output of INFO TEST-PASSes, not the failure cases.
Meant to say:

Only consideration to the elided approach would be to ensure we don't exceed the 1200s timeout with no output.
Whiteboard: [sheriff-want]
Blocks: 790889
Blocks: 762710
Summary: [Meta] Make tinderbox test logs less verbose for INFO TEST-PASSes → [Meta] Make tinderbox test logs less verbose for non-failures
Depends on: 794453
Depends on: 794458
Depends on: 794467
Assignee: nobody → bmo
Status: NEW → ASSIGNED
Bug 794458 and bug 794453 have already reduced mochitest-other logs by a fair amount (eg linux opt from 163K to 127K lines) :-)
Depends on: 794790
Depends on: 796328
Depends on: 797637, 797645, 797649
I found a few tests that bloat up the logs by a fair amount for no real good reason.
(In reply to Andrew McCreight [:mccr8] from comment #3)
> I found a few tests that bloat up the logs by a fair amount for no real good
> reason.

Much appreciated, thank you! :-D
It might be tricky, but if we could rework Mochitest to do something like the xpcshell harness that would be nice. xpcshell tests only display a single TEST-PASS line for the whole test file unless it fails, in which case they display a TEST-UNEXPECTED-FAIL and dump the entire log.
Depends on: 797827
Status: ASSIGNED → NEW
Assignee: bmo → nobody
Depends on: 811286
Whiteboard: [sheriff-want]
Blocks: 992485
Depends on: 1170642
Depends on: 1171209
Depends on: 1171294
(In reply to Ted Mielczarek [:ted.mielczarek] from comment #5)
> It might be tricky, but if we could rework Mochitest to do something like
> the xpcshell harness that would be nice. xpcshell tests only display a
> single TEST-PASS line for the whole test file unless it fails, in which case
> they display a TEST-UNEXPECTED-FAIL and dump the entire log.

This is a great approach.

Except: I have found that some test platforms, notably |make mozmill| test suite of
C-C TB fails to notice there are serious JavaScript errors and such during test execution, but if the end result is OK (heaven knows how much we can trust the conclusion when we see
undefined variables, etc. along the way),
it announces success of the test.

So as long as the test harness properly picks up problematic warnings/errors properly,
I agree with the approach in general.

Secondly, we really need to have an INFO-level output.
Today, we have
ERROR (or stacktrace for serious errors coming from some form of asserts.)
WARNING (NS_WARNING comes to my mind)

But I notice after looking at voluminous log from |make mozmill| for a few years now,
that most of the messages are actually
INFO (a piece of information for developers to guide their future efforts by
giving some information on the run-time behavior of the code, etc.)

By creating a macro/function to print out 
INFO: blah...
in the log and replacing inappropriate NS_WARNING and other WARNING-level output routines in the source code,
we can cope with REAL warnings and errors in a saner way.
We can even weed out INFO-level messages fromt the automatic build logs, etc.

Local test or specially run log can record INFO-level messages.

Just a thought.

TIA
Depends on: 1171322
(In reply to ISHIKAWA, Chiaki from comment #6)
> (In reply to Ted Mielczarek [:ted.mielczarek] from comment #5)
> > It might be tricky, but if we could rework Mochitest to do something like
> > the xpcshell harness that would be nice. xpcshell tests only display a
> > single TEST-PASS line for the whole test file unless it fails, in which case
> > they display a TEST-UNEXPECTED-FAIL and dump the entire log.
> 
> This is a great approach.

This got implemented in bug 937181.
Depends on: 937181
Depends on: 1171440
Depends on: 1171528
Depends on: 1171555
Depends on: 1171583
Depends on: 1171586
Depends on: 1171716
Depends on: 1171722
Depends on: 1172138
Depends on: 1173858
Depends on: 1175249
Depends on: 1175631
Depends on: 1175530
Depends on: 1177565
Depends on: 1177819
Depends on: 1177541
Depends on: 1177578
Depends on: 1179048
Depends on: 1179058
Depends on: 1179069
Depends on: 1180036
Depends on: 1180045
Depends on: 1180048
Depends on: 1164175
Summary: [Meta] Make tinderbox test logs less verbose for non-failures → [Meta] Make job logs less verbose for non-failures
Depends on: 1183786
Depends on: 1183824
Depends on: 1183828
Depends on: 1183845
Depends on: 1183849
Depends on: 1183873
Depends on: 1183875
Depends on: 1183879
Depends on: 1183883
Depends on: 1183888
Depends on: 1183891
Depends on: 1183893
Depends on: 1183894
Depends on: 1184242
Depends on: 1184249
Depends on: 1184260
Depends on: 1184275
Depends on: 1184280
Depends on: 1184282
Depends on: 1184285
Depends on: 1184289
Depends on: 1184292
Depends on: 1184293
Depends on: 1184295
Depends on: 1184298
Depends on: 1184661
Depends on: 1184665
Depends on: 1184675
Depends on: 1184677
Depends on: 1184689
Depends on: 1184803
Depends on: 1185793
Depends on: 1186113
Depends on: 1179568
Keywords: meta
Depends on: 1191291
Depends on: 1191911
Depends on: 1193527
Depends on: 1194023
Depends on: 1196855
Depends on: 1196861
Depends on: 1197936
Depends on: 1208584
Depends on: 1208594
Depends on: 1211046
Depends on: 1212136
Depends on: 1216288
Depends on: 1219868
Depends on: 1219992
Alias: logspam
Depends on: 1230660
Depends on: 1253040
Depends on: 1253044
Depends on: 1253054
Depends on: 1255005
Depends on: 1249300
Depends on: 1262930
Depends on: 1262935
Depends on: 1262942
Depends on: 1262948
Depends on: 1267879
Depends on: 1269047
Depends on: 1269448
Depends on: 1278399
Depends on: 1278412
Depends on: 1279614
Depends on: 1286024
Depends on: 1286026
Depends on: 1286036
Depends on: 1286041
Depends on: 1286082
Depends on: 1286084
Depends on: 1286341
Depends on: 1245364
Depends on: 1289233
Depends on: 1289598
Depends on: 1289614
Depends on: 1289637
Depends on: 1289872
Depends on: 1290288
Depends on: 1290289
Depends on: 1290290
Depends on: 1290533
Depends on: 1293374
Depends on: 1293375
Depends on: 1293376
Depends on: 1293377
Depends on: 1294577
Depends on: 1304195
Depends on: 1304197
Depends on: 1304199
Depends on: 1307212
Depends on: 1307216
Depends on: 1307220
Depends on: 1307223
Depends on: 1307228
Depends on: 1307237
Depends on: 1308993
Depends on: 1297970
Depends on: 1309057
Depends on: 1313440
Depends on: 1316650
Depends on: 1316652
Depends on: 1316654
Depends on: 1317464
Depends on: 1318790
Depends on: 1319151
No longer depends on: 1319151
Depends on: 1329784
Depends on: 1329792
Depends on: 1329794
Depends on: 1330123
Depends on: 1330133
Depends on: 1333162
Depends on: 1333163
Depends on: 1333164
Depends on: 1333172
Depends on: 1333174
Depends on: 1333597
Depends on: 1335477
Depends on: 1340665
Depends on: 1349805
Depends on: 1350090
Depends on: 1350091
Depends on: 1357208
Depends on: 1357215
Depends on: 1357219
Depends on: 1357231
Depends on: 1356575
Depends on: 1354619
Depends on: 1358259
Depends on: 1366086
Depends on: 1366101
Depends on: 1366103
Depends on: 1366112
Depends on: 1366127
Depends on: 1366147
Depends on: 1374414
Depends on: 1369002
Depends on: 1384638
Depends on: 1384639
Depends on: 1384641
Depends on: 1384646
Depends on: 1384647
Depends on: 1384650
Depends on: 1388430
Depends on: 1388433
Depends on: 1398980
Depends on: 1398981
Depends on: 1398982
Depends on: 1398983
Depends on: 1398985
Depends on: 1429935
Depends on: 1429939
Depends on: 1429941
Depends on: 1429943
Depends on: 1437173
Depends on: 1437175
Depends on: 1437188
Depends on: 1437693
Depends on: 1437991
Depends on: 1437996
Depends on: 1437998
Depends on: 1438996
Depends on: 1438998
Depends on: 1438999
Depends on: 1439002
Depends on: 1515821
Depends on: 1515827
Depends on: 1515833
Depends on: 1523340
Depends on: 1524130
Depends on: 1524355
Depends on: 1524359
Depends on: 1524361
Depends on: 1524362
Depends on: 1540283
Depends on: 1540289
Depends on: 1540292
Depends on: 1540300
Depends on: 1542373
Depends on: 1542374
Depends on: 1542375
Depends on: 1540879
Depends on: 1547108
You need to log in before you can comment on or make changes to this bug.