Voyz / ibind

IBind is a REST and WebSocket client library for Interactive Brokers Client Portal Web API.
Apache License 2.0
116 stars 14 forks source link

Disconnect / Errors from stream #25

Closed Tsopic closed 9 hours ago

Tsopic commented 2 months ago

Hey,

I tend to have this problem, where the ´md´ subscription works for a while but then crashes in the background and is not handled properly.

2024-09-05 01:24:40,317|E| IbkrWsClient: Status unauthenticated: {'authenticated': False}
2024-09-05 01:24:40.317 [ERROR] [ws_client_thread] - IbkrWsClient: Status unauthenticated: {'authenticated': False}
2024-09-05 01:24:40,459|I| IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'competing': False}}
2024-09-05 01:24:40.459 [INFO] [ws_client_thread] - IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'competing': False}}
2024-09-05 01:24:40,460|I| IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'message': ''}}
2024-09-05 01:24:40.460 [INFO] [ws_client_thread] - IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'message': ''}}
2024-09-05 01:24:40,460|E| IbkrWsClient: Status unauthenticated: {'authenticated': False}
2024-09-05 01:24:40.460 [ERROR] [ws_client_thread] - IbkrWsClient: Status unauthenticated: {'authenticated': False}

Are there any best practices for reconnecting to WS gracefully?

Voyz commented 2 months ago

Hey @Tsopic thanks for checking out IBind and letting me know of this issue 👍

I was not aware of some of these status responses returned by IBKR. I'll be sure to add them when I find a minute.

As for handling this gracefully, you say:

the ´md´ subscription works for a while but then crashes in the background

Can you expand on this? What do you mean it crashes?

From what I see in the logs, the authentication status seems to be lost with IBKR - which is not uncommon - and the IbkrWsClient indeed handles it gracefully by logging the incorrect authentication status. Should the authentication be recreated (assuming you're using some automated way such as IBeam) the client would recreate the subscriptions automatically. Does that not happen? If so, I'd appreciate if you'd share a full output log and the code you use to create the subscription - thanks!

Tsopic commented 2 months ago

So far it seems: The recreation of subscriptions does not happen indeed.

IBEAM at some point does restore the authorization, but the streamed data if any, does not show up.

    def subscribe(self, tickers: List[Tuple[str, str]]):
        for ticker, exchange in tickers:
            ticker_key = f"{ticker}_{exchange}"
            if ticker_key in self.subscribed_tickers:
                logger.info(f"Already subscribed to {ticker} on {exchange}")
                continue

            try:
                conid = self.get_conid_for_ticker(ticker, exchange)
                if not conid:
                    logger.warning(f"Could not find conid for ticker: {ticker}")
                    continue

                logger.info(f"Subscribing to {ticker} (conid: {conid})")
                market_data_fields = [
                    MarketFields.SYMBOL,
                    MarketFields.LAST_PRICE, MarketFields.BID_PRICE, MarketFields.ASK_PRICE,
                    MarketFields.BID_SIZE, MarketFields.ASK_SIZE, MarketFields.VOLUME,
                    MarketFields.CHANGE, MarketFields.CHANGE_PERCENT, MarketFields.VOLUME_LONG
                ]

                channel = f"md+{conid}"

                success = self.ws_client.subscribe(channel=channel, data={
                    'fields': market_data_fields,
                    'outsideRth': True
                })

                if success:
                    queue_accessor = self.ws_client.new_queue_accessor(IbkrWsKey.MARKET_DATA)
                    self.ticker_info[conid] = TickerInfo(ticker, exchange, conid)
                    self.queue_accessor = queue_accessor
                    self.subscribed_tickers.add(ticker_key)
                    logger.info(f"Successfully subscribed to {ticker} on {exchange}")
                else:
                    logger.error(f"Failed to subscribe to {ticker} on {exchange}")
            except Exception as e:
                logger.exception(f"Exception occurred while subscribing to {ticker} on {exchange}: {str(e)}")

    def unsubscribe_all(self):
        logger.info(f"Unsubscribing from all queues")

        if self.queue_accessor:
            logger.info(f"Unsubscribing from queue_accessor: {self.queue_accessor.key}")
            channel = f"md+{self.queue_accessor.key.channel}"
            success = self.ws_client.unsubscribe(channel=channel)
            self.queue_accessor = None # type: ignore
            for conid, info in self.ticker_info.items():
                channel = f"md+{conid}"
                success = self.ws_client.unsubscribe(channel=channel)
                if success:
                    logger.info(f"Unsubscribed from {channel}")
                else:
                    logger.warning(f"Failed to unsubscribe from {channel}")
            self.ticker_info.clear()
            if success:
                logger.info(f"Unsubscribed from {channel}")
            else:
                logger.warning(f"Failed to unsubscribe from {channel}")
        else:   
            logger.info(f"No queue_accessor to unsubscribe from")

        logger.info(f"Unsubscription complete")
        self.subscribed_tickers.clear()

    def get_latest_data(self, ticker: str) -> Optional[Dict]:
        if self.queue_accessor:
            try:
                return self.queue_accessor.get(block=False)
            except Empty:
                return None
        return None

For logs, I need to wait a little bit, to encounter this again

Voyz commented 2 months ago

hey, thanks for sharing that - it seems all in order. I've pushed v0.1.6 which should handle the competing:true, though that has nothing to do with the resubscriptions. Please try to share the full log once you encounter that same issue next time 👍

Tsopic commented 2 months ago

This is using v0.1.6

@Voyz Adding some more logs,

Just for full context, I removed the SSL Warnings for cleaner logs. "process_ticker_data" is the thread handling incoming data. I think I'll switch the logs to DEBUG level, and wait for the next occurrence.

2024-09-11 01:30:15.576 [DEBUG] [Thread-ConsumeBidirectionalStream] - Search result for 2015: Result(data=[{'conid': '506568272', 'companyHeader': 'LI AUTO INC-CLASS A - SEHK', 'companyName': 'LI AUTO INC-CLASS A', 'symbol': '2015', 'description': 'SEHK', 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK', 'exchange': 'SEHK;'}, {'secType': 'FUT', 'months': 'SEP24;OCT24;NOV24;DEC24;MAR25', 'exchange': 'HKFE'}, {'secType': 'OPT', 'months': 'SEP24;OCT24;NOV24;DEC24;MAR25;JUN25;SEP25', 'exchange': 'SEHK'}, {'secType': 'WAR', 'months': 'SEP24;OCT24;NOV24;DEC24;JAN25;MAR25;APR25;SEP25', 'exchange': 'SEHK'}, {'secType': 'IOPT'}, {'secType': 'BAG', 'exchange': 'HKFE', 'legSecType': 'FUT'}, {'secType': 'BAG', 'exchange': 'SEHK', 'legSecType': 'OPT'}]}, {'conid': '676414434', 'companyHeader': 'IFREEETF US TRE BD 7-10 Y NH - TSEJ', 'companyName': 'IFREEETF US TRE BD 7-10 Y NH', 'symbol': '2015', 'description': 'TSEJ', 'restricted': 'STK', 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK'}]}, {'conid': '39130348', 'companyHeader': 'FENG HSIN STEEL CO LTD - TWSE', 'companyName': 'FENG HSIN STEEL CO LTD', 'symbol': '2015', 'description': 'TWSE', 'restricted': 'STK', 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK', 'exchange': 'TWSE;'}]}], request={'url': 'https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search', 'params': {'symbol': '2015'}})
2024-09-11 01:30:15.577 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to 2015 (conid: 506568272)
2024-09-11 01:30:15,777|I| IbkrWsClient: Subscribed: smd+506568272+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-11 01:30:15.777 [INFO] [Thread-ConsumeBidirectionalStream] - IbkrWsClient: Subscribed: smd+506568272+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-11 01:30:15.778 [INFO] [Thread-ConsumeBidirectionalStream] - Successfully subscribed to 2015 on SEHK
2024-09-11 01:30:15.778 [INFO] [Thread-ConsumeBidirectionalStream] - Change type: ADDED, Document ID: uV1twRfzq1cS5y54tjJK
2024-09-11 01:30:15.778 [INFO] [Thread-ConsumeBidirectionalStream] - Document data: {'lastUpdated': DatetimeWithNanoseconds(2024, 8, 24, 14, 34, 46, 871000, tzinfo=datetime.timezone.utc), 'ticker': '9988', 'exchange': 'SEHK'}
2024-09-11 01:30:15.779 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to symbol: 9988 SEHK
2024-09-11 01:30:15.779 [INFO] [Thread-ConsumeBidirectionalStream] - GET https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search {'params': {'symbol': '9988'}}

2024-09-11 01:30:16.225 [DEBUG] [Thread-ConsumeBidirectionalStream] - Search result for 9988: Result(data=[{'conid': '391638829', 'companyHeader': 'ALIBABA GROUP HOLDING LTD - SEHK', 'companyName': 'ALIBABA GROUP HOLDING LTD', 'symbol': '9988', 'description': 'SEHK', 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK', 'exchange': 'SEHK;'}, {'secType': 'FUT', 'months': 'SEP24;OCT24;NOV24;DEC24;MAR25', 'exchange': 'HKFE'}, {'secType': 'OPT', 'months': 'SEP24;OCT24;NOV24;DEC24;MAR25;JUN25;SEP25', 'exchange': 'SEHK'}, {'secType': 'WAR', 'months': 'SEP24;OCT24;NOV24;DEC24;FEB25;MAR25;APR25;JUN25;JUL25;SEP25;DEC25;JUN28;DEC28', 'exchange': 'SEHK'}, {'secType': 'IOPT'}, {'secType': 'BAG', 'exchange': 'HKFE', 'legSecType': 'FUT'}, {'secType': 'BAG', 'exchange': 'SEHK', 'legSecType': 'OPT'}]}, {'issuers': [{'id': 'e1648825', 'name': 'Alibaba Group Holding Ltd'}], 'bondid': 1, 'conid': '2147483647', 'companyHeader': 'Corporate Fixed Income', 'companyName': None, 'symbol': 'BABA', 'description': None, 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'BOND'}]}], request={'url': 'https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search', 'params': {'symbol': '9988'}})
2024-09-11 01:30:16.225 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to 9988 (conid: 391638829)
2024-09-11 01:30:16,426|I| IbkrWsClient: Subscribed: smd+391638829+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-11 01:30:16.426 [INFO] [Thread-ConsumeBidirectionalStream] - IbkrWsClient: Subscribed: smd+391638829+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-11 01:30:16.427 [INFO] [Thread-ConsumeBidirectionalStream] - Successfully subscribed to 9988 on SEHK
2024-09-11 01:30:16.427 [INFO] [Thread-ConsumeBidirectionalStream] - Change type: ADDED, Document ID: uySJr8nAmZKppRsZeWeM
2024-09-11 01:30:16.427 [INFO] [Thread-ConsumeBidirectionalStream] - Document data: {'lastUpdated': DatetimeWithNanoseconds(2024, 8, 24, 14, 34, 48, 43000, tzinfo=datetime.timezone.utc), 'ticker': '1698', 'exchange': 'SEHK'}
2024-09-11 01:30:16.428 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to symbol: 1698 SEHK
2024-09-11 01:30:16.428 [INFO] [Thread-ConsumeBidirectionalStream] - GET https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search {'params': {'symbol': '1698'}}

2024-09-11 01:30:16.669 [DEBUG] [Thread-ConsumeBidirectionalStream] - Search result for 1698: Result(data=[{'conid': '586243703', 'companyHeader': 'TENCENT MUSIC ENT - CLASS A - SEHK', 'companyName': 'TENCENT MUSIC ENT - CLASS A', 'symbol': '1698', 'description': 'SEHK', 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK', 'exchange': 'SEHK;'}]}, {'conid': '131086405', 'companyHeader': 'JAPAN HIGH D TSE DIVS FO 100 - TSEJ', 'companyName': 'JAPAN HIGH D TSE DIVS FO 100', 'symbol': '1698', 'description': 'TSEJ', 'restricted': 'STK', 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK'}]}, {'issuers': [{'id': 'e1401278', 'name': 'Tencent Holdings Ltd'}, {'id': 'e3297296', 'name': 'Tencent Music Entertainment Group'}], 'bondid': 2, 'conid': '2147483647', 'companyHeader': 'Corporate Fixed Income', 'companyName': None, 'symbol': None, 'description': None, 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'BOND'}]}], request={'url': 'https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search', 'params': {'symbol': '1698'}})
2024-09-11 01:30:16.670 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to 1698 (conid: 586243703)
2024-09-11 01:30:16.828 [WARNING] [Thread-4 (process_ticker_data)] - Ticker info not found for conid: 586243703
2024-09-11 01:30:16.829 [WARNING] [Thread-4 (process_ticker_data)] - Ticker info not found for conid: 586243703
2024-09-11 01:30:16,870|I| IbkrWsClient: Subscribed: smd+586243703+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-11 01:30:16.870 [INFO] [Thread-ConsumeBidirectionalStream] - IbkrWsClient: Subscribed: smd+586243703+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-11 01:30:16.871 [INFO] [Thread-ConsumeBidirectionalStream] - Successfully subscribed to 1698 on SEHK
2024-09-11 01:31:05.429 [DEBUG] [Thread-4 (process_ticker_data)] - Published 397 messages in the last minute

INFO:     10.28.3.13:54590 - "GET /health HTTP/1.1" 200 OK
2024-09-11 01:31:32,723|E| IbkrWsClient: Status unauthenticated: {'authenticated': False}
2024-09-11 01:31:32.723 [ERROR] [ws_client_thread] - IbkrWsClient: Status unauthenticated: {'authenticated': False}

2024-09-11 01:31:32,874|I| IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'competing': False}}
2024-09-11 01:31:32.874 [INFO] [ws_client_thread] - IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'competing': False}}
2024-09-11 01:31:32,875|I| IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'message': ''}}
2024-09-11 01:31:32.875 [INFO] [ws_client_thread] - IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'message': ''}}
2024-09-11 01:31:32,876|E| IbkrWsClient: Status unauthenticated: {'authenticated': False}
2024-09-11 01:31:32.876 [ERROR] [ws_client_thread] - IbkrWsClient: Status unauthenticated: {'authenticated': False}

2024-09-11 01:31:33,008|E| IbkrWsClient: Status unauthenticated: {'authenticated': False}
2024-09-11 01:31:33.008 [ERROR] [ws_client_thread] - IbkrWsClient: Status unauthenticated: {'authenticated': False}

2024-09-11 01:31:33,133|I| IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'competing': False}}
2024-09-11 01:31:33.133 [INFO] [ws_client_thread] - IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'competing': False}}
2024-09-11 01:31:33,134|I| IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'message': ''}}
2024-09-11 01:31:33.134 [INFO] [ws_client_thread] - IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'message': ''}}
2024-09-11 01:31:33,135|E| IbkrWsClient: on_message error: {'error': 'Topic unknown \'{"s\'', 'code': 1, 'topic': '{"s'}
2024-09-11 01:31:33.135 [ERROR] [ws_client_thread] - IbkrWsClient: on_message error: {'error': 'Topic unknown \'{"s\'', 'code': 1, 'topic': '{"s'}
2024-09-11 01:31:33,136|E| IbkrWsClient: on_message error: {'error': 'Topic unknown \'{"s\'', 'code': 1, 'topic': '{"s'}
2024-09-11 01:31:33.136 [ERROR] [ws_client_thread] - IbkrWsClient: on_message error: {'error': 'Topic unknown \'{"s\'', 'code': 1, 'topic': '{"s'}
2024-09-11 01:31:33,187|E| IbkrWsClient: on_message error: {'error': 'Topic unknown \'{"s\'', 'code': 1, 'topic': '{"s'}
2024-09-11 01:31:33.187 [ERROR] [ws_client_thread] - IbkrWsClient: on_message error: {'error': 'Topic unknown \'{"s\'', 'code': 1, 'topic': '{"s'}
2024-09-11 01:31:44,404|E| IbkrWsClient: Status unauthenticated: {'authenticated': False}
2024-09-11 01:31:44.404 [ERROR] [ws_client_thread] - IbkrWsClient: Status unauthenticated: {'authenticated': False}

2024-09-11 01:31:44,601|I| IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'competing': False}}
2024-09-11 01:31:44.601 [INFO] [ws_client_thread] - IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'competing': False}}
2024-09-11 01:31:44,602|I| IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'message': ''}}
2024-09-11 01:31:44.602 [INFO] [ws_client_thread] - IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'message': ''}}
2024-09-11 01:31:44,602|E| IbkrWsClient: Status unauthenticated: {'authenticated': False}
2024-09-11 01:31:44.602 [ERROR] [ws_client_thread] - IbkrWsClient: Status unauthenticated: {'authenticated': False}

2024-09-11 01:31:44,755|E| IbkrWsClient: on_message error: {'error': 'Topic unknown \'{"s\'', 'code': 1, 'topic': '{"s'}
2024-09-11 01:31:44.755 [ERROR] [ws_client_thread] - IbkrWsClient: on_message error: {'error': 'Topic unknown \'{"s\'', 'code': 1, 'topic': '{"s'}
2024-09-11 01:31:44,791|E| IbkrWsClient: on_message error: {'error': 'Topic unknown \'{"s\'', 'code': 1, 'topic': '{"s'}
2024-09-11 01:31:44.791 [ERROR] [ws_client_thread] - IbkrWsClient: on_message error: {'error': 'Topic unknown \'{"s\'', 'code': 1, 'topic': '{"s'}

INFO:     10.28.3.13:51296 - "GET /health HTTP/1.1" 200 OK

INFO:     10.28.3.13:49020 - "GET /health HTTP/1.1" 200 OK

INFO:     10.28.3.13:37860 - "GET /health HTTP/1.1" 200 OK

INFO:     10.28.3.13:57838 - "GET /health HTTP/1.1" 200 OK

INFO:     10.28.3.13:43652 - "GET /health HTTP/1.1" 200 OK
Voyz commented 2 months ago

Hey @Tsopic thanks for providing all of this log - it helped me understand what's happening.

I've noticed that the connection is never re-established and subscriptions are not recreated.

There is a 'check_health' method on both the IbkrClient and IbkrWsClient. I'd encourage you to call it on a fixed interval (say every 10 seconds). The IbkrWsClient's one will additionally attempt to perform a hard reset automatically if it recognises a broken connection (identified by a long disruption in receiving ping or heartbeat). You can read more about it here: docs 1 and docs 2. I apologise for not having pointed you in that direction sooner.

I run it along the lines of:

authenticated = self._ibkr_client.check_health()
if not authenticated:
    _LOGGER.warning(f'IBeam is not healthy: {self.ibkr_url}')

ws_healthy = self._ibkr_ws_client.ready() and self._ibkr_ws_client.check_health()
if not ws_healthy:
    _LOGGER.warning(f'IBeam websocket is not healthy: {self.ibkr_websocket_url}')

As for the log itself, it seems that the corruption is causing some strange responses to be received from IBKR. It seems that IbkrWsClient recognises these correctly and ignores them. All we need is to recognise that the connection has been corrupted and attempt to reconnect. Let me know how check_health helps you in this case.

Tsopic commented 2 months ago

Okay, adding this as the next iteration of healthcheck.

Currently running the health check with 60 sec interval with Uptime Kuma ;)

def check_gateway_health() -> Dict[str, Any]:
    try:
        gateway_result = ibkr_client.tickle()
        authenticated = ibkr_client.check_health()
        auth_status = gateway_result.data.get('iserver', {}).get('authStatus', {}) # type: ignore
        return {
            "authenticated": authenticated and auth_status.get('authenticated', False),
            "connected": auth_status.get('connected', False),
            "competing": auth_status.get('competing', False),
            "message": "Gateway health check successful"
        }
    except Exception as e:
        return {"error": f"Gateway health check failed: {str(e)}"}

def check_websocket_health() -> Dict[str, Any]:
    try:
        ws_client = ws_manager.get_client()
        if not ws_client:
            return {"error": "WebSocket client not initialized"}

        ws_ready = ws_client.ready()
        ws_health = ws_client.check_health()
        return {
            "ready": ws_ready,
            "healthy": ws_health,
            "message": "WebSocket health check successful"
        }
    except Exception as e:
        return {"error": f"WebSocket health check failed: {str(e)}"}

@app.get("/health")
def health_check():
    gateway_health = check_gateway_health()
    ws_health = check_websocket_health()

    overall_status = "healthy"
    if "error" in gateway_health or "error" in ws_health:
        overall_status = "unhealthy"
    elif not gateway_health.get("authenticated", False) or not ws_health.get("healthy", False):
        overall_status = "degraded"

    response = {
        "status": overall_status,
        "gateway": gateway_health,
        "websocket": ws_health
    }

    if overall_status != "healthy":
        return JSONResponse(content=response, status_code=503)
    return response
Voyz commented 2 months ago

Great, let me know how it goes! 🔥

Tsopic commented 2 months ago

sidecomment -

gateway_result = ibkr_client.tickle() is already handled in ibkr_client.check_health() so reducing the double tickling :)

Voyz commented 2 months ago

It is - I noticed it too. I thought you wanted to return the various authentication-related messages from that endpoint hence done it twice. Both ways are valid 👍

Tsopic commented 2 months ago

@Voyz Sending you the logs over email, still encountering some strange behavior.

On the first restart it hangs after like 10min, and on the second restart seems to work fine for hours.

Voyz commented 2 months ago

hey @Tsopic I'd appreciate if you could share the logs here for consistency and for other users who may run into this issue in the future. If you feel it's too long you can make it collapsible in the following fashion:

.<details>

[YOUR CODE HERE]

</details>

Which will look like this: .

[YOUR CODE HERE]

Note the dot . character before <details>.

Thanks!

Tsopic commented 2 months ago

So current state is that it still hangs up on the stream.

There is a strange behavior, where for about 10 minutes at the beginning of the day it works after restarting. And then hangs and stops sending the price updates.

On second Restart it runs a lot longer.

I reduced the logs for the "commit" and "consume" thread quite a bit.

01:31:18,825 timestamp is where it hangs.

.

2024-09-13 01:18:52.264 [INFO] [MainThread] - #################
2024-09-13 01:18:52.344 [INFO] [MainThread] - New IbkrClient(base_url='https://ibeam.ibeam.svc.cluster.local:5000/v1/api/', account_id='U15420905', ssl=False, timeout=10, max_retries=3)
2024-09-13 01:18:52.347 [INFO] [MainThread] - #################
2024-09-13 01:18:52.348 [INFO] [MainThread] - New IbkrClient(base_url='https://ibeam.ibeam.svc.cluster.local:5000/v1/api/', account_id='U15420905', ssl=False, timeout=10, max_retries=3)
2024-09-13 01:18:52.349 [INFO] [MainThread] - IbkrWsClient: Starting
2024-09-13 01:18:52.349 [INFO] [MainThread] - IbkrWsClient: Trying to connect
2024-09-13 01:18:52.349 [DEBUG] [MainThread] - IbkrWsClient: Creating new WebSocketApp
2024-09-13 01:18:52.350 [DEBUG] [ws_client_thread] - IbkrWsClient: Thread started (ws_client_thread-137454101608128)
2024-09-13 01:18:52.378 [DEBUG] [Thread-1 (run_fastapi)] - Using selector: EpollSelector
INFO:     Started server process [1]
INFO:     Waiting for application startup.
INFO:     Application startup complete.
INFO:     Uvicorn running on http://0.0.0.0:8000 (Press CTRL+C to quit)
2024-09-13 01:18:52.656 [INFO] [ws_client_thread] - Websocket connected
2024-09-13 01:18:52.657 [INFO] [ws_client_thread] - IbkrWsClient: Connection open
2024-09-13 01:18:52.757 [INFO] [MainThread] - WebSocket manager started successfully.
2024-09-13 01:18:52.758 [INFO] [MainThread] - #################
2024-09-13 01:18:52.758 [INFO] [MainThread] - New IbkrClient(base_url='https://ibeam.ibeam.svc.cluster.local:5000/v1/api/', account_id='U15420905', ssl=False, timeout=10, max_retries=3)
2024-09-13 01:18:52.931 [DEBUG] [MainThread] - Started helper thread Thread-ConsumeBidirectionalStream
2024-09-13 01:18:52.931 [INFO] [MainThread] - Started listening for updates on market_data_subscription documents
2024-09-13 01:18:52.944 [DEBUG] [Thread-ConsumeBidirectionalStream] - waiting for recv.
2024-09-13 01:18:52.967 [DEBUG] [Thread-7 (_run)] - Making request: POST https://oauth2.googleapis.com/token
2024-09-13 01:18:52.983 [DEBUG] [Thread-7 (_run)] - Starting new HTTPS connection (1): oauth2.googleapis.com:443
2024-09-13 01:18:53.076 [DEBUG] [Thread-7 (_run)] - https://oauth2.googleapis.com:443 "POST /token HTTP/11" 200 None
2024-09-13 01:18:53.837 [DEBUG] [Thread-ConsumeBidirectionalStream] - recved response.
2024-09-13 01:18:53.837 [DEBUG] [Thread-ConsumeBidirectionalStream] - on_snapshot: target change: 1
2024-09-13 01:18:53.838 [DEBUG] [Thread-ConsumeBidirectionalStream] - on_snapshot: target change: ADD
2024-09-13 01:18:53.838 [DEBUG] [Thread-ConsumeBidirectionalStream] - waiting for recv.
2024-09-13 01:18:53.861 [DEBUG] [Thread-ConsumeBidirectionalStream] - recved response.
2024-09-13 01:18:53.861 [DEBUG] [Thread-ConsumeBidirectionalStream] - on_snapshot: document change
2024-09-13 01:18:53.862 [DEBUG] [Thread-ConsumeBidirectionalStream] - on_snapshot: document change: CHANGED
2024-09-13 01:18:53.900 [DEBUG] [Thread-ConsumeBidirectionalStream] - recved response.
2024-09-13 01:18:53.900 [DEBUG] [Thread-ConsumeBidirectionalStream] - on_snapshot: target change: 3
2024-09-13 01:18:53.900 [DEBUG] [Thread-ConsumeBidirectionalStream] - on_snapshot: target change: CURRENT
2024-09-13 01:18:53.901 [DEBUG] [Thread-ConsumeBidirectionalStream] - waiting for recv.
2024-09-13 01:18:53.901 [DEBUG] [Thread-ConsumeBidirectionalStream] - recved response.
2024-09-13 01:18:53.901 [DEBUG] [Thread-ConsumeBidirectionalStream] - on_snapshot: target change: 0
2024-09-13 01:18:53.902 [DEBUG] [Thread-ConsumeBidirectionalStream] - on_snapshot: target change: NO_CHANGE
2024-09-13 01:18:53.903 [DEBUG] [Thread-ConsumeBidirectionalStream] - walk over add_changes
2024-09-13 01:18:53.903 [DEBUG] [Thread-ConsumeBidirectionalStream] - in add_changes

2024-09-13 01:18:53.912 [INFO] [Thread-ConsumeBidirectionalStream] - Change type: ADDED, Document ID: 0oyxFBEHpyWy0znNfcTR
2024-09-13 01:18:53.913 [INFO] [Thread-ConsumeBidirectionalStream] - Document data: {'lastUpdated': DatetimeWithNanoseconds(2024, 8, 24, 14, 34, 47, 419000, tzinfo=datetime.timezone.utc), 'ticker': '2423', 'exchange': 'SEHK'}
2024-09-13 01:18:53.913 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to symbol: 2423 SEHK
2024-09-13 01:18:53.913 [INFO] [Thread-ConsumeBidirectionalStream] - GET https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search {'params': {'symbol': '2423'}}
2024-09-13 01:18:53.916 [DEBUG] [Thread-ConsumeBidirectionalStream] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000

2024-09-13 01:18:54.230 [DEBUG] [Thread-ConsumeBidirectionalStream] - https://ibeam.ibeam.svc.cluster.local:5000 "GET /v1/api/iserver/secdef/search?symbol=2423 HTTP/11" 200 None
2024-09-13 01:18:54.234 [DEBUG] [Thread-ConsumeBidirectionalStream] - Search result for 2423: Result(data=[{'conid': '560332250', 'companyHeader': 'KE HOLDINGS INC-CL A - SEHK', 'companyName': 'KE HOLDINGS INC-CL A', 'symbol': '2423', 'description': 'SEHK', 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK', 'exchange': 'SEHK;'}, {'secType': 'CFD', 'exchange': 'SMART', 'conid': '583962023'}]}, {'conid': '39130669', 'companyHeader': 'GOOD WILL INSTRUMENT CO LTD - TWSE', 'companyName': 'GOOD WILL INSTRUMENT CO LTD', 'symbol': '2423', 'description': 'TWSE', 'restricted': 'STK', 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK', 'exchange': 'TWSE;'}]}], request={'url': 'https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search', 'params': {'symbol': '2423'}})
2024-09-13 01:18:54.235 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to 2423 (conid: 560332250)
2024-09-13 01:18:54,436|I| IbkrWsClient: Subscribed: smd+560332250+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:18:54.436 [INFO] [Thread-ConsumeBidirectionalStream] - IbkrWsClient: Subscribed: smd+560332250+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:18:54.437 [INFO] [Thread-ConsumeBidirectionalStream] - Successfully subscribed to 2423 on SEHK
2024-09-13 01:18:54.437 [INFO] [Thread-ConsumeBidirectionalStream] - Change type: ADDED, Document ID: 0vHjXuWA59pCK5R786eZ
2024-09-13 01:18:54.438 [INFO] [Thread-ConsumeBidirectionalStream] - Document data: {'lastUpdated': DatetimeWithNanoseconds(2024, 8, 24, 14, 34, 45, 991000, tzinfo=datetime.timezone.utc), 'ticker': '9888', 'exchange': 'SEHK'}
2024-09-13 01:18:54.438 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to symbol: 9888 SEHK
2024-09-13 01:18:54.438 [INFO] [Thread-ConsumeBidirectionalStream] - GET https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search {'params': {'symbol': '9888'}}
2024-09-13 01:18:54.440 [DEBUG] [Thread-ConsumeBidirectionalStream] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000

2024-09-13 01:18:54.546 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:18:54.615 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.06784272193908691 seconds.
2024-09-13 01:18:54.626 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:18:54.716 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.08919000625610352 seconds.
2024-09-13 01:18:54.928 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:18:54.949 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.02013993263244629 seconds.
2024-09-13 01:18:55.029 [DEBUG] [Thread-ConsumeBidirectionalStream] - https://ibeam.ibeam.svc.cluster.local:5000 "GET /v1/api/iserver/secdef/search?symbol=9888 HTTP/11" 200 None
2024-09-13 01:18:55.032 [DEBUG] [Thread-ConsumeBidirectionalStream] - Search result for 9888: Result(data=[{'conid': '476787454', 'companyHeader': 'BAIDU INC-CLASS A - SEHK', 'companyName': 'BAIDU INC-CLASS A', 'symbol': '9888', 'description': 'SEHK', 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK', 'exchange': 'SEHK;'}, {'secType': 'FUT', 'months': 'SEP24;OCT24;NOV24;DEC24;MAR25', 'exchange': 'HKFE'}, {'secType': 'OPT', 'months': 'SEP24;OCT24;NOV24;DEC24;MAR25;JUN25;SEP25', 'exchange': 'SEHK'}, {'secType': 'WAR', 'months': 'SEP24;NOV24;DEC24;JAN25;FEB25;MAR25;JUN25;JUL25;SEP25;DEC25;JUN26', 'exchange': 'SEHK'}, {'secType': 'IOPT'}, {'secType': 'CFD', 'exchange': 'SMART', 'conid': '481818575'}, {'secType': 'BAG', 'exchange': 'HKFE', 'legSecType': 'FUT'}, {'secType': 'BAG', 'exchange': 'SEHK', 'legSecType': 'OPT'}]}, {'conid': '131083438', 'companyHeader': 'UEX LTD - TSEJ', 'companyName': 'UEX LTD', 'symbol': '9888', 'description': 'TSEJ', 'restricted': 'STK', 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK'}]}, {'issuers': [{'id': 'e1393775', 'name': 'Baidu Inc'}], 'bondid': 2, 'conid': '2147483647', 'companyHeader': 'Corporate Fixed Income', 'companyName': None, 'symbol': 'BIDU', 'description': None, 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'BOND'}]}], request={'url': 'https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search', 'params': {'symbol': '9888'}})
2024-09-13 01:18:55.032 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to 9888 (conid: 476787454)
2024-09-13 01:18:55,233|I| IbkrWsClient: Subscribed: smd+476787454+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:18:55.233 [INFO] [Thread-ConsumeBidirectionalStream] - IbkrWsClient: Subscribed: smd+476787454+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:18:55.234 [INFO] [Thread-ConsumeBidirectionalStream] - Successfully subscribed to 9888 on SEHK
2024-09-13 01:18:55.234 [INFO] [Thread-ConsumeBidirectionalStream] - Change type: ADDED, Document ID: 2DheqapAYGMs5hNT3ed8
2024-09-13 01:18:55.234 [INFO] [Thread-ConsumeBidirectionalStream] - Document data: {'lastUpdated': DatetimeWithNanoseconds(2024, 8, 24, 14, 34, 47, 745000, tzinfo=datetime.timezone.utc), 'ticker': '6623', 'exchange': 'SEHK'}
2024-09-13 01:18:55.235 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to symbol: 6623 SEHK
2024-09-13 01:18:55.235 [INFO] [Thread-ConsumeBidirectionalStream] - GET https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search {'params': {'symbol': '6623'}}
2024-09-13 01:18:55.237 [DEBUG] [Thread-ConsumeBidirectionalStream] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000
2024-09-13 01:18:55.261 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:18:55.285 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.022661685943603516 seconds.
2024-09-13 01:18:55.297 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up

2024-09-13 01:18:55.319 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.021902084350585938 seconds.
2024-09-13 01:18:55.431 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:18:55.458 [DEBUG] [Thread-ConsumeBidirectionalStream] - https://ibeam.ibeam.svc.cluster.local:5000 "GET /v1/api/iserver/secdef/search?symbol=6623 HTTP/11" 200 None
2024-09-13 01:18:55.463 [DEBUG] [Thread-ConsumeBidirectionalStream] - Search result for 6623: Result(data=[{'conid': '625086794', 'companyHeader': 'LUFAX HOLDING LTD - SEHK', 'companyName': 'LUFAX HOLDING LTD', 'symbol': '6623', 'description': 'SEHK', 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK', 'exchange': 'SEHK;'}]}], request={'url': 'https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search', 'params': {'symbol': '6623'}})
2024-09-13 01:18:55.463 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to 6623 (conid: 625086794)
2024-09-13 01:18:55.472 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.03999805450439453 seconds.
2024-09-13 01:18:55,664|I| IbkrWsClient: Subscribed: smd+625086794+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:18:55.664 [INFO] [Thread-ConsumeBidirectionalStream] - IbkrWsClient: Subscribed: smd+625086794+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:18:55.666 [INFO] [Thread-ConsumeBidirectionalStream] - Successfully subscribed to 6623 on SEHK
2024-09-13 01:18:55.666 [INFO] [Thread-ConsumeBidirectionalStream] - Change type: ADDED, Document ID: 2bVFvjwS1TbNRJKlaoqa
2024-09-13 01:18:55.666 [INFO] [Thread-ConsumeBidirectionalStream] - Document data: {'lastUpdated': DatetimeWithNanoseconds(2024, 8, 24, 14, 34, 46, 990000, tzinfo=datetime.timezone.utc), 'ticker': '9999', 'exchange': 'SEHK'}
2024-09-13 01:18:55.667 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to symbol: 9999 SEHK
2024-09-13 01:18:55.667 [INFO] [Thread-ConsumeBidirectionalStream] - GET https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search {'params': {'symbol': '9999'}}
2024-09-13 01:18:55.669 [DEBUG] [Thread-ConsumeBidirectionalStream] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000
2024-09-13 01:18:55.684 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:18:55.719 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.03336668014526367 seconds.
2024-09-13 01:18:55.731 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up

2024-09-13 01:18:55.766 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.03373146057128906 seconds.
2024-09-13 01:18:55.778 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:18:55.816 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.03595280647277832 seconds.
2024-09-13 01:18:55.928 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:18:55.975 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.04676508903503418 seconds.
2024-09-13 01:18:56.089 [DEBUG] [Thread-ConsumeBidirectionalStream] - https://ibeam.ibeam.svc.cluster.local:5000 "GET /v1/api/iserver/secdef/search?symbol=9999 HTTP/11" 200 None
2024-09-13 01:18:56.092 [DEBUG] [Thread-ConsumeBidirectionalStream] - Search result for 9999: Result(data=[{'conid': '425145098', 'companyHeader': 'NETEASE INC - SEHK', 'companyName': 'NETEASE INC', 'symbol': '9999', 'description': 'SEHK', 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK', 'exchange': 'SEHK;'}, {'secType': 'FUT', 'months': 'SEP24;OCT24;NOV24;DEC24;MAR25', 'exchange': 'HKFE'}, {'secType': 'OPT', 'months': 'SEP24;OCT24;NOV24;DEC24;MAR25;JUN25;SEP25', 'exchange': 'SEHK'}, {'secType': 'WAR', 'months': 'SEP24;NOV24;DEC24;JAN25;FEB25;MAR25;APR25;JUN25;JUL25;SEP25', 'exchange': 'SEHK'}, {'secType': 'IOPT'}, {'secType': 'CFD', 'exchange': 'SMART', 'conid': '430458233'}, {'secType': 'BAG', 'exchange': 'HKFE', 'legSecType': 'FUT'}, {'secType': 'BAG', 'exchange': 'SEHK', 'legSecType': 'OPT'}]}], request={'url': 'https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search', 'params': {'symbol': '9999'}})
2024-09-13 01:18:56.093 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to 9999 (conid: 425145098)
2024-09-13 01:18:56.277 [WARNING] [Thread-4 (process_ticker_data)] - Ticker info not found for conid: 425145098
2024-09-13 01:18:56.278 [WARNING] [Thread-4 (process_ticker_data)] - Ticker info not found for conid: 425145098
2024-09-13 01:18:56,294|I| IbkrWsClient: Subscribed: smd+425145098+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:18:56.294 [INFO] [Thread-ConsumeBidirectionalStream] - IbkrWsClient: Subscribed: smd+425145098+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:18:56.295 [INFO] [Thread-ConsumeBidirectionalStream] - Successfully subscribed to 9999 on SEHK
2024-09-13 01:18:56.296 [INFO] [Thread-ConsumeBidirectionalStream] - Change type: ADDED, Document ID: D37cmKoqkH3YFLSbALyj
2024-09-13 01:18:56.296 [INFO] [Thread-ConsumeBidirectionalStream] - Document data: {'lastUpdated': DatetimeWithNanoseconds(2024, 8, 24, 14, 34, 47, 106000, tzinfo=datetime.timezone.utc), 'ticker': '6160', 'exchange': 'SEHK'}
2024-09-13 01:18:56.297 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to symbol: 6160 SEHK
2024-09-13 01:18:56.297 [INFO] [Thread-ConsumeBidirectionalStream] - GET https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search {'params': {'symbol': '6160'}}
2024-09-13 01:18:56.299 [DEBUG] [Thread-ConsumeBidirectionalStream] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000

2024-09-13 01:18:56.389 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:18:56.412 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.02163839340209961 seconds.
2024-09-13 01:18:56.594 [DEBUG] [Thread-ConsumeBidirectionalStream] - https://ibeam.ibeam.svc.cluster.local:5000 "GET /v1/api/iserver/secdef/search?symbol=6160 HTTP/11" 200 None
2024-09-13 01:18:56.597 [DEBUG] [Thread-ConsumeBidirectionalStream] - Search result for 6160: Result(data=[{'conid': '328844678', 'companyHeader': 'BEIGENE LTD - SEHK', 'companyName': 'BEIGENE LTD', 'symbol': '6160', 'description': 'SEHK', 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK', 'exchange': 'SEHK;'}, {'secType': 'CFD', 'exchange': 'SMART', 'conid': '451396005'}]}], request={'url': 'https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search', 'params': {'symbol': '6160'}})
2024-09-13 01:18:56.597 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to 6160 (conid: 328844678)
2024-09-13 01:18:56,798|I| IbkrWsClient: Subscribed: smd+328844678+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:18:56.798 [INFO] [Thread-ConsumeBidirectionalStream] - IbkrWsClient: Subscribed: smd+328844678+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:18:56.799 [INFO] [Thread-ConsumeBidirectionalStream] - Successfully subscribed to 6160 on SEHK
2024-09-13 01:18:56.800 [INFO] [Thread-ConsumeBidirectionalStream] - Change type: ADDED, Document ID: HfclXilTjta3WKoGsmOr
2024-09-13 01:18:56.800 [INFO] [Thread-ConsumeBidirectionalStream] - Document data: {'lastUpdated': DatetimeWithNanoseconds(2024, 8, 24, 14, 34, 47, 311000, tzinfo=datetime.timezone.utc), 'ticker': '9698', 'exchange': 'SEHK'}
2024-09-13 01:18:56.800 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to symbol: 9698 SEHK
2024-09-13 01:18:56.801 [INFO] [Thread-ConsumeBidirectionalStream] - GET https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search {'params': {'symbol': '9698'}}
2024-09-13 01:18:56.803 [DEBUG] [Thread-ConsumeBidirectionalStream] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000
2024-09-13 01:18:56.825 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:18:56.855 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.028566837310791016 seconds.

2024-09-13 01:18:56.866 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:18:56.912 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.044996023178100586 seconds.
2024-09-13 01:18:56.923 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:18:56.959 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.035445451736450195 seconds.
2024-09-13 01:18:57.102 [DEBUG] [Thread-ConsumeBidirectionalStream] - https://ibeam.ibeam.svc.cluster.local:5000 "GET /v1/api/iserver/secdef/search?symbol=9698 HTTP/11" 200 None
2024-09-13 01:18:57.105 [DEBUG] [Thread-ConsumeBidirectionalStream] - Search result for 9698: Result(data=[{'conid': '451690805', 'companyHeader': 'GDS HOLDINGS LTD-CL A - SEHK', 'companyName': 'GDS HOLDINGS LTD-CL A', 'symbol': '9698', 'description': 'SEHK', 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK', 'exchange': 'SEHK;'}, {'secType': 'WAR', 'months': 'OCT24', 'exchange': 'SEHK'}, {'secType': 'CFD', 'exchange': 'SMART', 'conid': '481701341'}]}, {'conid': '131085479', 'companyHeader': 'CREO CO LTD - TSEJ', 'companyName': 'CREO CO LTD', 'symbol': '9698', 'description': 'TSEJ', 'restricted': 'STK', 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK'}]}], request={'url': 'https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search', 'params': {'symbol': '9698'}})
2024-09-13 01:18:57.106 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to 9698 (conid: 451690805)
2024-09-13 01:18:57.271 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:18:57.291 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.018955469131469727 seconds.
2024-09-13 01:18:57.292 [WARNING] [Thread-4 (process_ticker_data)] - Ticker info not found for conid: 451690805
2024-09-13 01:18:57.292 [WARNING] [Thread-4 (process_ticker_data)] - Ticker info not found for conid: 451690805
2024-09-13 01:18:57,307|I| IbkrWsClient: Subscribed: smd+451690805+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:18:57.307 [INFO] [Thread-ConsumeBidirectionalStream] - IbkrWsClient: Subscribed: smd+451690805+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:18:57.307 [INFO] [Thread-ConsumeBidirectionalStream] - Successfully subscribed to 9698 on SEHK
2024-09-13 01:18:57.308 [INFO] [Thread-ConsumeBidirectionalStream] - Change type: ADDED, Document ID: RzWu3N9RSRQjKlG6vI84
2024-09-13 01:18:57.308 [INFO] [Thread-ConsumeBidirectionalStream] - Document data: {'lastUpdated': DatetimeWithNanoseconds(2024, 8, 24, 14, 34, 47, 205000, tzinfo=datetime.timezone.utc), 'ticker': '9961', 'exchange': 'SEHK'}
2024-09-13 01:18:57.309 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to symbol: 9961 SEHK
2024-09-13 01:18:57.309 [INFO] [Thread-ConsumeBidirectionalStream] - GET https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search {'params': {'symbol': '9961'}}
2024-09-13 01:18:57.311 [DEBUG] [Thread-ConsumeBidirectionalStream] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000

2024-09-13 01:18:57.718 [DEBUG] [Thread-ConsumeBidirectionalStream] - https://ibeam.ibeam.svc.cluster.local:5000 "GET /v1/api/iserver/secdef/search?symbol=9961 HTTP/11" 200 None
2024-09-13 01:18:57.721 [DEBUG] [Thread-ConsumeBidirectionalStream] - Search result for 9961: Result(data=[{'conid': '481432897', 'companyHeader': 'TRIP.COM GROUP LTD - SEHK', 'companyName': 'TRIP.COM GROUP LTD', 'symbol': '9961', 'description': 'SEHK', 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK', 'exchange': 'SEHK;'}, {'secType': 'FUT', 'months': 'SEP24;OCT24;NOV24;DEC24;MAR25', 'exchange': 'HKFE'}, {'secType': 'OPT', 'months': 'SEP24;OCT24;NOV24;DEC24;MAR25;JUN25;SEP25', 'exchange': 'SEHK'}, {'secType': 'WAR', 'months': 'SEP24;OCT24;NOV24;DEC24;JAN25;FEB25;MAR25;APR25;JUL25', 'exchange': 'SEHK'}, {'secType': 'IOPT'}, {'secType': 'CFD', 'exchange': 'SMART', 'conid': '519074975'}, {'secType': 'BAG', 'exchange': 'HKFE', 'legSecType': 'FUT'}, {'secType': 'BAG', 'exchange': 'SEHK', 'legSecType': 'OPT'}]}], request={'url': 'https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search', 'params': {'symbol': '9961'}})
2024-09-13 01:18:57.721 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to 9961 (conid: 481432897)
2024-09-13 01:18:57.904 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:18:57.923 [INFO] [Thread-ConsumeBidirectionalStream] - IbkrWsClient: Subscribed: smd+481432897+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:18:57,923|I| IbkrWsClient: Subscribed: smd+481432897+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:18:57.923 [INFO] [Thread-ConsumeBidirectionalStream] - Successfully subscribed to 9961 on SEHK
2024-09-13 01:18:57.923 [INFO] [Thread-ConsumeBidirectionalStream] - Change type: ADDED, Document ID: S2tAgix0Ux4F42ZKrs6U
2024-09-13 01:18:57.924 [INFO] [Thread-ConsumeBidirectionalStream] - Document data: {'lastUpdated': DatetimeWithNanoseconds(2024, 8, 24, 14, 34, 46, 671000, tzinfo=datetime.timezone.utc), 'ticker': '9866', 'exchange': 'SEHK'}
2024-09-13 01:18:57.924 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to symbol: 9866 SEHK
2024-09-13 01:18:57.924 [INFO] [Thread-ConsumeBidirectionalStream] - GET https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search {'params': {'symbol': '9866'}}
2024-09-13 01:18:57.926 [DEBUG] [Thread-ConsumeBidirectionalStream] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000
2024-09-13 01:18:57.959 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.05453228950500488 seconds.
2024-09-13 01:18:57.971 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up

2024-09-13 01:18:58.008 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.03664565086364746 seconds.
2024-09-13 01:18:58.020 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:18:58.049 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.028560400009155273 seconds.
2024-09-13 01:18:58.060 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:18:58.093 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.03213000297546387 seconds.
2024-09-13 01:18:58.222 [DEBUG] [Thread-ConsumeBidirectionalStream] - https://ibeam.ibeam.svc.cluster.local:5000 "GET /v1/api/iserver/secdef/search?symbol=9866 HTTP/11" 200 None
2024-09-13 01:18:58.225 [DEBUG] [Thread-ConsumeBidirectionalStream] - Search result for 9866: Result(data=[{'conid': '548854840', 'companyHeader': 'NIO INC-CLASS A - SEHK', 'companyName': 'NIO INC-CLASS A', 'symbol': '9866', 'description': 'SEHK', 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK', 'exchange': 'SEHK;'}, {'secType': 'WAR', 'months': 'DEC24;JUL25;AUG25;NOV25;DEC25', 'exchange': 'SEHK'}, {'secType': 'CFD', 'exchange': 'SMART', 'conid': '567310854'}]}], request={'url': 'https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search', 'params': {'symbol': '9866'}})
2024-09-13 01:18:58.226 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to 9866 (conid: 548854840)
2024-09-13 01:18:58.405 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:18:58,427|I| IbkrWsClient: Subscribed: smd+548854840+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:18:58.427 [INFO] [Thread-ConsumeBidirectionalStream] - IbkrWsClient: Subscribed: smd+548854840+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:18:58.428 [INFO] [Thread-ConsumeBidirectionalStream] - Successfully subscribed to 9866 on SEHK
2024-09-13 01:18:58.428 [INFO] [Thread-ConsumeBidirectionalStream] - Change type: ADDED, Document ID: aDO5zBkIwMCXNVvfePQE
2024-09-13 01:18:58.428 [INFO] [Thread-ConsumeBidirectionalStream] - Document data: {'lastUpdated': DatetimeWithNanoseconds(2024, 8, 24, 14, 34, 46, 776000, tzinfo=datetime.timezone.utc), 'ticker': '9868', 'exchange': 'SEHK'}
2024-09-13 01:18:58.429 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to symbol: 9868 SEHK
2024-09-13 01:18:58.429 [INFO] [Thread-ConsumeBidirectionalStream] - GET https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search {'params': {'symbol': '9868'}}
2024-09-13 01:18:58.431 [DEBUG] [Thread-ConsumeBidirectionalStream] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000
2024-09-13 01:18:58.433 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.02749323844909668 seconds.
2024-09-13 01:18:58.445 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:18:58.477 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.031465768814086914 seconds.
2024-09-13 01:18:58.488 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up

2024-09-13 01:18:58.522 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.03302001953125 seconds.
2024-09-13 01:18:58.533 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:18:58.557 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.0228731632232666 seconds.
2024-09-13 01:18:58.829 [DEBUG] [Thread-ConsumeBidirectionalStream] - https://ibeam.ibeam.svc.cluster.local:5000 "GET /v1/api/iserver/secdef/search?symbol=9868 HTTP/11" 200 None
2024-09-13 01:18:58.831 [DEBUG] [Thread-ConsumeBidirectionalStream] - Search result for 9868: Result(data=[{'conid': '499871328', 'companyHeader': 'XPENG INC - CLASS A SHARES - SEHK', 'companyName': 'XPENG INC - CLASS A SHARES', 'symbol': '9868', 'description': 'SEHK', 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK', 'exchange': 'SEHK;'}, {'secType': 'FUT', 'months': 'SEP24;OCT24;NOV24;DEC24;MAR25', 'exchange': 'HKFE'}, {'secType': 'OPT', 'months': 'SEP24;OCT24;NOV24;DEC24;MAR25;JUN25;SEP25', 'exchange': 'SEHK'}, {'secType': 'WAR', 'months': 'SEP24;NOV24;DEC24;JAN25;FEB25;JUL25;DEC25', 'exchange': 'SEHK'}, {'secType': 'IOPT'}, {'secType': 'CFD', 'exchange': 'SMART', 'conid': '504485061'}, {'secType': 'BAG', 'exchange': 'HKFE', 'legSecType': 'FUT'}, {'secType': 'BAG', 'exchange': 'SEHK', 'legSecType': 'OPT'}]}], request={'url': 'https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search', 'params': {'symbol': '9868'}})
2024-09-13 01:18:58.832 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to 9868 (conid: 499871328)
2024-09-13 01:18:58.969 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:18:58.996 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.026515960693359375 seconds.
2024-09-13 01:18:59.008 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:18:59,033|I| IbkrWsClient: Subscribed: smd+499871328+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:18:59.033 [INFO] [Thread-ConsumeBidirectionalStream] - IbkrWsClient: Subscribed: smd+499871328+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:18:59.033 [INFO] [Thread-ConsumeBidirectionalStream] - Successfully subscribed to 9868 on SEHK
2024-09-13 01:18:59.034 [INFO] [Thread-ConsumeBidirectionalStream] - Change type: ADDED, Document ID: cAhGWgzAN14bGQIwkuPk
2024-09-13 01:18:59.034 [INFO] [Thread-ConsumeBidirectionalStream] - Document data: {'lastUpdated': DatetimeWithNanoseconds(2024, 8, 24, 14, 34, 46, 398000, tzinfo=datetime.timezone.utc), 'ticker': '9618', 'exchange': 'SEHK'}
2024-09-13 01:18:59.034 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to symbol: 9618 SEHK
2024-09-13 01:18:59.034 [INFO] [Thread-ConsumeBidirectionalStream] - GET https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search {'params': {'symbol': '9618'}}
2024-09-13 01:18:59.037 [DEBUG] [Thread-ConsumeBidirectionalStream] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000
2024-09-13 01:18:59.040 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.03187108039855957 seconds.

2024-09-13 01:18:59.153 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:18:59.176 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.022471904754638672 seconds.
2024-09-13 01:18:59.188 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:18:59.212 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.02406454086303711 seconds.
2024-09-13 01:18:59.424 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:18:59.457 [DEBUG] [Thread-ConsumeBidirectionalStream] - https://ibeam.ibeam.svc.cluster.local:5000 "GET /v1/api/iserver/secdef/search?symbol=9618 HTTP/11" 200 None
2024-09-13 01:18:59.460 [DEBUG] [Thread-ConsumeBidirectionalStream] - Search result for 9618: Result(data=[{'conid': '426228059', 'companyHeader': 'JD.COM INC-CLASS A - SEHK', 'companyName': 'JD.COM INC-CLASS A', 'symbol': '9618', 'description': 'SEHK', 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK', 'exchange': 'SEHK;'}, {'secType': 'FUT', 'months': 'SEP24;OCT24;NOV24;DEC24;MAR25', 'exchange': 'HKFE'}, {'secType': 'OPT', 'months': 'SEP24;OCT24;NOV24;DEC24;MAR25;JUN25;SEP25', 'exchange': 'SEHK'}, {'secType': 'WAR', 'months': 'SEP24;OCT24;NOV24;DEC24;JAN25;FEB25;MAR25;APR25;MAY25;JUN25;JUL25;SEP25;NOV25;DEC25', 'exchange': 'SEHK'}, {'secType': 'IOPT'}, {'secType': 'CFD', 'exchange': 'SMART', 'conid': '432421677'}, {'secType': 'BAG', 'exchange': 'HKFE', 'legSecType': 'FUT'}, {'secType': 'BAG', 'exchange': 'SEHK', 'legSecType': 'OPT'}]}, {'issuers': [{'id': 'e1743862', 'name': 'JD.com Inc'}], 'bondid': 1, 'conid': '2147483647', 'companyHeader': 'Corporate Fixed Income', 'companyName': None, 'symbol': 'JD', 'description': None, 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'BOND'}]}], request={'url': 'https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search', 'params': {'symbol': '9618'}})
2024-09-13 01:18:59.460 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to 9618 (conid: 426228059)
2024-09-13 01:18:59.465 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.03961753845214844 seconds.
2024-09-13 01:18:59,661|I| IbkrWsClient: Subscribed: smd+426228059+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:18:59.661 [INFO] [Thread-ConsumeBidirectionalStream] - IbkrWsClient: Subscribed: smd+426228059+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:18:59.662 [INFO] [Thread-ConsumeBidirectionalStream] - Successfully subscribed to 9618 on SEHK
2024-09-13 01:18:59.662 [INFO] [Thread-ConsumeBidirectionalStream] - Change type: ADDED, Document ID: hk7WN2I10mXA8DmwJm1n
2024-09-13 01:18:59.663 [INFO] [Thread-ConsumeBidirectionalStream] - Document data: {'lastUpdated': DatetimeWithNanoseconds(2024, 8, 24, 14, 34, 47, 522000, tzinfo=datetime.timezone.utc), 'ticker': '2390', 'exchange': 'SEHK'}
2024-09-13 01:18:59.663 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to symbol: 2390 SEHK
2024-09-13 01:18:59.664 [INFO] [Thread-ConsumeBidirectionalStream] - GET https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search {'params': {'symbol': '2390'}}
2024-09-13 01:18:59.666 [DEBUG] [Thread-ConsumeBidirectionalStream] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000
2024-09-13 01:18:59.678 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:18:59.712 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.0330507755279541 seconds.
2024-09-13 01:18:59.724 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up

2024-09-13 01:18:59.750 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.024489402770996094 seconds.
2024-09-13 01:18:59.890 [DEBUG] [Thread-ConsumeBidirectionalStream] - https://ibeam.ibeam.svc.cluster.local:5000 "GET /v1/api/iserver/secdef/search?symbol=2390 HTTP/11" 200 None
2024-09-13 01:18:59.894 [DEBUG] [Thread-ConsumeBidirectionalStream] - Search result for 2390: Result(data=[{'conid': '556011129', 'companyHeader': 'ZHIHU INC. - SEHK', 'companyName': 'ZHIHU INC.', 'symbol': '2390', 'description': 'SEHK', 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK', 'exchange': 'SEHK;'}]}, {'conid': '39130587', 'companyHeader': 'EVERSPRING INDUSTRY CO LTD - TWSE', 'companyName': 'EVERSPRING INDUSTRY CO LTD', 'symbol': '2390', 'description': 'TWSE', 'restricted': 'STK', 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK', 'exchange': 'TWSE;'}]}], request={'url': 'https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search', 'params': {'symbol': '2390'}})
2024-09-13 01:18:59.895 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to 2390 (conid: 556011129)
2024-09-13 01:18:59.962 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:18:59.989 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.025484800338745117 seconds.
2024-09-13 01:19:00.090 [WARNING] [Thread-4 (process_ticker_data)] - Ticker info not found for conid: 556011129
2024-09-13 01:19:00.090 [WARNING] [Thread-4 (process_ticker_data)] - Ticker info not found for conid: 556011129
2024-09-13 01:19:00,096|I| IbkrWsClient: Subscribed: smd+556011129+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:19:00.096 [INFO] [Thread-ConsumeBidirectionalStream] - IbkrWsClient: Subscribed: smd+556011129+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:19:00.097 [INFO] [Thread-ConsumeBidirectionalStream] - Successfully subscribed to 2390 on SEHK
2024-09-13 01:19:00.098 [INFO] [Thread-ConsumeBidirectionalStream] - Change type: ADDED, Document ID: lkg0Qyh1nLpWqw2qzOIU
2024-09-13 01:19:00.098 [INFO] [Thread-ConsumeBidirectionalStream] - Document data: {'lastUpdated': DatetimeWithNanoseconds(2024, 8, 24, 14, 34, 47, 640000, tzinfo=datetime.timezone.utc), 'ticker': '5', 'exchange': 'SEHK'}
2024-09-13 01:19:00.099 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to symbol: 5 SEHK
2024-09-13 01:19:00.099 [INFO] [Thread-ConsumeBidirectionalStream] - GET https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search {'params': {'symbol': '5'}}
2024-09-13 01:19:00.101 [DEBUG] [Thread-ConsumeBidirectionalStream] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000

2024-09-13 01:19:00.402 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:00.427 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.023973703384399414 seconds.
2024-09-13 01:19:00.439 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:00.464 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.02366495132446289 seconds.
2024-09-13 01:19:00.639 [DEBUG] [Thread-ConsumeBidirectionalStream] - https://ibeam.ibeam.svc.cluster.local:5000 "GET /v1/api/iserver/secdef/search?symbol=5 HTTP/11" 200 None
2024-09-13 01:19:00.643 [DEBUG] [Thread-ConsumeBidirectionalStream] - Search result for 5: Result(data=[{'conid': '1616390', 'companyHeader': 'HSBC HOLDINGS PLC - SEHK', 'companyName': 'HSBC HOLDINGS PLC', 'symbol': '5', 'description': 'SEHK', 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK', 'exchange': 'SEHK;'}, {'secType': 'FUT', 'months': 'SEP24;OCT24;NOV24;DEC24;MAR25', 'exchange': 'HKFE'}, {'secType': 'OPT', 'months': 'SEP24;OCT24;NOV24;DEC24;MAR25;JUN25;SEP25', 'exchange': 'SEHK'}, {'secType': 'WAR', 'months': 'SEP24;OCT24;NOV24;DEC24;JAN25;FEB25;MAR25;APR25;MAY25;JUN25;SEP25;NOV28;DEC28', 'exchange': 'SEHK'}, {'secType': 'IOPT'}, {'secType': 'CFD', 'exchange': 'SMART', 'conid': '190006136'}, {'secType': 'BAG', 'exchange': 'HKFE', 'legSecType': 'FUT'}, {'secType': 'BAG', 'exchange': 'SEHK', 'legSecType': 'OPT'}]}, {'issuers': [{'id': 'e1669439', 'name': 'Barion Funding Ltd'}, {'id': 'e1360720', 'name': 'HSBC Bank PLC'}, {'id': 'e1416054', 'name': 'HSBC Holdings PLC'}, {'id': 'e3375601', 'name': 'HSBC UK Bank PLC'}, {'id': 'e1669442', 'name': 'Malachite Funding Ltd'}, {'id': 'e1669440', 'name': 'Mazarin Funding Ltd'}], 'bondid': 1, 'conid': '2147483647', 'companyHeader': 'Corporate Fixed Income', 'companyName': None, 'symbol': None, 'description': None, 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'BOND'}]}], request={'url': 'https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search', 'params': {'symbol': '5'}})
2024-09-13 01:19:00.644 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to 5 (conid: 1616390)
2024-09-13 01:19:00,845|I| IbkrWsClient: Subscribed: smd+1616390+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:19:00.845 [INFO] [Thread-ConsumeBidirectionalStream] - IbkrWsClient: Subscribed: smd+1616390+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:19:00.846 [INFO] [Thread-ConsumeBidirectionalStream] - Successfully subscribed to 5 on SEHK
2024-09-13 01:19:00.846 [INFO] [Thread-ConsumeBidirectionalStream] - Change type: ADDED, Document ID: loiOqtH4LlLchGzyrooT
2024-09-13 01:19:00.847 [INFO] [Thread-ConsumeBidirectionalStream] - Document data: {'symbol': '9618', 'exchange': 'SEHK'}
2024-09-13 01:19:00.848 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to symbol: 9618 SEHK
2024-09-13 01:19:00.848 [INFO] [Thread-ConsumeBidirectionalStream] - Change type: ADDED, Document ID: nMPzwSJcqAqwVhq6JJTU
2024-09-13 01:19:00.849 [INFO] [Thread-ConsumeBidirectionalStream] - Document data: {'lastUpdated': DatetimeWithNanoseconds(2024, 8, 24, 14, 34, 47, 848000, tzinfo=datetime.timezone.utc), 'ticker': '9901', 'exchange': 'SEHK'}
2024-09-13 01:19:00.850 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to symbol: 9901 SEHK
2024-09-13 01:19:00.850 [INFO] [Thread-ConsumeBidirectionalStream] - GET https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search {'params': {'symbol': '9901'}}
2024-09-13 01:19:00.853 [DEBUG] [Thread-ConsumeBidirectionalStream] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000
2024-09-13 01:19:00.876 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:00.908 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.02989053726196289 seconds.
2024-09-13 01:19:00.921 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up

2024-09-13 01:19:00.978 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.05539584159851074 seconds.
2024-09-13 01:19:01.089 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:01.113 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.02233433723449707 seconds.
2024-09-13 01:19:01.124 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:01.150 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.024403095245361328 seconds.
2024-09-13 01:19:01.252 [DEBUG] [Thread-ConsumeBidirectionalStream] - https://ibeam.ibeam.svc.cluster.local:5000 "GET /v1/api/iserver/secdef/search?symbol=9901 HTTP/11" 200 None
2024-09-13 01:19:01.256 [DEBUG] [Thread-ConsumeBidirectionalStream] - Search result for 9901: Result(data=[{'conid': '478596149', 'companyHeader': 'NEW ORIENTAL EDUCATION & TEC - SEHK', 'companyName': 'NEW ORIENTAL EDUCATION & TEC', 'symbol': '9901', 'description': 'SEHK', 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK', 'exchange': 'SEHK;'}, {'secType': 'WAR', 'months': 'APR25', 'exchange': 'SEHK'}, {'secType': 'CFD', 'exchange': 'SMART', 'conid': '457224826'}]}, {'issuers': [{'id': 'e1424943', 'name': 'New Oriental Education & Technology Group Inc'}], 'bondid': 1, 'conid': '2147483647', 'companyHeader': 'Corporate Fixed Income', 'companyName': None, 'symbol': 'EDU', 'description': None, 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'BOND'}]}], request={'url': 'https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search', 'params': {'symbol': '9901'}})
2024-09-13 01:19:01.257 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to 9901 (conid: 478596149)
2024-09-13 01:19:01,458|I| IbkrWsClient: Subscribed: smd+478596149+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:19:01.458 [INFO] [Thread-ConsumeBidirectionalStream] - IbkrWsClient: Subscribed: smd+478596149+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:19:01.459 [INFO] [Thread-ConsumeBidirectionalStream] - Successfully subscribed to 9901 on SEHK
2024-09-13 01:19:01.459 [INFO] [Thread-ConsumeBidirectionalStream] - Change type: ADDED, Document ID: o1xdItV8XRYBBXbnYadB
2024-09-13 01:19:01.460 [INFO] [Thread-ConsumeBidirectionalStream] - Document data: {'lastUpdated': DatetimeWithNanoseconds(2024, 8, 24, 14, 34, 46, 530000, tzinfo=datetime.timezone.utc), 'ticker': '9626', 'exchange': 'SEHK'}
2024-09-13 01:19:01.460 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to symbol: 9626 SEHK
2024-09-13 01:19:01.460 [INFO] [Thread-ConsumeBidirectionalStream] - GET https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search {'params': {'symbol': '9626'}}
2024-09-13 01:19:01.462 [DEBUG] [Thread-ConsumeBidirectionalStream] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000
2024-09-13 01:19:01.464 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:01.490 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.02561187744140625 seconds.
2024-09-13 01:19:01.502 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:01.526 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.02165699005126953 seconds.

2024-09-13 01:19:01.537 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:01.568 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.029134750366210938 seconds.
2024-09-13 01:19:01.865 [DEBUG] [Thread-ConsumeBidirectionalStream] - https://ibeam.ibeam.svc.cluster.local:5000 "GET /v1/api/iserver/secdef/search?symbol=9626 HTTP/11" 200 None
2024-09-13 01:19:01.868 [DEBUG] [Thread-ConsumeBidirectionalStream] - Search result for 9626: Result(data=[{'conid': '477963416', 'companyHeader': 'BILIBILI INC-CLASS Z - SEHK', 'companyName': 'BILIBILI INC-CLASS Z', 'symbol': '9626', 'description': 'SEHK', 'restricted': 'IOPT', 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK', 'exchange': 'SEHK;'}, {'secType': 'FUT', 'months': 'SEP24;OCT24;NOV24;DEC24;MAR25', 'exchange': 'HKFE'}, {'secType': 'OPT', 'months': 'SEP24;OCT24;NOV24;DEC24;MAR25;JUN25;SEP25', 'exchange': 'SEHK'}, {'secType': 'WAR', 'months': 'SEP24;DEC24;JAN25;FEB25;APR25;JUN25', 'exchange': 'SEHK'}, {'secType': 'IOPT'}, {'secType': 'CFD', 'exchange': 'SMART', 'conid': '491797867'}, {'secType': 'BAG', 'exchange': 'HKFE', 'legSecType': 'FUT'}, {'secType': 'BAG', 'exchange': 'SEHK', 'legSecType': 'OPT'}]}], request={'url': 'https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search', 'params': {'symbol': '9626'}})
2024-09-13 01:19:01.869 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to 9626 (conid: 477963416)
2024-09-13 01:19:01.980 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:02.004 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.023114442825317383 seconds.
2024-09-13 01:19:02.016 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:02.042 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.025721073150634766 seconds.
2024-09-13 01:19:02.055 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:02,070|I| IbkrWsClient: Subscribed: smd+477963416+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:19:02.070 [INFO] [Thread-ConsumeBidirectionalStream] - IbkrWsClient: Subscribed: smd+477963416+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:19:02.071 [INFO] [Thread-ConsumeBidirectionalStream] - Successfully subscribed to 9626 on SEHK
2024-09-13 01:19:02.071 [INFO] [Thread-ConsumeBidirectionalStream] - Change type: ADDED, Document ID: pbnkwEL9MqD7tgdJ3Pgl
2024-09-13 01:19:02.072 [INFO] [Thread-ConsumeBidirectionalStream] - Document data: {'lastUpdated': DatetimeWithNanoseconds(2024, 8, 24, 14, 34, 47, 954000, tzinfo=datetime.timezone.utc), 'ticker': '9896', 'exchange': 'SEHK'}
2024-09-13 01:19:02.072 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to symbol: 9896 SEHK
2024-09-13 01:19:02.072 [INFO] [Thread-ConsumeBidirectionalStream] - GET https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search {'params': {'symbol': '9896'}}
2024-09-13 01:19:02.074 [DEBUG] [Thread-ConsumeBidirectionalStream] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000
2024-09-13 01:19:02.081 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.025518417358398438 seconds.

2024-09-13 01:19:02.193 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:02.252 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.058260440826416016 seconds.
2024-09-13 01:19:02.263 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:02.287 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.022574663162231445 seconds.
2024-09-13 01:19:02.299 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:02.324 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.024208545684814453 seconds.
2024-09-13 01:19:02.388 [DEBUG] [Thread-ConsumeBidirectionalStream] - https://ibeam.ibeam.svc.cluster.local:5000 "GET /v1/api/iserver/secdef/search?symbol=9896 HTTP/11" 200 None
2024-09-13 01:19:02.392 [DEBUG] [Thread-ConsumeBidirectionalStream] - Search result for 9896: Result(data=[{'conid': '571503160', 'companyHeader': 'MINISO GROUP HOLDING LTD - SEHK', 'companyName': 'MINISO GROUP HOLDING LTD', 'symbol': '9896', 'description': 'SEHK', 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK', 'exchange': 'SEHK;'}, {'secType': 'WAR', 'months': 'DEC25', 'exchange': 'SEHK'}, {'secType': 'CFD', 'exchange': 'SMART', 'conid': '619477533'}]}, {'conid': '14032827', 'companyHeader': 'JK HOLDINGS CO LTD - TSEJ', 'companyName': 'JK HOLDINGS CO LTD', 'symbol': '9896', 'description': 'TSEJ', 'restricted': 'STK', 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK'}]}], request={'url': 'https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search', 'params': {'symbol': '9896'}})
2024-09-13 01:19:02.393 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to 9896 (conid: 571503160)
2024-09-13 01:19:02.436 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:02.460 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.022557497024536133 seconds.
2024-09-13 01:19:02.471 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:02.497 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.02494335174560547 seconds.
2024-09-13 01:19:02.509 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:02.535 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.02517223358154297 seconds.
2024-09-13 01:19:02.547 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:02.571 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.02299785614013672 seconds.
2024-09-13 01:19:02,594|I| IbkrWsClient: Subscribed: smd+571503160+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:19:02.594 [INFO] [Thread-ConsumeBidirectionalStream] - IbkrWsClient: Subscribed: smd+571503160+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:19:02.595 [INFO] [Thread-ConsumeBidirectionalStream] - Successfully subscribed to 9896 on SEHK
2024-09-13 01:19:02.596 [INFO] [Thread-ConsumeBidirectionalStream] - Change type: ADDED, Document ID: uNySo7cIaDAmYNxLPeOs
2024-09-13 01:19:02.596 [INFO] [Thread-ConsumeBidirectionalStream] - Document data: {'lastUpdated': DatetimeWithNanoseconds(2024, 8, 24, 14, 34, 46, 242000, tzinfo=datetime.timezone.utc), 'ticker': '2015', 'exchange': 'SEHK'}
2024-09-13 01:19:02.596 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to symbol: 2015 SEHK
2024-09-13 01:19:02.597 [INFO] [Thread-ConsumeBidirectionalStream] - GET https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search {'params': {'symbol': '2015'}}
2024-09-13 01:19:02.599 [DEBUG] [Thread-ConsumeBidirectionalStream] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000

2024-09-13 01:19:02.683 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:02.705 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.020441532135009766 seconds.
2024-09-13 01:19:02.716 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:02.739 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.021806001663208008 seconds.
2024-09-13 01:19:02.950 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:02.975 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.024480104446411133 seconds.
2024-09-13 01:19:02.987 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:03.005 [DEBUG] [Thread-ConsumeBidirectionalStream] - https://ibeam.ibeam.svc.cluster.local:5000 "GET /v1/api/iserver/secdef/search?symbol=2015 HTTP/11" 200 None
2024-09-13 01:19:03.009 [DEBUG] [Thread-ConsumeBidirectionalStream] - Search result for 2015: Result(data=[{'conid': '506568272', 'companyHeader': 'LI AUTO INC-CLASS A - SEHK', 'companyName': 'LI AUTO INC-CLASS A', 'symbol': '2015', 'description': 'SEHK', 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK', 'exchange': 'SEHK;'}, {'secType': 'FUT', 'months': 'SEP24;OCT24;NOV24;DEC24;MAR25', 'exchange': 'HKFE'}, {'secType': 'OPT', 'months': 'SEP24;OCT24;NOV24;DEC24;MAR25;JUN25;SEP25', 'exchange': 'SEHK'}, {'secType': 'WAR', 'months': 'SEP24;OCT24;NOV24;DEC24;JAN25;MAR25;APR25;SEP25', 'exchange': 'SEHK'}, {'secType': 'IOPT'}, {'secType': 'CFD', 'exchange': 'SMART', 'conid': '519076020'}, {'secType': 'BAG', 'exchange': 'HKFE', 'legSecType': 'FUT'}, {'secType': 'BAG', 'exchange': 'SEHK', 'legSecType': 'OPT'}]}, {'conid': '676414434', 'companyHeader': 'IFREEETF US TRE BD 7-10 Y NH - TSEJ', 'companyName': 'IFREEETF US TRE BD 7-10 Y NH', 'symbol': '2015', 'description': 'TSEJ', 'restricted': 'STK', 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK'}]}, {'conid': '39130348', 'companyHeader': 'FENG HSIN STEEL CO LTD - TWSE', 'companyName': 'FENG HSIN STEEL CO LTD', 'symbol': '2015', 'description': 'TWSE', 'restricted': 'STK', 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK', 'exchange': 'TWSE;'}]}], request={'url': 'https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search', 'params': {'symbol': '2015'}})
2024-09-13 01:19:03.010 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.021907567977905273 seconds.
2024-09-13 01:19:03.010 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to 2015 (conid: 506568272)
2024-09-13 01:19:03.022 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:03.052 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.028696060180664062 seconds.
2024-09-13 01:19:03.163 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:03,212|I| IbkrWsClient: Subscribed: smd+506568272+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:19:03.212 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.048212528228759766 seconds.
2024-09-13 01:19:03.212 [INFO] [Thread-ConsumeBidirectionalStream] - IbkrWsClient: Subscribed: smd+506568272+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:19:03.214 [INFO] [Thread-ConsumeBidirectionalStream] - Successfully subscribed to 2015 on SEHK
2024-09-13 01:19:03.214 [INFO] [Thread-ConsumeBidirectionalStream] - Change type: ADDED, Document ID: uV1twRfzq1cS5y54tjJK
2024-09-13 01:19:03.215 [INFO] [Thread-ConsumeBidirectionalStream] - Document data: {'lastUpdated': DatetimeWithNanoseconds(2024, 8, 24, 14, 34, 46, 871000, tzinfo=datetime.timezone.utc), 'ticker': '9988', 'exchange': 'SEHK'}
2024-09-13 01:19:03.215 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to symbol: 9988 SEHK
2024-09-13 01:19:03.216 [INFO] [Thread-ConsumeBidirectionalStream] - GET https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search {'params': {'symbol': '9988'}}
2024-09-13 01:19:03.217 [DEBUG] [Thread-ConsumeBidirectionalStream] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000
2024-09-13 01:19:03.224 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:03.252 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.026982784271240234 seconds.
2024-09-13 01:19:03.264 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up

2024-09-13 01:19:03.293 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.028208017349243164 seconds.
2024-09-13 01:19:03.305 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:03.335 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.029334545135498047 seconds.
2024-09-13 01:19:03.347 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:03.394 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.04689311981201172 seconds.
2024-09-13 01:19:03.641 [DEBUG] [Thread-ConsumeBidirectionalStream] - https://ibeam.ibeam.svc.cluster.local:5000 "GET /v1/api/iserver/secdef/search?symbol=9988 HTTP/11" 200 None
2024-09-13 01:19:03.644 [DEBUG] [Thread-ConsumeBidirectionalStream] - Search result for 9988: Result(data=[{'conid': '391638829', 'companyHeader': 'ALIBABA GROUP HOLDING LTD - SEHK', 'companyName': 'ALIBABA GROUP HOLDING LTD', 'symbol': '9988', 'description': 'SEHK', 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK', 'exchange': 'SEHK;'}, {'secType': 'FUT', 'months': 'SEP24;OCT24;NOV24;DEC24;MAR25', 'exchange': 'HKFE'}, {'secType': 'OPT', 'months': 'SEP24;OCT24;NOV24;DEC24;MAR25;JUN25;SEP25', 'exchange': 'SEHK'}, {'secType': 'WAR', 'months': 'SEP24;OCT24;NOV24;DEC24;FEB25;MAR25;APR25;JUN25;JUL25;SEP25;DEC25;JUN28;DEC28', 'exchange': 'SEHK'}, {'secType': 'IOPT'}, {'secType': 'CFD', 'exchange': 'SMART', 'conid': '393223446'}, {'secType': 'BAG', 'exchange': 'HKFE', 'legSecType': 'FUT'}, {'secType': 'BAG', 'exchange': 'SEHK', 'legSecType': 'OPT'}]}, {'issuers': [{'id': 'e1648825', 'name': 'Alibaba Group Holding Ltd'}], 'bondid': 1, 'conid': '2147483647', 'companyHeader': 'Corporate Fixed Income', 'companyName': None, 'symbol': 'BABA', 'description': None, 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'BOND'}]}], request={'url': 'https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search', 'params': {'symbol': '9988'}})
2024-09-13 01:19:03.645 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to 9988 (conid: 391638829)
2024-09-13 01:19:03.806 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:03.840 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.032782554626464844 seconds.
2024-09-13 01:19:03,846|I| IbkrWsClient: Subscribed: smd+391638829+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:19:03.846 [INFO] [Thread-ConsumeBidirectionalStream] - IbkrWsClient: Subscribed: smd+391638829+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:19:03.847 [INFO] [Thread-ConsumeBidirectionalStream] - Successfully subscribed to 9988 on SEHK
2024-09-13 01:19:03.848 [INFO] [Thread-ConsumeBidirectionalStream] - Change type: ADDED, Document ID: uySJr8nAmZKppRsZeWeM
2024-09-13 01:19:03.848 [INFO] [Thread-ConsumeBidirectionalStream] - Document data: {'lastUpdated': DatetimeWithNanoseconds(2024, 8, 24, 14, 34, 48, 43000, tzinfo=datetime.timezone.utc), 'ticker': '1698', 'exchange': 'SEHK'}
2024-09-13 01:19:03.848 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to symbol: 1698 SEHK
2024-09-13 01:19:03.849 [INFO] [Thread-ConsumeBidirectionalStream] - GET https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search {'params': {'symbol': '1698'}}
2024-09-13 01:19:03.851 [DEBUG] [Thread-ConsumeBidirectionalStream] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000
2024-09-13 01:19:03.851 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:03.877 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.02509021759033203 seconds.
2024-09-13 01:19:03.889 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:03.916 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.02553081512451172 seconds.

2024-09-13 01:19:03.928 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:03.958 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.028862953186035156 seconds.
2024-09-13 01:19:03.970 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:03.993 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.022876977920532227 seconds.
2024-09-13 01:19:04.072 [DEBUG] [Thread-ConsumeBidirectionalStream] - https://ibeam.ibeam.svc.cluster.local:5000 "GET /v1/api/iserver/secdef/search?symbol=1698 HTTP/11" 200 None
2024-09-13 01:19:04.075 [DEBUG] [Thread-ConsumeBidirectionalStream] - Search result for 1698: Result(data=[{'conid': '586243703', 'companyHeader': 'TENCENT MUSIC ENT - CLASS A - SEHK', 'companyName': 'TENCENT MUSIC ENT - CLASS A', 'symbol': '1698', 'description': 'SEHK', 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK', 'exchange': 'SEHK;'}]}, {'conid': '131086405', 'companyHeader': 'JAPAN HIGH D TSE DIVS FO 100 - TSEJ', 'companyName': 'JAPAN HIGH D TSE DIVS FO 100', 'symbol': '1698', 'description': 'TSEJ', 'restricted': 'STK', 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'STK'}]}, {'issuers': [{'id': 'e1401278', 'name': 'Tencent Holdings Ltd'}, {'id': 'e3297296', 'name': 'Tencent Music Entertainment Group'}], 'bondid': 2, 'conid': '2147483647', 'companyHeader': 'Corporate Fixed Income', 'companyName': None, 'symbol': None, 'description': None, 'restricted': None, 'fop': None, 'opt': None, 'war': None, 'sections': [{'secType': 'BOND'}]}], request={'url': 'https://ibeam.ibeam.svc.cluster.local:5000/v1/api/iserver/secdef/search', 'params': {'symbol': '1698'}})
2024-09-13 01:19:04.075 [INFO] [Thread-ConsumeBidirectionalStream] - Subscribing to 1698 (conid: 586243703)
2024-09-13 01:19:04.105 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:04.137 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.030986785888671875 seconds.
2024-09-13 01:19:04.148 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:04.247 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.09817028045654297 seconds.
2024-09-13 01:19:04.259 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:04,276|I| IbkrWsClient: Subscribed: smd+586243703+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:19:04.276 [INFO] [Thread-ConsumeBidirectionalStream] - IbkrWsClient: Subscribed: smd+586243703+{"fields": ["55", "31", "84", "86", "88", "85", "87", "82", "83", "7762"], "outsideRth": true}
2024-09-13 01:19:04.279 [INFO] [Thread-ConsumeBidirectionalStream] - Successfully subscribed to 1698 on SEHK
2024-09-13 01:19:04.279 [DEBUG] [Thread-ConsumeBidirectionalStream] - waiting for recv.
2024-09-13 01:19:04.281 [DEBUG] [Thread-ConsumeBidirectionalStream] - recved response.
2024-09-13 01:19:04.281 [DEBUG] [Thread-ConsumeBidirectionalStream] - on_snapshot: filter update
2024-09-13 01:19:04.281 [DEBUG] [Thread-ConsumeBidirectionalStream] - waiting for recv.
2024-09-13 01:19:04.282 [DEBUG] [Thread-ConsumeBidirectionalStream] - recved response.
2024-09-13 01:19:04.282 [DEBUG] [Thread-ConsumeBidirectionalStream] - on_snapshot: target change: 0
2024-09-13 01:19:04.283 [DEBUG] [Thread-ConsumeBidirectionalStream] - on_snapshot: target change: NO_CHANGE
2024-09-13 01:19:04.283 [DEBUG] [Thread-ConsumeBidirectionalStream] - walk over add_changes
2024-09-13 01:19:04.283 [DEBUG] [Thread-ConsumeBidirectionalStream] - waiting for recv.
2024-09-13 01:19:04.299 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.03972887992858887 seconds.
2024-09-13 01:19:04.311 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:04.338 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.02617502212524414 seconds.
2024-09-13 01:19:04.450 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:19:04.478 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.026584148406982422 seconds.
2024-09-13 01:19:04.489 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:30:51.904 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:30:51.913 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.007851362228393555 seconds.
2024-09-13 01:30:51.924 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:30:51.941 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.015981674194335938 seconds.
2024-09-13 01:30:52.675 [DEBUG] [Thread-2 (_send_ping)] - Sending ping
2024-09-13 01:30:52.855 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:30:52.863 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.007778167724609375 seconds.
2024-09-13 01:30:53.378 [DEBUG] [AnyIO worker thread] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000

2024-09-13 01:30:53.508 [DEBUG] [AnyIO worker thread] - https://ibeam.ibeam.svc.cluster.local:5000 "POST /v1/api/tickle HTTP/11" 200 None
INFO:     10.28.3.13:46470 - "GET /health HTTP/1.1" 200 OK
2024-09-13 01:30:53.676 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:30:53.683 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.0064983367919921875 seconds.
2024-09-13 01:30:53.695 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:30:53.704 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.008946895599365234 seconds.
2024-09-13 01:30:53.958 [DEBUG] [Thread-ConsumeBidirectionalStream] - recved response.
2024-09-13 01:30:53.959 [DEBUG] [Thread-ConsumeBidirectionalStream] - on_snapshot: target change: 0
2024-09-13 01:30:53.959 [DEBUG] [Thread-ConsumeBidirectionalStream] - on_snapshot: target change: NO_CHANGE
2024-09-13 01:30:53.960 [DEBUG] [Thread-ConsumeBidirectionalStream] - walk over add_changes
2024-09-13 01:30:53.960 [DEBUG] [Thread-ConsumeBidirectionalStream] - waiting for recv.
2024-09-13 01:30:54.218 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:30:54.230 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.010928869247436523 seconds.
2024-09-13 01:30:54.243 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:30:54.262 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.017499446868896484 seconds.
2024-09-13 01:30:54.777 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:30:54.803 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.025643587112426758 seconds.
2024-09-13 01:30:54.804 [DEBUG] [Thread-4 (process_ticker_data)] - Published 393 messages in the last minute
2024-09-13 01:30:54.815 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:31:18.445 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.008169174194335938 seconds.
2024-09-13 01:31:18.457 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:31:18.467 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.009732246398925781 seconds.
2024-09-13 01:31:18.478 [DEBUG] [Thread-PubSubBatchCommitter] - Commit thread is waking up
2024-09-13 01:31:18.497 [DEBUG] [Thread-CommitBatchPublisher] - gRPC Publish took 0.017555952072143555 seconds.
2024-09-13 01:31:18,825|E| IbkrWsClient: Status unauthenticated: {'authenticated': False}
2024-09-13 01:31:18.825 [ERROR] [ws_client_thread] - IbkrWsClient: Status unauthenticated: {'authenticated': False}
2024-09-13 01:31:18.827 [DEBUG] [ws_client_thread] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000

2024-09-13 01:31:19.175 [DEBUG] [ws_client_thread] - https://ibeam.ibeam.svc.cluster.local:5000 "POST /v1/api/tickle HTTP/11" 200 None
2024-09-13 01:31:19,179|I| IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'competing': False}}
2024-09-13 01:31:19.179 [INFO] [ws_client_thread] - IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'competing': False}}
2024-09-13 01:31:19,180|I| IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'message': ''}}
2024-09-13 01:31:19.180 [INFO] [ws_client_thread] - IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'message': ''}}
2024-09-13 01:31:19,180|E| IbkrWsClient: Status unauthenticated: {'authenticated': False}
2024-09-13 01:31:19.180 [ERROR] [ws_client_thread] - IbkrWsClient: Status unauthenticated: {'authenticated': False}
2024-09-13 01:31:19.182 [DEBUG] [ws_client_thread] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000

2024-09-13 01:31:19.319 [DEBUG] [ws_client_thread] - https://ibeam.ibeam.svc.cluster.local:5000 "POST /v1/api/tickle HTTP/11" 200 None
2024-09-13 01:31:19,322|E| IbkrWsClient: Status unauthenticated: {'authenticated': False}
2024-09-13 01:31:19.322 [ERROR] [ws_client_thread] - IbkrWsClient: Status unauthenticated: {'authenticated': False}
2024-09-13 01:31:19.324 [DEBUG] [ws_client_thread] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000

2024-09-13 01:31:19.457 [DEBUG] [ws_client_thread] - https://ibeam.ibeam.svc.cluster.local:5000 "POST /v1/api/tickle HTTP/11" 200 None
2024-09-13 01:31:19,461|I| IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'competing': False}}
2024-09-13 01:31:19.461 [INFO] [ws_client_thread] - IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'competing': False}}
2024-09-13 01:31:19,462|I| IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'message': ''}}
2024-09-13 01:31:19.462 [INFO] [ws_client_thread] - IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'message': ''}}
2024-09-13 01:31:19,462|E| IbkrWsClient: on_message error: {'error': 'Topic unknown \'{"s\'', 'code': 1, 'topic': '{"s'}
2024-09-13 01:31:19.462 [ERROR] [ws_client_thread] - IbkrWsClient: on_message error: {'error': 'Topic unknown \'{"s\'', 'code': 1, 'topic': '{"s'}
2024-09-13 01:31:19,463|E| IbkrWsClient: on_message error: {'error': 'Topic unknown \'{"s\'', 'code': 1, 'topic': '{"s'}
2024-09-13 01:31:19.463 [ERROR] [ws_client_thread] - IbkrWsClient: on_message error: {'error': 'Topic unknown \'{"s\'', 'code': 1, 'topic': '{"s'}
2024-09-13 01:31:19,536|E| IbkrWsClient: on_message error: {'error': 'Topic unknown \'{"s\'', 'code': 1, 'topic': '{"s'}
2024-09-13 01:31:19.536 [ERROR] [ws_client_thread] - IbkrWsClient: on_message error: {'error': 'Topic unknown \'{"s\'', 'code': 1, 'topic': '{"s'}
2024-09-13 01:31:37.676 [DEBUG] [Thread-2 (_send_ping)] - Sending ping
2024-09-13 01:31:38.965 [DEBUG] [Thread-ConsumeBidirectionalStream] - recved response.
2024-09-13 01:31:38.966 [DEBUG] [Thread-ConsumeBidirectionalStream] - on_snapshot: target change: 0
2024-09-13 01:31:38.966 [DEBUG] [Thread-ConsumeBidirectionalStream] - on_snapshot: target change: NO_CHANGE
2024-09-13 01:31:38.967 [DEBUG] [Thread-ConsumeBidirectionalStream] - walk over add_changes
2024-09-13 01:31:38.967 [DEBUG] [Thread-ConsumeBidirectionalStream] - waiting for recv.
2024-09-13 01:31:50,078|E| IbkrWsClient: Status unauthenticated: {'authenticated': False}
2024-09-13 01:31:50.078 [ERROR] [ws_client_thread] - IbkrWsClient: Status unauthenticated: {'authenticated': False}
2024-09-13 01:31:50.080 [DEBUG] [ws_client_thread] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000

2024-09-13 01:31:50.242 [DEBUG] [ws_client_thread] - https://ibeam.ibeam.svc.cluster.local:5000 "POST /v1/api/tickle HTTP/11" 200 None
2024-09-13 01:31:50,247|I| IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'competing': False}}
2024-09-13 01:31:50.247 [INFO] [ws_client_thread] - IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'competing': False}}
2024-09-13 01:31:50,247|I| IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'message': ''}}
2024-09-13 01:31:50.247 [INFO] [ws_client_thread] - IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'message': ''}}
2024-09-13 01:31:50,248|E| IbkrWsClient: Status unauthenticated: {'authenticated': False}
2024-09-13 01:31:50.248 [ERROR] [ws_client_thread] - IbkrWsClient: Status unauthenticated: {'authenticated': False}
2024-09-13 01:31:50.250 [DEBUG] [ws_client_thread] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000

2024-09-13 01:31:50.452 [DEBUG] [ws_client_thread] - https://ibeam.ibeam.svc.cluster.local:5000 "POST /v1/api/tickle HTTP/11" 200 None
2024-09-13 01:31:50,456|E| IbkrWsClient: on_message error: {'error': 'Topic unknown \'{"s\'', 'code': 1, 'topic': '{"s'}
2024-09-13 01:31:50.456 [ERROR] [ws_client_thread] - IbkrWsClient: on_message error: {'error': 'Topic unknown \'{"s\'', 'code': 1, 'topic': '{"s'}
2024-09-13 01:31:50,492|E| IbkrWsClient: on_message error: {'error': 'Topic unknown \'{"s\'', 'code': 1, 'topic': '{"s'}
2024-09-13 01:31:50.492 [ERROR] [ws_client_thread] - IbkrWsClient: on_message error: {'error': 'Topic unknown \'{"s\'', 'code': 1, 'topic': '{"s'}
2024-09-13 01:31:53.533 [DEBUG] [AnyIO worker thread] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000

2024-09-13 01:31:53.660 [DEBUG] [AnyIO worker thread] - https://ibeam.ibeam.svc.cluster.local:5000 "POST /v1/api/tickle HTTP/11" 200 None
INFO:     10.28.3.13:34718 - "GET /health HTTP/1.1" 503 Service Unavailable
2024-09-13 01:32:22.676 [DEBUG] [Thread-2 (_send_ping)] - Sending ping
2024-09-13 01:32:23.972 [DEBUG] [Thread-ConsumeBidirectionalStream] - recved response.
2024-09-13 01:32:23.973 [DEBUG] [Thread-ConsumeBidirectionalStream] - on_snapshot: target change: 0
2024-09-13 01:32:23.973 [DEBUG] [Thread-ConsumeBidirectionalStream] - on_snapshot: target change: NO_CHANGE
2024-09-13 01:32:23.974 [DEBUG] [Thread-ConsumeBidirectionalStream] - walk over add_changes
2024-09-13 01:32:23.975 [DEBUG] [Thread-ConsumeBidirectionalStream] - waiting for recv.
2024-09-13 01:32:54.516 [DEBUG] [AnyIO worker thread] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000

2024-09-13 01:32:54.680 [DEBUG] [AnyIO worker thread] - https://ibeam.ibeam.svc.cluster.local:5000 "POST /v1/api/tickle HTTP/11" 200 None
INFO:     10.28.3.13:43202 - "GET /health HTTP/1.1" 200 OK
2024-09-13 01:33:07.678 [DEBUG] [Thread-2 (_send_ping)] - Sending ping
2024-09-13 01:33:08.977 [DEBUG] [Thread-ConsumeBidirectionalStream] - recved response.
2024-09-13 01:33:08.977 [DEBUG] [Thread-ConsumeBidirectionalStream] - on_snapshot: target change: 0
2024-09-13 01:33:08.977 [DEBUG] [Thread-ConsumeBidirectionalStream] - on_snapshot: target change: NO_CHANGE
2024-09-13 01:33:08.978 [DEBUG] [Thread-ConsumeBidirectionalStream] - walk over add_changes
2024-09-13 01:33:08.978 [DEBUG] [Thread-ConsumeBidirectionalStream] - waiting for recv.
2024-09-13 01:33:52.679 [DEBUG] [Thread-2 (_send_ping)] - Sending ping
2024-09-13 01:33:53.984 [DEBUG] [Thread-ConsumeBidirectionalStream] - recved response.
2024-09-13 01:33:53.985 [DEBUG] [Thread-ConsumeBidirectionalStream] - on_snapshot: target change: 0
2024-09-13 01:33:53.985 [DEBUG] [Thread-ConsumeBidirectionalStream] - on_snapshot: target change: NO_CHANGE
2024-09-13 01:33:53.986 [DEBUG] [Thread-ConsumeBidirectionalStream] - walk over add_changes
2024-09-13 01:33:53.986 [DEBUG] [Thread-ConsumeBidirectionalStream] - waiting for recv.
2024-09-13 01:33:55.487 [DEBUG] [AnyIO worker thread] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000

Voyz commented 2 months ago

Thanks for sharing these 👍 If I could ask you a favour: in the future if you would have a chance to disable or remove the Thread-ConsumeBidirectionalStream Thread-CommitBatchPublisher and Thread-PubSubBatchCommitter logs it would make it easier to debug this issue 🙏

As for the log itself - I cannot see any indication of the IbkrWsClient trying to reset the connection, which leads me to believe that something unexpected is happening here. Usually when these errors appeared, the ping and heartbeat would fail and after one minute cause the re-subscription of all channels. This isn't happening.

Strangely, your health endpoint starts returning 200 after a while, indicating that the connection seems to have restored itself, by itself.

In the log you attached I cannot see any websocket messages being consumed - I'm assuming you're doing it elsewhere and not outputting anything into this log. In the situation we're facing it would be useful to see when the data is coming in correctly, and when it stops. Can you either try adding message consumption logs to your log output, or confirm in which areas of the above log the data is coming through as expected and when not?

Lastly, if you detect such an anomaly using your health endpoint, you can call the hard_reset(restart=True) method by yourself. This should cause the connection to be dropped, re-established, and subscriptions to be remade.

Let me know how it goes 👍

Tsopic commented 1 month ago
2024-10-04 01:32:43,357|I| IbkrWsClient: Hard reset is closing the WebSocketApp
2024-10-04 01:32:43.357 [INFO] [AnyIO worker thread] - IbkrWsClient: Hard reset is closing the WebSocketApp
2024-10-04 01:32:43,360|I| IbkrWsClient: on_close
2024-10-04 01:32:43.360 [INFO] [ws_client_thread] - IbkrWsClient: on_close
2024-10-04 01:32:43,360|I| IbkrWsClient: Connection closed
2024-10-04 01:32:43.360 [INFO] [ws_client_thread] - IbkrWsClient: Connection closed
2024-10-04 01:32:43,361|D| IbkrWsClient: Thread stopped (ws_client_thread-134913042937536)
2024-10-04 01:32:43.361 [DEBUG] [ws_client_thread] - IbkrWsClient: Thread stopped (ws_client_thread-134913042937536)
2024-10-04 01:32:43,361|I| IbkrWsClient: Reconnecting
2024-10-04 01:32:43.361 [INFO] [ws_client_thread] - IbkrWsClient: Reconnecting
2024-10-04 01:32:43,362|I| IbkrWsClient: Trying to connect
2024-10-04 01:32:43.362 [INFO] [ws_client_thread] - IbkrWsClient: Trying to connect
2024-10-04 01:32:43,362|D| IbkrWsClient: Creating new WebSocketApp
2024-10-04 01:32:43.362 [DEBUG] [ws_client_thread] - IbkrWsClient: Creating new WebSocketApp
2024-10-04 01:32:43,363|D| IbkrWsClient: Thread started (ws_client_thread-134913034544832)
2024-10-04 01:32:43.363 [DEBUG] [ws_client_thread] - IbkrWsClient: Thread started (ws_client_thread-134913034544832)
2024-10-04 01:32:43.386 [INFO] [ws_client_thread] - Websocket connected
2024-10-04 01:32:43,387|I| IbkrWsClient: Connection open
2024-10-04 01:32:43.387 [INFO] [ws_client_thread] - IbkrWsClient: Connection open
2024-10-04 01:32:43,643|E| IbkrWsClient: Status unauthenticated: {'authenticated': False, 'competing': False, 'message': '', 'fail': '', 'serverName': 'JifN11121', 'serverVersion': 'Build 10.30.1p, Sep 26, 2024 3:48:55 PM', 'username': '*****'}
2024-10-04 01:32:43.643 [ERROR] [ws_client_thread] - IbkrWsClient: Status unauthenticated: {'authenticated': False, 'competing': False, 'message': '', 'fail': '', 'serverName': 'JifN11121', 'serverVersion': 'Build 10.30.1p, Sep 26, 2024 3:48:55 PM', 'username': )
2024-10-04 01:32:43.645 [DEBUG] [ws_client_thread] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000
/usr/local/lib/python3.11/site-packages/urllib3/connectionpool.py:1099: InsecureRequestWarning: Unverified HTTPS request is being made to host 'ibeam.ibeam.svc.cluster.local'. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.io/en/latest/advanced-usage.html#tls-warnings
  warnings.warn(
2024-10-04 01:32:43.870 [DEBUG] [ws_client_thread] - https://ibeam.ibeam.svc.cluster.local:5000 "POST /v1/api/tickle HTTP/11" 200 None
2024-10-04 01:32:43,982|E| IbkrWsClient: on_message error: {'error': 'Topic unknown \'{"s\'', 'code': 1, 'topic': '{"s'}
2024-10-04 01:32:43.982 [ERROR] [ws_client_thread] - IbkrWsClient: on_message error: {'error': 'Topic unknown \'{"s\'', 'code': 1, 'topic': '{"s'}
2024-10-04 01:32:48,370|E| IbkrWsClient: Hard reset close timeout
2024-10-04 01:32:48.370 [ERROR] [AnyIO worker thread] - IbkrWsClient: Hard reset close timeout
2024-10-04 01:32:48,371|W| IbkrWsClient: Abandoning current WebSocketApp that cannot be closed: <websocket._app.WebSocketApp object at 0x7ab3e86e9710>
2024-10-04 01:32:48.371 [WARNING] [AnyIO worker thread] - IbkrWsClient: Abandoning current WebSocketApp that cannot be closed: <websocket._app.WebSocketApp object at 0x7ab3e86e9710>
2024-10-04 01:32:48,371|I| IbkrWsClient: Forced restart
2024-10-04 01:32:48.371 [INFO] [AnyIO worker thread] - IbkrWsClient: Forced restart
2024-10-04 01:32:48,371|I| IbkrWsClient: Reconnecting
2024-10-04 01:32:48.371 [INFO] [AnyIO worker thread] - IbkrWsClient: Reconnecting
2024-10-04 01:32:48,372|W| IbkrWsClient: Thread already running: ws_client_thread-134913034544832
2024-10-04 01:32:48.372 [WARNING] [AnyIO worker thread] - IbkrWsClient: Thread already running: ws_client_thread-134913034544832
INFO:     10.28.4.16:46488 - "GET /health HTTP/1.1" 503 Service Unavailable
2024-10-04 01:32:48,388|E| IbkrWsClient: Invalid ws returned: <websocket._app.WebSocketApp object at 0x7ab3e86e9710> | expected: None
NoneType: None
2024-10-04 01:32:48.388 [ERROR] [ws_client_thread] - IbkrWsClient: Invalid ws returned: <websocket._app.WebSocketApp object at 0x7ab3e86e9710> | expected: None
NoneType: None
2024-10-04 01:32:58,386|E| IbkrWsClient: Invalid ws returned: <websocket._app.WebSocketApp object at 0x7ab3e86e9710> | expected: None
NoneType: None
Tsopic commented 1 month ago

@Voyz Logs, in the last comment, it is with the ard_reset(restart=True) method. Now it's complaining about Invalid WS returned

Tsopic commented 1 month ago

Could you point me in right direction how to catch this error in my client?

2024-10-04 01:32:43,982|E| IbkrWsClient: on_message error: {'error': 'Topic unknown \'{"s\'', 'code': 1, 'topic': '{"s'} 2

Would be useful to handle it then on client side

@Voyz

Voyz commented 1 month ago

I'm sorry @Tsopic I'm travelling at the moment. I should be able to investigate within the next couple of weeks. Thanks for bearing with me in the meantime and for keeping this thread active 👍

Voyz commented 1 month ago

Hey @Tsopic thanks for your patience 🙏

I've spent a while investigating the reason behind the 'Topic unknown \'{"s\'' and I've concluded that IBind was not responding correctly to authenticated=False in status message. Quite frankly, in the old documentation the way the connection guide was laid out was unclear to me. I've just reviewed the current docs and updated the code accordingly.

In short:

The rest of your log tells me that where you're calling hard_reset(True) you should actually call it with hard_reset(False). The restart happens automatically when the WebSocketApp is closed, and doesn't need to be initiated from hard_reset separately.

Try the ibind==0.1.8rc1 and let me know if it helps. Thanks for helping me catch this issue, this has been a great contribution 👍

Tsopic commented 1 month ago

Trying the ibind==0.1.8rc1

Will let know, in few days

Tsopic commented 4 weeks ago

Still encountering the same behavior with new ibind version.

2024-10-29 01:26:57,780|E| IbkrWsClient: Status unauthenticated: {'authenticated': False}
2024-10-29 01:26:57.780 [ERROR] [ws_client_thread] - IbkrWsClient: Status unauthenticated: {'authenticated': False}
2024-10-29 01:26:57,781|I| IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'competing': False}}
2024-10-29 01:26:57.781 [INFO] [ws_client_thread] - IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'competing': False}}
2024-10-29 01:26:57,781|I| IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'message': ''}}
2024-10-29 01:26:57.781 [INFO] [ws_client_thread] - IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'message': ''}}
2024-10-29 01:26:57,782|E| IbkrWsClient: Status unauthenticated: {'authenticated': False}
2024-10-29 01:26:57.782 [ERROR] [ws_client_thread] - IbkrWsClient: Status unauthenticated: {'authenticated': False}
2024-10-29 01:26:57,782|E| IbkrWsClient: Status unauthenticated: {'authenticated': False}
2024-10-29 01:26:57.782 [ERROR] [ws_client_thread] - IbkrWsClient: Status unauthenticated: {'authenticated': False}
2024-10-29 01:26:57,783|I| IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'competing': False}}
2024-10-29 01:26:57.783 [INFO] [ws_client_thread] - IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'competing': False}}
2024-10-29 01:26:57,784|I| IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'message': ''}}
2024-10-29 01:26:57.784 [INFO] [ws_client_thread] - IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'message': ''}}
2024-10-29 01:26:58.040 [DEBUG] [AnyIO worker thread] - Starting new HTTPS connection (1): ibeam.ibeam.svc.cluster.local:5000
/usr/local/lib/python3.11/site-packages/urllib3/connectionpool.py:1099: InsecureRequestWarning: Unverified HTTPS request is being made to host 'ibeam.ibeam.svc.cluster.local'. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.io/en/latest/advanced-usage.html#tls-warnings
  warnings.warn(
2024-10-29 01:26:58.269 [DEBUG] [AnyIO worker thread] - https://ibeam.ibeam.svc.cluster.local:5000 "POST /v1/api/tickle HTTP/11" 200 None
2024-10-29 01:26:58.272 [INFO] [AnyIO worker thread] - WebSocket ready: True, authenticated: True
INFO:     10.28.0.14:55896 - "GET /health HTTP/1.1" 200 OK

Attaching the latest state of health check endpoint code. Think it could use some simplification

.

def check_gateway_health() -> dict[str, Any]:
    try:
        authenticated = ibkr_client.check_health()
        return {
            "authenticated": authenticated,
            "message": "Gateway health check successful"
        }
    except Exception as e:
        return {"error": f"Gateway health check failed: {str(e)}"}

def check_websocket_health() -> dict[str, Any]:
    try:
        ws_client = ws_manager.get_client()
        if not ws_client:
            logger.error("WebSocket client not initialized")
            raise ApplicationExit("WebSocket client not initialized")

        ws_ready = ws_client.ready()
        ws_health = ws_client.check_health()

        # Handle ws_health as a boolean
        if isinstance(ws_health, bool):
            authenticated = ws_health
        else:
            authenticated = ws_health.get("authenticated", True)

        # Log the health status for debugging
        logger.info(f"WebSocket ready: {ws_ready}, authenticated: {authenticated}")

        # Check for unauthenticated status
        if not authenticated:
            logger.error("WebSocket client is unauthenticated")
            raise ApplicationExit("WebSocket client is unauthenticated")

        return {
            "ready": ws_ready,
            "healthy": {"authenticated": authenticated},
            "message": "WebSocket health check successful"
        }
    except Exception as e:
        logger.error(f"WebSocket health check failed: {str(e)}")
        raise ApplicationExit(f"WebSocket health check failed: {str(e)}")

@app.get("/health")
def health_check():
    gateway_health = check_gateway_health()
    ws_health = check_websocket_health()

    overall_status = "healthy"
    if "error" in gateway_health or "error" in ws_health:
        overall_status = "unhealthy"
        logger.error(f"Unhealthy status detected. Gateway: {gateway_health}, WebSocket: {ws_health}")
        raise ApplicationExit("Unhealthy status detected")
    # elif not gateway_health.get("authenticated", False) or not ws_health.get("healthy", False):
    #     overall_status = "degraded"
    #     logger.error(f"Degraded status detected. Gateway: {gateway_health}, WebSocket: {ws_health}")
    #     ws_manager.ws_client.hard_reset(False)
    #     raise ApplicationExit("Degraded status detected")

    response = {
        "status": overall_status,
        "gateway": gateway_health,
        "websocket": ws_health
    }

    if overall_status != "healthy":
        return JSONResponse(content=response, status_code=503)
    return response

Voyz commented 3 weeks ago

Many thanks fo reporting back, appreciate it 👍

Still encountering the same behavior with new ibind version.

When you say 'same', can you elaborate? From what I can see the 'Topic unknown \'{"s\'' seems to be solved, right? Just trying to make sure if that bit got fixed, or if you're still seeing it elsewhere.


Other than that I've just pushed 0.1.8rc2 with additions to handle these two:

IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'message': ''}}
bkrWsClient: Unknown status response: {'topic': 'sts', 'args': {'competing': False}}

As for the rest of your log - it seems to indicate that your session loses authentication and that needs to be fixed externally, possibly by IBeam. Then I can see a call to health server indicating that the authentication is restored. Does the IbkrWsClient proceed to output anything past that point? Have you attempted to use the websocket connection after that point, and if so to what result?


A separate interpretation could be that despite receiving authenticated:false on the WebSocket, IBeam doesn't report any issues. This could be either because A) it lags a tiny bit behind and will recognise the problem with unauthenticated session in a while, or B) it never receives any similar information indicating that the session lost its authentication.

If it's A) then I'd suggest that you send a few of these health-check requests over a course of a minute or two, and see what happens.

If it's B) then I have no idea what to do 😅 We'd have to talk to IBKR and ask them why does that happen.


Thanks for sharing your code too, it looks reasonable. Though here:

        ws_health = ws_client.check_health()

        # Handle ws_health as a boolean
        if isinstance(ws_health, bool):

I'm a little confused. Does check_health() ever return anything else than a bool?

Tsopic commented 3 weeks ago

By same I mean it still disconnects from the MD stream and does not successfully reestablish the streams.

By my definition, it would be solved when It's able to restart / resubscribe itself whenever the datastreams get interrupted. I was expecting this kind of behavior.

I'm now switching to 0.1.8rc2 and will get some results by end of next week. Where can I track the changes made to the code for 0.1.8rc2? @Voyz

I'm a little confused. Does check_health() ever return anything else than a bool?

I think I just added this to satisfy the linting tools for type check

Voyz commented 3 weeks ago

Okay, I think I've got some good news. I found the core issue here.

The IbkrWsClient has a lot of code in place to handle drops in connectivity, but it wasn't handling authentication drop as gracefully. While IBKR WS API sends a message when authentication is dropped, it doesn't send a message when authentication is restored, leaving us thinking that authentication continues to be false. I've spent a while to add a bunch of code for handling authentication drops.

In short, it will close the WS connection completely, as this will get it into a reauthentication loop, attempting to reopen and resubscribe every few seconds. Once the authentication is restored, this should eventually succeed.

I've tested it with Market Data channel and can report that it is restored successfully.

Please try the ibind-0.1.8rc3 and let me know if it helps.

2024-11-04 16:32:09,794|I| IbkrWsClient: Starting
2024-11-04 16:32:09,795|I| IbkrWsClient: Trying to connect
2024-11-04 16:32:09,795|D| IbkrWsClient: Creating new WebSocketApp
2024-11-04 16:32:10,044|D| IbkrWsClient: Thread started (ws_client_thread-25700)
2024-11-04 16:32:10,067|I| IbkrWsClient: Connection open
2024-11-04 16:32:12,152|I| IbkrWsClient: Subscribing reattempt (2/5) smd+265598+{"fields": ["55", "71", "84", "86", "88", "85", "87", "7295", "7296", "70"]}
2024-11-04 16:32:12,253|I| IbkrWsClient: Subscribed: smd+265598+{"fields": ["55", "71", "84", "86", "88", "85", "87", "7295", "7296", "70"]}
data: [RETURNED CHANNEL DATA]
data: [RETURNED CHANNEL DATA]

[NOTE - THIS IS WHERE I FORCE A DROP IN AUTHENTICATION]

2024-11-04 16:32:19,944|E| IbkrWsClient: Status unauthenticated: {'authenticated': False}
2024-11-04 16:32:19,944|W| IbkrWsClient: Not authenticated, closing WebSocketApp
2024-11-04 16:32:19,947|I| IbkrWsClient: on_close
2024-11-04 16:32:19,947|I| IbkrWsClient: Invalidated subscription: md+265598
2024-11-04 16:32:19,947|I| IbkrWsClient: Connection closed
2024-11-04 16:32:19,947|D| IbkrWsClient: Thread stopped (ws_client_thread-25700)
2024-11-04 16:32:19,947|I| IbkrWsClient: Reconnecting
2024-11-04 16:32:19,948|I| IbkrWsClient: Trying to connect
2024-11-04 16:32:19,948|D| IbkrWsClient: Creating new WebSocketApp
2024-11-04 16:32:20,090|D| IbkrWsClient: Thread started (ws_client_thread-26364)
2024-11-04 16:32:20,111|I| IbkrWsClient: Connection open
2024-11-04 16:32:20,361|E| IbkrWsClient: Status unauthenticated: {'authenticated': False, 'competing': False, 'message': '', 'fail': '', 'serverName': 'JifZ37090', 'serverVersion': 'Build 10.30.1y, Nov 1, 2024 1:41:18 PM', 'username': 'ancov851'}
2024-11-04 16:32:20,361|W| IbkrWsClient: Not authenticated, closing WebSocketApp
2024-11-04 16:32:20,364|I| IbkrWsClient: on_close
2024-11-04 16:32:20,364|I| IbkrWsClient: Connection closed
2024-11-04 16:32:20,364|D| IbkrWsClient: Thread stopped (ws_client_thread-26364)
data: [RETURNED CHANNEL DATA - NO IDEA WHY THIS STILL GOT RETURNED HERE AFTER LOSING AUTHENTICATION, BUT OH WELL]
2024-11-04 16:32:30,273|E| IbkrWsClient: Reconnecting and recreating subscriptions stopped due to lack of authentication.

[THE FOLLOWING BLOCK REPEATS INDICATING THAT THE CONNECTION GETS REESTABLISHED PERIODICALLY]
2024-11-04 16:32:30,304|I| IbkrWsClient: Reconnecting
2024-11-04 16:32:30,304|I| IbkrWsClient: Trying to connect
2024-11-04 16:32:30,304|D| IbkrWsClient: Creating new WebSocketApp
2024-11-04 16:32:30,868|D| IbkrWsClient: Thread started (ws_client_thread-26444)
2024-11-04 16:32:31,240|I| IbkrWsClient: Connection open
2024-11-04 16:32:31,302|E| IbkrWsClient: Status unauthenticated: {'authenticated': False, 'competing': False, 'message': '', 'fail': '', 'serverName': 'JifZ37090', 'serverVersion': 'Build 10.30.1y, Nov 1, 2024 1:41:18 PM', 'username': 'ancov851'}
2024-11-04 16:32:31,302|W| IbkrWsClient: Not authenticated, closing WebSocketApp
2024-11-04 16:32:31,409|I| IbkrWsClient: on_close
2024-11-04 16:32:31,409|I| IbkrWsClient: Connection closed
2024-11-04 16:32:31,409|D| IbkrWsClient: Thread stopped (ws_client_thread-26444)
2024-11-04 16:32:41,272|E| IbkrWsClient: Reconnecting and recreating subscriptions stopped due to lack of authentication.
[THE ABOVE BLOCK REPEATS INDICATING THAT THE CONNECTION GETS REESTABLISHED PERIODICALLY]

2024-11-04 16:32:41,317|I| IbkrWsClient: Reconnecting
2024-11-04 16:32:41,317|I| IbkrWsClient: Trying to connect
2024-11-04 16:32:41,317|D| IbkrWsClient: Creating new WebSocketApp
2024-11-04 16:32:41,752|D| IbkrWsClient: Thread started (ws_client_thread-13028)
2024-11-04 16:32:42,047|I| IbkrWsClient: Connection open
2024-11-04 16:32:42,140|E| IbkrWsClient: Status unauthenticated: {'authenticated': False, 'competing': False, 'message': '', 'fail': '', 'serverName': 'JifZ37090', 'serverVersion': 'Build 10.30.1y, Nov 1, 2024 1:41:18 PM', 'username': 'ancov851'}
2024-11-04 16:32:42,140|W| IbkrWsClient: Not authenticated, closing WebSocketApp
2024-11-04 16:32:42,202|I| IbkrWsClient: on_close
2024-11-04 16:32:42,202|I| IbkrWsClient: Connection closed
2024-11-04 16:32:42,202|D| IbkrWsClient: Thread stopped (ws_client_thread-13028)
2024-11-04 16:32:52,110|E| IbkrWsClient: Reconnecting and recreating subscriptions stopped due to lack of authentication.
2024-11-04 16:32:52,141|I| IbkrWsClient: Reconnecting
2024-11-04 16:32:52,141|I| IbkrWsClient: Trying to connect
2024-11-04 16:32:52,141|D| IbkrWsClient: Creating new WebSocketApp
2024-11-04 16:32:52,716|D| IbkrWsClient: Thread started (ws_client_thread-26112)
2024-11-04 16:32:52,932|I| IbkrWsClient: Connection open
2024-11-04 16:32:53,023|E| IbkrWsClient: Status unauthenticated: {'authenticated': False, 'competing': False, 'message': '', 'fail': '', 'serverName': 'JifZ37090', 'serverVersion': 'Build 10.30.1y, Nov 1, 2024 1:41:18 PM', 'username': 'ancov851'}
2024-11-04 16:32:53,038|W| IbkrWsClient: Not authenticated, closing WebSocketApp
2024-11-04 16:32:53,147|I| IbkrWsClient: on_close
2024-11-04 16:32:53,147|I| IbkrWsClient: Connection closed
2024-11-04 16:32:53,147|D| IbkrWsClient: Thread stopped (ws_client_thread-26112)
2024-11-04 16:33:03,051|E| IbkrWsClient: Reconnecting and recreating subscriptions stopped due to lack of authentication.
2024-11-04 16:33:03,083|I| IbkrWsClient: Reconnecting
2024-11-04 16:33:03,083|I| IbkrWsClient: Trying to connect
2024-11-04 16:33:03,099|D| IbkrWsClient: Creating new WebSocketApp
2024-11-04 16:33:03,655|D| IbkrWsClient: Thread started (ws_client_thread-6896)
2024-11-04 16:33:03,966|I| IbkrWsClient: Connection open
2024-11-04 16:33:07,158|I| IbkrWsClient: Unknown status response: {'topic': 'sts', 'args': {}}
2024-11-04 16:33:07,314|E| IbkrWsClient: Status unauthenticated: {'authenticated': False}
2024-11-04 16:33:07,314|W| IbkrWsClient: Not authenticated, closing WebSocketApp
2024-11-04 16:33:07,515|I| IbkrWsClient: on_close
2024-11-04 16:33:07,515|I| IbkrWsClient: Connection closed
2024-11-04 16:33:07,515|D| IbkrWsClient: Thread stopped (ws_client_thread-6896)
2024-11-04 16:33:14,018|E| IbkrWsClient: Reconnecting and recreating subscriptions stopped due to lack of authentication.

[FINAL RECONNECITON, THIS TIME SUCCESSFUL]
2024-11-04 16:33:14,049|I| IbkrWsClient: Reconnecting
2024-11-04 16:33:14,049|I| IbkrWsClient: Trying to connect
2024-11-04 16:33:14,049|D| IbkrWsClient: Creating new WebSocketApp
2024-11-04 16:33:14,717|D| IbkrWsClient: Thread started (ws_client_thread-26384)
2024-11-04 16:33:15,058|I| IbkrWsClient: Connection open
2024-11-04 16:33:15,167|I| IbkrWsClient: Recreating 1/1 subscriptions: {'md+265598': {'status': False, 'data': {'fields': ['55', '71', '84', '86', '88', '85', '87', '7295', '7296', '70']}, 'needs_confirmation': True, 'subscription_processor': None}}
data: [RETURNED CHANNEL DATA]
2024-11-04 16:33:15,422|I| IbkrWsClient: Subscribed: smd+265598+{"fields": ["55", "71", "84", "86", "88", "85", "87", "7295", "7296", "70"]}
data: [RETURNED CHANNEL DATA]

Where can I track the changes made to the code for 0.1.8rc2?

On the master branch.

Tsopic commented 3 weeks ago

Updated to 0.1.8rc3 will get results tmrw 💯

Tsopic commented 3 weeks ago

Heh :) It seems solved for now. I will monitor until Friday, and close this issue, if success keeps repeating 👍

Voyz commented 3 weeks ago

Music to my ears! Keep me posted, hopefully we got it this time 👍

Tsopic commented 2 weeks ago

Gonna keep monitoring it for one more week. Getting IBeam re-authentication flow happening more often now now, wanna pinpoint the scenario :)

Voyz commented 7 hours ago

hey @Tsopic do I understand it is sorted and the problem hasn't reoccurred?

Tsopic commented 7 hours ago

That's correct @Voyz :) I'll reopen when it reoccurs 👍

Voyz commented 7 hours ago

Fantastic! Many thanks for your patience and help with this issue. I'm glad we've managed to catch it 👏👏👏