puppeteer webdriver Pup(wd) task's logs are too big to be parsed by Treeherder (>5MB gzipped)
Categories
(Remote Protocol :: WebDriver BiDi, defect, P2)
Tracking
(firefox-esr115 unaffected, firefox-esr128 unaffected, firefox129 unaffected, firefox130 wontfix, firefox131 fixed)
Tracking | Status | |
---|---|---|
firefox-esr115 | --- | unaffected |
firefox-esr128 | --- | unaffected |
firefox129 | --- | unaffected |
firefox130 | --- | wontfix |
firefox131 | --- | fixed |
People
(Reporter: aryx, Assigned: jdescottes)
References
(Regression)
Details
(Keywords: regression, Whiteboard: [webdriver:m12])
Attachments
(1 file)
Since bug 1909952 landed, the logs of Pup(wd)
tasks are too big to be parsed by Treeherder (above the 5MB gzipped threshold). Example
Could the logging be reduced or the task be split into chunks?
Assignee | ||
Updated•3 months ago
|
Assignee | ||
Comment 1•3 months ago
|
||
Discussed in triage, we prefer to split the jobs in chunks and preserve the current log level.
Comment 2•3 months ago
|
||
Set release status flags based on info from the regressing bug 1909952
Comment 3•3 months ago
|
||
Reporter | ||
Comment 4•3 months ago
|
||
The raw log size decreased by 54kB, compressed it increased by 127kB. Does anything more dynamic get logged now?
Assignee | ||
Comment 5•3 months ago
|
||
It's hard to tell.
The log level is set to TRACE for this job, so we log all the commands, results, errors and events from WebDriver BiDi which occur during the tests. I think that especially with tests relying on network events, we might have some requests which intermittently show up (eg requests to favicons).
I looked a bit at the logs and there are two things which stand out:
- one test querySelector QueryAll $$eval should handle many elements (queryselector.spec.js) generates 7000+ lines of log. It's probably similar to another test we had to disable (https://phabricator.services.mozilla.com/D216415)
- MessageHandler logs are responsible for roughly 30% of the logs, and I'm not sure they bring a lot of value
The message handler logs fall into two main categories:
Received command script.callFunction for destination ROOT
and
Module root/script.sys.mjs found for ROOT
The module ones are especially useless I think at this point. I think they were useful in the beginning when we introduced the framework, but at this point they only indicate that the module system works as expected. They can still be useful to debug issues in development when introducing new modules, but maybe we can flag them behind another pref for now until we get chunks to work?
Assignee | ||
Comment 6•3 months ago
|
||
Removing those 2 logs by default reduces the log size of the pup wd job significantly (320K lines -> 200K lines)
Updated•3 months ago
|
Comment 7•3 months ago
|
||
(In reply to Julian Descottes [:jdescottes] from comment #6)
Created attachment 9418200 [details]
Bug 1911382 - [remote] Reduce logs for MessageHandler module systemRemoving those 2 logs by default reduces the log size of the pup wd job significantly (320K lines -> 200K lines)
Does that help without having to skip querySelector QueryAll $$eval should handle many elements (queryselector.spec.js)
? Maybe we could even re-enable the other test that you was referring to earlier?
Assignee | ||
Comment 8•3 months ago
•
|
||
(In reply to Henrik Skupin [:whimboo][⌚️UTC+2] from comment #7)
(In reply to Julian Descottes [:jdescottes] from comment #6)
Created attachment 9418200 [details]
Bug 1911382 - [remote] Reduce logs for MessageHandler module systemRemoving those 2 logs by default reduces the log size of the pup wd job significantly (320K lines -> 200K lines)
Does that help without having to skip
querySelector QueryAll $$eval should handle many elements (queryselector.spec.js)
? Maybe we could even re-enable the other test that you was referring to earlier?
Yes, I didn't have to skip this test. I'll try to re-enable the Aria one.
Edit: try push re-enabling the other test https://treeherder.mozilla.org/jobs?repo=try&revision=f2a7d1fa9d73f28f535eb153426f9effec920564
Assignee | ||
Comment 9•3 months ago
|
||
Re-enabling [ariaqueryhandler.spec] AriaQueryHandler queryAllArray $$eval should handle many elements
generates 80k lines of logs , meaning we go to 280k lines. But it seems that those additional 80k lines are not handled well when using gzip, because the gzipped size goes well over 5 MB.
To summarize the various gzipped sizes:
- baseline: ~5MB (sometimes slightly more, slightly less)
- with the patch to just remove the logs: 4.2MB
- with remove logs + re-enable Aria test: 5.6MB
I would be in favor of landing my current patch, and then work on chunks. I think it's valuable to remove those logs by default anyway, because they don't bring value, and make the logs harder to read.
Comment 10•3 months ago
|
||
Sounds good Julian. Lets get this temporary fix in. Thanks.
Comment 11•3 months ago
|
||
Mind filing a new bug for the chunking?
Assignee | ||
Comment 12•3 months ago
|
||
(In reply to Henrik Skupin [:whimboo][⌚️UTC+2] from comment #11)
Mind filing a new bug for the chunking?
Sure filed Bug 1912292
Comment 13•3 months ago
|
||
Comment 14•3 months ago
|
||
bugherder |
Comment 15•2 months ago
|
||
The patch landed in nightly and beta is affected.
:jdescottes, is this bug important enough to require an uplift?
- If yes, please nominate the patch for beta approval.
- If no, please set
status-firefox130
towontfix
.
For more information, please visit BugBot documentation.
Assignee | ||
Comment 16•2 months ago
|
||
Considering this is only an intermittent log parsing issue, I think it can ride the trains.
Description
•