Handling Solace Message Router Events in Applications

Solace message routers expose a rich set of events that help users understand the behavior of their applications and Solace message routers. These events are of interest to diverse groups including system administrators, middleware managers, application support teams and developers. Administrators and support teams use a variety of tools such as syslog servers, monitoring dashboards, NMS systems, etc to collect and process events of interest. As an application developer, these tools may not be accessible or familiar to you. Besides, not all the events from the router is of interest to development teams. In this blog post, I will discuss how you can gather Solace events of interest directly in your application.

Event Types

Before we begin, let’s briefly take a look at the types of events emanating from the Solace message router.

• System Events: These events indicate the overall system (Solace message router) health and status, not related to specific message VPNs or clients. Events relating to component failure, subsystem failures, and message spool or disk utilization alerts are included in this category. These events are generally of interest to operations teams.
• Message VPN Events: As the name indicates, these are the events related to a specific message VPN. Events relating to message VPN resources such as connection and subscription limits are included in this category. In addition to operations teams, application teams will also find these events useful to optimize and fine-tune application resource utilization.
• Client Events: These events cover the individual client connections, disconnects etc. For application teams, these events will help in troubleshooting.
• Subscription Events: These events cover topic subscription and un-subscription events. Similar to client events, these will be helpful to application teams when troubleshooting.

Log Files

The default behavior for the Solace message router is to log all these events on the Solace message router in various log files. The following files in particular have events that are of interest to application developers.

• Event.log: All of the events (including client and subscription events) are logged in event log.
• System.log: All operational events in the system and message VPN scope events are saved in this file.

These files are maintained on the Solace message router for a limited time based on the event volume. They are rolled over as they grow and Solace keeps a limited number of them available on the Solace message router. The logs will rotate once it hits 50M in size and at most 20 iterations of the file are kept and older files are automatically removed.

On a Solace message router with high logging rate, it’s not uncommon for the event.log files to be rolled over in a matter of hours and removed intra-day. Solace also provides a mechanism for these logs to be exported to an external syslog server. Solace recommends syslog export so that events are available longer than what the Solace message router can hold.  This also allows logs to be processed without impact to the Solace message router.

Events on the Message Bus

The Solace message router log files and syslog servers are generally managed by the administrators or operations teams and application teams have limited to no access to these. This is especially true in environments like production. In some cases, they are available as log exports, monitoring dashboards, etc. Though this exposes these events to the application teams, its usually hard to integrate them into application space in order to take action on them in a timely fashion.

Message bus Events

So, how can application team gain access to the events easily? Solace message routers can be configured to publish informational events on the message bus as regular messages. This empowers applications to subscribe to events like regular messages and process them in the application space. System administrators and operators who depend on Solace message router logs, syslog forwarding, etc. will continue to get them the way that they always have.

Management VPN

All events relating to the message VPN are published and contained in the same message VPN. But what about events that are global in scope? As we have seen above, the systems events may also be of interest to application teams. These system events are not published on any single message VPN, but on special “Management VPN” if one is configured. Assuming this is configured and enabled, your application can now subscribe to system events as well by subscribing to predefined topics on the Management VPN.

Benefits

So, how does this benefit you?

• All events pertaining to the message VPN are published on the same message VPN in predefined topic hierarchy. This mean no additional access mechanisms or tools are required to gather events.
• The log topic hierarchy is fine grained and intuitive, allowing you to use topic filtering. This enables you to harness Solace message router’s topic routing for event messages as well. Event filtering by topic also minimizes the overhead of processing and parsing the events in your application.
• The events are now available to in your application space as they happen. Any application action you may want to take based on these events is both easier and near real time.

Drawbacks

Event processing does have some, albeit negligible drawbacks. However, the benefits outweigh the drawbacks.

• Publishing the events on the message bus does use some system resources on the Solace message router in terms of topic routing, network resources, etc. If your environment has too many events being published (eg: some misconfigured clients trying to connect and fail repeatedly) then it can put some load on the messaging system. But in a well configured environment, the overhead on the messaging subsystems should be quite low given the tremendous message processing capacity of the Solace message routers.
• Likewise, processing excessive events can cause some overhead on the application. By using appropriate topic filtering, you can minimize this in your application.
• Processing event messages in addition to application messages in your application may be seen as “polluting” the application space. If this is a concern, a separate “monitoring application” focusing only on events message processing is an option.

Event Handling

Topic hierarchy

As mentioned before, the events are published on pre-defined topic that is thoughtfully structured to offer greater flexibility for subscribing application.

SMF vs MQTT

The topic syntax for different supported protocols is beyond the scope of this blog posts. Briefly, SMF (Solace message format) uses ‘/’ as topic separator and ‘>’ and ‘*’ as wildcards. MQTT on the other hand uses ‘+’ and ‘#’ as wildcard characters.  Please refer Topic Support and Syntax for details on topic syntax.

This difference in wildcard characters gives rise to different field topic Prefix for event messages. The solace message VPN can be configured to publish events in SMF, MQTT or both formats.

More on subscription events

By default, topics where subscription events are published to don’t have the message VPN or client info in them. In this sense, they are published as global events.  This format is referred to as “V1 format” in Solace documentation and this is the default topic format for publishing subscription events. The newer format includes these fields and its referred as (as you may have guessed) “V2 format”. If you intend to apply topic filtering on these fields for subscription events, the topic format should be set to “V2” on the VPN. Please refer to “Subscribing to Message bus Events” for additional information and steps. Unless you are working with legacy admin scripts that depend on V1 format, you should consider enabling V2 format on the Solace message router.

The following table lists the fields for different event messages.

The topic hierarchy with few samples is given below for each of the event types.

System Events

• Format:

  #LOG/<Level>/SYSTEM/<RouterName>/<EventName>

• Samples:

  #LOG/WARNING/SYSTEM/solace1/SYSTEM_CLIENT_CONNECT_AUTH_FAIL

VPN Events

• Format:

  #LOG/<level>/VPN/<routerName>/<eventName>/<vpnName>

• Samples:

  #LOG/WARNING/VPN/solace1/VPN_AD_MSG_SPOOL_HIGH/myVpn

  #LOG/WARNING/VPN/solace1/VPN_AD_MSG_SPOOL_QUOTA_EXCEED/myVpn

Client Events

• Format:

  #LOG/<level>/CLIENT/<routerName>/<eventName>/<vpnName>/<ClientName>

• Samples:

  #LOG/INFO/CLIENT/solace1/CLIENT_CLIENT_CONNECT/myVpn/appHost.domain/15174/#000b0001

  #LOG/WARNING/CLIENT/solace1/CLIENT_CLIENT_LARGE_MESSAGE/myVpn/appHost.domain/14986/#000b0001

Subscription Events (v1)

• Format:

  #LOG/INFO/SUB_ADD|SUB_DEL/<subscribedTopic>

• Samples:

  #LOG/INFO/SUB_ADD/test1

  #LOG/INFO/SUB_DEL/test1

Subscription Events (v2)

• Format:

  #LOG/INFO/SUB/<routerName>/ADD|DEL/<vpnName>/<clientName>/<subscribedTopic>

• Samples:

  #LOG/INFO/SUB/solace1/ADD/myVpn/appHost.domain /14320/#000b0001/test/1

  #LOG/INFO/SUB/solace1/DEL/myVpn/appHost.domain/14320/#000b0001/test/1

Application handling

To gather these event messages on your application, there are no special APIs or tools required. The events are published on the above mentioned predefined topics and applications can subscribe to them using regular topic subscription mechanism.  A simple JMS client that subscribes to all client connect events is given below:

JMS Subscriber for Client Connect Events

public void onMessage(Message message) {
try {
  if (message != null) {
   byte [] bytes = new byte [1024] ;
   ((BytesMessage)message).readBytes(bytes,  bytes.length);
   System.out.println("Got Event: " + message.getJMSDestination());
   System.out.println(new String(bytes,  "UTF-8"));
  }
}
catch (JMSException e) { e.printStackTrace(); }
catch (UnsupportedEncodingException e) { e.printStackTrace(); }
}

try {
   private String cfJNDIName = "cf/default";
   long napTime = 60000 ;

   Hashtable<tring, Object> env = new Hashtable<String, Object>();
   // populating env skipped

   // create context and lookup connection factory
   initialContext = new InitialContext(env);
   ConnectionFactory cf =         
       (ConnectionFactory)initialContext.lookup(cfJNDIName);

   // Create the connection,  session,  and topic to publish/subscribe to.
   Connection connection = cf.createConnection();
   Session session = connection.createSession(false,     
               Session.AUTO_ACKNOWLEDGE);
   // Subscribe to all client connect events on message bus
   final String strEventTopic =     
         String.format("#LOG/INFO/CLIENT/*/CLIENT_CLIENT_CONNECT/>");
   System.out.println ("Subscring to log topic: " + strEventTopic);
   Topic topic = session.createTopic(strEventTopic);

   // create consumer and start connection
   MessageConsumer consumer = session.createConsumer(topic);
   consumer.setMessageListener(this);
   connection.start();
   Thread.sleep(napTime); 
}
catch (...)  // skipped

JCSMP Event Monitor

As you can see from the JMS sample above, any consumer application can be used to subscribe to event messages by using the right topic hierarchy. “EventMonitor.java” bundled with the Solace Java API samples implements the same in Java API.

Subscribing events to Queues

Since the events are published onto the message bus like other messages, it is possible to configure endpoints to attract event messages. For eg, if you want to collect all ERROR logs to a queue for end of day processing, you can easily do that by adding a topic subscription “#LOG/ERROR/>” on a queue. Its recommended that the log messages be sent to a separate queue so they don’t clutter application queues. Also, allocate the spool quota appropriately for the log queue(s) so the events don’t over-consume message spool resources. Starting SolOS 7.2, you will be able to set TTL on endpoint level and this is recommended to be enabled for such log queues.

Event subscription Examples

Combined with topic wildcarding, applications can subscribe to entire class of events (eg: all client events), events from a specific client or a single event from a specific client.

Using sdkperf as sample client, some possible event subscriptions are shown below.

Subscribing to all event logs on the management VPN

sdkperf_java.sh -cip tcp://192.168.56.104:55555 -cu mgmtuser@mgmtvpn -cp password -stl '#LOG/>' -md –q

Subscribing to all Warning events on myVpn

sdkperf_java.sh -cip tcp://192.168.56.104:55555 -cu user1@myVpn -cp password  -stl '#LOG/WARNING/>' -md -q

Subscribing to subscription events on myVpn

sdkperf_java.sh -cip tcp://192.168.56.104:55555 -cu user1@myVpn -cp password  -stl '#LOG/INFO/SUB/*/ADD/>' -md –q

Subscribing to all events from a specific client

sdkperf_java.sh -cip tcp://192.168.56.104:55555 -cu user1@myVpn -cp password  -stl '#LOG/*/*/*/ADD/*/appHost*/>' -md -q

Handling specific events

As the sample events show above, the topic where the events are delivered to has a wealth of info in itself such as the client name. The message body is delivered as text attachment that has further information on the event.

Consider for example, the event details delivered for a VPN_AD_MSG_SPOOL_QUOTA_EXCEED event which is generated when the spool quota for the VPN has exceeded

Destination: #LOG/WARNING/VPN/solace1/VPN_AD_MSG_SPOOL_QUOTA_EXCEED/myVpn

2016-03-16T12:01:40.178+00:00 WARNING solace1 VPN: VPN_AD_MSG_SPOOL_QUOTA_EXCEED: myVpn - Message VPN (4) Queue q1 message spool quota (1024 kB) exceeded,  messages discarded

As you can see the event message body has information such as end point that caused this event and current message spool quota This information is specific to each event.

Now, lets consider another event, a client disconnect event:

Destination: #LOG/INFO/CLIENT/solace1/CLIENT_CLIENT_DISCONNECT/myVpn/appHost.domain/13275/#000b0001

2016-03-17T18:23:50.782+00:00 <local3.info> solace-vmr4 VPN-vpn1INFO: CLIENT: CLIENT_CLIENT_DISCONNECT: vpn1 marvin.local/15963/#000b0001 Client (47) marvin.local/15963/#000b0001 username user1 WebSessionId (N/A) reason(Peer TCP Closed) final statistics - dp(34,  34,  0,  2,  34,  36,  818,  1129,  0,  480,  818,  1609,  0,  0,  0,  0,  0,  0,  0,  0,  0,  0) conn(0,  0,  192.168.56.1:52150,  CLSWT,  0,  0,  0) zip(0,  0,  0,  0,  0.00,  0.00,  0,  0,  0,  0,  0,  0,  0,  0) web(0,  0,  0,  0,  0,  0,  0),  SslVersion(),  SslCipher()

This event has a lot more information on the connection. As you can see, parsing this is more involved than parsing the previous spool event. Such useful and complex events are documented in “Solace Message Bus Management” (See: Interpreting client disconnect event logs)

Solace also supplies a tool (decode-event-log) to interpret them that can be used as reference to parse them in the application. Contact your router administrator to access this tool. A sample output from this tool is given below, which corresponds to the client disconnect above.

Sample decode-event-log output

                              type: : vpn1 marvin.local/15963/#000b0001 
                         Client ID: 47
                     name/username: marvin.local/15963/#000b0001 
                           username user1
                         sessionId: N/A
                  disconnectReason: Peer TCP Closed
               controlMsgsReceived: 34
              controlMsgsDelivered: 34
                 topicMsgsReceived: 0
                topicMsgsDelivered: 2
                 totalMsgsReceived: 34
                totalMsgsDelivered: 36
              controlBytesReceived: 818
             controlBytesDelivered: 1129
                topicBytesReceived: 0
               topicBytesDelivered: 480
                totalBytesReceived: 818
               totalBytesDelivered: 1609
                 curMsgRateIngress: 0
                  curMsgRateEgress: 0
                 avgMsgRateIngress: 0
                  avgMsgRateEgress: 0
            deniedDuplicateClients: 0
       discardsNoSubscriptionMatch: 0
           discardsTopicParseError: 0
                discardsParseError: 0
                 discardsMsgTooBig: 0
        discardsTransmitCongestion: 0
                        recvQBytes: 0
                        sendQBytes: 0
                        clientAddr: 192.168.56.1
                        clientPort: 52150
                             state: CLSWT
                        outOfOrder: 0
                    fastRetransmit: 0
                   timedRetransmit: 0
           compressedBytesReceived: 0
          compressedBytesDelivered: 0
         uncompressedBytesReceived: 0
        uncompressedBytesDelivered: 0
           compressionRatioIngress: 0.00
            compressionRatioEgress: 0.00
      curCompressedByteRateIngress: 0
       curCompressedByteRateEgress: 0
    curUncompressedByteRateIngress: 0
     curUncompressedByteRateEgress: 0
      avgCompressedByteRateIngress: 0
       avgCompressedByteRateEgress: 0
    avgUncompressedByteRateIngress: 0
     avgUncompressedByteRateEgress: 0
                   webMsgsReceived: 0
                  webMsgsDelivered: 0
                  webBytesReceived: 0
                 webBytesDelivered: 0
                     webOutOfOrder: 0
                 webFastRetransmit: 0
                webTimedRetransmit: 0
                        sslVersion: 
              sslCipherDescription:

Configuration

By default, the events are not published on the message bus, nor a management VPN present out of the box. In this section, I will review the administrative activities relating to event publishing on the message bus. The actual steps and CLI command however are not covered here. Please refer to respective sections in the “Solace Feature Provisioning Guide”

Enabling Message bus events

To have events to be published on the message bus, this feature needs to be enabled on the Solace message router for the message VPN. You can choose what types of events should be published on the message bus: VPN, Client, Subscription events. Please refer to “Publishing Message-VPN level Events” in “Subscribing to Message bus Events”.

Event format

Subscription events support two types of topic hierarchy. By default, V1 format is used. If you prefer the newer V2 format with VPN, Client-name etc. in the topic name, this this need to be set on the message VPN. Please refer to Publishing Subscription Events in Subscribing to Message bus Events.

MQTT Topics

Due to difference in wildcard characters in MQTT, applications using MQTT protocol should explicitly use MQTT topic prefix. Please refer to Setting a Topic Format for Published Events in Subscribing to Message bus Events

Management VPN

All system scope events can be configured to be published on a special “Management VPN”. Each router can designate one VPN as management VPN. Please refer Designating Management Message VPNs

By default, only system scoped events are published on the management VPN. All VPN scope events are published to individual message VPNs. If you desire to collect all events in a single consumer application (eg: a monitoring application), it recommended that you use mechanisms such as interfacing with syslog server.

Reference

So for in this post we have covered the following grounds related to event handling in the application.

• Required background such as event types
• Available mechanisms such as events on message bus and management VPN
• Implementation details such as topic hierarchy and sample code
• Configuration overview

Solace documentation is accessible from the Solace developer portal. You are encouraged to check them out for further information and details.