1773868 - Intermittent raptor-browsertime Critical: VisualMetrics failed to run SyntaxError: Unexpected end of JSON input

Status: RESOLVED FIXED

(Testing :: Raptor, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2022-06-12T00:42:12.799Z] 00:42:12     INFO -  raptor-browsertime Info: Get visual metrics from the video
[task 2022-06-12T00:42:12.799Z] 00:42:12    ERROR -  raptor-browsertime Error: Browsertime failed to run
[task 2022-06-12T00:42:12.799Z] 00:42:12     INFO -  raptor-browsertime Info:     at JSON.parse (<anonymous>)
[task 2022-06-12T00:42:12.799Z] 00:42:12     INFO -  raptor-browsertime Info:     at Object.run (/builds/task_165499392139955/fetches/browsertime/node_modules/browsertime/lib/video/postprocessing/visualmetrics/visualMetrics.js:154:19)
[task 2022-06-12T00:42:12.799Z] 00:42:12     INFO -  raptor-browsertime Info:     at async module.exports (/builds/task_165499392139955/fetches/browsertime/node_modules/browsertime/lib/video/postprocessing/visualmetrics/getVideoMetrics.js:34:21)
[task 2022-06-12T00:42:12.799Z] 00:42:12     INFO -  raptor-browsertime Info:     at async Video.postProcessing (/builds/task_165499392139955/fetches/browsertime/node_modules/browsertime/lib/video/video.js:94:22)
[task 2022-06-12T00:42:12.799Z] 00:42:12     INFO -  raptor-browsertime Info:     at async Iteration.run (/builds/task_165499392139955/fetches/browsertime/node_modules/browsertime/lib/core/engine/iteration.js:273:34)
[task 2022-06-12T00:42:12.799Z] 00:42:12     INFO -  raptor-browsertime Info:     at async Engine.runByScript (/builds/task_165499392139955/fetches/browsertime/node_modules/browsertime/lib/core/engine/index.js:266:20)
[task 2022-06-12T00:42:12.799Z] 00:42:12     INFO -  raptor-browsertime Info:     at async run (/builds/task_165499392139955/fetches/browsertime/node_modules/browsertime/bin/browsertime.js:74:22)
[task 2022-06-12T00:42:12.799Z] 00:42:12    ERROR -  raptor-browsertime Critical: VisualMetrics failed to run SyntaxError: Unexpected end of JSON input
[task 2022-06-12T00:42:12.799Z] 00:42:12     INFO -  raptor-browsertime-android Info: removing reverse socket connections
[task 2022-06-12T00:42:12.799Z] 00:42:12     INFO -  adb command_output: adb -s HT7A21A02882 wait-for-device reverse --remove-all, timeout: None, timedout: None, exitcode: 0, output:
[task 2022-06-12T00:42:12.799Z] 00:42:12     INFO -  adb shell_bool: adb -s HT7A21A02882 wait-for-device shell test -d /sdcard/Android/data/org.mozilla.geckoview_example/files/test_root/org.mozilla.geckoview_example-geckodriver-profile/minidumps, timeout: None, timedout: None, exitcode: 1, output:
[task 2022-06-12T00:42:12.799Z] 00:42:12     INFO -  raptor-mitmproxy Info: Mitmproxy stop!!
[task 2022-06-12T00:42:23.267Z] 00:42:12     INFO -  raptor-mitmproxy Info: Stopping mitmproxy playback, killing process 1498
[task 2022-06-12T00:42:23.267Z] 00:42:13     INFO -  raptor-mitmproxy Info: Successfully killed the mitmproxy playback process
[task 2022-06-12T00:42:23.267Z] 00:42:13     INFO -  raptor-perftest Info: Removing temporary directory: /tmp/tmp1u10eher
[task 2022-06-12T00:42:23.267Z] 00:42:13    ERROR -  Traceback (most recent call last):
[task 2022-06-12T00:42:23.267Z] 00:42:13     INFO -    File "/builds/task_165499392139955/workspace/build/tests/raptor/raptor/raptor.py", line 203, in <module>
[task 2022-06-12T00:42:23.267Z] 00:42:13     INFO -      main()
[task 2022-06-12T00:42:23.267Z] 00:42:13     INFO -    File "/builds/task_165499392139955/workspace/build/tests/raptor/raptor/raptor.py", line 149, in main
[task 2022-06-12T00:42:23.267Z] 00:42:13     INFO -      success = raptor.run_tests(raptor_test_list, raptor_test_names)
[task 2022-06-12T00:42:23.267Z] 00:42:13     INFO -    File "/builds/task_165499392139955/workspace/build/tests/raptor/raptor/browsertime/android.py", line 243, in run_tests
[task 2022-06-12T00:42:23.267Z] 00:42:13     INFO -      return super(BrowsertimeAndroid, self).run_tests(tests, test_names)
[task 2022-06-12T00:42:23.267Z] 00:42:13     INFO -    File "/builds/task_165499392139955/workspace/build/tests/raptor/raptor/perftest.py", line 459, in run_tests
[task 2022-06-12T00:42:23.267Z] 00:42:13     INFO -      self.run_test(test, timeout=int(test.get("page_timeout")))
[task 2022-06-12T00:42:23.267Z] 00:42:13     INFO -    File "/builds/task_165499392139955/workspace/build/tests/raptor/raptor/browsertime/base.py", line 620, in run_test
[task 2022-06-12T00:42:23.267Z] 00:42:13     INFO -      raise Exception(self.browsertime_failure)
[task 2022-06-12T00:42:23.267Z] 00:42:13    ERROR -  Exception: VisualMetrics failed to run SyntaxError: Unexpected end of JSON input
[task 2022-06-12T00:42:23.267Z] 00:42:13    ERROR - Return code: 1
[task 2022-06-12T00:42:23.267Z] 00:42:13  WARNING - setting return code to 1
[task 2022-06-12T00:42:23.267Z] 00:42:13     INFO - Killing logcat pid 982.
[task 2022-06-12T00:42:23.267Z] 00:42:13     INFO - Copying Raptor results to upload dir:
[task 2022-06-12T00:42:23.267Z] 00:42:13     INFO - /builds/task_165499392139955/workspace/build/blobber_upload_dir/perfherder-data.json
[task 2022-06-12T00:42:23.267Z] 00:42:13     INFO - Copying raptor results from /builds/task_165499392139955/workspace/build/raptor.json to /builds/task_165499392139955/workspace/build/blobber_upload_dir/perfherder-data.json
[task 2022-06-12T00:42:23.267Z] 00:42:13 CRITICAL - Error copying results /builds/task_165499392139955/workspace/build/raptor.json to upload dir /builds/task_165499392139955/workspace/build/blobber_upload_dir/perfherder-data.json
[task 2022-06-12T00:42:23.267Z] 00:42:13     INFO - [Errno 2] No such file or directory: '/builds/task_165499392139955/workspace/build/raptor.json'
[task 2022-06-12T00:42:23.267Z] 00:42:13     INFO - Running post-action listener: _package_coverage_data

Comment 1

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• android-hw-p2-8-0-android-aarch64-shippable-qr: 1
  • opt: 1

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

Comment 2

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Continuation of bug 1768061. Please investigate and also decide if this should be fixed for version 102 which will be used for an ESR release.

Comment 3

[Andrej (:aglavic)]

I don't think this needs to be fixed for version 102

Comment 4

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 3
• mozilla-beta: 2
• mozilla-central: 2

Platform and build breakdown:

• android-hw-p2-8-0-android-aarch64-shippable-qr: 5
  • opt: 5
• android-hw-g5-7-0-arm7-shippable-qr: 2
  • opt: 2

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

Comment 5

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 5
• autoland: 4

Platform and build breakdown:

• windows10-64-shippable-qr: 1
  • opt: 1
• android-hw-p2-8-0-android-aarch64-shippable-qr: 7
  • opt: 7
• android-hw-g5-7-0-arm7-shippable-qr: 1
  • opt: 1

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

Comment 6

[Intermittent Failures Robot]

9 failures in 3312 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 7
• mozilla-central: 2

Platform and build breakdown:

• android-hw-p2-8-0-android-aarch64-shippable-qr: 9
  • opt: 9

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

Comment 7

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 4
• mozilla-release: 3
• autoland: 5
• fenix: 2
• mozilla-beta: 1

Platform and build breakdown:

• android-hw-p2-8-0-android-aarch64-shippable-qr: 15
  • opt: 15

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

Comment 8

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 4
• mozilla-central: 3
• mozilla-beta: 1
• fenix: 1

Platform and build breakdown:

• android-hw-p2-8-0-android-aarch64-shippable-qr: 9
  • opt: 9

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

Comment 9

[Intermittent Failures Robot]

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

Repository breakdown:

• fenix: 2
• autoland: 4
• mozilla-release: 2
• mozilla-central: 2

Platform and build breakdown:

• android-hw-p2-8-0-android-aarch64-shippable-qr: 8
  • opt: 8
• windows10-64-shippable-qr: 1
  • opt: 1
• android-hw-p2-8-0-arm7-shippable-qr: 1
  • opt: 1

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

Comment 10

[Intermittent Failures Robot]

11 failures in 3245 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 4
• mozilla-central: 3
• fenix: 3
• mozilla-release: 1

Platform and build breakdown:

• android-hw-p2-8-0-android-aarch64-shippable-qr: 11
  • opt: 11

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

Comment 11

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-release: 1
• mozilla-central: 4
• autoland: 4
• mozilla-beta: 2

Platform and build breakdown:

• windows10-64-shippable-qr: 2
  • opt: 2
• android-hw-p2-8-0-android-aarch64-shippable-qr: 8
  • opt: 8
• android-hw-p2-8-0-arm7-shippable-qr: 1
  • opt: 1

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

Comment 12

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 8
• mozilla-central: 4
• fenix: 1
• mozilla-beta: 1

Platform and build breakdown:

• windows10-64-shippable-qr: 1
  • opt: 1
• android-hw-p2-8-0-android-aarch64-shippable-qr: 12
  • opt: 12
• android-hw-p2-8-0-arm7-shippable-qr: 1
  • opt: 1

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

Comment 13

[Intermittent Failures Robot]

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

Repository breakdown:

• fenix: 6
• autoland: 13
• mozilla-central: 3

Platform and build breakdown:

• android-hw-a51-11-0-aarch64-shippable-qr: 1
  • opt: 1
• android-hw-p2-8-0-android-aarch64-shippable-qr: 20
  • opt: 20
• windows10-64-shippable-qr: 1
  • opt: 1

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

Comment 14

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-beta: 5
• autoland: 6
• mozilla-central: 3
• fenix: 3

Platform and build breakdown:

• android-hw-p2-8-0-android-aarch64-shippable-qr: 16
  • opt: 16
• windows10-64-shippable-qr: 1
  • opt: 1

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

Comment 15

[Intermittent Failures Robot]

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

This is the #33 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 19
• mozilla-central: 6
• mozilla-beta: 10
• fenix: 3

Platform and build breakdown:

• android-hw-p2-8-0-android-aarch64-shippable-qr: 38
  • opt: 38

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

Comment 16

[Intermittent Failures Robot]

26 failures in 3616 pushes (0.007 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 3
• mozilla-release: 2
• mozilla-central: 11
• autoland: 9
• fenix: 1

Platform and build breakdown:

• android-hw-p2-8-0-android-aarch64-shippable-qr: 26
  • opt: 26

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

Comment 17

[Andreea Pavel [:apavel]]

There are 27 total failures in the last 7 days on android-hw-p2-8-0-android-aarch64-shippable-qr opt
Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=390492197&repo=autoland&lineNumber=2624

[task 2022-09-14T22:48:39.670Z] 22:47:42     INFO -  raptor-browsertime Info: Starting a browsertime pageload
[task 2022-09-14T22:48:39.670Z] 22:47:42     INFO -  raptor-browsertime Info: Waiting for 1000 ms (post_startup_delay)
[task 2022-09-14T22:48:39.670Z] 22:47:43     INFO -  raptor-browsertime Info: Navigating to about:blank, count: 0
[task 2022-09-14T22:48:39.670Z] 22:47:43     INFO -  raptor-browsertime Info: Navigating to url about:blank iteration 9
[task 2022-09-14T22:48:39.670Z] 22:47:48     INFO -  raptor-browsertime Info: Navigating to primary url:https://cnn.com
[task 2022-09-14T22:48:39.670Z] 22:47:48     INFO -  raptor-browsertime Info: Cycle 0, waiting for 1000 ms
[task 2022-09-14T22:48:39.670Z] 22:47:49     INFO -  raptor-browsertime Info: Cycle 0, starting the measure
[task 2022-09-14T22:48:39.670Z] 22:47:49     INFO -  raptor-browsertime Info: Testing url https://cnn.com iteration 9
[task 2022-09-14T22:48:39.670Z] 22:47:49     INFO -  raptor-browsertime Info: Wed, 14 Sep 2022 22:47:49 GMT adb:command Send '001Bhost:transport:HT8641A00582'
[task 2022-09-14T22:48:39.670Z] 22:47:49     INFO -  raptor-browsertime Info: Wed, 14 Sep 2022 22:47:49 GMT adb:command Send '003Dshell:screenrecord --bit-rate 8000000 /sdcard/browsertime.mp4'
[task 2022-09-14T22:48:39.670Z] 22:47:59     INFO -  raptor-browsertime Info: Wed, 14 Sep 2022 22:47:59 GMT adb:command Send '001Bhost:transport:HT8641A00582'
[task 2022-09-14T22:48:39.670Z] 22:47:59     INFO -  raptor-browsertime Info: Wed, 14 Sep 2022 22:47:59 GMT adb:command Send '0088shell:command -v pkill >/dev/null && pkill -l SIGINT screenrecord || kill -2 $(ps screenrecord | grep -Eo [0-9]+ | grep -m 1 -Eo [0-9]+)'
[task 2022-09-14T22:48:39.670Z] 22:48:09     INFO -  raptor-browsertime Info: Wed, 14 Sep 2022 22:48:09 GMT adb:command Send '001Bhost:transport:HT8641A00582'
[task 2022-09-14T22:48:39.670Z] 22:48:09     INFO -  raptor-browsertime Info: Wed, 14 Sep 2022 22:48:09 GMT adb:command Send '0005sync:'
[task 2022-09-14T22:48:39.670Z] 22:48:09     INFO -  raptor-browsertime Info: Wed, 14 Sep 2022 22:48:09 GMT adb:sync RECV /sdcard/browsertime.mp4
[task 2022-09-14T22:48:39.670Z] 22:48:09     INFO -  raptor-browsertime Info: Wed, 14 Sep 2022 22:48:09 GMT adb:command Send '001Bhost:transport:HT8641A00582'
[task 2022-09-14T22:48:39.670Z] 22:48:09     INFO -  raptor-browsertime Info: Wed, 14 Sep 2022 22:48:09 GMT adb:command Send '002Dshell:rm -- "/sdcard//sdcard/browsertime.mp4"'
[task 2022-09-14T22:48:39.670Z] 22:48:10     INFO -  raptor-browsertime Info: Navigating to about:blank, count: 1
[task 2022-09-14T22:48:39.670Z] 22:48:10     INFO -  raptor-browsertime Info: Navigating to url about:blank iteration 9
[task 2022-09-14T22:48:39.670Z] 22:48:16     INFO -  raptor-browsertime Info: Navigating to primary url:https://cnn.com
[task 2022-09-14T22:48:39.670Z] 22:48:16     INFO -  raptor-browsertime Info: Cycle 1, waiting for 1000 ms
[task 2022-09-14T22:48:39.670Z] 22:48:17     INFO -  raptor-browsertime Info: Cycle 1, starting the measure
[task 2022-09-14T22:48:39.670Z] 22:48:17     INFO -  raptor-browsertime Info: Testing url https://cnn.com iteration 9
[task 2022-09-14T22:48:39.670Z] 22:48:17     INFO -  raptor-browsertime Info: Wed, 14 Sep 2022 22:48:17 GMT adb:command Send '001Bhost:transport:HT8641A00582'
[task 2022-09-14T22:48:39.670Z] 22:48:17     INFO -  raptor-browsertime Info: Wed, 14 Sep 2022 22:48:17 GMT adb:command Send '003Dshell:screenrecord --bit-rate 8000000 /sdcard/browsertime.mp4'
[task 2022-09-14T22:48:39.670Z] 22:48:26     INFO -  raptor-browsertime Info: https://cnn.com has been tested before within the same run, it will get an extra query parameter named browsertime_run. Make sure to use alias to keep track of the URLs
[task 2022-09-14T22:48:39.670Z] 22:48:26     INFO -  raptor-browsertime Info: Wed, 14 Sep 2022 22:48:26 GMT adb:command Send '001Bhost:transport:HT8641A00582'
[task 2022-09-14T22:48:39.670Z] 22:48:26     INFO -  raptor-browsertime Info: Wed, 14 Sep 2022 22:48:26 GMT adb:command Send '0088shell:command -v pkill >/dev/null && pkill -l SIGINT screenrecord || kill -2 $(ps screenrecord | grep -Eo [0-9]+ | grep -m 1 -Eo [0-9]+)'
[task 2022-09-14T22:48:39.670Z] 22:48:36     INFO -  raptor-browsertime Info: Wed, 14 Sep 2022 22:48:36 GMT adb:command Send '001Bhost:transport:HT8641A00582'
[task 2022-09-14T22:48:39.670Z] 22:48:36     INFO -  raptor-browsertime Info: Wed, 14 Sep 2022 22:48:36 GMT adb:command Send '0005sync:'
[task 2022-09-14T22:48:39.670Z] 22:48:36     INFO -  raptor-browsertime Info: Wed, 14 Sep 2022 22:48:36 GMT adb:sync RECV /sdcard/browsertime.mp4
[task 2022-09-14T22:48:39.670Z] 22:48:36     INFO -  raptor-browsertime Info: Wed, 14 Sep 2022 22:48:36 GMT adb:command Send '001Bhost:transport:HT8641A00582'
[task 2022-09-14T22:48:39.670Z] 22:48:36     INFO -  raptor-browsertime Info: Wed, 14 Sep 2022 22:48:36 GMT adb:command Send '002Dshell:rm -- "/sdcard//sdcard/browsertime.mp4"'
[task 2022-09-14T22:48:39.670Z] 22:48:36     INFO -  raptor-browsertime Info: Browsertime pageload ended.
[task 2022-09-14T22:48:39.670Z] 22:48:39     INFO -  raptor-browsertime Info: Wed, 14 Sep 2022 22:48:39 GMT adb:command Send '001Bhost:transport:HT8641A00582'
[task 2022-09-14T22:48:39.670Z] 22:48:39     INFO -  raptor-browsertime Info: Wed, 14 Sep 2022 22:48:39 GMT adb:command Send '0040shell:dumpsys battery | grep temperature | grep -Eo '[0-9]{1,3}''
[task 2022-09-14T22:48:39.670Z] 22:48:39     INFO -  raptor-browsertime Info: Get visual metrics from the video
[task 2022-09-14T22:48:50.247Z] 22:48:39    ERROR -  raptor-browsertime Error: Browsertime failed to run
[task 2022-09-14T22:48:50.247Z] 22:48:39     INFO -  raptor-browsertime Info:     at JSON.parse (<anonymous>)
[task 2022-09-14T22:48:50.247Z] 22:48:39     INFO -  raptor-browsertime Info:     at Object.run (/builds/task_166319423774727/fetches/browsertime/node_modules/browsertime/lib/video/postprocessing/visualmetrics/visualMetrics.js:154:19)
[task 2022-09-14T22:48:50.247Z] 22:48:39     INFO -  raptor-browsertime Info:     at async module.exports (/builds/task_166319423774727/fetches/browsertime/node_modules/browsertime/lib/video/postprocessing/visualmetrics/getVideoMetrics.js:34:21)
[task 2022-09-14T22:48:50.247Z] 22:48:39     INFO -  raptor-browsertime Info:     at async Video.postProcessing (/builds/task_166319423774727/fetches/browsertime/node_modules/browsertime/lib/video/video.js:94:22)
[task 2022-09-14T22:48:50.247Z] 22:48:39     INFO -  raptor-browsertime Info:     at async Iteration.run (/builds/task_166319423774727/fetches/browsertime/node_modules/browsertime/lib/core/engine/iteration.js:273:34)
[task 2022-09-14T22:48:50.247Z] 22:48:39     INFO -  raptor-browsertime Info:     at async Engine.runByScript (/builds/task_166319423774727/fetches/browsertime/node_modules/browsertime/lib/core/engine/index.js:266:20)
[task 2022-09-14T22:48:50.247Z] 22:48:39     INFO -  raptor-browsertime Info:     at async run (/builds/task_166319423774727/fetches/browsertime/node_modules/browsertime/bin/browsertime.js:74:22)
[task 2022-09-14T22:48:50.247Z] 22:48:39    ERROR -  raptor-browsertime Critical: VisualMetrics failed to run SyntaxError: Unexpected end of JSON input
[task 2022-09-14T22:48:50.247Z] 22:48:39     INFO -  raptor-browsertime-android Info: removing reverse socket connections
task 2022-09-14T22:48:50.247Z] 22:48:39     INFO -  adb command_output: adb -s HT8641A00582 wait-for-device reverse --remove-all, timeout: None, timedout: None, exitcode: 0, output:
[task 2022-09-14T22:48:50.247Z] 22:48:39     INFO -  adb shell_bool: adb -s HT8641A00582 wait-for-device shell test -d /sdcard/Android/data/org.mozilla.geckoview_example/files/test_root/org.mozilla.geckoview_example-geckodriver-profile/minidumps, timeout: None, timedout: None, exitcode: 1, output:
[task 2022-09-14T22:48:50.247Z] 22:48:39     INFO -  raptor-mitmproxy Info: Mitmproxy stop!!
[task 2022-09-14T22:48:50.247Z] 22:48:39     INFO -  raptor-mitmproxy Info: Stopping mitmproxy playback, killing process 1179
[task 2022-09-14T22:48:50.247Z] 22:48:39     INFO -  raptor-mitmproxy Info: Successfully killed the mitmproxy playback process
[task 2022-09-14T22:48:50.247Z] 22:48:39     INFO -  raptor-perftest Info: Removing temporary directory: /tmp/tmpglvtmydh
[task 2022-09-14T22:48:50.247Z] 22:48:40    ERROR -  Traceback (most recent call last):
[task 2022-09-14T22:48:50.247Z] 22:48:40     INFO -    File "/builds/task_166319423774727/workspace/build/tests/raptor/raptor/raptor.py", line 206, in <module>
[task 2022-09-14T22:48:50.247Z] 22:48:40     INFO -      main()
[task 2022-09-14T22:48:50.247Z] 22:48:40     INFO -    File "/builds/task_166319423774727/workspace/build/tests/raptor/raptor/raptor.py", line 152, in main
[task 2022-09-14T22:48:50.247Z] 22:48:40     INFO -      success = raptor.run_tests(raptor_test_list, raptor_test_names)
[task 2022-09-14T22:48:50.247Z] 22:48:40     INFO -    File "/builds/task_166319423774727/workspace/build/tests/raptor/raptor/browsertime/android.py", line 243, in run_tests
[task 2022-09-14T22:48:50.247Z] 22:48:40     INFO -      return super(BrowsertimeAndroid, self).run_tests(tests, test_names)
[task 2022-09-14T22:48:50.247Z] 22:48:40     INFO -    File "/builds/task_166319423774727/workspace/build/tests/raptor/raptor/perftest.py", line 467, in run_tests
[task 2022-09-14T22:48:50.247Z] 22:48:40     INFO -      self.run_test(test, timeout=int(test.get("page_timeout")))
[task 2022-09-14T22:48:50.247Z] 22:48:40     INFO -    File "/builds/task_166319423774727/workspace/build/tests/raptor/raptor/browsertime/base.py", line 801, in run_test
[task 2022-09-14T22:48:50.247Z] 22:48:40     INFO -      raise Exception(self.browsertime_failure)
[task 2022-09-14T22:48:50.247Z] 22:48:40    ERROR -  Exception: VisualMetrics failed to run SyntaxError: Unexpected end of JSON input
[task 2022-09-14T22:48:50.247Z] 22:48:40    ERROR - Return code: 1
[task 2022-09-14T22:48:50.247Z] 22:48:40  WARNING - setting return code to 1
[task 2022-09-14T22:48:50.247Z] 22:48:40     INFO - Killing logcat pid 664.
[task 2022-09-14T22:48:50.247Z] 22:48:40     INFO - Copying Raptor results to upload dir:
[task 2022-09-14T22:48:50.247Z] 22:48:40     INFO - /builds/task_166319423774727/workspace/build/blobber_upload_dir/perfherder-data.json
[task 2022-09-14T22:48:50.247Z] 22:48:40     INFO - Copying raptor results from /builds/task_166319423774727/workspace/build/raptor.json to /builds/task_166319423774727/workspace/build/blobber_upload_dir/perfherder-data.json
[task 2022-09-14T22:48:50.247Z] 22:48:40 CRITICAL - Error copying results /builds/task_166319423774727/workspace/build/raptor.json to upload dir /builds/task_166319423774727/workspace/build/blobber_upload_dir/perfherder-data.json
[task 2022-09-14T22:48:50.247Z] 22:48:40     INFO - [Errno 2] No such file or directory: '/builds/task_166319423774727/workspace/build/raptor.json'
[task 2022-09-14T22:48:50.247Z] 22:48:40     INFO - Running post-action listener: _package_coverage_data
[task 2022-09-14T22:48:50.247Z] 22:48:40     INFO - Running post-action listener: _resource_record_post_action
[task 2022-09-14T22:48:50.247Z] 22:48:40     INFO - Running post-action listener: process_java_coverage_data
[task 2022-09-14T22:48:50.247Z] 22:48:40     INFO - Running post-action listener: stop_device
[task 2022-09-14T22:48:50.247Z] 22:48:44     INFO - /data/tombstones/tombstone_00 deleted
[task 2022-09-14T22:48:50.247Z] 22:48:44     INFO - Killing logcat pid 664.
[task 2022-09-14T22:48:50.247Z] 22:48:44     INFO - [mozharness: 2022-09-14 22:48:44.213298Z] Finished run-tests step (success)
[task 2022-09-14T22:48:50.247Z] 22:48:44     INFO - Running post-run listener: _resource_record_post_run
[task 2022-09-14T22:48:50.247Z] 22:48:44     INFO - Total resource usage - Wall time: 1205s; CPU: 47%; Read bytes: 1394868224; Write bytes: 5801758720; Read time: 205568; Write time: 8532888
[task 2022-09-14T22:48:50.247Z] 22:48:44     INFO - TinderboxPrint: CPU usage<br/>46.7%
[task 2022-09-14T22:48:50.247Z] 22:48:44     INFO - TinderboxPrint: I/O read bytes / time<br/>1,394,868,224 / 205,568
[task 2022-09-14T22:48:50.247Z] 22:48:44     INFO - TinderboxPrint: I/O write bytes / time<br/>5,801,758,720 / 8,532,888
[task 2022-09-14T22:48:50.247Z] 22:48:44     INFO - TinderboxPrint: CPU idle<br/>2,354.3 (49.3%)
[task 2022-09-14T22:48:50.247Z] 22:48:44     INFO - TinderboxPrint: CPU iowait<br/>183.2 (3.8%)
[task 2022-09-14T22:48:50.247Z] 22:48:44     INFO - TinderboxPrint: CPU nice<br/>789.5 (16.5%)
[task 2022-09-14T22:48:50.247Z] 22:48:44     INFO - TinderboxPrint: CPU system<br/>208.6 (4.4%)
[task 2022-09-14T22:48:50.247Z] 22:48:44     INFO - TinderboxPrint: CPU user<br/>1,208.5 (25.3%)
[task 2022-09-14T22:48:50.247Z] 22:48:44     INFO - TinderboxPrint: Swap in / out<br/>18,341,888 / 26,890,240
[task 2022-09-14T22:48:50.247Z] 22:48:44     INFO - install-chrome-android - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2022-09-14T22:48:50.247Z] 22:48:44     INFO - install-chromium-distribution - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2022-09-14T22:48:50.247Z] 22:48:44     INFO - install - Wall time: 32s; CPU: 15%; Read bytes: 54190080; Write bytes: 678846464; Read time: 4544; Write time: 831808
[task 2022-09-14T22:48:50.247Z] 22:48:44     INFO - run-tests - Wall time: 1169s; CPU: 48%; Read bytes: 1338748928; Write bytes: 5121232896; Read time: 199688; Write time: 7700988
[task 2022-09-14T22:48:50.247Z] 22:48:44  WARNING - returning nonzero exit status 1

Andrej are there any updates here?

Comment 18

[Andrej (:aglavic)]

We've been dealing with a high android queue, and had delayed working on this queue is back to normal now and I am beginning to investigating later today

Comment 19

[Intermittent Failures Robot]

28 failures in 3023 pushes (0.009 failures/push) were associated with this bug in the last 7 days.

This is the #27 most frequent failure this week.

Repository breakdown:

• autoland: 13
• fenix: 3
• mozilla-central: 7
• mozilla-beta: 4
• mozilla-release: 1

Platform and build breakdown:

• android-hw-p2-8-0-android-aarch64-shippable-qr: 28
  • opt: 28

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

Comment 20

[Andrej (:aglavic)]

Attachment: Bug 1773868 - - Increase wait time for obtaining video from android devices. r?#perftest

Comment 21

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/2d037a44308c
Increase wait time for obtaining video from android devices. r=perftest-reviewers,sparky

Comment 22

[Cristian Tuns]

https://hg.mozilla.org/mozilla-central/rev/2d037a44308c

Comment 23

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 2
• mozilla-beta: 3
• autoland: 4
• fenix: 1

Platform and build breakdown:

• android-hw-p2-8-0-android-aarch64-shippable-qr: 10
  • opt: 10

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

Comment 24

[Alexandru Ionescu (needinfo me) [:alexandrui]]

(In reply to Pulsebot from comment #21)

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/2d037a44308c
Increase wait time for obtaining video from android devices.
r=perftest-reviewers,sparky

== Change summary for alert #35509 (as of Sun, 25 Sep 2022 18:10:47 GMT) ==

Regressions:

Ratio	Test	Platform	Options	Absolute values (old vs new)
72%	web-de fcp	android-hw-a51-11-0-aarch64-shippable-qr	warm webrender	288.62 -> 495.79
61%	web-de FirstVisualChange	android-hw-a51-11-0-aarch64-shippable-qr	warm webrender	335.42 -> 538.42
50%	web-de SpeedIndex	android-hw-a51-11-0-aarch64-shippable-qr	warm webrender	413.33 -> 620.58
50%	web-de ContentfulSpeedIndex	android-hw-a51-11-0-aarch64-shippable-qr	warm webrender	407.67 -> 611.25
35%	web-de PerceptualSpeedIndex	android-hw-a51-11-0-aarch64-shippable-qr	warm webrender	610.25 -> 823.25
33%	web-de fcp	android-hw-p2-8-0-android-aarch64-shippable-qr	warm webrender	121.17 -> 161.46
27%	web-de FirstVisualChange	android-hw-p2-8-0-android-aarch64-shippable-qr	warm webrender	151.83 -> 192.50
20%	web-de SpeedIndex	android-hw-p2-8-0-android-aarch64-shippable-qr	warm webrender	206.75 -> 247.25
18%	web-de ContentfulSpeedIndex	android-hw-p2-8-0-android-aarch64-shippable-qr	warm webrender	249.00 -> 293.42
16%	web-de loadtime	android-hw-a51-11-0-aarch64-shippable-qr	warm webrender	1,598.33 -> 1,846.50
15%	web-de LastVisualChange	android-hw-a51-11-0-aarch64-shippable-qr	warm webrender	1,415.00 -> 1,633.42
15%	web-de PerceptualSpeedIndex	android-hw-p2-8-0-android-aarch64-shippable-qr	warm webrender	275.92 -> 317.08
6%	web-de loadtime	android-hw-p2-8-0-android-aarch64-shippable-qr	warm webrender	830.71 -> 880.46
6%	web-de LastVisualChange	android-hw-p2-8-0-android-aarch64-shippable-qr	warm webrender	969.50 -> 1,026.25
5%	bing-search-restaurants FirstVisualChange	android-hw-p2-8-0-android-aarch64-shippable-qr	warm webrender	223.58 -> 235.25

For up to date results, see: https://treeherder.mozilla.org/perfherder/alerts?id=35509