getsockname fails: 'NoneType' object is not subscriptable

[robsdedude]

Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/nodestream/pipeline/pipeline.py", line 196, in try_work_body
    await self.work_body()
  File "/usr/local/lib/python3.11/site-packages/nodestream/pipeline/pipeline.py", line 171, in work_body
    async for index, record in enumerate_async(results):
  File "/usr/local/lib/python3.11/site-packages/nodestream/pipeline/pipeline.py", line 20, in enumerate_async
    async for item in iterable:
  File "/usr/local/lib/python3.11/site-packages/nodestream/pipeline/writers.py", line 22, in handle_async_record_stream
    await self.flush()
  File "/usr/local/lib/python3.11/site-packages/nodestream/databases/writer.py", line 54, in flush
    await self.ingest_strategy.flush()
  File "/usr/local/lib/python3.11/site-packages/nodestream/databases/debounced_ingest_strategy.py", line 69, in flush
    await self.flush_relationship_updates()
  File "/usr/local/lib/python3.11/site-packages/nodestream/databases/query_executor_with_statistics.py", line 34, in upsert_relationships_in_bulk_of_same_operation
    await self.inner.upsert_relationships_in_bulk_of_same_operation(
  File "/usr/local/lib/python3.11/site-packages/nodestream_plugin_neo4j/query_executor.py", line 68, in upsert_relationships_in_bulk_of_same_operation
    await self.database_connection.execute(
  File "/usr/local/lib/python3.11/site-packages/nodestream_plugin_neo4j/neo4j_database.py", line 40, in execute
    result = await self.driver.execute_query(
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/neo4j/_async/driver.py", line 921, in execute_query
    return await session._run_transaction(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/neo4j/_async/work/session.py", line 543, in _run_transaction
    await self._open_transaction(
  File "/usr/local/lib/python3.11/site-packages/neo4j/_async/work/session.py", line 423, in _open_transaction
    await self._connect(access_mode=access_mode)
  File "/usr/local/lib/python3.11/site-packages/neo4j/_async/work/session.py", line 130, in _connect
    await super()._connect(
  File "/usr/local/lib/python3.11/site-packages/neo4j/_async/work/workspace.py", line 178, in _connect
    self._connection = await self._pool.acquire(**acquire_kwargs_)
                       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/neo4j/_async/io/_pool.py", line 913, in acquire
    await self.ensure_routing_table_is_fresh(
  File "/usr/local/lib/python3.11/site-packages/neo4j/_async/io/_pool.py", line 855, in ensure_routing_table_is_fresh
    await self.update_routing_table(
  File "/usr/local/lib/python3.11/site-packages/neo4j/_async/io/_pool.py", line 777, in update_routing_table
    if await self._update_routing_table_from(
       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/neo4j/_async/io/_pool.py", line 723, in _update_routing_table_from
    new_routing_table = await self.fetch_routing_table(
                        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/neo4j/_async/io/_pool.py", line 660, in fetch_routing_table
    new_routing_info = await self.fetch_routing_info(
                       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/neo4j/_async/io/_pool.py", line 628, in fetch_routing_info
    cx = await self._acquire(address, auth, deadline, None)
         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/neo4j/_async/io/_pool.py", line 316, in _acquire
    return await connection_creator()
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/neo4j/_async/io/_pool.py", line 166, in connection_creator
    connection = await self.opener(
                 ^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/neo4j/_async/io/_pool.py", line 560, in opener
    return await AsyncBolt.open(
           ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/neo4j/_async/io/_bolt.py", line 475, in open
    connection = bolt_cls(
                 ^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/neo4j/_async/io/_bolt5.py", line 472, in __init__
    super().__init__(*args, **kwargs)
  File "/usr/local/lib/python3.11/site-packages/neo4j/_async/io/_bolt5.py", line 79, in __init__
    super().__init__(*args, **kwargs)
  File "/usr/local/lib/python3.11/site-packages/neo4j/_async/io/_bolt.py", line 141, in __init__
    self.local_port = self.socket.getsockname()[1]
                      ~~~~~~~~~~~~~~~~~~~~~~~~~^^^
TypeError: 'NoneType' object is not subscriptable

Originally posted by @ccloes in #730 (comment)

[robsdedude]

Hi @ccloes and thanks for sharing the stack trace.

This is a very unexpected code-path, I must admit. Right after the async socket has been opened, writer.transport.get_extra_info("sockname") is being called. According to the docs and looking at the source code of asyncio, get_extra_info("sockname") will be None if there was an error receiving this information. The different transport implementations try to get the sockname pretty much right after the socket connection has been established. So there really should be that information about the connection.

I was not able to reproduce this condition locally, so can you please provide me with additional information that should help me pin-point how this came to be:

• Please enable debug logging for all loggers and share the logs with me. You could, for instance use the driver's helper for that

  from neo4j.debug import watch
  
  watch("")

  Some of the async TCP transport implementations log errors when trying to compute the sockname for caching it in extra. Further, I'll be able to see what the failing connection was up to before the error occurred.
• Please install this custom version of the driver pip install -U git+https://github.com/robsdedude/neo4j-python-driver@async-sockname. It will hopefully turn this TypeError: 'NoneType' object is not subscriptable into the underlying OSError that caused the caching of sockname to fail and therefore it to be None.

[robsdedude]

One last attempt as I'd really like to dig into this issue but can't reproduce it on my own.

@ccloes please help me (see comment above).

[ccloes]

@MarkPAndrews can you help us get this reviewed?

[ccloes]

@robsdedude sorry for the delay... we are asking for Mark with Neo4j to help get this worked.

[ccloes]

We discussed with this the Neo4j team, and we are going to try and push this to later when we revisit hardening the connector code in Nodestream and doing some of the performance testing work that is planned.

The issue manifested itself under high load, and when leader elections were happening on the database side.

We can close this ticket for now until we are better able to reproduce the issue.

[robsdedude]

Thank you for coming back on this. As you suggested, I'll close this issue for now.

For future you or anyone else coming across this issue: feel free to reopen this issue while providing the additional information requested in my earlier comment. The linked custom driver version might not exist anymore though.