Closed Bug 1174612 Opened 4 years ago Closed 4 years ago

Make MEMORY STAT logging less verbose

Categories

(Testing :: Mochitest, defect)

defect
Not set

Tracking

(firefox41 fixed)

RESOLVED FIXED
mozilla41
Tracking Status
firefox41 --- fixed

People

(Reporter: poiru, Assigned: poiru)

Details

Attachments

(1 file)

Currently, each test generates 3 or 4 lines of MEMORY STAT messages:

  20:18:05     INFO -  MEMORY STAT vsize after test: 581251072
  20:18:05     INFO -  MEMORY STAT residentFast after test: 146239488
  20:18:05     INFO -  MEMORY STAT heapAllocated after test: 68727408
  20:18:05     INFO -  4 INFO TEST-OK | test.html | took 183ms

We should consolidate all of these into the test end message in a compact format:

  20:18:05     INFO -  4 INFO TEST-OK | test.html | took 183ms | MEMSTAT(vs=581251072 rf=146239488 ha=68727408)

Shu, Ryan, any objections?
Flags: needinfo?(shu)
Flags: needinfo?(ryanvm)
(In reply to Birunthan Mohanathas [:poiru] from comment #0)
> We should consolidate all of these into the test end message in a compact
> format:
> 
>   20:18:05     INFO -  4 INFO TEST-OK | test.html | took 183ms |
> MEMSTAT(vs=581251072 rf=146239488 ha=68727408)

We could also use megabytes (or at least kilobytes):

  20:18:05     INFO -  4 INFO TEST-OK | test.html | took 183ms | MEMSTAT(vs=581 rf=146 ha=68)
I think they should be on a separate line from the test result still, but agree that consolidating them down to one line makes a lot of sense.
Flags: needinfo?(ryanvm)
Having all of the memory stats on a single line and using MB sound fine to me, but please take a few extra characters and make it something comprehensible. Something more like
MEMORY STAT | vsize 581mb | residentFast 146mb | heapAllocated 68mb
This spells out what it actually is, and gives the units. Without that, you might as well just print out the numbers and nothing else, because people are going to have to look up what they mean anyways.
This uses the format from comment 3.
Attachment #8622529 - Flags: review?(cmanchester)
Comment on attachment 8622529 [details] [diff] [review]
Consolidate MEMORY STAT messages into a single line

Review of attachment 8622529 [details] [diff] [review]:
-----------------------------------------------------------------

This looks ok, but I think there are out of tree consumers of these logs that would break with this change. Maybe shu can advise.
Attachment #8622529 - Flags: review?(cmanchester)
https://github.com/syg/mochimem/tree/master will break, but it will be easy to fix.

I also agree with what mccr8 said in comment 3. Please needinfo me again when this lands and I will update mochimem.
Flags: needinfo?(shu)
https://hg.mozilla.org/mozilla-central/rev/d8783d8b557f
Status: ASSIGNED → RESOLVED
Closed: 4 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla41
ni? for comment 6.
Flags: needinfo?(shu)
Birunthan, sorry, should've caught this earlier:

Since this data is supposed to be machine-consumed, the "mb" suffix (or other sizes) is not preferred here.

Could you do "MEMORY STAT | vsize 123456 | residentFast 123456 | heapAllocated 123456"?
Status: RESOLVED → REOPENED
Flags: needinfo?(shu)
Resolution: FIXED → ---
(In reply to Shu-yu Guo [:shu] from comment #13)
> Since this data is supposed to be machine-consumed, the "mb" suffix (or
> other sizes) is not preferred here.
What do you mean? People read this data manually out of the logs, too.
(In reply to Andrew McCreight [:mccr8] from comment #14)
> (In reply to Shu-yu Guo [:shu] from comment #13)
> > Since this data is supposed to be machine-consumed, the "mb" suffix (or
> > other sizes) is not preferred here.
> What do you mean? People read this data manually out of the logs, too.

Oh really? Those are cumulative numbers, without showing a chart like mochimem does, how are they individually consumable?
s/consumable/interpreted
I think one of the sheriffs said that if they start seeing weird OOM-y looking behavior they can check out the memory in the logs around the test where bad stuff started happening.
(In reply to Andrew McCreight [:mccr8] from comment #17)
> I think one of the sheriffs said that if they start seeing weird OOM-y
> looking behavior they can check out the memory in the logs around the test
> where bad stuff started happening.

Huh, okay. We can leave it as is then I suppose.
Status: REOPENED → RESOLVED
Closed: 4 years ago4 years ago
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.