event-logger

Log entries to a standard JSON format.

e.g.

{ "type": "job", "name": "upload_material_job", "job_id": "2949ad19-6c2a-4aec-b097-47a81ce629d3", "state": "enqueued", "material_id": "TST/TEST017/015" }

Based on:

Ditch the Debugger and use Log Analysis Instead by Matthew Skelton.

Log Elements and Format

A log entry must contain a name and a state.

Names should come from a controlled vocabulary

Valid states are:

• enqueued - Enqueued waiting to be started
• started - Process has started
• mark - Useful way point or event
• completed - Process has completed
• failed - Process has failed

If available is should log the correlation_id. This is used for related activities that take place across process boundaries.

For example, archive-material archives a new Original Master TTB-GODD004-030.mxf to S3 and then makes a request to the API for it to be ingested.

Once ingested jobs are enqueued for the production of the Destination Masters, Proxy and Thumbnails before finally being delivered to Discovery and Channel 5.

So when we put the logs together from sky-sig-01.prod, hon-web-01.prod, hon-que-01.prod, hon-qtm-01.prod and we should see something like:

sky-sig-01.prod {"correlation_id":"68a0296f", "name":"process-new-material", "state":"started", "av-file":"TTB-GODD004-030.mxf", "sidecar":"TTB-GODD004-030.xml"}
sky-sig-01.prod {"correlation_id":"68a0296f", "name":"archive-av-file-to-s3", "state":"started"}
sky-sig-01.prod {"correlation_id":"68a0296f", "name":"archive-av-file-to-s3", "state":"completed", "archive-path":"s3:/path/to/file/TTB-GODD004-030.mxf"}
sky-sig-01.prod {"correlation_id":"68a0296f", "name":"archive-sidecar-to-s3", "state":"started"}
sky-sig-01.prod {"correlation_id":"68a0296f", "name":"archive-sidecar-to-s3", "state":"completed", "archive-path":"s3:/path/to/file/TTB-GODD004-030.xml"}
sky-sig-01.prod {"correlation_id":"68a0296f", "name":"request-ingest", "state":"mark"}
sky-sig-01.prod {"correlation_id":"68a0296f", "name":"process-new-material", "state":"completed", "av-file":"TTB-GODD004-030.mxf", "sidecar":"TTB-GODD004-030.xml"}

hon-web-01.prod {"correlation_id":"68a0296f", "name":"ingest", "state":"enqueued", "clock":"TTB/GODD044/030"}
hon-que-01.prod {"correlation_id":"68a0296f", "name":"ingest", "state":"started", "clock":"TTB/GODD044/030"}
hon-que-01.prod {"correlation_id":"68a0296f", "name":"ingest", "state":"completed", "clock":"TTB/GODD044/030"}

hon-que-01.prod {"correlation_id":"68a0296f", "name":"make-thumbnails", "state":"enqueued", "clock":"TTB/GODD044/030"}
hon-que-01.prod {"correlation_id":"68a0296f", "name":"make-proxies", "state":"enqueued", "clock":"TTB/GODD044/030"}
hon-que-01.prod {"correlation_id":"68a0296f", "name":"make-destination-master", "state":"enqueued", "clock":"TTB/GODD044/030", "destination":"Discovery"}
hon-que-01.prod {"correlation_id":"68a0296f", "name":"make-destination-master", "state":"enqueued", "clock":"TTB/GODD044/030", "destination":"Channel 5"}

hon-que-01.prod {"correlation_id":"68a0296f", "name":"make-thumbnails", "state":"started", "clock":"TTB/GODD044/030"}
hon-que-01.prod {"correlation_id":"68a0296f", "name":"make-thumbnails", "state":"completed", "clock":"TTB/GODD044/030"}

hon-que-01.prod {"correlation_id":"68a0296f", "name":"make-proxies", "state":"started", "clock":"TTB/GODD044/030"}
hon-que-01.prod {"correlation_id":"68a0296f", "name":"make-proxies", "state":"completed", "clock":"TTB/GODD044/030"}

hon-qtm-01.prod {"correlation_id":"68a0296f", "name":"make-dm", "state":"started", "clock":"TTB/GODD044/030", "destination":"Discovery"}
hon-qtm-01.prod {"correlation_id":"68a0296f", "name":"make-dm", "state":"completed", "clock":"TTB/GODD044/030", "destination":"Discovery"}

hon-qtm-01.prod {"correlation_id":"68a0296f", "name":"make-dm", "state":"started", "clock":"TTB/GODD044/030", "destination":"Channel 5"}
hon-qtm-01.prod {"correlation_id":"68a0296f", "name":"make-dm", "state":"completed", "clock":"TTB/GODD044/030", "destination":"Channel 5"}
hon-qtm-01.prod {"correlation_id":"68a0296f", "name":"deliver-dm", "state":"enqueued", "clock":"TTB/GODD044/030", "destination":"Discovery"}
hon-qtm-01.prod {"correlation_id":"68a0296f", "name":"deliver-dm", "state":"enqueued", "clock":"TTB/GODD044/030", "destination":"'Channel 5"}
hon-que-01.prod {"correlation_id":"68a0296f", "name":"deliver-dm", "state":"started", "clock":"TTB/GODD044/030", "destination":"Discovery"}
hon-que-01.prod {"correlation_id":"68a0296f", "name":"deliver-dm", "state":"completed", "clock":"TTB/GODD044/030", "destination":"Discovery"}

hon-que-01.prod {"correlation_id":"68a0296f", "name":"deliver-dm", "state":"started", "clock":"TTB/GODD044/030", "destination":"Channel 5"}
hon-que-01.prod {"correlation_id":"68a0296f", "name":"deliver-dm", "state":"completed", "clock":"TTB/GODD044/030", "destination":"Channel 5"}

Usage

Include in your Gemfile with:

gem 'event-logger'

Then log with the log method e.g.:

Mark:

EventLogger.log(:process, name: 'ingest_material', state: 'mark', details: "ignoring: #{File.basename(mxf_file)}")

Started:

EventLogger.log(:process, name: 'ingest_material', state: 'started', clock_number: clock_number)

Failed:

EventLogger.log(:process, name: 'ingest_material', state: 'failed', details: 'cannot upload directory', severity: 'error')

Completed:

EventLogger.log(:process, name: 'ingest_material', state: 'completed', clock_number: clock_number, details: 'completed ingest with sidecar from s3')

Configuration

By default, EventLogger will write to stdout with full Logger headers:

I, [2017-06-22T09:04:44.827889 #7]  INFO -- : {"type":"process","name":"transcend","state":"start","details":"Starting Transcend Server."}

When using this with the Docker Logentries container, you should instead configure the message to be output in JSON format without Logger headers:

EventLogger.instance.config.logger = :stdout

All available configuration options set via EventLogger.instance.config are:

• logger - set to one of:
  • :logger (default) for Logger on STDOUT
  • :stdout to write to STDOUT undecorated (generated_at and level will be included in the JSON)
  • an IO object that responds to <<
  • a logging object that responds to severity methods, e.g. info

Environment variables

• EVENT_LOGGER_LOGGER - change the default value of the logger configuration option, either logger or stdout