Skip to content

Logging overhaul #849

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 10 commits into from
Nov 9, 2022
Merged

Logging overhaul #849

merged 10 commits into from
Nov 9, 2022

Conversation

robsdedude
Copy link
Member

  • Add more logging to the pool when acquiring and releasing connections.
  • Improved log format:
    • All debug messages should not start with [#hhhh] x: where hhhh is the hex representation of the local port number of the connection or 0000 if there is none. x is one of C if it's the driver writing/opening/closing onto the socket, S if it's the driver reading/receiving an error from the socket and _ if it's not communication between the server and the driver.
    • Reduced logging noise in routing table.
  • API docs: explain how to manually log the async task id.
  • Logging helpers neo4j.debug:
    • Add config options to decide if thread id and/or task id should be logged.
    • Their docs make clear that the logging format is not following semver.
    • Changed logging format to accommodate the new config options.

 * Add more logging to the pool when acquiring and releasing connections.
 * Improved log format:
   * All debug messages should not start with `[#hhhh]  x:` where `hhhh` is the
     hex representation of the local port number of the connection or 0000 if
     there is none. `x` is one of `C` if it's the driver writing/opening/closing
     onto the socket, `S` if it's the driver reading/receiving an error from
     the socket and `_` if it's not communication between the server and the
     driver.
   * Reduced logging noise in routing table.
 * API docs: explain how to manually log the async task id.
 * Logging helpers `neo4j.debug`:
   * Add config options to decide if thread id and/or task id should be logged.
   * Their docs make clear that the logging format is not following semver.
   * Changed logging format to accommodate the new config options.
@robsdedude
Copy link
Member Author

Here is what some logging looked like before

[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,530  [#0000]  C: <NEO4J POOL> routing address IPv4Address(('localhost', 7687))
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,530  [#0000]  C: <ROUTING TABLE ENSURE FRESH> {None: RoutingTable(database=None routers={IPv4Address(('localhost', 7687))}, readers={}, writers={}, last_updated_time=3961.23487757, ttl=0)}
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,530  [#0000]  C: <ROUTING> Checking table freshness (readonly=False)
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,531  [#0000]  C: <ROUTING> Table expired=True
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,531  [#0000]  C: <ROUTING> Table routers={IPv4Address(('localhost', 7687))}
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,531  [#0000]  C: <ROUTING> Table has_server_for_mode=False
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,531  Attempting to update routing table from IPv4Address(('localhost', 7687))
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,531  [#0000]  C: <RESOLVE> localhost:7687
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,534  [#0000]  C: <OPEN> 127.0.0.1:7687
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,536  [#D73A]  C: <MAGIC> 0x6060B017
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,536  [#D73A]  C: <HANDSHAKE> 0x00000005 0x00020404 0x00000104 0x00000003
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,536  [#D73A]  S: <HANDSHAKE> 0x00000404
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,537  [#D73A]  C: HELLO {'user_agent': 'neo4j-python/5.2.dev0 Python/3.7.13-final-0 (linux)', 'routing': {'address': 'localhost:7687'}, 'patch_bolt': ['utc'], 'scheme': 'basic', 'principal': 'neo4j', 'credentials': '*******'}
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,539  [#D73A]  S: SUCCESS {'server': 'Neo4j/4.4.11', 'connection_id': 'bolt-4', 'hints': {}}
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,539  [#D73A]  State: CONNECTED > READY
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,539  [#D73A]  C: ROUTE {'address': 'localhost:7687'} () {'db': 'neo4j'}
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,549  [#D73A]  S: SUCCESS {'rt': {'servers': [{'addresses': ['localhost:7687'], 'role': 'WRITE'}, {'addresses': ['localhost:7687'], 'role': 'READ'}, {'addresses': ['localhost:7687'], 'role': 'ROUTE'}], 'ttl': 300, 'db': 'neo4j'}}
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,549  [#0000]  S: <ROUTING> table=RoutingTable(database='neo4j' routers={IPv4Address(('localhost', 7687))}, readers={IPv4Address(('localhost', 7687))}, writers={IPv4Address(('localhost', 7687))}, last_updated_time=3961.253965695, ttl=300)
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,549  [#0000]  C: <UPDATE ROUTING TABLE> address=ResolvedIPv4Address(('127.0.0.1', 7687)) (RoutingTable(database='neo4j' routers={IPv4Address(('localhost', 7687))}, readers={IPv4Address(('localhost', 7687))}, writers={IPv4Address(('localhost', 7687))}, last_updated_time=3961.253965695, ttl=300))
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,550  [#0000]  C: <ROUTING AGED> database=None
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,550  [#0000]  C: <ROUTING AGED> last_updated_time=3961.23487757 perf_time=3961.254272422
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,550  [#0000]  C: <ROUTING AGED> database=neo4j
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,550  [#0000]  C: <ROUTING AGED> last_updated_time=3961.253965695 perf_time=3961.25437554
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,550  [#0000]  C: <ACQUIRE ADDRESS> database='neo4j' address=IPv4Address(('localhost', 7687))
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,550  [#0000]  C: <RESOLVE> localhost:7687
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,550  [#0000]  C: <OPEN> 127.0.0.1:7687
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,551  [#D73C]  C: <MAGIC> 0x6060B017
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,551  [#D73C]  C: <HANDSHAKE> 0x00000005 0x00020404 0x00000104 0x00000003
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,552  [#D73C]  S: <HANDSHAKE> 0x00000404
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,552  [#D73C]  C: HELLO {'user_agent': 'neo4j-python/5.2.dev0 Python/3.7.13-final-0 (linux)', 'routing': {'address': 'localhost:7687'}, 'patch_bolt': ['utc'], 'scheme': 'basic', 'principal': 'neo4j', 'credentials': '*******'}
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,554  [#D73C]  S: SUCCESS {'server': 'Neo4j/4.4.11', 'connection_id': 'bolt-5', 'hints': {}}
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,554  [#D73C]  State: CONNECTED > READY
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,554  [#D73C]  C: RUN 'RETURN 1 AS n' {} {'db': 'neo4j'}
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,555  [#D73C]  C: PULL {'n': 1000}
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,559  [#D73C]  S: SUCCESS {'t_first': 2, 'fields': ['n']}
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,559  [#D73C]  State: READY > STREAMING
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,559  [#D73C]  S: RECORD * 1
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,559  [#D73C]  S: SUCCESS {'bookmark': 'FB:kcwQyZhOaL2BSyWaQWC1sqN3EQOQ', 'type': 'r', 't_last': 1, 'db': 'neo4j'}
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,559  [#D73C]  State: STREAMING > READY




[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,560  [#0000]  C: <ROUTING TABLE ENSURE FRESH> {None: RoutingTable(database=None routers={IPv4Address(('localhost', 7687))}, readers={}, writers={}, last_updated_time=3961.23487757, ttl=0), 'neo4j': RoutingTable(database='neo4j' routers={IPv4Address(('localhost', 7687))}, readers={IPv4Address(('localhost', 7687))}, writers={IPv4Address(('localhost', 7687))}, last_updated_time=3961.253965695, ttl=300)}
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,560  [#0000]  C: <ROUTING> Checking table freshness (readonly=False)
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,560  [#0000]  C: <ROUTING> Table expired=False
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,560  [#0000]  C: <ROUTING> Table routers={IPv4Address(('localhost', 7687))}
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,560  [#0000]  C: <ROUTING> Table has_server_for_mode=True
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,560  [#0000]  C: <ACQUIRE ADDRESS> database='neo4j' address=IPv4Address(('localhost', 7687))
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,560  [#D73C]  C: RUN 'RETURN 1 AS n' {} {'db': 'neo4j'}
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,560  [#D73C]  C: PULL {'n': 1000}
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,565  [#D73C]  S: SUCCESS {'t_first': 2, 'fields': ['n']}
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,566  [#D73C]  State: READY > STREAMING
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,566  [#D73C]  S: RECORD * 1
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,566  [#D73C]  S: SUCCESS {'bookmark': 'FB:kcwQyZhOaL2BSyWaQWC1sqN3EQOQ', 'type': 'r', 't_last': 1, 'db': 'neo4j'}
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,566  [#D73C]  State: STREAMING > READY
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,566  [#0000]  C: <POOL> close
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,566  [#D73A]  C: GOODBYE
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,566  [#D73A]  C: <CLOSE>
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,566  [#D73C]  C: GOODBYE
[DEBUG   ] MainThread(140035918219072) 2022-11-02 09:46:04,566  [#D73C]  C: <CLOSE>

This is what the same code logs now:

[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,919  [#0000]  _: <POOL> created, routing address IPv4Address(('localhost', 7687))
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,919  [#0000]  _: <POOL> acquire routing connection
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,919  [#0000]  _: <POOL> routing table ensure fresh {None: RoutingTable(database=None routers={IPv4Address(('localhost', 7687))}, readers={}, writers={}, last_updated_time=4282.623778156, ttl=0)}
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,919  [#0000]  _: <ROUTING> checking table freshness (readonly=False): table expired=True, has_server_for_mode=False, table routers={IPv4Address(('localhost', 7687))} => False
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,920  [#0000]  _: <POOL> attempting to update routing table from IPv4Address(('localhost', 7687))
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,920  [#0000]  _: <RESOLVE> in: localhost:7687
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,922  [#0000]  _: <RESOLVE> dns resolver out: 127.0.0.1:7687
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,923  [#0000]  _: <POOL> trying to hand out new connection
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,923  [#0000]  C: <OPEN> 127.0.0.1:7687
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,925  [#8C12]  C: <MAGIC> 0x6060B017
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,925  [#8C12]  C: <HANDSHAKE> 0x00000005 0x00020404 0x00000104 0x00000003
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,926  [#8C12]  S: <HANDSHAKE> 0x00000404
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,926  [#8C12]  C: HELLO {'user_agent': 'neo4j-python/5.2.dev0 Python/3.7.13-final-0 (linux)', 'routing': {'address': 'localhost:7687'}, 'patch_bolt': ['utc'], 'scheme': 'basic', 'principal': 'neo4j', 'credentials': '*******'}
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,928  [#8C12]  S: SUCCESS {'server': 'Neo4j/4.4.11', 'connection_id': 'bolt-12', 'hints': {}}
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,928  [#8C12]  _: <CONNECTION> state: CONNECTED > READY
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,928  [#8C12]  C: ROUTE {'address': 'localhost:7687'} () {'db': 'neo4j'}
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,936  [#8C12]  S: SUCCESS {'rt': {'servers': [{'addresses': ['localhost:7687'], 'role': 'WRITE'}, {'addresses': ['localhost:7687'], 'role': 'READ'}, {'addresses': ['localhost:7687'], 'role': 'ROUTE'}], 'ttl': 300, 'db': 'neo4j'}}
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,936  [#8C12]  _: <POOL> released bolt-12
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,936  [#0000]  _: <ROUTING> updated table=RoutingTable(database='neo4j' routers={IPv4Address(('localhost', 7687))}, readers={IPv4Address(('localhost', 7687))}, writers={IPv4Address(('localhost', 7687))}, last_updated_time=4282.640483177, ttl=300)
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,936  [#0000]  _: <POOL> update routing table from address=ResolvedIPv4Address(('127.0.0.1', 7687)) (RoutingTable(database='neo4j' routers={IPv4Address(('localhost', 7687))}, readers={IPv4Address(('localhost', 7687))}, writers={IPv4Address(('localhost', 7687))}, last_updated_time=4282.640483177, ttl=300))
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,936  [#0000]  _: <POOL> routing aged, database=None
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,936  [#0000]  _: <ROUTING> purge check: last_updated_time=4282.623778156, ttl=0, perf_time=4282.640782713 => False
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,936  [#0000]  _: <POOL> routing aged, database=neo4j
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,936  [#0000]  _: <ROUTING> purge check: last_updated_time=4282.640483177, ttl=300, perf_time=4282.640888854 => False
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,936  [#0000]  _: <POOL> acquire address, database='neo4j' address=IPv4Address(('localhost', 7687))
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,936  [#0000]  _: <POOL> trying to hand out new connection
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,936  [#0000]  _: <RESOLVE> in: localhost:7687
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,937  [#0000]  _: <RESOLVE> dns resolver out: 127.0.0.1:7687
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,937  [#0000]  C: <OPEN> 127.0.0.1:7687
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,937  [#8C16]  C: <MAGIC> 0x6060B017
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,937  [#8C16]  C: <HANDSHAKE> 0x00000005 0x00020404 0x00000104 0x00000003
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,938  [#8C16]  S: <HANDSHAKE> 0x00000404
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,938  [#8C16]  C: HELLO {'user_agent': 'neo4j-python/5.2.dev0 Python/3.7.13-final-0 (linux)', 'routing': {'address': 'localhost:7687'}, 'patch_bolt': ['utc'], 'scheme': 'basic', 'principal': 'neo4j', 'credentials': '*******'}
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,940  [#8C16]  S: SUCCESS {'server': 'Neo4j/4.4.11', 'connection_id': 'bolt-13', 'hints': {}}
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,940  [#8C16]  _: <CONNECTION> state: CONNECTED > READY
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,940  [#8C16]  C: RUN 'RETURN 1 AS n' {} {'db': 'neo4j'}
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,940  [#8C16]  C: PULL {'n': 1000}
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,943  [#8C16]  S: SUCCESS {'t_first': 1, 'fields': ['n']}
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,943  [#8C16]  _: <CONNECTION> state: READY > STREAMING
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,943  [#8C16]  S: RECORD * 1
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,943  [#8C16]  S: SUCCESS {'bookmark': 'FB:kcwQyZhOaL2BSyWaQWC1sqN3EQOQ', 'type': 'r', 't_last': 1, 'db': 'neo4j'}
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,944  [#8C16]  _: <CONNECTION> state: STREAMING > READY
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,944  [#8C16]  _: <POOL> released bolt-13




[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,944  [#0000]  _: <POOL> acquire routing connection
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,944  [#0000]  _: <POOL> routing table ensure fresh {None: RoutingTable(database=None routers={IPv4Address(('localhost', 7687))}, readers={}, writers={}, last_updated_time=4282.623778156, ttl=0), 'neo4j': RoutingTable(database='neo4j' routers={IPv4Address(('localhost', 7687))}, readers={IPv4Address(('localhost', 7687))}, writers={IPv4Address(('localhost', 7687))}, last_updated_time=4282.640483177, ttl=300)}
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,944  [#0000]  _: <ROUTING> checking table freshness (readonly=False): table expired=False, has_server_for_mode=True, table routers={IPv4Address(('localhost', 7687))} => True
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,944  [#0000]  _: <POOL> acquire address, database='neo4j' address=IPv4Address(('localhost', 7687))
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,944  [#8C16]  _: <POOL> handing out existing connection bolt-13
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,944  [#8C16]  C: RUN 'RETURN 1 AS n' {} {'db': 'neo4j'}
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,944  [#8C16]  C: PULL {'n': 1000}
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,947  [#8C16]  S: SUCCESS {'t_first': 1, 'fields': ['n']}
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,947  [#8C16]  _: <CONNECTION> state: READY > STREAMING
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,947  [#8C16]  S: RECORD * 1
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,947  [#8C16]  S: SUCCESS {'bookmark': 'FB:kcwQyZhOaL2BSyWaQWC1sqN3EQOQ', 'type': 'r', 't_last': 0, 'db': 'neo4j'}
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,947  [#8C16]  _: <CONNECTION> state: STREAMING > READY
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,947  [#8C16]  _: <POOL> released bolt-13
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,947  [#0000]  _: <POOL> close
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,947  [#8C12]  C: GOODBYE
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,947  [#8C12]  C: <CLOSE>
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,948  [#8C16]  C: GOODBYE
[DEBUG   ] [Thread 139968297072448] [Task 139968235592640] 2022-11-02 09:51:25,948  [#8C16]  C: <CLOSE>

Copy link
Contributor

@bigmontz bigmontz left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

📝

(as future work, it might be nice newer logs came with test ensuring the logger calls. this is not need for now.)

@robsdedude robsdedude merged commit 0649f71 into neo4j:5.0 Nov 9, 2022
@robsdedude robsdedude deleted the logging-overhaul branch November 9, 2022 12:06
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants