firebase-tools
firebase-tools copied to clipboard
firebase
Firestore emulator sometimes fails on data export when stopped
Describe your environment:
- Operating System version: Windows 10
- Browser version: Chrome 88.0.4324.104
- Firebase SDK version: 8.0.0
- Firebase Product: Firestore local emulator
Problem: When I stop my local firestore emulator most of the time it exports the data fine. However sometimes is has an error and it deletes my export files so I lose all my data. Nothing seems to appear in the logs. I am using: firebase emulators:start --import=emulator/emulator-export-data --export-on-exit=emulator/emulator-export-data
Then: Ctrl+C to stop the emulator.
I get the following in the terminal:
i emulators: Received SIGINT (Ctrl-C) for the first time. Starting a clean shutdown. i emulators: Please wait for a clean shutdown or send the SIGINT (Ctrl-C) signal again to stop right now. i Automatically exporting data using --export-on-exit "emulator/emulator-export-data" please wait for the export to finish... i Found running emulator hub for project hivepass-dev at http://localhost:4401 i Deleting directory R:\hivepass\HivePassApp\emulator\emulator-export-data\firestore_export i Exporting data to: R:\hivepass\HivePassApp\emulator\emulator-export-data ! Export request failed, see emulator logs for more information. ! Automatic export to "emulator/emulator-export-data" failed, going to exit now... i emulators: Shutting down emulators. i ui: Stopping Emulator UI ! Emulator UI has exited upon receiving signal: SIGINT i hosting: Stopping Hosting Emulator i firestore: Stopping Firestore Emulator ! Firestore Emulator has exited upon receiving signal: SIGINT i auth: Stopping Authentication Emulator i hub: Stopping emulator hub i logging: Stopping Logging Emulator
There is not much in the firestore-debug.log in the root:
INFO: Detected non-HTTP/2 connection. Jan 28, 2021 12:46:37 PM io.gapi.emulators.netty.HttpVersionRoutingHandler channelRead INFO: Detected non-HTTP/2 connection. Jan 28, 2021 12:46:38 PM io.gapi.emulators.netty.HttpVersionRoutingHandler channelRead INFO: Detected non-HTTP/2 connection. Jan 28, 2021 12:46:38 PM io.gapi.emulators.netty.HttpVersionRoutingHandler channelRead INFO: Detected non-HTTP/2 connection. Jan 28, 2021 12:46:39 PM io.gapi.emulators.netty.HttpVersionRoutingHandler channelRead INFO: Detected non-HTTP/2 connection. Jan 28, 2021 12:46:39 PM io.gapi.emulators.netty.HttpVersionRoutingHandler channelRead INFO: Detected non-HTTP/2 connection.
Hi @madmacc, thanks for the report.
Would you mind expanding a bit about the steps you're taking before seeing this issue? For example, how much data is being saved? What SDKs are you using? Are you using any of the other emulators in conjunction with Firestore?
Sure @samhorlbeck. The data is only 130k. I am running the following emulators. Firestore, Auth, Functions However I am running the functions emulator as a separate instance as the functions folder is in a different project/location and I can't figure out how to run all of them with one command.
I am using v9.2.1 of the firebase-tools.
Let me know if you need any more information.
What is your general use case? Can you discern any particular action that reliably causes the data to not be saved correctly? Basically I'm just trying to get a sense of how we could start to debug this issue and potentially reproduce it.
Unfortunately not. I'm sure there is some reason but it seems random to me at this stage. I can run it loading the previously exported data. Add some more data and then stop it by hitting ctrl+c in the terminal. It will sometimes export ok and sometimes not. It only deletes the firestore_export folder not the firebase-export-metadata.json file.
At the moment when it is successful I manually copy the exported data to a safe location so it is not deleted.
I was hoping the logs would show something but they don't unless I am looking in the wrong place. Root of the project firestore-debug.log.
I am just testing an web application locally using the firebase js sdk and angularfire.
I just tried starting and stopping it about 10 times in a row and it worked every time. I tried adding some data, adding data from my app and even putting the computer into sleep mode and coming back out.
So not sure what it is but it is either time related or caused by something else.
I just had a similar issue after leaving my computer for a couple of hours in sleep mode. Slightly different error this time and at least it didn't delete the files this time!
Log is attached. Looks the same. I'm not sure if this is correct log file as it doesn't have much interesting in it.
i emulators: Received SIGINT (Ctrl-C) for the first time. Starting a clean shutdown. i emulators: Please wait for a clean shutdown or send the SIGINT (Ctrl-C) signal again to stop right now. i Automatically exporting data using --export-on-exit "emulator/emulator-export-data" please wait for the export to finish... ! Did not find any running emulators for project hivepass-dev. ! Automatic export to "emulator/emulator-export-data" failed, going to exit now... i emulators: Shutting down emulators. i ui: Stopping Emulator UI ! Emulator UI has exited upon receiving signal: SIGINT i hosting: Stopping Hosting Emulator i firestore: Stopping Firestore Emulator ! Firestore Emulator has exited upon receiving signal: SIGINT i auth: Stopping Authentication Emulator i hub: Stopping emulator hub ! hub: Error stopping emulator hub i logging: Stopping Logging Emulator firestore-debug.log
! Did not find any running emulators for project hivepass-dev.
The Emulator Suite writes a temporary file to keep track of the running instances, and looks like that file was deleted somehow before you terminated the suite. For example, Windows may delete those temporary files to reclaim disk space (especially if disk space is low), or it may be some other cleanup tools installed on your dev machine.
Right now, --export-on-exit relies on that file, but it doesn't have to -- I've created b/179048252 to track making it more reliable. Thanks again for the bug report!
@yuchenshi Ok that 2nd error above is because I am running two instances of the emulator. If I stop the functions emulator first it causes that problem. This is not the problem where it deletes the exported data files, it just fails to export. My cloud functions folder is in a different project directory so I have to run the functions emulator as a separate instance.
Unfortunately it doesn't resolved my original problem of it deleting the files though.
Glad we found that out! The export APIs cannot handle two instances running together yet, but the internal bug I've created above should be able to solve this.
In the meantime, have you considered creating symlinks so that your functions can be "part of" the main project directory? They are available on Windows 10 and you can ignore them in .gitignore (or similar) if you'd like to.
In the meantime, have you considered creating symlinks so that your functions can be "part of" the main project directory? They are available on Windows 10 and you can ignore them in
.gitignore(or similar) if you'd like to.
This is a good idea. I have not used them before but have had them on my todo list, I will give it a try. I tried a shortcut which of course did not work!
It must be common scenario for people that have multiple apps in their firebase project. Not sure why I am the only one who has brought it up.
Actually after some more testing the first issue with the deleted export data files is due to the two instances of the emulator running. But only if I start the firestore emulator first then the functions emulator and then stop the firestore emulator while the functions emulator is still running.
UPDATE: It seems to work well with symbolic links. I will update if any issues.
If anyone else want to do this the command on Windows is:
mklink /D "R:\firestore-project\functions" "R:\cloud-functions-proj\functions"
Am seeing this also on Mac, every other time my export files are either corrupted or missing data.
Will comeback with the detail
On macOS 11.1 with [email protected] I'm seeing something of the kind:
On WebStorm 2020.3.2 when using the "Run" button on emulators:start:
// package.json
"emulators:start": "firebase emulators:start --project=\"local-emulators\" --import=\"./a\" --export-on-exit=\"./a\""
The result is:
/Users/carlos.chida/.nvm/versions/node/v12.13.0/bin/node /usr/local/Cellar/yarn/1.22.5/libexec/bin/yarn.js run emulators:start
yarn run v1.22.10
$ firebase emulators:start --project="local-emulators" --import="./a" --export-on-exit="./a"
...
┌─────────────────────────────────────────────────────────────┐
│ ✔ All emulators ready! It is now safe to connect your app. │
│ i View Emulator UI at http://localhost:4000 │
└─────────────────────────────────────────────────────────────┘
### STOPPED THE PROCESS VIA WEBSTORM ###
i emulators: Received SIGINT (Ctrl-C) for the first time. Starting a clean shutdown.
i emulators: Please wait for a clean shutdown or send the SIGINT (Ctrl-C) signal again to stop right now.
i Automatically exporting data using --export-on-exit "./a" please wait for the export to finish...
⚠ Emulator UI has exited upon receiving signal: SIGINT
i Found running emulator hub for project local-emulators at http://localhost:4400
i Creating export directory /Users/carlos.chida/WebstormProjects/veriphi/functions/a
i Exporting data to: /Users/carlos.chida/WebstormProjects/veriphi/functions/a
But only the folder gets created without any contents. I'm assuming that WebStorm is not giving the process enough time after sending the interrupt signal.
On the other hand, when running yarn emulators:start, it works without problems. Nonetheless, it looks like it consumes much time after receiving the signal:
yarn emulators:start
yarn run v1.22.10
$ firebase emulators:start --project="local-emulators" --import="./a" --export-on-exit="./a"
...
### PRESSED ctrl-C
i emulators: Received SIGINT (Ctrl-C) for the first time. Starting a clean shutdown.
i emulators: Please wait for a clean shutdown or send the SIGINT (Ctrl-C) signal again to stop right now.
i Automatically exporting data using --export-on-exit "./import-export-data" please wait for the export to finish...
i Found running emulator hub for project local-emulators at http://localhost:4400
i Creating export directory /Users/carlos.chida/WebstormProjects/veriphi/functions/import-export-data
i Exporting data to: /Users/carlos.chida/WebstormProjects/veriphi/functions/import-export-data
i emulators: Received export request. Exporting data to /Users/carlos.chida/WebstormProjects/veriphi/functions/import-export-data.
$ ### NEW PROMPT!
➜ ✔ emulators: Export complete.
✔ Export complete
i emulators: Shutting down emulators.
i ui: Stopping Emulator UI
⚠ Emulator UI has exited upon receiving signal: SIGINT
i functions: Stopping Functions Emulator
i database: Stopping Database Emulator
i firestore: Stopping Firestore Emulator
i pubsub: Stopping Pub/Sub Emulator
⚠ functions: The Cloud Firestore emulator is not running, so calls to Firestore will affect production.
i auth: Stopping Authentication Emulator
i hub: Stopping emulator hub
$ ### ANOTHER NEW PROMPT
@carloschida Thanks for the report! Exporting may take a few seconds and if WebStorm isn't giving the emulator enough time to do the work, there isn't a ton we can do here. We suggest running emulators:start in a terminal and you may find the built-in WebStorm terminal emulator better than the "Run" button for your case. Anyway, feel free to contact WebStorm regarding the issue.
Not sure if it's related to this issue but a similar error is happening to a co-worker:
emulators: Export failed: Server Error. read ECONNRESET
Our emulator script:
firebase --emulators:exec --import="./exports/current" --export-on-exit --ui "next dev"
It's very hard to reproduce since it happens only sometimes. I haven't been able to reproduce it myself but I was wondering if you have any ideas of what this could be or what I could investigate.
Another thing I'm finding weird is that we have duplicated shutting down operations:
emulators: Received export request. Exporting data to /exports/current.
✔ emulators: Export complete.
✔ emulators: Export complete.
✔ Export complete
i emulators: Shutting down emulators.
i ui: Stopping Emulator UI
✔ Export complete
i emulators: Shutting down emulators.
i ui: Stopping Emulator UI
⚠ Emulator UI has exited upon receiving signal: SIGINT
i functions: Stopping Functions Emulator
i functions: Stopping Functions Emulator
i database: Stopping Database Emulator
i database: Stopping Database Emulator
i firestore: Stopping Firestore Emulator
i firestore: Stopping Firestore Emulator
i pubsub: Stopping Pub/Sub Emulator
i pubsub: Stopping Pub/Sub Emulator
i auth: Stopping Authentication Emulator
i auth: Stopping Authentication Emulator
i hub: Stopping emulator hub
i hub: Stopping emulator hub
i logging: Stopping Logging Emulator
i logging: Stopping Logging Emulator
You can see all operation happen twice. However, that seems to be related to the next dev script used by Next.js. That doesn't happen with other scripts (i.e. Jest in watch mode).
@wceolin This is an interesting case and would you be able to get the firebase-debug.log for this one? That may be helpful for troubleshooting what caused everything to happen twice.
@yuchenshi These are the logs my co-worker shared with me when she got that error:
Apr 27, 2021 4:50:13 PM com.google.cloud.datastore.emulator.firestore.webchannel.FirestoreV1WebChannelAdapter$FirestoreWriteHandler onClose
INFO: channel closed
Apr 27, 2021 4:50:43 PM io.gapi.emulators.netty.HttpVersionRoutingHandler channelRead
INFO: Detected non-HTTP/2 connection.
Apr 27, 2021 4:51:43 PM io.gapi.emulators.netty.HttpVersionRoutingHandler channelRead
INFO: Detected non-HTTP/2 connection.
Apr 27, 2021 4:52:28 PM io.gapi.emulators.netty.HttpVersionRoutingHandler channelRead
INFO: Detected non-HTTP/2 connection.
Apr 27, 2021 5:13:26 PM io.gapi.emulators.netty.HttpVersionRoutingHandler channelRead
INFO: Detected HTTP/2 connection.
Apr 27, 2021 5:13:33 PM io.gapi.emulators.netty.HttpVersionRoutingHandler channelRead
INFO: Detected non-HTTP/2 connection.
Apr 27, 2021 5:13:34 PM io.gapi.emulators.netty.HttpVersionRoutingHandler channelRead
INFO: Detected non-HTTP/2 connection.
*** shutting down gRPC server since JVM is shutting down
*** server shut down
@wceolin I appreciate the help, but we need the firebase-debug.log (created by CLI), not firestore-.
@yuchenshi Sorry. I wasn't able to find a firebase-debug.log file. There's only database-debug, firestore-debug, pubsub-debug, and ui-debug. Not sure if this helps but the database-debug.log had the following warning:
WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by io.netty.util.internal.ReflectionUtil (file:/Users/$username/.cache/firebase/emulators/firebase-database-emulator-v4.7.2.jar) to field sun.nio.ch.SelectorImpl.selectedKeys
WARNING: Please consider reporting this to the maintainers of io.netty.util.internal.ReflectionUtil
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
19:10:08.230 [NamespaceSystem-akka.actor.default-dispatcher-5] INFO akka.event.slf4j.Slf4jLogger - Slf4jLogger started
19:10:08.387 [main] INFO com.firebase.server.forge.App$ - Listening at 0.0.0.0:9000
19:35:26.787 [Thread-0] INFO com.firebase.server.forge.App$ - Attempting graceful shutdown.
19:35:26.799 [NamespaceSystem-akka.actor.default-dispatcher-10] INFO com.firebase.core.namespace.Terminator$Terminator - 1 actors left to terminate: project-name
19:35:26.805 [NamespaceSystem-akka.actor.default-dispatcher-10] INFO com.firebase.core.namespace.NamespaceActor - Stopping namespace actor for project-name
19:35:26.806 [NamespaceSystem-akka.actor.default-dispatcher-10] INFO com.firebase.core.namespace.NamespaceActor - Gauges removed for project-name
19:35:26.810 [Thread-0] INFO com.firebase.server.forge.App$ - Graceful shutdown complete.
Btw, this issue doesn't seem to happen when using emulators:start - only when using emulators:exec.
On macOS 11.1 with
[email protected]I'm seeing something of the kind:On WebStorm 2020.3.2 when using the "Run" button on
emulators:start:
As mentioned, in Webstorm I could handle it by using the Webstorm terminal and not the Run Configuration. However, that's strange.
This happens intermittently to me as well but only if I leave the emulators running for a few days and the machine goes through various wake and sleep cycles during that time.
I just came back to a project I had not run in the emulator for a few weeks and the data was gone again. Not sure how or when it happened. I assume it just didn't export correctly when I shut it down the last time. Can be quite frustrating as I need to regularly make a manual backup of the data in case this happens.
I'm still not able to consistently reproduce the "export failed" error but this issue is happening to 3 co-workers at the moment. In all cases, there's no firebase-debug.log file. Enabling the --debug flag, we got the following information:
emulators: Export failed: Server Error. read ECONNRESET
[2021-07-15T15:00:42.106Z] <<< HTTP RESPONSE 500 {"x-powered-by":"Express","vary":"Origin","content-type":"application/json; charset=utf-8","content-length":"43","etag":"W/\"2b-PTnaVGW4PHglIRlUWNl1/Oxt2Ys\"","date":"Thu, 15 Jul 2021 15:00:42 GMT","connection":"keep-alive","keep-alive":"timeout=5"}
[2021-07-15T15:00:42.107Z] <<< HTTP RESPONSE BODY Server Error. read ECONNRESET {"message":"Server Error. read ECONNRESET"}
⚠ Export request failed, see emulator logs for more information. {"name":"FirebaseError","children":[],"exit":1,"message":"Export request failed, see emulator logs for more information.","original":{"name":"FirebaseError","children":[],"context":{"body":{"message":"Server Error. read ECONNRESET","error":{"message":"Unknown Error"}},"response":{"statusCode":500,"body":{"message":"Server Error. read ECONNRESET","error":{"message":"Unknown Error"}},"headers":{"x-powered-by":"Express","vary":"Origin","content-type":"application/json; charset=utf-8","content-length":"43","etag":"W/\"2b-PTnaVGW4PHglIRlUWNl1/Oxt2Ys\"","date":"Thu, 15 Jul 2021 15:00:42 GMT","connection":"keep-alive","keep-alive":"timeout=5"},"request":{"uri":{"protocol":"http:","slashes":true,"auth":null,"host":"localhost:4400","port":"4400","hostname":"localhost","hash":null,"search":null,"query":null,"pathname":"/_admin/export","path":"/_admin/export","href":"http://localhost:4400/_admin/export"},"method":"POST"}}},"exit":2,"message":"HTTP Error: 500, Unknown Error","status":500},"status":500}
⚠ Automatic export to "./firebase-sdk/exports/current" failed, going to exit now...
Sometimes, we also get this:
logging: Stopping Logging Emulator
(node:3153) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'exit' of undefined
at /my-project/node_modules/firebase-tools/lib/command.js:92:40
at runMicrotasks (<anonymous>)
at processTicksAndRejections (internal/process/task_queues.js:97:5)
(node:3153)
That seems to come from this line suggesting that maybe the error is undefined?
These export failed issues seem to happening only when using the emulators:exec. We haven't seen them with emulators:start AFAIK.
I'm going to try digging more into the firebase-tools codebase to see if I can have a better understanding of what might be going on here but I'm posting the information above in case someone more familiar with the codebase has any ideas.
Can confirm the problem occurs when running firebase emulator within webstorm run window, but works fine in terminal.
I bought a new MacBook Air this week and the export failed error is happening every time on my new machine (I'm using the terminal, btw), which is weird because it's basically the same setup I have in another machine (a Mac Mini M1) where it doesn't happen.
Initially, I thought this could be because I was using Node 14 on my new machine and Node 12 in my old one (that's the only difference I could spot) but that's not the case since a co-worker told me she's having the same issue using Node 12.
This also doesn't seem to be OS specific. This is happening to two co-workers using Ubuntu, to another one using MacOS with an Intel processor, and now with me using MacOS with an M1 processor.
@yuchenshi is there a way to recover from this state? I seem to run into it occasionally when I make changes to my code that crash the function (I'm running tsc in watch mode).
We have this issue as well when we leave the emulator running for long times, is there a way to recover from this? The file the emulator writes can be saved somehow to be reused later when this happen in case it gets removed?
I have been having the same issue on Windows 10 (Firebase Tools version 10.7.1). It happens regardless of if the emulator has been running for a long time or just a minute or two, and when the amount of data is minimal (i.e., one collection with one document with one field). I try exporting emulator data to a local folder directory named data but when I shut down I get the following exported to my root directory:
When I run firebase emulators:start --export-on-exit=data, this is my PowerShell output:
i emulators: Starting emulators: auth, firestore, database, hosting, pubsub, storage
! emulators: It seems that you are running multiple instances of the emulator suite for project drew-daniels-wheres-waldo. This may result in unexpected behavior.
i firestore: Firestore Emulator logging to firestore-debug.log
i database: Database Emulator logging to database-debug.log
i pubsub: Pub/Sub Emulator logging to pubsub-debug.log
i hosting: Serving hosting files from: build
+ hosting: Local server: http://localhost:5000
i ui: Emulator UI logging to ui-debug.log
┌─────────────────────────────────────────────────────────────┐
│ ✔ All emulators ready! It is now safe to connect your app. │
│ i View Emulator UI at http://localhost:4000 │
└─────────────────────────────────────────────────────────────┘
┌────────────────┬────────────────┬─────────────────────────────────┐
│ Emulator │ Host:Port │ View in Emulator UI │
├────────────────┼────────────────┼─────────────────────────────────┤
│ Authentication │ localhost:9099 │ http://localhost:4000/auth │
├────────────────┼────────────────┼─────────────────────────────────┤
│ Firestore │ localhost:8080 │ http://localhost:4000/firestore │
├────────────────┼────────────────┼─────────────────────────────────┤
│ Database │ localhost:9000 │ http://localhost:4000/database │
├────────────────┼────────────────┼─────────────────────────────────┤
│ Hosting │ localhost:5000 │ n/a │
├────────────────┼────────────────┼─────────────────────────────────┤
│ Pub/Sub │ localhost:8085 │ n/a │
├────────────────┼────────────────┼─────────────────────────────────┤
│ Storage │ localhost:9199 │ http://localhost:4000/storage │
└────────────────┴────────────────┴─────────────────────────────────┘
Emulator Hub running at localhost:4400
Other reserved ports: 4500
Issues? Report them at https://github.com/firebase/firebase-tools/issues and attach the *-debug.log files.
Everything appears to run fine, but once I ctrl+C it appears that the emulator does not shut down gracefully:
i emulators: Received SIGINT (Ctrl-C) for the first time. Starting a clean shutdown.
i emulators: Please wait for a clean shutdown or send the SIGINT (Ctrl-C) signal again to stop right now.
i Automatically exporting data using --export-on-exit "data" please wait for the export to finish...
Terminate batch job (Y/N)? Error: Storage Emulator Rules runtime exited unexpectedly.
i Found running emulator hub for project (my-project-name) at http://localhost:4400
i Exporting data to: C:\Users\MyUserName\my\folder\project\data
i emulators: Received export request. Exporting data to C:\Users\MyUserName\my\folder\project\data.
What I have tried:
- Changing the relative file paths from ./data to data
- Ensuring all java.exe instances are closed (via task manager)
- Restarting my computer
Made an SO post on this yesterday: https://stackoverflow.com/questions/71972842/firebase-emulator-export-on-exit-not-working-properly-windows-10?noredirect=1#comment127180514_71972842
My co-worker was having the exact same issue as described above by @Drew-Daniels , and I wasn't. He was also seeing 2 java terminal's open, but I wasn't. After upgrading to the latest firebase-tools I started getting a warning that I need to upgrade Java to at least v11 (not sure what I had initially or why it was so old). So I upgrade Java to v18, now I am seeing the 2 java terminals open when the emulator starts, and my emulator data is getting exported to a folder at my project root instead of the export location. Before upgrading Java it seemed to create this root folder for a few seconds on shutdown, then move the contents over, now it seems like something is interrupting the process halfway through. I'm tagging @yuchenshi and @weixifan since this seems to at give some insight into a change that can initiate the issue. Let me know if I should create a new issue or if you think this is related.
Update: I tried rolling back Java JDK to v11, but that didn't help. Looks like the Java terminal's don't like how they are being shut down, which is maybe what is causing the process of moving the export files to the desired folder not to happen.
Here is what the Java terminals look like before shutting down.
And here is after hitting ctrl + c from the terminal running the emulator.
