GET intermittently failing with TLS13(DeadlineExceeded desc = context deadline exceeded)

My SSL library recently upgraded to support TLS13. But gRPC GET commands are intermittently failing now with timeout error.

Is there a way to enable more logs except --debug flag ?
Also, can we configure this GET timeout value ? I am using --timeout flag with 25s , but results are same.
Workaround : Force --tls-version "1.2"

`bash-4.4$ time gnmic -a 192.168.0.15 --port 10161 -u ADMIN -p ADMIN get --path "/shelves/shelf" --skip-verify --format prototext --debug 2024/04/24 04:28:07.251632 /home/runner/work/gnmic/gnmic/pkg/app/app.go:227: [gnmic] version=0.36.2, commit=a7844a6d, date=2024-03-05T20:10:26Z, gitURL=https://github.com/openconfig/gnmic, docs=https://gnmic.openconfig.net 2024/04/24 04:28:07.251670 /home/runner/work/gnmic/gnmic/pkg/app/app.go:232: [gnmic] using config file "" 2024/04/24 04:28:07.252242 /home/runner/work/gnmic/gnmic/pkg/app/app.go:270: [gnmic] set flags/config: address:

192.168.0.15 api: "" auth-scheme: "" calculate-latency: false capabilities-version: false cluster-name: default-cluster config: "" debug: true diff-compare: [] diff-model: [] diff-path: [] diff-prefix: "" diff-qos: "0" diff-ref: "" diff-set-to-notifs-full: false diff-set-to-notifs-response: "" diff-set-to-notifs-setrequest: "" diff-setrequest-full: false diff-setrequest-new: "" diff-setrequest-ref: "" diff-sub: false diff-target: "" diff-type: ALL dir: [] encoding: json exclude: [] file: [] format: prototext generate-camel-case: false generate-config-only: false generate-path: "" generate-snake-case: false get-model: [] get-path:
/shelves/shelf get-prefix: "" get-processor: [] get-target: "" get-type: ALL get-values-only: false getset-condition: any([true]) getset-delete: "" getset-get: "" getset-model: [] getset-prefix: "" getset-replace: "" getset-target: "" getset-type: ALL getset-update: "" getset-value: "" gzip: false insecure: false instance-name: "" listen-max-concurrent-streams: "256" listen-prometheus-address: "" log: true log-file: "" log-tls-secret: false max-msg-size: 536870912 metadata: {} no-prefix: false password: ADMIN path-config-only: false path-descr: false path-path-type: xpath path-search: false path-state-only: false path-types: false path-with-non-leaves: false path-with-prefix: false port: "10161" print-request: false processors-plugins-path: "" prompt-description-bg-color: dark_gray prompt-description-with-prefix: false prompt-description-with-types: false prompt-max-suggestions: "10" prompt-prefix-color: dark_blue prompt-suggest-all-flags: false prompt-suggest-with-origin: false prompt-suggestions-bg-color: dark_blue proto-dir: [] proto-file: [] proxy-from-env: false retry: 10s set-delete: [] set-delimiter: ':::' set-dry-run: false set-prefix: "" set-proto-file: [] set-replace: [] set-replace-cli: [] set-replace-cli-file: "" set-replace-file: [] set-replace-path: [] set-replace-value: [] set-request-file: [] set-request-replace: [] set-request-update: [] set-request-vars: "" set-target: "" set-union-replace: [] set-union-replace-file: [] set-union-replace-path: [] set-union-replace-value: [] set-update: [] set-update-cli: [] set-update-cli-file: "" set-update-file: [] set-update-path: [] set-update-value: [] skip-verify: true subscribe-backoff: 0s subscribe-heartbeat-interval: 0s subscribe-history-end: "" subscribe-history-snapshot: "" subscribe-history-start: "" subscribe-lock-retry: 5s subscribe-mode: stream subscribe-model: [] subscribe-name: [] subscribe-output: [] subscribe-path: [] subscribe-prefix: "" subscribe-qos: "0" subscribe-quiet: false subscribe-sample-interval: 0s subscribe-set-target: false subscribe-stream-mode: target-defined subscribe-suppress-redundant: false subscribe-target: "" subscribe-updates-only: false subscribe-watch-config: false targets-file: "" timeout: 10s tls-ca: "" tls-cert: "" tls-key: "" tls-max-version: "" tls-min-version: "" tls-server-name: "" tls-version: "" token: "" upgrade-use-pkg: false use-tunnel-server: false username: ADMIN

2024/04/24 04:28:07.252404 /home/runner/work/gnmic/gnmic/pkg/app/app.go:280: [gnmic] address='[192.168.0.15]'([]string) 2024/04/24 04:28:07.252417 /home/runner/work/gnmic/gnmic/pkg/app/app.go:280: [gnmic] debug='true'(bool) 2024/04/24 04:28:07.252434 /home/runner/work/gnmic/gnmic/pkg/app/app.go:280: [gnmic] format='prototext'(string) 2024/04/24 04:28:07.252446 /home/runner/work/gnmic/gnmic/pkg/app/app.go:280: [gnmic] get-path='[/shelves/shelf]'([]string) 2024/04/24 04:28:07.252467 /home/runner/work/gnmic/gnmic/pkg/app/app.go:280: [gnmic] password='ADMIN'(string) 2024/04/24 04:28:07.252478 /home/runner/work/gnmic/gnmic/pkg/app/app.go:280: [gnmic] port='10161'(string) 2024/04/24 04:28:07.252505 /home/runner/work/gnmic/gnmic/pkg/app/app.go:280: [gnmic] skip-verify='true'(bool) 2024/04/24 04:28:07.252529 /home/runner/work/gnmic/gnmic/pkg/app/app.go:280: [gnmic] username='ADMIN'(string) 2024/04/24 04:28:07.252557 /home/runner/work/gnmic/gnmic/pkg/config/config.go:387: [config] cmd=get, flagName=help, changed=false, isSetInFile=false 2024/04/24 04:28:07.252578 /home/runner/work/gnmic/gnmic/pkg/config/config.go:387: [config] cmd=get, flagName=model, changed=false, isSetInFile=false 2024/04/24 04:28:07.252583 /home/runner/work/gnmic/gnmic/pkg/config/config.go:387: [config] cmd=get, flagName=path, changed=true, isSetInFile=true 2024/04/24 04:28:07.252590 /home/runner/work/gnmic/gnmic/pkg/config/config.go:387: [config] cmd=get, flagName=prefix, changed=false, isSetInFile=false 2024/04/24 04:28:07.252595 /home/runner/work/gnmic/gnmic/pkg/config/config.go:387: [config] cmd=get, flagName=processor, changed=false, isSetInFile=false 2024/04/24 04:28:07.252599 /home/runner/work/gnmic/gnmic/pkg/config/config.go:387: [config] cmd=get, flagName=target, changed=false, isSetInFile=false 2024/04/24 04:28:07.252604 /home/runner/work/gnmic/gnmic/pkg/config/config.go:387: [config] cmd=get, flagName=type, changed=false, isSetInFile=false 2024/04/24 04:28:07.252608 /home/runner/work/gnmic/gnmic/pkg/config/config.go:387: [config] cmd=get, flagName=values-only, changed=false, isSetInFile=false 2024/04/24 04:28:07.252890 /home/runner/work/gnmic/gnmic/pkg/config/targets.go:47: [config] targets: map[192.168.0.15:{"name":"192.168.0.15","address":"192.168.0.15:10161","username":"ADMIN","password":"****","timeout":10000000000,"insecure":false,"tls-cert":"","tls-key":"","skip-verify":true,"buffer-size":100,"retry-timer":10000000000,"log-tls-secret":false,"gzip":false,"token":""}] 2024/04/24 04:28:07.253293 /home/runner/work/gnmic/gnmic/pkg/config/actions.go:49: [config] actions: map[] 2024/04/24 04:28:07.253309 /home/runner/work/gnmic/gnmic/pkg/config/processors.go:45: [config] processors: map[] 2024/04/24 04:28:07.253355 /home/runner/work/gnmic/gnmic/pkg/app/get.go:132: [gnmic] sending gNMI GetRequest: prefix='', path='[elem:{name:"shelves"} elem:{name:"shelf"}]', type='ALL', encoding='JSON', models='[]', extension='[]' to 192.168.0.15 2024/04/24 04:28:07.254759 /home/runner/work/gnmic/gnmic/pkg/app/app.go:523: [gnmic] creating gRPC client for target "192.168.0.15" 2024/04/24 04:28:07.254842 /home/runner/go/pkg/mod/google.golang.org/grpc@v1.61.0/grpclog/logger.go:53: [gnmic] [core] [Channel #1] Channel created 2024/04/24 04:28:07.254858 /home/runner/go/pkg/mod/google.golang.org/grpc@v1.61.0/grpclog/logger.go:53: [gnmic] [core] [Channel #1] original dial target is: "192.168.0.15:10161" 2024/04/24 04:28:07.254868 /home/runner/go/pkg/mod/google.golang.org/grpc@v1.61.0/grpclog/logger.go:53: [gnmic] [core] [Channel #1] dial target "192.168.0.15:10161" parse failed: parse "192.168.0.15:10161": first path segment in URL cannot contain colon 2024/04/24 04:28:07.254873 /home/runner/go/pkg/mod/google.golang.org/grpc@v1.61.0/grpclog/logger.go:53: [gnmic] [core] [Channel #1] fallback to scheme "passthrough" 2024/04/24 04:28:07.254881 /home/runner/go/pkg/mod/google.golang.org/grpc@v1.61.0/grpclog/logger.go:53: [gnmic] [core] [Channel #1] parsed dial target is: passthrough:///192.168.0.15:10161 2024/04/24 04:28:07.254886 /home/runner/go/pkg/mod/google.golang.org/grpc@v1.61.0/grpclog/logger.go:53: [gnmic] [core] [Channel #1] Channel authority set to "192.168.0.15:10161" 2024/04/24 04:28:07.255021 /home/runner/go/pkg/mod/google.golang.org/grpc@v1.61.0/grpclog/logger.go:53: [gnmic] [core] [Channel #1] Resolver state updated: { "Addresses": [ { "Addr": "192.168.0.15:10161", "ServerName": "", "Attributes": null, "BalancerAttributes": null, "Metadata": null } ], "Endpoints": [ { "Addresses": [ { "Addr": "192.168.0.15:10161", "ServerName": "", "Attributes": null, "BalancerAttributes": null, "Metadata": null } ], "Attributes": null } ], "ServiceConfig": null, "Attributes": null } (resolver returned new addresses) 2024/04/24 04:28:07.255049 /home/runner/go/pkg/mod/google.golang.org/grpc@v1.61.0/grpclog/logger.go:53: [gnmic] [core] [Channel #1] Channel switches to new LB policy "pick_first" 2024/04/24 04:28:07.255078 /home/runner/go/pkg/mod/google.golang.org/grpc@v1.61.0/grpclog/logger.go:53: [gnmic] [core] [pick-first-lb 0xc000b10810] Received new config { "shuffleAddressList": false }, resolver state { "Addresses": [ { "Addr": "192.168.0.15:10161", "ServerName": "", "Attributes": null, "BalancerAttributes": null, "Metadata": null } ], "Endpoints": [ { "Addresses": [ { "Addr": "192.168.0.15:10161", "ServerName": "", "Attributes": null, "BalancerAttributes": null, "Metadata": null } ], "Attributes": null } ], "ServiceConfig": null, "Attributes": null } 2024/04/24 04:28:07.255098 /home/runner/go/pkg/mod/google.golang.org/grpc@v1.61.0/grpclog/logger.go:53: [gnmic] [core] [Channel #1 SubChannel #2] Subchannel created 2024/04/24 04:28:07.255107 /home/runner/go/pkg/mod/google.golang.org/grpc@v1.61.0/grpclog/logger.go:53: [gnmic] [core] [Channel #1] Channel Connectivity change to CONNECTING 2024/04/24 04:28:07.255124 /home/runner/go/pkg/mod/google.golang.org/grpc@v1.61.0/grpclog/logger.go:53: [gnmic] [core] [Channel #1] Channel exiting idle mode 2024/04/24 04:28:07.255147 /home/runner/go/pkg/mod/google.golang.org/grpc@v1.61.0/grpclog/logger.go:53: [gnmic] [core] [Channel #1 SubChannel #2] Subchannel Connectivity change to CONNECTING 2024/04/24 04:28:07.255173 /home/runner/go/pkg/mod/google.golang.org/grpc@v1.61.0/grpclog/logger.go:53: [gnmic] [core] [Channel #1 SubChannel #2] Subchannel picks a new address "192.168.0.15:10161" to connect 2024/04/24 04:28:07.255295 /home/runner/go/pkg/mod/google.golang.org/grpc@v1.61.0/grpclog/logger.go:53: [gnmic] [core] [pick-first-lb 0xc000b10810] Received SubConn state update: 0xc000b10990, {ConnectivityState:CONNECTING ConnectionError:} 2024/04/24 04:28:11.464366 /home/runner/go/pkg/mod/google.golang.org/grpc@v1.61.0/grpclog/logger.go:53: [gnmic] [core] [Channel #1 SubChannel #2] Subchannel Connectivity change to READY 2024/04/24 04:28:11.464404 /home/runner/go/pkg/mod/google.golang.org/grpc@v1.61.0/grpclog/logger.go:53: [gnmic] [core] [pick-first-lb 0xc000b10810] Received SubConn state update: 0xc000b10990, {ConnectivityState:READY ConnectionError:} 2024/04/24 04:28:11.464413 /home/runner/go/pkg/mod/google.golang.org/grpc@v1.61.0/grpclog/logger.go:53: [gnmic] [core] [Channel #1] Channel Connectivity change to READY 2024/04/24 04:28:21.464999 /home/runner/work/gnmic/gnmic/pkg/app/logging.go:21: [gnmic] target "192.168.0.15" get request failed: "192.168.0.15:10161" GetRequest failed: rpc error: code = DeadlineExceeded desc = context deadline exceeded 2024/04/24 04:28:21.465039 /home/runner/work/gnmic/gnmic/pkg/app/logging.go:21: [gnmic] target "192.168.0.15" Get request failed: "192.168.0.15:10161" GetRequest failed: rpc error: code = DeadlineExceeded desc = context deadline exceeded target "192.168.0.15" get request failed: "192.168.0.15:10161" GetRequest failed: rpc error: code = DeadlineExceeded desc = context deadline exceeded target "192.168.0.15" Get request failed: "192.168.0.15:10161" GetRequest failed: rpc error: code = DeadlineExceeded desc = context deadline exceeded Error: one or more requests failed

real 0m14.243s user 0m0.039s sys 0m0.012s `

openconfig / gnmic

GET intermittently failing with TLS13(DeadlineExceeded desc = context deadline exceeded) #416