Logging

This section describes the logging mechanisms in Neo4j, including general log files, error messages, and severity levels.

Log files

Neo4j provides logs for monitoring purposes. The root directory where the general log files are located is configured by dbms.directories.logs. The default format of the log files is configured by dbms.logs.default_format. For more information on where files are located, see File locations.

The following table describes the Neo4j general log files and the information they contain.

Table 1. Neo4j logs for monitoring
Filename Name Description

neo4j.log

The user log

Logs general information about Neo4j. Not written for Debian and RPM packages.

debug.log

The debug log

Logs information that is useful when debugging problems with Neo4j.

http.log

The HTTP log

Logs information about the HTTP API.

gc.log

The garbage collection log

Logs information provided by the JVM.

query.log

The query log

Logs information about queries that run longer than a specified threshold. Enterprise

security.log

The security log

Logs information about security events. Enterprise

service-error.log

The windows service log

Logs information about errors encountered when installing or running the Windows service. Windows

Table 2. Log paths
Configuration setting Default value Description

dbms.directories.logs

logs

Path to the logs directory.

dbms.logs.user.path

neo4j.log

Path to the user log file.

dbms.logs.debug.path

debug.log

Path to the debug log file.

dbms.logs.http.path

http.log

Path to the HTTP log file.

dbms.logs.query.path

query.log

Path to the query log file.

dbms.logs.security.path

security.log

Path to the security log file.

Log format

Table 3. Log formats
Configuration setting Default value Description

dbms.logs.default_format

PLAIN

The default log format for all logs. Valid options are PLAIN and JSON.

dbms.logs.user.format

Inherits from dbms.logs.default_format

The log format for the user log. Valid options are PLAIN and JSON.

dbms.logs.query.format

Inherits from dbms.logs.default_format

The log format for the query log. Valid options are PLAIN and JSON.

dbms.logs.debug.format

Inherits from dbms.logs.default_format

The log format for the debug log. Valid options are PLAIN and JSON.

dbms.logs.security.format

Inherits from dbms.logs.default_format

The log format for the security log. Valid options are PLAIN and JSON.

Log configurations

There are a number of configuration options to enable/disable logging, decide how to rotate the logs, and how many of the logs to keep around.

User log (neo4j.log)

Table 4. User log configurations
The user log configuration Default value Description

dbms.logs.user.format

Inherits from dbms.logs.default_format

The log format for the user log.

dbms.logs.user.rotation.delay

5m

The minimum time interval after the last rotation of the user log before it may be rotated again.

dbms.logs.user.rotation.keep_number

7

The maximum number of history files for the user log.

dbms.logs.user.rotation.size

0B

The threshold size for rotation of the user log. If set to 0, the log rotation is disabled.

dbms.logs.user.stdout_enabled

true

Send user logs to the process stdout. If disabled, the logs are sent to the user log.

The following information is available in the JSON format:

Table 5. JSON format log entries
Name Description

time

The timestamp of the log message.

level

The log level.

message

The log message.

stacktrace

Included when there is a stacktrace associated with the log message.

Debug log

The debug log logs problems, errors, stacktraces, etc.

Table 6. Debug log configurations
The debug log configuration Default value Description

dbms.logs.debug.level

INFO

Log level threshold for the debug log.

dbms.logs.debug.format

Inherits from dbms.logs.default_format

The log format for the debug log.

dbms.logs.debug.rotation.delay

5m

The minimum time interval after the last rotation of the debug log before it may be rotated again.

dbms.logs.debug.rotation.keep_number

7

The maximum number of history files for the debug log.

dbms.logs.debug.rotation.size

20M

The threshold size for rotation of the debug log.

The following table lists all message types raised by Neo4j and their severity level:

Table 7. Message types
Message type Severity level Description

INFO

Low severity

Report status information and errors that are not severe.

DEBUG

Low severity

Report details on the raised errors and possible solutions.

WARN

Low severity

Report errors that need attention but are not severe.

ERROR

High severity

Report errors that prevent the Neo4j server from running and must be addressed immediately.

To set the log level threshold for the debug log, use the configuration setting dbms.logs.debug.level.

The following information is available in the JSON format:

Table 8. JSON format log entries
Name Description

time

The timestamp of the log message.

level

The log level.

category

The class the message was logged from.

message

The log message.

stacktrace

Included when there is a stacktrace associated with the log message.

Garbage collection log

Table 9. Garbage collection log configurations
The garbage collection log configuration Default value Description

dbms.logs.gc.enabled

false

Enable garbage collection logging.

dbms.logs.gc.options

Garbage collection logging options.

dbms.logs.gc.rotation.keep_number

0

The maximum number of history files for the garbage collection log.

dbms.logs.gc.rotation.size

The threshold size for rotation of the garbage collection log.

HTTP log

Table 10. HTTP log configurations
The HTTP log configuration Default value Description

dbms.logs.http.enabled

false

Enable HTTP logging.

dbms.logs.http.rotation.keep_number

5

The maximum number of history files for the HTTP log.

dbms.logs.http.rotation.size

20M

The threshold size for rotation of the HTTP log.

Security log

Neo4j provides security event logging that records all security events.

For native user management, the following actions are recorded:

  • Login attempts — by default, both successful and unsuccessful logins are recorded.

  • All administration commands run against the system database.

  • All security procedures run against the system database.

  • Authorization failures from role-based access control.

Rotation of the security events log can be configured in the neo4j.conf configuration file.

The following configuration settings are available for the security log:

Table 11. Security log configurations
The security log configuration Default value Description

INFO

Security log level threshold.

Inherits from dbms.logs.default_format

The log format for the security log.

security.log

The name of the security log file.

20M

The file size at which the security event log auto-rotates.

300s

The minimum time interval after the last security log rotation occurred before the security log may be rotated again.

7

The number of historical log files kept.

If using LDAP as the authentication method, some cases of LDAP misconfiguration are also logged, as well as LDAP server communication events and failures.

If many programmatic interactions are expected, it is advised to disable the logging of successful logins by setting the dbms.security.log_successful_authentication parameter in the neo4j.conf file:

dbms.security.log_successful_authentication=false

The following information is available in the JSON format:

Table 12. JSON format log entries
Name Description

time

The timestamp of the log message.

level

The log level.

type

It is always security.

source

Connection details.

database

The database name the command is executed on.

username

The user connected to the security event. This field is deprecated by executingUser.

executingUser

The name of the user triggering the security event. Either same as authenticatedUser or an impersonated user.

authenticatedUser

The name of the user who authenticated and is connected to the security event.

message

The log message.

stacktrace

Included if there is a stacktrace associated with the log message.

Example of the security log in plain format:

2019-12-09 13:45:00.796+0000 INFO  [AsyncLog @ 2019-12-09 ...]  [johnsmith]: logged in
2019-12-09 13:47:53.443+0000 ERROR [AsyncLog @ 2019-12-09 ...]  [johndoe]: failed to log in: invalid principal or credentials
2019-12-09 13:48:28.566+0000 INFO  [AsyncLog @ 2019-12-09 ...]  [johnsmith]: CREATE USER janedoe SET PASSWORD '******' CHANGE REQUIRED
2019-12-09 13:48:32.753+0000 INFO  [AsyncLog @ 2019-12-09 ...]  [johnsmith]: CREATE ROLE custom
2019-12-09 13:49:11.880+0000 INFO  [AsyncLog @ 2019-12-09 ...]  [johnsmith]: GRANT ROLE custom TO janedoe
2019-12-09 13:49:34.979+0000 INFO  [AsyncLog @ 2019-12-09 ...]  [johnsmith]: GRANT TRAVERSE ON GRAPH * NODES A, B (*) TO custom
2019-12-09 13:49:37.053+0000 INFO  [AsyncLog @ 2019-12-09 ...]  [johnsmith]: DROP USER janedoe
2019-12-09 13:52:24.685+0000 INFO  [AsyncLog @ 2019-12-09 ...]  [johnsmith:alice]: impersonating user alice logged in

Query log

Query logging is enabled by default and is controlled by the setting dbms.logs.query.enabled. It helps you analyze long-running queries and does not impact system performance. The default is to log all queries, but it is recommended to log for queries exceeding a certain threshold.

The following configuration settings are available for the query log:

Table 13. Query log enabled setting
Option Description

OFF

Completely disable logging.

INFO

Log at the end of queries that have either succeeded or failed. The dbms.logs.query.threshold parameter is used to determine the threshold for logging a query. If the execution of a query takes longer than this threshold, the query is logged. Setting the threshold to 0s results in all queries being logged.

VERBOSE

Log all queries at both start and finish, regardless of dbms.logs.query.threshold. Default

The name of the query log file is query.log by default. For more information, see dbms.logs.query.path.

You can configure the rotation of the query log in the neo4j.conf file.

The following configuration settings are available for the query log file:

Table 14. Query log configurations
The query log configuration Default value Description

dbms.logs.query.allocation_logging_enabled

true

Log allocated bytes for the executed queries being logged. The logged number is cumulative over the duration of the query. That means the value may be larger for memory intense or long-running queries than the current memory allocation. Requires dbms.track_query_allocation=true.

dbms.logs.query.early_raw_logging_enabled

false

Log query text and parameters without obfuscating passwords. This allows queries to be logged earlier before parsing starts.

dbms.logs.query.enabled

VERBOSE

Log executed queries.

dbms.logs.query.format

Inherits from dbms.logs.default_format

The log format for the query log. For logging detailed time information requires dbms.track_query_cpu_time=true.

dbms.logs.query.max_parameter_length

2147483647

This configuration option allows you to set a maximum parameter length to include in the log. Parameters exceeding this length will be truncated and appended with .... This applies to each parameter in the query.

dbms.logs.query.obfuscate_literals

false

If true, obfuscates all query literals before writing to the log. This is useful when Cypher queries expose sensitive information.

Node labels, relationship types, and map property keys are still shown. Changing the setting does not affect cached queries. Therefore, if you want the switch to have an immediate effect, you must also clear the query cache; CALL db.clearQueryCaches().

This does not obfuscate literals in parameters. If parameter values are not required in the log, set dbms.logs.query.parameter_logging_enabled=false.

dbms.logs.query.page_logging_enabled

false

Log page hits and page faults for the executed queries being logged.

dbms.logs.query.parameter_full_entities

false

Log complete parameter entities including ID, labels or relationship type, and properties. If false, only the entity ID is logged. This only takes effect if dbms.logs.query.parameter_logging_enabled=true.

dbms.logs.query.parameter_logging_enabled

true

Log parameters for the executed queries being logged. You can disable this configuration setting if you do not want to display sensitive information.

dbms.logs.query.plan_description_enabled

false

This configuration option allows you to log the query plan for each query. The query plan shows up as a description table and is useful for debugging purposes. Every time a Cypher query is run, it generates and uses a plan for the execution of the code. The plan generated can be affected by changes in the database, such as adding a new index. As a result, it is not possible to historically see what plan was used for the original query execution.

Enabling this option has a performance impact on the database due to the cost of preparing and including the plan in the query log. It is not recommended for everyday use.

dbms.logs.query.rotation.keep_number

7

The maximum number of history files for the query log.

dbms.logs.query.rotation.size

20M

The file size in bytes at which the query log auto-rotates.

dbms.logs.query.runtime_logging_enabled

true

Logs which runtime that was used to run the query.

dbms.logs.query.threshold

0s

If the query execution takes longer than this threshold, the query is logged once completed (provided query logging is set to INFO). A threshold of 0 seconds logs all queries.

dbms.logs.query.time_logging_enabled

false

Log detailed time information for the executed queries being logged, such as (planning: 92, waiting: 0). Eanbling dbms.track_query_cpu_time=true as well, adds the CPU time used by current transaction in milliseconds, e.g., (planning: 95, cpu: 96, waiting: 0).

dbms.logs.query.transaction.enabled

OFF

Track the start and end of a transaction within the query log. Log entries are written to the query log. They include the transaction ID for a specific query and the start and end of a transaction. You can also choose a level of logging (OFF, INFO, or VERBOSE). If INFO is selected, you must exceed the time before the log is written (dbms.logs.query.transaction.threshold).

dbms.logs.query.transaction.threshold

0s

If the transaction is open for longer than this threshold (duration of time), the transaction is logged once completed, provided transaction logging is set to INFO. Defaults to 0 seconds, which means all transactions are logged. This can be useful when identifying where there is a significant time lapse after query execution and transaction commits, especially in performance analysis around locking.

dbms.logs.query.transaction_id.enabled

false

This configuration option allows the administrator to request the transaction ID is included with the query ID in all query log entries. Queries are run as part of a transaction. For simple queries, there is usually a 1:1 correlation. In application usage, however, a transaction can include many queries, especially if retries are required in the event of connection instability.

Example 1. Configure for simple query logging

In this example, the query logging is set to INFO, and all other query log parameters are at their defaults.

dbms.logs.query.enabled=INFO

Below is an example of the query log with this basic configuration:

2017-11-22 14:31 ... INFO  9 ms: bolt-session	bolt	johndoe	neo4j-javascript/1.4.1		client/127.0.0.1:59167	...
2017-11-22 14:31 ... INFO  0 ms: bolt-session	bolt	johndoe	neo4j-javascript/1.4.1		client/127.0.0.1:59167	...
2017-11-22 14:32 ... INFO  3 ms: server-session	http	127.0.0.1	/db/data/cypher	neo4j - CALL dbms.procedures() - {}
2017-11-22 14:32 ... INFO  1 ms: server-session	http	127.0.0.1	/db/data/cypher	neo4j - CALL dbms.showCurrentUs...
2017-11-22 14:32 ... INFO  0 ms: bolt-session	bolt	johndoe	neo4j-javascript/1.4.1		client/127.0.0.1:59167	...
2017-11-22 14:32 ... INFO  0 ms: bolt-session	bolt	johndoe	neo4j-javascript/1.4.1		client/127.0.0.1:59167	...
2017-11-22 14:32 ... INFO  2 ms: bolt-session	bolt	johndoe	neo4j-javascript/1.4.1		client/127.0.0.1:59261	...
Example 2. Configure for query logging with more details

In this example, the query log is enabled, as well as some additional logging:

dbms.logs.query.enabled=INFO
dbms.logs.query.allocation_logging_enabled=true
dbms.logs.query.page_logging_enabled=true
dbms.logs.query.parameter_logging_enabled=true
dbms.logs.query.time_logging_enabled=true
dbms.logs.query.threshold=<appropriate value>

The following sample query is run on the Movies database:

MATCH (n:Person {name:'Tom Hanks'})-[:ACTED_IN]->(n1:Movie)<-[:DIRECTED]-(n2:Person {name:"Tom Hanks"}) RETURN n1.title

The corresponding query log in <.file>query.log is:

2017-11-23 12:44:56.973+0000 INFO  1550 ms: (planning: 20, cpu: 920, waiting: 10) - 13792 B - 15 page hits, 0 page faults - bolt-session	bolt	neo4j	neo4j-javascript/1.4.1		client/127.0.0.1:58189	server/127.0.0.1:7687>	neo4j - match (n:Person {name:'Tom Hanks'})-[:ACTED_IN]->(n1:Movie)<-[:DIRECTED]-(n2:Person {name:"Tom Hanks"}) return n1.title; - {} - {}

An obvious but essential point of note when examining parameters of a particular query is to ensure you analyze only the entries relevant to that specific query plan, as opposed to, e.g., CPU, time, bytes, and so on for each log entry in sequence.

Following is a breakdown of resource usage parameters with descriptions corresponding to the above query:

2017-11-23 12:44:56.973+0000

Log timestamp.

INFO

Log category.

1550 ms

Total elapsed cumulative wall time spent in query execution. It is the total of planning time + CPU + waiting + any other processing time, e.g., taken to acquire execution threads. This figure is cumulative for every time a CPU thread works on executing the query.

Planning

Refers to the time the Cypher engine takes to create a query plan. Plans may be cached for repetitive queries, and therefore, planning times for such queries will be shorter than those for previously unplanned ones. In the example, this contributed 20ms to the total execution time of 1550ms.

CPU time

Refers to the time taken by the individual threads executing the query, e.g., a query is submitted at 08:00. It uses CPU for 720ms, but then the CPU swaps out to another query, so the first query is no longer using the CPU. Then, after 100ms, it gets/uses the CPU again for 200ms (more results to be loaded, requested by the client via the Driver), then the query completes at 08:01:30, so the total duration is 1550ms (includes some round-trip time for 2 round-trips), and CPU is 720+200=920ms.

Waiting

Time a query spent waiting before execution (in ms), for example, if an existing query has a lock which the new query must wait to release. In the example, this contributed 10ms to the total execution time of 1550ms.
It is important to note that the client requests data from the server only when its record buffer is empty (one round-trip from the server may end up with several records), and the server stops pushing data into outgoing buffers if the client does not read them in a timely fashion. Therefore, it depends on the size of the result set. If it is relatively small and fits in a single round-trip, the client receives all the results at once, and the server finishes processing without any client-side effect. Meanwhile, if the result set is large, the client-side processing time will affect the overall time, as it is directly connected to when new data is requested from the server.

13792 B

The allocated bytes for the executed queries being logged. This is the amount of HEAP memory used during the life of the query. The logged number is cumulative over the duration of the query, i.e., for memory intense or long-running queries the value may be larger than the current memory allocation.

15 page hits

Page hit means the result was returned from page cache as opposed to disk. In this case, page cache was hit 15 times.

0 page faults

Page fault means that the query result data was not in the dbms.memory.pagecache, and therefore, had to be fetched from the file system. In this case, query results were returned entirely from the 8 page cache hits mentioned above, so there were 0 hits on the disk required.

bolt-session

The session type.

bolt

The Browser ←→ database communication protocol used by the query.

neo4j

The process ID.

neo4j-javascript/1.4.1

The Driver version.

client/127.0.0.1:52935

The query client outbound IP:port used.

server/127.0.0.1:7687>

The server listening IP:port used.

neo4j

username of the query executioner

match (n:Person {name:'Tom Hanks'})-[:ACTED_IN]→(n1:Movie)←[:DIRECTED]-(n2:Person {name:"Tom Hanks"}) return n1.title

The executed query.

The last two parenthesis {} {} are for the query parameters and txMetaData.

Attach metadata to a transaction

You can attach metadata to a transaction and have it printed in the query log using the built-in procedure tx.setMetaData.

Neo4j Drivers also support attaching metadata to a transaction. For more information, see the respective Driver’s manual.

Every graph app should follow a convention for passing metadata with the queries that it sends to Neo4j:

{
  app: "neo4j-browser_v4.4.0", (1)
  type: "system" (2)
}
1 app can be a user-agent styled-name plus version.
2 type can be one of:
  • system — a query automatically run by the app.

  • user-direct — a query the user directly submitted to/through the app.

  • user-action — a query resulting from an action the user performed.

  • user-transpiled — a query that has been derived from the user input.

This is typically done programmatically but can also be used with the Neo4j dev tools.
In general, you start a transaction on a user database and attach a list of metadata to it by calling tx.setMetaData. You can also use the procedure CALL tx.getMetaData() to show the metadata of the current transaction. These examples use the MovieGraph dataset from the Neo4j Browser guide.

Example 3. Using cypher-shell, attach metadata to a transaction
neo4j@neo4j> :begin
neo4j@neo4j# CALL tx.setMetaData({app: 'neo4j-cypher-shell_v.4.4.0', type: 'user-direct', user: 'jsmith'});
0 rows
ready to start consuming query after 2 ms, results consumed after another 0 ms
neo4j@neo4j# CALL tx.getMetaData();
+--------------------------------------------------------------------------+
| metadata                                                                 |
+--------------------------------------------------------------------------+
| {app: "neo4j-cypher-shell_v.4.4.0", type: "user-direct", user: "jsmith"} |
+--------------------------------------------------------------------------+

1 row
ready to start consuming query after 37 ms, results consumed after another 2 ms
neo4j@neo4j# MATCH (n:Person) RETURN n  LIMIT 5;
+----------------------------------------------------+
| n                                                  |
+----------------------------------------------------+
| (:Person {name: "Keanu Reeves", born: 1964})       |
| (:Person {name: "Carrie-Anne Moss", born: 1967})   |
| (:Person {name: "Laurence Fishburne", born: 1961}) |
| (:Person {name: "Hugo Weaving", born: 1960})       |
| (:Person {name: "Lilly Wachowski", born: 1967})    |
+----------------------------------------------------+

5 rows
ready to start consuming query after 2 ms, results consumed after another 1 ms
neo4j@neo4j# :commit
Example result in the query.log file
2021-07-30 14:43:17.176+0000 INFO  id:225 - 2 ms: 136 B - bolt-session	bolt	neo4j-cypher-shell/v4.4.0		client/127.0.0.1:54026	server/127.0.0.1:7687>	neo4j - neo4j -
MATCH (n:Person) RETURN n  LIMIT 5; - {} - runtime=pipelined - {app: 'neo4j-cypher-shell_v.4.4.0', type: 'user-direct', user: 'jsmith'}
Example 4. Using Neo4j Browser, attach metadata to a transaction
CALL tx.setMetaData({app: 'neo4j-browser_v.4.4.0', type: 'user-direct', user: 'jsmith'});
MATCH (n:Person) RETURN n LIMIT 5
Example result in the query.log file
2021-07-30 14:51:39.457+0000 INFO  Query started: id:328 - 0 ms: 0 B - bolt-session	bolt	neo4j-browser/v4.4.0		client/127.0.0.1:53666	server/127.0.0.1:7687>	neo4j - neo4j - MATCH (n:Person) RETURN n  LIMIT 5 - {} - runtime=null - {type: 'system', app: 'neo4j-browser_v4.4.0'}
Example 5. Using Neo4j Bloom, attach metadata to a transaction
CALL tx.setMetaData({app: 'neo4j-browser_v.1.7.0', type: 'user-direct', user: 'jsmith'})
MATCH (n:Person) RETURN n LIMIT 5
Example result in the query.log file
2021-07-30 15:09:54.048+0000 INFO  id:95 - 1 ms: 72 B - bolt-session	bolt	neo4j-bloom/v1.7.0		client/127.0.0.1:54693	server/127.0.0.1:11003>	neo4j - neo4j - RETURN TRUE - {} - runtime=pipelined - {app: 'neo4j-bloom_v1.7.0', type: 'system'}

In Neo4j Browser and Bloom, the user-provided metadata is always replaced by the system metadata.

JSON format

The following information is available in the JSON format:

Table 15. JSON format log entries
Name Description

time

The timestamp of the log message.

level

The log level.

type

Valid options are query and transaction.

stacktrace

Included when there is a stacktrace associated with the log message.

If the type of the log entry is query, these additional fields are available:

Table 16. JSON format log entries
Name Description

event

Valid options are start, fail, and success.

id

The query ID. Included when dbms.logs.query.enabled is VERBOSE.

elapsedTimeMs

The elapsed time in milliseconds.

planning

Milliseconds spent on planning. Included when dbms.logs.query.time_logging_enabled is true.

cpu

Milliseconds spent actively executing on the CPU. Included when dbms.logs.query.time_logging_enabled and dbms.track_query_cpu_time=true are true.

waiting

Milliseconds spent waiting on locks or other queries, as opposed to actively running this query. Included when dbms.logs.query.time_logging_enabled is true.

allocatedBytes

Number of bytes allocated by the query. Included when dbms.logs.query.allocation_logging_enabled is true.

pageHits

Number of page hits. Included when dbms.logs.query.page_logging_enabled is true.

pageFaults

Number of page faults. Included when dbms.logs.query.page_logging_enabled is true.

source

Connection details.

database

The database name on which the query is run.

username

The user running the query. This field is deprecated by executingUser.

executingUser

The name of the user executing the query. Either same as authenticatedUser or an impersonated user.

authenticatedUser

The name of the user who authenticated and is executing the query.

query

The query text.

queryParameters

The query parameters. Included when dbms.logs.query.parameter_logging_enabled is true.

runtime

The runtime used to run the query. Included when dbms.logs.query.runtime_logging_enabled is true.

annotationData

Metadata attached to the transaction.

failureReason

Reason for failure. Included when applicable.

transactionId

The transaction ID of the running query. Included when dbms.logs.query.transaction_id.enabled is true.

queryPlan

The query plan. Included when dbms.logs.query.plan_description_enabled is true.

If the type of the log entry is transaction, the following additional fields are available:

Table 17. JSON format log entries
Name Description

event

Valid options are start, rollback, and commit.

database

The database name on which the transaction is run.

username

The user connected to the transaction. This field is deprecated by executingUser.

executingUser

The name of the user connected to the transaction. Either same as authenticatedUser or an impersonated user.

authenticatedUser

The name of the user who authenticated and is connected to the transaction.

transactionId

ID of the transaction.