read time out

[xiongnuren]

I constantly encountered 'read operation timed out' issue. And when it occurs, the program thinks the gateway is not authenticated and will try to authenticate again. So I have to authenticate on my iPhone whenever it happens. If I didn't notice the request to authenticate on my iPhone the authentication process will fail. Is there a better handling for 'read time out'?

2020-11-08 02:32:54,672|E| The read operation timed out
Traceback (most recent call last):
File "/srv/ibeam/src/gateway_client.py", line 314, in _try_request
self._url_request(url)
File "/srv/ibeam/src/gateway_client.py", line 309, in _url_request
return urllib.request.urlopen(url, context=self._ssl_context, timeout=15)
File "/usr/local/lib/python3.7/urllib/request.py", line 222, in urlopen
return opener.open(url, data, timeout)
File "/usr/local/lib/python3.7/urllib/request.py", line 525, in open
response = self._open(req, data)
File "/usr/local/lib/python3.7/urllib/request.py", line 543, in _open
'_open', req)
File "/usr/local/lib/python3.7/urllib/request.py", line 503, in _call_chain
result = func(*args)
File "/usr/local/lib/python3.7/urllib/request.py", line 1362, in https_open
context=self._context, check_hostname=self._check_hostname)
File "/usr/local/lib/python3.7/urllib/request.py", line 1322, in do_open
r = h.getresponse()
File "/usr/local/lib/python3.7/http/client.py", line 1344, in getresponse
response.begin()
File "/usr/local/lib/python3.7/http/client.py", line 306, in begin
version, status, reason = self._read_status()
File "/usr/local/lib/python3.7/http/client.py", line 267, in _read_status
line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1")
File "/usr/local/lib/python3.7/socket.py", line 589, in readinto
return self._sock.recv_into(b)
File "/usr/local/lib/python3.7/ssl.py", line 1071, in recv_into
return self.read(nbytes, buffer)
File "/usr/local/lib/python3.7/ssl.py", line 929, in read
return self._sslobj.read(len, buffer)
socket.timeout: The read operation timed out
2020-11-08 02:32:54,673|I| Gateway not authenticated, authenticating...
2020-11-08 02:33:06,098|I| Authentication succeeded.

[Voyz]

Thanks for reporting the first issue on IBeam @seismars 🎉😄

From what you wrote I understand that you're running into the The read operation timed out error when authenticating and that you need to use your iPhone to complete the authentication. You're also asking if we could handle that error better. My initial guess would be that the two-factor authentication is what's holding the gateway and if not completed it causes a timeout.

Could I ask you to provide us with a little more information first?

• Do you usually have to perform two-factor authentication using your iPhone when using the IBKR Gateway without IBeam?
• Are you running IBeam as a Docker image or standalone?
• What exact command are you starting IBeam with?
• The stack trace you included is helpful, but still not quite conclusive. Would you be able to run IBeam with verbose logs and submit the entire stack trace of the execution? You can enable verbose logs by setting IBEAM_LOG_LEVEL environment variable to DEBUG (or if run in standalone mode by passing -v flag when running ibeam_starter.py)

Thanks!

[xiongnuren]

• Yes, I always need to use two-factor authentication either use IBeam or not. It was required by IB for my account. I don't have the option to not using two-factor authentication.
• I'm using Docker image Ibeam.
• the current command I'm using is: docker run --env IBEAM_ACCOUNT=myacount123 --env IBEAM_PASSWORD=mypassword -p 5000:5000 voyz/ibeam
• No I don't think the time out was caused during two-factor authentication. It was likely during the maintenance operation that some request timed out which was treated as 'Gateway not authenticated' which then triggered another attempt to 'authenticating...' I suspect the gateway is still connected but had a time out due to network being not very reliable. I'm thinking if IBeam try another time to check the connection it might find out that the gateway is still connected.
• I will add the IBEAM_LOG_LEVEL=DEBUG option and run more test again. Will update later.

Thanks for this program. I can see clear benefits to me if it work out.

[Voyz]

Fantastic, thanks for all that info! Looking forward to seeing more logs and we'll continue from there 👍

[xiongnuren]

I'm running more tests, but I haven't encounter another 'read time out' issue again. Maybe my internet connection or server's response to requests are not bad at the moment. I will update later when I do encounter the same issue again, with the debug option turned on.

However, I do encounter another issue. This time I did lost the connection to IBKR's gateway several times. My own program was periodically checking the connect with the gateway using the tickle endpoint. I had several encounters of loosing connection to the gateway. However, everything appeared to be fine on the Ibeam side: it continues to print out the Maintenance message every 60 seconds, without trying to authenticate again. I had to manually stop the ibeam and restart again in order to reconnect to IBKR.

[Voyz]

Thanks for more info. It may be indeed that a weak connection causes that issue you originally described. In such case, it seems like the error message indeed describes the issue at hand correctly - the request simply timing out (due to connectivity issues). Let me know if you encounter this issue again, would be great to read these logs then.

As for the second problem you described - could I bother you to open a new issue for it and provide more details? Would love to get to the bottom of it and discover what is causing the discrepancy between IBeam and your client in regard to whether the gateway is authenticated.

[xiongnuren]

I will open a separate issue for the discrepancy.

Here is the new time out issue again with the DEBUG option:
2020-11-08 15:40:33,913|I| Gateway started with pid: 11
2020-11-08 15:40:33,914|D| HTTP request to: https://localhost:5000/v1/portal/sso/validate
2020-11-08 15:40:34,642|I| Gateway not authenticated, authenticating...
2020-11-08 15:40:35,921|D| Loading auth page at https://localhost:5000/sso/Login?forwardTo=22&RL=1&ip2loc=on
2020-11-08 15:40:38,794|D| Gateway auth page loaded
2020-11-08 15:40:38,922|D| Submitting the form
2020-11-08 15:40:50,209|D| Client login succeeds
2020-11-08 15:40:52,283|I| Authentication succeeded.
2020-11-08 15:40:52,284|D| HTTP request to: https://localhost:5000/v1/portal/sso/validate
2020-11-08 15:40:52,369|I| Gateway running and authenticated.
2020-11-08 15:40:52,808|I| Starting maintenance with interval 60 seconds.
2020-11-08 15:41:52,809|D| Maintenance
2020-11-08 15:41:52,815|D| HTTP request to: https://localhost:5000/v1/portal/sso/validate
2020-11-08 15:42:07,880|E| The read operation timed out
Traceback (most recent call last):
File "/srv/ibeam/src/gateway_client.py", line 314, in _try_request
self._url_request(url)
File "/srv/ibeam/src/gateway_client.py", line 309, in _url_request
return urllib.request.urlopen(url, context=self._ssl_context, timeout=15)
File "/usr/local/lib/python3.7/urllib/request.py", line 222, in urlopen
return opener.open(url, data, timeout)
File "/usr/local/lib/python3.7/urllib/request.py", line 525, in open
response = self._open(req, data)
File "/usr/local/lib/python3.7/urllib/request.py", line 543, in _open
'_open', req)
File "/usr/local/lib/python3.7/urllib/request.py", line 503, in _call_chain
result = func(*args)
File "/usr/local/lib/python3.7/urllib/request.py", line 1362, in https_open
context=self._context, check_hostname=self._check_hostname)
File "/usr/local/lib/python3.7/urllib/request.py", line 1322, in do_open
r = h.getresponse()
File "/usr/local/lib/python3.7/http/client.py", line 1344, in getresponse
response.begin()
File "/usr/local/lib/python3.7/http/client.py", line 306, in begin
version, status, reason = self._read_status()
File "/usr/local/lib/python3.7/http/client.py", line 267, in _read_status
line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1")
File "/usr/local/lib/python3.7/socket.py", line 589, in readinto
return self._sock.recv_into(b)
File "/usr/local/lib/python3.7/ssl.py", line 1071, in recv_into
return self.read(nbytes, buffer)
File "/usr/local/lib/python3.7/ssl.py", line 929, in read
return self._sslobj.read(len, buffer)
socket.timeout: The read operation timed out
2020-11-08 15:42:07,882|I| Gateway not authenticated, authenticating...
2020-11-08 15:42:09,177|D| Loading auth page at https://localhost:5000/sso/Login?forwardTo=22&RL=1&ip2loc=on
2020-11-08 15:42:11,298|D| Gateway auth page loaded
2020-11-08 15:42:11,426|D| Submitting the form
2020-11-08 15:42:22,321|D| Client login succeeds
2020-11-08 15:42:24,410|I| Authentication succeeded.
2020-11-08 15:42:24,411|D| HTTP request to: https://localhost:5000/v1/portal/sso/validate
2020-11-08 15:42:52,813|D| Maintenance
2020-11-08 15:42:52,818|D| HTTP request to: https://localhost:5000/v1/portal/sso/validate

[Voyz]

Thanks for submitting this log, it's good to see the chronology of this error.

You marked this issue as 'Enhancement', therefore do I understand well that you're suggesting catching the socket.timeout: The read operation timed out error and displaying a clearer message to the user?

Given that this is a timeout error (as discussed earlier probably caused by network issues), the other solution I can think of now would be to make multiple validate attempts before going for reauthentication. However I wonder whether it would be better to be 'safe than sorry' and reauthenticate as soon as possible, in order to minimise trading downtime.

I also think we could add information to the documentation regarding the two-factor authentication.

[xiongnuren]

Below are some of my thoughts:

• What is the current time out period in second? Depending on the current default value, there might be some room to make it longer so time out will happen less often.

• I like the proposal of multiple validation attempts when timeout exception occurs.

• In my case when I have to use two-factor authentication, reauthenticate for every timeout exception seems too much a distraction. Further, I don't think I will be able to notice the authentication requests on my iPhone in time for every request. As a result the authenticatio fails.

Of course I'm only speaking for myself based on my own situation. I understanding it's your call as to how you want to better address the issue.
Another approach I may explore later is to go with the standalone method, where I might build a custom logic in my script and only request IBeam to authenticate whenever I need.

[Voyz]

Thanks for sharing your thoughts, very valuable.

Indeed, having to do two-factor auth more often than needed is an unwanted behaviour. I can totally see where you're coming from.

After reading your thoughts I realised that we can have an easy solution for this - we could introduce an environment variable defining how many times IBeam will attempt to validate before launching restart/reauthentication. This way each user could adjust the behaviour to their needs - if needed reauth as soon as possible, otherwise allow more slack. What's more, we could expose the request timeout value in the same way, increasing the customisability even more. Do I assume correctly this would help your case?

[xiongnuren]

It will definitely help.

[Voyz]

Fantastic, I'll go ahead with the following:

• Add environment variables for requests timeout and validate retries.
• Catch the timeout error and display a clearer message.
• Add information about the two-factor authentication to IBeam documentation.

Thank you for highlighting this issue and working with me on the solution 🙌 Please feel free to suggest other improvements that might make this situation even better. I will update here once the patch is ready.

[xiongnuren]

Today is Friday Nov 13, 2020.
I run my trading with IBeam's latest version. IBeam encountered 9 times of read timeout, all went through in its second attempt. If I was using the previous version I would have to authorize 9 more times.
Also for issue #2: now IBeam is aware when IB's connection is lost.(I will update on issue #2 as well).
Big thumbs up!

[Voyz]

Glad to hear :) Going ahead with a merge. Once again, thanks for your help!