TritonDataCenter / pg_prefaulter

Faults pages into PostgreSQL shared_buffers or filesystem caches in advance of WAL apply
Apache License 2.0
56 stars 13 forks source link

Human logs #35

Closed sean- closed 7 years ago

sean- commented 7 years ago

Use the human-friendly zerolog.ConsoleWriter when stdout is a TTY.

This change:

a) moves logging from stderr to stdout (I'm not sure why I used stderr to begin with) b) uses a sane time format that abates my hostile OCD operational tendencies c) Uses a human-friendly logger when stdout is a TTY. This can be changed with the flag --json-logs=(true|false) or config value run.json-logs=(true|false). d) Uses colorized output when stdout is a TTY. This can be changed with the flag --use-colors=(true|false) or the config value run.use-colors=(true|false).

Human friendly output:

$ pg_prefaulter run
2017-10-06T06:42:43.690004116-07:00 |DEBU| <nil> config-file=./pg_prefaulter-follower.toml
2017-10-06T06:42:43.690153216-07:00 |DEBU| args: []
2017-10-06T06:42:43.690236783-07:00 |DEBU| starting gops(1) agent
2017-10-06T06:42:43.690332132-07:00 |DEBU| flags postgresql.host=/tmp postgresql.pgdata=/Users/seanc/go/src/github.com/joyent/pg_prefaulter/.pgdata_follower/ postgresql.poll-interval=1000 postgresql.port=5433 postgresql.user=postgres postgresql.xlog.mode=pg postgresql.xlog.pg_xlogdump-path=/opt/local/lib/postgresql96/bin/pg_xlogdump
2017-10-06T06:42:43.690803979-07:00 |INFO| Starting pg_prefaulter pid=16043
2017-10-06T06:42:43.692740595-07:00 |DEBU| filehandle cache initialized filehandle-cache-size=2000 filehandle-cache-ttl=300000 rlimit-nofile=7168
2017-10-06T06:42:43.710555175-07:00 |INFO| started IO worker threads io-worker-threads=3600
2017-10-06T06:42:43.710984084-07:00 |INFO| started WAL worker threads wal-worker-threads=4
2017-10-06T06:42:43.711073646-07:00 |DEBU| Starting wait
2017-10-06T06:42:43.711116352-07:00 |INFO| Starting pg_prefaulter agent commit=none date=unknown tag= version=dev
2017-10-06T06:42:43.716317523-07:00 |ERRO| unable to find WAL files error="FATAL: password authentication failed for user \"postgres\" (SQLSTATE 28P01): (retriable: false, purge cache: false" next step=exiting
2017-10-06T06:42:43.716813454-07:00 |DEBU| Shutting down
2017-10-06T06:42:43.720427315-07:00 |DEBU| Stopped pg_prefaulter agent
2017-10-06T06:42:43.720476034-07:00 |INFO| Stopped pg_prefaulter pid=16043

Structured logging:

$ pg_prefaulter run | cat
{"time":"2017-10-06T06:43:34.827738183-07:00","level":"debug","config-file":"./pg_prefaulter-follower.toml"}
{"time":"2017-10-06T06:43:34.827828887-07:00","level":"debug","message":"args: []"}
{"time":"2017-10-06T06:43:34.827960705-07:00","level":"debug","message":"starting gops(1) agent"}
{"time":"2017-10-06T06:43:34.828050108-07:00","level":"debug","postgresql.pgdata":"/Users/seanc/go/src/github.com/joyent/pg_prefaulter/.pgdata_follower/","postgresql.host":"/tmp","postgresql.port":5433,"postgresql.user":"postgres","postgresql.xlog.mode":"pg","postgresql.xlog.pg_xlogdump-path":"/opt/local/lib/postgresql96/bin/pg_xlogdump","postgresql.poll-interval":1000,"message":"flags"}
{"time":"2017-10-06T06:43:34.828510862-07:00","level":"info","pid":16113,"message":"Starting pg_prefaulter"}
{"time":"2017-10-06T06:43:34.830408069-07:00","level":"debug","rlimit-nofile":7168,"filehandle-cache-size":2000,"filehandle-cache-ttl":300000,"message":"filehandle cache initialized"}
{"time":"2017-10-06T06:43:34.847611151-07:00","level":"info","io-worker-threads":3600,"message":"started IO worker threads"}
{"time":"2017-10-06T06:43:34.848289272-07:00","level":"info","wal-worker-threads":4,"message":"started WAL worker threads"}
{"time":"2017-10-06T06:43:34.848319666-07:00","level":"debug","message":"Starting wait"}
{"time":"2017-10-06T06:43:34.848328614-07:00","level":"info","date":"unknown","version":"dev","commit":"none","tag":"","message":"Starting pg_prefaulter agent"}
{"time":"2017-10-06T06:43:34.853523595-07:00","level":"error","error":"FATAL: password authentication failed for user \"postgres\" (SQLSTATE 28P01): (retriable: false, purge cache: false","next step":"exiting","message":"unable to find WAL files"}
{"time":"2017-10-06T06:43:34.854155468-07:00","level":"debug","message":"Shutting down"}
{"time":"2017-10-06T06:43:34.857423618-07:00","level":"debug","message":"Stopped pg_prefaulter agent"}
{"time":"2017-10-06T06:43:34.857437766-07:00","level":"info","pid":16113,"message":"Stopped pg_prefaulter"}

Fixes: #10