Closed Bug 1779297 Opened 3 years ago Closed 3 years ago

Intermittent mozproxy b"/var/folders/w6/mmyn49294nd977c_4vsk_bkh000014/T/_MEI7KkKFQ/asyncio/base_events.py:608: RuntimeWarning: coroutine 'AddonManager.handle_lifecycle' was never awaited"

Categories

(Testing :: Raptor, defect, P5)

Product:
Testing
Component:
Raptor
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure)

Filed by: imoraru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=384128634&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/UqGrV2KrSG-ERIXRUQeGWg/runs/0/artifacts/public/logs/live_backing.log

[task 2022-07-12T18:38:33.446Z] 18:38:33     INFO - starting checkpoint TabsClosedForceGC...
[task 2022-07-12T18:38:34.677Z] 18:38:34     INFO - checkpoint created, stored in /opt/worker/tasks/task_165765010372518/build/tests/results/memory-report-TabsClosedForceGC-0.json.gz
[task 2022-07-12T18:38:34.678Z] 18:38:34     INFO - setting results
[task 2022-07-12T18:38:34.678Z] 18:38:34     INFO - tearing down!
[task 2022-07-12T18:38:34.678Z] 18:38:34     INFO - tearing down webservers!
[task 2022-07-12T18:38:34.679Z] 18:38:34     INFO - mozproxy MitmproxyDesktop stop!!
[task 2022-07-12T18:38:34.679Z] 18:38:34     INFO - mozproxy Mitmproxy stop!!
[task 2022-07-12T18:38:34.679Z] 18:38:34     INFO - mozproxy Stopping mitmproxy playback, killing process 1191
[task 2022-07-12T18:38:34.885Z] 18:38:34    ERROR - mozproxy b"/var/folders/w6/mmyn49294nd977c_4vsk_bkh000014/T/_MEI7KkKFQ/asyncio/base_events.py:608: RuntimeWarning: coroutine 'AddonManager.handle_lifecycle' was never awaited"
[task 2022-07-12T18:38:34.886Z] 18:38:34    ERROR - mozproxy b'RuntimeWarning: Enable tracemalloc to get the object allocation traceback'
[task 2022-07-12T18:38:35.498Z] 18:38:35     INFO - mozproxy Successfully killed the mitmproxy playback process
[task 2022-07-12T18:38:35.499Z] 18:38:35     INFO - mozproxy Turning off the browser proxy
[task 2022-07-12T18:38:35.499Z] 18:38:35     INFO - mozproxy writing: /opt/worker/tasks/task_165765010372518/build/application/Firefox Nightly.app/Contents/Resources/distribution/policies.json
[task 2022-07-12T18:38:35.500Z] 18:38:35     INFO - processing data in /opt/worker/tasks/task_165765010372518/build/tests/results!
[task 2022-07-12T18:38:39.003Z] 18:38:39     INFO - PERFHERDER_DATA: {"framework": {"name": "awsy"}, "suites": [{"name": "Resident Memory", "subtests": [{"name": "Fresh start", "value": 354480128, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Fresh start [+30s]", "value": 384311296, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open", "value": 4357054464, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open [+30s]", "value": 3853905920, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open [+30s, forced GC]", "value": 3701559296, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed extra processes", "value": 694706176, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed", "value": 681070592, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed [+30s]", "value": 580571136, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed [+30s, forced GC]", "value": 566689792, "lowerIsBetter": true, "unit": "bytes"}], "lowerIsBetter": true, "unit": "bytes", "extraOptions": ["tp6", "fission"], "value": 1031163548.1385711}, {"name": "Explicit Memory", "subtests": [{"name": "Fresh start", "value": 229642201, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Fresh start [+30s]", "value": 198762393, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open", "value": 3220040665, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open [+30s]", "value": 3170663417, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open [+30s, forced GC]", "value": 2980305961, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed extra processes", "value": 360935193, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed", "value": 361594649, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed [+30s]", "value": 288686009, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed [+30s, forced GC]", "value": 272895929, "lowerIsBetter": true, "unit": "bytes"}], "lowerIsBetter": true, "unit": "bytes", "extraOptions": ["tp6", "fission"], "value": 623692115.6070188}, {"name": "Heap Unclassified", "subtests": [{"name": "Fresh start", "value": 74339424, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Fresh start [+30s]", "value": 52916112, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open", "value": 448331447, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open [+30s]", "value": 436342735, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open [+30s, forced GC]", "value": 414166648, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed extra processes", "value": 116747924, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed", "value": 115107692, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed [+30s]", "value": 88901620, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed [+30s, forced GC]", "value": 82029576, "lowerIsBetter": true, "unit": "bytes"}], "lowerIsBetter": true, "unit": "bytes", "extraOptions": ["tp6", "fission"], "value": 146578889.65853032}, {"name": "JS", "subtests": [{"name": "Fresh start", "value": 82671792, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Fresh start [+30s]", "value": 54266680, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open", "value": 1619084080, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open [+30s]", "value": 1581360840, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open [+30s, forced GC]", "value": 1474818128, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed extra processes", "value": 72138408, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed", "value": 72301208, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed [+30s]", "value": 52174120, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed [+30s, forced GC]", "value": 50974728, "lowerIsBetter": true, "unit": "bytes"}], "lowerIsBetter": true, "unit": "bytes", "extraOptions": ["tp6", "fission"], "value": 183421473.9165006}, {"name": "Images", "subtests": [{"name": "Fresh start", "value": 649584, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Fresh start [+30s]", "value": 1289120, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open", "value": 46655584, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open [+30s]", "value": 46367552, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open [+30s, forced GC]", "value": 46366768, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed extra processes", "value": 3413152, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed", "value": 3413200, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed [+30s]", "value": 3166784, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed [+30s, forced GC]", "value": 1957072, "lowerIsBetter": true, "unit": "bytes"}], "lowerIsBetter": true, "unit": "bytes", "extraOptions": ["tp6", "fission"], "value": 5670795.536181166}]}
[task 2022-07-12T18:38:39.004Z] 18:38:39     INFO - Perfherder data written to /opt/worker/tasks/task_165765010372518/build/tests/results/perfherder_data.json
[task 2022-07-12T18:38:39.007Z] 18:38:39     INFO - done tearing down!
[task 2022-07-12T18:38:39.011Z] 18:38:39     INFO - TEST-PASS | awsy/test_memory_usage.py TestMemoryUsage.test_open_tabs | took 676644ms
[task 2022-07-12T18:38:39.011Z] 18:38:39     INFO - 
[task 2022-07-12T18:38:39.011Z] 18:38:39     INFO - SUMMARY
[task 2022-07-12T18:38:39.011Z] 18:38:39     INFO - -------
[task 2022-07-12T18:38:39.012Z] 18:38:39     INFO - passed: 1
[task 2022-07-12T18:38:39.012Z] 18:38:39     INFO - failed: 0
[task 2022-07-12T18:38:39.012Z] 18:38:39     INFO - todo: 0
[task 2022-07-12T18:38:39.013Z] 18:38:39     INFO - SUITE-END | took 676s
[task 2022-07-12T18:38:41.063Z] 18:38:41     INFO - Return code: 0
[task 2022-07-12T18:38:41.063Z] 18:38:41     INFO - AWSY exited with return code 0: FAILURE
[task 2022-07-12T18:38:41.064Z] 18:38:41    ERROR - # TBPL FAILURE #
[task 2022-07-12T18:38:41.064Z] 18:38:41  WARNING - setting return code to 2

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.