Piper Push Cache Documentation Download Samples Contact  

Building Realtime, Live-Updating Displays with JavaScript and Piper, a JSON Push Cache

Some information has to be displayed in real time with live updating to be effective. With JavaScript and Piper it is easier to build than ever.

Background

The kinds of applications that call out for using a push model include web pages that display stock price, race results of an ongoing marathon, or an operations log for a system. All those applications are expected to update immediately on changes in the underlying data. Without a push model the display of changed data will lag and provide less than satisfying results.

Building a system that makes use of push technology is a bit more involved than making a Rails app that pulls data from a database. It does not have to be that difficult though. With some planning and the right tools it is not that difficult to build a realtime push system with dynamic updating displays. By building this operation logging prototype the planning, tool identification, and integration are demonstrated.

The Tools

The tools or components available include JavaScript for the dynamic web pages. There really isn't much choice. If you want dynamic pages JavaScript is really the best choice today.

Moving from front end back to the data sources the next piece is the method for getting data to the display so the JavaScript components can update the page. The natural format for the data is JSON as JavaScript handles that so well. In the case of an operation log console, the data consists of log entries as JSON records. Since the log entries need to be pushed to the display either WebSockets or Server Send Events will get the jobs done effectively. WebSockets first with a fallback to SSE for mobile devices.

The server is the next component in the push chain but before getting to that the data distribution needs to be considered. The server is the nexus where the events are collected and then pushed to pages. As such the distribution mechanism has to be identified first.

For the operations logging prototype log entries are distributed using JSON messages. There are many choices for messaging infrastructure ranging from using direct HTTP PUTs or POSTs to open source RabbitMQ or even commercial products offered by TIBCO. For the operations logging prototype the NATS messaging system is used. It is a high performance open source software offering that is being used by many well established companies.

Back to the server. The server needs to support both WebSockets and SSE. More important though is that it must be able to accept realtime data and push it to the web pages. Since NATS is the messaging system, the server needs to support that. One other important requirement must be satified by the server. The server needs to not only pass messages through to the web pages but it also needs to cache older messages so that pages can display initial values that arrived before the page was opened.

The server used for the operation log prototype is Piper Push Cache which was purpose build for supporting push technology. It is a JSON caching server that supports both WebSockets and SSE on the outgoing side and among others, NATS messages on the incoming side.

Planning

Before jumping into the building of the operation logging prototype consider what is needed. Lets just call them the requirements. For logging to be useful it is important to have sufficient information in the log entries. Having that information organized and structured is even better when attempting system analysis based on log entries. Once the content of log entries has been established consideration can be given to system analysis and monitoring. Robustness and fault tolerant considerations round out the requirements.

What to log

Logging has been around for a long time and the information that is needed for operations and system analysis is not a mystery.

When

Knowing when a log entry is made is important in establishing a sequence of events in the system. With multiple applications order is not always precise but a timestamp on log entries helps establish relativity if not precise order.

Where

Where a log entry is made aids in identifying the location to apply a fix. The more detail provided the easier it will be for developers to address issues. What application, host, module, file, and even line number can all be useful. The level of details is a design decision made by weighing the cost of inclusion of the details against their usefulness.

What

What to log is application specific. Structured or unstructured content is the choice of the design team or developer. This is where the details of a log entry are placed.

Categorization

Common practice calls for at least including the severity in a log entry. Other categorization information can be useful when monitoring or is system analysis. As an example, in a system that responds to requests it is helpful to assign an identifier to each request and track log entries related to that request as it makes its way through the system.

Log entries with some structure are far more useful than completely unstructured text entries. Developers have a good idea of the importance and relevance of data and can make use of that knowledge in a log entries. Operations activities can be more effective with structured log entries and system analysis is easier when there is some structure to log entries. As an example, a structured log entry using JSON is much easier to parse JSON programmatically than an arbitrary string.

{
  "kind": "Log",
  "level": 3,
  "who": "mockapp",
  "where": "mockapp:97",
  "what": "Dummy message number 1 is a INFO.",
  "when": 1450568855.372067000,
  "tid": "1",
}

System Analysis

Having figured out what should be logged, the next step is how to make sense of it. As a system gets more complex and asynchronous it also becomes increasingly difficult to analyze failures and determine what has occurred. Effective logging and tools to analyze those logs plays a critical role in system sleuthing. Some thought early on in the design to optimize logging can save frustration and time later one. A good logging system also makes auditing much easier. This is where the decisions on what to log show their value.

Filtering

Typical logs include a lot more information that is necessary for solving a specific problem. Separating the wheat from the chaff when the accumulated logs are multiple gigabytes can be daunting without filtering. Having a number of key bits of information easily identified simplifies filtering. An obvious set of filter criteria are the fields logged, time, application, severity, and tracking identifiers if they are used. Having the flexibility to create customized filters is a useful addition.

Being able to bracket log entries to a time window around when a problem was detected reduces the amount of data that has to be sifted through to get at the heart of an issue. Since log entry order and even timestamps are not always in the sequence that they occur in multiple application system or even multithreaded application being able to grab a time window of entries is more useful than looking for an exact time.

Quickly identifying the application or host that an error occurs on and then tracing the log entries on that machine or application isolates tracing when it is necessary. At other times not filtering by application or host gives a broader view of a system. Both are important.

If you want to find all the error entries filtering by log entry severity is essential. It allows for fast identifying a problem. Usually considered the first step in checking or identifying the log entries associated with a fault.

A feature often not considered is tracking identifiers. In systems that handle requests or events a helpful feature is to track an event through the system across multiple applications. If that tracking identifier is included in the log entries it is much easier to isolate that stream from many others that may have been in progress simultaneously.

When all else is insufficient, filtering on the log messages themselves is very helpful. Some system are build to only filter on on the message portion of a log entry and all data must be in the text portion effectively unstructured unless agreed on patterns in the entries are adhered to. Leaving that approach as a last resort is better in many ways but even then it should be available as an option.

Location

Eventually you will want to fix a problem. Drilling down into the source is aided by accurate and details location data in a log entry. The more detail the better as far as analysis is concerned. The level of location detail has to be weighed against the overhead of including that information in the log entries. Including a full stack in each log entry not only adds a lot of text to an entry it also requires a bit of work in the application that is usually more than what the application is willing to sacrifice.

Monitoring

A successful system inevitably requires monitoring and an operation team. Having developers act as operators and also developers might work fine on small systems but before too long development schedules are impacted by operations responsibilities.

If you want happy customers then having the tools to detect problems quickly makes the all the difference. An operations team that can detect problems quickly response leaves a good impression. An operations console is a good place to start.

Right Now

In order to respond quickly an operations team needs to know about problems when they occur. Depending on polling every few minutes doesn't cut it when customers can detect an error immediately. A push model is necessary for speedy responses. A push from application to log aggregator on to an operation console is the desired approach.

Notification

With an attentive operations team, pushing errors and warning to a console allows for early detections of problems. It is also draining as constantly staring at the console is tough. Additional notification methods take some of the burden off the operations team. Providing the ability to notify the operations team by email, text, or chat is a highly desirable feature. Making those notification rule based and allowing the operation team to set up the rules is even better.

Filtering

Of course not every log message is of interest to operation monitoring. They might be of interest in determine the cause of a problem but not necessary for problem detection. Typically fatal, error, and warning log entries are what an operations team is interested in. That requires some level of filtering on a log stream.

Centralized

One way or another log monitoring needs to be centralized. Even if that means opening up a terminal on each machine in a system and tailing log file. A horrible solution but not as unusual as one would hope. Better is having log entries aggregated and stored in one place. Best is aggregated and replicated in multiple places. A redundant centralized solution satisfies most any set of requirements. The earlier the redundant streams can be split the better.

Multiple Views

A single operations console is not usually sufficient for very long. Multiple views on log entries and the system are really essential from the start. What ever system is used for monitoring should support multiple consoles.

Expansion

Requirements change and situations change even more quickly. Providing flexible tools for monitoring are of great benefit. Being able to put together new web pages or notification rules are a real bonus to monitoring a system.

Robustness and Fault Tolerance

Then there are non-functional requirements. A robust logging system must be able to tolerate the failure of a component in the logging system. Having all logging entries be lost dues to a syslog server failing is hardly robust. It might be acceptable at first but the first failure usually forces a look at how to avoid that situation again.

Deploying a system in containers or VMs introduces additional concerns as the loss of a container or VM should not make mean a loss of all logging data.

A robust and fault tolerant system should survive or be able to recover from a host or application failure, network outage, or storage media failure. Often that means redundancy and alternatives for storing log entries.

Piper OpsLog Sample

Enough of the background. Lets look at a real system. Piper OpsLog is a sample provided with Piper Push Cache.

The Piper OpsLog sample is an implementation of a message based logging system. The intent of the sample is to demonstrate how Piper Push Cache and the NATS messaging system can be used to form a logging system complete with aggregation, filtering, analysis, push to a web console, and persistence of log entries. The sample also provides insight into the characteristics of a message based logging system.

NATS

The messaging system used is NATS. It has clients libraries in many languages. The server, gnatsd, is written in Go. This is a high performance messaging system that is very simple to use. Options exist for clustering and use of authorizations. Setting up clustering provides robustness and fault tolerance. NATS was selected for this sample over others for its simplicity and performance.

Piper Push Cache

Piper Push Cache plays a number of roles in this sample. It is the log aggregator and the dynamic filter. It pushes filtered log records to the web console and writes all log records to a rotating set of log files.

The design pattern used to push log records to the web console is subscription based and uses a filter expression to identify the log records the web console is interested in on any given page. This allows the filtering to be done on the server (Piper) and the specification to be specified by the web console. This pattern provides an efficient and flexible solution.

Setting up Piper is a matter of providing parameters in the configuration file used on startup. The NATS section is set to listen on the subject "log.>" which will receive all messages starting with "log.". Those messages will be used to create records with an incrementing time based identifier added to the JSON under the "id" key. Next the change-log is turned on and set to store changes including all log entry to the log directory. Finally the record groups are configured to add any record more sever than an info to the Piper cache so they can be viewed by the web console. All log entries are stored in the change-log.

Part of the Piper Push Cache platform is the mill application. The mill application provides the filtering and reformatting to fill the analysis requirements of a logging system. The log files are composed of JSON entries making them easy to parse and manipular with Ruby or most other languages that have JSON parsers. The sample includes code for Ruby, C, and Go for a barebones mill alternative.

Multiple instances of Piper can be run at the same time. Each will receive and process every log message. This redundancy provides robustness to compliment the NATS clustering configuration.

Console

The web console is driven JavaScript and consists of a single page that contains a list of errors, warnings, and fatal log records if any have been logged. A full system would most likely have more pages with details of individual log records and filtering similar to what the piper mill application provides. The single page does provide an example of how the Piper subscription model is used.

WebSockets

WebSockets is used to connect and then stay connected with the Piper, the server. This allows new log records to be pushed to the console when they arrive. On loading the page the WebSocket connection is made and callbacks are defined for opening, closing, and receiving messages. The onmessage callback handles new log record arrivals as well as record removals. Since the server is set up to only keep the most recent records older records are removed and the console notified through the WebSocket connection.

Server Send Events (SSE)

SSE can also be used to connect to Piper. The mobile.html file uses that approach to stay connected to Piper. This allows new log records to be pushed to the console when they arrive. On loading the page the SSE EventSource is created and callbacks are defined for opening, errors, and receiving messages. Event listeners are set up for 'set' and 'remove' events. Since the server is set up to only keep the most recent records older records are removed and the console notified through the WebSocket connection.

JavaScript

JavaScript is used to manage a list of log records. The list contains the JSON parsed objects from the WebSocket or SSE connection. Those records are kept on a list and cached in a hidden element on the page. The list is sorted which would allow sorting by different fields in the log records in the future. In the same the sorting is by when the log record was created.

Items are removed from the list when an _Admin record is received with an identifier that matches one of the log records in the cache. Being able to identify a record by a unique identifier is key to managing the log records. The need for a record identifier is why the Piper configuration file specifies that an identifier be added to each log record.

In order to avoid using an external JavaScript library such as JQuery in the sample the list is built on top of a canvas as is the scrollbar. It does not have all the features as some of the libraries but it does allow the page to stand on it's own for the sample.

Records

Log entries are represented by a JSON object. This not only give structure to the log messages so they can be processed more easily but it make handling by JavaScript in the browser much easier as JSON objects become JavaScript objects with one call to JSON.parse() with all elements of the JSON object becoming attributes of the JavaScript objects.

The 'kind' attribute of the JavaScript object is checked to determine how the object will be processed. An '_Admin' object with a 'reason' attribute of 'Removed' is processed as an object removal command. A 'kind' of 'Log' is treated as a log entry and added to the cached log list. All others are ignored.

{
  "kind": "Log",
  "level": 3,
  "who": "mockapp",
  "where": "mockapp:97",
  "what": "Dummy message number 1 is a INFO.",
  "when": 1450568855.372067000,
  "tid": "1",
}

Subscription

The WebSocket and SSE protocols used are subscription based protocols. The client subscribes to records stored in Piper based on a filter expression. Options are available for batch updates and sorting by multiple keys. This allows web page updates of only the data necessary for that page. Other pages subscribe to what they are interested in. This results in a tuned system where the server does the work to minimize bandwidth based on what the JavaScript on the web page wants and reduces the processing on the client.

The filter expression that defines the subscription can read any of the fields in the JSON record to form a boolean expression that determines whether a record will be passed to the client when it is created or changes. In this sample the client subscribes to all records that have a 'kind' field of 'Log'. A more complex boolean expression could be used if INFO log messages were also being cached in Piper.

The use of the subscription based protocol facilitates a push from the applications, through Piper, and up to the web console. This push pipeline is controlled by the Piper configuration parameters and the WebSocket or SSE subscriptions.

List

The log record list is implemented without the use of third party libraries to avoid adding additional dependencies. It is back to basics with a canvas for the list and a separate canvas for the scrollbar. The implementation relies on the server to limit the number of items that will be displayed. This avoids having to write the JavaScript code to determine which log entries should be cached on the web page and potentially have to check for duplicates and redundantly check for items that are no longer relevant.

One advantage of log entries is that they do not change after they have been published so there is no need to write JavaScript to deal with updating records. Records are created or removed only. Removal of a record is triggered by an admin message that contains the record identifier of the log entry to be removed. The record with the identifier specified is removed from the log entry list and the display updated.

The data or model behind the display list is an array of log entry records. This array is cached in a hidden element on the web page. This array is kept sorted by the timestamp in the log record.

Mock App

For the sample only a mock application that generates log entries was needed. The mockapp, a Ruby application is used to generate log entries. It makes use of the piper-ruby and the Oj gem to generate the log records.

Log Analysis

Log analysis is done against the Piper change log. The piper mill application allows a variety of filtering options and can also reformat the output. The entries in the log are all JSON so it is easy to write your own log processing using what every language you prefer. Three different examples are included in the sample.

Flow

As applications generate log events they are published over NATS on a subject that is 'log.<app_name>' where <app_name> is the name of the application. In the sample the mockapp is the only application publishing.

Those log messages are received by Piper Push Cache and processed according to the group they fall into. Info and Debug log messages are written to the change log only and not cached. Fatal, Error, and Warn messages are cached.

The caching of the log record triggers the pushing of those records to any web page that has subscribed to log records or rather any records that match the subscription filter expression.

The change log is then analyzed with the piper mill application. The logs can be displayed in a classic log format or in JSON. If applications make use of the tracking identifier in the log messages log entries can be filtered by that as well. The sample uses random tracking identifiers that repeat to allow experimentation with the various filtering options.

What Next

More features are being added to Piper Push Cache that will provide even more options to the logging sample or to a logging system build using the same approach. The sample can also be taken and expanded.

On the Piper roadmap are additional push channels, database support, output adaptors, message routing, and process flow similar to OFlow. Database support will allow log records to be written to a database for analysis using tools that expect log records to be in databases. With a external adaptors and process flow, log entries can be written to a syslog file or sent to a syslogd server.

Expanding the OpsLog sample into a more fully featured logging system would make it more usable. With some interest an OSS project will be created on GitHub for development of the system. The web console has a lot of room for additions. Adaptors for converting various log sources into messages would provide a path for more systems to contribute log entries to one centralized aggregator.

Summary

The operations logging prototype demonstrates that building a realtime push based system is not difficult with the right tools. Piper Push Cache and NATS form the core of a message based logging facility that starts out simple but can be expanded as a system grows.

If you would like to get involved in expanding OpsLog into a full system email Pete at Piper Push Cache and OpsLog will become open source.