Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Firestore writes not working for a Node.js CLI app beyond version 6.0.0. Version 5.11.1 works. #2135

Closed
ssarangi opened this issue Sep 1, 2019 · 1 comment · Fixed by #2137
Assignees

Comments

@ssarangi
Copy link

ssarangi commented Sep 1, 2019

  • Operating System version: Mac OSX Mojave (10.14.6)
  • Browser version: 76.0.3809.132
  • Firebase SDK version: 6.4.1
  • Firebase Product: firestore

Node.js version: 11.9.0

[REQUIRED] Describe the problem

Firestore writes hang on a simple node.js CLI application. I have a simple node.js cli app which logs in a user and then writes some data to firestore. Once the write starts, the promise neither hits the success callback or the error callback. It just sits there doing nothing. Am not sure if the way I am waiting for the promises is wrong or not but the behavior is definitely different on the node.js cli. Firestore rules are in test mode.

From the logs, the main thing I notice is that in the older versions of the sdk, the user is initialized to the right user. However, in versions beyond 6, the logs indicate the user is initialized to null and then in between the process, the user changes to the right user.

Steps to reproduce:

Relevant Code:

Create a simple Node.js application and paste the code below. Try with versions 5.11.1 & 6.4.1.

const firebase = require("firebase");

/**
 * Initialize Firebase
 *
 * NOTE: This will be publically visible
 * please don't accidentally publish your
 * actual production credentials here.
 * Create a sample project that mimics
 * your setup to reproduce the error.
 */
var firebaseConfig = {
  apiKey: "AIzaSyDgYqoskKfwRXDHDJmbNCc7WCtUG1QCU5U",
  authDomain: "firestore-test-ded29.firebaseapp.com",
  databaseURL: "https://firestore-test-ded29.firebaseio.com",
  projectId: "firestore-test-ded29",
  storageBucket: "",
  messagingSenderId: "405012826015",
  appId: "1:405012826015:web:13098418d04e101a"
};
// Initialize Firebase
firebase.initializeApp(firebaseConfig);
firebase.firestore.setLogLevel("debug");

// Reproduce Issue below
// ...

async function login() {
  cred = await firebase
    .auth()
    .signInWithEmailAndPassword("[email protected]", "test123");
  return cred;
}

async function write() {
  result = await firebase
    .firestore()
    .collection("UserData")
    .doc("test")
    .collection("ShellCommands")
    .add({ Hello: "World" });
  return result;
}

async function main() {
  cred = await login();
  result = await write();
}

(async () => {
  try {
    await main();
  } catch (e) {
    // Deal with the fact the chain failed
    console.log(e);
  }
})();

Logs With 5.11.1

[2019-09-01T08:08:46.040Z] @firebase/firestore: Firestore (5.11.0) [FirestoreClient]: Initializing. user= PAnYLncZJobOGdNgXyoyATMklIA3
[2019-09-01T08:08:46.094Z] @firebase/firestore: Firestore (5.11.0) [MemoryPersistence]: Starting transaction: Get last stream token
[2019-09-01T08:08:46.095Z] @firebase/firestore: Firestore (5.11.0) [MemoryPersistence]: Starting transaction: Get next mutation batch
[2019-09-01T08:08:46.096Z] @firebase/firestore: Firestore (5.11.0) [MemoryPersistence]: Starting transaction: Locally write mutations
[2019-09-01T08:08:46.099Z] @firebase/firestore: Firestore (5.11.0) [MemoryPersistence]: Starting transaction: notifyLocalViewChanges
[2019-09-01T08:08:46.099Z] @firebase/firestore: Firestore (5.11.0) [MemoryPersistence]: Starting transaction: Get next mutation batch
[2019-09-01T08:08:46.100Z] @firebase/firestore: Firestore (5.11.0) [MemoryPersistence]: Starting transaction: Get next mutation batch
[2019-09-01T08:08:46.101Z] @firebase/firestore: Firestore (5.11.0) [Connection]: Creating Firestore stub.
[2019-09-01T08:08:46.104Z] @firebase/firestore: Firestore (5.11.0) [Connection]: Opening GRPC stream
(node:19755) DeprecationWarning: grpc.load: Use the @grpc/proto-loader module with grpc.loadPackageDefinition instead
[2019-09-01T08:08:46.108Z] @firebase/firestore: Firestore (5.11.0) [Connection]: GRPC stream sending: { database: 'projects/firestore-test-ded29/databases/(default)' }
[2019-09-01T08:08:46.489Z] @firebase/firestore: Firestore (5.11.0) [Connection]: GRPC stream received: { streamId: '0',
streamToken: <Buffer 19 10 68 42 02 81 f4 b5 b5>,
writeResults: [],
commitTime: null }
[2019-09-01T08:08:46.490Z] @firebase/firestore: Firestore (5.11.0) [MemoryPersistence]: Starting transaction: Set last stream token
[2019-09-01T08:08:46.491Z] @firebase/firestore: Firestore (5.11.0) [Connection]: GRPC stream sending: { streamToken: <Buffer 19 10 68 42 02 81 f4 b5 b5>,
writes:
[ { update:
{ name:
'projects/firestore-test-ded29/databases/(default)/documents/UserData/test/ShellCommands/c4MMN7K955CxrbZlSPkg',
fields: { Hello: { stringValue: 'World' } } } } ] }
[2019-09-01T08:08:46.657Z] @firebase/firestore: Firestore (5.11.0) [Connection]: GRPC stream received: { streamId: '',
streamToken: <Buffer 10 01 19 10 68 42 02 81 f4 b5 b5>,
writeResults:
[ { updateTime: { seconds: '1567325326', nanos: 613081000 },
transformResults: [] } ],
commitTime: { seconds: '1567325326', nanos: 613081000 } }
[2019-09-01T08:08:46.659Z] @firebase/firestore: Firestore (5.11.0) [MemoryPersistence]: Starting transaction: Acknowledge batch
[2019-09-01T08:08:46.661Z] @firebase/firestore: Firestore (5.11.0) [MemoryPersistence]: Starting transaction: notifyLocalViewChanges
[2019-09-01T08:08:46.662Z] @firebase/firestore: Firestore (5.11.0) [MemoryPersistence]: Starting transaction: Get next mutation batch

Logs with versions beyond 6.0.0

[2019-09-01T08:10:07.476Z] @firebase/firestore: Firestore (6.4.1) [FirestoreClient]: Initializing. user= null
[2019-09-01T08:10:07.559Z] @firebase/firestore: Firestore (6.4.1) [MemoryPersistence]: Starting transaction: Get last stream token
[2019-09-01T08:10:07.560Z] @firebase/firestore: Firestore (6.4.1) [MemoryPersistence]: Starting transaction: Get next mutation batch
[2019-09-01T08:10:07.562Z] @firebase/firestore: Firestore (6.4.1) [MemoryPersistence]: Starting transaction: Locally write mutations
[2019-09-01T08:10:07.564Z] @firebase/firestore: Firestore (6.4.1) [MemoryPersistence]: Starting transaction: notifyLocalViewChanges
[2019-09-01T08:10:07.565Z] @firebase/firestore: Firestore (6.4.1) [MemoryPersistence]: Starting transaction: Get next mutation batch
[2019-09-01T08:10:07.565Z] @firebase/firestore: Firestore (6.4.1) [MemoryPersistence]: Starting transaction: Get next mutation batch
[2019-09-01T08:10:07.569Z] @firebase/firestore: Firestore (6.4.1) [Connection]: Creating Firestore stub.
[2019-09-01T08:10:07.572Z] @firebase/firestore: Firestore (6.4.1) [Connection]: Opening GRPC stream
[2019-09-01T08:10:07.572Z] @firebase/firestore: Firestore (6.4.1) [FirestoreClient]: Credential Changed. Current user: PAnYLncZJobOGdNgXyoyATMklIA3
[2019-09-01T08:10:07.573Z] @firebase/firestore: Firestore (6.4.1) [MemoryPersistence]: Starting transaction: Handle user change
[2019-09-01T08:10:07.574Z] @firebase/firestore: Firestore (6.4.1) [MemoryPersistence]: Starting transaction: notifyLocalViewChanges
[2019-09-01T08:10:07.574Z] @firebase/firestore: Firestore (6.4.1) [RemoteStore]: RemoteStore restarting streams for new credential
[2019-09-01T08:10:07.575Z] @firebase/firestore: Firestore (6.4.1) [Connection]: GRPC stream closed locally via close().
[2019-09-01T08:10:07.575Z] @firebase/firestore: Firestore (6.4.1) [RemoteStore]: Stopping write stream with 1 pending writes
[2019-09-01T08:10:07.575Z] @firebase/firestore: Firestore (6.4.1) [MemoryPersistence]: Starting transaction: Get last stream token
[2019-09-01T08:10:07.575Z] @firebase/firestore: Firestore (6.4.1) [MemoryPersistence]: Starting transaction: Get next mutation batch
[2019-09-01T08:10:07.575Z] @firebase/firestore: Firestore (6.4.1) [PersistentStream]: stream callback skipped by getCloseGuardedDispatcher.
[2019-09-01T08:10:07.577Z] @firebase/firestore: Firestore (6.4.1) [PersistentStream]: stream callback skipped by getCloseGuardedDispatcher.
[2019-09-01T08:10:07.721Z] @firebase/firestore: Firestore (6.4.1) [Connection]: GRPC stream ended.

@rsgowman
Copy link
Member

rsgowman commented Sep 3, 2019

I can reproduce this (on at least 6.x; haven't tried 5.x). I'll look into it.

In the meantime, as a workaround you could try initializing firestore before logging in, i.e.:

...
firebase.initializeApp(firebaseConfig);
firebase.firestore.setLogLevel("debug");
firebase.firestore();  // Add this line!
...

@rsgowman rsgowman self-assigned this Sep 3, 2019
rsgowman added a commit that referenced this issue Sep 3, 2019
#2078 altered the
initial state of currentUser from undefined to not undefined, which
caused the if statement to unconditionally evaluate to true. This
results in a race condition that could cause some initial writes to the
database to be dropped.

Fixes #2135
Feiyang1 pushed a commit that referenced this issue Sep 3, 2019
* Avoid auth triggers if we haven't yet received the initial user.

#2078 altered the
initial state of currentUser from undefined to not undefined, which
caused the if statement to unconditionally evaluate to true. This
results in a race condition that could cause some initial writes to the
database to be dropped.

Fixes #2135

* CHANGELOG update.

* Fix to be more like android
@firebase firebase locked and limited conversation to collaborators Oct 8, 2019
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants