Failed Test PR #330 - Stuck on canceling a non-existing order

rxlxrxsx commented 1 year ago

Summary and Screenshots

The bot gets stuck trying to cancel a non-existing order that can be seen on the status output. In the logs the bot attempted to create 1 buy and 1 sell order but only the buy order was created successfully. As seen on the screenshot below the sell order was also seen open on the status output. After the order refresh time is met the bot now attempts to cancel this order but fails since it wasn't successfully created in the first place. Checking on the web app the sell order is not seen.

## Bot attempts to create 1 buy and 1 sell order

2023-04-06 09:50:58,060 - 4293 - hummingbot.strategy.perpetual_market_making.perpetual_market_making - INFO - (INJ-USDT) Creating 1 LIMIT bid orders at (Size, Price): ['1 INJ, 5.49 USDT'] to OPEN position.
2023-04-06 09:50:58,061 - 4293 - hummingbot.strategy.perpetual_market_making.perpetual_market_making - INFO - (INJ-USDT) Creating 1  LIMIT ask orders at (Size, Price): ['1 INJ, 5.6 USDT'] to OPEN position.
2023-04-06 09:50:58,062 - 4293 - root - INFO - Loaded market metadata for:'Mainnet Derivative INJ/USDT PERP'
2023-04-06 09:50:58,063 - 4293 - root - INFO - Loaded market metadata for:'Mainnet Derivative INJ/USDT PERP'
2023-04-06 09:50:58,421 - 4293 - hummingbot.connector.gateway.clob_perp.data_sources.injective_perpetual.injective_perpetual_api_data_source.InjectivePerpetualAPIDataSource - DEBUG - Placed order 0xe157daa2a5ac9dc86e5ae1525f1cab585c73c9987bc3bf9725bab1b12569af9f with nonce 9299 and tx hash 0E20C9F77694EBEB661839C5B54B489F341719942E6D6BE95236BA5AE2C7333A.
2023-04-06 09:50:58,804 - 4293 - hummingbot.connector.gateway.clob_perp.data_sources.injective_perpetual.injective_perpetual_api_data_source.InjectivePerpetualAPIDataSource - DEBUG - Placed order 0x72055715d53b2949813e3f7ccb98ae18c848d07623eddab2e7c985ad4771877e with nonce 9300 and tx hash .

## Only the buy order was created

2023-04-06 09:51:00,440 - 4293 - hummingbot.connector.client_order_tracker - INFO - Created LIMIT BUY order BIJUT5f8acdfe6cb03500df53e4e77a7cf55cdce608701a15c for 1.000 to OPEN a INJ-USDT position.
2023-04-06 09:51:00,441 - 4293 - hummingbot.core.event.event_reporter - EVENT_LOG - {"timestamp": 1680796260.0, "type": "OrderType.LIMIT", "trading_pair": "INJ-USDT", "amount": "1.000", "price": "5.490000", "order_id": "BIJUT5f8acdfe6cb03500df53e4e77a7cf55cdce608701a15c", "creation_timestamp": 1680796258.0, "exchange_order_id": "0xe157daa2a5ac9dc86e5ae1525f1cab585c73c9987bc3bf9725bab1b12569af9f", "leverage": 1, "position": "OPEN", "event_name": "BuyOrderCreatedEvent", "event_source": "injective_perpetual_injective_mainnet"}

Errors received after attempts to cancel the non-existing order:

2023-04-06 09:54:01,019 - 4293 - hummingbot.connector.gateway.clob_perp.gateway_clob_perp.GatewayCLOBPerp - WARNING - Error fetching status update for the order SIJUT5f8acdfe6cd2b500df53e4e77a7cf55cdce608701a15c: <AioRpcError of RPC that terminated with:
    status = StatusCode.INVALID_ARGUMENT
    details = "invalid hash"
    debug_error_string = "UNKNOWN:Error received from peer ipv4:34.138.231.254:443 {created_time:"2023-04-06T09:54:00.95888-06:00", grpc_status:3, grpc_message:"invalid hash"}"
>.

2023-04-06 09:54:02,504 - 4293 - hummingbot.core.utils.async_utils - ERROR - Unhandled error in background task: <AioRpcError of RPC that terminated with:
    status = StatusCode.INVALID_ARGUMENT
    details = "invalid hash"
    debug_error_string = "UNKNOWN:Error received from peer ipv4:34.138.231.254:443 {created_time:"2023-04-06T09:54:02.470405-06:00", grpc_status:3, grpc_message:"invalid hash"}"
>
Traceback (most recent call last):
  File "/Users/reiniersalazar/hbot-ca-injperp/hummingbot/core/utils/async_utils.py", line 9, in safe_wrapper
    return await c
  File "/Users/reiniersalazar/hbot-ca-injperp/hummingbot/connector/gateway/clob_perp/data_sources/injective_perpetual/injective_perpetual_api_data_source.py", line 229, in get_order_status_update
    tx_response: GetTxByTxHashResponse = await self._fetch_transaction_by_hash(
  File "/Users/reiniersalazar/hbot-ca-injperp/hummingbot/connector/gateway/clob_perp/data_sources/injective_perpetual/injective_perpetual_api_data_source.py", line 696, in _fetch_transaction_by_hash
    return await self._client.get_tx_by_hash(tx_hash=transaction_hash)
  File "/Users/reiniersalazar/opt/anaconda3/envs/hummingbot/lib/python3.8/site-packages/pyinjective/async_client.py", line 435, in get_tx_by_hash
    return await self.stubExplorer.GetTxByTxHash(req)
  File "/Users/reiniersalazar/opt/anaconda3/envs/hummingbot/lib/python3.8/site-packages/grpc/aio/_call.py", line 290, in __await__
    raise _create_rpc_error(self._cython_call._initial_metadata,
grpc.aio._call.AioRpcError: <AioRpcError of RPC that terminated with:
    status = StatusCode.INVALID_ARGUMENT
    details = "invalid hash"
    debug_error_string = "UNKNOWN:Error received from peer ipv4:34.138.231.254:443 {created_time:"2023-04-06T09:54:02.470405-06:00", grpc_status:3, grpc_message:"invalid hash"}"
>

Steps To Reproduce

Clone and install featured branch
Connect to gateway
Create and run a perpetual market making strategy
Observe the orders being created

Test Result Comparison

N/A, new connector

Attachments

Logs and config: injective_perpetual_fail_cancel.zip

petioptrv commented 1 year ago

Addressed by this commit.

rxlxrxsx commented 1 year ago

I haven't encountered this issue yet however after running the bot for a couple minutes the bot proceeds to place orders as usual but somehow didn't cancel the orders and got stuck causing the bot to not place any orders afterwards. Looking into the logs I didn't see any attempt for the said orders to get canceled.

EDIT: Stopping the bot won't successfully cancel the said orders as well.

Logs, config and data: inj_stuck.zip

petioptrv commented 1 year ago

@rxlxrxsx, very tricky, but I've pushed a fix for this issue in this commit. The issue happens when we send two orders at the same time and the second order fails. If the first one fails, this won't be an issue.

In my case, I tested the solution it by modifying the code so that the second order always fails. Then I checked if the bot will recover. Hopefully you can come up with a more natural way of testing the fix.

mrhzysbl commented 1 year ago

Orders were successfully created. There were no non-existing orders trying to be cancelled.

CoinAlpha / hummingbot