1767168 - Intermittent awsy/test_memory_usage.py TestMemoryUsage.test_open_tabs | AssertionError

Status: RESOLVED INCOMPLETE

(Testing :: AWSY, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2022-04-30T23:19:38.153Z] 23:19:38     INFO - TEST-START | awsy/test_memory_usage.py TestMemoryUsage.test_open_tabs
[task 2022-04-30T23:19:38.163Z] 23:19:38     INFO - areweslimyet run by 0 pages, 1 iterations, 15 perTabPause, 30 settleWaitTime
[task 2022-04-30T23:19:38.181Z] 23:19:38     INFO - setting up
[task 2022-04-30T23:19:38.221Z] 23:19:38     INFO - mozproxy mozproxy_dir used for mitmproxy downloads and exe files: /builds/worker/workspace/build/tests/html/testing/mozproxy
[task 2022-04-30T23:19:38.221Z] 23:19:38     INFO - mozproxy Playback tool: mitmproxy
[task 2022-04-30T23:19:38.221Z] 23:19:38     INFO - mozproxy Playback tool version: 5.1.1
[task 2022-04-30T23:19:38.221Z] 23:19:38     INFO - mozproxy create mitmproxy 5.1.1 dir
[task 2022-04-30T23:19:38.221Z] 23:19:38     INFO - mozproxy downloading mitmproxy binary
[task 2022-04-30T23:19:38.329Z] 23:19:38     INFO - mozproxy b'INFO - File mitmproxy-5.1.1-linux.tar.gz not present in local cache folder /builds/worker/tooltool-cache'
[task 2022-04-30T23:19:38.332Z] 23:19:38     INFO - mozproxy b"INFO - Attempting to fetch from 'http://taskcluster/tooltool.mozilla-releng.net/'..."
[task 2022-04-30T23:19:38.932Z] 23:19:38     INFO - mozproxy b'INFO - File mitmproxy-5.1.1-linux.tar.gz fetched from http://taskcluster/tooltool.mozilla-releng.net/ as /builds/worker/workspace/build/tests/html/testing/mozproxy/mitmdump-5.1.1/tmph0wtjt82'
[task 2022-04-30T23:19:39.026Z] 23:19:39     INFO - mozproxy b'INFO - File integrity verified, renaming tmph0wtjt82 to mitmproxy-5.1.1-linux.tar.gz'
[task 2022-04-30T23:19:39.026Z] 23:19:39     INFO - mozproxy b'INFO - Updating local cache /builds/worker/tooltool-cache...'
[task 2022-04-30T23:19:39.047Z] 23:19:39     INFO - mozproxy b'INFO - Local cache /builds/worker/tooltool-cache updated with mitmproxy-5.1.1-linux.tar.gz'
[task 2022-04-30T23:19:39.049Z] 23:19:39     INFO - mozproxy b'INFO - untarring "mitmproxy-5.1.1-linux.tar.gz"'
[task 2022-04-30T23:19:39.210Z] 23:19:39     INFO - mozproxy downloading mitmproxy pageset
[task 2022-04-30T23:19:39.300Z] 23:19:39     INFO - mozproxy b'INFO - File mitm5-linux-firefox-amazon.zip not present in local cache folder /builds/worker/tooltool-cache'
[task 2022-04-30T23:19:39.302Z] 23:19:39     INFO - mozproxy b"INFO - Attempting to fetch from 'http://taskcluster/tooltool.mozilla-releng.net/'..."
<...>
[task 2022-04-30T23:31:31.195Z] 23:31:31     INFO - closing preloaded browser
[task 2022-04-30T23:31:31.204Z] 23:31:31     INFO - starting checkpoint TabsClosed...
[task 2022-04-30T23:31:31.567Z] 23:31:31     INFO - checkpoint created, stored in /builds/worker/workspace/build/tests/results/memory-report-TabsClosed-0.json.gz
[task 2022-04-30T23:32:01.574Z] 23:32:01     INFO - starting checkpoint TabsClosedSettled...
[task 2022-04-30T23:32:01.836Z] 23:32:01     INFO - checkpoint created, stored in /builds/worker/workspace/build/tests/results/memory-report-TabsClosedSettled-0.json.gz
[task 2022-04-30T23:32:01.837Z] 23:32:01     INFO - starting checkpoint TabsClosedForceGC...
[task 2022-04-30T23:32:02.247Z] 23:32:02     INFO - checkpoint created, stored in /builds/worker/workspace/build/tests/results/memory-report-TabsClosedForceGC-0.json.gz
[task 2022-04-30T23:32:02.248Z] 23:32:02     INFO - setting results
[task 2022-04-30T23:32:02.248Z] 23:32:02     INFO - tearing down!
[task 2022-04-30T23:32:02.249Z] 23:32:02     INFO - tearing down webservers!
[task 2022-04-30T23:32:02.249Z] 23:32:02     INFO - mozproxy MitmproxyDesktop stop!!
[task 2022-04-30T23:32:02.249Z] 23:32:02     INFO - mozproxy Mitmproxy stop!!
[task 2022-04-30T23:32:02.250Z] 23:32:02     INFO - mozproxy Stopping mitmproxy playback, killing process 1529
[task 2022-04-30T23:32:03.126Z] 23:32:03     INFO - mozproxy Successfully killed the mitmproxy playback process
[task 2022-04-30T23:32:03.126Z] 23:32:03     INFO - mozproxy Turning off the browser proxy
[task 2022-04-30T23:32:03.127Z] 23:32:03     INFO - mozproxy writing: /builds/worker/workspace/build/application/firefox/distribution/policies.json
[task 2022-04-30T23:32:03.127Z] 23:32:03     INFO - processing data in /builds/worker/workspace/build/tests/results!
[task 2022-04-30T23:32:04.862Z] 23:32:04     INFO - TEST-UNEXPECTED-ERROR | awsy/test_memory_usage.py TestMemoryUsage.test_open_tabs | AssertionError
[task 2022-04-30T23:32:04.862Z] 23:32:04     INFO - Traceback (most recent call last):
[task 2022-04-30T23:32:04.862Z] 23:32:04     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_harness/marionette_test/testcases.py", line 235, in run
[task 2022-04-30T23:32:04.862Z] 23:32:04     INFO -     self.tearDown()
[task 2022-04-30T23:32:04.862Z] 23:32:04     INFO -   File "/builds/worker/workspace/build/tests/awsy/awsy/test_memory_usage.py", line 159, in tearDown
[task 2022-04-30T23:32:04.862Z] 23:32:04     INFO -     AwsyTestCase.tearDown(self)
[task 2022-04-30T23:32:04.862Z] 23:32:04     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/awsy/awsy_test_case.py", line 111, in tearDown
[task 2022-04-30T23:32:04.862Z] 23:32:04     INFO -     self.perf_extra_opts(),
[task 2022-04-30T23:32:04.862Z] 23:32:04     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/awsy/process_perf_data.py", line 207, in create_perf_data
[task 2022-04-30T23:32:04.863Z] 23:32:04     INFO -     extra_opts,
[task 2022-04-30T23:32:04.863Z] 23:32:04     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/awsy/process_perf_data.py", line 150, in create_suite
[task 2022-04-30T23:32:04.863Z] 23:32:04     INFO -     memory_report_path, node, name_filter
[task 2022-04-30T23:32:04.863Z] 23:32:04     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/awsy/parse_about_memory.py", line 119, in calculate_memory_report_values
[task 2022-04-30T23:32:04.864Z] 23:32:04     INFO -     totals = path_total(data, data_point_path)
[task 2022-04-30T23:32:04.864Z] 23:32:04     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/awsy/parse_about_memory.py", line 89, in path_total
[task 2022-04-30T23:32:04.864Z] 23:32:04     INFO -     path_totals[k] += heap_unclassified(k)
[task 2022-04-30T23:32:04.864Z] 23:32:04     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/awsy/parse_about_memory.py", line 64, in heap_unclassified
[task 2022-04-30T23:32:04.864Z] 23:32:04     INFO -     assert process in heap_allocated
[task 2022-04-30T23:32:04.864Z] 23:32:04     INFO - TEST-INFO took 746673ms
[task 2022-04-30T23:32:04.864Z] 23:32:04     INFO - 
[task 2022-04-30T23:32:04.864Z] 23:32:04     INFO - SUMMARY
[task 2022-04-30T23:32:04.864Z] 23:32:04     INFO - -------
[task 2022-04-30T23:32:04.865Z] 23:32:04     INFO - passed: 0
[task 2022-04-30T23:32:04.865Z] 23:32:04     INFO - failed: 1
[task 2022-04-30T23:32:04.866Z] 23:32:04     INFO - todo: 0
[task 2022-04-30T23:32:04.866Z] 23:32:04     INFO - 
[task 2022-04-30T23:32:04.866Z] 23:32:04     INFO - FAILED TESTS
[task 2022-04-30T23:32:04.866Z] 23:32:04     INFO - -------
[task 2022-04-30T23:32:04.866Z] 23:32:04     INFO - test_memory_usage.py test_memory_usage.TestMemoryUsage.test_open_tabs
[task 2022-04-30T23:32:04.866Z] 23:32:04     INFO - SUITE-END | took 746s
[task 2022-04-30T23:32:05.712Z] 23:32:05    ERROR - Return code: 10
[task 2022-04-30T23:32:05.713Z] 23:32:05    ERROR - Got 1 unexpected statuses
[task 2022-04-30T23:32:05.713Z] 23:32:05     INFO - AWSY exited with return code 10: WARNING
[task 2022-04-30T23:32:05.714Z] 23:32:05  WARNING - # TBPL WARNING #
[task 2022-04-30T23:32:05.714Z] 23:32:05  WARNING - setting return code to 1
[task 2022-04-30T23:32:05.714Z] 23:32:05     INFO - Running post-action listener: _package_coverage_data
[task 2022-04-30T23:32:05.715Z] 23:32:05     INFO - Running post-action listener: _resource_record_post_action
[task 2022-04-30T23:32:05.715Z] 23:32:05     INFO - Running post-action listener: process_java_coverage_data
[task 2022-04-30T23:32:05.715Z] 23:32:05     INFO - [mozharness: 2022-04-30 23:32:05.714824Z] Finished run-tests step (success)
[task 2022-04-30T23:32:05.715Z] 23:32:05     INFO - Running post-run listener: _resource_record_post_run
[task 2022-04-30T23:32:05.818Z] 23:32:05     INFO - Total resource usage - Wall time: 767s; CPU: 37%; Read bytes: 0; Write bytes: 4750159872; Read time: 0; Write time: 492548
[task 2022-04-30T23:32:05.818Z] 23:32:05     INFO - TinderboxPrint: CPU usage<br/>36.7%
[task 2022-04-30T23:32:05.818Z] 23:32:05     INFO - TinderboxPrint: I/O read bytes / time<br/>0 / 0
[task 2022-04-30T23:32:05.818Z] 23:32:05     INFO - TinderboxPrint: I/O write bytes / time<br/>4,750,159,872 / 492,548
[task 2022-04-30T23:32:05.818Z] 23:32:05     INFO - TinderboxPrint: CPU idle<br/>1,909.5 (62.9%)
[task 2022-04-30T23:32:05.818Z] 23:32:05     INFO - TinderboxPrint: CPU system<br/>124.6 (4.1%)
[task 2022-04-30T23:32:05.819Z] 23:32:05     INFO - TinderboxPrint: CPU user<br/>987.6 (32.5%)
[task 2022-04-30T23:32:05.819Z] 23:32:05     INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2022-04-30T23:32:05.820Z] 23:32:05     INFO - install - Wall time: 15s; CPU: 25%; Read bytes: 0; Write bytes: 6955008; Read time: 0; Write time: 4312
[task 2022-04-30T23:32:05.827Z] 23:32:05     INFO - run-tests - Wall time: 753s; CPU: 37%; Read bytes: 0; Write bytes: 4743204864; Read time: 0; Write time: 488236
[task 2022-04-30T23:32:05.993Z] 23:32:05  WARNING - returning nonzero exit status 1
[task 2022-04-30T23:32:06.022Z] cleanup
[task 2022-04-30T23:32:06.022Z] + cleanup
[task 2022-04-30T23:32:06.022Z] + local rv=1
[task 2022-04-30T23:32:06.022Z] + [[ -s /builds/worker/.xsession-errors ]]
[task 2022-04-30T23:32:06.022Z] + cp /builds/worker/.xsession-errors /builds/worker/artifacts/public/xsession-errors.log
[task 2022-04-30T23:32:06.024Z] + '[' ']'
[task 2022-04-30T23:32:06.024Z] + true
[task 2022-04-30T23:32:06.024Z] + cleanup_xvfb
[task 2022-04-30T23:32:06.024Z] ++ pidof Xvfb
[task 2022-04-30T23:32:06.030Z] + local xvfb_pid=50
[task 2022-04-30T23:32:06.030Z] + local vnc=false
[task 2022-04-30T23:32:06.030Z] + local interactive=false
[task 2022-04-30T23:32:06.030Z] + '[' -n 50 ']'
[task 2022-04-30T23:32:06.030Z] + [[ false == false ]]
[task 2022-04-30T23:32:06.030Z] + [[ false == false ]]
[task 2022-04-30T23:32:06.030Z] + kill 50
[task 2022-04-30T23:32:06.030Z] + screen -XS xvfb quit
[task 2022-04-30T23:32:06.042Z] + exit 1
[taskcluster 2022-04-30 23:32:06.376Z] === Task Finished ===
[taskcluster 2022-04-30 23:32:08.630Z] Unsuccessful task run with exit code: 1 completed in 853.538 seconds

Comment 1

[Intermittent Failures Robot]

1 failures in 3289 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• linux1804-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1767168&startday=2022-04-25&endday=2022-05-01&tree=all

Comment 2

[Intermittent Failures Robot]

1 failures in 3317 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• linux1804-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1767168&startday=2022-05-09&endday=2022-05-15&tree=all

Comment 3

[Intermittent Failures Robot]

3 failures in 2694 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 3

Platform and build breakdown:

• linux1804-64-shippable-qr: 3
  • opt: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1767168&startday=2022-05-16&endday=2022-05-22&tree=all

Comment 4

[Intermittent Failures Robot]

3 failures in 2624 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 3

Platform and build breakdown:

• windows10-64-2004-shippable-qr: 1
  • opt: 1
• linux1804-64-shippable-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1767168&startday=2022-05-23&endday=2022-05-29&tree=all

Comment 5

[Intermittent Failures Robot]

1 failures in 2917 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• linux1804-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1767168&startday=2022-05-30&endday=2022-06-05&tree=all

Comment 6

[Intermittent Failures Robot]

2 failures in 3336 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1
• try: 1

Platform and build breakdown:

• linux1804-64-shippable-qr: 1
  • opt: 1
• windows10-64-2004-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1767168&startday=2022-06-06&endday=2022-06-12&tree=all

Comment 7

[Intermittent Failures Robot]

1 failures in 3075 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• linux1804-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1767168&startday=2022-06-20&endday=2022-06-26&tree=all

Comment 8

[Intermittent Failures Robot]

1 failures in 3072 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 1

Platform and build breakdown:

• linux1804-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1767168&startday=2022-07-04&endday=2022-07-10&tree=all

Comment 9

[Intermittent Failures Robot]

1 failures in 3341 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• linux1804-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1767168&startday=2022-07-11&endday=2022-07-17&tree=all

Comment 10

[Intermittent Failures Robot]

1 failures in 3497 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 1

Platform and build breakdown:

• linux1804-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1767168&startday=2022-07-18&endday=2022-07-24&tree=all

Comment 11

[Intermittent Failures Robot]

1 failures in 3057 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• linux1804-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1767168&startday=2022-08-01&endday=2022-08-07&tree=all

Comment 12

[Intermittent Failures Robot]

1 failures in 3339 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• linux1804-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1767168&startday=2022-08-08&endday=2022-08-14&tree=all

Comment 13

[Intermittent Failures Robot]

1 failures in 2916 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• linux1804-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1767168&startday=2022-08-15&endday=2022-08-21&tree=all

Comment 14

[Intermittent Failures Robot]

1 failures in 3293 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 1

Platform and build breakdown:

• linux1804-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1767168&startday=2022-08-22&endday=2022-08-28&tree=all

Comment 15

[Intermittent Failures Robot]

1 failures in 3537 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• linux1804-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1767168&startday=2022-08-29&endday=2022-09-04&tree=all

Comment 16

[Intermittent Failures Robot]

1 failures in 2909 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 1

Platform and build breakdown:

• linux1804-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1767168&startday=2022-09-19&endday=2022-09-25&tree=all

Comment 17

[Intermittent Failures Robot]

1 failures in 2041 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 1

Platform and build breakdown:

• linux1804-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1767168&startday=2022-09-26&endday=2022-10-02&tree=all

Comment 18

[Intermittent Failures Robot]

1 failures in 2449 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 1

Platform and build breakdown:

• linux1804-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1767168&startday=2022-10-03&endday=2022-10-09&tree=all

Comment 19

[Intermittent Failures Robot]

5 failures in 3034 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 2
• autoland: 2
• try: 1

Platform and build breakdown:

• linux1804-64-shippable-qr: 5
  • opt: 5

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1767168&startday=2022-10-10&endday=2022-10-16&tree=all

Comment 20

[Intermittent Failures Robot]

2 failures in 3626 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 1
• mozilla-central: 1

Platform and build breakdown:

• linux1804-64-shippable-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1767168&startday=2022-10-31&endday=2022-11-06&tree=all

Comment 21

[Intermittent Failures Robot]

1 failures in 3589 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• linux1804-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1767168&startday=2022-11-14&endday=2022-11-20&tree=all

Comment 22

[BugBot [:suhaib / :marco]]

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