Google-cloud-go: http2Client.notifyError every 4 minutes when using gcd

[nvartolomei]

http2Client.notifyError got notified that the client transport was broken EOF

Is this normal? How to fix/get rid of this?

[bradfitz]

This is a gRPC-go bug. I think it's a dup of https://github.com/grpc/grpc-go/issues/120

[derekperkins]

Yeah, it definitely clogs up our logs.

[okdave]

I'll close this issue, since the bug is being tracked in the grpc one above. I don't think we can do anything reasonable in these clients to workaround the bug.

[nvartolomei]

@okdave I think this one is different, I get the error once every 4 minutes and not a bunch of errors when server disconnects. This happens on localhost and on k8s cluster too.

[nvartolomei]

10:17:17  curator | 2016/07/26 10:17:17 transport: http2Client.notifyError got notified that the client transport was broken EOF.
10:17:25 uploader | 2016/07/26 10:17:25 transport: http2Client.notifyError got notified that the client transport was broken EOF.
10:21:17  curator | 2016/07/26 10:21:17 transport: http2Client.notifyError got notified that the client transport was broken EOF.
10:21:25 uploader | 2016/07/26 10:21:25 transport: http2Client.notifyError got notified that the client transport was broken EOF.
10:25:18  curator | 2016/07/26 10:25:18 transport: http2Client.notifyError got notified that the client transport was broken EOF.
10:25:25 uploader | 2016/07/26 10:25:25 transport: http2Client.notifyError got notified that the client transport was broken EOF.
10:29:19  curator | 2016/07/26 10:29:19 transport: http2Client.notifyError got notified that the client transport was broken EOF.
10:29:26 uploader | 2016/07/26 10:29:26 transport: http2Client.notifyError got notified that the client transport was broken EOF.
10:33:20  curator | 2016/07/26 10:33:20 transport: http2Client.notifyError got notified that the client transport was broken EOF.
10:33:26 uploader | 2016/07/26 10:33:26 transport: http2Client.notifyError got notified that the client transport was broken EOF.
10:37:20  curator | 2016/07/26 10:37:20 transport: http2Client.notifyError got notified that the client transport was broken EOF.
10:37:26 uploader | 2016/07/26 10:37:26 transport: http2Client.notifyError got notified that the client transport was broken EOF.

this is what i see, please reconsider opening this back

[okdave]

Yep, I agree.

[jba]

I cannot reproduce.

I assume by gcd you mean the datastore emulator. I started this with

gcloud beta emulators datastore start --no-legacy

using the latest version of gcloud (SDK 119.0.0, emulator 1.1.1). I wrote a small program using the client that repeatedly puts and gets an entity. I let it run for over 10 minutes and did not observe any log messages other than my own.

Let me know how to reproduce.

[nvartolomei]

Try with real cloud. Do a put and let it wait for 5 minutes.

On 29 Jul 2016 17:10 +0300, Jonathan Amsterdam [email protected], wrote:

I cannot reproduce.

I assume by gcd you mean the datastore emulator. I started this with

gcloud beta emulators datastore start --no-legacy

using the latest version of gcloud (SDK 119.0.0, emulator 1.1.1). I wrote a small program using the client that repeatedly puts and gets an entity. I let it run for over 10 minutes and did not observe any log messages other than my own.

Let me know how to reproduce.

—
You are receiving this because you authored the thread.
Reply to this email directly, view it on GitHub (https://github.com/GoogleCloudPlatform/gcloud-golang/issues/293#issuecomment-236190460), or mute the thread (https://github.com/notifications/unsubscribe-auth/AAhJ2ZcNKcT2ApGM3Ng3vqLHnLK--IXAks5qagnfgaJpZM4JRizc).

[garye]

@jba I believe this can be reproduced only with an idle gRPC connection, not one that is constantly sending requests. I also think it's due to an interaction with Google frontend servers and wouldn't show up while connected to an emulator.

I reproduce this by running the bigtable loadtest for > 4m.

[garye]

@nvartolomei Does the idle connection comment sound right to you? In the bigtable example we have a data connection that is constantly used and an admin connection that is used at the start and then idle until after the test when it is asked to clean up the tables.

[nvartolomei]

@garye if this is normal behavior then I think this should not show up at all, imho.

[garye]

I agree, I suspect it's unnecessary logging on the part of grpc-go but
would be curious to see if @jba can also reproduce this.

[jba]

Thanks for the tips. I reproduced against the production service. This isn't our bug---it's happening in grpc somewhere. A workaround: make a no-op call every few minutes. client.Delete(ctx, datastore.NewKey(ctx, "", "junk", 0, nil) worked for me (it gives an error because the kind is empty).

[nvartolomei]

pff.

[christopherhesse]

Is it a bug in grpc if the datastore server is closing the connection? Or is the grpc client closing it? Or is this totally the way it should work, but the log entry is pointless? I tried enabling TCP keepalives, but that had no effect. The workaround didn't work for me because I am using the log service and pubsub service, and I'm not sure if those have similar no-op commands.

[garye]

I believe it's the google frontend server that is closing this connection after 4 minutes of inactivity, after which the grpc client reconnects automatically. This is expected behavior. The grpc client logging seems unnecessary (but maybe still useful?) since the reconnection is automatically handled under the covers.

[christopherhesse]

Okay, thanks! I will just filter out this error message.

[adams-sarah]

I realize this issue has been closed, but thought i'd add: if you want to filter out these messages you can set the grpc logger to write somewhere else (not stderr) - different file? drop all together?

https://godoc.org/google.golang.org/grpc/grpclog

You should be able to do something like:

import (
    "log"
    "google.golang.org/grpc/grpclog"
)

func init() {
    var myGRPCLogger grpclog.Logger = log.New(myIOWriter, "", log.LstdFlags)
    grpclog.SetLogger(myGRPCLogger)
}