1703433 - Intermittent mozproxy b"TypeError: 'NoneType' object is not callable"

Status: RESOLVED INCOMPLETE

(Testing :: AWSY, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2021-04-07T03:00:34.561Z] 03:00:34     INFO - starting checkpoint TabsClosed...
[task 2021-04-07T03:00:35.219Z] 03:00:35     INFO - checkpoint created, stored in Z:\\task_1617761143\\build\\tests\\results\\memory-report-TabsClosed-0.json.gz
[task 2021-04-07T03:01:05.228Z] 03:01:05     INFO - starting checkpoint TabsClosedSettled...
[task 2021-04-07T03:01:05.748Z] 03:01:05     INFO - checkpoint created, stored in Z:\\task_1617761143\\build\\tests\\results\\memory-report-TabsClosedSettled-0.json.gz
[task 2021-04-07T03:01:05.749Z] 03:01:05     INFO - starting checkpoint TabsClosedForceGC...
[task 2021-04-07T03:01:06.514Z] 03:01:06     INFO - checkpoint created, stored in Z:\\task_1617761143\\build\\tests\\results\\memory-report-TabsClosedForceGC-0.json.gz
[task 2021-04-07T03:01:06.515Z] 03:01:06     INFO - setting results
[task 2021-04-07T03:01:06.515Z] 03:01:06     INFO - tearing down!
[task 2021-04-07T03:01:06.515Z] 03:01:06     INFO - tearing down webservers!
[task 2021-04-07T03:01:06.515Z] 03:01:06     INFO - mozproxy MitmproxyDesktop stop!!
[task 2021-04-07T03:01:06.516Z] 03:01:06     INFO - mozproxy Mitmproxy stop!!
[task 2021-04-07T03:01:06.516Z] 03:01:06     INFO - mozproxy Stopping mitmproxy playback, killing process 4100
[task 2021-04-07T03:01:06.516Z] 03:01:06     INFO - mozproxy Sending CTRL_BREAK_EVENT to mitmproxy
[task 2021-04-07T03:01:06.564Z] 03:01:06    ERROR - mozproxy b'Traceback (most recent call last):'
[task 2021-04-07T03:01:06.564Z] 03:01:06    ERROR - mozproxy b'  File "mitmproxy\\proxy\\server.py", line 121, in handle'
[task 2021-04-07T03:01:06.565Z] 03:01:06    ERROR - mozproxy b"TypeError: 'NoneType' object is not callable"
[task 2021-04-07T03:01:06.565Z] 03:01:06    ERROR - mozproxy b''
[task 2021-04-07T03:01:06.565Z] 03:01:06    ERROR - mozproxy b'mitmproxy has crashed!'
[task 2021-04-07T03:01:06.565Z] 03:01:06    ERROR - mozproxy b'Please lodge a bug report at: https://github.com/mitmproxy/mitmproxy'
[task 2021-04-07T03:01:08.515Z] 03:01:08     INFO - mozproxy Successfully killed the mitmproxy playback process
[task 2021-04-07T03:01:08.516Z] 03:01:08     INFO - mozproxy Turning off the browser proxy
[task 2021-04-07T03:01:08.516Z] 03:01:08     INFO - mozproxy writing: Z:\task_1617761143\build\application\firefox\distribution\policies.json
[task 2021-04-07T03:01:08.516Z] 03:01:08     INFO - processing data in Z:\task_1617761143\build\tests\results!
[task 2021-04-07T03:01:10.173Z] 03:01:10     INFO - PERFHERDER_DATA: {"framework": {"name": "awsy"}, "suites": [{"name": "Resident Memory", "subtests": [{"name": "Fresh start", "value": 262643712, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Fresh start [+30s]", "value": 260366336, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open", "value": 1829187584, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open [+30s]", "value": 1803173888, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open [+30s, forced GC]", "value": 1724055552, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed extra processes", "value": 459079680, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed", "value": 453513216, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed [+30s]", "value": 380940288, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed [+30s, forced GC]", "value": 345423872, "lowerIsBetter": true, "unit": "bytes"}], "lowerIsBetter": true, "unit": "bytes", "extraOptions": ["tp6"], "value": 603714771.7120541}, {"name": "Explicit Memory", "subtests": [{"name": "Fresh start", "value": 164438252, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Fresh start [+30s]", "value": 149201132, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open", "value": 1663299724, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open [+30s]", "value": 1633341580, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open [+30s, forced GC]", "value": 1545654412, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed extra processes", "value": 333541644, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed", "value": 333504780, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed [+30s]", "value": 238919948, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed [+30s, forced GC]", "value": 197333260, "lowerIsBetter": true, "unit": "bytes"}], "lowerIsBetter": true, "unit": "bytes", "extraOptions": ["tp6"], "value": 433470922.58593655}, {"name": "Heap Unclassified", "subtests": [{"name": "Fresh start", "value": 23020050, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Fresh start [+30s]", "value": 19414550, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open", "value": 142151178, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open [+30s]", "value": 130756762, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open [+30s, forced GC]", "value": 121214976, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed extra processes", "value": 52666832, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed", "value": 52315712, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed [+30s]", "value": 38391328, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed [+30s, forced GC]", "value": 33895984, "lowerIsBetter": true, "unit": "bytes"}], "lowerIsBetter": true, "unit": "bytes", "extraOptions": ["tp6"], "value": 53532465.45194597}, {"name": "JS", "subtests": [{"name": "Fresh start", "value": 77997664, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Fresh start [+30s]", "value": 57022768, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open", "value": 814081936, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open [+30s]", "value": 790076352, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open [+30s, forced GC]", "value": 724657872, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed extra processes", "value": 130309472, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed", "value": 130430048, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed [+30s]", "value": 64336272, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed [+30s, forced GC]", "value": 55596800, "lowerIsBetter": true, "unit": "bytes"}], "lowerIsBetter": true, "unit": "bytes", "extraOptions": ["tp6"], "value": 171152946.12093955}, {"name": "Images", "subtests": [{"name": "Fresh start", "value": 862704, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Fresh start [+30s]", "value": 1508928, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open", "value": 50044672, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open [+30s]", "value": 47955936, "lowerIsBetter": true, "unit": "bytes"}, {"name": "After tabs open [+30s, forced GC]", "value": 47955936, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed extra processes", "value": 15726496, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed", "value": 15726544, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed [+30s]", "value": 6602208, "lowerIsBetter": true, "unit": "bytes"}, {"name": "Tabs closed [+30s, forced GC]", "value": 2870112, "lowerIsBetter": true, "unit": "bytes"}], "lowerIsBetter": true, "unit": "bytes", "extraOptions": ["tp6"], "value": 9614711.29033269}]}
[task 2021-04-07T03:01:10.173Z] 03:01:10     INFO - Perfherder data written to Z:\task_1617761143\build\tests\results\perfherder_data.json
[task 2021-04-07T03:01:10.179Z] 03:01:10     INFO - done tearing down!
[task 2021-04-07T03:01:10.183Z] 03:01:10     INFO - TEST-PASS | awsy/test_memory_usage.py TestMemoryUsage.test_open_tabs | took 567286ms
[task 2021-04-07T03:01:10.183Z] 03:01:10     INFO - 
[task 2021-04-07T03:01:10.183Z] 03:01:10     INFO - SUMMARY
[task 2021-04-07T03:01:10.183Z] 03:01:10     INFO - -------
[task 2021-04-07T03:01:10.184Z] 03:01:10     INFO - passed: 1
[task 2021-04-07T03:01:10.184Z] 03:01:10     INFO - failed: 0
[task 2021-04-07T03:01:10.184Z] 03:01:10     INFO - todo: 0
[task 2021-04-07T03:01:10.184Z] 03:01:10     INFO - SUITE-END | took 567s
[task 2021-04-07T03:01:11.754Z] 03:01:11     INFO - Return code: 0
[task 2021-04-07T03:01:11.755Z] 03:01:11     INFO - AWSY exited with return code 0: FAILURE
[task 2021-04-07T03:01:11.755Z] 03:01:11    ERROR - # TBPL FAILURE #```

Comment 1

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1
• mozilla-central: 1

Platform and build breakdown:

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

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1703433&startday=2021-04-05&endday=2021-04-11&tree=all

Comment 2

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

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

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1703433&startday=2021-04-12&endday=2021-04-18&tree=all

Comment 3

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 2

Platform and build breakdown:

• windows10-64-shippable-qr: 1
  • opt: 1
• macosx1015-64-shippable: 1
  • opt: 1

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

Comment 4

[Intermittent Failures Robot]

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

Repository breakdown:

• try: 1
• mozilla-beta: 1

Platform and build breakdown:

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

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1703433&startday=2021-04-26&endday=2021-05-02&tree=all

Comment 5

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

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

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

Comment 6

[BugBot [:suhaib / :marco]]

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

Comment 7

[Sandor Molnar[:smolnar]]

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=341616584&repo=autoland&lineNumber=1670

Comment 8

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 2

Platform and build breakdown:

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

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

Comment 9

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows10-64-shippable: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1703433&startday=2021-06-07&endday=2021-06-13&tree=all

Comment 10

[BugBot [:suhaib / :marco]]

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

Comment 11

[Alexandru Michis [:malexandru]]

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=348563058&repo=mozilla-release&lineNumber=1672

Comment 12

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-release: 1

Platform and build breakdown:

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

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

Comment 13

[BugBot [:suhaib / :marco]]

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