firestore.googleapis.com:443 was not shutdown properly

[yahortsaryk]

Hello, we're using java client google-cloud-firestore 0.32.0-beta library in our backend app for pushing records into a Firestore instance.
Here is a java code snippet that reflects our processing flow:

`
FirestoreOptions firestoreOptions =
FirestoreOptions.getDefaultInstance().toBuilder()
.setProjectId(projectId)
.setCredentials(credentials)
.build();

        Firestore db = firestoreOptions.getService();
        final List<String> results = new ArrayList<>();
        List<Object> records = new ArrayList<>(); // get list of records
        for (Object record : records) {

            String path = "path/to/collection/" + record.id;
            final DocumentReference doc = db.document(path);
            ApiFuture<String> transaction = db.runTransaction(
                    new Transaction.Function<String>() {
                        @Override
                        public String updateCallback(Transaction transaction) throws Exception {
                            DocumentSnapshot snapshot = transaction.get(doc).get();

                            if (!snapshot.exists()) {
                                transaction.set(snapshot.getReference(), record);
                                return "New record is inserted";
                            }

                            if (condition) {
                                transaction.update(doc, "field", "new value");
                                return "Record is updated";
                            } else {
                                return "Record is skipped";
                            }
                        }
                    });

            results.add(transaction.get());
        }

`

However in our Logs entries we constantly see the following error:

io.grpc.internal.ManagedChannelImpl *~*~*~ Channel io.grpc.internal.ManagedChannelImpl-609 for target firestore.googleapis.com:443 was not shutdown properly!!! ~*~*~* Make sure to call shutdown()/shutdownNow() and awaitTermination().

I guess, it causes a memory leak in our app as we often see OOM exceptions and crashes. We suppose it can be related to this issue #2497 . Can you confirm that ? What can you suggest us as a fix ? (btw, we can't use batch updates as there are no ability to check specific conditions with batches)

[yahortsaryk]

We concluded that internal Firestore RPC service doesn't release connection channels properly. Here is what we do as a quick fix:

` try (FirestoreRpc rpc = (FirestoreRpc) firestoreOptions.getRpc();) {
Firestore db = firestoreOptions.getService();
// send transactions

} catch (Exception ex) {
}`

After we've added this trick we don't see failures and errors in our logs. Could you provide more applicable interface for releasing the underlying resources?

[pongad]

@schmidt-sebastian Can you take a look?

[schmidt-sebastian]

I filed an internal issue to track this work. Will keep this issue updated.

[yahortsaryk]

@schmidt-sebastian @pongad Hello, thank you for making Firestore type AutoClosable, this provides more intuitive interface for resources releasing. However, I want to add some more details. After I fetched the latest firestore version (which is 0.34.0-beta at the moment) and tried to wrap the above code into a try-catch block like:

 Firestore db = firestoreOptions.getService();
 final List<String> results = new ArrayList<>();
 List<Object> records = new ArrayList<>(); // get around 200-300 records

try (Firestore db = firestoreOptions.getService();) {

for (Object record : records) {

            String path = "path/to/collection/" + record.id;
            final DocumentReference doc = db.document(path);
            ApiFuture<String> transaction = db.runTransaction(
                    new Transaction.Function<String>() {
                        @Override
                        public String updateCallback(Transaction transaction) throws Exception {
                            DocumentSnapshot snapshot = transaction.get(doc).get();

                            if (!snapshot.exists()) {
                                transaction.set(snapshot.getReference(), record);
                                return "New record is inserted";
                            }

                            if (condition) {
                                transaction.update(doc, "field", "new value");
                                return "Record is updated";
                            } else {
                                return "Record is skipped";
                            }
                        }
                    });

            results.add(transaction.get());
        }
}  catch (Exception ex) {

}

I'm still getting this:

2018-02-06 00:53:26,561 ERROR [Timer-Driven Process Thread-1] io.grpc.internal.ManagedChannelImpl *~*~*~ Channel io.grpc.internal.ManagedChannelImpl-17759 for target logging.googleapis.com:443 was not shutdown properly!!! ~*~*~* in app logs.

FYI we use Apache NiFi (https://nifi.apache.org/) data processing framework, It has a concept of processors that compose ETL workflow. We use google-cloud-firestore lib and the above code inside of such processors.
The interesting thing is that when I add Thread.sleep(10000); call in the end of the above code the error disappears. I have a suspicion that main thread which executes the above code doesn't wait for Firestore to close all underlying connections and just exits without waiting while Firestore releases connections in asynchronous manner. Can you confirm that ? How can we be sure that this io.grpc.internal.ManagedChannelImpl is being shutdown properly?

[pongad]

The channel is connected to "logging.googleapis.com:443". Are you using the logging client somewhere else? I don't think Firestore can be connecting to that endpoint.

[yahortsaryk]

@pongad Yeah, you are right. I missed that the error now is about logging.googleapis.com, not firestore.googleapis.com. And yes, we also use google-cloud-logging-1.16.0 lib to push log entries to GCP StackDriver. Both firestore and logging libs are updated to the latest versions. However, I still don't understand why adding of Thread.sleep(10000); line in firestore processor (code) prevents this error. Is it possible that some common components in google-cloud-* libs overlaps each other ?

[pongad]

@egortsaryk9 Are you using LoggingHandler? I believe the issue could be the following. The LoggingHandler has a close method that shuts down the gRPC connection but it doesn't wait for the connection to terminate. Sleeping for 10s gave the connections enough time to terminate and so you no longer see the issue.

@jabubake I'm not sure what the right answer here is. Should we call awaitTerminated in LoggingHandler.close? But then how long do we wait for?