1. twsapi@groups.io
Topics

realtimeBar subscription stops during the trading session

VladD
 

Experiencing this issue almost every trading day. Using TWSProxy.

At the start of the day multiple reqRealTimeBars requests are issued for different contracts (not much - 5-6 requests). However during the session one or more such subscriptions cease to work. For example the following API log shows that the subscription for AMD (contract id 16777225) stops working after 20:23:05 UTC and doesn't resume till eos (other subscriptions continue working):

(relevent log lines are marked with ***)

20:23:00:952 -> 50-3-16777219-1579206175-4.21-4.21-4.21-4.21-1-4.21-1-
20:23:00:952 -> 50-3-16777217-1579206175-6.61-6.61-6.61-6.61-1-6.61-1-
20:23:00:952 -> 50-3-16777227-1579206175-13.28-13.28-13.28-13.28-0-13.28-0-
20:23:05:544 -> 50-3-16777223-1579206180-10.63-10.63-10.62-10.63-22-10.63-5-
20:23:05:544 -> 50-3-16777221-1579206180-57.55-57.55-57.54-57.55-31-57.55-10-
***
20:23:05:940 -> 50-3-16777225-1579206180-49.77-49.77-49.75-49.76-81-49.76-27-
***
20:23:05:940 -> 50-3-16777219-1579206180-4.21-4.21-4.20-4.21-43-4.21-3-
20:23:05:940 -> 50-3-16777217-1579206180-6.61-6.61-6.60-6.61-18-6.61-8-
20:23:05:940 -> 50-3-16777227-1579206180-13.28-13.28-13.28-13.28-0-13.28-0-
20:23:10:532 -> 50-3-16777227-1579206185-13.28-13.28-13.28-13.28-0-13.28-0-
20:23:10:939 -> 50-3-16777221-1579206185-57.55-57.55-57.54-57.55-20-57.55-17-
20:23:10:939 -> 50-3-16777223-1579206185-10.63-10.63-10.62-10.63-10-10.63-7-
20:23:10:939 -> 50-3-16777219-1579206185-4.20-4.20-4.20-4.20-1-4.20-1-
20:23:10:939 -> 50-3-16777217-1579206185-6.61-6.61-6.61-6.61-9-6.61-2-
20:23:15:532 -> 50-3-16777219-1579206190-4.21-4.21-4.21-4.21-2-4.21-2-
20:23:15:943 -> 50-3-16777221-1579206190-57.54-57.54-57.54-57.54-2-57.54-1-
20:23:15:943 -> 50-3-16777223-1579206190-10.63-10.63-10.62-10.63-13-10.63-3-
20:23:15:943 -> 50-3-16777217-1579206190-6.61-6.61-6.61-6.61-6-6.61-3-
20:23:15:943 -> 50-3-16777227-1579206190-13.28-13.31-13.28-13.30-39-13.29-28-
20:23:20:644 -> 50-3-16777223-1579206195-10.63-10.63-10.63-10.63-2-10.63-2-
20:23:20:939 -> 50-3-16777221-1579206195-57.54-57.54-57.54-57.54-2-57.54-1-
20:23:20:939 -> 50-3-16777219-1579206195-4.20-4.20-4.20-4.20-10-4.20-1-
20:23:20:939 -> 50-3-16777217-1579206195-6.61-6.61-6.60-6.61-7-6.61-4-
20:23:20:939 -> 50-3-16777227-1579206195-13.30-13.30-13.30-13.30-0-13.30-0-
20:23:25:222 <- 49-1-
20:23:25:222 -> 49-1-1579206205-
20:23:25:346 -> 50-3-16777217-1579206200-6.61-6.61-6.61-6.61-5-6.61-3-
20:23:25:943 -> 50-3-16777221-1579206200-57.54-57.55-57.54-57.54-38-57.54-12-
20:23:25:944 -> 50-3-16777223-1579206200-10.63-10.63-10.62-10.63-4-10.63-3-
20:23:25:944 -> 50-3-16777219-1579206200-4.21-4.21-4.21-4.21-1-4.21-1-
20:23:25:944 -> 50-3-16777227-1579206200-13.24-13.24-13.24-13.24-4-13.24-1-
20:23:29:914 -> 50-3-16777227-1579206205-13.24-13.24-13.24-13.24-0-13.24-0-
20:23:29:914 -> 50-3-16777223-1579206205-10.62-10.62-10.62-10.62-1-10.62-1-
20:23:30:762 -> 50-3-16777221-1579206205-57.54-57.54-57.54-57.54-3-57.54-1-
20:23:30:763 -> 50-3-16777219-1579206205-4.20-4.20-4.20-4.20-8-4.20-1-
20:23:30:763 -> 50-3-16777217-1579206205-6.61-6.61-6.60-6.61-12-6.61-6-

Looking at the gateway logs around the same time always shows the following strange log lines (handleBustEvent):

2020-01-16 20:22:49.157 [TN] INFO  [JTS-CCPDispatcherS2-35] - CCP reported time: 2020-01-16 20:22:49.000 (GMT) [1579206169000], local time: 2020-01-16 20:22:49.157 (GMT), local time: 2020-01-16 20:22:49.157 (UTC), difference in seconds: -0.157, handling delta:n/a [Msg1]
2020-01-16 20:23:00.571 [TN] INFO  [JTS-Cleaner-33] - market data wrapper, cleaning maps
***
2020-01-16 20:23:07.303 [TN] INFO  [JTS-ushmdsDispatcherS5-81S5-82] - ====handleBustEvent delay 7
2020-01-16 20:23:14.304 [TN] INFO  [AWT-EventQueue-0] - ====handleBustEventAtRandomDelay
2020-01-16 20:23:14.304 [TN] INFO  [AWT-EventQueue-0] - API 5 second update bustEventReceived. Ignored now
***
2020-01-16 20:23:29.350 [TN] INFO  [JTS-CCPDispatcherS2-35] - Setting time offset to -350 diff -193
2020-01-16 20:23:29.350 [TN] INFO  [JTS-CCPDispatcherS2-35] - CCP reported time: 2020-01-16 20:23:29.000 (GMT) [1579206209000], local time: 2020-01-16 20:23:29.350 (GMT), local time: 2020-01-16 20:23:29.350 (UTC), difference in seconds: -0.350, handling delta:n/a [Msg1]

No API notification is sent to the application (as you may see from the API log). Would appreciate if anybody could shade a light on a possible cause of the failure.

Thanks Vlad
Nick
 

RealTimeBars has always had an issue where data sometimes stopped being sent when a session closed.

The only solution was to unsubscribe and re-subscribe. You will probably have to experiment on what time works best for the re-subscribe. For futures it used to work if I subscribed 15 minutes before the start of the next session.

I haven't used realtime bars for a while and never for stocks so I can't give a specific recommendation for what might work best.

On 1/20/2020 3:37 PM, VladD wrote:

Experiencing this issue almost every trading day. Using TWSProxy.

At the start of the day multiple reqRealTimeBars requests are issued for different contracts (not much - 5-6 requests). However during the session one or more such subscriptions cease to work. For example the following API log shows that the subscription for AMD (contract id 16777225) stops working after 20:23:05 UTC and doesn't resume till eos (other subscriptions continue working):
...
Josh
 

Vlad can you try upgrading to a current version of TWS/IB Gateway v978 or v979? It should be ok there.
VladD
 

Thanks Josh,

I've upgraded to 978.1h - still experiencing the problem of subscriptions deactivation. However now there is an additional error notification sent to the application, explicitly stating that subscription was deactivated and should be renewed.

See the API log quote below for MU contract subscription (contract id = 16777221) (relevant entries are marked with ***):

***
15:23:50:150 -> 50-3-16777221-1579620225-58.16-58.16-58.15-58.15-10-58.15-5-
***
15:23:50:150 -> 50-3-16777225-1579620225-51.59-51.60-51.59-51.60-117-51.60-14-
15:23:50:681 -> 50-3-16777219-1579620225-4.11-4.11-4.10-4.11-55-4.11-5-
15:23:50:681 -> 50-3-16777223-1579620225-10.16-10.16-10.15-10.15-2-10.15-2-
15:23:50:681 -> 50-3-16777227-1579620225-14.67-14.67-14.67-14.67-0-14.67-0-
15:23:50:681 -> 50-3-16777217-1579620225-6.66-6.66-6.66-6.66-0-6.66-0-
15:23:54:871 -> 50-3-16777225-1579620230-51.60-51.60-51.57-51.58-225-51.58-47-
15:23:54:871 -> 50-3-16777223-1579620230-10.15-10.15-10.15-10.15-1-10.15-1-
15:23:55:702 -> 50-3-16777219-1579620230-4.11-4.11-4.10-4.10-29-4.10-5-
15:23:55:702 -> 50-3-16777227-1579620230-14.67-14.67-14.67-14.67-0-14.67-0-
15:23:55:702 -> 50-3-16777217-1579620230-6.67-6.67-6.66-6.66-34-6.67-8-
15:23:59:902 -> 50-3-16777225-1579620235-51.58-51.58-51.56-51.57-98-51.57-42-
15:24:00:505 -> 50-3-16777219-1579620235-4.11-4.11-4.10-4.10-26-4.11-3-
15:24:00:505 -> 50-3-16777223-1579620235-10.16-10.16-10.15-10.15-2-10.15-2-
15:24:00:505 -> 50-3-16777227-1579620235-14.67-14.67-14.67-14.67-0-14.67-0-
15:24:00:505 -> 50-3-16777217-1579620235-6.67-6.67-6.66-6.67-2-6.67-2-
***
15:24:00:896 -> 4-2-16777221-10225-Bust event occurred, current subscription is deactivated. Please resubscribe real-time bars immediately.-
***

Gateway logs still show the same (BustEvent) events:

2020-01-21 15:24:01.573 [MO] INFO  [AWT-EventQueue-0] - ====handleBustEventAtRandomDelay
2020-01-21 15:24:01.573 [MO] INFO  [AWT-EventQueue-0] - API 5 second update bustEventReceived. Ignored now
2020-01-21 15:24:01.573 [MO] WARN  [AWT-EventQueue-0] - Bust event occurred, current subscription is deactivated. Please resubscribe real-time bars immediately.

Will update the application to handle the above error events of cause.

The question though - is there anything that could be done to avoid those 'Bust' events from the application side ? And what do those 'Bust' events mean at all ?

Thanks Vlad
Josh
 

the busts occur when the datastream is interrupted or modified in the middle of a bar and the subscription is cancelled by the backend. They should be relatively uncommon but unfortunately no can't be avoided completely. By checking for the error code you should be able to resubscribe automatically. 
VladD
 

Thank Josh for the explanation.

I've updated my system to re-subscribe for the realtimeBar upon receiving the 10225 error.

It works in most of the cases (see the log below - relevant lines are marked with ***)

*** < here the last valid realtimeBar for MU - contract 16777221) >
20:13:10:209 -> 50-3-16777221-1580242385-56.60-56.61-56.60-56.60-27-56.60-16-
***
20:13:10:209 -> 50-3-16777219-1580242385-4.04-4.05-4.04-4.04-3-4.04-3-
20:13:10:209 -> 50-3-16777223-1580242385-10.22-10.22-10.22-10.22-0-10.22-0-
20:13:10:209 -> 50-3-16777227-1580242385-13.96-13.96-13.96-13.96-1-13.96-1-
20:13:10:209 -> 50-3-16777217-1580242385-6.65-6.65-6.65-6.65-9-6.65-2-
20:13:15:209 -> 50-3-16777225-1580242390-50.51-50.51-50.50-50.51-142-50.50-22-
20:13:15:209 -> 50-3-16777219-1580242390-4.04-4.04-4.04-4.04-2-4.04-2-
20:13:15:209 -> 50-3-16777223-1580242390-10.22-10.24-10.22-10.24-108-10.23-37-
20:13:15:210 -> 50-3-16777227-1580242390-13.96-13.96-13.96-13.96-0-13.96-0-
20:13:15:210 -> 50-3-16777217-1580242390-6.65-6.65-6.65-6.65-9-6.65-6-
20:13:19:876 -> 50-3-16777225-1580242395-50.51-50.51-50.50-50.50-71-50.50-33-
20:13:20:249 -> 50-3-16777219-1580242395-4.04-4.05-4.04-4.04-5-4.04-4-
20:13:20:249 -> 50-3-16777223-1580242395-10.23-10.23-10.23-10.23-0-10.23-0-
20:13:20:249 -> 50-3-16777227-1580242395-13.96-13.96-13.96-13.96-0-13.96-0-
20:13:20:249 -> 50-3-16777217-1580242395-6.65-6.65-6.65-6.65-8-6.65-5-
*** < bust event and re-subscription issued> 
20:13:21:356 -> 4-2-16777221-10225-Bust event occurred, current subscription is deactivated. Please resubscribe real-time bars immediately.-
20:13:21:803 <- 50-2-16777228-9939-MU-STK--0.0---SMART-NASDAQ-USD-MU-NMS-5-TRADES-0-
***
20:13:22:166 -> 50-3-16777228-1580242395-56.60-56.60-56.60-56.60-1-56.60-1-
20:13:24:672 <- 49-1-
20:13:24:672 -> 49-1-1580242404-
20:13:25:206 -> 50-3-16777225-1580242400-50.50-50.51-50.49-50.50-118-50.50-64-
*** < new realtimeBar receivied once again > 
20:13:25:208 -> 50-3-16777228-1580242400-56.60-56.60-56.60-56.60-0-56.60-0-
***

However in some cases it doesn't. The re-subscription is issued but no other realtimeBar packets are received for the re-subscribed contract.

*** < last valid realtimeBar for AMD - contract 16777225>
15:09:29:875 -> 50-3-16777225-1580310565-46.55-46.55-46.52-46.53-370-46.53-59-
***
15:09:29:875 -> 50-3-16777221-1580310565-56.17-56.18-56.17-56.17-64-56.17-16-
15:09:30:750 -> 50-3-16777223-1580310565-10.28-10.28-10.26-10.27-133-10.27-42-
15:09:30:750 -> 50-3-16777219-1580310565-3.97-3.97-3.97-3.97-1-3.97-1-
15:09:30:750 -> 50-3-16777217-1580310565-6.63-6.63-6.63-6.63-0-6.63-0-
15:09:30:750 -> 50-3-16777227-1580310565-14.23-14.23-14.23-14.23-6-14.23-2-
15:09:34:097 <- 49-1-
15:09:34:097 -> 49-1-1580310574-
15:09:34:933 -> 50-3-16777223-1580310570-10.27-10.27-10.26-10.27-69-10.27-10-
15:09:35:294 -> 50-3-16777221-1580310570-56.17-56.18-56.15-56.15-65-56.17-44-
15:09:35:294 -> 50-3-16777219-1580310570-3.97-3.97-3.97-3.97-7-3.97-1-
15:09:35:294 -> 50-3-16777217-1580310570-6.63-6.63-6.63-6.63-0-6.63-0-
15:09:35:294 -> 50-3-16777227-1580310570-14.23-14.23-14.23-14.23-0-14.23-0-
*** < bust event and re-subscription issued >
15:09:37:263 -> 4-2-16777225-10225-Bust event occurred, current subscription is deactivated. Please resubscribe real-time bars immediately.-
15:09:37:349 <- 50-2-16777228-4391-AMD-STK--0.0---SMART-NASDAQ-USD-AMD-NMS-5-TRADES-0-
***
15:09:39:706 -> 50-3-16777223-1580310575-10.26-10.27-10.26-10.26-37-10.26-7-

*** < no other realtimeBar packet received for AMD that day - believe me >

What could be wrong? Re-subscription failed? Any way to know about it in this case?

Should the application wait for some timeout to re-subscribe ?

Thanks Vlad
Nick
 

Just FYI, the other live data streams don't have this issue. Building bars from ticks might be preferable to random and unpredictable failures with realtime bars.

On 1/29/2020 1:53 PM, VladD wrote:

Thank Josh for the explanation.

I've updated my system to re-subscribe for the realtimeBar upon receiving the 10225 error.

It works in most of the cases (see the log below - relevant lines are marked with ***)
Josh
 

Yes I would try a slight delay (though the message says to resubscribe 'immediately') but also agree with what Nick said. 
It wouldn't hurt to contact API Support with detailed logs and your findings, the message is a new feature. 
VladD
 

Just FYI, I've contacted the API Support and here the answer I've got:

''' The existing request may not have terminated. When bust event occurs please try using cancelRealTimeBars() then call reqRealTimeBars() again. '''

Will update my application and test it for few days - will update after that.
VladD
 

Update: after a week of testing - realtimeBars seems to be working flawlessly. Re-subscribing after bust events doesn't require any delay to be added by the application - just make sure to cancel the previous subscription before re-subscribing, as was mentioned above.
1 - 10 of 10