w07 Logging

Logging to file

2022-03-01T15:30:00-05:00

Agenda

  1. Logging wrap-up
  2. Thinking about sources of error
  3. Errors in Express
  4. Writing error and other logs to file

Generating logs

Express.js and Morgan Logging

How to use morgan in your Express project - Cooper Makhijani

Morgan NPM Logger - The Beginner’s Guide - Fernando Doglio

Morgan NPM Logger (source code)

Morgan (npm package)

A guide to Node.js logging - Dominik Kundel

Node.js logging made easy: A tutorial on just about everything you need to know - Adnan Rahić

Error handling

Error Handling - Express Guide

A guide to error handling in Express.js - Mukul Khanna

How to handle errors in Express - Robin Wieruch

ExpressJS - Error Handling - Tutorialspoint

Better error handling in Express.js - Kevin Luu

How to hangle errors in an Express and Node.js app - Olusola Samuel

Using Express.js routes for promise-based error handling - Vitaly Senko

Writing log files

Morgan - Express

Logging - RIP Tutorial

Node.js logging - How to get started

A complete guide to Node.js logging (with the best practices for logging) - Yasas Sandeepa

How to get started with logging in Node.js - Better Stack Team

Notes

In class on Tuesday, we were working through writing an access log to a file instead of just echoing to STDOUT.

We were going in the right direction, but time ran out… and we were kind of overthinking things.

morgan() takes two arguments: a log type and an object with options.

In our case, we wanted to write the log output to a stream using the FS module.

The end result would be this:

1
2
3
4
5
6
7
...
// Use morgan for logging to files
// Create a write stream to append to an access.log file
const accessLog = fs.createWriteStream('access.log', { flags: 'a' })
// Set up the access logging middleware
app.use(morgan('combined', { stream: accessLog }))
...

The above code will produse a file access.log that looks like this:

::1 - - [02/Mar/2022:01:45:47 +0000] "GET /app/flips/60 HTTP/1.1" 200 523 "-" "curl/7.74.0"
::1 - - [02/Mar/2022:01:46:08 +0000] "GET /app/flip/call/heads HTTP/1.1" 200 47 "-" "curl/7.74.0"
::1 - - [02/Mar/2022:01:46:14 +0000] "GET /app/flips/700 HTTP/1.1" 200 5645 "-" "curl/7.74.0"
::1 - - [02/Mar/2022:01:46:23 +0000] "GET /app/flips/9000 HTTP/1.1" 200 72047 "-" "curl/7.74.0"
::1 - - [02/Mar/2022:01:46:32 +0000] "GET /app/flips/90000 HTTP/1.1" 200 720049 "-" "curl/7.74.0"
::1 - - [03/Mar/2022:22:57:18 +0000] "GET /app/flip/ HTTP/1.1" 200 16 "-" "curl/7.74.0"

Databases

Agenda

  1. Types of database
  2. When to use a database
  3. Making your API talk to a database
  4. Database connections

Express Database Integration Guide

Database integration in Express

SQLite3

better-sqlite3 API documentation

better-sqlite3 - NPM

SQLite3 data types

Notes

Right at the end of the session today when I tried to run our new database.js script, it caught an error and we were out of time so I didn’t want to run it down right then. The error looked like this:

[email protected]:~/comp426/a04-draft$ node server.js
Log database appears to be empty. Creating log database...

/home/john/comp426/a04-draft/node_modules/better-sqlite3/lib/methods/wrappers.js:9
        this[cppdb].exec(sql);
                    ^
SqliteError: near "-": syntax error
    at Database.exec (/home/john/comp426/a04-draft/node_modules/better-sqlite3/lib/methods/wrappers.js:9:14)
    at Object.<anonymous> (/home/john/comp426/a04-draft/database.js:14:11)
    at Module._compile (node:internal/modules/cjs/loader:1101:14)
    at Object.Module._extensions..js (node:internal/modules/cjs/loader:1153:10)
    at Module.load (node:internal/modules/cjs/loader:981:32)
    at Function.Module._load (node:internal/modules/cjs/loader:822:12)
    at Module.require (node:internal/modules/cjs/loader:1005:19)
    at require (node:internal/modules/cjs/helpers:102:18)
    at Object.<anonymous> (/home/john/comp426/a04-draft/server.js:5:15)
    at Module._compile (node:internal/modules/cjs/loader:1101:14) {
  code: 'SQLITE_ERROR'
}

And my script looked like this:

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
const database = require('better-sqlite3')

const logdb = new database('log.db')

const stmt = logdb.prepare(`SELECT name FROM sqlite_master WHERE type='table' and name='access';`)
let row = stmt.get();
if (row === undefined) {
    console.log('Log database appears to be empty. Creating log database...')

    const sqlInit = `
        CREATE TABLE access ( id INTEGER PRIMARY KEY, remote-addr VARCHAR, remote-user VARCHAR, datetime VARCHAR, method VARCHAR, url VARCHAR, http-version NUMERIC, status INTEGER, content-length NUMERIC);
    `

    logdb.exec(sqlInit)
} else {
    console.log('Log database exists.')
}


module.exports = logdb

The relevant piece of the error log is:

...
SqliteError: near "-": syntax error
...
    at Object.<anonymous> (/home/john/comp426/a04-draft/database.js:14:11)

This means that I have a SQLite syntax error on line 14 at position 11, which is a reference to the const named sqlInit. And that const has several hyphens ("-") in it, which is a syntax error.

Why?

Because in SQL syntax, a hyphen is an operator and we can’t use it in variable names… and we have several.

SO, what our script should look like instead is:

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
const database = require('better-sqlite3')

const logdb = new database('log.db')

const stmt = logdb.prepare(`SELECT name FROM sqlite_master WHERE type='table' and name='access';`)
let row = stmt.get();
if (row === undefined) {
    console.log('Log database appears to be empty. Creating log database...')

    const sqlInit = `
        CREATE TABLE accesslog ( 
            id INTEGER PRIMARY KEY, 
            remote_addr VARCHAR, 
            remote_user VARCHAR, 
            date VARCHAR, 
            method VARCHAR, 
            url VARCHAR, 
            http_version NUMERIC, 
            status INTEGER, 
            content_length NUMERIC,
            referrer_url VARCHAR,
            user_agent VARCHAR
        );
    `

    logdb.exec(sqlInit)
} else {
    console.log('Log database exists.')
}

module.exports = logdb

Replacing the hyphens with underscores (snake case) makes our field names work properly.

The above script will check for an access log table in a database, and if it doesn’t exist, it will initialize the DB and create a table that will hold all of the relevant pieces of information to be able to reproduce a combined log entry.