Logging
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.
Filename | Name | Description |
---|---|---|
neo4j.log |
The user log |
Logs general information about Neo4j.
For Debian and RPM packages run |
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 |
Configuration setting | Default value | Description |
---|---|---|
|
Path to the logs directory. |
|
|
Path to the user log file. |
|
|
Path to the debug log file. |
|
|
Path to the HTTP log file. |
|
|
Path to the query log file. |
|
|
Path to the security log file. |
Log format
Configuration setting | Default value | Description |
---|---|---|
|
The default log format for all logs.
Valid options are |
|
Inherits from |
The log format for the user log.
Valid options are |
|
Inherits from |
The log format for the query log.
Valid options are |
|
Inherits from |
The log format for the debug log.
Valid options are |
|
Inherits from |
The log format for the security log.
Valid options are |
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)
The user log configuration | Default value | Description |
---|---|---|
Inherits from |
The log format for the user log. |
|
|
The minimum time interval after the last rotation of the user log before it may be rotated again. |
|
|
The maximum number of history files for the user log. |
|
|
The threshold size for rotation of the user log.
If set to |
|
|
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:
Name | Description |
---|---|
|
The timestamp of the log message. |
|
The log level. |
|
The log message. |
|
Included when there is a stacktrace associated with the log message. |
Debug log
The debug log logs problems, errors, stacktraces, etc.
The debug log configuration | Default value | Description |
---|---|---|
|
Log level threshold for the debug log. |
|
Inherits from |
The log format for the debug log. |
|
|
The minimum time interval after the last rotation of the debug log before it may be rotated again. |
|
|
The maximum number of history files for the debug log. |
|
|
The threshold size for rotation of the debug log. |
The following table lists all message types raised by Neo4j and their severity level:
Message type | Severity level | Description |
---|---|---|
|
Low severity |
Report status information and errors that are not severe. |
|
Low severity |
Report details on the raised errors and possible solutions. |
|
Low severity |
Report errors that need attention but are not severe. |
|
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:
Name | Description |
---|---|
|
The timestamp of the log message. |
|
The log level. |
|
The class the message was logged from. |
|
The log message. |
|
Included when there is a stacktrace associated with the log message. |
Garbage collection log
The garbage collection log configuration | Default value | Description |
---|---|---|
|
Enable garbage collection logging. |
|
Garbage collection logging options. |
||
|
The maximum number of history files for the garbage collection log. |
|
The threshold size for rotation of the garbage collection log. |
HTTP log
The HTTP log configuration | Default value | Description |
---|---|---|
|
Enable HTTP logging. |
|
|
The maximum number of history files for the HTTP log. |
|
|
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:
The security log configuration | Default value | Description |
---|---|---|
|
Security log level threshold. |
|
Inherits from |
The log format for the security log. |
|
|
The name of the security log file. |
|
|
The file size at which the security event log auto-rotates. |
|
|
The minimum time interval after the last security log rotation occurred before the security log may be rotated again. |
|
|
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:
Name | Description |
---|---|
|
The timestamp of the log message. |
|
The log level. |
|
It is always |
|
Connection details. |
|
The database name the command is executed on. |
|
The user connected to the security event.
This field is deprecated by |
|
The name of the user triggering the security event.
Either same as |
|
The name of the user who authenticated and is connected to the security event. |
|
The log message. |
|
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 [johnsmith]: logged in
2019-12-09 13:47:53.443+0000 ERROR [johndoe]: failed to log in: invalid principal or credentials
2019-12-09 13:48:28.566+0000 INFO [johnsmith]: CREATE USER janedoe SET PASSWORD '********' CHANGE REQUIRED
2019-12-09 13:48:32.753+0000 INFO [johnsmith]: CREATE ROLE custom
2019-12-09 13:49:11.880+0000 INFO [johnsmith]: GRANT ROLE custom TO janedoe
2019-12-09 13:49:34.979+0000 INFO [johnsmith]: GRANT TRAVERSE ON GRAPH * NODES A, B (*) TO custom
2019-12-09 13:49:37.053+0000 INFO [johnsmith]: DROP USER janedoe
2019-12-09 13:52:24.685+0000 INFO [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:
Option | Description |
---|---|
|
Completely disable logging. |
|
Log at the end of queries that have either succeeded or failed.
The |
|
Log all queries at both start and finish, regardless of |
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:
The query log configuration | Default value | Description | ||||
---|---|---|---|---|---|---|
|
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 |
|||||
|
Log query text and parameters without obfuscating passwords. This allows queries to be logged earlier before parsing starts. |
|||||
|
Log executed queries. |
|||||
Inherits from |
The log format for the query log.
For logging detailed time information requires |
|||||
|
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 |
|||||
|
If
|
|||||
|
Log page hits and page faults for the executed queries being logged. |
|||||
|
Log complete parameter entities including ID, labels or relationship type, and properties.
If |
|||||
|
Log parameters for the executed queries being logged. You can disable this configuration setting if you do not want to display sensitive information. |
|||||
|
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.
|
|||||
|
The maximum number of history files for the query log. |
|||||
|
The file size in bytes at which the query log auto-rotates. |
|||||
|
Logs which runtime that was used to run the query. |
|||||
|
If the query execution takes longer than this threshold, the query is logged once completed (provided query logging is set to |
|||||
|
Log detailed time information for the executed queries being logged, such as |
|||||
|
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 ( |
|||||
|
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 |
|||||
|
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. |
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 ...
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 andtxMetaData
.
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:
|
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.
cypher-shell
, attach metadata to a transactionneo4j@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
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'}
CALL tx.setMetaData({app: 'neo4j-browser_v.4.4.0', type: 'user-direct', user: 'jsmith'})
MATCH (n:Person) RETURN n LIMIT 5
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'}
CALL tx.setMetaData({app: 'neo4j-browser_v.1.7.0', type: 'user-direct', user: 'jsmith'})
MATCH (n:Person) RETURN n LIMIT 5
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:
Name | Description |
---|---|
|
The timestamp of the log message. |
|
The log level. |
|
Valid options are |
|
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:
Name | Description |
---|---|
|
Valid options are |
|
The query ID.
Included when |
|
The elapsed time in milliseconds. |
|
Milliseconds spent on planning.
Included when |
|
Milliseconds spent actively executing on the CPU.
Included when |
|
Milliseconds spent waiting on locks or other queries, as opposed to actively running this query.
Included when |
|
Number of bytes allocated by the query.
Included when |
|
Number of page hits.
Included when |
|
Number of page faults.
Included when |
|
Connection details. |
|
The database name on which the query is run. |
|
The user running the query.
This field is deprecated by |
|
The name of the user executing the query.
Either same as |
|
The name of the user who authenticated and is executing the query. |
|
The query text. |
|
The query parameters.
Included when |
|
The runtime used to run the query.
Included when |
|
Metadata attached to the transaction. |
|
Reason for failure. Included when applicable. |
|
The transaction ID of the running query.
Included when |
|
The query plan.
Included when |
If the type of the log entry is transaction
, the following additional fields are available:
Name | Description |
---|---|
|
Valid options are |
|
The database name on which the transaction is run. |
|
The user connected to the transaction.
This field is deprecated by |
|
The name of the user connected to the transaction.
Either same as |
|
The name of the user who authenticated and is connected to the transaction. |
|
ID of the transaction. |