Logging

Build a simple Hello World application using QLog and cloud logging services; explore QLog features

Hello world

A simple application to print some logging to STDOUT. Execute the following:

# navigate to app dir & copy qlog.qpk
cd ${HOME}/KxCloudEdition/examples/qlog/qlog-qs
cp ${HOME}/KxCloudEdition/code/qlog.qpk .

# build & run
qp build
qp run

The output will be a structured, timestamped, JSON log message.

{"time":"2021-01-26T15:18:02.287","component":"qlog","level":"INFO","message":"Hello world!"}

Basics for more on the APIs and a breakdown of the script

Logging agent

How logs can be collected by an agent and routed to other cloud services

Here we will use the Fluent Bit agent and the Hello World example from the previous section. The agent can be configured to route to cloud logging applications or other endpoints.

Docker Compose and Kubernetes

This walkthrough uses Docker Compose for simplicity. It is likely Kubernetes would be preferred for production.

The same Fluent Bit agent can be set up to run in a Kubernetes application as a DaemonSet. This process is relatively straightforward and well documented online: the offical guide looks at both Kubernetes and Helm.

Here we run two Docker containers: one for the application, and one for the agent. The application’s logging is forwarded to the agent, which initially simply dumps it to its own STDOUT.

Requires docker-compose version 1.25+

cd ${HOME}/KxCloudEdition/examples/qlog/qlog-qs
qp build
docker-compose -f docker-compose.yml --env-file=./qpbuild/.env up

As below, the client application output is seen from the Fluent container. So the routing is working successfully. Press Ctrl-C to shut down. Ignore the warning that no logs are available: this is by design.

..
fluent    | [0] 247202086d68: [1611761398.000000000, {"log"=>"INFO: Using existing license file [/opt/kx/lic/kc.lic]", "container_id"=>"247202086d680f33f1f9e50ab383c0b7935d35cd0847652ba36ea2260b0d38c5", "container_name"=>"/hello", "source"=>"stdout"}]
fluent    | [1] 247202086d68: [1611761398.000000000, {"log"=>"RUN [q startq.q ]", "container_id"=>"247202086d680f33f1f9e50ab383c0b7935d35cd0847652ba36ea2260b0d38c5", "container_name"=>"/hello", "source"=>"stdout"}]
fluent    | [0] 247202086d68: [1611761399.000000000, {"component"=>"qlog", "level"=>"INFO", "message"=>"Hello world!", "container_id"=>"247202086d680f33f1f9e50ab383c0b7935d35cd0847652ba36ea2260b0d38c5", "container_name"=>"/hello", "source"=>"stdout"}]
hello exited with code 0

The agent is highly pluggable and supports a variety of different output types. If you are running on a cloud platform, let’s update it to do something more useful. Each of the cloud providers has its own logging application and we can configure the agent to route to there. We can switch between providers by setting the FLUENT_CONFIG environment variable.

GCP      gcp.conf
AWS      aws.conf
Azure    azure.conf

GCP

Execute the following to rerun the example and output to Google Cloud Logging.

export FLUENT_CONFIG=gcp.conf
docker-compose -f docker-compose.yml --env-file=./qpbuild/.env up

Open the Logs Explorer and it should contain the Hello world! message. In the Query builder pane, enter jsonPayload.source="stdout" to filter the dataset.

AWS

Execute the following to rerun the example and output to Amazon CloudWatch Logs.

export FLUENT_CONFIG=aws.conf
docker-compose -f docker-compose.yml --env-file=./qpbuild/.env up

The uploaded logs should be available on AWS.

Azure

Azure requires some additonal setup.

1. Edit the fluent/conf/azure.conf file.
2. Replace the <WORKSPACE_id> and <AUTH_KEY> fields. The values to replace them with can be looked up from the Azure portal.
3. Navigate to the Log Analytics workspaces service.
4. Open Advanced Settings > Agents management.
5. Copy the displayed values and save the file.

Execute the following to rerun the example and output to Azure Monitor Logs.

export FLUENT_CONFIG=azure.conf
docker-compose -f docker-compose.yml --env-file=./qpbuild/.env up

The uploaded logs should be available in the Log Analytics workspaces.

It may take some time for the first upload of logs to appear

Examples

The code for each example is available in

${HOME}/KxCloudEdition/examples/qlog/qlog-examples/src

The script name corresponds to the qp run parameter to run it; e.g. in the quickstart example, do the following.

cd $HOME/KxCloudEdition/examples/qlog/qlog-examples
cp ${HOME}/KxCloudEdition/code/qlog.qpk .
qp run quickstart -- -debug

The code would be available in src/quickstart.q. The -debug flag keeps the process running interactively to dive deeper.

Basics

Examine the earlier Quick Start example.

src/quickstart.q

id:.com_kx_log.init[`:fd://stdout; ()]
.qlog:.com_kx_log.new[`qlog; ()]

.qlog.info["Hello world!"]

if[not `debug in key .Q.opt .z.x; exit 0]

Look at the .qlog dictionary. Each element corresponds to a different log level. We can print messages using two handlers to compare. Note the difference in the level field.

q).qlog
trace| locked[`TRACE;`qlog]
debug| locked[`DEBUG;`qlog]
info | locked[`INFO;`qlog]
warn | locked[`WARN;`qlog]
error| locked[`ERROR;`qlog]
fatal| locked[`FATAL;`qlog]

q).qlog.info["Process starting"]
{"time":"2021-01-26T16:33:21.396","component":"qlog","level":"INFO","message":"Process starting"}

q).qlog.fatal["Process crashing"]
{"time":"2021-01-26T16:33:21.397","component":"qlog","level":"FATAL","message":"Process crashing"}

Create a new logging component. Where levels are used to distinguish the severity of messages, components can be used to distinguish the source of a message. A component can be a module, a process or any other grouping that makes sense for the application. Below we create another set of logging APIs for a Monitor component. Note the change in the component field.

q).mon:.com_kx_log.new[`Monitor; ()];
q).mon.info["Monitor starting"];
{"time":"2021-01-26T16:37:50.768","component":"Monitor","level":"INFO","message":"Monitor starting"}

Routing

Log messages can be routed or suppressed according to their severity. Often applications will suppress all debug or trace logs. Each logging component can set its own level routing.

QLog has the following list of levels, in ascending order of severity: TRACE, DEBUG, INFO, ERROR, FATAL.

This example initializes the STDOUT endpoint with a default routing of INFO. Messages will be logged with severities of INFO or above. Anything below that will be suppressed.

$ qp run routing1
..
{"time":"2021-01-26T17:19:38.113","component":"qlog","level":"INFO","message":"Info"}
{"time":"2021-01-26T17:19:38.113","component":"qlog","level":"ERROR","message":"Error"}
{"time":"2021-01-26T17:19:38.113","component":"qlog","level":"FATAL","message":"Fatal"}

The routing2 example shows how to route severities by component, and routing3 illustrates how to configure different routings per endpoint when several are set up.

Message formatting

It is common for log messages to include the values of variables or process state. These are often built into the message body. Often it is the responsibility of the client to do this parsing. QLog supports a token-based method of doing this in the APIs. The client can provide a list containing the message body and variables to be automatically parsed into a string.

q).qlog.info ("Complex list format with an int=%1 and a dict=%2"; rand 10; `a`b`c!til 3)
{"time":"2021-01-27T11:24:10.393","component":"qlog","level":"INFO","message":"Complex list format with an int=9 and a dict=`a`b`c!0 1 2"}

The logging string should contain tokens from %1 to %N, corresponding to the number of variables.

Dictionary inputs are supported and are appended to the log message. It must include a message key for the actual log body. Other keys will be appended to the output.

Run the following for an example

$ qp run formatting
..
{"time":"2021-01-27T11:24:10.392","component":"qlog","level":"INFO","message":"Simple message"}
{"time":"2021-01-27T11:24:10.393","component":"qlog","level":"INFO","message":"Dictionary message","labels":["rdb","eod"]}
{"time":"2021-01-27T11:24:10.393","component":"qlog","level":"INFO","message":"Complex list format with an int=9 and a dict=`a`b`c!0 1 2"}
{"time":"2021-01-27T11:24:10.393","component":"qlog","level":"INFO","message":"Complex dict format with an int=5 and a dict=`a`b`c!0 1 2","labels":["rdb","eod"]}

Log metadata

A common use case when logging is to include some metadata with logs. There are two types supported: correlators and service details.

Service details

are set globally on the process and appended to each message

Correlators

are set globally as part of an event and appended to each message

For example, each incoming request would be assigned its own correlator and any logs emitted as part of that request would contain the same correlator.

This example starts up with some basic logging, simulates receiving a request and shutting down. Note the corr field in the middle two log messages.

$ qp run metadata
..
{"time":"2021-01-27T11:38:17.989","component":"Monitor","level":"INFO","message":"Process initialised","service":"rdb","PID":1}
{"time":"2021-01-27T11:38:17.989","corr":"d13b7c7c-6d0f-5d56-7eb0-5e029c9f4609","component":"Monitor","level":"INFO","message":"API request received from kf","service":"rdb","PID":1}
{"time":"2021-01-27T11:38:17.990","corr":"d13b7c7c-6d0f-5d56-7eb0-5e029c9f4609","component":"Monitor","level":"DEBUG","message":"Request complete","service":"rdb","PID":1}
{"time":"2021-01-27T11:38:17.990","component":"Monitor","level":"INFO","message":"Shutting down","service":"rdb","PID":1}

REST endpoints

QLog can also log directly to the cloud applications over REST. The following examples illustrate this;

GCP    qp run gcpRest
AWS    qp run awsRest
Azure  qp run azureRest

These each require further parameters.

Summary

We have seen how to build and run a basic application with QLog. We have introduced the concept of the logging agent.

---

QLog documentation