Error loading config/jwt.json on deploying osctrl with dockerize.sh

[avinashkurup]

Hello,
I am using the latest master branch for deploying osctrl. I am deploying using the dockerize.sh script and face the following issues on deployment.

1. osctrl-api | main.go:163: Error loading config/jwt.json - While parsing config: unexpected end of JSON input
2. osctrl-api exited with code 1

I find that osctrl-api container is in an exited state. After the script runs I see the following.

$ docker ps -a | head
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
540aa20eaa4d osctrl_osquery-ubuntu18 "/bin/sh wait.sh" About an hour ago Up About an hour osquery-ubuntu18
1d14cad30249 nginx:1.13.5 "nginx -g 'daemon of…" About an hour ago Up About an hour 0.0.0.0:443->443/tcp, 80/tcp, 0.0.0.0:8443->8443/tcp osctrl-nginx
d40d37391fbb osctrl_osctrl-tls "/osctrl-tls/bin/osc…" About an hour ago Up About an hour 0.0.0.0:9000->9000/tcp osctrl-tls
11298d44696b osctrl_osctrl-api "/osctrl-api/bin/osc…" About an hour ago Exited (1) About an hour ago osctrl-api
b09756739c1a osctrl_osctrl-admin "/bin/sh /osctrl-adm…" About an hour ago Exited (1) About an hour ago osctrl-admin
85e04607fd8d postgres:10-alpine "docker-entrypoint.s…" About an hour ago Up About an hour 0.0.0.0:5432->5432/tcp osctrl-db

I would like to add that this issue I face with osctrl-admin as well.
osctrl-admin | Created admin user
osctrl-admin | main.go:159: Loading config/admin.json
osctrl-admin | jwt.go:18: Loading config/jwt.json
osctrl-admin | main.go:228: Error loading config/jwt.json - While parsing config: unexpected end of JSON input
osctrl-admin exited with code 1

I find osctrl-api and osctrl-admin in the exited state after the script runs.

I also find these messages in the log.

osctrl-admin | 2020/05/07 01:51:01 Failed to load DB - dial tcp 172.18.0.2:5432: connect: connection refused
osctrl-db | creating subdirectories ... ok
osctrl-db | selecting default max_connections ... 100
osctrl-db | selecting default shared_buffers ... 128MB
osctrl-db | selecting default timezone ... UTC
osctrl-db | selecting dynamic shared memory implementation ... posix
osctrl-db | creating configuration files ... ok
osctrl-db | running bootstrap script ... ok
osctrl-db | performing post-bootstrap initialization ... sh: locale: not found
osctrl-db | 2020-05-07 01:50:52.870 UTC [29] WARNING: no usable system locales were found
osctrl-db | ok
osctrl-db | syncing data to disk ...
osctrl-db | WARNING: enabling "trust" authentication for local connections
osctrl-db | You can change this by editing pg_hba.conf or using the option -A, or
osctrl-db | --auth-local and --auth-host, the next time you run initdb.
osctrl-db | ok
osctrl-db |
osctrl-db | Success. You can now start the database server using:
osctrl-db |
osctrl-db | pg_ctl -D /var/lib/postgresql/data -l logfile start
osctrl-db |
osctrl-db | waiting for server to start....2020-05-07 01:51:01.424 UTC [34] LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
osctrl-db | 2020-05-07 01:51:01.568 UTC [35] LOG: database system was shut down at 2020-05-07 01:50:57 UTC
osctrl-db | 2020-05-07 01:51:01.601 UTC [34] LOG: database system is ready to accept connections
osctrl-db | done
osctrl-db | server started
osctrl-db | CREATE DATABASE
osctrl-db |
osctrl-db |
osctrl-db | /usr/local/bin/docker-entrypoint.sh: ignoring /docker-entrypoint-initdb.d/*
osctrl-db |
osctrl-db | waiting for server to shut down....2020-05-07 01:51:02.910 UTC [34] LOG: received fast shutdown request
osctrl-db | 2020-05-07 01:51:03.016 UTC [34] LOG: aborting any active transactions
osctrl-db | 2020-05-07 01:51:03.017 UTC [34] LOG: worker process: logical replication launcher (PID 41) exited with exit code 1
osctrl-db | 2020-05-07 01:51:03.017 UTC [36] LOG: shutting down
osctrl-db | 2020-05-07 01:51:03.513 UTC [34] LOG: database system is shut down
osctrl-db | done
osctrl-db | server stopped
osctrl-db |
osctrl-db | PostgreSQL init process complete; ready for start up.
osctrl-db |
osctrl-db | 2020-05-07 01:51:03.893 UTC [1] LOG: listening on IPv4 address "0.0.0.0", port 5432
osctrl-db | 2020-05-07 01:51:03.893 UTC [1] LOG: listening on IPv6 address "::", port 5432
osctrl-db | 2020-05-07 01:51:04.002 UTC [1] LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
osctrl-db | 2020-05-07 01:51:04.330 UTC [45] LOG: database system was shut down at 2020-05-07 01:51:03 UTC
osctrl-db | 2020-05-07 01:51:04.360 UTC [46] FATAL: the database system is starting up
osctrl-db | 2020-05-07 01:51:04.456 UTC [1] LOG: database system is ready to accept connections
osctrl-admin | Postgres is unavailable - Waiting...

Please help me with fixing this issue in deployment.

Thank you,
Avinash.

[javuto]

What is the command you used to generate the docker environment? I just tried with master and it did generated a brand new docker osctrl environment with no issues at all. I used make docker_all which is just running ./deploy/docker/dockerize.sh -u -b -f. Please try that and let me know if you are still seeing problems. Thanks!

[avinashkurup]

Thank you Javotu,
I generated the docker environment after pulling latest changes, I used the make docker_all command. I still face the issues as mentioned.

Output of running docker container list.
$ docker ps -a | head
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
7236577fcf60 osctrl_osquery-ubuntu18 "/bin/sh wait.sh" 51 seconds ago Up 46 seconds osquery-ubuntu18
814303a61dac nginx:1.13.5 "nginx -g 'daemon of…" 55 seconds ago Exited (1) 49 seconds ago osctrl-nginx
7125b57b5c8a osctrl_osctrl-tls "/osctrl-tls/bin/osc…" About a minute ago Up 55 seconds 0.0.0.0:9000->9000/tcp osctrl-tls
76cc8a5a8e9d osctrl_osctrl-api "/osctrl-api/bin/osc…" About a minute ago Exited (1) 56 seconds ago osctrl-api
7319dc0151ae osctrl_osctrl-admin "/bin/sh /osctrl-adm…" About a minute ago Exited (1) 37 seconds ago osctrl-admin
85e04607fd8d postgres:10-alpine "docker-entrypoint.s…" 3 days ago Up About a minute 0.0.0.0:5432->5432/tcp osctrl-db

I have appended the log after the containers have started.
Successfully built 3594a4671cfe
Successfully tagged osctrl_osquery-ubuntu18:latest
[+] Access osctrl-admin using https://localhost:8443
[+] Running containers
Starting osctrl-db ... done
Recreating osctrl-admin ... done
Recreating osctrl-tls ... done
Recreating osctrl-api ... done
Recreating osctrl-nginx ... done
Recreating osquery-ubuntu18 ... done
Attaching to osctrl-db, osctrl-api, osctrl-tls, osctrl-admin, osctrl-nginx, osquery-ubuntu18
osctrl-admin | Postgres is up - Starting osctrl-admin
osctrl-api | 2020/05/10 23:23:33 ==================== Initializing osctrl-api v0.2.1
osctrl-api | main.go:112: Loading config/api.json
osctrl-api | jwt.go:14: Loading config/jwt.json
osctrl-api | main.go:164: Error loading config/jwt.json - While parsing config: unexpected end of JSON input
osctrl-api exited with code 1
osctrl-db |
osctrl-db | PostgreSQL Database directory appears to contain a database; Skipping initialization
osctrl-db |
osctrl-db | 2020-05-10 23:23:28.788 UTC [1] LOG: listening on IPv4 address "0.0.0.0", port 5432
osctrl-db | 2020-05-10 23:23:28.788 UTC [1] LOG: listening on IPv6 address "::", port 5432
osctrl-db | 2020-05-10 23:23:28.946 UTC [1] LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
osctrl-db | 2020-05-10 23:23:29.247 UTC [20] LOG: database system was shut down at 2020-05-10 23:20:22 UTC
osctrl-db | 2020-05-10 23:23:29.348 UTC [1] LOG: database system is ready to accept connections
osctrl-tls | 2020/05/10 23:23:34 ==================== Initializing osctrl-tls v0.2.1
osctrl-tls | main.go:93: Loading config/tls.json
osctrl-tls | main.go:142: ==================== Starting osctrl-tls v0.2.1
osctrl-tls | main.go:152: Connection to backend successful!
osctrl-tls | main.go:179: Loading service settings
osctrl-tls | settings.go:390: SetString 0.0.0.0 tls json_listener
osctrl-tls | settings.go:390: SetString 9000 tls json_port
osctrl-tls | settings.go:390: SetString localhost tls json_host
osctrl-tls | settings.go:390: SetString none tls json_auth
osctrl-tls | settings.go:390: SetString db tls json_logging
osctrl-tls | main.go:184: Loading service metrics
osctrl-tls | main.go:190: Loading TLS logger
osctrl-tls | db.go:96: Setting DB logging settings
osquery-ubuntu18 | osctrl is up - Enrolling osctrl-ubuntu18
osctrl-tls | main.go:268: osctrl-tls v0.2.1 - HTTP listening 0.0.0.0:9000
osctrl-tls | utils.go:56: Refreshing settings...
osctrl-tls | utils.go:45: Refreshing environments...
osctrl-nginx | 2020/05/10 23:23:39 [emerg] 1#1: host not found in upstream "osctrl-api" in /etc/nginx/conf.d/api.conf:44
osctrl-nginx | nginx: [emerg] host not found in upstream "osctrl-api" in /etc/nginx/conf.d/api.conf:44
osctrl-nginx exited with code 1
osctrl-admin | Environment dev exists
osquery-ubuntu18 | I0510 23:23:47.335966 7 init.cpp:340] osquery initialized [version=4.2.0]
osquery-ubuntu18 | I0510 23:23:47.336311 7 system.cpp:362] Writing osqueryd pid (7) to /var/run/osqueryd.pidfile
osquery-ubuntu18 | I0510 23:23:47.338867 7 extensions.cpp:349] Could not autoload extensions: Failed reading: /etc/osquery/extensions.load
osquery-ubuntu18 | I0510 23:23:47.340471 8 watcher.cpp:583] osqueryd watcher (7) executing worker (9)
osquery-ubuntu18 | I0510 23:23:47.359158 9 init.cpp:337] osquery worker initialized [watcher=7]
osquery-ubuntu18 | I0510 23:23:47.359905 9 rocksdb.cpp:131] Opening RocksDB handle: /var/osquery/osquery.db
osquery-ubuntu18 | I0510 23:23:47.805342 9 auto_constructed_tables.cpp:93] Removing stale ATC entries
osquery-ubuntu18 | I0510 23:23:47.805356 16 interface.cpp:268] Extension manager service starting: /var/osquery/osquery.em
osquery-ubuntu18 | W0510 23:23:47.806165 9 init.cpp:596] Error reading config: config file does not exist: /etc/osquery/osquery.conf
osquery-ubuntu18 | I0510 23:23:47.831410 9 events.cpp:863] Event publisher not enabled: auditeventpublisher: Publisher disabled via configuration
osquery-ubuntu18 | I0510 23:23:47.831594 9 events.cpp:863] Event publisher not enabled: syslog: Publisher disabled via configuration
osquery-ubuntu18 | I0510 23:23:47.832321 9 events.cpp:1122] Error registering subscriber: process_file_events: Subscriber disabled via configuration
osquery-ubuntu18 | I0510 23:23:47.832382 9 events.cpp:1122] Error registering subscriber: selinux_events: Subscriber disabled via configuration
osquery-ubuntu18 | I0510 23:23:47.832413 9 events.cpp:1122] Error registering subscriber: socket_events: Subscriber disabled via configuration
osquery-ubuntu18 | I0510 23:23:47.832659 9 main.cpp:103] Not starting the distributed query service: Distributed query service not enabled.
osquery-ubuntu18 | I0510 23:23:47.832774 17 events.cpp:784] Starting event publisher run loop: inotify
osquery-ubuntu18 | I0510 23:23:47.838960 18 events.cpp:784] Starting event publisher run loop: udev
osctrl-admin | 2020/05/10 23:23:53 Failed to execute admin already exists
osctrl-admin | Admin user exists
osctrl-admin | 2020/05/10 23:23:53 ==================== Initializing osctrl-admin v0.2.1
osctrl-admin | main.go:159: Loading config/admin.json
osctrl-admin | jwt.go:18: Loading config/jwt.json
osctrl-admin | main.go:229: Error loading config/jwt.json - While parsing config: unexpected end of JSON input
osctrl-admin exited with code 1
osquery-ubuntu18 | I0510 23:25:00.838565 19 database.cpp:140] Resetting the database plugin: rocksdb
osquery-ubuntu18 | I0510 23:25:00.839051 19 rocksdb.cpp:131] Opening RocksDB handle: /var/osquery/osquery.db

[javuto]

Hey Avinash,

Thank you so much for reporting this issue. There was a problem indeed in dockerize.sh and it was using the wrong path for the template to generate the jwt.json, necessary to deploy the osctrl-api component and making the whole deployment to fail. I have added a fix in #70 and I will add it to the 0.2.2 version, which was released today. Please let me know if it works for you and thanks again!

[avinashkurup]

Thank you so much for your help, I just pulled the latest master and ran it on one of the systems which was facing the issue. Now I find all the containers running successfully and the error regarding jwt.json does not come up in the logs.

$ docker ps -a | head
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
482b21936185 osctrl_osquery-ubuntu18 "/bin/sh wait.sh" About a minute ago Up 59 seconds osquery-ubuntu18
897f8cfe2e38 nginx:1.13.5 "nginx -g 'daemon of\u2026" About a minute ago Up About a minute 0.0.0.0:443->443/tcp, 80/tcp, 0.0.0.0:8443->8443/tcp osctrl-nginx
4eeab2c78ce0 osctrl_osctrl-admin "/bin/sh /osctrl-adm\u2026" About a minute ago Up About a minute 0.0.0.0:9001->9001/tcp osctrl-admin
a521aa96d3fc osctrl_osctrl-api "/osctrl-api/bin/osc\u2026" About a minute ago Up About a minute 0.0.0.0:9002->9002/tcp osctrl-api
097be495a6dd osctrl_osctrl-tls "/osctrl-tls/bin/osc\u2026" About a minute ago Up About a minute 0.0.0.0:9000->9000/tcp osctrl-tls
24d63605e9d7 postgres:10-alpine "docker-entrypoint.s\u2026" 19 minutes ago Up 19 minutes 0.0.0.0:5432->5432/tcp osctrl-db

Thank you,
Avinash.

[avinashkurup]

The issue has been fixed. Thank you once again for your prompt reply and help.