googleapis / nodejs-firestore

Node.js client for Google Cloud Firestore: a NoSQL document database built for automatic scaling, high performance, and ease of application development.
https://cloud.google.com/firestore/
Apache License 2.0
641 stars 149 forks source link

ignoreUndefinedProperties causes error #1629

Closed joshpetit closed 2 years ago

joshpetit commented 2 years ago

Environment details

So I'm using firestore through the firebase-admin sdk and have had some trouble since enabling the ignoreUndefinedProperties field.

I created a file called admin.ts and import this file into user.ts and user.test.ts

Within admin.ts I have this code:

import * as firebaseAdmin from "firebase-admin";
firebaseAdmin.initializeApp();
firebaseAdmin.firestore().settings({ignoreUndefinedProperties: true});
export default firebaseAdmin;

I just recently added ignoreUndefinedProperties since an update function I created may have some undefined values in the object. After doing this I receive this error:

   2 UNKNOWN:

      27 |   //   {projectId: process.env.GCLOUD_PROJECT ?? ""}
      28 |   // );
    > 29 |   await admin.firestore().doc(`users/${USER_ID}`).delete();
         |                                                         ^
      30 |   await admin.firestore().doc(`publicProfile/${USER_ID}`).delete();
      31 | });
      32 |

      at Object.callErrorFromStatus (node_modules/@grpc/grpc-js/src/call.ts:81:24)
      at Object.onReceiveStatus (node_modules/@grpc/grpc-js/src/client.ts:338:36)
      at Object.onReceiveStatus (node_modules/@grpc/grpc-js/src/client-interceptors.ts:426:34)
      at Object.onReceiveStatus (node_modules/@grpc/grpc-js/src/client-interceptors.ts:389:48)
      at node_modules/@grpc/grpc-js/src/call-stream.ts:276:24
      Caused by: Error:
      at WriteBatch.commit (node_modules/@google-cloud/firestore/build/src/write-batch.js:414:23)
      at DocumentReference.delete (node_modules/@google-cloud/firestore/build/src/reference.js:321:14)
      at Object.<anonymous> (test/user.test.ts:29:57)

This is inside the testing file where I delete user documents before running a test.

I initially thought that this was just because the test may be messing up, but after running the emulator a similar error was thrown. This is the output of the log:

Error ``` Nov 08, 2021 5:43:16 AM com.google.cloud.datastore.emulator.impl.util.WrappedStreamObserver onError INFO: operation failed: Invalid pattern. Reason: [71:] Unexpected end of input at start of path segment. java.lang.IllegalArgumentException: Invalid pattern. Reason: [71:] Unexpected end of input at start of path segment. at com.google.common.base.Preconditions.checkArgument(Preconditions.java:147) at com.google.firebase.rules.eventflow.client.path.PathPattern.compileInternal(PathPattern.java:78) at com.google.firebase.rules.eventflow.client.path.PathPattern.compile(PathPattern.java:50) at com.google.firebase.rules.eventflow.client.EventRuleEvaluatorImpl.lambda$new$0(EventRuleEvaluatorImpl.java:58) at com.google.common.collect.ImmutableList.forEach(ImmutableList.java:447) at com.google.firebase.rules.eventflow.client.EventRuleEvaluatorImpl.(EventRuleEvaluatorImpl.java:52) at com.google.firebase.rules.eventflow.client.EventRuleEvaluatorImpl.(EventRuleEvaluatorImpl.java:39) at com.google.cloud.datastore.emulator.impl.events.EventManager.reportEvents(EventManager.java:84) at com.google.cloud.datastore.emulator.impl.CloudFirestoreV1.commitHelper(CloudFirestoreV1.java:891) at com.google.cloud.datastore.emulator.impl.CloudFirestoreV1.internalCommit(CloudFirestoreV1.java:780) at com.google.cloud.datastore.emulator.impl.CloudFirestoreV1.commit(CloudFirestoreV1.java:416) at com.google.cloud.datastore.emulator.impl.CloudFirestoreV1Router.commit(CloudFirestoreV1Router.java:137) at com.google.cloud.datastore.emulator.firestore.v1.FirestoreV1GrpcAdapter$1.lambda$commit$8(FirestoreV1GrpcAdapter.java:156) at com.google.cloud.datastore.emulator.firestore.v1.FirestoreV1GrpcAdapter.unary(FirestoreV1GrpcAdapter.java:67) at com.google.cloud.datastore.emulator.firestore.v1.FirestoreV1GrpcAdapter.access$000(FirestoreV1GrpcAdapter.java:39) at com.google.cloud.datastore.emulator.firestore.v1.FirestoreV1GrpcAdapter$1.commit(FirestoreV1GrpcAdapter.java:156) at com.google.firestore.v1.FirestoreGrpc$MethodHandlers.invoke(FirestoreGrpc.java:1224) at io.grpc.stub.ServerCalls$UnaryServerCallHandler$UnaryServerCallListener.onHalfClose(ServerCalls.java:182) at io.grpc.PartialForwardingServerCallListener.onHalfClose(PartialForwardingServerCallListener.java:35) at io.grpc.ForwardingServerCallListener.onHalfClose(ForwardingServerCallListener.java:23) at io.grpc.ForwardingServerCallListener$SimpleForwardingServerCallListener.onHalfClose(ForwardingServerCallListener.java:40) at io.grpc.Contexts$ContextualizedServerCallListener.onHalfClose(Contexts.java:86) at io.grpc.PartialForwardingServerCallListener.onHalfClose(PartialForwardingServerCallListener.java:35) at io.grpc.ForwardingServerCallListener.onHalfClose(ForwardingServerCallListener.java:23) at io.grpc.ForwardingServerCallListener$SimpleForwardingServerCallListener.onHalfClose(ForwardingServerCallListener.java:40) at io.grpc.Contexts$ContextualizedServerCallListener.onHalfClose(Contexts.java:86) at io.grpc.internal.ServerCallImpl$ServerStreamListenerImpl.halfClosed(ServerCallImpl.java:331) at io.grpc.internal.ServerImpl$JumpToApplicationThreadServerStreamListener$1HalfClosed.runInContext(ServerImpl.java:866) at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37) at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:133) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) at java.base/java.lang.Thread.run(Thread.java:833) ```

I looked into similar errors and found this, but don't see the merge property on the settings object.

When I remove ignoreUndefinedProperties from the settings everything works perfectly, so I'm assuming it has something to do with it. If I can't find a solution I'll likely just use this to clean objects before trying to set or update documents.

I've read countless SO posts and haven't found anything similar to this, so help would be really appreciated!

Steps to reproduce

  1. Use ignoreUndefinedProperties

Making sure to follow these steps will guarantee the quickest resolution possible.

Thanks!

schmidt-sebastian commented 2 years ago

@joshpetit Thanks for reporting this. It sounds like your request may be malformed. Are you able to turn on debug logging, which will let us know what the request looks like? You should be able to do so by invoking admin.firestore.setLogFunction(console.log).

joshpetit commented 2 years ago

@schmidt-sebastian I'm sorry, I wont be able to touch the code for about 10 days right now, if it's alright with you could you keep the issue open until then?

schmidt-sebastian commented 2 years ago

@joshpetit Yes, that should be fine.

joshpetit commented 2 years ago

I'm back and thank you for your patience! I turned on debug logging and this is the output I get:

 console.log
      Firestore (4.13.1) 2021-11-29T13:20:03.554Z GM9oq [WriteBatch.commit]: Sending 1 writes

      at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9)

    console.log
      Firestore (4.13.1) 2021-11-29T13:20:03.559Z GM9oq [ClientPool.acquire]: Creating a new client

      at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9)

    console.log
      Firestore (4.13.1) 2021-11-29T13:20:03.684Z ##### [Firestore]: Initialized Firestore GAPIC Client

      at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9)

    console.log
      Firestore (4.13.1) 2021-11-29T13:20:03.684Z GM9oq [Firestore.request]: Sending request: {"database":"projects/milestone-five-dev/databases/(default)","writes":[{"delete":"projects/milestone-five-dev/databases/(default)/documents/users/user_id"}]}

      at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9)

    console.log
      Firestore (4.13.1) 2021-11-29T13:20:03.738Z GM9oq [Firestore.request]: Received error: Error: 2 UNKNOWN:
          at Object.callErrorFromStatus (/home/joshu/projects/petit.dev/milestone5/firebase/functions/node_modules/@grpc/grpc-js/src/call.ts:81:24)
          at Object.onReceiveStatus (/home/joshu/projects/petit.dev/milestone5/firebase/functions/node_modules/@grpc/grpc-js/src/client.ts:338:36)
          at Object.onReceiveStatus (/home/joshu/projects/petit.dev/milestone5/firebase/functions/node_modules/@grpc/grpc-js/src/client-interceptors.ts:426:34)
          at Object.onReceiveStatus (/home/joshu/projects/petit.dev/milestone5/firebase/functions/node_modules/@grpc/grpc-js/src/client-interceptors.ts:389:48)
          at /home/joshu/projects/petit.dev/milestone5/firebase/functions/node_modules/@grpc/grpc-js/src/call-stream.ts:276:24
          at processTicksAndRejections (internal/process/task_queues.js:75:11) {
        code: 2,
        details: '',
        metadata: Metadata {
          internalRepr: Map(1) { 'content-type' => [Array] },
          options: {}
        },
        note: 'Exception occurred in retry method that was not classified as transient'
      }

      at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9)

    console.log
      Firestore (4.13.1) 2021-11-29T13:20:03.743Z 21czJ [WriteBatch.commit]: Sending 1 writes

      at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9)

    console.log
      Firestore (4.13.1) 2021-11-29T13:20:03.743Z 21czJ [ClientPool.acquire]: Re-using existing client with 100 remaining operations

      at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9)

    console.log
      Firestore (4.13.1) 2021-11-29T13:20:03.743Z 21czJ [Firestore.request]: Sending request: {"database":"projects/milestone-five-dev/databases/(default)","writes":[{"delete":"projects/milestone-five-dev/databases/(default)/documents/users/user_id"}]}

      at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9)
schmidt-sebastian commented 2 years ago

This is very strange. The bit from the log that performs the request looks valid:

Sending request: {"database":"projects/milestone-five-dev/databases/(default)","writes":[{"delete":"projects/milestone-five-dev/databases/(default)/documents/users/user_id"}]}

Would you be able to provide the same logs without ignoreUndefinedProperties? I am a little perplexed.

joshpetit commented 2 years ago

It's actually very strange, if I rerun the tests, one of them will fail but if I rerun the tests a lot of times eventually all of them will pass 😅. My tear down function in the tests does everything correctly afaik, but running tests and the emulators I still encounter problems. Here's the whole log output:

Entire Log

console.warn {"severity":"WARNING","message":"Warning, estimating Firebase Config based on GCLOUD_PROJECT. Initializing firebase-admin may fail"} at write (node_modules/firebase-functions/lib/logger.js:39:78) at Object.warn (node_modules/firebase-functions/lib/logger.js:90:5) at Object.setup (node_modules/firebase-functions/lib/setup.js:46:22) at Object. (node_modules/firebase-functions/lib/index.js:67:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.178Z ##### [Firestore]: Initialized Firestore at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.323Z BFBh0 [WriteBatch.commit]: Sending 1 writes at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.327Z BFBh0 [ClientPool.acquire]: Creating a new client at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.445Z ##### [Firestore]: Initialized Firestore GAPIC Client at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.446Z BFBh0 [Firestore.request]: Sending request: {"database":"projects/not-a-project/databases/(default)","writes":[{"delete":"projects/not-a-project/databases/(default)/documents/users/user_id"}]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.475Z BFBh0 [Firestore.request]: Received response: {"writeResults":[{"transformResults":[],"updateTime":null}],"commitTime":{"seconds":"1638270516","nanos":468292000}} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.476Z S7CrR [WriteBatch.commit]: Sending 1 writes at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.476Z S7CrR [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.476Z S7CrR [Firestore.request]: Sending request: {"database":"projects/not-a-project/databases/(default)","writes":[{"delete":"projects/not-a-project/databases/(default)/documents/publicProfile/user_id"}]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.479Z S7CrR [Firestore.request]: Received response: {"writeResults":[{"transformResults":[],"updateTime":null}],"commitTime":{"seconds":"1638270516","nanos":478055000}} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.495Z yQQDW [WriteBatch.commit]: Sending 1 writes at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.497Z yQQDW [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.497Z yQQDW [Firestore.request]: Sending request: {"database":"projects/not-a-project/databases/(default)","writes":[{"update":{"name":"projects/not-a-project/databases/(default)/documents/users/user_id","fields":{"firstName":{"stringValue":"James"},"email":{"stringValue":"email@email.com"},"phoneNumber":{"stringValue":"222-222-2222"},"birthDate":{"stringValue":"May 10"},"lastName":{"stringValue":"Peterson"},"profileURL":{"stringValue":"image_url"},"lifeEvents":{"arrayValue":{}}}}}]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.502Z yQQDW [Firestore.request]: Received response: {"writeResults":[{"transformResults":[],"updateTime":{"seconds":"1638270516","nanos":501822000}}],"commitTime":{"seconds":"1638270516","nanos":501822000}} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.503Z 84hrE [WriteBatch.commit]: Sending 1 writes at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.504Z 84hrE [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.504Z 84hrE [Firestore.request]: Sending request: {"database":"projects/not-a-project/databases/(default)","writes":[{"update":{"name":"projects/not-a-project/databases/(default)/documents/publicProfile/user_id","fields":{"firstName":{"stringValue":"James"},"lastName":{"stringValue":"Peterson"},"profileURL":{"stringValue":"image_url"},"uid":{"stringValue":"user_id"}}},"updateMask":{"fieldPaths":["firstName","lastName","profileURL","uid"]}}]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.507Z 84hrE [Firestore.request]: Received response: {"writeResults":[{"transformResults":[],"updateTime":{"seconds":"1638270516","nanos":506791000}}],"commitTime":{"seconds":"1638270516","nanos":506791000}} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.508Z M4tTi [WriteBatch.commit]: Sending 1 writes at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.508Z M4tTi [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.509Z M4tTi [Firestore.request]: Sending request: {"database":"projects/not-a-project/databases/(default)","writes":[{"update":{"name":"projects/not-a-project/databases/(default)/documents/users/user_id/private/friends","fields":{"friends":{"arrayValue":{}},"deniedFriends":{"arrayValue":{}},"friendRequests":{"arrayValue":{}},"friendIds":{"arrayValue":{}}}}}]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.514Z M4tTi [Firestore.request]: Received response: {"writeResults":[{"transformResults":[],"updateTime":{"seconds":"1638270425","nanos":568732000}}],"commitTime":{"seconds":"1638270516","nanos":513634000}} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.515Z LIkHf [WriteBatch.commit]: Sending 1 writes at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.515Z LIkHf [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.515Z LIkHf [Firestore.request]: Sending request: {"database":"projects/not-a-project/databases/(default)","writes":[{"update":{"name":"projects/not-a-project/databases/(default)/documents/users/user_id/private/settings","fields":{"pushNotifications":{"booleanValue":true},"emailNotifications":{"booleanValue":true},"textNotifications":{"booleanValue":true}}}}]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.518Z LIkHf [Firestore.request]: Received response: {"writeResults":[{"transformResults":[],"updateTime":{"seconds":"1638270425","nanos":573481000}}],"commitTime":{"seconds":"1638270516","nanos":517176000}} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.520Z ME75t [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.520Z ME75t [Firestore.requestStream]: Sending request: {"database":"projects/not-a-project/databases/(default)","documents":["projects/not-a-project/databases/(default)/documents/users/user_id"]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.528Z ME75t [Firestore.requestStream]: Received response: {"transaction":{"type":"Buffer","data":[]},"readTime":{"seconds":"1638270516","nanos":525467000},"found":{"fields":{"profileURL":{"stringValue":"image_url","valueType":"stringValue"},"lastName":{"stringValue":"Peterson","valueType":"stringValue"},"birthDate":{"stringValue":"May 10","valueType":"stringValue"},"firstName":{"stringValue":"James","valueType":"stringValue"},"phoneNumber":{"stringValue":"222-222-2222","valueType":"stringValue"},"email":{"stringValue":"email@email.com","valueType":"stringValue"},"lifeEvents":{"arrayValue":{"values":[{"stringValue":"yjFH7fp79vQ6OpiUyQHM","valueType":"stringValue"},{"stringValue":"yjFH7fp79vQ6OpiUyQHM","valueType":"stringValue"}]},"valueType":"arrayValue"}},"name":"projects/not-a-project/databases/(default)/documents/users/user_id","createTime":{"seconds":"1638270516","nanos":501822000},"updateTime":{"seconds":"1638270516","nanos":524601000}},"result":"found"} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.528Z ME75t [Firestore._initializeStream]: Releasing stream at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.529Z ME75t [DocumentReader.fetchDocuments]: Received document: projects/not-a-project/databases/(default)/documents/users/user_id at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.530Z ME75t [Firestore._initializeStream]: Received stream end at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.531Z ME75t [DocumentReader.fetchDocuments]: Received 1 results at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.539Z JCC84 [WriteBatch.commit]: Sending 1 writes at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.539Z JCC84 [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.539Z JCC84 [Firestore.request]: Sending request: {"database":"projects/not-a-project/databases/(default)","writes":[{"delete":"projects/not-a-project/databases/(default)/documents/users/user_id"}]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.542Z JCC84 [Firestore.request]: Received response: {"writeResults":[{"transformResults":[],"updateTime":null}],"commitTime":{"seconds":"1638270516","nanos":541219000}} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.542Z nL3JF [WriteBatch.commit]: Sending 1 writes at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.542Z nL3JF [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.542Z nL3JF [Firestore.request]: Sending request: {"database":"projects/not-a-project/databases/(default)","writes":[{"delete":"projects/not-a-project/databases/(default)/documents/publicProfile/user_id"}]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.545Z nL3JF [Firestore.request]: Received response: {"writeResults":[{"transformResults":[],"updateTime":null}],"commitTime":{"seconds":"1638270516","nanos":544283000}} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Unauthenticated Access attempted at Function.run (src/user.ts:12:13) console.log Firestore (4.13.1) 2021-11-30T11:08:36.547Z 5OlmH [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.547Z 5OlmH [Firestore.requestStream]: Sending request: {"database":"projects/not-a-project/databases/(default)","documents":["projects/not-a-project/databases/(default)/documents/users/user_id"]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.549Z 5OlmH [Firestore.requestStream]: Received response: {"transaction":{"type":"Buffer","data":[]},"readTime":{"seconds":"1638270516","nanos":549178000},"missing":"projects/not-a-project/databases/(default)/documents/users/user_id","result":"missing"} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.550Z 5OlmH [Firestore._initializeStream]: Releasing stream at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.550Z 5OlmH [DocumentReader.fetchDocuments]: Document missing: projects/not-a-project/databases/(default)/documents/users/user_id at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.551Z 5OlmH [Firestore._initializeStream]: Received stream end at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.551Z 5OlmH [DocumentReader.fetchDocuments]: Received 1 results at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.552Z zmqGK [WriteBatch.commit]: Sending 1 writes at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.552Z zmqGK [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.552Z zmqGK [Firestore.request]: Sending request: {"database":"projects/not-a-project/databases/(default)","writes":[{"delete":"projects/not-a-project/databases/(default)/documents/users/user_id"}]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.554Z zmqGK [Firestore.request]: Received response: {"writeResults":[{"transformResults":[],"updateTime":null}],"commitTime":{"seconds":"1638270516","nanos":553917000}} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.555Z NnVdk [WriteBatch.commit]: Sending 1 writes at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.555Z NnVdk [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.555Z NnVdk [Firestore.request]: Sending request: {"database":"projects/not-a-project/databases/(default)","writes":[{"delete":"projects/not-a-project/databases/(default)/documents/publicProfile/user_id"}]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.557Z NnVdk [Firestore.request]: Received response: {"writeResults":[{"transformResults":[],"updateTime":null}],"commitTime":{"seconds":"1638270516","nanos":556909000}} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.558Z 6Mlm4 [WriteBatch.commit]: Sending 1 writes at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.559Z 6Mlm4 [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.559Z 6Mlm4 [Firestore.request]: Sending request: {"database":"projects/not-a-project/databases/(default)","writes":[{"update":{"name":"projects/not-a-project/databases/(default)/documents/users/user_id","fields":{"firstName":{"stringValue":"James"},"email":{"stringValue":"email@email.com"},"phoneNumber":{"stringValue":"222-222-2222"},"birthDate":{"stringValue":"May 10"},"lastName":{"stringValue":"Peterson"},"profileURL":{"stringValue":"image_url"},"lifeEvents":{"arrayValue":{}}}}}]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.562Z 6Mlm4 [Firestore.request]: Received response: {"writeResults":[{"transformResults":[],"updateTime":{"seconds":"1638270516","nanos":561631000}}],"commitTime":{"seconds":"1638270516","nanos":561631000}} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.563Z pBuZs [WriteBatch.commit]: Sending 1 writes at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.564Z pBuZs [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.564Z pBuZs [Firestore.request]: Sending request: {"database":"projects/not-a-project/databases/(default)","writes":[{"update":{"name":"projects/not-a-project/databases/(default)/documents/publicProfile/user_id","fields":{"firstName":{"stringValue":"James"},"lastName":{"stringValue":"Peterson"},"profileURL":{"stringValue":"image_url"},"uid":{"stringValue":"user_id"}}},"updateMask":{"fieldPaths":["firstName","lastName","profileURL","uid"]}}]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.567Z pBuZs [Firestore.request]: Received response: {"writeResults":[{"transformResults":[],"updateTime":{"seconds":"1638270516","nanos":566484000}}],"commitTime":{"seconds":"1638270516","nanos":566484000}} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.568Z wTKto [WriteBatch.commit]: Sending 1 writes at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.568Z wTKto [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.568Z wTKto [Firestore.request]: Sending request: {"database":"projects/not-a-project/databases/(default)","writes":[{"update":{"name":"projects/not-a-project/databases/(default)/documents/users/user_id/private/friends","fields":{"friends":{"arrayValue":{}},"deniedFriends":{"arrayValue":{}},"friendRequests":{"arrayValue":{}},"friendIds":{"arrayValue":{}}}}}]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.571Z wTKto [Firestore.request]: Received response: {"writeResults":[{"transformResults":[],"updateTime":{"seconds":"1638270425","nanos":568732000}}],"commitTime":{"seconds":"1638270516","nanos":570097000}} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.571Z 4aGpv [WriteBatch.commit]: Sending 1 writes at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.571Z 4aGpv [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.572Z 4aGpv [Firestore.request]: Sending request: {"database":"projects/not-a-project/databases/(default)","writes":[{"update":{"name":"projects/not-a-project/databases/(default)/documents/users/user_id/private/settings","fields":{"pushNotifications":{"booleanValue":true},"emailNotifications":{"booleanValue":true},"textNotifications":{"booleanValue":true}}}}]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.574Z 4aGpv [Firestore.request]: Received response: {"writeResults":[{"transformResults":[],"updateTime":{"seconds":"1638270425","nanos":573481000}}],"commitTime":{"seconds":"1638270516","nanos":573463000}} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.576Z eL1Uo [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.576Z eL1Uo [Firestore.requestStream]: Sending request: {"database":"projects/not-a-project/databases/(default)","documents":["projects/not-a-project/databases/(default)/documents/publicProfile/user_id"]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.579Z eL1Uo [Firestore.requestStream]: Received response: {"transaction":{"type":"Buffer","data":[]},"readTime":{"seconds":"1638270516","nanos":578877000},"found":{"fields":{"profileURL":{"stringValue":"image_url","valueType":"stringValue"},"firstName":{"stringValue":"James","valueType":"stringValue"},"lastName":{"stringValue":"Peterson","valueType":"stringValue"},"uid":{"stringValue":"user_id","valueType":"stringValue"}},"name":"projects/not-a-project/databases/(default)/documents/publicProfile/user_id","createTime":{"seconds":"1638270516","nanos":566484000},"updateTime":{"seconds":"1638270516","nanos":566484000}},"result":"found"} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.579Z eL1Uo [Firestore._initializeStream]: Releasing stream at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.580Z eL1Uo [DocumentReader.fetchDocuments]: Received document: projects/not-a-project/databases/(default)/documents/publicProfile/user_id at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.581Z eL1Uo [Firestore._initializeStream]: Received stream end at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.581Z eL1Uo [DocumentReader.fetchDocuments]: Received 1 results at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.582Z HPXIz [WriteBatch.commit]: Sending 1 writes at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.582Z HPXIz [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.582Z HPXIz [Firestore.request]: Sending request: {"database":"projects/not-a-project/databases/(default)","writes":[{"delete":"projects/not-a-project/databases/(default)/documents/users/user_id"}]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.585Z HPXIz [Firestore.request]: Received response: {"writeResults":[{"transformResults":[],"updateTime":null}],"commitTime":{"seconds":"1638270516","nanos":584391000}} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.585Z SGuWW [WriteBatch.commit]: Sending 1 writes at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.585Z SGuWW [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.585Z SGuWW [Firestore.request]: Sending request: {"database":"projects/not-a-project/databases/(default)","writes":[{"delete":"projects/not-a-project/databases/(default)/documents/publicProfile/user_id"}]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.587Z SGuWW [Firestore.request]: Received response: {"writeResults":[{"transformResults":[],"updateTime":null}],"commitTime":{"seconds":"1638270516","nanos":586982000}} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.588Z tPVFj [WriteBatch.commit]: Sending 1 writes at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.588Z tPVFj [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.588Z tPVFj [Firestore.request]: Sending request: {"database":"projects/not-a-project/databases/(default)","writes":[{"update":{"name":"projects/not-a-project/databases/(default)/documents/users/user_id","fields":{"firstName":{"stringValue":"James"},"email":{"stringValue":"email@email.com"},"phoneNumber":{"stringValue":"222-222-2222"},"lastName":{"stringValue":"Peterson"},"profileURL":{"stringValue":"image_url"},"lifeEvents":{"arrayValue":{}}}}}]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.591Z tPVFj [Firestore.request]: Received response: {"writeResults":[{"transformResults":[],"updateTime":{"seconds":"1638270516","nanos":590604000}}],"commitTime":{"seconds":"1638270516","nanos":590604000}} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.592Z WZRYd [WriteBatch.commit]: Sending 1 writes at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.592Z WZRYd [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.592Z WZRYd [Firestore.request]: Sending request: {"database":"projects/not-a-project/databases/(default)","writes":[{"update":{"name":"projects/not-a-project/databases/(default)/documents/publicProfile/user_id","fields":{"firstName":{"stringValue":"James"},"lastName":{"stringValue":"Peterson"},"profileURL":{"stringValue":"image_url"},"uid":{"stringValue":"user_id"}}},"updateMask":{"fieldPaths":["firstName","lastName","profileURL","uid"]}}]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.595Z WZRYd [Firestore.request]: Received response: {"writeResults":[{"transformResults":[],"updateTime":{"seconds":"1638270516","nanos":594828000}}],"commitTime":{"seconds":"1638270516","nanos":594828000}} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.596Z i6DpM [WriteBatch.commit]: Sending 1 writes at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.596Z i6DpM [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.596Z i6DpM [Firestore.request]: Sending request: {"database":"projects/not-a-project/databases/(default)","writes":[{"update":{"name":"projects/not-a-project/databases/(default)/documents/users/user_id/private/friends","fields":{"friends":{"arrayValue":{}},"deniedFriends":{"arrayValue":{}},"friendRequests":{"arrayValue":{}},"friendIds":{"arrayValue":{}}}}}]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.599Z i6DpM [Firestore.request]: Received response: {"writeResults":[{"transformResults":[],"updateTime":{"seconds":"1638270425","nanos":568732000}}],"commitTime":{"seconds":"1638270516","nanos":598279000}} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.599Z JuZUq [WriteBatch.commit]: Sending 1 writes at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.599Z JuZUq [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.600Z JuZUq [Firestore.request]: Sending request: {"database":"projects/not-a-project/databases/(default)","writes":[{"update":{"name":"projects/not-a-project/databases/(default)/documents/users/user_id/private/settings","fields":{"pushNotifications":{"booleanValue":true},"emailNotifications":{"booleanValue":true},"textNotifications":{"booleanValue":true}}}}]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.602Z JuZUq [Firestore.request]: Received response: {"writeResults":[{"transformResults":[],"updateTime":{"seconds":"1638270425","nanos":573481000}}],"commitTime":{"seconds":"1638270516","nanos":601367000}} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.604Z kzgpJ [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.604Z kzgpJ [Firestore.requestStream]: Sending request: {"database":"projects/not-a-project/databases/(default)","documents":["projects/not-a-project/databases/(default)/documents/users/user_id"]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.606Z kzgpJ [Firestore.requestStream]: Received response: {"transaction":{"type":"Buffer","data":[]},"readTime":{"seconds":"1638270516","nanos":605625000},"missing":"projects/not-a-project/databases/(default)/documents/users/user_id","result":"missing"} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.606Z kzgpJ [Firestore._initializeStream]: Releasing stream at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.606Z kzgpJ [DocumentReader.fetchDocuments]: Document missing: projects/not-a-project/databases/(default)/documents/users/user_id at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.607Z kzgpJ [Firestore._initializeStream]: Received stream end at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.607Z kzgpJ [DocumentReader.fetchDocuments]: Received 1 results at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.608Z Oa7Y5 [WriteBatch.commit]: Sending 1 writes at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.608Z Oa7Y5 [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.608Z Oa7Y5 [Firestore.request]: Sending request: {"database":"projects/not-a-project/databases/(default)","writes":[{"delete":"projects/not-a-project/databases/(default)/documents/users/user_id"}]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.611Z Oa7Y5 [Firestore.request]: Received response: {"writeResults":[{"transformResults":[],"updateTime":null}],"commitTime":{"seconds":"1638270516","nanos":610347000}} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.611Z TpPyX [WriteBatch.commit]: Sending 1 writes at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.612Z TpPyX [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.612Z TpPyX [Firestore.request]: Sending request: {"database":"projects/not-a-project/databases/(default)","writes":[{"delete":"projects/not-a-project/databases/(default)/documents/publicProfile/user_id"}]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.614Z TpPyX [Firestore.request]: Received response: {"writeResults":[{"transformResults":[],"updateTime":null}],"commitTime":{"seconds":"1638270516","nanos":613694000}} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.616Z ##### [Firestore]: Initialized Firestore at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log we gon kill it at Function.run (src/user.ts:64:19) console.log Firestore (4.13.1) 2021-11-30T11:08:36.619Z mEzmy [WriteBatch.commit]: Sending 1 writes at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.619Z mEzmy [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.620Z mEzmy [Firestore.request]: Sending request: {"database":"projects/not-a-project/databases/(default)","writes":[{"update":{"name":"projects/not-a-project/databases/(default)/documents/publicProfile/user_id","fields":{"firstName":{"stringValue":"Jang"},"lastName":{"stringValue":"Peterson"},"profileURL":{"stringValue":"profile"},"uid":{"stringValue":"user_id"}}},"updateMask":{"fieldPaths":["firstName","lastName","profileURL","uid"]}}]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.623Z mEzmy [Firestore.request]: Received response: {"writeResults":[{"transformResults":[],"updateTime":{"seconds":"1638270516","nanos":622377000}}],"commitTime":{"seconds":"1638270516","nanos":622377000}} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.625Z Q0Rx8 [ClientPool.acquire]: Re-using existing client with 100 remaining operations at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.625Z Q0Rx8 [Firestore.requestStream]: Sending request: {"database":"projects/not-a-project/databases/(default)","documents":["projects/not-a-project/databases/(default)/documents/publicProfile/user_id"]} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.628Z Q0Rx8 [Firestore.requestStream]: Received response: {"transaction":{"type":"Buffer","data":[]},"readTime":{"seconds":"1638270516","nanos":627209000},"found":{"fields":{"profileURL":{"stringValue":"profile","valueType":"stringValue"},"firstName":{"stringValue":"Jang","valueType":"stringValue"},"lastName":{"stringValue":"Peterson","valueType":"stringValue"},"uid":{"stringValue":"user_id","valueType":"stringValue"}},"name":"projects/not-a-project/databases/(default)/documents/publicProfile/user_id","createTime":{"seconds":"1638270516","nanos":622377000},"updateTime":{"seconds":"1638270516","nanos":622377000}},"result":"found"} at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.628Z Q0Rx8 [Firestore._initializeStream]: Releasing stream at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.628Z Q0Rx8 [DocumentReader.fetchDocuments]: Received document: projects/not-a-project/databases/(default)/documents/publicProfile/user_id at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.629Z Q0Rx8 [Firestore._initializeStream]: Received stream end at Object.logger (node_modules/@google-cloud/firestore/build/src/logger.js:35:9) console.log Firestore (4.13.1) 2021-11-30T11:08:36.629Z Q0Rx8 [DocumentReader.fetchDocuments]: Received 1 results

Thanks for your time!

schmidt-sebastian commented 2 years ago

Hm, there is nothing unusual about the logs. I wish could provide more help here, but I might need a reproduction. Are you able to share more of your code? You can send it me privately at mrschmidt(at)google.com.

schmidt-sebastian commented 2 years ago

I worked with @joshpetit to reproduce this and unfortunately was not able to. We can re-visit this issue once we have a reproducible case.