TL;DR Pino is the fastest logger. Which frees up computing cycles for your application's business logic. Azure Event Hub is Microsoft Azure's aggregator. Pino output can easily be streamed to Event Hub with our npm module
pino-eventhub.
In our previous article, entitled Developer experience of Azure, we demonstrated how easy it is to create a web app on Microsoft's Azure. While we did show how to enable logging locally for a web app, that is not really practical or useful for a real app.
For real world applications we need a logger that gets out of the way. Logging is not the truly value of our application. We need logger that is fast, to free up the maximum computing cycles for our business logic.
Pino is the obvious choice to increase our application's performance. Or at least to minimize the impact of loggin on our app's performance.
Pino logs only in JSON via a binary stream (a file or stdout). This simplicity was leveraged to optimise Pino. Pino outperforms the other existing loggers by up to 6x.
If you are used to Bunyan, Bole, or Winston, in 99% of case you should just be able to drop in Pino.
Pino plays nicely with a lot of packages.
Keeping in line with our article series we will be using Hapi.
Hooking up Pino with Hapi is pretty straight forward using the hapi-pino npm module.
server.register(require('hapi-pino'), (err) => {
if (err) {
console.error(err)
process.exit(1)
}
// Start the server
server.start((err) => {
if (err) {
console.error(err)
process.exit(1)
}
})
})This creates logs on all our routes of the format
{"pid":11518,"hostname":"local-server","level":30,"time":1499413842512,"msg":"server started","created":1499413842353,"started":1499413842502,"host":"localhost","port":1337,"protocol":"http","id":"local-server:11518:j4tkad9t","uri":"http://localhost:1337","address":"127.0.0.1","v":1}
There are two additional ways of logging available to pass down extra information
// the logger is available in server.app
server.app.logger.warn('Pino is registered')
// and through Hapi standard logging system
server.log(['subsystem'], 'standard logging way for accessing it')
To see more examples of pino output
- clone our pino branch
- run
yarn - run
npm run watch - in another tab run
curl localhost:1337
The type definitions of @types/hapi are restricted.
I.e., if you are using TypeScript, then
this form of logging server.logger().info('some info') is not available.
Great now we have a logger working, but a feed on a local machine is not that useful. We need to be able to get this information into a dashboard.
Here we need to take a step back, and consider our architecture. We are deploying an app in the cloud, i.e., on a VM or container. Presumably there are multiple instances of your app, and there other instances of, e.g., databases. There will also be other services, if you are doing a micro-services deploy. You might also be collecting client-side or IoT data. Connecting all off these to a dashboard in parallel might overwhelm it. It makes more sense to connect to a log aggregation service. Event Hub is the obvious candidate, since this is part of our series on Azure.
Microsoft describes Event Hub(s) as
Azure Event Hubs is a highly scalable data streaming platform and event ingestion service capable of receiving and processing millions of events per second. Event Hubs can process and store events, data, or telemetry produced by distributed software and devices. Data sent to an event hub can be transformed and stored using any real-time analytics provider or batching/storage adapters. With the ability to provide publish-subscribe capabilities with low latency and at massive scale, Event Hubs serves as the "on ramp" for Big Data.
Note that Event Hub can be used even if part of your architecture is on another cloud or own infrastructure. We will make use of this during development below to test the connection from our local machine to Event Hub.
Instead of using Pino with Event Hub, we could've opted for a solution like Application Insights (AI).
According to Microsoft:
Application Insights is an extensible Application Performance Management (APM) service for web developers on multiple platforms. Use it to monitor your live web application. It will automatically detect performance anomalies. It includes powerful analytics tools to help you diagnose issues and to understand what users actually do with your app. It's designed to help you continuously improve performance and usability.
All the functionality AI ties into looks great. AI, however, tightly couples to your application through monkey-patching. At the moment AI is instrumented for Bunyan, Console, MongoDB, MongoDB-Core, Mysql and Redis. However, for this application we are looking at the lightest/fastest possible logging solution. Hence, Event Hub makes more sense for us.
That said, it is still necessary for us to connect a dashboard by subscribing it to our Event Hub. That is outside the scope of this article.
Please note that when using Event Hub there is a delay of ±10 minutes when viewing data on its dashboard. Keep this in mind as you build your own application.
In our previous article we demonstrated how to provision a web app. Assuming you have an Azure and a deployment user, then this simple bash script will get you started:
#! /bin/bash
GROUP_NAME=nearGroup
LOCATION=westeurope
PLAN_NAME=nearPlan
SKU=B1
APP_NAME=pino007
CREATE_GROUP="az group create -n $GROUP_NAME --location $LOCATION"
echo $CREATE_GROUP
$CREATE_GROUP
CREATE_PLAN="az appservice plan create -n $PLAN_NAME -g $GROUP_NAME --sku $SKU"
echo $CREATE_PLAN
$CREATE_PLAN
CREATE_WEBAPP="az webapp create -n $APP_NAME -g $GROUP_NAME -p $PLAN_NAME"
echo $CREATE_WEBAPP
$CREATE_WEBAPP
SET_WEBAPP_SOURCE="az webapp deployment source config-local-git -n $APP_NAME -g $GROUP_NAME --query url --output tsv"
echo $SET_WEBAPP_SOURCE
$SET_WEBAPP_SOURCEPlease remember to replace APP_NAME with a unique name of your choice.
Note that while we could deploy a web app for free, Event Hub requires at least the Basic 1 (BI) plan.
In case you have not done it before set your Azure git repository as a target.
git remote add azure https://<username>@pino007.scm.azurewebsites.net/ath.git
Provisioning Event Hub is possible using the Azure CLI. But, that is kind of tricky since we need to use templates. To simplify things for this example, we will use the web interface.
Under https://portal.azure.com/#create/Microsoft.EventHub
create a (unique) namespace. We used pinoEventHubNS (which will be accessible via pinoEventHubNS.servicebus.windows.net, hence why it needs to be unique.)
Then create eventHub called pinoEventHub.
Here you can see the Event Hub pinoEventHub linked under the namespace pinoEventHubNS.
Then create Shared Access Policy called sendPinoEvent
Congratulations you have provisioned a simple web app infrastructure, including a log aggregator. More can be done to fine tune Event Hub provisioning, but for now this suffices.
To be able to send your first event to Event Hub, all we need to do is create a Shared Access Signature.
First you will need the data from Shared Access Policy under CONNECTION STRING–PRIMARY KEY, eg,
Endpoint=sb://pinoeventhubns.servicebus.windows.net/;
SharedAccessKeyName=sendPinoEvent;
SharedAccessKey=<your-SharedAccessKey>;
EntityPath=pinoeventhub
Using Microsoft's example as basis we created a simple function
function createSignature (uri, ttl, sapk) {
var signature = encodeURIComponent(uri) + '\n' + ttl
var signatureUTF8 = utf8.encode(signature)
var hash = crypto.createHmac('sha256', sapk)
.update(signatureUTF8)
.digest('base64')
return encodeURIComponent(hash)
}Where the ttl is the expiry date of the SAS in Unix time.
And the uri is simply https://pinoeventhubns.servicebus.windows.net/pinoeventhub
Armed with your SAS, you can now send an event
curl -v -H 'Authorization: SharedAccessSignature sr=http%3A%2F%2Fpinoeventhubns.servicebus.windows.net%2Fpinoeventhub&sig=<your-SAS>&se=<your-ttl>&skn=sendPinoEvent' -H 'Content-Type:application/atom+xml;type=entry;charset=utf-8' --data '{ "event": "hello world" }' https://pinoeventhubns.servicebus.windows.net/pinoeventhub/messagesWhich should give response similar to
* Trying 52.233.192.247...
* Connected to pinoeventhubns.servicebus.windows.net (52.233.192.247) port 443 (#0)
* TLS 1.2 connection using TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384
* Server certificate: servicebus.windows.net
* Server certificate: Microsoft IT SSL SHA2
* Server certificate: Baltimore CyberTrust Root
> POST /pinoeventhub/messages HTTP/1.1
> Host: pinoeventhubns.servicebus.windows.net
> User-Agent: curl/7.43.0
> Accept: */*
> Authorization: SharedAccessSignature sr=http%3A%2F%2Fpinoeventhubns.servicebus.windows.net%2Fpinoeventhub&sig=<your-SAS>&se=<your-ttl>&skn=sendPinoEvent
> Content-Type:application/atom+xml;type=entry;charset=utf-8
> Content-Length: 26
>
* upload completely sent off: 26 out of 26 bytes
< HTTP/1.1 201 Created
< Transfer-Encoding: chunked
< Content-Type: application/xml; charset=utf-8
< Server: Microsoft-HTTPAPI/2.0
< Strict-Transport-Security: max-age=31536000
< Date: Tue, 04 Jul 2017 11:56:58 GMT
<
The key element in the above is the 201 statusCode being returned, denoting a successful POST.
We can now successfully post to Event Hub, now all we need is to send all the pino logs to such a posting mechanism. Since pino logs to stdout, all we need is something like node yourapp.js | eventhub.
What we have is a stream of output from pino. First we can break those into discrete events using split2. Then POST of each of those to Event Hub with a writable stream in object mode using https. Something similar to
const writable = new Writable({
objectMode: true,
write: function (body, enc, done) {
var req = https.request(options, callback(done))
req.write(body)
req.end()
},
})
pump(split2(), writable)We have captured this in an npm module called pino-eventhub. You have already installed this as part of your download, and we can test this on your local machine using
node build/index.js | ./node_modules/.bin/pino-eventhub -s pinoeventhubns -e pinoeventhub -n sendPinoEvent -a <your-SAS> -x <unix-time-expiry>
To see it working
- run
curl localhost:1337 - open https://portal.azure.com
- click on
pinoEventHubNS(or your equivalent Event Hub namespace) - wait ±10 minutes, and you will see a blip under
incoming messages
Alternatively AMQP could be used to send the logs to Event Hub. We stuck to piping for this article, because of its simplicity.
We have our basic web app setup done already.
However, to keep inline with Twelve-Factor App development, we want to simplify our npm run start command to node build/index.js | pino-eventhub.
We have setup our npm module to take environment variables, so this can be done using the Azure CLI
az webapp config appsettings set -n pino007 -g nearGroup --settings \
PINO_EVENT_HUB_NAMESPACE=pinoeventhubns \
PINO_EVENT_HUB=pinoeventhub \
PINO_SHARED_ACCESS_POLICY_NAME=sendPinoEvent \
PINO_SHARED_ACCESS_SIGNATURE=<your-SAS> \
PINO_SAS_EXPIRY=<unix-time-expiry>
Now all we need to do is
git push azure pino:master
az webapp browse -n pino007 -g nearGroup
Again, you can go to your Event Hub dashboard on the Azure Portal to see your events arrive.
Building on our previous article, we wanted to be able to collect the log files from our application. We choose Pino as a logger because it is very fast. Pino's speed allows our application's business logic to run faster. We showed that it is easy to provision an Event Hub on the Azure portal. After creating credentials (using the tool we provided), your web app can stream to Event Hub from a 1 line command.
