various `new_gallery__transition_perf` devicelab tests timing out

[christopherfujino]

For example:

[Linux_android new_gallery__transition_perf](https://ci.chromium.org/p/flutter/builders/prod/Linux_android%20new_gallery__transition_perf)

• https://ci.chromium.org/p/flutter/builders/prod/Linux_android%20new_gallery__transition_perf/4323

[Linux_samsung_s10 new_gallery__transition_perf](https://ci.chromium.org/p/flutter/builders/prod/Linux_samsung_s10%20new_gallery__transition_perf)

• https://ci.chromium.org/p/flutter/builders/prod/Linux_samsung_s10%20new_gallery__transition_perf/3738
• https://ci.chromium.org/p/flutter/builders/prod/Linux_samsung_s10%20new_gallery__transition_perf/3724
• https://ci.chromium.org/p/flutter/builders/prod/Linux_samsung_s10%20new_gallery__transition_perf/3643
• https://ci.chromium.org/p/flutter/builders/prod/Linux_samsung_s10%20new_gallery__transition_perf/3794

[christopherfujino]

Assigning P2 as it flakes infrequently enough that a re-run will usually fix the tree.

[zanderso]

Comparing a successful vs. unsuccessful run of new_gallery__transition_perf, the driver commands and responses look different:

Unsuccessful: https://storage.googleapis.com/flutter_logs/flutter/b4058b95f52d461914b29c5dd2b5aa4b4ae09206/new_gallery__transition_perf/ee25924b-00d8-446a-a756-adcfd40f1687/flutter_driver_commands_0.log

2022-10-24 12:25:41.994213 >>> {command: request_data, message: isTestingCraneOnly}
2022-10-24 12:25:42.000725 <<< {isError: false, response: {message: false}, type: _extensionType, method: ext.flutter.driver}
2022-10-24 12:25:42.002498 >>> {command: request_data, message: isTestingReplyOnly}
2022-10-24 12:25:42.011756 <<< {isError: false, response: {message: false}, type: _extensionType, method: ext.flutter.driver}
2022-10-24 12:25:42.014435 >>> {command: waitFor, timeout: 5000, finderType: ByText, text: Gallery}
2022-10-24 12:25:42.019663 <<< {isError: false, response: {}, type: _extensionType, method: ext.flutter.driver}
2022-10-24 12:25:42.088070 >>> {command: waitFor, timeout: 10000, finderType: ByValueKey, keyValueString: reply@study, keyValueType: String}
2022-10-24 12:25:42.593312 >>> {command: scroll, finderType: ByValueKey, keyValueString: studyDemoList, keyValueType: String, dx: -800.0, dy: -50.0, duration: 100000, frequency: 60}
2022-10-24 12:25:42.598029 <<< {isError: false, response: {}, type: _extensionType, method: ext.flutter.driver}
2022-10-24 12:25:42.733032 <<< {isError: false, response: {}, type: _extensionType, method: ext.flutter.driver}
2022-10-24 12:25:43.238202 >>> {command: scrollIntoView, finderType: ByValueKey, keyValueString: reply@study, keyValueType: String, alignment: 0.5}
[EOF]

Successful: https://storage.googleapis.com/flutter_logs/flutter/563e0a4aae3640f0bee2bf41d8e6ce486b790e46/new_gallery__transition_perf/72e07505-6afb-45cf-9be5-a593b23575ea/flutter_driver_commands_0.log

2022-10-25 10:24:39.000071 >>> {command: request_data, message: isTestingCraneOnly}
2022-10-25 10:24:39.008162 <<< {isError: false, response: {message: false}, type: _extensionType, method: ext.flutter.driver}
2022-10-25 10:24:39.010004 >>> {command: request_data, message: isTestingReplyOnly}
2022-10-25 10:24:39.019209 <<< {isError: false, response: {message: false}, type: _extensionType, method: ext.flutter.driver}
2022-10-25 10:24:39.024503 >>> {command: waitFor, timeout: 5000, finderType: ByText, text: Gallery}
2022-10-25 10:24:39.072036 <<< {isError: false, response: {}, type: _extensionType, method: ext.flutter.driver}
2022-10-25 10:24:39.117994 >>> {command: waitFor, timeout: 10000, finderType: ByValueKey, keyValueString: reply@study, keyValueType: String}
2022-10-25 10:24:39.540429 <<< {isError: false, response: {}, type: _extensionType, method: ext.flutter.driver}
2022-10-25 10:24:39.624355 >>> {command: scrollIntoView, finderType: ByValueKey, keyValueString: reply@study, keyValueType: String, alignment: 0.5}
[Test continues...]

[zanderso]

@jmagman recently updated the driver in flutter/gallery#792. @jmagman Do you know how to interpret the vm service messages and responses?

[jmagman]

That sure does look similar to the logs in flutter/gallery#792. Unfortunately those Linux tests don't upload a screenshot on failure so it's not obvious why it's not scrolling into view. In the case of my PR I could see that the iPhone was in landscape which was a pretty big hint, then I could reproduce locally.

[jmagman]

I'm not sure why it's not uploading screenshots for Linux, it should be...

Executing "/opt/s/w/ir/x/w/recipe_cleanup/tmpo5hlmkw8/flutter sdk/bin/flutter drive --screenshot /opt/s/w/ir/x/w/recipe_cleanup/flutter_logs_dir -...

[jmagman]

In the other case FlutterDriverExtension timed out before the task was killed at 30 minutes, which gave it time to take the screenshot.

FlutterDriverExtension: Timeout while executing waitFor: TimeoutException after 0:00:10.000000: Future not completed

However here it's waiting the full 30 minutes and being killed at the task level, so doesn't have a chance to save the screenshot.

[zanderso]

Assigning to @christopherfujino to look into the screenshots.

[christopherfujino]

Since LUCI sends SIGTERM to the currently running process when timing it out, I will try registering a handler in the drive command to take a screenshot when SIGTERM is sent.

[cbracken]

Hit one of these here:
https://ci.chromium.org/ui/p/flutter/builders/prod/Linux_android%20new_gallery__transition_perf/4421/overview

one more:
https://ci.chromium.org/ui/p/flutter/builders/prod/Linux_android%20new_gallery__transition_perf/4426/overview

[christopherfujino]

Since LUCI sends SIGTERM to the currently running process when timing it out, I will try registering a handler in the drive command to take a screenshot when SIGTERM is sent.

It appears this didn't work, so I will add a flag to allow explicitly specifying a timeout that will ensure the screenshot is taken.