search

karimra / gnmic

gNMIc is a gNMI CLI client and collector
https://gnmic.kmrd.dev
Apache License 2.0
217 stars 32 forks source link

event-merge does not appear to work with file output #571

Closed bewing closed 2 years ago

bewing commented 2 years ago

While trying to figure out how to tag interface counters with interface descriptions, I discovered that EOS's Octa gNMI server apparently emits every leaf as a separate gNMI.SubscribeResponse. I tried using the documented event-merge processor to combine these events, but that doesn't appear to work either. Debug log below:

#.gnmic.yml
username: <removed>
password: <removed>
insecure: true
outputs:
  output1:
    type: file
    file-type: stdout
    event-processors:
      - merge-arista
    format: event

targets:
  eos:6030:
    subscriptions:
      - port-stats

subscriptions:
  port-stats:
    paths:
      - "/interfaces/interface[name=Ethernet1]/state/counters"
      - "/interfaces/interface[name=Ethernet1]/state/description"
    stream-mode: sample
    encoding: bytes
    sample-interval: 10s

processors:
  merge-arista:
    event-merge:
      always: true
      debug: true
$ gnmic sub --debug
2022/03/31 15:25:48.774656 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/app.go:209: [gnmic] version=dev, commit=none, date=unknown, gitURL=, docs=https://gnmic.kmrd.dev
2022/03/31 15:25:48.774786 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/app.go:214: [gnmic] using config file "/home/bewing/.gnmic.yml"
2022/03/31 15:25:48.784696 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/app.go:260: [gnmic] set flags/config:
address: []
api: ""
capabilities-version: false
cluster-name: default-cluster
config: ""
debug: true
diff-compare: []
diff-model: []
diff-path: []
diff-prefix: ""
diff-qos: "0"
diff-ref: ""
diff-sub: false
diff-target: ""
diff-type: ALL
dir: []
encoding: json
exclude: []
file: []
format: ""
generate-camel-case: false
generate-config-only: false
generate-path: ""
generate-snake-case: false
get-model: []
get-path: []
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: true
instance-name: ""
listen-max-concurrent-streams: "256"
listen-prometheus-address: ""
log: true
log-file: ""
log-tls-secret: false
max-msg-size: 536870912
no-prefix: false
outputs:
  output1:
    event-processors:
    - merge-arista
    file-type: stdout
    format: event
    type: file
password: <removed>
path-config-only: false
path-descr: false
path-path-type: xpath
path-search: false
path-state-only: false
path-types: false
path-with-prefix: false
port: "57400"
print-request: false
processors:
  merge-arista:
    event-merge:
      always: true
      debug: true
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-replace: []
set-replace-file: []
set-replace-path: []
set-replace-value: []
set-request-file: []
set-request-replace: []
set-request-update: []
set-request-vars: ""
set-target: ""
set-update: []
set-update-file: []
set-update-path: []
set-update-value: []
skip-verify: false
subscribe-backoff: 0s
subscribe-heartbeat-interval: 0s
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
subscriptions:
  port-stats:
    encoding: bytes
    paths:
    - /interfaces/interface[name=Ethernet1]/state/counters
    - /interfaces/interface[name=Ethernet1]/state/description
    sample-interval: 10s
    stream-mode: sample
targets:
  eos:6030:
    subscriptions:
    - port-stats
targets-file: ""
timeout: 10s
tls-ca: ""
tls-cert: ""
tls-key: ""
tls-max-version: ""
tls-min-version: ""
tls-version: ""
token: ""
upgrade-use-pkg: false
use-tunnel-server: false
username: <removed>

2022/03/31 15:25:48.785173 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/app.go:270: [gnmic] debug='true'(bool)
2022/03/31 15:25:48.785300 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/app.go:270: [gnmic] insecure='true'(bool)
2022/03/31 15:25:48.786019 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/app.go:270: [gnmic] outputs/output1/event-processors='[merge-arista]'([]interface {})
2022/03/31 15:25:48.786668 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/app.go:270: [gnmic] outputs/output1/file-type='stdout'(string)
2022/03/31 15:25:48.787380 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/app.go:270: [gnmic] outputs/output1/format='event'(string)
2022/03/31 15:25:48.788056 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/app.go:270: [gnmic] outputs/output1/type='file'(string)
2022/03/31 15:25:48.788117 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/app.go:270: [gnmic] password='<removed>'(string)
2022/03/31 15:25:48.789502 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/app.go:270: [gnmic] processors/merge-arista/event-merge/always='true'(bool)
2022/03/31 15:25:48.790196 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/app.go:270: [gnmic] processors/merge-arista/event-merge/debug='true'(bool)
2022/03/31 15:25:48.791788 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/app.go:270: [gnmic] subscriptions/port-stats/encoding='bytes'(string)
2022/03/31 15:25:48.792167 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/app.go:270: [gnmic] subscriptions/port-stats/paths='[/interfaces/interface[name=Ethernet1]/state/counters /interfaces/interface[name=Ethernet1]/state/description]'([]interface {})
2022/03/31 15:25:48.792534 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/app.go:270: [gnmic] subscriptions/port-stats/sample-interval='10s'(string)
2022/03/31 15:25:48.792904 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/app.go:270: [gnmic] subscriptions/port-stats/stream-mode='sample'(string)
2022/03/31 15:25:48.793347 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/app.go:270: [gnmic] targets/eos:6030/subscriptions='[port-stats]'([]interface {})
2022/03/31 15:25:48.793393 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/app.go:270: [gnmic] username='<removed>'(string)
2022/03/31 15:25:48.793437 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/config.go:340: [config] cmd=subscribe, flagName=backoff, changed=false, isSetInFile=false
2022/03/31 15:25:48.793485 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/config.go:340: [config] cmd=subscribe, flagName=heartbeat-interval, changed=false, isSetInFile=false
2022/03/31 15:25:48.793495 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/config.go:340: [config] cmd=subscribe, flagName=help, changed=false, isSetInFile=false
2022/03/31 15:25:48.793502 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/config.go:340: [config] cmd=subscribe, flagName=lock-retry, changed=false, isSetInFile=false
2022/03/31 15:25:48.793513 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/config.go:340: [config] cmd=subscribe, flagName=mode, changed=false, isSetInFile=false
2022/03/31 15:25:48.793521 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/config.go:340: [config] cmd=subscribe, flagName=model, changed=false, isSetInFile=false
2022/03/31 15:25:48.793531 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/config.go:340: [config] cmd=subscribe, flagName=name, changed=false, isSetInFile=false
2022/03/31 15:25:48.793538 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/config.go:340: [config] cmd=subscribe, flagName=output, changed=false, isSetInFile=false
2022/03/31 15:25:48.793547 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/config.go:340: [config] cmd=subscribe, flagName=path, changed=false, isSetInFile=false
2022/03/31 15:25:48.793582 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/config.go:340: [config] cmd=subscribe, flagName=prefix, changed=false, isSetInFile=false
2022/03/31 15:25:48.793619 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/config.go:340: [config] cmd=subscribe, flagName=qos, changed=false, isSetInFile=false
2022/03/31 15:25:48.793631 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/config.go:340: [config] cmd=subscribe, flagName=quiet, changed=false, isSetInFile=false
2022/03/31 15:25:48.793638 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/config.go:340: [config] cmd=subscribe, flagName=sample-interval, changed=false, isSetInFile=false
2022/03/31 15:25:48.793648 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/config.go:340: [config] cmd=subscribe, flagName=set-target, changed=false, isSetInFile=false
2022/03/31 15:25:48.793655 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/config.go:340: [config] cmd=subscribe, flagName=stream-mode, changed=false, isSetInFile=false
2022/03/31 15:25:48.793666 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/config.go:340: [config] cmd=subscribe, flagName=suppress-redundant, changed=false, isSetInFile=false
2022/03/31 15:25:48.793672 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/config.go:340: [config] cmd=subscribe, flagName=target, changed=false, isSetInFile=false
2022/03/31 15:25:48.793680 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/config.go:340: [config] cmd=subscribe, flagName=updates-only, changed=false, isSetInFile=false
2022/03/31 15:25:48.793688 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/config.go:340: [config] cmd=subscribe, flagName=watch-config, changed=false, isSetInFile=false
2022/03/31 15:25:48.793714 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/subscriptions.go:58: [config] subscriptions map: map[port-stats:map[encoding:bytes paths:[/interfaces/interface[name=Ethernet1]/state/counters /interfaces/interface[name=Ethernet1]/state/description] sample-interval:10s stream-mode:sample]]+
2022/03/31 15:25:48.793889 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/subscriptions.go:83: [config] subscriptions: map[port-stats:{"name":"port-stats","paths":["/interfaces/interface[name=Ethernet1]/state/counters","/interfaces/interface[name=Ethernet1]/state/description"],"mode":"stream","stream-mode":"sample","encoding":"bytes","sample-interval":10000000000}]
2022/03/31 15:25:48.794015 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/targets.go:105: [config] read target config: {"name":"eos:6030","address":"eos:6030","username":"<removed>","password":"<removed>","timeout":10000000000,"insecure":true,"skip-verify":false,"subscriptions":["port-stats"],"retry-timer":10000000000,"log-tls-secret":false,"gzip":false,"token":""}
2022/03/31 15:25:48.794272 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/targets.go:127: [config] targets: map[eos:6030:{"name":"eos:6030","address":"eos:6030","username":"<removed>","password":"<removed>","timeout":10000000000,"insecure":true,"skip-verify":false,"subscriptions":["port-stats"],"retry-timer":10000000000,"log-tls-secret":false,"gzip":false,"token":""}]
2022/03/31 15:25:48.794297 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/outputs.go:52: [config] outputs: map[output1:map[event-processors:[merge-arista] file-type:stdout format:event type:file]]
2022/03/31 15:25:48.794335 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/inputs.go:49: [config] inputs: map[]
2022/03/31 15:25:48.794344 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/actions.go:41: [config] actions: map[]
2022/03/31 15:25:48.794352 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/processors.go:14: [config] validating processor "merge-arista" config
2022/03/31 15:25:48.794377 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/config/processors.go:37: [config] processors: map[merge-arista:map[event-merge:map[always:true debug:true]]]
2022/03/31 15:25:48.794428 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/outputs.go:19: [gnmic] starting output type file
2022/03/31 15:25:48.794537 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/collector.go:27: [gnmic] starting target &{Config:{"name":"eos:6030","address":"eos:6030","username":"<removed>","password":"<removed>","timeout":10000000000,"insecure":true,"skip-verify":false,"subscriptions":["port-stats"],"retry-timer":10000000000,"log-tls-secret":false,"gzip":false,"token":""} Subscriptions:map[port-stats:{"name":"port-stats","paths":["/interfaces/interface[name=Ethernet1]/state/counters","/interfaces/interface[name=Ethernet1]/state/description"],"mode":"stream","stream-mode":"sample","encoding":"bytes","sample-interval":10000000000}] m:0xc000d031b8 conn:<nil> Client:<nil> SubscribeClients:map[] subscribeCancelFn:map[] pollChan:0xc000048480 subscribeResponses:0xc000048900 errors:0xc000048960 stopped:false StopChan:0xc0000489c0 Cfn:<nil> RootDesc:<nil>}
2022/03/31 15:25:48.794577 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/collector.go:39: [gnmic] starting target "eos:6030" listener
2022/03/31 15:25:48.794600 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/gnmi_client_subscribe.go:74: [gnmic] queuing target "eos:6030"
2022/03/31 15:25:48.794607 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/gnmi_client_subscribe.go:76: [gnmic] subscribing to target: "eos:6030"
2022/03/31 15:25:48.794687 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/formatters/event_merge/event_merge.go:50: [event-merge] initialized processor 'event-merge': {"always":true,"debug":true}
2022/03/31 15:25:48.794734 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/outputs/file/file_output.go:101: [file_output] added event processor 'merge-arista' of type=event-merge to file output
2022/03/31 15:25:48.794824 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/outputs/file/file_output.go:191: [file_output] initialized file output: {"Cfg":{"FileName":"","FileType":"stdout","Format":"event","Multiline":true,"Indent":"  ","Separator":"\n","OverrideTimestamps":false,"AddTarget":"","TargetTemplate":"","EventProcessors":["merge-arista"],"MsgTemplate":"","ConcurrencyLimit":1000,"EnableMetrics":false,"Debug":false}}
2022/03/31 15:25:48.794999 /home/bewing/go/pkg/mod/google.golang.org/grpc@v1.44.0/grpclog/logger.go:53: [gnmic] [core] original dial target is: "eos:6030"
2022/03/31 15:25:48.795130 /home/bewing/go/pkg/mod/google.golang.org/grpc@v1.44.0/grpclog/logger.go:53: [gnmic] [core] parsed dial target is: {Scheme:eos Authority: Endpoint:6030 URL:{Scheme:eos Opaque:6030 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022/03/31 15:25:48.795295 /home/bewing/go/pkg/mod/google.golang.org/grpc@v1.44.0/grpclog/logger.go:53: [gnmic] [core] fallback to scheme "passthrough"
2022/03/31 15:25:48.795586 /home/bewing/go/pkg/mod/google.golang.org/grpc@v1.44.0/grpclog/logger.go:53: [gnmic] [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:eos:6030 URL:{Scheme:passthrough Opaque: User: Host: Path:/eos:6030 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022/03/31 15:25:48.795618 /home/bewing/go/pkg/mod/google.golang.org/grpc@v1.44.0/grpclog/logger.go:53: [gnmic] [core] Channel authority set to "eos:6030"
2022/03/31 15:25:48.795775 /home/bewing/go/pkg/mod/google.golang.org/grpc@v1.44.0/grpclog/logger.go:53: [gnmic] [core] ccResolverWrapper: sending update to cc: {[{eos:6030  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022/03/31 15:25:48.795805 /home/bewing/go/pkg/mod/google.golang.org/grpc@v1.44.0/grpclog/logger.go:53: [gnmic] [core] ClientConn switching balancer to "pick_first"
2022/03/31 15:25:48.795890 /home/bewing/go/pkg/mod/google.golang.org/grpc@v1.44.0/grpclog/logger.go:53: [gnmic] [core] Channel switches to new LB policy "pick_first"
2022/03/31 15:25:48.796044 /home/bewing/go/pkg/mod/google.golang.org/grpc@v1.44.0/grpclog/logger.go:53: [gnmic] [core] Subchannel Connectivity change to CONNECTING
2022/03/31 15:25:48.796102 /home/bewing/go/pkg/mod/google.golang.org/grpc@v1.44.0/grpclog/logger.go:53: [gnmic] [core] Subchannel picks a new address "eos:6030" to connect
2022/03/31 15:25:48.796396 /home/bewing/go/pkg/mod/google.golang.org/grpc@v1.44.0/grpclog/logger.go:53: [gnmic] [core] pickfirstBalancer: UpdateSubConnState: 0xc000816380, {CONNECTING <nil>}
2022/03/31 15:25:48.796459 /home/bewing/go/pkg/mod/google.golang.org/grpc@v1.44.0/grpclog/logger.go:53: [gnmic] [core] Channel Connectivity change to CONNECTING
2022/03/31 15:25:48.840135 /home/bewing/go/pkg/mod/google.golang.org/grpc@v1.44.0/grpclog/logger.go:53: [gnmic] [core] Subchannel Connectivity change to READY
2022/03/31 15:25:48.840321 /home/bewing/go/pkg/mod/google.golang.org/grpc@v1.44.0/grpclog/logger.go:53: [gnmic] [core] pickfirstBalancer: UpdateSubConnState: 0xc000816380, {READY <nil>}
2022/03/31 15:25:48.840419 /home/bewing/go/pkg/mod/google.golang.org/grpc@v1.44.0/grpclog/logger.go:53: [gnmic] [core] Channel Connectivity change to READY
2022/03/31 15:25:48.840535 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/gnmi_client_subscribe.go:207: [gnmic] target "eos:6030" gNMI client created
2022/03/31 15:25:48.842031 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/gnmi_client_subscribe.go:210: [gnmic] sending gNMI SubscribeRequest: subscribe='subscribe:{subscription:{path:{elem:{name:"interfaces"}  elem:{name:"interface"  key:{key:"name"  value:"Ethernet1"}}  elem:{name:"state"}  elem:{name:"counters"}}  mode:SAMPLE  sample_interval:10000000000}  subscription:{path:{elem:{name:"interfaces"}  elem:{name:"interface"  key:{key:"name"  value:"Ethernet1"}}  elem:{name:"state"}  elem:{name:"description"}}  mode:SAMPLE  sample_interval:10000000000}  encoding:BYTES}', mode='STREAM', encoding='BYTES', to eos:6030
2022/03/31 15:25:49.234532 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/collector.go:49: [gnmic] received gNMI Subscribe Response: &{SubscriptionName:port-stats SubscriptionConfig:{"name":"port-stats","paths":["/interfaces/interface[name=Ethernet1]/state/counters","/interfaces/interface[name=Ethernet1]/state/description"],"mode":"stream","stream-mode":"sample","encoding":"bytes","sample-interval":10000000000} Response:update:{timestamp:1648747327992018318  update:{path:{elem:{name:"interfaces"}  elem:{name:"interface"  key:{key:"name"  value:"Ethernet1"}}  elem:{name:"state"}  elem:{name:"counters"}  elem:{name:"in-broadcast-pkts"}}  val:{uint_val:2}}}}
2022/03/31 15:25:49.234825 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/collector.go:49: [gnmic] received gNMI Subscribe Response: &{SubscriptionName:port-stats SubscriptionConfig:{"name":"port-stats","paths":["/interfaces/interface[name=Ethernet1]/state/counters","/interfaces/interface[name=Ethernet1]/state/description"],"mode":"stream","stream-mode":"sample","encoding":"bytes","sample-interval":10000000000} Response:update:{timestamp:1648747327992068660  update:{path:{elem:{name:"interfaces"}  elem:{name:"interface"  key:{key:"name"  value:"Ethernet1"}}  elem:{name:"state"}  elem:{name:"counters"}  elem:{name:"in-discards"}}  val:{uint_val:0}}}}
2022/03/31 15:25:49.235112 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/collector.go:49: [gnmic] received gNMI Subscribe Response: &{SubscriptionName:port-stats SubscriptionConfig:{"name":"port-stats","paths":["/interfaces/interface[name=Ethernet1]/state/counters","/interfaces/interface[name=Ethernet1]/state/description"],"mode":"stream","stream-mode":"sample","encoding":"bytes","sample-interval":10000000000} Response:update:{timestamp:1648747327992086067  update:{path:{elem:{name:"interfaces"}  elem:{name:"interface"  key:{key:"name"  value:"Ethernet1"}}  elem:{name:"state"}  elem:{name:"counters"}  elem:{name:"in-errors"}}  val:{uint_val:0}}}}
[
  {
    "name": "port-stats",
    "timestamp": 1648747327992018318,
    "tags": {
      "interface_name": "Ethernet1",
      "source": "eos:6030",
      "subscription-name": "port-stats"
    },
    "values": {
      "/interfaces/interface/state/counters/in-broadcast-pkts": 2
    }
  }
]
[
  {
    "name": "port-stats",
    "timestamp": 1648747327992068660,
    "tags": {
      "interface_name": "Ethernet1",
      "source": "eos:6030",
      "subscription-name": "port-stats"
    },
    "values": {
      "/interfaces/interface/state/counters/in-discards": 0
    }
  }
]
2022/03/31 15:25:49.235370 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/collector.go:49: [gnmic] received gNMI Subscribe Response: &{SubscriptionName:port-stats SubscriptionConfig:{"name":"port-stats","paths":["/interfaces/interface[name=Ethernet1]/state/counters","/interfaces/interface[name=Ethernet1]/state/description"],"mode":"stream","stream-mode":"sample","encoding":"bytes","sample-interval":10000000000} Response:update:{timestamp:1648747327991652472  update:{path:{elem:{name:"interfaces"}  elem:{name:"interface"  key:{key:"name"  value:"Ethernet1"}}  elem:{name:"state"}  elem:{name:"counters"}  elem:{name:"in-fcs-errors"}}  val:{uint_val:0}}}}
[
  {
    "name": "port-stats",
    "timestamp": 1648747327992086067,
    "tags": {
      "interface_name": "Ethernet1",
      "source": "eos:6030",
      "subscription-name": "port-stats"
    },
    "values": {
      "/interfaces/interface/state/counters/in-errors": 0
    }
  }
]
[
  {
    "name": "port-stats",
    "timestamp": 1648747327991652472,
    "tags": {
      "interface_name": "Ethernet1",
      "source": "eos:6030",
      "subscription-name": "port-stats"
    },
    "values": {
      "/interfaces/interface/state/counters/in-fcs-errors": 0
    }
  }
]
2022/03/31 15:25:49.236316 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/collector.go:49: [gnmic] received gNMI Subscribe Response: &{SubscriptionName:port-stats SubscriptionConfig:{"name":"port-stats","paths":["/interfaces/interface[name=Ethernet1]/state/counters","/interfaces/interface[name=Ethernet1]/state/description"],"mode":"stream","stream-mode":"sample","encoding":"bytes","sample-interval":10000000000} Response:update:{timestamp:1648758304136140443  update:{path:{elem:{name:"interfaces"}  elem:{name:"interface"  key:{key:"name"  value:"Ethernet1"}}  elem:{name:"state"}  elem:{name:"counters"}  elem:{name:"in-multicast-pkts"}}  val:{uint_val:153171}}}}
2022/03/31 15:25:49.236609 /home/bewing/go/pkg/mod/github.com/karimra/gnmic@v0.24.2/app/collector.go:49: [gnmic] received gNMI Subscribe Response: &{SubscriptionName:port-stats SubscriptionConfig:{"name":"port-stats","paths":["/interfaces/interface[name=Ethernet1]/state/counters","/interfaces/interface[name=Ethernet1]/state/description"],"mode":"stream","stream-mode":"sample","encoding":"bytes","sample-interval":10000000000} Response:update:{timestamp:1648758348169492537  update:{path:{elem:{name:"interfaces"}  elem:{name:"interface"  key:{key:"name"  value:"Ethernet1"}}  elem:{name:"state"}  elem:{name:"counters"}  elem:{name:"in-octets"}}  val:{uint_val:17884279701}}}}
[
  {
    "name": "port-stats",
    "timestamp": 1648758304136140443,
    "tags": {
      "interface_name": "Ethernet1",
      "source": "eos:6030",
      "subscription-name": "port-stats"
    },
    "values": {
      "/interfaces/interface/state/counters/in-multicast-pkts": 153171
    }
  }
]
karimra commented 2 years ago

hi @bewing , thanks for opening this issue.

Right now, the event-merge processor only works:

    # a boolean, if set to true, the received gNMI notifications are stored in a cache.
    # the prometheus metrics are generated at the time a prometheus server sends scrape request.
    # this behavior allows the processors (if defined) to be run on all the generated events at once.
    # this mode uses more resource compared to the default one, but offers more flexibility when it comes 
    # to manipulating the data to customize the returned metrics using event-processors.
    gnmi-cache: false

In your case, each leaf is sent in a separate SubscribeResponse, so the responses need to be cached before a metric is written to the output.

I believe you are using a file output just for testing purposes ? Do you know which output you will ultimately use?

I will make sure to document all this a bit better.

bewing commented 2 years ago

In your case, each leaf is sent in a separate SubscribeResponse, so the responses need to be cached before a metric is written to the output.

I believe you are using a file output just for testing purposes ? Do you know which output you will ultimately use?

That is correct, I was using file output for iterative testing (same reason I only subscribed to a single interface). I was planning on outputting to InfluxDB, so seeing a generic approach to this (instead of the utility of only using it for scraping) for vendors with aggressive SubscribeResponse generation strategies are better supported. If not feasible, I will look at other options, so no worries.

I will make sure to document all this a bit better.

I much appreciate all the work you have done and continue to do!

karimra commented 2 years ago

The same caching method can be used for influxDB (I will need to write it), so if you are interested I can work on it.

The difference with prometheus will be that writing to influxDB will happen at regular intervals ( instead of waiting for prometheus to send a scrape request). The write interval will have to be long enough to make sure all the leaf values arrived, i.e write_interval > sample_interval

hellt commented 2 years ago

Maybe doing that processing/augmentation is better to happen in TSDB. Using a collector-side caching will cause timestamp alteration (original TS will be rewritten with a TS of a merge event), which might be undesirable.

This makes me thinking that maybe a cool hack would be to add an optional facts-collection step before the subscriptions start to collect certain information about the target and store it in mem for the sake of flexible augmentations of an event.

For example, we collect the facts from that eos target and maintain the JSON in an interface{} struct. Then a processor called event-augment can refer to this in-mem stored structure with a jq accessor, i.e.


processors:
  augment-desc:
    event-augment:
      key: description
      value: 'some jq expression to access description field for a target-specific in-mem stored json'
bewing commented 2 years ago

Maybe doing that processing/augmentation is better to happen in TSDB. Using a collector-side caching will cause timestamp alteration (original TS will be rewritten with a TS of a merge event), which might be undesirable.

The unfortunate part here is if you need the events merged prior to doing any tag processing, you cannot add tags to already written readings in InfluxDB (I am not sure about Prometheus). The timestamp argument is important, however -- if you are looking for extremely accurate readings, this would cause an issue. There's also the problem of timing -- I am not sure how you could guarantee that the correct readings are all grouped together, or that none would be missed, especially with multiple targets, as over time you might have a device restart its gNMI server, and there's the possibility of the windowing falling in the middle of a device emitting readings. Maybe something that could be addressed in a kafka streams pipeline?

For example, we collect the facts from that eos target and maintain the JSON in an interface{} struct. Then a processor called event-augment can refer to this in-mem stored structure with a jq accessor, i.e.

processors:
  augment-desc:
    event-augment:
      key: description
      value: 'some jq expression to access description field for a target-specific in-mem stored json'

I actually used this approach in telegraf's gNMI plugin to solve this problem for Arista -- there are gNMI subscriptions we have just to maintain metadata and attach to subsequent readings. Using ON_CHANGE subscriptions keeps the data from going stale

karimra commented 2 years ago

The resulting merged message will have the timestamp of the most recent message, not the time at which the merge happened. If someone is using a merge I believe they don't care about accurate timestamps per leaf anymore.

Augmenting messages with data from other subscriptions is the goal behind the event-merge processor. This could be done by adding a cache to the influxDB output. Right now, influxDB points are batched and written every 10s or 1000 points (configurable) By adding a cache the batching will happen for the gnmi updates instead of the influxDB points.

bewing commented 2 years ago

The resulting merged message will have the timestamp of the most recent message, not the time at which the merge happened. If someone is using a merge I believe they don't care about accurate timestamps per leaf anymore.

The primary Arista use case would be counters when using target_defined subscriptions (10s for counters, on_change for the rest of state). Caching/TS changing of events would have a non-zero impact on delta calculation, I would think (but haven't fully thought through).

For example, we collect the facts from that eos target and maintain the JSON in an interface{} struct. Then a processor called event-augment can refer to this in-mem stored structure with a jq accessor, i.e.

I did re-write the tag subscription code in telegraf with a similar approach (see influxdata/telegraf#11019). Given a subscription like

/network-instances/network-instance[name=*]/protocols/protocol[identifier=BGP][name=BGP]/bgp/neighbors/neighbor[neighbor-address=*]/state

And a config like:

path: "/network-instances/network-instance/protocols/protocol/bgp/neighbors/neighbor/state/description"
elements:
  - vrf
  - protocol
  - neighbor

It would be nice to say "if I receive an event with that has a /network-instances/network-instance/protocols/protocol/bgp/neighbors/neighbor/state/description value key and all the following tags:

Write the value of the value to an in-memory store keyed by the above tags + the source tag

And the same processor would then identify events with the same set of tags above, and write the description as a new tag.

I'd be happy to work on this if the community thinks there is value in it. Not sure what the concurrency model of gnmic is, and what kind of locks would be needed on the processor datastore (or if each target gets its own instance of a processor, etc)

karimra commented 2 years ago

What you are describing is a subset of the caching method I described above (which is already implemented in the prometheus output)

It basically caches all the received updates in a gNMI cache which allows a processor run to be applied to all the updates. So a user can augment a data point with any value/tag from any other update message in the cache.

The difference with the suggested solution is that there is no need to define which paths and elements need to be cached.