Streaming Syslog Events Through Junos Telemetry Interface

When we talk about streaming network telemetry data to a downstream collector, we are typically referring to “Interval Based” telemetry, which involves the periodic export of time-series data, such as counters or gauge metrics, at a user-defined frequency (eg. every 120 seconds).  But, as shown in Figure 1 below, Interval Based telemetry is just one of three main categories of network telemetry data.  “Query Based” telemetry involves a request/response methodology whereby a collector initiates the process by requesting operational data from the device, typically via a NETCONF RPC call, to which the router replies back with a response containing the requested data.  Finally, “Event Based” telemetry, which is the focus of this blog post, involves pushing event data (eg. syslog events) as streaming telemetry to a downstream collector.

As of Junos 18.1, users can subscribe to receiving Junos syslog events from the router as streamed telemetry via JTI (Junos Telemetry Interface) over gRPC.

1
Figure 1: Three Categories Of Network Telmetry Data

Prerequisites

The lab environment used to write this blog post consisted of the following:

For instructions on how to install the Junos Network Agent and OpenConfig packages, please refer to the “Prerequisites: OpenConfig & Network Agent Packages” section of the following blog post.

For instructions on how to install “jtimon”, please refer to the excellent blog post written by Marcel Wiget.

Configuring Syslog Events As Streaming Telemetry

Using a gRPC client (such as “jtimon“, as used in this blog post), a user can receive syslog event from a Junos device simply by subscribing to “/junos/events/” with a sample frequency of 0.  To try this out using jtimon, we first need to create a simple JSON configuration file to instruct jtimon how to connect to Junos and which telemetry sensors to subscribe to.  The following configuration file, shown in the snippet below, subscribes to all syslog events from router 10.10.10.1 via gRPC subscription to port 50051.  Be sure to adjust the hostportuser, and password values in accordance to your lab environment.  Note that we set the path to the top-level node “/junos/events/” and the freq to 0, which will stream all syslog events back to the client.

root@ubuntu:~/jtimon# pwd
/root/jtimon
root@ubuntu:~/jtimon# cat jtimon_config.json
{
    "host": "10.10.10.1",
    "port": 50051,
    "user": "username",
    "password": "password",
    "cid": "unique-alphanumeric-id-for-each-client-1”,
    "grpc" : {
        "ws" : 524288
    },
    "paths": [{
        "path": "/junos/events/",
        "freq": 0
    }]
}

Next, we launch the jtimon client, using the JSON configuration file above as an input parameter, as shown in the snippet below.  Note that the initial syslog messages we receive are for the actual configuration and commit operations for the subscription to “/junos/events/” for syslog event telemetry.

root@ubuntu:~/jtimon# ./jtimon --config jtimon_config.json --print
gRPC headers from Junos:
  grpc-accept-encoding: [identity,deflate,gzip]
  init-response: [response { subscription_id: 1 } path_list { path: "/junos/events/" } ]
  content-type: [application/grpc]
2018/04/04 11:23:05 system_id: mx0_re0
2018/04/04 11:23:05 component_id: 65535
2018/04/04 11:23:05 sub_component_id: 0
2018/04/04 11:23:05 path: sensor_1000:/junos/events/:/junos/events/:eventd
2018/04/04 11:23:05 sequence_number: 0
2018/04/04 11:23:05 timestamp: 1522866185156
2018/04/04 11:23:05 sync_response: %!d(bool=false)
2018/04/04 11:23:05   key: __timestamp__
2018/04/04 11:23:05   uint_value: 1522866185157
2018/04/04 11:23:05   key: __junos_re_stream_creation_timestamp__
2018/04/04 11:23:05   uint_value: 1522866185156
2018/04/04 11:23:05   key: __junos_re_payload_get_timestamp__
2018/04/04 11:23:05   uint_value: 1522866185156
2018/04/04 11:23:05   key: __junos_re_event_timestamp__
2018/04/04 11:23:05   uint_value: 1522866185156
2018/04/04 11:23:05   key: __prefix__
2018/04/04 11:23:05   str_value: /junos/events/event[id='SYSTEM' and type='3' and facility='5']/
2018/04/04 11:23:05   key: timestamp/seconds
2018/04/04 11:23:05   uint_value: 1522866185
2018/04/04 11:23:05   key: timestamp/microseconds
2018/04/04 11:23:05   uint_value: 155874
2018/04/04 11:23:05   key: priority
2018/04/04 11:23:05   uint_value: 6
2018/04/04 11:23:05   key: pid
2018/04/04 11:23:05   uint_value: 7324
2018/04/04 11:23:05   key: message
2018/04/04 11:23:05   str_value: Subscribing sensor_1000, id: 562950492949427, rep_rate: 0
2018/04/04 11:23:05   key: daemon
2018/04/04 11:23:05   str_value: eventd
2018/04/04 11:23:05   key: hostname
2018/04/04 11:23:05   str_value: mx0_re0
2018/04/04 11:23:05   key: __prefix__
2018/04/04 11:23:05   str_value: /junos/events/event[id='SYSTEM' and type='3' and facility='5']/attributes[key='message']/
2018/04/04 11:23:05   key: value
2018/04/04 11:23:05   str_value: Subscribing sensor_1000, id: 562950492949427, rep_rate: 0
2018/04/04 11:23:05   key: __prefix__
2018/04/04 11:23:05   str_value: /junos/events/event[id='SYSTEM' and type='3' and facility='5']/
2018/04/04 11:23:05   key: logoptions
2018/04/04 11:23:05   int_value: 1
[... CONTENT OMITTED FOR BREVITY ...]
2018/04/04 11:23:05 system_id: mx0_re0
2018/04/04 11:23:05 component_id: 65535
2018/04/04 11:23:05 sub_component_id: 0
2018/04/04 11:23:05 path: sensor_1000:/junos/events/:/junos/events/:eventd
2018/04/04 11:23:05 sequence_number: 4
2018/04/04 11:23:05 timestamp: 1522866185159
2018/04/04 11:23:05 sync_response: %!d(bool=false)
2018/04/04 11:23:05   key: __timestamp__
2018/04/04 11:23:05   uint_value: 1522866185358
2018/04/04 11:23:05   key: __junos_re_stream_creation_timestamp__
2018/04/04 11:23:05   uint_value: 1522866185159
2018/04/04 11:23:05   key: __junos_re_payload_get_timestamp__
2018/04/04 11:23:05   uint_value: 1522866185159
2018/04/04 11:23:05   key: __junos_re_event_timestamp__
2018/04/04 11:23:05   uint_value: 1522866185159
2018/04/04 11:23:05   key: __prefix__
2018/04/04 11:23:05   str_value: /junos/events/event[id='UI_COMMIT_PROGRESS' and type='2' and facility='23']/
2018/04/04 11:23:05   key: timestamp/seconds
2018/04/04 11:23:05   uint_value: 1522866185
2018/04/04 11:23:05   key: timestamp/microseconds
2018/04/04 11:23:05   uint_value: 158748
2018/04/04 11:23:05   key: priority
2018/04/04 11:23:05   uint_value: 6
2018/04/04 11:23:05   key: pid
2018/04/04 11:23:05   uint_value: 26526
2018/04/04 11:23:05   key: message
2018/04/04 11:23:05   str_value: UI_COMMIT_PROGRESS: Commit operation in progress: signaling 'agent for all the telemetry sensors', pid 7475, signal 1, status 0 with notification errors enabled
2018/04/04 11:23:05   key: daemon
2018/04/04 11:23:05   str_value: mgd
2018/04/04 11:23:05   key: hostname
2018/04/04 11:23:05   str_value: mx0_re0
2018/04/04 11:23:05   key: __prefix__
2018/04/04 11:23:05   str_value: /junos/events/event[id='UI_COMMIT_PROGRESS' and type='2' and facility='23']/attributes[key='message']/
2018/04/04 11:23:05   key: value
2018/04/04 11:23:05   str_value: signaling 'agent for all the telemetry sensors', pid 7475, signal 1, status 0 with notification errors enabled
2018/04/04 11:23:05   key: __prefix__
2018/04/04 11:23:05   str_value: /junos/events/event[id='UI_COMMIT_PROGRESS' and type='2' and facility='23']/
2018/04/04 11:23:05   key: logoptions
2018/04/04 11:23:05   int_value: 1
[... CONTENT OMITTED FOR BREVITY ...]

Moving over the Juniper router, we can verify the telemetry subscription status via the “show agent sensors” operational command, as follows:

root@mx0_re0> show agent sensors 

Sensor Information : 
           
    Name                                    : __default_fabric_sensor__ 
    Resource                                : /junos/system/linecard/fabric/ 
    Version                                 : 1.0                  
    Sensor-id                               : 2277069355            
    Subscription-ID                         : 562952230490667      
    Parent-Sensor-Name                      : Not applicable       
    Component(s)                            : PFE                   
 
    Server Information : 
           
        Name                                : __default__snmp_server__ 
        Scope-id                            : 0                     
        Remote-Address                      : 0.0.0.0               
        Remote-port                         : 0                     
        Transport-protocol                  : UDP                   

    Profile Information : 
           
        Name                                : __default_snmp_export_profile__ 
        Reporting-interval                  : 30                    
        Payload-size                        : 5000                  
        Address                             : 0.0.0.0               
        Port                                : 0                     
        Timestamp                           : 0                     
        Format                              : GPB                   
        DSCP                                : 0                     
        Forwarding-class                    : 0                     
        Loss-priority                       : low                  

Sensor Information : 
           
    Name                                    : sensor_1000           
    Resource                                : /junos/events/        
    Version                                 : 1.0                  
    Sensor-id                               : 539528115             
    Subscription-ID                         : 1000                 
    Parent-Sensor-Name                      : Not applicable       
    Component(s)                            : eventd                

    Profile Information : 
           
        Name                                : export_1000           
        Reporting-interval                  : 0                     
        Payload-size                        : 5000                  
        Format                              : GPB                   

root@mx0_re0>

Let’s verify that we are indeed able to receive syslog events as streaming telemetry at the collector in real-time by running some commands on the router.  So for example, by issuing the “show agent sensors” command from above on the router, we should expect to receive a “UI_CMDLINE_READ_LINE” syslog message via jtimon, as shown (highlighted in green) below:

root@ubuntu:~/jtimon# ./jtimon --config jtimon_config.json --print
gRPC headers from Junos:
  grpc-accept-encoding: [identity,deflate,gzip]
  init-response: [response { subscription_id: 1 } path_list { path: "/junos/events/" } ]
  content-type: [application/grpc]
2018/04/04 11:23:19 system_id: mx0_re0
2018/04/04 11:23:19 component_id: 65535
2018/04/04 11:23:19 sub_component_id: 0
2018/04/04 11:23:19 path: sensor_1000:/junos/events/:/junos/events/:eventd
2018/04/04 11:23:19 sequence_number: 7
2018/04/04 11:23:19 timestamp: 1522866199661
2018/04/04 11:23:19 sync_response: %!d(bool=false)
2018/04/04 11:23:19   key: __timestamp__
2018/04/04 11:23:19   uint_value: 1522866199661
2018/04/04 11:23:19   key: __junos_re_stream_creation_timestamp__
2018/04/04 11:23:19   uint_value: 1522866199660
2018/04/04 11:23:19   key: __junos_re_payload_get_timestamp__
2018/04/04 11:23:19   uint_value: 1522866199660
2018/04/04 11:23:19   key: __junos_re_event_timestamp__
2018/04/04 11:23:19   uint_value: 1522866199660
2018/04/04 11:23:19   key: __prefix__
2018/04/04 11:23:19   str_value: /junos/events/event[id='UI_CMDLINE_READ_LINE' and type='2' and facility='23']/
2018/04/04 11:23:19   key: timestamp/seconds
2018/04/04 11:23:19   uint_value: 1522866199
2018/04/04 11:23:19   key: timestamp/microseconds
2018/04/04 11:23:19   uint_value: 659448
2018/04/04 11:23:19   key: priority
2018/04/04 11:23:19   uint_value: 6
2018/04/04 11:23:19   key: pid
2018/04/04 11:23:19   uint_value: 25707
2018/04/04 11:23:19   key: message
2018/04/04 11:23:19   str_value: UI_CMDLINE_READ_LINE: User 'root', command 'show agent sensors '
2018/04/04 11:23:19   key: daemon
2018/04/04 11:23:19   str_value: mgd
2018/04/04 11:23:19   key: hostname
2018/04/04 11:23:19   str_value: mx0_re0
2018/04/04 11:23:19   key: __prefix__
2018/04/04 11:23:19   str_value: /junos/events/event[id='UI_CMDLINE_READ_LINE' and type='2' and facility='23']/attributes[key='command']/
2018/04/04 11:23:19   key: value
2018/04/04 11:23:19   str_value: show agent sensors 
2018/04/04 11:23:19   key: __prefix__
2018/04/04 11:23:19   str_value: /junos/events/event[id='UI_CMDLINE_READ_LINE' and type='2' and facility='23']/
2018/04/04 11:23:19   key: logoptions
2018/04/04 11:23:19   int_value: 129

Filtering For Specific Syslog Events

When subscribing to telemetry-based syslog events, the following snippet below represents a generic message structure a user can expect to receive as key/value pairs from the syslog telemetry stream.  As mentioned above, subscribing to the top-level node “/junos/events/” results in receiving all syslog events from the device.  In order to filter for specific events, we need to construct an XPATH expression against the generic message structure below.

list event {
  key "id type facility";
  dr:source "event";

  leaf id {
      type string;
      dr:source "id";
  }

  leaf type {
      type uint8;
      dr:source "type";
  }

  container timestamp {
      dr:source "timestamp";
      leaf seconds {
          dr:source "seconds";
          type uint32;
      }
      leaf microseconds {
          dr:source "microseconds";
          type uint32;
      }
  }

  leaf priority {
      dr:source "priority";
      type uint8;
  }

  leaf facility {
      type uint8;
      dr:source "facility";
  }

  leaf pid {
      dr:source "pid";
      type uint32;
  }

  leaf message {
      dr:source "message";
      type string;
  }

  leaf daemon {
      dr:source "daemon";
      type string;
  }

  leaf hostname {
      dr:source "hostname";
      type string;
  }

  leaf lsname {
      dr:source "lsname";
      type string;
  }

  list attributes {
      key "key";
      dr:source "attributes";
      leaf key {
          dr:source "key";
          type string;
      }

      leaf value {
          dr:source "value";
          type string;
      }
  }

  leaf logoptions {
      dr:source "logoptions";
      type int32;
  }
}

For example, let’s say we want to receive notifications whenever a user commits a configuration on the router.  In Junos, everytime a user executes a commit operation, a “UI_COMMIT” syslog message is generated.  So in this case, to receive only “UI_COMMIT” messages, we would specify the following path as our sensor subscription: “/junos/events/event[id=’UI_COMMIT’]“.  Using jtimon, we would use the following as our input JSON configuration file:

root@ubuntu:~/jtimon# pwd
/root/jtimon
root@ubuntu:~/jtimon# cat jtimon_config.json
{
    "host": "10.10.10.1",
    "port": 50051,
    "user": "username",
    "password": "password",
    "cid": "unique-alphanumeric-id-for-each-client-1”,
    "grpc" : {
        "ws" : 524288
    },
    "paths": [{
        "path": "/junos/events/event[id='UI_COMMIT']",
        "freq": 0
    }]
}

Launching the jtimon client, using the JSON configuration file above as an input parameter, we would see the response snippet below whenever a commit operation is performed on the router:

root@ubuntu:~/jtimon# ./jtimon --config jtimon_config.json --print
gRPC headers from Junos:
  grpc-accept-encoding: [identity,deflate,gzip]
  init-response: [response { subscription_id: 1 } path_list { path: "/junos/events/event[id='UI_COMMIT']/" } ]
  content-type: [application/grpc]
2018/04/04 18:40:10 system_id: mx0_re0
2018/04/04 18:40:10 component_id: 65535
2018/04/04 18:40:10 sub_component_id: 0
2018/04/04 18:40:10 path: sensor_1000:/junos/events/event[id='UI_COMMIT']/:/junos/events/event[id='UI_COMMIT']/:eventd
2018/04/04 18:40:10 sequence_number: 0
2018/04/04 18:40:10 timestamp: 1522892410090
2018/04/04 18:40:10 sync_response: %!d(bool=false)
2018/04/04 18:40:10   key: __timestamp__
2018/04/04 18:40:10   uint_value: 1522892410092
2018/04/04 18:40:10   key: __junos_re_stream_creation_timestamp__
2018/04/04 18:40:10   uint_value: 1522892410089
2018/04/04 18:40:10   key: __junos_re_payload_get_timestamp__
2018/04/04 18:40:10   uint_value: 1522892410089
2018/04/04 18:40:10   key: __junos_re_event_timestamp__
2018/04/04 18:40:10   uint_value: 1522892410089
2018/04/04 18:40:10   key: __prefix__
2018/04/04 18:40:10   str_value: /junos/events/event[id='UI_COMMIT' and type='2' and facility='23']/
2018/04/04 18:40:10   key: timestamp/seconds
2018/04/04 18:40:10   uint_value: 1522892410
2018/04/04 18:40:10   key: timestamp/microseconds
2018/04/04 18:40:10   uint_value: 89646
2018/04/04 18:40:10   key: priority
2018/04/04 18:40:10   uint_value: 5
2018/04/04 18:40:10   key: pid
2018/04/04 18:40:10   uint_value: 54802
2018/04/04 18:40:10   key: message
2018/04/04 18:40:10   str_value: UI_COMMIT: User 'root' requested 'commit' operation (comment: none)
2018/04/04 18:40:10   key: daemon
2018/04/04 18:40:10   str_value: mgd
2018/04/04 18:40:10   key: hostname
2018/04/04 18:40:10   str_value: mx0_re0
2018/04/04 18:40:10   key: __prefix__
2018/04/04 18:40:10   str_value: /junos/events/event[id='UI_COMMIT' and type='2' and facility='23']/attributes[key='message']/
2018/04/04 18:40:10   key: value
2018/04/04 18:40:10   str_value: none
2018/04/04 18:40:10   key: __prefix__
2018/04/04 18:40:10   str_value: /junos/events/event[id='UI_COMMIT' and type='2' and facility='23']/
2018/04/04 18:40:10   key: logoptions
2018/04/04 18:40:10   int_value: 1

Building on the above example, let’s say that we want to receive all syslog messages that begin with ‘UI_COMMIT’, such as ‘UI_COMMIT‘ and ‘UI_COMMIT_PROGRESS‘, then we would specify the following path as our sensor subscription: “/junos/events/event[starts-with(id, ‘UI_COMMIT’)]“.

Or, say we want to receive all syslog events sourced from the Management Daemon (mgd), then the following sensor subscription would be used: “/junos/events/event[daemon=’mgd’]“.

To view a complete listing of all possible Junos syslog messages in a software release, use the System Log Explorer

Use the Junos system logger utility (from the Junos shell) to quickly generate any syslog event at will.  It has the following command syntax:

logger -e EVENT_ID -p SYSLOG_PRIORITY -d DAEMON -a ATTRIBUTE=VALUE MESSAGE

eg. logger -e TECHMOCHA_EVENT_FAKE -d mgd -p external.info -a attribute1=value1 “THIS IS A FAKE SYSLOG EVENT!!”

One comment

  1. Great blog, thanks!
    BTW to get just a single event for every commit, one can trigger on UI_COMMIT_COMPLETED:

    “`
    $ cat vmx1.json
    {
    “host”: “172.18.0.2”,
    “port”: 50051,
    “cid”: “my-client-id”,
    “grpc” : {
    “ws” : 524288
    },
    “paths”: [{
    “path”: “/junos/events/event[id=’UI_COMMIT_COMPLETED’]”,
    “freq”: 0
    }]
    }
    “`

    Launch jtimon:

    “`
    $ jtimon –config vmx1.json –print
    gRPC headers from Junos:
    init-response: [response { subscription_id: 1 } path_list { path: “/junos/events/event[id=\’UI_COMMIT_COMPLETED\’]/” } ]
    content-type: [application/grpc]
    grpc-accept-encoding: [identity,deflate,gzip]
    2018/04/05 11:46:21 system_id: vmxdockerlight_vmx1_1
    2018/04/05 11:46:21 component_id: 65535
    2018/04/05 11:46:21 sub_component_id: 0
    2018/04/05 11:46:21 path: sensor_1000:/junos/events/event[id=’UI_COMMIT_COMPLETED’]/:/junos/events/event[id=’UI_COMMIT_COMPLETED’]/:eventd
    2018/04/05 11:46:21 sequence_number: 0
    2018/04/05 11:46:21 timestamp: 1522921580979
    2018/04/05 11:46:21 sync_response: %!d(bool=false)
    2018/04/05 11:46:21 key: __timestamp__
    2018/04/05 11:46:21 uint_value: 1522921580980
    2018/04/05 11:46:21 key: __junos_re_stream_creation_timestamp__
    2018/04/05 11:46:21 uint_value: 1522921580979
    2018/04/05 11:46:21 key: __junos_re_payload_get_timestamp__
    2018/04/05 11:46:21 uint_value: 1522921580979
    2018/04/05 11:46:21 key: __junos_re_event_timestamp__
    2018/04/05 11:46:21 uint_value: 1522921580979
    2018/04/05 11:46:21 key: __prefix__
    2018/04/05 11:46:21 str_value: /junos/events/event[id=’UI_COMMIT_COMPLETED’ and type=’2′ and facility=’23’]/
    2018/04/05 11:46:21 key: timestamp/seconds
    2018/04/05 11:46:21 uint_value: 1522921580
    2018/04/05 11:46:21 key: timestamp/microseconds
    2018/04/05 11:46:21 uint_value: 979726
    2018/04/05 11:46:21 key: priority
    2018/04/05 11:46:21 uint_value: 4
    2018/04/05 11:46:21 key: pid
    2018/04/05 11:46:21 uint_value: 12897
    2018/04/05 11:46:21 key: message
    2018/04/05 11:46:21 str_value: UI_COMMIT_COMPLETED: commit complete
    2018/04/05 11:46:21 key: daemon
    2018/04/05 11:46:21 str_value: mgd
    2018/04/05 11:46:21 key: hostname
    2018/04/05 11:46:21 str_value: vmxdockerlight_vmx1_1
    2018/04/05 11:46:21 key: logoptions
    2018/04/05 11:46:21 int_value: 1
    ^C

    Collector Stats (Run time : 6.752891782s)
    1 : in-packets
    13 : data points (KV pairs)
    231 : in-header wirelength (bytes)
    594 : in-payload length (bytes)
    594 : in-payload wirelength (bytes)
    99 : throughput (bytes per seconds)

    “`

Leave a Reply