Skip to content

SlashDB Logging

SlashDB has 3 sources of logs:

  • SlashDB application
  • WSGI server
  • NGINX reverse proxy

Logging for SlashDB and the WSGI server is configured in the INI file located in /etc/slashdb/slashdb.ini, and logging for the reverse proxy is configured in /etc/slashdb/nginx.conf.

Each log source has been adjusted to use a common format which uses the pipe character | as a separator. This allows for easier log browsing, merging log files together and tracking requests in all components.

All loggers have placeholders for attributes such as:

  • date & time
  • timestamp
  • source
  • logger name
  • level
  • pid
  • thread name
  • request id
  • request method
  • URL
  • resp status code
  • request processing time
  • request size (header + body)
  • response size (headers + body)
  • remote address
  • http referer
  • http user agent
  • python module
  • user id
  • message

This table lists the attributes are provided by each logger:

Generic SlashDB uWSGI internal uWSGI request NGINX
date & time Yes Yes Yes Yes Yes
timestamp Yes Yes Yes Yes Yes
source Yes Yes Yes Yes Yes
logger name Yes Yes Yes Yes Yes
level Yes Yes Yes Yes Yes
pid Yes Yes Yes Yes Yes
thread name Yes Yes Yes Yes
request id Yes Yes Yes
request method Yes Yes Yes
URL Yes Yes Yes
resp status code Yes Yes Yes
request processing time Yes Yes
request size (header + body) Yes
response size (headers + body) Yes Yes
remote address Yes Yes Yes
http referer Yes Yes Yes
http user agent Yes Yes Yes
python module Yes Yes
user id Yes
message Yes Yes Yes

Here is an example of log entries from all three sources regarding the same request:

2024-02-05 13:03:05 | 1707138185141 | sdbapp | slashdb.requests | INFO  | 25 | uWSGIWorker1Core4 | 42d58aadec19c9e11c36284adb236e0c | GET | /db/databricks-chinook/customer.json?limit=29 |     |          |     |       | 192.168.32.3 | https://beta.slashdb.com/db/databricks-chinook.html?retryToken=34VycJU:1 | Mozilla/5.0 (X11; Linux x86_64; rv:122.0) Gecko/20100101 Firefox/122.0 | adapters:derived_subscriber:101 |  | Received request
2024-02-05 13:03:06 | 1707138186845 | sdbapp | slashdb          | DEBUG | 25 | uWSGIWorker1Core4 | 42d58aadec19c9e11c36284adb236e0c | GET | /db/databricks-chinook/customer.json?limit=29 |     |          |     |       | 192.168.32.3 | https://beta.slashdb.com/db/databricks-chinook.html?retryToken=34VycJU:1 | Mozilla/5.0 (X11; Linux x86_64; rv:122.0) Gecko/20100101 Firefox/122.0 | __init__:get_view:8             |  | Closed SQLAlchemy session
2024-02-05 13:03:06 | 1707138186845 | sdbapp | slashdb.requests | INFO  | 25 | uWSGIWorker1Core4 | 42d58aadec19c9e11c36284adb236e0c | GET | /db/databricks-chinook/customer.json?limit=29 |     |          |     |       | 192.168.32.3 | https://beta.slashdb.com/db/databricks-chinook.html?retryToken=34VycJU:1 | Mozilla/5.0 (X11; Linux x86_64; rv:122.0) Gecko/20100101 Firefox/122.0 | adapters:derived_subscriber:101 |  | Returned response
2024-02-05 13:03:06 | 1707138186846 | uwsgi  | uwsgi            | INFO  | 25 | uWSGIWorker1Core4 | 42d58aadec19c9e11c36284adb236e0c | GET | /db/databricks-chinook/customer.json?limit=29 | 200 | 1.704940 |     | 12955 | 192.168.32.3 | https://beta.slashdb.com/db/databricks-chinook.html?retryToken=34VycJU:1 | Mozilla/5.0 (X11; Linux x86_64; rv:122.0) Gecko/20100101 Firefox/122.0 |                                 |  |
2024-02-05 13:03:06 | 1707138186846 | nginx  | nginx            | INFO  | 22 |                   | 42d58aadec19c9e11c36284adb236e0c | GET | /db/databricks-chinook/customer.json?limit=29 | 200 | 1.705    | 740 | 13544 | 192.168.32.3 | https://beta.slashdb.com/db/databricks-chinook.html?retryToken=34VycJU:1 | Mozilla/5.0 (X11; Linux x86_64; rv:122.0) Gecko/20100101 Firefox/122.0 |                                 |  |

SlashDB Application Logs

The application logs are configured in the INI file between lines # Logging Config and # End of Logging Config. You can read more about Python 3 logging in this Logging HOWTO. The logging config allows users to customize what logs are collected, where they are sent and in what format.

The default SlashDB application logging configuration is explained below.

Loggers

The base sources for logs are 3 loggers: root, slashdb and exc_logger,which are enabled by default. The other three: sqlalchemy,sqlalchemy_engine and sqlalchemy_pool are useful for debugging communication with databases and are disabled by default.

Logger root

A special logger that collects log entries from all other loggers unless the other loggers are configured with propagate = 0 to prevent that behavior.

  • level INFO
  • logs are passed to the file handler which uses the generic formatter
  • logs are saved in /var/log/slashdb/slashdb.log. 
[logger_root]
level = INFO
handlers = file

Logger slashdb

A general SlashDB application logger which provides additional SlashDB specific log record attributes used by a formatter.

  • level INFO
  • logs are sent to the file_slashdb handler which uses the slashdb formatter
  • propagate = 0 prevents duplicated logs by not passing logs to the root logger
  • logs are saved in /var/log/slashdb/slashdb.log
[logger_slashdb]
level = INFO
handlers = file_slashdb
qualname = slashdb
propagate = 0

Logger exc_logger

A logger for errors which are not handled by the application.

  • level ERROR
  • logs are passed to the exc_handler handler and formatted with the exc_formatter
  • propagate = 0 prevents duplicated logs by not passing logs to the root logger
  • logs are saved in /var/log/slashdb/exceptions.log
[logger_exc_logger]
level = ERROR
handlers = exc_handler
qualname = exc_logger
propagate = 0

Logger sqlalchemy

A general logger for communication with databases. Provides information about connections, database reflect process, etc.

  • level WARNING
  • the logger does not have a specific handler defined but logs are propagated (propagate = 1), which means the logs will also be collected and handled by the root logger and saved in /var/log/slashdb/slashdb.log.
[logger_sqlalchemy]
level = WARNING
handlers =
qualname = sqlalchemy
propagate = 1

Logger sqlalchemy_engine

Similar to the sqlalchemy logger, but monitors the database engine, which allows it to log actual SQL statements that are sent to databases or even the returned data set.

[logger_sqlalchemy_engine]
level = INFO
handlers =
qualname = sqlalchemy.engine
propagate = 1

Logger sqlalchemy_pool

Similar to the sqlalchemy logger, but logs information related to creating database connections.

[logger_sqlalchemy_pool]
level = INFO
handlers =
qualname = sqlalchemy.pool
propagate = 1

Handlers

These receive log entries from loggers, format them using a predefined formatter and send them to an output stream like stdio, files, etc. (many more available - see Python 3 logging handlers).

Handler file

[handler_file]
class = handlers.WatchedFileHandler
args = ('/var/log/slashdb/slashdb.log', 'a', 'utf-8')
level = NOTSET
formatter = generic

This is a WatchedFileHandler which saves log entries to a file /var/log/slashdb/slashdb.log using the generic formatter.

The handler file is not configured to rotate log files because it saves log entries to the same file as the file_slashdb handler. The latter is responsible for log file rotation. If both were configured to rotate the same file, they would interfere with each other and break log entries.

Handler file_slashdb

This is a RotatingFileHandler which saves log entries in 5 files, each 2 MB. The handler is configured to use the slashdb formatter that can handle SlashDB-specific log record attributes. 

[handler_file_slashdb]
class = handlers.RotatingFileHandler
args = ('/var/log/slashdb/slashdb.log', 'a', 2*1024*1024, 5, 'utf-8')
level = NOTSET
formatter = slashdb

The args are:

  • /var/log/slashdb/slashdb.log location and name of the file where logs are stored
  • a is the file mode used to append data to the file
  • 2*1024*1024 is the maximum size of each file, i.e. 2 MB
  • utf-8 specifies the encoding of the file

Handler exc_handler

This is a RotatingFileHandler that uses the exc_formatter formatter and saves log entries in 5 files, each 2 MB. The oldest file is removed to make space for newer logs. For more information, please refer to the documentation on RotatingFileHandler.

[handler_exc_handler]
class = handlers.RotatingFileHandler
args = ('/var/log/slashdb/exceptions.log', 'a', 2*1024*1024, 5, 'utf-8')
level = ERROR
formatter = exc_formatter

The args are:

  • /var/log/slashdb/exceptions.log location and name of the file where logs are stored
  • a is the file mode used to append data to the file
  • 2*1024*1024 is the maximum size of each file, i.e. 2 MB
  • utf-8 specifies the encoding of the file

Formatters

These define how log entries appear. Various log record attributes can be used to provide additional information beyond the message from the source; for example, the log record attribute %(asctime)s adds human readable date and time to the log entry.

Formatter generic

The general formatter that uses standard log record attributes.

[formatter_generic]
format = %(asctime)-.19s | %(created)d%(msecs)03d | sdbapp | %(name)s | %(levelname)-5.5s | %(process)d | %(threadName)s |  |  |  |  |  |  |  |  |  |  | %(module)s:%(funcName)s:%(lineno)d |  | %(message)s

Empty segments in the format are necessary to keep logs consistent with logs from different sources, making them easier to analyze together.

Formatter slashdb

The root and slashdb loggers are very similar but must be separated because only the slashdb logger provides SlashDB-specific log record attributes. The formatter will fail to generate a log entry if an attribute is not available from its source. The slashdb logger has a special formatter configuration for this purpose.

The formatter handles SlashDB-specific log record attributes associated with each log entry such as:

  • user_id - SlashDB authenticated user id
  • request_id - unique request identifier that is the same across all loggers, making it easier to track a specific request
  • request_method - HTTP request method
  • request_url - request URL
  • response_status_code - status code of the HTTP response
  • request_client_addr - IP address of the client that sent the request
  • request_referer - address of the web page from which the resource was requested
  • request_user_agent - client user agent
[formatter_slashdb]
format = %(asctime)-.19s | %(created)d%(msecs)03d | sdbapp | %(name)s | %(levelname)-5.5s | %(process)d | %(threadName)s | %(request_id)s | %(request_method)s | %(request_url)s | %(response_status_code)s |  |  |  | %(request_client_addr)s | %(request_referer)s | %(request_user_agent)s | %(module)s:%(funcName)s:%(lineno)d | %(user_id)s | %(message)s

Formatter exc_formatter

Formatter for exceptions that matches the unified log format.

[formatter_exc_formatter]
format = %(asctime)-.19s | %(created)d%(msecs)03d | sdbapp | %(name)s | %(levelname)-5.5s | %(process)d | %(threadName)s |  |  |  |  |  |  |  |  |  |  | %(module)s:%(funcName)s:%(lineno)d |  | %(message)s

Debugging

Extended log details

There are 5 levels of event severity:

  • DEBUG
  • INFO
  • WARNING
  • ERROR
  • CRITICAL

DEBUG is the most detailed, CRITICAL logs only the most important events.

In case more detailed logs are needed for debugging, you can change the log level severity:

Detailed log entries will appear in /var/log/slashdb/slshdb.log.

Limiting SQLAlchemy Logger Output for Clarity

Because the sqlalchemy logger collects logs from many SQLAlchemy modules, the output may be very cluttered when using the INFO level. In such cases, it's better set the detailed logging level on a more specific logger, e.g sqlalchemy.engine and keep the sqlalchemy level as INFO. The sqlalchemy.engine logger can provide useful information like the SQL statements that are sent to databases.

The sqlalchemy.engine logger is already in the INI configuration file and only has to be enabled. Just replace the logger key sqlalchemy with sqlalchemy_engine for the keys option in the [loggers] section of the INI file. The section should look like:

[loggers]
keys = root, slashdb, exc_logger, sqlalchemy_engine

uWSGI Server Logs

SlashDB is distributed with uWSGI server. By default, the server logs are saved separately from application logs in /var/log/slashdb/uwsgi.log

The logs provided by uWSGI are configurable in the [uwsgi] section starting at the line labeled # uWSGI Logging Settings

# uWSGI Logging Settings
logto = /var/log/slashdb/uwsgi.log
logfile-chown = slashdb:slashdb
# 20 MB
log-maxsize = %(20 * 1024 * 1024)

# internal uWSGI logs
logger = stdio
log-encoder = format ${strftime:%%Y-%%m-%%d %%H:%%M:%%S} | ${millis} | uwsgi | uwsgi | INFO |  |  |  |  |  |  |  |  |  |  |  |  |  |  | ${msgnl}

# request logs
logger-req = stdio
log-req-encoder = format ${strftime:%%Y-%%m-%%d %%H:%%M:%%S} | ${millis} | uwsgi | uwsgi | INFO | ${msgnl}
log-format = %(pid) | uWSGIWorker%(wid)Core%(core) | %(var.REQUEST_ID) | %(method) | %(uri) | %(status) | %(secs) |  | %(size) | %(addr) | %(referer) | %(uagent) |  |  |
  • logto - location of the uWSGI log file (not rotated)
  • logfile-chown - sets the log file owner and group
  • log-maxsize - maximum size of the file in bytes
  • logger - type of logger plugin to be used when option logto is not present; used when uWSGI is started as foreground process for debugging purposes
  • log-encoder - log encoder type and format for uWSGI internal logs which matches the unified log format
  • log-req-encoder - log encoder type and format for request logs which matches the unified log format

NGINX Logs

All HTTP requests are logged by the reverse proxy, NGINX. Request logs match the unified format and are saved in /var/log/nginx/access.log. Errors are saved in /var/log/nginx/error.log but NGINX does not allow configuring error message formats. However, the slashdb-diag tool can parse these logs and output them in the unified format.

log_format sdblog '$time_iso8601mod | $msec_int | nginx | nginx | INFO '
                  '| $pid |  | $request_id  | $request_method | $request_uri '
                  '| $status | $request_time  | $request_length | $bytes_sent '
                  '| $remote_addr | $http_referer | $http_user_agent |  |  | ';

access_log /var/log/nginx/access.log sdblog;
error_log /var/log/nginx/error.log;
  • log_format - name and format for access log
  • access_log - path to file for access log
  • error_log - path to file for error log

For more information on configuring logging, please refer to the NGINX documentation.

Collecting Logs with slashdb-diag tool

The CLI tool slashb-diag helps to collect logs and configuration files. It allows filtering logs by a specified date range, combining different logs, and zipping them with configuration files into a single file. For security purposes, all database and user credentials are masked.

To use the tool, SSH to the server, activate the SlashDB environment and run slashdb-diag which by default collects all configs and logs from default locations, then combines all logs into a single log and finally makes a single zip file.

For more options, run slashdb-diag --help to see the help documentation. 

source /opt/slashdb/bin/activate
slashdb-diag --help

Usage: slashdb-diag [OPTIONS] LOG_FILES

  Tool for collecting log files and config files to help with troubleshooting.

  Examples:
  $ slashdb_diag
  Will try to find configs and logs in standard locations
  and will save them in a zip file.

  $ slashdb_diag --ini /path/to/slashdb.ini --nginx-conf /path/to/nginx.conf
  Will get configs and logs based on the paths provided.

  $ slashdb_diag /var/log/slashdb/slashdb.log /var/log/slashdb/uwsgi.log --no-combined --no-zip
  Will get only these two log files and save them in a folder.

  $ slashdb_diag --start 2023-11-17T16:06:10 --end 2023-11-17T17:06:10
  Will get only logs in the given time frame.

Options:
  --ini FILE                   Path to slashdb.ini.
  --nginx-conf FILE            Path to nginx.conf.
  --start [%Y-%m-%dT%H:%M:%S]  Start date of the logs, YYYY-MM-DDTHH:mm:ss
                               format.
  --end [%Y-%m-%dT%H:%M:%S]    End date of the logs, YYYY-MM-DDTHH:mm:ss
                               format.
  --configs / --no-configs     Whether to include config files.  [default:
                               configs]
  --zip / --no-zip             Whether to zip the resulting directory.
                               [default: zip]
  --combined / --no-combined   Whether to combine log files to a single file.
                               [default: combined]
  --help                       Show this message and exit.

Saving Logs in S3

Assuming the AWS CLI is configured for root on the SlashDB instance, you can run a daily cron job that will copy log files.

Below is a cron job definition that runs every day at 2 AM, looking for files in SDB_LOGS_DIR that are not older than 1 day and sends them to an S3 bucket defined in SDB_LOGS_S3.

The same is done for NGINX logs from folder NGX_LOGS_DIR to bucket NGX_LOGS_S3.

To edit cron:

sudo crontab -e

then paste, assuming the environment variables SDB_LOGS_S3 and NGX_LOGS_S3 are S3 buckets and folders where you want to save the logs:

SDB_LOGS_DIR=/var/log/slashdb
SDB_LOGS_S3=s3://slashdb-logs/instance1/slashdb

NGX_LOGS_DIR=/var/log/nginx
NGX_LOGS_S3=s3://slashdb-logs/instance1/nginx


0  2  *  *  *  find ${SDB_LOGS_DIR} -type f -mtime -1 | xargs -L 1 -I {} bash -c 'aws s3 cp {} ${SDB_LOGS_S3}'
0  2  *  *  *  find ${NGX_LOGS_DIR} -type f -mtime -1 | xargs -L 1 -I {} bash -c 'aws s3 cp {} ${NGX_LOGS_S3}'

Sending Logs to CloudWatch

The easiest way is to use amazon-cloudwatch-agent. That allows sending any logs without need to install additional Python libraries.

To start quickly, follow the blog post Monitoring NGINX with CloudWatch. It has straightforward instructions on how to setup the amazon-cloudwatch-agent.

To dive deeper, read the official Amazon documentation on the agent.

The logs for SlashDB are located in folders: - /var/log/slashdb - /var/log/nginx