[Bug] ValueError: operation on destroyed loop on shutdown

[daverigby]

Is this a new bug?

• I believe this is a new bug
• I have searched the existing issues, and I could not find an existing issue for this bug

Current Behavior

When running vsb workload mnist-test against pinecone on macOS using python3.12, an exception was thrown at the end of the run (after summary stats were printed).

Expected Behavior

A clean shutdown occurs

Steps To Reproduce

1. On macOS (@brickj could you confirm version?) with python3.12 from homebrew:
2. vsb --database=pinecone --workload=mnist-test --pinecone_api_key=<API_KEY>

Relevant log output

2024-07-10T12:19:51 INFO     Saved stats to 'reports/pinecone/2024-07-10T12:19:23/stats.json'
Traceback (most recent call last):
  File "/opt/homebrew/Cellar/[email protected]/3.12.4/Frameworks/Python.framework/Versions/3.12/lib/python3.12/weakref.py", line 666, in _exitfunc
    f()
  File "/opt/homebrew/Cellar/[email protected]/3.12.4/Frameworks/Python.framework/Versions/3.12/lib/python3.12/weakref.py", line 590, in __call__
    return info.func(*info.args, **(info.kwargs or {}))
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/rick/IdeaProjects/VSB/venv/lib/python3.12/site-packages/urllib3/connectionpool.py", line 1180, in _close_pool_connections
    conn.close()
  File "/Users/rick/IdeaProjects/VSB/venv/lib/python3.12/site-packages/urllib3/connection.py", line 275, in close
    super().close()
  File "/opt/homebrew/Cellar/[email protected]/3.12.4/Frameworks/Python.framework/Versions/3.12/lib/python3.12/http/client.py", line 1020, in close
    sock.close()   # close it manually... there may be other refs
    ^^^^^^^^^^^^
  File "/Users/rick/IdeaProjects/VSB/venv/lib/python3.12/site-packages/gevent/_socket3.py", line 331, in close
    self._real_close()
  File "/Users/rick/IdeaProjects/VSB/venv/lib/python3.12/site-packages/gevent/ssl.py", line 717, in _real_close
    socket._real_close(self)
  File "/Users/rick/IdeaProjects/VSB/venv/lib/python3.12/site-packages/gevent/_socket3.py", line 324, in _real_close
    self._detach_socket('closed')
  File "/Users/rick/IdeaProjects/VSB/venv/lib/python3.12/site-packages/gevent/_socket3.py", line 315, in _detach_socket
    self._drop_events_and_close(closefd=(reason == 'closed'))
  File "/Users/rick/IdeaProjects/VSB/venv/lib/python3.12/site-packages/gevent/_socketcommon.py", line 466, in _drop_events_and_close
    hub.cancel_waits_close_and_then(
  File "src/gevent/_hub_primitives.py", line 75, in gevent._gevent_c_hub_primitives.WaitOperationsGreenlet.cancel_waits_close_and_then
  File "src/gevent/libev/corecext.pyx", line 1059, in gevent.libev.corecext.watcher.close
  File "src/gevent/libev/corecext.pyx", line 1015, in gevent.libev.corecext.watcher.stop
  File "src/gevent/libev/corecext.pyx", line 280, in gevent.libev.corecext._check_loop
ValueError: operation on destroyed loop

### Environment

_No response_

### Additional Context

_No response_

[jonathanzxu]

Can't reproduce, but error seems to have something to do with running queries in a gevent child process (e.g. Locust User) (see https://groups.google.com/a/lists.datastax.com/g/python-driver-user/c/XVicwbCxtiM). How frequently does this happen? @brickj

[daverigby]

I just got a reproduction of this.

• Environment: macOS 14.6, Python 3.12
• Command:

vsb --database=pinecone --workload=mnist-test --pinecone_api_key=XXXX

• Ouput:

2024-08-06T11:36:09 INFO     Vector Search Bench: Starting experiment with backend='pinecone', workload='mnist-test', users=1, requests_per_sec=unlimited                                                                                              
2024-08-06T11:36:09 INFO     Writing benchmark results to 'reports/pinecone/2024-08-06T11:36:09'                                                                                                                                                       
2024-08-06T11:36:09 INFO     Starting Setup phase                                                                                                                                                                                                      
/Users/dave/repos/pinecone-io/VSB/.venv/lib/python3.12/site-packages/google_crc32c/__init__.py:29: RuntimeWarning: As the c extension couldn't be imported, `google-crc32c` is using a pure python implementation that is significantly slower. If 
possible, please configure a c build environment and compile the extension
  warnings.warn(_SLOW_CRC32C_WARNING, RuntimeWarning)
2024-08-06T11:36:23 INFO     Workload 'mnist-test' initialized record_count=600 dimensions=784 metric=DistanceMetric.Euclidean                                                                                                                         
2024-08-06T11:36:23 INFO     PineconeDB: Specified index 'vsb-mnist-test' was not found, or the specified API key cannot access it. Creating new index 'vsb-mnist-test'.                                                                               
✔ Setup complete                               1/1 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100% 0:00:20 00:00  
  ✔ Dataset download complete                  3/3 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100% 0:00:03 00:00  
2024-08-06T11:36:29 INFO     Completed Setup phase, took 20.50s                                                                                                                                                                                        
2024-08-06T11:36:31 INFO     Starting Populate phase                                                                                                                                                                                                   
✔ Populate complete                        600/600 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100% 0:00:04 00:00  
  Records/sec: 147.5
2024-08-06T11:36:35 INFO     Completed Populate phase, took 4.09s                                                                                               
2024-08-06T11:36:37 INFO     Starting Finalize phase                                                                                                            
✔ Finalize complete                            1/? ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━  0:00:00   
  ✔ Finalize population                    600/600 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100% 0:00:00 00:00  
2024-08-06T11:36:37 INFO     Completed Finalize phase, took 0.15s                                                                                               
2024-08-06T11:36:39 INFO     Starting Run phase                                                                                                                 
✔ Run complete                               20/20 ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100% 0:00:02 00:00  
  Current metrics (last 10s): 0.0 op/s | latency: p50=100ms, p95=110.0ms | recall: p50=1.00, p5=1.00
2024-08-06T11:36:41 INFO     Completed Run phase, took 2.14s                                                                                                    

                      Operation Summary                      
                                                             
  Operation  Requests  Failures  Requests/sec  Failures/sec  
 ─────────────────────────────────────────────────────────── 
  Populate          2     0(0%)             0           0.0  
  Search           20     0(0%)             1           0.0  
                                                             
                                                    Metrics Summary                                                     
                                                                                                                        
  Operation  Metric         Min  0.1%    1%    5%   10%   25%   50%   75%   90%   95%   99%  99.9%  99.99%   Max  Mean  
 ────────────────────────────────────────────────────────────────────────────────────────────────────────────────────── 
  Populate   Latency (ms)   311   310   310   310   310   310  3100  3100  3100  3100  3100   3100    3100  3083  1697  
                                                                                                                        
  Search     Latency (ms)    99    99    99   100   100   100   100   100   130   140   140    140     140   142   105  
  Search     Recall        1.00  1.00  1.00  1.00  1.00  1.00  1.00  1.00  1.00  1.00  1.00   1.00    1.00  1.00  1.00  
                                                                                                                        
2024-08-06T11:36:42 INFO     Saved stats to 'reports/pinecone/2024-08-06T11:36:09/stats.json'                                                                   
Traceback (most recent call last):
  File "/opt/homebrew/Cellar/[email protected]/3.12.4/Frameworks/Python.framework/Versions/3.12/lib/python3.12/weakref.py", line 666, in _exitfunc
    f()
  File "/opt/homebrew/Cellar/[email protected]/3.12.4/Frameworks/Python.framework/Versions/3.12/lib/python3.12/weakref.py", line 590, in __call__
    return info.func(*info.args, **(info.kwargs or {}))
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/dave/repos/pinecone-io/VSB/.venv/lib/python3.12/site-packages/urllib3/connectionpool.py", line 1180, in _close_pool_connections
    conn.close()
  File "/Users/dave/repos/pinecone-io/VSB/.venv/lib/python3.12/site-packages/urllib3/connection.py", line 275, in close
    super().close()
  File "/opt/homebrew/Cellar/[email protected]/3.12.4/Frameworks/Python.framework/Versions/3.12/lib/python3.12/http/client.py", line 1020, in close
    sock.close()   # close it manually... there may be other refs
    ^^^^^^^^^^^^
  File "/Users/dave/repos/pinecone-io/VSB/.venv/lib/python3.12/site-packages/gevent/_socket3.py", line 331, in close
    self._real_close()
  File "/Users/dave/repos/pinecone-io/VSB/.venv/lib/python3.12/site-packages/gevent/ssl.py", line 717, in _real_close
    socket._real_close(self)
  File "/Users/dave/repos/pinecone-io/VSB/.venv/lib/python3.12/site-packages/gevent/_socket3.py", line 324, in _real_close
    self._detach_socket('closed')
  File "/Users/dave/repos/pinecone-io/VSB/.venv/lib/python3.12/site-packages/gevent/_socket3.py", line 315, in _detach_socket
    self._drop_events_and_close(closefd=(reason == 'closed'))
  File "/Users/dave/repos/pinecone-io/VSB/.venv/lib/python3.12/site-packages/gevent/_socketcommon.py", line 466, in _drop_events_and_close
    hub.cancel_waits_close_and_then(
  File "src/gevent/_hub_primitives.py", line 75, in gevent._gevent_c_hub_primitives.WaitOperationsGreenlet.cancel_waits_close_and_then
  File "src/gevent/libev/corecext.pyx", line 1059, in gevent.libev.corecext.watcher.close
  File "src/gevent/libev/corecext.pyx", line 1015, in gevent.libev.corecext.watcher.stop
  File "src/gevent/libev/corecext.pyx", line 280, in gevent.libev.corecext._check_loop
ValueError: operation on destroyed loop

However, running the exact same command again didn't fail, so this is an intermittent issue.