Skip to content

clientv3: watch shutdown may log "retrying of unary invoker failed" / "getToken failed" on expected client.Close() cancellation #21643

@HorseArcher567

Description

@HorseArcher567

Bug report criteria

What happened?

Version

Observed with:

  • go.etcd.io/etcd/client/v3 v3.6.5
  • go.etcd.io/etcd/client/v3 v3.6.10

The behavior is reproducible on both versions.

When using clientv3 with auth enabled and creating watch streams, calling client.Close() during normal application shutdown
may emit logs like:

  warn  retrying of unary invoker failed ... method=/etcdserverpb.Auth/Authenticate ... error="rpc error: code = Canceled
desc = context canceled"
  error clientv3/retry_interceptor: getToken failed error="context canceled"

From the application perspective, shutdown is expected and successful, and all higher-level watch/resolver users have already
been closed cleanly before client.Close() is called.

This looks like expected cancellation during shutdown is still being logged as warn/error by clientv3 internals.

Actual logs

Example output:

  {"level":"warn","ts":"...","logger":"etcd-client","caller":"v3@v3.6.10/retry_interceptor.go:65","msg":"retrying of unary
invoker
failed","target":"etcd-endpoints://.../localhost:2379","method":"/etcdserverpb.Auth/Authenticate","attempt":0,"error":"rpc
error: code = Canceled desc = context canceled"}


{"level":"error","ts":"...","logger":"etcd-client","caller":"v3@v3.6.10/retry_interceptor.go:116","msg":"clientv3/retry_inter
ceptor: getToken failed","error":"context
canceled","stacktrace":"go.etcd.io/etcd/client/v3.(*Client).streamClientInterceptor.func1\n...\ngo.etcd.io/etcd/client/v3.(*w
atchGRPCStream).openWatchClient\n...\ngo.etcd.io/etcd/client/v3.(*watchGRPCStream).run"}

### What did you expect to happen?

On normal client.Close() shutdown, expected internal cancellation during watch/auth/token teardown should ideally not be
logged as warning/error, or should at least be downgraded / suppressed when cancellation is caused by normal client shutdown.


### How can we reproduce it (as minimally and precisely as possible)?

I first suspected my own resolver / watch user teardown order, but after adding instrumentation on the application side, I
verified that:

- all application-level gRPC resolvers/watch users were closed cleanly
- their watch loops had fully exited
- only after that did the shared etcd client get closed
- the noisy logs appear after client.Close() / store shutdown

So this does not appear to be caused by application-level resolver leakage or late close.

### Anything else we need to know?

From reading clientv3 source, the log chain appears to be:

1. watch stream creation goes through streamClientInterceptor
2. streamClientInterceptor calls c.getToken(ctx)
3. getToken(ctx) calls c.Auth.Authenticate(ctx, c.Username, c.Password)
4. Authenticate goes through the unary interceptor
5. during client.Close(), the client context is canceled
6. Authenticate returns context canceled
7. unary interceptor logs:
  ```text
    retrying of unary invoker failed
  1. then stream interceptor logs:
  clientv3/retry_interceptor: getToken failed

The close path in client.go is also relevant:

  func (c *Client) Close() error {
      c.cancel()
      if c.Watcher != nil {
          c.Watcher.Close()
      }
      if c.Lease != nil {
          c.Lease.Close()
      }
      if c.conn != nil {
          return ContextError(c.ctx, c.conn.Close())
      }
      return c.ctx.Err()
  }

So this seems to be an expected shutdown cancellation path being logged as warn/error.

Etcd version (please run commands below)

Details
$ etcd --version
etcd Version: 3.6.8
Git SHA: 4e814e204
Go Version: go1.26.0
Go OS/Arch: darwin/amd64

$ etcdctl version
etcdctl version: 3.6.8
API version: 3.6

Etcd configuration (command line flags or environment variables)

Details

paste your configuration here

Etcd debug information (please run commands below, feel free to obfuscate the IP address or FQDN in the output)

Details
$ etcdctl member list -w table
# paste output here

$ etcdctl --endpoints=<member list> endpoint status -w table
# paste output here

Relevant log output

Metadata

Metadata

Assignees

No one assigned

    Labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions