Skip to content
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.

Sign up for GitHub

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

Jump to bottom

Potential deadlock in order_place #8

Open
chipkent opened this issue Jan 25, 2022 · 4 comments
Open

Potential deadlock in order_place #8

chipkent opened this issue Jan 25, 2022 · 4 comments
Assignees
@chipkent

Comments

@chipkent
Copy link
Collaborator

I've seen frequent cases where the code seems to deadlock in the req_id = self._client.next_order_id() line below. Deadlock monitoring has been added to try to find the problem.

    def order_place(self, contract: RegisteredContract, order: Order) -> Request:
        """Places an order.

        Args:
            contract (RegisteredContract): contract to place an order on
            order (Order): order to place
        """
        self._assert_connected()

        if contract.is_multi():
            raise Exception(
                f"RegisteredContracts with multiple contract details are not supported for orders: {contract}")

        req_id = self._client.next_order_id()
        cd = contract.contract_details[0]
        self._client.log_request(req_id, "PlaceOrder", cd.contract, {"order": f"Order({order})"})
        self._client.placeOrder(req_id, cd.contract, order)
        return Request(request_id=req_id, cancel_func=self.order_cancel)
@chipkent chipkent self-assigned this Jan 25, 2022
@chipkent
Copy link
Collaborator Author

chipkent commented Mar 1, 2022 •
edited
Loading

The deadlock detector returned this. It seems like TWS is not responding on some ID requests.

r-Scheduler-Serial-1 | i.d.s.s.SessionState      | Internal Error 'cc58a3f9-12ab-45b1-b71b-c53912c3facc' java.lang.RuntimeException: Error in Python interpreter:
Type: <class 'Exception'>
Value: OrderIdRequest.get() timed out after 120.0 sec.
Line: 37
Namespace: get
File: /opt/deephaven-venv/lib/python3.7/site-packages/deephaven_ib/_tws/order_id_queue.py
Traceback (most recent call last):
  File "<string>", line 426, in <module>
  File "/opt/deephaven-venv/lib/python3.7/site-packages/deephaven_ib/__init__.py", line 1080, in order_place
  File "/opt/deephaven-venv/lib/python3.7/site-packages/deephaven_ib/_tws/tws_client.py", line 907, in next_order_id
  File "/opt/deephaven-venv/lib/python3.7/site-packages/deephaven_ib/_tws/requests.py", line 27, in next_order_id
  File "/opt/deephaven-venv/lib/python3.7/site-packages/deephaven_ib/_tws/order_id_queue.py", line 37, in get

        at org.jpy.PyLib.executeCode(PyLib.java:-2)
        at org.jpy.PyObject.executeCode(PyObject.java:138)
        at io.deephaven.engine.util.PythonEvaluatorJpy.evalScript(PythonEvaluatorJpy.java:56)
        at io.deephaven.engine.util.PythonDeephavenSession.lambda$evaluate$1(PythonDeephavenSession.java:190)
        at io.deephaven.util.locks.FunctionalLock.doLockedInterruptibly(FunctionalLock.java:46)
        at io.deephaven.engine.util.PythonDeephavenSession.evaluate(PythonDeephavenSession.java:189)
        at io.deephaven.engine.util.AbstractScriptSession.evaluateScript(AbstractScriptSession.java:147)
        at io.deephaven.engine.util.DelegatingScriptSession.evaluateScript(DelegatingScriptSession.java:71)
        at io.deephaven.engine.util.ScriptSession.evaluateScript(ScriptSession.java:85)
        at io.deephaven.server.console.ConsoleServiceGrpcImpl.lambda$executeCommand$8(ConsoleServiceGrpcImpl.java:219)
        at io.deephaven.server.session.SessionState$ExportBuilder.lambda$submit$2(SessionState.java:1299)
        at io.deephaven.server.session.SessionState$ExportObject.doExport(SessionState.java:847)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
        at java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at io.deephaven.server.runner.DeephavenApiServerModule$ThreadFactory.lambda$newThread$0(DeephavenApiServerModule.java:143)
        at java.lang.Thread.run(Thread.java:829)

This is triggered by the following code in tws_client.py.

    def next_order_id(self) -> int:
        """Gets the next valid order ID."""
        return self.request_id_manager.next_order_id(self.order_id_queue)

@chipkent chipkent mentioned this issue Mar 2, 2022
Merged
@chipkent
Copy link
Collaborator Author

chipkent commented Mar 2, 2022

#31 allows different methods to get the next order id. This is a potential work around for the problem.

@chipkent chipkent mentioned this issue May 11, 2022
Open
@chipkent
Copy link
Collaborator Author

Saw this again:

r-Scheduler-Serial-1 | i.d.s.s.SessionState      | Internal Error '9aaf405f-8e59-424a-8f8f-2c5e4ed13d43' java.lang.RuntimeException: Error in Python interpreter:
Type: <class 'Exception'>
Value: OrderIdRequest.get() timed out after 60.0 sec.  A possible deadlock or TWS bug was detected!  You may be able to avoid this problem by using a different OrderIdStrategy.  Please create an issue at https://github.com/deephaven-examples/deephaven-ib/issues containing this error message
Stack Traces:
<_MainThread(MainThread, started 140166847809280)>Thread stack not found: thread=140166847809280
<Thread(DeadlockMonitor, started daemon 140163184277248)>  File "/usr/lib/python3.7/threading.py", line 885, in _bootstrap
    self._bootstrap_inner()
  File "/usr/lib/python3.7/threading.py", line 917, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.7/threading.py", line 865, in run
    self._target(*self._args, **self._kwargs)
  File "/opt/deephaven-venv/lib/python3.7/site-packages/deephaven_ib/_internal/threading.py", line 34, in _run
    time.sleep(self.sleep_sec)

<Thread(OrderIdEventQueueRetry, started daemon 140161534646016)>  File "/usr/lib/python3.7/threading.py", line 885, in _bootstrap
    self._bootstrap_inner()
  File "/usr/lib/python3.7/threading.py", line 917, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.7/threading.py", line 865, in run
    self._target(*self._args, **self._kwargs)
  File "/opt/deephaven-venv/lib/python3.7/site-packages/deephaven_ib/_tws/order_id_queue.py", line 95, in _retry
    sleep(0.01)

<_DummyThread(Dummy-2, started daemon 140163190327040)>  File "<string>", line 428, in <module>
  File "/opt/deephaven-venv/lib/python3.7/site-packages/deephaven_ib/__init__.py", line 1101, in order_place
    req_id = self._client.next_order_id()
  File "/opt/deephaven-venv/lib/python3.7/site-packages/deephaven_ib/_tws/tws_client.py", line 939, in next_order_id
    return self.request_id_manager.next_order_id(self.order_id_queue)
  File "/opt/deephaven-venv/lib/python3.7/site-packages/deephaven_ib/_tws/requests.py", line 27, in next_order_id
    oid = request.get()
  File "/opt/deephaven-venv/lib/python3.7/site-packages/deephaven_ib/_tws/order_id_queue.py", line 55, in get
    trace = trace_all_threads_str()
  File "/opt/deephaven-venv/lib/python3.7/site-packages/deephaven_ib/_internal/trace.py", line 27, in trace_all_threads_str
    rst += trace_thread_str(th)
  File "/opt/deephaven-venv/lib/python3.7/site-packages/deephaven_ib/_internal/trace.py", line 15, in trace_thread_str
    return "".join(traceback.format_stack(sys._current_frames()[thread.ident]))

<Thread(OrderIdEventQueueRetry, started daemon 140161526253312)>  File "/usr/lib/python3.7/threading.py", line 885, in _bootstrap
    self._bootstrap_inner()
  File "/usr/lib/python3.7/threading.py", line 917, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.7/threading.py", line 865, in run
    self._target(*self._args, **self._kwargs)
  File "/opt/deephaven-venv/lib/python3.7/site-packages/deephaven_ib/_tws/order_id_queue.py", line 95, in _retry
    sleep(0.01)

<EReader(Thread-3, started daemon 140161517074176)>  File "/usr/lib/python3.7/threading.py", line 885, in _bootstrap
    self._bootstrap_inner()
  File "/usr/lib/python3.7/threading.py", line 917, in _bootstrap_inner
    self.run()
  File "/opt/deephaven-venv/lib/python3.7/site-packages/ibapi/reader.py", line 35, in run
    data = self.conn.recvMsg()
  File "/opt/deephaven-venv/lib/python3.7/site-packages/ibapi/connection.py", line 93, in recvMsg
    buf = self._recvAllMsg()
  File "/opt/deephaven-venv/lib/python3.7/site-packages/ibapi/connection.py", line 114, in _recvAllMsg
    buf = self.socket.recv(4096)

<Thread(IbTwsClient, started daemon 140161508681472)>  File "/usr/lib/python3.7/threading.py", line 885, in _bootstrap
    self._bootstrap_inner()
  File "/usr/lib/python3.7/threading.py", line 917, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.7/threading.py", line 865, in run
    self._target(*self._args, **self._kwargs)
  File "/opt/deephaven-venv/lib/python3.7/site-packages/ibapi/client.py", line 263, in run
    self.decoder.interpret(fields)
  File "/opt/deephaven-venv/lib/python3.7/site-packages/ibapi/decoder.py", line 1296, in interpret
    handleInfo.processMeth(self, iter(fields))
  File "/opt/deephaven-venv/lib/python3.7/site-packages/ibapi/decoder.py", line 795, in processSymbolSamplesMsg
    self.wrapper.symbolSamples(reqId, contractDescriptions)
  File "/opt/deephaven-venv/lib/python3.7/site-packages/deephaven_ib/_tws/tws_client.py", line 470, in symbolSamples
    self.contract_registry.request_contract_details_nonblocking(cd.contract)
  File "/opt/deephaven-venv/lib/python3.7/site-packages/deephaven_ib/_tws/contract_registry.py", line 142, in request_contract_details_nonblocking
    self._request_contract_details(contract=contract)
  File "/opt/deephaven-venv/lib/python3.7/site-packages/deephaven_ib/_tws/contract_registry.py", line 201, in _request_contract_details
    req_id = self._client.request_id_manager.next_id()
  File "/opt/deephaven-venv/lib/python3.7/site-packages/deephaven_ib/_tws/requests.py", line 19, in next_id
    with self._lock:
  File "/opt/deephaven-venv/lib/python3.7/site-packages/deephaven_ib/_internal/threading.py", line 131, in __enter__
    self.acquire()
  File "/opt/deephaven-venv/lib/python3.7/site-packages/deephaven_ib/_internal/threading.py", line 113, in acquire
    ret = self.lock.acquire(blocking)



Line: 57
Namespace: get
File: /opt/deephaven-venv/lib/python3.7/site-packages/deephaven_ib/_tws/order_id_queue.py
Traceback (most recent call last):
  File "<string>", line 428, in <module>
  File "/opt/deephaven-venv/lib/python3.7/site-packages/deephaven_ib/__init__.py", line 1101, in order_place
  File "/opt/deephaven-venv/lib/python3.7/site-packages/deephaven_ib/_tws/tws_client.py", line 939, in next_order_id
  File "/opt/deephaven-venv/lib/python3.7/site-packages/deephaven_ib/_tws/requests.py", line 27, in next_order_id
  File "/opt/deephaven-venv/lib/python3.7/site-packages/deephaven_ib/_tws/order_id_queue.py", line 57, in get

        at org.jpy.PyLib.executeCode(PyLib.java:-2)
        at org.jpy.PyObject.executeCode(PyObject.java:138)
        at io.deephaven.engine.util.PythonEvaluatorJpy.evalScript(PythonEvaluatorJpy.java:56)
        at io.deephaven.engine.util.PythonDeephavenSession.lambda$evaluate$1(PythonDeephavenSession.java:188)
        at io.deephaven.util.locks.FunctionalLock.doLockedInterruptibly(FunctionalLock.java:46)
        at io.deephaven.engine.util.PythonDeephavenSession.evaluate(PythonDeephavenSession.java:187)
        at io.deephaven.engine.util.AbstractScriptSession.evaluateScript(AbstractScriptSession.java:145)
        at io.deephaven.engine.util.DelegatingScriptSession.evaluateScript(DelegatingScriptSession.java:71)
        at io.deephaven.engine.util.ScriptSession.evaluateScript(ScriptSession.java:84)
        at io.deephaven.server.console.ConsoleServiceGrpcImpl.lambda$executeCommand$8(ConsoleServiceGrpcImpl.java:187)
        at io.deephaven.server.session.SessionState$ExportBuilder.lambda$submit$2(SessionState.java:1299)
        at io.deephaven.server.session.SessionState$ExportObject.doExport(SessionState.java:847)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
        at java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at io.deephaven.server.runner.DeephavenApiServerModule$ThreadFactory.lambda$newThread$0(DeephavenApiServerModule.java:157)
        at java.lang.Thread.run(Thread.java:829)

@chipkent
Copy link
Collaborator Author

I will note that this deadlock seems to happen when deephaven-ib is used at the start of the day. If deephaven-ib is bounced and then reconnects, the problem does not seem to recur during the day.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@chipkent chipkent

Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@chipkent