react-native-firebase
react-native-firebase copied to clipboard
Published
20 hours ago •
invertase
invertase
E2E Github Action is flaky
This is a tracking issue for a work effort I intend to undertake personally
I will greatly appreciate any collaboration with anyone that has thoughts or help to offer, so feel free to chime in!
Observation: The E2E android test fails frequently, unknown root cause
Recent example:
detox[4758] INFO: [DetoxServer.js] server listening on localhost:49713...
detox[4758] ERROR: [exec.js/EXEC_FAIL, #23] ""/Users/runner/Library/Android/sdk/platform-tools/adb" -s emulator-5554 shell "ps | grep \"com\.invertase\.testing$\""" failed with code = 1, stdout and stderr:
detox[4758] ERROR: [exec.js/EXEC_FAIL, #23]
detox[4758] ERROR: [exec.js/EXEC_FAIL, #23]
1) "before all" hook in "{root}"
detox[4758] INFO: at e2e/init.js:53:11
✨ Tests Complete ✨
detox[4758] ERROR: at internal/process/warning.js:25:20
(node:4758) UnhandledPromiseRejectionWarning: DetoxRuntimeError: Failed to run application on the device
I have noticed that it fails sometimes locally as well, unknown cause.
I'd like to figure out exactly why.
Initial Thoughts:
- reproduce locally, fix (ideally)
- Removing the jet dependency (and possibly using cavy.app) is a stretch goal
For reference a successful run currently looks like this at the start of the 'Detox Test' step
[Sat Aug 08 2020 15:12:55.914] BUNDLE ./index.js
[Sat Aug 08 2020 15:13:11.365] LOG Running "testing" with {"rootTag":1}
info Starting custom debugger by executing:, echo nope "/Users/runner/work/react-native-firebase/react-native-firebase/tests" "/Users/runner/work/react-native-firebase/react-native-firebase/tests" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/admob" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/analytics" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/app" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/auth" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/crashlytics" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/database" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/dynamic-links" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/firestore" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/functions" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/iid" "/U...
detox[3191] INFO: at node_modules/jet/lib/node/vm.js:78:11
[✈️] debugger has connected! Downloading app JS bundle...
[Sat Aug 08 2020 15:13:12.536] BUNDLE ./index.js
[Sat Aug 08 2020 15:13:12.940] MAP ./index.js
App -> NativeModules -> Constants
.apps
✓ should be an array
✓ array items contain name, options & state properties
firebase
✓ it should allow read the default app from native
✓ it should create js apps for natively initialized apps
✓ natively initialized apps should have options available in js
- it should initialize dynamic apps
Another one recently:
2020-08-11T08:05:43.4420540Z ##[group]Run nohup yarn run tests:packager:jet &
2020-08-11T08:05:43.4421030Z [36;1mnohup yarn run tests:packager:jet &[0m
2020-08-11T08:05:43.4421270Z [36;1mprintf 'Waiting for packager to come online'[0m
2020-08-11T08:05:43.4421510Z [36;1muntil curl --output /dev/null --silent --head --fail http://localhost:8081/status; do[0m
2020-08-11T08:05:43.4421700Z [36;1m printf '.'[0m
2020-08-11T08:05:43.4421850Z [36;1m sleep 2[0m
2020-08-11T08:05:43.4421990Z [36;1mdone[0m
2020-08-11T08:05:43.4422160Z [36;1mecho "Packager is online!"[0m
2020-08-11T08:05:43.4422370Z [36;1mcurl --output /dev/null --silent --head --fail "http://localhost:8081/index.bundle?platform=android&dev=true&minify=false&inlineSourceMap=true"[0m
2020-08-11T08:05:43.4422620Z [36;1mnohup sh -c "until false; do $ANDROID_HOME/platform-tools/adb shell input tap 100 800; sleep 0.1; done" &[0m
2020-08-11T08:05:43.4422840Z [36;1mnohup sh -c "$ANDROID_HOME/platform-tools/adb logcat '*:E' > adb-log.txt" &[0m
2020-08-11T08:05:43.4422990Z [36;1mcd tests[0m
2020-08-11T08:05:43.4423140Z [36;1m./node_modules/.bin/nyc ./node_modules/.bin/detox test --configuration android.emu.debug --cleanup[0m
2020-08-11T08:05:43.5305970Z shell: /bin/bash --noprofile --norc -e -o pipefail {0}
2020-08-11T08:05:43.5306150Z env:
2020-08-11T08:05:43.5306290Z CODECOV_TOKEN:
2020-08-11T08:05:43.5306440Z JAVA_HOME_8.0.265_x64: /Users/runner/hostedtoolcache/jdk/8.0.265/x64
2020-08-11T08:05:43.5306590Z JAVA_HOME: /Users/runner/hostedtoolcache/jdk/8.0.265/x64
2020-08-11T08:05:43.5306750Z JAVA_HOME_8_0_265_X64: /Users/runner/hostedtoolcache/jdk/8.0.265/x64
2020-08-11T08:05:43.5306920Z ##[endgroup]
2020-08-11T08:05:43.9289670Z Waiting for packager to come online.yarn run v1.22.4
2020-08-11T08:05:43.9862710Z $ cd tests && cross-env REACT_DEBUGGER="echo nope" node_modules/.bin/react-native start --no-interactive
2020-08-11T08:05:46.5049750Z .
2020-08-11T08:05:46.5050170Z ###### ######
2020-08-11T08:05:46.5059800Z ### #### #### ###
2020-08-11T08:05:46.5060130Z ## ### ### ##
2020-08-11T08:05:46.5060820Z ## #### ##
2020-08-11T08:05:46.5071120Z ## #### ##
2020-08-11T08:05:46.5071740Z ## ## ## ##
2020-08-11T08:05:46.5084140Z ## ### ### ##
2020-08-11T08:05:46.5084460Z ## ######################## ##
2020-08-11T08:05:46.5145630Z ###### ### ### ######
2020-08-11T08:05:46.5146320Z ### ## ## ## ## ###
2020-08-11T08:05:46.5146860Z ### ## ### #### ### ## ###
2020-08-11T08:05:46.5147440Z ## #### ######## #### ##
2020-08-11T08:05:46.5147970Z ## ### ########## ### ##
2020-08-11T08:05:46.5148740Z ## #### ######## #### ##
2020-08-11T08:05:46.5149280Z ### ## ### #### ### ## ###
2020-08-11T08:05:46.5149820Z ### ## ## ## ## ###
2020-08-11T08:05:46.5150340Z ###### ### ### ######
2020-08-11T08:05:46.5150850Z ## ######################## ##
2020-08-11T08:05:46.5151350Z ## ### ### ##
2020-08-11T08:05:46.5151860Z ## ## ## ##
2020-08-11T08:05:46.5152370Z ## #### ##
2020-08-11T08:05:46.5152920Z ## #### ##
2020-08-11T08:05:46.5153430Z ## ### ### ##
2020-08-11T08:05:46.5154960Z ### #### #### ###
2020-08-11T08:05:46.5155600Z ###### ######
2020-08-11T08:05:46.5156240Z
2020-08-11T08:05:46.6362010Z Welcome to React Native!
2020-08-11T08:05:47.3212410Z Learn once, write anywhere
2020-08-11T08:05:47.3217570Z
2020-08-11T08:05:47.3228670Z
2020-08-11T08:05:48.1936800Z Packager is online!
2020-08-11T08:07:19.8648860Z [Tue Aug 11 2020 08:05:54.494] BUNDLE ./index.js
2020-08-11T08:07:19.8660560Z
2020-08-11T08:07:20.9943750Z detox[3263] INFO: [test.js] node_modules/.bin/mocha --opts e2e/mocha.opts --configuration android.emu.debug --cleanup --invert --grep :ios: --use-custom-logger "true" e2e
2020-08-11T08:07:22.3705060Z
2020-08-11T08:07:22.3753630Z
2020-08-11T08:07:22.4264520Z detox[3266] INFO: [DetoxServer.js] server listening on localhost:49571...
2020-08-11T08:10:04.4309000Z [Tue Aug 11 2020 08:10:04.314] BUNDLE ./index.js
2020-08-11T08:10:04.4408790Z
2020-08-11T08:10:21.8701850Z info Starting custom debugger by executing:, echo nope "/Users/runner/work/react-native-firebase/react-native-firebase/tests" "/Users/runner/work/react-native-firebase/react-native-firebase/tests" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/admob" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/analytics" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/app" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/auth" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/crashlytics" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/database" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/dynamic-links" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/firestore" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/functions" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/iid" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/in-app-messaging" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/messaging" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/ml-natural-language" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/ml-vision" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/perf" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/remote-config" "/Users/runner/work/react-native-firebase/react-native-firebase/packages/storage"
2020-08-11T08:10:23.6138330Z detox[3266] INFO: at node_modules/jet/lib/node/vm.js:78:11
2020-08-11T08:10:23.6140820Z [✈️] debugger has connected! Downloading app JS bundle...
2020-08-11T08:10:23.7286840Z [Tue Aug 11 2020 08:10:23.628] BUNDLE ./index.js
2020-08-11T08:10:23.7314780Z
2020-08-11T08:10:24.6764240Z [Tue Aug 11 2020 08:10:24.590] MAP ./index.js
2020-08-11T08:10:24.6864660Z
2020-08-11T08:10:25.3046930Z detox[3266] INFO: at node_modules/jet/lib/node/console.js:16:15
2020-08-11T08:10:25.3047210Z Running "testing" with {"rootTag":21}
2020-08-11T08:10:25.7003470Z [Tue Aug 11 2020 08:10:25.698] LOG JavaScript logs will appear in your environment console
2020-08-11T08:13:22.4051350Z 1) "before all" hook in "{root}"
2020-08-11T08:13:22.4083540Z detox[3266] INFO: at e2e/init.js:53:11
2020-08-11T08:13:22.4097520Z ✨ Tests Complete ✨
2020-08-11T08:13:22.4333590Z detox[3266] ERROR: [DetoxExportWrapper.js/DETOX_INIT_ERROR]
2020-08-11T08:13:22.4379950Z { DetoxRuntimeError: Failed to run application on the device
2020-08-11T08:13:22.4380590Z
2020-08-11T08:13:22.4381440Z HINT: Most likely, your tests have timed out and called detox.cleanup() while it was waiting for "ready" message (over WebSocket) from the instrumentation process.
2020-08-11T08:13:22.4398900Z at EmulatorDriver._getInstrumentationCrashError (/Users/runner/work/react-native-firebase/react-native-firebase/tests/node_modules/detox/src/devices/drivers/android/AndroidDriver.js:165:12)
2020-08-11T08:13:22.4401060Z at EmulatorDriver.instrumentationCloseListener (/Users/runner/work/react-native-firebase/react-native-firebase/tests/node_modules/detox/src/devices/drivers/android/AndroidDriver.js:128:67)
2020-08-11T08:13:22.4402690Z at EmulatorDriver._terminateInstrumentation (/Users/runner/work/react-native-firebase/react-native-firebase/tests/node_modules/detox/src/devices/drivers/android/AndroidDriver.js:156:12) name: 'DetoxRuntimeError' }
2020-08-11T08:13:23.0761840Z
2020-08-11T08:13:23.0768680Z 0 passing (6m)
2020-08-11T08:13:23.0776970Z 1 failing
2020-08-11T08:13:23.0795280Z
2020-08-11T08:13:23.0796270Z 1) "before all" hook in "{root}":
2020-08-11T08:13:23.0797410Z Error: Timeout of 360000ms exceeded. For async tests and hooks, ensure "done()" is called; if returning a Promise, ensure it resolves.
2020-08-11T08:13:23.0798160Z
2020-08-11T08:13:23.0822140Z
2020-08-11T08:13:23.0834900Z
2020-08-11T08:13:23.0853340Z
2020-08-11T08:13:23.1523440Z detox[3263] ERROR: [cli.js] Error: Command failed: node_modules/.bin/mocha --opts e2e/mocha.opts --configuration android.emu.debug --cleanup --invert --grep :ios: --use-custom-logger "true" e2e
2020-08-11T08:13:23.1524750Z
~~Sometimes the instrumentation process ps adb command fails for some reason, which means the instrumentation process isn't detected, so the instrumentationCloseListener is called which tears everything down~~
Sometimes the app just takes too long to start I think, the adb logs are inconclusive on that
There are still cases on my local machine where this happens though, and this comment is my best lead on it: https://github.com/nodejs/node/issues/28337#issuecomment-515762218 - shows how to increase ephemeral port range and decrease timeouts on macOS, ~~but requires sudo and I'm not sure the macOS VMs have it.~~ which may work and macOS github virtual environment does enable sudo
All of the failures seem to be the android side of the things not successfully connecting to the websocket and logging in, so the node side never gets a return on it's isReady message.
I'm adding --loglevel trace to the detox invocation which can help prove that out in combo with the adb logs
~~initial ADB logs containing extra info show something that seems racy in the app/detox-testee side react native context bringup + websocket init~~
This could use some upstream attention, but we can at least hack out the synchronization now
- Detox has no way to turn off synchronization in Android, and it should (can hang on UIManager and Timers)
- React Native has UIManager issues where the queue never empties
Here is an "emulator did not look like it was started from detox' perspective fail":
detox[4922] DEBUG: [exec.js/EXEC_CMD, #3] "/Users/runner/Library/Android/sdk/platform-tools/adb" -s emulator-5554 shell "getprop dev.bootcomplete"
Not sure how frequently that pops up but the emulator start could be wrapped with a test for that and a retry perhaps.
Clocked another one of these, there appears to be evidence in the start emulator step, here is the log output from start emulator in a case where the bootcomplete prop fetch fails:
2020-08-13T15:10:52.0131850Z Starting emulator
2020-08-13T15:10:52.1993830Z * daemon not running; starting now at tcp:5037
2020-08-13T15:10:52.8351770Z * daemon started successfully
2020-08-13T15:10:53.9386530Z emulator: WARNING: Running on a system with less than 6 logical cores. Setting number of virtual cores to 1
2020-08-13T15:10:54.0537480Z emulator: ### WARNING: /etc/localtime does not point to zoneinfo-compatible timezone name
2020-08-13T15:10:54.0537690Z
2020-08-13T15:10:54.0767610Z emulator: Cold boot: requested by the user
2020-08-13T15:10:54.1191460Z Your emulator is out of date, please update by launching Android Studio:
2020-08-13T15:10:54.1192700Z - Start Android Studio
2020-08-13T15:10:54.1198040Z - Select menu "Tools > Android > SDK Manager"
2020-08-13T15:10:54.1198700Z - Click "SDK Tools" tab
2020-08-13T15:10:54.1199270Z - Check "Android Emulator" checkbox
2020-08-13T15:10:54.1199790Z - Click "OK"
2020-08-13T15:10:54.1199940Z
2020-08-13T15:11:27.8607710Z emulator: ### WARNING: /etc/localtime does not point to zoneinfo-compatible timezone name
2020-08-13T15:11:27.8608010Z
2020-08-13T15:13:53.0255900Z emulator: INFO: boot completed
2020-08-13T15:13:53.0256290Z emulator: INFO: boot time 180382 ms
2020-08-13T15:13:53.0256640Z emulator: Increasing screen off timeout, logcat buffer size to 2M.
2020-08-13T15:13:53.0260450Z emulator: Revoking microphone permissions for Google App.
2020-08-13T15:14:04.8736040Z emulator: ### WARNING: /etc/localtime does not point to zoneinfo-compatible timezone name
2020-08-13T15:14:04.8736640Z
2020-08-13T15:26:04.6382200Z ##[error]The action has timed out.
~~This is more familiar to me, the emulator itself can fail to download/install correctly and is not wrapped in any sort of error-check/retry loop:~~
Warning: An error occurred while preparing SDK package Google APIs Intel x86 Atom_64 System Image: archive is not a ZIP archive.
Note that the macOS runner does not appear to have anything pre-installed w.r.t. emulator images so there's no avoiding the download
~~JDK8 install failure:~~
2020-08-13T14:09:53.9624000Z ##[group]Run actions/setup-java@v1
2020-08-13T14:09:53.9624220Z with:
2020-08-13T14:09:53.9624360Z java-version: 8
2020-08-13T14:09:53.9624520Z architecture: x64
2020-08-13T14:09:53.9624650Z java-package: jdk
2020-08-13T14:09:53.9624790Z server-id: github
2020-08-13T14:09:53.9624930Z server-username: GITHUB_ACTOR
2020-08-13T14:09:53.9625060Z server-password: GITHUB_TOKEN
2020-08-13T14:09:53.9625190Z env:
2020-08-13T14:09:53.9625320Z CODECOV_TOKEN:
2020-08-13T14:09:53.9625450Z ##[endgroup]
2020-08-13T14:10:25.0543430Z ##[error]getaddrinfo ENOTFOUND static.azul.com
Turns out JDK8 is the default on the runner, so just removed that to remove a point of failure
JDK check
Run java -fullversion
openjdk full version "1.8.0_265-b01"
Just saw one where it appeared that things were just slow on the emulator. This would likely have been okay and succeeded as a test run but indicates some performance tuning and maybe slacker timeouts would be useful.
Specific ideas:
- ~~add
-nojnito emulator startup, we don't need JNI checking~~ - ~~increase emulator RAM (macOS env has 7GB of RAM) -
-memory NNNN(in megabytes)~~ - ~~allow more time in Detox config before Detox terminates the app after startup~~
~~Codecov can apparently fail to upload, on a 4 minute timeout?~~
2020-08-14T00:08:07.3571345Z ##[endgroup]
2020-08-14T00:08:07.4612825Z _____ _
2020-08-14T00:08:07.4613423Z / ____| | |
2020-08-14T00:08:07.4613881Z | | ___ __| | ___ ___ _____ __
2020-08-14T00:08:07.4614312Z | | / _ \ / _` |/ _ \/ __/ _ \ \ / /
2020-08-14T00:08:07.4614755Z | |___| (_) | (_| | __/ (_| (_) \ V /
2020-08-14T00:08:07.4615132Z \_____\___/ \__,_|\___|\___\___/ \_/
2020-08-14T00:08:07.4615520Z v3.7.2
2020-08-14T00:08:07.4617472Z ==> Detecting CI Provider
2020-08-14T00:08:07.4624656Z No CI Detected. Using git/mercurial
2020-08-14T00:08:07.4776315Z ==> Configuration:
2020-08-14T00:08:07.4777205Z Endpoint: https://codecov.io
2020-08-14T00:08:07.4792356Z {
2020-08-14T00:08:07.4793360Z commit: '4594da9b822e768584f6c79a0229c06680e14df3',
2020-08-14T00:08:07.4793910Z branch: 'master',
2020-08-14T00:08:07.4794436Z package: 'node-v3.7.2'
2020-08-14T00:08:07.4795034Z }
2020-08-14T00:08:07.4795450Z ==> Building file structure
2020-08-14T00:08:07.4840253Z ==> Generating gcov reports (skip via --disable=gcov)
2020-08-14T00:08:07.4840882Z Failed to run gcov command.
2020-08-14T00:08:07.4868386Z ==> Scanning for reports
2020-08-14T00:08:07.9507325Z + /home/runner/work/react-native-firebase/react-native-firebase/coverage/lcov.info
2020-08-14T00:08:07.9507851Z + /home/runner/work/react-native-firebase/react-native-firebase/coverage/clover.xml
2020-08-14T00:08:07.9508098Z ==> Uploading reports
2020-08-14T00:12:05.3948284Z ##[error]The operation was canceled.
2020-08-14T00:12:05.3967876Z Cleaning up orphan processes
Found another one! This is new
08-14 14:23:47.124 4341 4341 W IdlingPolicy: These resources are not idle: [com.wix.detox.reactnative.idlingresources.timers.TimersIdlingResource]
Flaky test I think:
1) firestore().collection().onSnapshot()
unsubscribes from further updates:
AssertionError: expected Function { name: '' } to be called thrice but was called 4 times
spy([object Object], null) at handleSuccess (http://localhost:8081/index.bundle?platform=android&dev=true&minify=false&sourceMapURL=true:202068:11)
spy([object Object], null) at handleSuccess (http://localhost:8081/index.bundle?platform=android&dev=true&minify=false&sourceMapURL=true:202068:11)
spy([object Object], null) at handleSuccess (http://localhost:8081/index.bundle?platform=android&dev=true&minify=false&sourceMapURL=true:202068:11)
spy([object Object], null) at handleSuccess (http://localhost:8081/index.bundle?platform=android&dev=true&minify=false&sourceMapURL=true:202068:11)
Not sure what step detox was on yet but it failed once on android with a device log of:
08-14 19:32:49.164 1906 4879 W ActivityManager: Invalid packageName: com.invertase.testing
As if the adb push / adb install failed? Not sure how often that happens, but those steps should be re-tryable - really everything should be retried via full emulator destruction up until the application logs in
Solve with https://github.com/wix/Detox/blob/master/docs/APIRef.Configuration.md#behavior-configuration reinstallapp: false in detox config and do a retry-able install first
New flaky E2E call:
firestore 'should clear any persisted data'
08-15 02:12:21.461 3937 8568 E unknown:ReactNative: Exception in native call
08-15 02:12:21.461 3937 8568 E unknown:ReactNative: java.lang.IllegalStateException: FirebaseFirestore has already been started and its settings can no longer be changed. You can only call setFirestoreSettings() before calling any other methods on a FirebaseFirestore object.
08-15 02:12:21.461 3937 8568 E unknown:ReactNative: at com.google.firebase.firestore.FirebaseFirestore.setFirestoreSettings(com.google.firebase:firebase-firestore@@21.4.3:191)
08-15 02:12:21.461 3937 8568 E unknown:ReactNative: at io.invertase.firebase.firestore.UniversalFirebaseFirestoreCommon.setFirestoreSettings(UniversalFirebaseFirestoreCommon.java:93)
08-15 02:12:21.461 3937 8568 E unknown:ReactNative: at io.invertase.firebase.firestore.UniversalFirebaseFirestoreCommon.getFirestoreForApp(UniversalFirebaseFirestoreCommon.java:45)
08-15 02:12:21.461 3937 8568 E unknown:ReactNative: at io.invertase.firebase.firestore.UniversalFirebaseFirestoreModule.clearPersistence(UniversalFirebaseFirestoreModule.java:83)
08-15 02:12:21.461 3937 8568 E unknown:ReactNative: at io.invertase.firebase.firestore.ReactNativeFirebaseFirestoreModule.clearPersistence(ReactNativeFirebaseFirestoreModule.java:50)
08-15 02:12:21.461 3937 8568 E unknown:ReactNative: at java.lang.reflect.Method.invoke(Native Method)
08-15 02:12:21.461 3937 8568 E unknown:ReactNative: at com.facebook.react.bridge.JavaMethodWrapper.invoke(JavaMethodWrapper.java:372)
08-15 02:12:21.461 3937 8568 E unknown:ReactNative: at com.facebook.react.bridge.JavaModuleWrapper.invoke(JavaModuleWrapper.java:151)
08-15 02:12:21.461 3937 8568 E unknown:ReactNative: at com.facebook.react.bridge.queue.NativeRunnable.run(Native Method)
08-15 02:12:21.461 3937 8568 E unknown:ReactNative: at android.os.Handler.handleCallback(Handler.java:873)
08-15 02:12:21.461 3937 8568 E unknown:ReactNative: at android.os.Handler.dispatchMessage(Handler.java:99)
08-15 02:12:21.461 3937 8568 E unknown:ReactNative: at com.facebook.react.bridge.queue.MessageQueueThreadHandler.dispatchMessage(MessageQueueThreadHandler.java:27)
08-15 02:12:21.461 3937 8568 E unknown:ReactNative: at android.os.Looper.loop(Looper.java:193)
08-15 02:12:21.461 3937 8568 E unknown:ReactNative: at com.facebook.react.bridge.queue.MessageQueueThreadImpl$4.run(MessageQueueThreadImpl.java:226)
08-15 02:12:21.461 3937 8568 E unknown:ReactNative: at java.lang.Thread.run(Thread.java:764)
got this one again 20200828
iOS failed on the 6 minute timeout. It should probably get the same bundle-warming treatment that android gets, separate from it's run, or at least bump the timeout or a couple minutes
Would be nice to have the simulator logs, something like? /usr/bin/xcrun simctl spawn 1B16AB9B-657A-4F7D-A7A8-524F7575BEC4 log stream --level debug --style compact --predicate 'process == "testing"'
The brew applesimutils download step can fail (of course, it touches the network...) and needs a retry.
Our most common flake at this point:
Fri, 21 Aug 2020 15:18:11 GMT NativeFirebaseError: [auth/too-many-requests] We have blocked all requests from this device due to unusual activity. Try again later.
mocha timeout of 3600s was too short for some boots of the android emulator
Increased timeout to 7200 and set '-cores 2' on emulator
Also the timezone was waffling (which just causes extra work for the emulator) so I pinned it on the command line
New flaky test - hit android and ios on same test run humm - it appears multiple operating systems running at the same time through the tests can cross-perturb each other's test fixtures, causing failures. Wow.
I guess each test needs it's own unique test prefix when it creates it's test fixture.
android
Fri, 21 Aug 2020 16:49:52 GMT 1) firestore().collection().limitToLast()
Fri, 21 Aug 2020 16:49:52 GMT limitToLast the number of documents:
Fri, 21 Aug 2020 16:49:52 GMT
Fri, 21 Aug 2020 16:49:52 GMT AssertionError: expected 1 to be 2
Fri, 21 Aug 2020 16:49:52 GMT + expected - actual
Fri, 21 Aug 2020 16:49:52 GMT
Fri, 21 Aug 2020 16:49:52 GMT -1
Fri, 21 Aug 2020 16:49:52 GMT +2
ios
Fri, 21 Aug 2020 16:49:51 GMT 1) firestore().collection().limitToLast()
Fri, 21 Aug 2020 16:49:51 GMT limitToLast the number of documents:
Fri, 21 Aug 2020 16:49:51 GMT
Fri, 21 Aug 2020 16:49:51 GMT AssertionError: expected 1 to be 2
Fri, 21 Aug 2020 16:49:51 GMT + expected - actual
Fri, 21 Aug 2020 16:49:51 GMT
Fri, 21 Aug 2020 16:49:51 GMT -1
Fri, 21 Aug 2020 16:49:51 GMT +2
Fri, 21 Aug 2020 16:49:51 GMT
Failed somehow on the android transition to background for background message handling? Appears rare:
Wed, 26 Aug 2020 18:23:32 GMT ✓ throws if handler is not a function
Wed, 26 Aug 2020 18:23:32 GMT detox[3663] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"invoke","params":{"target":{"type":"Invocation","value":{"target":{"type":"Class","value":"com.wix.detox.uiautomator.UiAutomator"},"method":"uiDevice","args":[]}},"method":"pressHome","args":[]},"messageId":2}
Wed, 26 Aug 2020 18:23:32 GMT detox[3663] TRACE: [DetoxServer.js/MESSAGE] role=tester action=invoke (sessionId=e8fb8afa-93e2-f306-d7c2-3493f1791ebe)
Wed, 26 Aug 2020 18:23:33 GMT detox[3663] TRACE: [DetoxServer.js/MESSAGE] role=testee action=invokeResult (sessionId=e8fb8afa-93e2-f306-d7c2-3493f1791ebe)
Wed, 26 Aug 2020 18:23:33 GMT detox[3663] TRACE: [AsyncWebSocket.js/WEBSOCKET_MESSAGE] {"messageId":2,"type":"invokeResult","params":{"result":true}}
Wed, 26 Aug 2020 18:23:33 GMT
Wed, 26 Aug 2020 18:23:39 GMT detox[3663] INFO: at e2e/init.js:38:15
Wed, 26 Aug 2020 18:23:39 GMT
Wed, 26 Aug 2020 18:23:39 GMT detox[3663] WARN: at e2e/init.js:39:15
Wed, 26 Aug 2020 18:23:39 GMT ⚠️ A test failed:
Wed, 26 Aug 2020 18:23:39 GMT detox[3663] WARN: at e2e/init.js:40:15
Wed, 26 Aug 2020 18:23:39 GMT ️ -> receives messages when the app is in the background
Wed, 26 Aug 2020 18:23:39 GMT detox[3663] WARN: at e2e/init.js:47:13
Wed, 26 Aug 2020 18:23:39 GMT ️ -> Retrying in 1 seconds ... (1)
Wed, 26 Aug 2020 18:35:44 GMT detox[3663] WARN: at e2e/init.js:44:15
Wed, 26 Aug 2020 18:35:44 GMT 🔴 Retry #1 failed...
Wed, 26 Aug 2020 18:35:44 GMT detox[3663] WARN: at e2e/init.js:47:13
Wed, 26 Aug 2020 18:35:44 GMT ️ -> Retrying in 2 seconds ... (2)
Wed, 26 Aug 2020 18:47:54 GMT detox[3663] WARN: at e2e/init.js:44:15
Worth noting that I bumped a timeout to 12mins I think, and apparently that's the per-test mocha inside-app timeout, when what I was hoping for was to give the app more time to connect to detox
If the application and test APK install steps could be separated from the test run and combined with a retry on the whole emulator bring-up loop, that would eliminate one more flake:
2020-08-26T18:12:52.3769020Z detox[4099] DEBUG: [exec.js/EXEC_CMD, #15] "/Users/runner/Library/Android/sdk/platform-tools/adb" -s emulator-5554 shell "pm install -r -g -t /data/local/tmp/detox/Application.apk"
2020-08-26T18:13:03.6529100Z detox[4099] TRACE: [exec.js/EXEC_SUCCESS, #15] Success
2020-08-26T18:13:03.6557430Z
2020-08-26T18:13:03.6577460Z detox[4099] DEBUG: [exec.js/EXEC_CMD, #16] "/Users/runner/Library/Android/sdk/platform-tools/adb" -s emulator-5554 push "/Users/runner/work/react-native-firebase/react-native-firebase/tests/android/app/build/outputs/apk/androidTest/debug/app-debug-androidTest.apk" "/data/local/tmp/detox/Test.apk"
2020-08-26T18:13:04.3642840Z detox[4099] TRACE: [exec.js/EXEC_SUCCESS, #16] /Users/runner/work/react-native-firebase/react-native-firebase/tests/android/app/build/outputs/apk/androidTest/debug/app-debug-androidTest.apk: 1 file pushed, 0 skipped. 9.0 MB/s (1629029 bytes in 0.172s)
2020-08-26T18:13:04.3741680Z
2020-08-26T18:13:04.3841520Z detox[4099] DEBUG: [exec.js/EXEC_CMD, #17] "/Users/runner/Library/Android/sdk/platform-tools/adb" -s emulator-5554 shell "pm install -r -g -t /data/local/tmp/detox/Test.apk"
2020-08-26T18:13:31.8217810Z detox[4099] ERROR: [exec.js/EXEC_FAIL, #17] ""/Users/runner/Library/Android/sdk/platform-tools/adb" -s emulator-5554 shell "pm install -r -g -t /data/local/tmp/detox/Test.apk"" failed with code = 20, stdout and stderr:
2020-08-26T18:13:31.8219420Z
2020-08-26T18:13:31.8225940Z detox[4099] ERROR: [exec.js/EXEC_FAIL, #17]
2020-08-26T18:13:31.8236480Z detox[4099] ERROR: [exec.js/EXEC_FAIL, #17] cmd: Can't find service: package
2020-08-26T18:13:31.8264170Z
2020-08-26T18:13:31.8265910Z detox[4099] ERROR: [DetoxExportWrapper.js/DETOX_INIT_ERROR]
2020-08-26T18:13:31.8267550Z ChildProcessError: Command failed: "/Users/runner/Library/Android/sdk/platform-tools/adb" -s emulator-5554 shell "pm install -r -g -t /data/local/tmp/detox/Test.apk"
Seeing some mysterious ones on android where the app is installed and detox runs the app start command, the app connects to jet and downloads the bundle, and then...nothing - nothing in detox or adb log. Adding some more instrumentation there (Java level system outs or similar on absolutely every single step) would help to see where the hookup is failing.
Flakes once a week (on Fridays currently) as Auth API rate limits must be raised above defaults, and that only lasts 7 days at a time
A new one, the firestore emulator failed - it looks like we have a custom script that itself calls a script - but ignores the sub-script's return status and continues waiting without timeout or retry:
Start Firestore Emulator
59m 38s
Tue, 01 Sep 2020 14:43:44 GMT EMULATOR_EXECUTABLE: qemu-system-x86_64-headless
Tue, 01 Sep 2020 14:43:44 GMT
Run cd ./.github/workflows/scripts && sh ./start-firestore-emulator.sh
Tue, 01 Sep 2020 14:43:44 GMT cd ./.github/workflows/scripts && sh ./start-firestore-emulator.sh
Tue, 01 Sep 2020 14:43:44 GMT shell: /bin/bash -e {0}
Tue, 01 Sep 2020 14:43:44 GMT env:
Tue, 01 Sep 2020 14:43:44 GMT CODECOV_TOKEN: ***
Tue, 01 Sep 2020 14:43:44 GMT EMULATOR_COMMAND: -avd TestingAVD -noaudio -gpu swiftshader_indirect -camera-back none -no-snapshot -no-window -no-boot-anim -nojni -memory 2048 -timezone 'Europe/London' -cores 2
Tue, 01 Sep 2020 14:43:44 GMT EMULATOR_EXECUTABLE: qemu-system-x86_64-headless
Tue, 01 Sep 2020 14:43:44 GMT Waiting for Firestore emulator to come online...
Tue, 01 Sep 2020 14:43:46 GMT ⚠ emulators: You are not currently authenticated so some features may not work correctly. Please run firebase login to authenticate the CLI.
Tue, 01 Sep 2020 14:43:46 GMT i emulators: Starting emulators: firestore
Tue, 01 Sep 2020 14:43:46 GMT ⚠ It appears you are running in a CI environment. You can avoid downloading the Firestore Emulator repeatedly by caching the /Users/runner/.cache/firebase/emulators directory.
Tue, 01 Sep 2020 14:43:46 GMT i firestore: downloading cloud-firestore-emulator-v1.11.7.jar...
Tue, 01 Sep 2020 14:43:46 GMT Waiting for Firestore emulator to come online...
Tue, 01 Sep 2020 14:43:47 GMT i emulators: Shutting down emulators.
Tue, 01 Sep 2020 14:43:47 GMT i firestore: Stopping Firestore Emulator
Tue, 01 Sep 2020 14:43:47 GMT
Tue, 01 Sep 2020 14:43:47 GMT Error: An unexpected error has occurred.
Tue, 01 Sep 2020 14:43:48 GMT Waiting for Firestore emulator to come online...
Tue, 01 Sep 2020 14:43:50 GMT Waiting for Firestore emulator to come online...
Tue, 01 Sep 2020 14:43:52 GMT Waiting for Firestore emulator to come online...
Tue, 01 Sep 2020 14:43:54 GMT Waiting for Firestore emulator to come online...
Tue, 01 Sep 2020 14:43:56 GMT Waiting for Firestore emulator to come online...
This is a new one! A TypeError, undefined!?
Tue, 01 Sep 2020 16:36:16 GMT 1) auth()
Tue, 01 Sep 2020 16:36:16 GMT "before each" hook for "exists after reload":
Tue, 01 Sep 2020 16:36:16 GMT TypeError: Cannot read property 'auth' of undefined
Tue, 01 Sep 2020 16:36:16 GMT at Context.<anonymous> (/Users/runner/work/react-native-firebase/react-native-firebase/packages/auth/e2e/rnReload.e2e.js:3:18)
Tue, 01 Sep 2020 16:36:16 GMT at processImmediate (internal/timers.js:456:21)
Tue, 01 Sep 2020 16:36:16 GMT
Tue, 01 Sep 2020 16:36:16 GMT
New flaky test on firestore.QuerySnapshot - it appears that the ios app hangs (which usually means it quietly crashed)
Tue, 17 Nov 2020 05:15:34 GMT firestore.QuerySnapshot
Tue, 17 Nov 2020 05:15:34 GMT ✓ is returned from a collection get()
Tue, 17 Nov 2020 05:15:34 GMT ✓ is returned from a collection onSnapshot()
Tue, 17 Nov 2020 05:15:35 GMT ✓ returns an array of DocumentSnapshots
Tue, 17 Nov 2020 05:15:35 GMT ✓ returns false if not empty
Tue, 17 Nov 2020 05:15:35 GMT ✓ returns true if empty
Tue, 17 Nov 2020 05:15:35 GMT ✓ returns a SnapshotMetadata instance
Tue, 17 Nov 2020 05:15:35 GMT ✓ returns a Query instance
Tue, 17 Nov 2020 05:15:35 GMT ✓ returns size as a number
Tue, 17 Nov 2020 05:15:35 GMT docChanges()
Tue, 17 Nov 2020 05:15:35 GMT ✓ throws if options is not an object
Tue, 17 Nov 2020 05:15:35 GMT ✓ throws if options.includeMetadataChanges is not a boolean
Tue, 17 Nov 2020 05:15:35 GMT ✓ throws if options.includeMetadataChanges is true, but snapshot does not include those changes
Tue, 17 Nov 2020 05:15:35 GMT ✓ returns an array of DocumentChange instances
Tue, 17 Nov 2020 05:15:35 GMT - returns the correct number of document changes if listening to metadata changes
Tue, 17 Nov 2020 05:15:35 GMT - returns the correct number of document changes if listening to metadata changes, but not including them in docChanges
Tue, 17 Nov 2020 05:15:35 GMT forEach()
Tue, 17 Nov 2020 05:15:35 GMT ✓ throws if callback is not a function
Tue, 17 Nov 2020 05:27:35 GMT detox[6530] INFO: at e2e/init.js:38:15
Down to just some new storage things at the moment...android storage cancel / pause upload I think
on android -
seen again 20210319 seen a lot 20210419 - this is becoming really troublesome
Thu, 04 Mar 2021 18:58:35 GMT 1) auth()
Thu, 04 Mar 2021 18:58:35 GMT "before each" hook for "returns the same user with multiple subscribers #1815":
Thu, 04 Mar 2021 18:58:35 GMT NativeFirebaseError: [auth/no-current-user] No user currently signed in.
1) auth()
onAuthStateChanged()
calls callback with the current user and when auth state changes:
expected 'spy' to be called twice but was called thrice
1) auth()
"before all" hook in "auth()":
NativeFirebaseError: [auth/unknown] An internal error has occurred. [ unexpected end of stream on com.android.okhttp.Address@c2602640 ]
on iOS, caught this again a couple days later and again on iOS 20210322:1341 again many times, most recent 20210510:1031
1) firestore.QuerySnapshot
})
docChanges()
returns the correct number of document changes if listening to metadata changes, but not including them in docChanges:
Error: Spy was not called within timeout period.
at Timeout._onTimeout (node_modules/@react-native-firebase/private-tests-helpers/lib/index.js:3:1104)