Closed Qarj closed 2 years ago
Actually it looks like I'm getting two different errors in the logs, here is the other error in the log
2022-02-13 14:17:53,167|E| Error encountered during authentication
Traceback (most recent call last):
File "/srv/ibeam/src/authenticate.py", line 218, in authenticate_gateway
two_fa_el[0].send_keys(two_fa_code)
File "/opt/venv/lib/python3.7/site-packages/selenium/webdriver/remote/webelement.py", line 479, in send_keys
'value': keys_to_typing(value)})
File "/opt/venv/lib/python3.7/site-packages/selenium/webdriver/remote/webelement.py", line 633, in _execute
return self._parent.execute(command, params)
File "/opt/venv/lib/python3.7/site-packages/selenium/webdriver/remote/webdriver.py", line 321, in execute
self.error_handler.check_response(response)
File "/opt/venv/lib/python3.7/site-packages/selenium/webdriver/remote/errorhandler.py", line 242, in check_response
raise exception_class(message, screen, stacktrace)
selenium.common.exceptions.ElementNotInteractableException: Message: element not interactable
(Session info: headless chrome=90.0.4430.212)
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/srv/ibeam/src/authenticate.py", line 263, in authenticate_gateway
raise RuntimeError('Error encountered during authentication') from e
The page seems to run a little slower than before, I did get a little further putting in a sleep hack + a click to the input field
if two_fa_code is None:
_LOGGER.warning(f'No 2FA code returned. Aborting authentication.')
else:
time.sleep (3)
two_fa_el = driver.find_elements_by_id(var.TWO_FA_INPUT_EL_ID)
two_fa_el[0].click()
two_fa_el[0].send_keys(two_fa_code)
Now it is getting past the authentication step, but I'm getting a competing Gateway session found
error which I don't understand.
Java Version: 11.0.13
****************************************************
version: ed4af2592e9dd4a784d5403843bd18292fd441ea Fri, 9 Nov 2018 13:23:18 -0500
****************************************************
This is a Beta release of the Client Portal Gateway
for any issues, please contact api@ibkr.com
and include a copy of your logs
****************************************************
https://www.interactivebrokers.com/api/doc.html
****************************************************
Open https://localhost:5000 to login
App demo is available after you login under: https://localhost:5000/demo/
2022-02-13 17:13:57,005|I| Gateway started with pid: 45745
2022-02-13 17:13:57,797|I| No active sessions, logging in...
2022-02-13 17:14:06,631|I| Credentials correct, but Gateway requires two-factor authentication.
2022-02-13 17:14:06,631|I| Attempting to acquire 2FA code from: GoogleMessagesTwoFaHandler(driver_path=/usr/local/bin/selenium/chromedriver)
2022-02-13 17:14:10,572|I| Your requested authentication code: 554339
2022-02-13 17:14:18,618|I| Authentication process succeeded
2022-02-13 17:14:21,692|I| Authenticated but competing Gateway session found, reauthenticating...
Hey @Qarj thanks for the detailed report π I can see clearly what seems to be the issue. Also thanks for attempting to solve the problem yourself, it simplified my work significantly π
The page seems to run a little slower than before, I did get a little further putting in a sleep hack + a click to the input field
You can actually wait for an element to become clickable. Can you try the following replacement instead on your end and see if it solves the first two problems?
if two_fa_code is None:
_LOGGER.warning(f'No 2FA code returned. Aborting authentication.')
else:
two_fa_el = driver.find_elements_by_id(var.TWO_FA_INPUT_EL_ID)
WebDriverWait(driver, var.OAUTH_TIMEOUT).until(
EC.element_to_be_clickable((By.ID, var.TWO_FA_INPUT_EL_ID)))
two_fa_el[0].send_keys(two_fa_code)
_LOGGER.debug('Submitting the 2FA form')
submit_form_el = driver.find_element_by_id(var.SUBMIT_EL_ID)
WebDriverWait(driver, var.OAUTH_TIMEOUT).until(
EC.element_to_be_clickable((By.ID, var.SUBMIT_EL_ID)))
submit_form_el.click()
trigger = WebDriverWait(driver, var.OAUTH_TIMEOUT).until(any_of(success_present, error_displayed))
trigger_id = trigger.get_attribute('id')
Note how I added the following two lines:
WebDriverWait(driver, var.OAUTH_TIMEOUT).until(
EC.element_to_be_clickable((By.ID, var.TWO_FA_INPUT_EL_ID)))
...
WebDriverWait(driver, var.OAUTH_TIMEOUT).until(
EC.element_to_be_clickable((By.ID, var.SUBMIT_EL_ID)))
I'm getting a
competing Gateway session found
error which I don't understand
This is a big fat issue that the community is trying to get around right now. In short, this seems to be caused by IBKR servers, and IBeam attempts to detect it and cause a reauthentication. Does it resume normal work after it runs into competing Gateway session found
and reauthenticates?
Hey @Voyz thanks for looking!
I just tried now, but got this error
2022-02-14 09:25:22,826|E| Error encountered during authentication
Traceback (most recent call last):
File "/home/tim/git/ibeam/ibeam/src/authenticate.py", line 219, in authenticate_gateway
EC.element_to_be_clickable(By.ID(var.TWO_FA_INPUT_EL_ID)))
TypeError: 'str' object is not callable
I then tried changing the line that failed to
EC.element_to_be_clickable(two_fa_el[0]))
But then got
Traceback (most recent call last):
File "/home/tim/git/ibeam/ibeam/src/authenticate.py", line 308, in handle_two_fa
two_fa_code = two_fa_handler.get_two_fa_code()
File "/home/tim/git/ibeam/ibeam/src/two_fa_handlers/google_msg_handler.py", line 73, in get_two_fa_code
sms_list_el[0].click() # mark message as read
File "/home/tim/miniconda3/lib/python3.7/site-packages/selenium/webdriver/remote/webelement.py", line 80, in click
self._execute(Command.CLICK_ELEMENT)
File "/home/tim/miniconda3/lib/python3.7/site-packages/selenium/webdriver/remote/webelement.py", line 633, in _execute
return self._parent.execute(command, params)
File "/home/tim/miniconda3/lib/python3.7/site-packages/selenium/webdriver/remote/webdriver.py", line 321, in execute
self.error_handler.check_response(response)
File "/home/tim/miniconda3/lib/python3.7/site-packages/selenium/webdriver/remote/errorhandler.py", line 242, in check_response
raise exception_class(message, screen, stacktrace)
selenium.common.exceptions.ElementClickInterceptedException: Message: element click intercepted: Element <div _ngcontent-yhp-c103="" dir="auto" class="snippet-text ng-star-inserted">...</div> is not clickable at point (163, 194). Other element would receive the click: <div id="loader" aria-hidden="true" dir="ltr" style="display: flex;">...</div>
(Session info: headless chrome=98.0.4758.80)
I can't investigate any further right now, but will look more later.
@Qarj my bad, I've updated my previous comment - it should work now. Thanks for the quick turnaround π
Thanks very much @Voyz , ok so now I have
selenium.common.exceptions.ElementClickInterceptedException: Message: element click intercepted: Element <div _ngcontent-cyd-c103="" dir="auto" class="snippet-text ng-star-inserted">...</div> is not clickable at point (163, 194). Other element would receive the click: <span dir="auto" class="ng-star-inserted">...</span>
(Session info: headless chrome=98.0.4758.80)
Though sometimes it gets past this, then I get log output like this
2022-02-14 09:49:36,257|I| Authentication process succeeded
2022-02-14 09:49:39,354|E| Gateway session active but not authenticated
2022-02-14 09:49:39,354|I| Logging out and restarting the Gateway
2022-02-14 09:49:39,442|I| Gateway logout successful
2022-02-14 09:49:39,577|I| Gateway session found but not authenticated, authenticating...
2022-02-14 09:49:47,802|I| Credentials correct, but Gateway requires two-factor authentication.
2022-02-14 09:49:47,802|I| Attempting to acquire 2FA code from: GoogleMessagesTwoFaHandler(driver_path=/usr/local/bin/selenium/chromedriver)
2022-02-14 09:49:51,742|I| Your requested authentication code: 563043
2022-02-14 09:49:57,640|I| Authentication process succeeded
2022-02-14 09:50:00,814|E| Gateway session active but not authenticated
2022-02-14 09:50:00,814|I| Logging out and restarting the Gateway
2022-02-14 09:50:00,917|I| Gateway logout successful
2022-02-14 09:50:01,008|I| Gateway session found but not authenticated, authenticating...
Tonight I might see if I can figure out how to make it a headed Chrome session, put in some sleeps/pauses and try and figure out what is happening on the UI side...
Interesting, this is what StackOverflow suggests:
"Other element would receive the click: ..." means there is other element above(overlapping) your element(pop up window, page is grayed out(disabled while loading, Some JS running)), so when Selenium trying to click on your element its actually clicking on that blocking element
Indeed it would be helpful to see if the login page displays some modal on top that occludes the submit button - let me know if you find something there π
I've done a little more debugging, after getting a bit confused, I realised that it seems the problem isn't where I thought it was (or perhaps there are multiple issues).
It appears that in the Google 2FA handler it also needs to do a click to mark the message as read.
I added a screenshot to immediately before the click. It failed once, then worked (the click) the next time, however the fact that it failed the first time appeared to confuse things and break the login process.
Here is the screenshot for the time it failed:
It seems that behind this overlay is the list of messages.
Selenium seems to be letting us down, I've tried two different methods of waiting until it is visible, but Selenium is stating the condition is met even though I can clearly see we are still seeing the big overlay I posted in my previous comment. Think I might go down the path of a try / except loop now.
WebDriverWait(driver_2fa, 30).until(EC.element_to_be_clickable((By.CSS_SELECTOR, _GOOG_MESSAGES_LIST_CLASS)))
WebDriverWait(driver_2fa, 30).until(EC.visibility_of(sms_list_el[0]))
I've managed to get the clicking on the 2FA message pretty stable now I think. Selenium does seem to wait for element visibility, it just doesn't seem to wait long enough, it is though the DOM has been built OK but there is a lag to render it sometimes.
Here is the code I'm currently running with
sms_list_el = driver_2fa.find_elements_by_css_selector(_GOOG_MESSAGES_LIST_CLASS)
if not sms_list_el:
_LOGGER.error('Timeout or authentication error while loading SMS messages.')
save_screenshot(driver_2fa, postfix='__google_2fa')
else:
_LOGGER.info(sms_list_el[0].text)
code_two_fa = re.search(r'(\d+)', sms_list_el[0].text).group(1)
_LOGGER.debug('Waiting for the message to be visible.')
WebDriverWait(driver_2fa, 30).until(EC.visibility_of(sms_list_el[0]))
clicked_ok = False
for _ in range(5):
try:
sms_list_el[0].click() # mark message as read
clicked_ok = True
_LOGGER.debug('Clicked message to mark as read OK.')
break
except:
_LOGGER.debug('Failed to mark SMS message as read.')
time.sleep (2)
if not clicked_ok:
_LOGGER.warning('Failed all attempts to mark SMS message as read.')
time.sleep(2) # wait for click to mark message as read
release_chrome_driver(driver_2fa)
return code_two_fa
And some sample log output showing the retry had to be invoked for me
2022-02-14 21:58:57,651|D| Login attempt number 1
2022-02-14 21:59:02,767|D| Submitting the form
2022-02-14 21:59:03,376|I| Credentials correct, but Gateway requires two-factor authentication.
2022-02-14 21:59:03,377|I| Attempting to acquire 2FA code from: GoogleMessagesTwoFaHandler(driver_path=/usr/local/bin/selenium/chromedriver)
2022-02-14 21:59:06,267|I| Your requested authentication code: 122753
2022-02-14 21:59:06,272|D| Waiting for the message to be visible.
2022-02-14 21:59:07,342|D| Failed to mark SMS message as read.
2022-02-14 21:59:09,438|D| Clicked message to mark as read OK.
2022-02-14 21:59:11,487|D| 2FA code returned: 122753
2022-02-14 21:59:11,536|D| Submitting the 2FA form
2022-02-14 21:59:12,266|D| Webpage displayed "Client login succeeds"
Note that clicking on the SMS message doesn't seem to be a critical function for authentication - though maybe it is important to mark the message as read for the next time round? At any rate the 2FA code will be returned now to the calling function regardless of whether it succeeded in clicking the message to mark it as read.
By the way, this evening I haven't seen that competing Gateway session found
error again even though I was getting it a lot this morning. I did notice though a few times the Gateway was left running after ibeam ended (possibly due to crash), but once I killed the process, I never saw it left running again after CTRL-C
which I did a lot tonight.
Have run this on my desktop for 2 days now without issue, and a further day in a local docker build, it seems to have resolved the issue for me.
Hey @Qarj thanks for doing all that fantastic work on this 2faHandler π Very happy to hear that your code indeed seemed to have fixed it. I went ahead and implemented it, adding a couple of tweaks:
_GOOG_MESSAGE_CLICK_RETRIES = int(os.environ.get('IBEAM_GOOG_MESSAGE_CLICK_RETRIES', 5))
"""How many times to try marking the message as read."""
...
if not sms_list_el:
_LOGGER.error('Timeout or authentication error while loading sms messages.')
save_screenshot(driver_2fa, postfix='__google_2fa')
else:
_LOGGER.info(sms_list_el[0].text)
code_two_fa = re.search(r'(\d+)', sms_list_el[0].text).group(1)
_LOGGER.debug('Waiting for SMS message to be visible')
WebDriverWait(driver_2fa, 30).until(EC.visibility_of(sms_list_el[0]))
clicked_ok = False
for i in range(_GOOG_MESSAGE_CLICK_RETRIES):
try:
sms_list_el[0].click() # mark message as read
clicked_ok = True
_LOGGER.debug('SMS message marked as read')
break
except ElementClickInterceptedException as e:
if isinstance(e, ElementClickInterceptedException) \
and 'Other element would receive the click' in str(e):
_LOGGER.warning(f'Failed marking SMS message as read due to obstructing elements')
else:
_LOGGER.exception(f'Exception while marking SMS message as read: {e}')
save_screenshot(driver_2fa, postfix='__google_2fa')
_LOGGER.debug(f'Retrying clicking SMS message {_GOOG_MESSAGE_CLICK_RETRIES - i - 1} more times.')
time.sleep(2)
if not clicked_ok:
_LOGGER.warning('Failed all attempts to mark SMS message as read')
time.sleep(2) # wait for click to mark message as read
release_chrome_driver(driver_2fa)
The changes include:
ElementClickInterceptedException
containing Other element would receive the click
without verbose exception log.I've just released this version as v0.4.0-rc7
- could I ask you to try using it and letting me know if it works for you?
Note that clicking on the SMS message doesn't seem to be a critical function for authentication - though maybe it is important to mark the message as read for the next time round?
I'm not 100% sure, but I think it is important that we mark them as read. The CSS selector we're matching for when reading messages is .text-content.unread .snippet-text
.
If messages don't get marked as read, next time the handler requires the 2FA code and the SMS message hasn't arrived yet it may pick up an older 2FA message and cause an erroneous authentication attempt.
If we rely on marking them as read and later look only for ones that are unread - and there isn't any - the handler will error out and retry, under the assumption in the meantime the new 2FA message will have arrived.
Thanks very much @Voyz , it looks great, I'll install the new docker image this evening and will run it over the weekend :-)
Hi @Voyz unfortunately I'm getting a weird error when I try to do a docker run ...
standard_init_linux.go:228: exec user process caused: no such file or directory
Stack overflow is suggesting this: https://stackoverflow.com/questions/51508150/standard-init-linux-go190-exec-user-process-caused-no-such-file-or-directory
Not sure if this is relevant in this situation, maybe CRLF?
Hey @Qarj that's correct - thanks for pointing me in the right direction right away π Sometimes my IDE changes them without me noticing. Just updated rc7
with the fix and tested that the container can start. Sorry about this π
Thanks @Voyz , ok I'm up and running again :smile: The fail safe code appears to be working, it was used right away, I'll keep an eye on it over the weekend
2022-02-19 10:20:35,611|I| Authentication process succeeded
2022-02-19 10:20:38,689|E| Gateway session active but not authenticated
2022-02-19 10:20:38,689|I| Logging out and restarting the Gateway
2022-02-19 10:20:38,767|I| Gateway logout successful
2022-02-19 10:20:38,836|I| Gateway session found but not authenticated, authenticating...
2022-02-19 10:20:47,285|I| Credentials correct, but Gateway requires two-factor authentication.
2022-02-19 10:20:47,285|I| Attempting to acquire 2FA code from: GoogleMessagesTwoFaHandler(driver_path=/usr/bin/chromedriver)
2022-02-19 10:20:51,046|I| Your requested authentication code: 345801
2022-02-19 10:20:52,133|W| Failed marking SMS message as read due to obstructing elements
2022-02-19 10:20:58,965|I| Authentication process succeeded
2022-02-19 10:21:02,052|I| Gateway running and authenticated.
2022-02-19 10:21:02,074|I| Starting maintenance with interval 60 seconds
Hi @Voyz it looks like maybe you didn't push the branch to GitHub for this change? I'm getting a weird behaviour where it doesn't seem to be doing the retry even though Failed marking SMS message as read due to obstructing elements
is written to log and I want to try and figure out why... :)
Oh! Unfortunately a new screen is showing after submitting 2FA auth code...
It seems after two minutes the promo message automatically continues on, so a workaround might be --env IBEAM_OAUTH_TIMEOUT=150
, though when I tried this I started getting the dreaded Authenticated but competing Gateway session found, reauthenticating...
again, so will need to check later.
Hey @Qarj thanks for reporting π My apologies, I indeed forgot to push the changes out - just did now.
Also, note there's another issue tracking that new IB key promo popup: #68
Hi,
A previously working ibeam docker container is no longer working, and it seems likely that it could be related to this issue. I was on rc6 when this issue started, moving to rc8 did not fix it.
I get these logs repeating:
Mar 10 08:50:23 Debian-109-buster-64-minimal docker[362]: 2022-03-10 08:50:23,464|E| Timeout reached when waiting for authentication. Consider increasing IBEAM_PAGE_LOAD_TIMEOUT. Er
Mar 10 08:50:23 Debian-109-buster-64-minimal docker[362]: 2022-03-10 08:50:23,544|I| Authentication process failed
Setting IBEAM_PAGE_LOAD_TIMEOUT to 180 didn't fix it. I'm happy to help fix / test things, thanks for your work!
Hey @Voyz, I am getting this issue trying to authenticate using 2FA EXTERNAL REQUEST HANDLER but the image is not recieving the code even though when performed a request manually, I get the code. I suggest that there should be waiting time before a request is made to the endpoint for new security code. How can I add that. Here is the logs: `Java Version: 11.0.12
version: ed4af2592e9dd4a784d5403843bd18292fd441ea Fri, 9 Nov 2018 13:23:18 -0500
This is a Beta release of the Client Portal Gateway for any issues, please contact api@ibkr.com and include a copy of your logs
https://www.interactivebrokers.com/api/doc.html
Open https://localhost:5000/ to login App demo is available after you login under: https://localhost:5000/demo/ 2022-04-08 18:08:18,409|I| No active sessions, logging in... 2022-04-08 18:08:28,715|I| Credentials correct, but Gateway requires two-factor authentication. 2022-04-08 18:08:28,715|I| Attempting to acquire 2FA code from: ExternalRequestTwoFaHandler(method=GET, url=-------, timeout=180, params=None, headers=None) 2022-04-08 18:08:30,068|E| Error displayed by the login webpage: failed 2022-04-08 18:08:36,897|I| Credentials correct, but Gateway requires two-factor authentication. 2022-04-08 18:08:36,897|I| Attempting to acquire 2FA code from: ExternalRequestTwoFaHandler(method=GET, url=-------, timeout=180, params=None, headers=None) 2022-04-08 18:08:37,922|E| Error displayed by the login webpage: failed 2022-04-08 18:08:44,725|I| Credentials correct, but Gateway requires two-factor authentication. 2022-04-08 18:08:44,726|I| Attempting to acquire 2FA code from: ExternalRequestTwoFaHandler(method=GET, url=-------, timeout=180, params=None, headers=None) 2022-04-08 18:08:45,803|E| Error displayed by the login webpage: failed`
for security reason I have hidden the url to make request to.
I just installed 0.4.0 from docker hub, seems to be working great so far with 2FA, thanks Voyz!
@matthewrobertbell thanks for reporting your problem - could I ask you to provide a full debug log of that happening?
@murtazayusuf thanks for providing the details - could you run IBeam in debug mode and see what is output then?
@Voyz this was fixed in one of the release candidates, thank you!
Closing this issue due to lack of activity. Feel free to reopen if you'd like to continue the discussion π
@Voyz I encouter this issue, after filling user name / password, I was expecting to reach the 2FA branch, but seems not. did I miss something important?
Thanks
2023-01-16 14:57:27,852|I| ############ Starting IBeam version 0.4.3 ############ 2023-01-16 14:57:27,854|I| Secrets source: env 2023-01-16 14:57:36,617|I| Health server started at port=5001 try_authenticating status.authenticated 0 status.competing 0 2023-01-16 14:57:40,503|I| No active sessions, logging in... 2023-01-16 14:57:40,504|I| Loading auth webpage at https://localhost:5000/sso/Login?forwardTo=22&RL=1&ip2loc=on DevTools listening on ws://127.0.0.1:9222/devtools/browser/4080ac13-5177-40bb-b4f5-7fb5edd835d4 2023-01-16 14:57:43,941|I| Gateway auth webpage loaded 2023-01-16 14:57:49,018|I| Submitting the form 2023-01-16 14:58:19,461|E| Timeout reached when waiting for authentication. Consider increasing IBEAM_PAGE_LOAD_TIMEOUT. Error: "" at File "D:\workspace\ibkr\ibeam-master\ibeam\src\authenticate.py", line 205, in authenticate_gateway trigger = WebDriverWait(driver, var.OAUTH_TIMEOUT).until( 2023-01-16 14:58:22,696|I| Authentication process failed 2023-01-16 14:58:22,698|I| Starting maintenance with interval 60 seconds
@coldcodefire I think you address this same problem already in https://github.com/Voyz/ibeam/issues/126 - let me know if its something different though
Describe the bug Since around 2 PM Sunday UK time I got into a fail loop authenticating with these error messages
To Reproduce Steps to reproduce the behavior: Authenticate using 2FA with Google Messages.
Environment Docker image or standalone: voyz/ibeam 0.4.0-rc6 e3d3b268f7cc
Suggest a Fix I did try to debug the problem.
The element id hasn't changed.
However it appears that maybe they have changed things so that you need to click into the 2FA field first before typing into it. Am only guessing, but the fact that JavaScript is run on focus suggests that focusing the element is important.