|
| 1 | +# firebase-functions-future-async-nested |
| 2 | + |
| 3 | +This repo is an example/test app to repro a problem I am seeing using https://github.com/firebase/firebase-cpp-sdk where `firebase::Future<firebase::functions::HttpsCallableResult>` |
| 4 | +appears to deadlock when nested inside a `Future::OnCompletion`. |
| 5 | + |
| 6 | +The problem happens on both the Emulator and the live project. |
| 7 | + |
| 8 | +Opened firebase-cpp-sdk Issue: https://github.com/firebase/firebase-cpp-sdk/issues/1621 |
| 9 | + |
| 10 | +Example... |
| 11 | + |
| 12 | +Works: |
| 13 | +```C++ |
| 14 | + auto value = Foo(); |
| 15 | + cout << "tid=" << pthread_self() << " Foo #1: value=" << value << endl; |
| 16 | + value = Foo(); |
| 17 | + cout << "tid=" << pthread_self() << " Foo #2: value=" << value << endl; |
| 18 | + auto future = FooAsync([](int value) { |
| 19 | + cout << "tid=" << pthread_self() << " FooAsync #1: value=" << value << endl; |
| 20 | + }); |
| 21 | + future = FooAsync([](int value) { |
| 22 | + cout << "tid=" << pthread_self() << " FooAsync #2: value=" << value << endl; |
| 23 | + }); |
| 24 | +``` |
| 25 | +
|
| 26 | +Deadlocks: |
| 27 | +```C++ |
| 28 | + future = FooAsync([](int value) { |
| 29 | + cout << "tid=" << pthread_self() << " FooAsync #3: value=" << value << endl; |
| 30 | + FooAsync([](int value) { // <- deadlocks a few levels into this call and firebase never logs it called the firebase function |
| 31 | + cout << "tid=" << pthread_self() << " FooAsync #4: value=" << value << endl; |
| 32 | + }); |
| 33 | + }); |
| 34 | +``` |
| 35 | + |
| 36 | +Log of the above 6 calls: |
| 37 | +```bash |
| 38 | +% ./FirebaseExample |
| 39 | +WARNING: Database URL not set in the Firebase config. |
| 40 | +DEBUG: Creating Firebase App __FIRAPP_DEFAULT for Firebase C++ 12.1.0 |
| 41 | +DEBUG: Validating semaphore creation. |
| 42 | +DEBUG: Added app name=__FIRAPP_DEFAULT: options, api_key=..., app_id=..., database_url=, messaging_sender_id=..., storage_bucket=..., project_id=... (0x...) |
| 43 | +Using Functions Emulator at 127.0.0.1:5001 |
| 44 | +tid=0x1fefccc00 +Foo(...) |
| 45 | +tid=0x1fefccc00 +Cloud::Call(`foo`, ...) |
| 46 | +tid=0x1fefccc00 Call: `foo` +Call(...) |
| 47 | +DEBUG: Calling Cloud Function with url: 127.0.0.1:5001/functions-futures-async-nested/us-central1/foo |
| 48 | +data: {"data":null} |
| 49 | +tid=0x1fefccc00 Call: `foo` -Call(...) |
| 50 | +tid=0x1fefccc00 ProcessEvents(100) |
| 51 | +DEBUG: Cloud Function response body = {"result":200} |
| 52 | +tid=0x1fefccc00 +OnCallCompleted(...) |
| 53 | +tid=0x1fefccc00 -OnCallCompleted(...) |
| 54 | +tid=0x1fefccc00 -Cloud::Call(`foo`, ...) |
| 55 | +tid=0x1fefccc00 -Foo(...) |
| 56 | +tid=0x1fefccc00 Foo #1: value=200 |
| 57 | +tid=0x1fefccc00 +Foo(...) |
| 58 | +tid=0x1fefccc00 +Cloud::Call(`foo`, ...) |
| 59 | +tid=0x1fefccc00 Call: `foo` +Call(...) |
| 60 | +DEBUG: Calling Cloud Function with url: 127.0.0.1:5001/functions-futures-async-nested/us-central1/foo |
| 61 | +data: {"data":null} |
| 62 | +tid=0x1fefccc00 Call: `foo` -Call(...) |
| 63 | +tid=0x1fefccc00 ProcessEvents(100) |
| 64 | +DEBUG: Cloud Function response body = {"result":200} |
| 65 | +tid=0x1fefccc00 +OnCallCompleted(...) |
| 66 | +tid=0x1fefccc00 -OnCallCompleted(...) |
| 67 | +tid=0x1fefccc00 -Cloud::Call(`foo`, ...) |
| 68 | +tid=0x1fefccc00 -Foo(...) |
| 69 | +tid=0x1fefccc00 Foo #2: value=200 |
| 70 | +tid=0x1fefccc00 +FooAsync(...) |
| 71 | +tid=0x1fefccc00 +Cloud::Call(`foo`, ...) |
| 72 | +tid=0x1fefccc00 Call: `foo` +Call(...) |
| 73 | +DEBUG: Calling Cloud Function with url: 127.0.0.1:5001/functions-futures-async-nested/us-central1/foo |
| 74 | +data: {"data":null} |
| 75 | +tid=0x1fefccc00 Call: `foo` -Call(...) |
| 76 | +DEBUG: Cloud Function response body = {"result":200} |
| 77 | +tid=0x16b7fb000 +OnCallCompleted(...) |
| 78 | +tid=0x16b7fb000 FooAsync #1: value=200 |
| 79 | +tid=0x16b7fb000 -OnCallCompleted(...) |
| 80 | +tid=0x1fefccc00 -Cloud::Call(`foo`, ...) |
| 81 | +tid=0x1fefccc00 -FooAsync(...) |
| 82 | +tid=0x1fefccc00 +FooAsync(...) |
| 83 | +tid=0x1fefccc00 +Cloud::Call(`foo`, ...) |
| 84 | +tid=0x1fefccc00 Call: `foo` +Call(...) |
| 85 | +DEBUG: Calling Cloud Function with url: 127.0.0.1:5001/functions-futures-async-nested/us-central1/foo |
| 86 | +data: {"data":null} |
| 87 | +tid=0x1fefccc00 Call: `foo` -Call(...) |
| 88 | +DEBUG: Cloud Function response body = {"result":200} |
| 89 | +tid=0x16b7fb000 +OnCallCompleted(...) |
| 90 | +tid=0x16b7fb000 FooAsync #2: value=200 |
| 91 | +tid=0x16b7fb000 -OnCallCompleted(...) |
| 92 | +tid=0x1fefccc00 -Cloud::Call(`foo`, ...) |
| 93 | +tid=0x1fefccc00 -FooAsync(...) |
| 94 | +tid=0x1fefccc00 +FooAsync(...) |
| 95 | +tid=0x1fefccc00 +Cloud::Call(`foo`, ...) |
| 96 | +tid=0x1fefccc00 Call: `foo` +Call(...) |
| 97 | +DEBUG: Calling Cloud Function with url: 127.0.0.1:5001/functions-futures-async-nested/us-central1/foo |
| 98 | +data: {"data":null} |
| 99 | +tid=0x1fefccc00 Call: `foo` -Call(...) |
| 100 | +DEBUG: Cloud Function response body = {"result":200} |
| 101 | +tid=0x16b7fb000 +OnCallCompleted(...) |
| 102 | +tid=0x16b7fb000 FooAsync #3: value=200 |
| 103 | +tid=0x16b7fb000 +FooAsync(...) |
| 104 | +tid=0x16b7fb000 +Cloud::Call(`foo`, ...) |
| 105 | +^C |
| 106 | +``` |
| 107 | + |
| 108 | +Note at the end that the app hung indefinitely before the 6th `DEBUG: Calling Cloud Function` was logged and I had to Ctrl-Break. |
| 109 | + |
| 110 | +I suspect this has something to do with the muxtex(s)/semaphore(s) used to track pending Futures and their OnCompletion. |
| 111 | + |
| 112 | +One **admittedly not directly related** hint I got about this was from https://github.com/firebase/firebase-cpp-sdk/issues/51#issuecomment-654535769 |
| 113 | +> In my case I resolved the issue by ensuring the HttpsCallableReference was not destroyed until the future had resolved. The destructor for this class releases the future and calls rest::CleanupTransportCurl() which I imagine is the cause of the problem. |
| 114 | +
|
| 115 | +It seems like the official code could stand for a bit more verbose logging around these areas... but what do I know? |
| 116 | + |
| 117 | +I am not certain if these issues are [closely?] related: |
| 118 | +* https://github.com/firebase/firebase-cpp-sdk/issues/61 |
| 119 | +* ... |
| 120 | + |
| 121 | +## To test/run/use... |
| 122 | + |
| 123 | +### firebase functions |
| 124 | +```bash |
| 125 | +cd firebase |
| 126 | +``` |
| 127 | + |
| 128 | +To run in emulator: |
| 129 | +```bash |
| 130 | +firebase emulators:start --only functions |
| 131 | +``` |
| 132 | + |
| 133 | +To deploy to firebase cloud: |
| 134 | +```bash |
| 135 | +firebase deploy --only functions |
| 136 | +``` |
| 137 | + |
| 138 | +### app |
| 139 | + |
| 140 | +To build: |
| 141 | +```bash |
| 142 | +cd app |
| 143 | + |
| 144 | +# once, or whenever firebase-cpp-sdk changes |
| 145 | +pushd libs |
| 146 | +./get-firebase-cpp-sdk.sh |
| 147 | +popd |
| 148 | + |
| 149 | +mkdir -p build && cd $_ |
| 150 | + |
| 151 | +# Define an Android app in your firebase project and download its google-services.json |
| 152 | +cp /path/to/your/google-services.json . |
| 153 | + |
| 154 | +# once, or whenever CMakeLists.txt changes |
| 155 | +cmake .. |
| 156 | + |
| 157 | +# whenever code changes |
| 158 | +cmake --build . |
| 159 | +``` |
| 160 | + |
| 161 | +To run [and use firebase emulator by default]: |
| 162 | +```bash |
| 163 | +./FirebaseExample |
| 164 | +``` |
| 165 | + |
| 166 | +To run and not use emulator [use firebase cloud]: |
| 167 | +```bash |
| 168 | +./FirebaseExample --no-emulator |
| 169 | +``` |
0 commit comments