Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

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

Open
Shikha-Chowdhary opened this issue Apr 24, 2024 · 2 comments
Open

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

Shikha-Chowdhary opened this issue Apr 24, 2024 · 2 comments

Comments

@Shikha-Chowdhary
Copy link

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/[email protected]/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/[email protected]/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/[email protected]/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/[email protected]/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/[email protected]/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/[email protected]/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/[email protected]/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/[email protected]/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/[email protected]/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/[email protected]/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/[email protected]/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/[email protected]/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/[email protected]/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/[email protected]/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/[email protected]/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/[email protected]/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/[email protected]/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/[email protected]/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
`
@Shikha-Chowdhary
Copy link
Author

bash-4.4$ gnmic version
version : 0.36.2
commit : a7844a6
date : 2024-03-05T20:10:26Z
gitURL : https://github.com/openconfig/gnmic
docs : https://gnmic.openconfig.net
bash-4.4$

@karimra
Copy link
Collaborator

karimra commented Apr 24, 2024

Is there a way to enable more logs except --debug flag ?

No, that's as much as you can get without editing code.

Also, can we configure this GET timeout value ? I am using --timeout flag with 25s , but results are same.

The --timeout flag works fine from my tests. Can you give an example where you pass --timeout 25s and a 10s timeout is applied ?

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

Can you detail what you mean by "intermittently". What kind of errors do you get ? Just a timeout ?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@karimra @Shikha-Chowdhary