Python Client Websockets: Delay in getting the first tick data

skaramo0osh
I'm using websockets (Python client library) to get real-time tick data. I subscribe to tick data at 9:15:00 AM but I receive the first tick data with a delay of anywhere between 300 milliseconds to 1300 milliseconds. This is very consistent irrespective of the number of instruments I subscribe to - I have tried from 1 to 100 instruments. I'm running the websocket client in threaded mode. Because of this delay, sometimes I don't get the correct opening prices for the instruments.

The following is an excerpt from my logs for 2024-04-15. Here, it shows that I have successfully subscribed to tick data at 09:15:00.017 (the print statement is after KiteTicker.subscribe() returns) but I receive the first tick only at 09:15:00.410. And, the tick is from 09:12:37 AM, which I understand can happen.

2024-04-15 09:15:00.006 (Thread-11 (run)): Tick data subscription: [1793, 3329, 758529, 2953217, 784129, 60417, 579329, 103425, 197633, 119553, 356865, 4561409, 617473, 975873]
2024-04-15 09:15:00.017 (Thread-11 (run)): ==> Successful
2024-04-15 09:15:00.410 (TickProc ): SAIL:last_price: 2024-04-15 09:12:37 152.9
The delay could be due to any of the following:
- Network latency
- Websocket implementation: The client library may introduce some overhead or delays in processing incoming messages. While debugging, I've observed multiple empty payloads in _on_message() method of KiteConnect ticker.py for 500-1000 milliseconds. This happens only after subscription and for the first tick data. I haven't seen any empty payloads after the first tick.
- Server-side processing: The server that sends tick data may have some processing overhead before it can send the data to clients. This could be due to aggregating data from multiple sources, performing calculations, or other server-side operations.

I don't think this is network latency because I haven't seen such delays with any other Kite APIs, but I could be wrong. Please help me understand what's going on here.
  • skaramo0osh
    @sujith Any insight is much appreciated. After going through the forum posts, I understand that you relay whatever data you get from the exchange. So, I can assume that there's no processing overhead, correct?

    I've registered both on_ticks and on_message callbacks. For ticks, both the callbacks are getting called - on_ticks with parsed binary data and on_message with message type 2 (for binary) and binary payload, which is what I see from the code.

    def _on_message(self, ws, payload, is_binary):
    """Call `on_message` callback when text message is received."""

    # logging.info(f"_on_message: {payload} {is_binary}")

    if self.on_message:
    self.on_message(self, payload, is_binary)

    # If the message is binary, parse it and send it to the callback.
    if self.on_ticks and is_binary and len(payload) > 4:
    self.on_ticks(self, self._parse_binary(payload))

    # Parse text messages
    if not is_binary:
    self._parse_text_message(payload)
    I choose to ignore binary payloads since I don't want to parse them myself.

    Like I mentioned in my last post, I'm seeing empty binary payloads right after subscription and before the first tick.

    2024-04-09 11:59:00.046 (Thread-6 (run)): Tick data subscription: [3771393]
    2024-04-09 11:59:00.086 (Thread-6 (run)): ==> Successful
    2024-04-09 11:59:00.134 (Thread-6 (run)): _on_message: b'{"type": "instruments_meta", "data": {"count": 82074, "etag": "W/\\"66148fa4-b13\\""}}' False
    2024-04-09 11:59:00.167 (Thread-6 (run)): _on_message: b'{"type":"app_code","timestamp":"2024-04-09T08:45:14+05:30"}' False
    2024-04-09 11:59:00.302 (Thread-6 (run)): _on_message: b'\x00' True
    2024-04-09 11:59:00.350 (Thread-6 (run)): _on_message: b'\x00' True
    2024-04-09 11:59:00.398 (Thread-6 (run)): _on_message: b'\x00' True
    2024-04-09 11:59:00.449 (Thread-6 (run)): _on_message: b'\x00' True
    2024-04-09 11:59:00.500 (Thread-6 (run)): _on_message: b'\x00' True
    2024-04-09 11:59:00.566 (Thread-6 (run)): _on_message: b'\x00' True
    2024-04-09 11:59:00.618 (Thread-6 (run)): _on_message: b'\x00' True
    2024-04-09 11:59:00.664 (Thread-6 (run)): _on_message: b'\x00' True
    2024-04-09 11:59:00.727 (Thread-6 (run)): _on_message: b'\x00' True
    2024-04-09 11:59:00.784 (Thread-6 (run)): _on_message: b'\x00' True
    2024-04-09 11:59:00.832 (Thread-6 (run)): _on_message: b'\x00' True
    2024-04-09 11:59:00.878 (Thread-6 (run)): _on_message: b'\x00' True
    2024-04-09 11:59:00.918 (Thread-6 (run)): _on_message: b'\x00' True
    2024-04-09 11:59:00.982 (Thread-6 (run)): _on_message: b'\x00' True
    2024-04-09 11:59:01.034 (Thread-6 (run)): _on_message: b'\x00' True
    2024-04-09 11:59:01.082 (Thread-6 (run)): _on_message: b'\x00' True
    2024-04-09 11:59:01.128 (Thread-6 (run)): _on_message: b'\x00' True
    2024-04-09 11:59:01.163 (Thread-6 (run)): _on_message: b'\x00' True
    2024-04-09 11:59:01.210 (Thread-6 (run)): _on_message: b'\x00' True
    2024-04-09 11:59:01.248 (Thread-6 (run)): _on_message: b'\x00' True
    2024-04-09 11:59:01.316 (Thread-6 (run)): _on_message: b'\x00' True
    2024-04-09 11:59:01.367 (Thread-6 (run)): _on_message: b'\x00' True
    2024-04-09 11:59:01.417 (Thread-6 (run)): _on_message: b'\x00' True
    2024-04-09 11:59:02.027 (Thread-6 (run)): _on_message: b'\x00\x01\x00\xb8\x009\x8c\x01\x00\x01f\x1b\x00\x00\x00\x01\x00\x01h\xfa\x00\x19\xf2D\x00\x04&\xc0\x00\x078\x1d\x00\x01h#\x00\x01k\x89\x00\x01e\x85\x00\x01f\xb1f\x14\xe0+\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00f\x14\xe0,\x00\x00\x00\xb4\x00\x01f\x0c\x00\x03\x00\x00\x00\x00\x01=\x00\x01f\x07\x00\x04\x00\x00\x00\x00\x02^\x00\x01f\x02\x00\x06\x00\x00\x00\x00\x00\x8e\x00\x01e\xfd\x00\x02\x00\x00\x00\x00\x01\xbf\x00\x01e\xf8\x00\t\x00\x00\x00\x00\x00\x03\x00\x01f\x1b\x00\x02\x00\x00\x00\x00\x00\xac\x00\x01f%\x00\x01\x00\x00\x00\x00\x00\n\x00\x01f*\x00\x02\x00\x00\x00\x00\x00\x9b\x00\x01f/\x00\x01\x00\x00\x00\x00\x00B\x00\x01f>\x00\x02\x00\x00' True
    2024-04-09 11:59:02.066 (Thread-6 (run)): [{'tradable': True, 'mode': 'full', 'instrument_token': 3771393, 'last_price': 916.75, 'last_traded_quantity': 1, 'average_traded_price': 924.1, 'volume_traded': 1700420, 'total_buy_quantity': 272064, 'total_sell_quantity': 473117, 'ohlc': {'open': 921.95, 'high': 930.65, 'low': 915.25, 'close': 918.25}, 'change': -0.16335420637081405, 'last_trade_time': datetime.datetime(2024, 4, 9, 11, 58, 59), 'oi': 0, 'oi_day_high': 0, 'oi_day_low': 0, 'exchange_timestamp': datetime.datetime(2024, 4, 9, 11, 59), 'depth': {'buy': [{'quantity': 180, 'price': 916.6, 'orders': 3}, {'quantity': 317, 'price': 916.55, 'orders': 4}, {'quantity': 606, 'price': 916.5, 'orders': 6}, {'quantity': 142, 'price': 916.45, 'orders': 2}, {'quantity': 447, 'price': 916.4, 'orders': 9}], 'sell': [{'quantity': 3, 'price': 916.75, 'orders': 2}, {'quantity': 172, 'price': 916.85, 'orders': 1}, {'quantity': 10, 'price': 916.9, 'orders': 2}, {'quantity': 155, 'price': 916.95, 'orders': 1}, {'quantity': 66, 'price': 917.1, 'orders': 2}]}}]
    2024-04-09 11:59:02.118 (TickProc ): DLF:last_price: 2024-04-09 11:59:00 916.75
    2024-04-09 11:59:02.119 (TickProc ): Tick added to the pipe
    2024-04-09 11:59:02.119 (TickProc ): Scheduling batch update
    2024-04-09 11:59:02.119 (TickProc ): ==> Timer expires in 57.880861 seconds
    2024-04-09 11:59:02.541 (Thread-6 (run)): _on_message: b'\x00\x01\x00\xb8\x009\x8c\x01\x00\x01f%\x00\x00\x00\xac\x00\x01h\xfa\x00\x19\xf2D\x00\x04&\xc0\x00\x078\x1d\x00\x01h#\x00\x01k\x89\x00\x01e\x85\x00\x01f\xb1f\x14\xe0+\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00f\x14\xe0-\x00\x00\x00\xb4\x00\x01f\x0c\x00\x03\x00\x00\x00\x00\x01=\x00\x01f\x07\x00\x04\x00\x00\x00\x00\x02^\x00\x01f\x02\x00\x06\x00\x00\x00\x00\x00\x8e\x00\x01e\xfd\x00\x02\x00\x00\x00\x00\x01\xbf\x00\x01e\xf8\x00\t\x00\x00\x00\x00\x00\x03\x00\x01f\x1b\x00\x02\x00\x00\x00\x00\x00\xac\x00\x01f%\x00\x01\x00\x00\x00\x00\x00\n\x00\x01f*\x00\x02\x00\x00\x00\x00\x00\x9b\x00\x01f/\x00\x01\x00\x00\x00\x00\x00B\x00\x01f>\x00\x02\x00\x00' True
    2024-04-09 11:59:02.577 (Thread-6 (run)): [{'tradable': True, 'mode': 'full', 'instrument_token': 3771393, 'last_price': 916.85, 'last_traded_quantity': 172, 'average_traded_price': 924.1, 'volume_traded': 1700420, 'total_buy_quantity': 272064, 'total_sell_quantity': 473117, 'ohlc': {'open': 921.95, 'high': 930.65, 'low': 915.25, 'close': 918.25}, 'change': -0.15246392594609062, 'last_trade_time': datetime.datetime(2024, 4, 9, 11, 58, 59), 'oi': 0, 'oi_day_high': 0, 'oi_day_low': 0, 'exchange_timestamp': datetime.datetime(2024, 4, 9, 11, 59, 1), 'depth': {'buy': [{'quantity': 180, 'price': 916.6, 'orders': 3}, {'quantity': 317, 'price': 916.55, 'orders': 4}, {'quantity': 606, 'price': 916.5, 'orders': 6}, {'quantity': 142, 'price': 916.45, 'orders': 2}, {'quantity': 447, 'price': 916.4, 'orders': 9}], 'sell': [{'quantity': 3, 'price': 916.75, 'orders': 2}, {'quantity': 172, 'price': 916.85, 'orders': 1}, {'quantity': 10, 'price': 916.9, 'orders': 2}, {'quantity': 155, 'price': 916.95, 'orders': 1}, {'quantity': 66, 'price': 917.1, 'orders': 2}]}}]
    2024-04-09 11:59:02.696 (Thread-6 (run)): _on_message: b'\x00' True
    2024-04-09 11:59:04.449 (Thread-6 (run)): _on_message: b'\x00\x01\x00\xb8\x009\x8c\x01\x00\x01f/\x00\x00\x00\x9b\x00\x01h\xfa\x00\x19\xf2D\x00\x04&\xc0\x00\x078\x1d\x00\x01h#\x00\x01k\x89\x00\x01e\x85\x00\x01f\xb1f\x14\xe0+\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00f\x14\xe0.\x00\x00\x00\xb4\x00\x01f\x0c\x00\x03\x00\x00\x00\x00\x01=\x00\x01f\x07\x00\x04\x00\x00\x00\x00\x02^\x00\x01f\x02\x00\x06\x00\x00\x00\x00\x00\x8e\x00\x01e\xfd\x00\x02\x00\x00\x00\x00\x01\xbf\x00\x01e\xf8\x00\t\x00\x00\x00\x00\x00\x03\x00\x01f\x1b\x00\x02\x00\x00\x00\x00\x00\xac\x00\x01f%\x00\x01\x00\x00\x00\x00\x00\n\x00\x01f*\x00\x02\x00\x00\x00\x00\x00\x9b\x00\x01f/\x00\x01\x00\x00\x00\x00\x00B\x00\x01f>\x00\x02\x00\x00' True
    2024-04-09 11:59:04.483 (Thread-6 (run)): [{'tradable': True, 'mode': 'full', 'instrument_token': 3771393, 'last_price': 916.95, 'last_traded_quantity': 155, 'average_traded_price': 924.1, 'volume_traded': 1700420, 'total_buy_quantity': 272064, 'total_sell_quantity': 473117, 'ohlc': {'open': 921.95, 'high': 930.65, 'low': 915.25, 'close': 918.25}, 'change': -0.14157364552136723, 'last_trade_time': datetime.datetime(2024, 4, 9, 11, 58, 59), 'oi': 0, 'oi_day_high': 0, 'oi_day_low': 0, 'exchange_timestamp': datetime.datetime(2024, 4, 9, 11, 59, 2), 'depth': {'buy': [{'quantity': 180, 'price': 916.6, 'orders': 3}, {'quantity': 317, 'price': 916.55, 'orders': 4}, {'quantity': 606, 'price': 916.5, 'orders': 6}, {'quantity': 142, 'price': 916.45, 'orders': 2}, {'quantity': 447, 'price': 916.4, 'orders': 9}], 'sell': [{'quantity': 3, 'price': 916.75, 'orders': 2}, {'quantity': 172, 'price': 916.85, 'orders': 1}, {'quantity': 10, 'price': 916.9, 'orders': 2}, {'quantity': 155, 'price': 916.95, 'orders': 1}, {'quantity': 66, 'price': 917.1, 'orders': 2}]}}]
    If the 500 - 1000 millisecond delay/latency is expected from the client library, I can modify my code to work with this. I'm just trying to understand what's going on.
  • sbalaji987
    I think this may be expected? You can try launching your websocket at 9:14 or 9:14:50 - I do that and don't miss any data.
  • skaramo0osh
    It affects my task scheduler but I will probably end up subscribing to tick data before 9:15:00 AM. I was hoping to get a response from the developers to understand why this is happening.
Sign In or Register to comment.