search

Voyz / ibeam

IBeam is an authentication and maintenance tool used for the Interactive Brokers Client Portal Web API Gateway.
Apache License 2.0
580 stars 115 forks source link

Validation result is False when IBeam attempted to extend the SSO token #164

Closed Sairav closed 8 months ago

Sairav commented 1 year ago

Describe the bug Connection with Gateway keeps breaking ->

2023-11-05 06:08:07,798|I| Gateway running and authenticated, session id: 0bb73cc1000b743e34fb5bd9bd65abcc, server name: JifH11119
2023-11-05 06:08:34,359|I| Maintenance
2023-11-05 06:08:35,217|I| Gateway running and authenticated, session id: 0bb73cc1000b743e34fb5bd9bd65abcc, server name: JifH11119
2023-11-05 06:09:34,359|I| Maintenance
2023-11-05 06:09:35,211|I| Gateway running and authenticated, session id: 0bb73cc1000b743e34fb5bd9bd65abcc, server name: JifH11119
2023-11-05 06:09:37,498|W| Validation result is False when IBeam attempted to extend the SSO token. This could indicate token authentication issues.

To Reproduce Steps to reproduce the behavior:

  1. Run the Ibeam container ->

docker run --env-file env.list --env IBEAM_PAGE_LOAD_TIMEOUT=30 --env IBEAM_AUTHENTICATION_STRATEGY=B -p 5000:5000 voyz/ibeam

  1. Observe the logs mentioning " Validation result is False when IBeam attempted to extend the SSO token. This could indicate token authentication issues."

Expected behavior Gateway running and authenticated

Environment IBeam version: Docker image or standalone: voyz/ibeam:latest (v0.5.0) Python version (standalone users only): OS: WINDOWS

Additional context I am able to login to the Client Portal from website directly. I am ensuring before starting container , that I am logged out of the website client portal.

More Logs =>


Java Version: 11.0.20
****************************************************
version: a27ed42161ad96c53e715ca5c5e3e3fa4cff5262 Mon, 24 Apr 2023 15:41:53 -0400
****************************************************
This is 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#/
2023-11-05 06:07:39,191|I| Gateway connection established
2023-11-05 06:07:40,917|I| Attempt number 2
2023-11-05 06:07:42,708|I| Max request retries reached after 2 attempts. Consider increasing the retries by setting IBEAM_REQUEST_RETRIES environment variable
2023-11-05 06:07:42,708|I| NO SESSION Status(running=True, session=False, connected=False, authenticated=False, competing=False, collision=False, session_id=None, server_name=None, server_version=None, expires=None)
2023-11-05 06:07:42,708|I| Authentication strategy: "B"
2023-11-05 06:07:42,708|I| No active sessions, logging in...
2023-11-05 06:07:42,708|I| Loading auth webpage at https://localhost:5000/sso/Login?forwardTo=22&RL=1&ip2loc=on
2023-11-05 06:07:56,198|I| Gateway auth webpage loaded
2023-11-05 06:07:56,198|I| Login attempt number 1
2023-11-05 06:08:01,541|I| Submitting the form
2023-11-05 06:08:05,787|I| Webpage displayed "Client login succeeds"
2023-11-05 06:08:06,787|I| Cleaning up the resources. Display: <pyvirtualdisplay.display.Display object at 0x7f0efd9e1f10> | Driver: <selenium.webdriver.chrome.webdriver.WebDriver (session="dc6f5538bedc38706c3ac071d2b17a77")>
2023-11-05 06:08:06,855|I| Logging in succeeded
2023-11-05 06:08:07,798|I| AUTHENTICATED Status(running=True, session=True, connected=True, authenticated=True, competing=False, collision=False, session_id='0bb73cc1000b743e34fb5bd9bd65abcc', server_name='JifH11119', server_version='Build 10.25.0i, Oct 27, 2023 12:12:00 PM', expires=599020)
2023-11-05 06:08:07,798|I| Gateway running and authenticated, session id: 0bb73cc1000b743e34fb5bd9bd65abcc, server name: JifH11119
2023-11-05 06:08:34,359|I| Maintenance
2023-11-05 06:08:35,217|I| Gateway running and authenticated, session id: 0bb73cc1000b743e34fb5bd9bd65abcc, server name: JifH11119
2023-11-05 06:09:34,359|I| Maintenance
2023-11-05 06:09:35,211|I| Gateway running and authenticated, session id: 0bb73cc1000b743e34fb5bd9bd65abcc, server name: JifH11119
2023-11-05 06:09:37,498|W| Validation result is False when IBeam attempted to extend the SSO token. This could indicate token authentication issues.
2023-11-05 06:10:34,359|I| Maintenance
2023-11-05 06:10:35,224|I| Gateway running and authenticated, session id: 0bb73cc1000b743e34fb5bd9bd65abcc, server name: JifH11119
2023-11-05 06:11:34,359|I| Maintenance
2023-11-05 06:11:35,224|I| Gateway running and authenticated, session id: 0bb73cc1000b743e34fb5bd9bd65abcc, server name: JifH11119
2023-11-05 06:12:34,359|I| Maintenance
2023-11-05 06:12:35,204|I| Gateway running and authenticated, session id: 0bb73cc1000b743e34fb5bd9bd65abcc, server name: JifH11119
2023-11-05 06:13:34,358|I| Maintenance
2023-11-05 06:13:35,200|I| Gateway running and authenticated, session id: 0bb73cc1000b743e34fb5bd9bd65abcc, server name: JifH11119
2023-11-05 06:13:37,686|W| Validation result is False when IBeam attempted to extend the SSO token. This could indicate token authentication issues.
2023-11-05 06:14:34,358|I| Maintenance
2023-11-05 06:14:35,214|I| Gateway running and authenticated, session id: 0bb73cc1000b743e34fb5bd9bd65abcc, server name: JifH11119
2023-11-05 06:14:36,325|W| Validation result is False when IBeam attempted to extend the SSO token. This could indicate token authentication issues.
2023-11-05 06:15:34,358|I| Maintenance
2023-11-05 06:15:35,320|I| Gateway running and authenticated, session id: 0bb73cc1000b743e34fb5bd9bd65abcc, server name: JifH11119
2023-11-05 06:16:34,358|I| Maintenance
2023-11-05 06:16:36,524|I| Attempt number 2
2023-11-05 06:16:38,683|I| Max request retries reached after 2 attempts. Consider increasing the retries by setting IBEAM_REQUEST_RETRIES environment variable
2023-11-05 06:16:38,683|I| NO SESSION Status(running=True, session=False, connected=False, authenticated=False, competing=False, collision=False, session_id=None, server_name=None, server_version=None, expires=None)
2023-11-05 06:16:38,683|I| Authentication strategy: "B"
2023-11-05 06:16:38,683|I| No active sessions, logging in...
2023-11-05 06:16:38,684|I| Loading auth webpage at https://localhost:5000/sso/Login?forwardTo=22&RL=1&ip2loc=on
2023-11-05 06:16:52,050|I| Gateway auth webpage loaded
2023-11-05 06:16:52,050|I| Login attempt number 1
2023-11-05 06:16:57,366|I| Submitting the form
2023-11-05 06:17:02,014|I| Webpage displayed "Client login succeeds"
2023-11-05 06:17:03,014|I| Cleaning up the resources. Display: <pyvirtualdisplay.display.Display object at 0x7f0efc0840d0> | Driver: <selenium.webdriver.chrome.webdriver.WebDriver (session="2607d9c18768de0a1dd8b8e2c8b374c9")>
2023-11-05 06:17:03,073|I| Logging in succeeded
2023-11-05 06:17:04,561|I| NO SESSION Status(running=True, session=False, connected=False, authenticated=False, competing=False, collision=False, session_id=None, server_name=None, server_version=None, expires=None)
2023-11-05 06:17:04,561|E| Repeatedly reauthenticating failed 3 times. Killing the Gateway and restarting the authentication process.
2023-11-05 06:17:34,358|I| Maintenance
2023-11-05 06:17:34,359|I| Gateway not found, starting new one...
2023-11-05 06:17:34,359|I| Note that the Gateway log below may display "Open https://localhost:[PORT] to login" - ignore this command.
2023-11-05 06:17:34,359|I| Starting Gateway as Linux process with params: ['bash', 'bin/run.sh', 'root/conf.yaml']
running
 runtime path : root:dist/ibgroup.web.core.iblink.router.clientportal.gw.jar:build/lib/runtime/*
 config file  : root/conf.yaml
2023-11-05 06:17:34,363|I| Gateway started with pids: [1019]
2023-11-05 06:17:34,364|I| Cannot ping Gateway. Retrying for another 20 seconds
WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by io.netty.util.internal.ReflectionUtil (file:/srv/clientportal.gw/build/lib/runtime/netty-common-4.1.15.Final.jar) to constructor java.nio.DirectByteBuffer(long,int)
WARNING: Please consider reporting this to the maintainers of io.netty.util.internal.ReflectionUtil
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
 -> mount demo on /demo
Java Version: 11.0.20
****************************************************
version: a27ed42161ad96c53e715ca5c5e3e3fa4cff5262 Mon, 24 Apr 2023 15:41:53 -0400
****************************************************
This is 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#/
2023-11-05 06:17:38,683|I| Gateway connection established
2023-11-05 06:17:40,306|I| Attempt number 2
2023-11-05 06:17:41,962|I| Max request retries reached after 2 attempts. Consider increasing the retries by setting IBEAM_REQUEST_RETRIES environment variable
2023-11-05 06:17:41,962|I| NO SESSION Status(running=True, session=False, connected=False, authenticated=False, competing=False, collision=False, session_id=None, server_name=None, server_version=None, expires=None)
2023-11-05 06:17:41,962|I| Authentication strategy: "B"
2023-11-05 06:17:41,962|I| No active sessions, logging in...
2023-11-05 06:17:41,962|I| Loading auth webpage at https://localhost:5000/sso/Login?forwardTo=22&RL=1&ip2loc=on
2023-11-05 06:18:01,087|I| Gateway auth webpage loaded
2023-11-05 06:18:01,087|I| Login attempt number 1
2023-11-05 06:18:06,422|I| Submitting the form
2023-11-05 06:18:21,613|E| Timeout reached when waiting for authentication. The website seems to not be loaded correctly. Consider increasing IBEAM_PAGE_LOAD_TIMEOUT.
Website URL: https://localhost:5000/sso/Login?forwardTo=22&RL=1&ip2loc=on

Exception:
  File "/usr/local/lib/python3.11/threading.py", line 995, in _bootstrap
    self._bootstrap_inner()
  File "/usr/local/lib/python3.11/threading.py", line 1038, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.11/threading.py", line 975, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.11/concurrent/futures/thread.py", line 83, in _worker
    work_item.run()
  File "/usr/local/lib/python3.11/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/opt/venv/lib/python3.11/site-packages/apscheduler/executors/base.py", line 125, in run_job
    retval = job.func(*job.args, **job.kwargs)
  File "/srv/ibeam/src/gateway_client.py", line 84, in _maintenance
    success, shutdown, status = self.start_and_authenticate(request_retries=self.request_retries)
  File "/srv/ibeam/src/gateway_client.py", line 53, in start_and_authenticate
    success, shutdown, status = self.strategy_handler.try_authenticating(request_retries=request_retries)
  File "/srv/ibeam/src/handlers/strategy_handler.py", line 85, in try_authenticating
    return self._authentication_strategy_B(status, request_retries)
  File "/srv/ibeam/src/handlers/strategy_handler.py", line 140, in _authentication_strategy_B
    return self._log_in(status)
  File "/srv/ibeam/src/handlers/strategy_handler.py", line 151, in _log_in
    success, shutdown = self.login_handler.login()
  File "/srv/ibeam/src/handlers/login_handler.py", line 454, in login
    self.handle_timeout_exception(e, targets, driver, website_version, self.route_auth, self.base_url, self.outputs_dir)
  File "/srv/ibeam/src/handlers/login_handler.py", line 435, in login
    self.attempt(targets, wait_and_identify_trigger, driver)
  File "/srv/ibeam/src/handlers/login_handler.py", line 359, in attempt
    trigger, target = self.step_login(targets, wait_and_identify_trigger, driver, self.secrets_handler.account, self.secrets_handler.password, self.secrets_handler.key, self.presubmit_buffer)
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/ibeam/src/handlers/login_handler.py", line 180, in step_login
    trigger, target = wait_and_identify_trigger(
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/srv/ibeam/src/handlers/login_handler.py", line 67, in _wait_and_identify_trigger
    trigger = WebDriverWait(driver, timeout).until(any_of(*expected_conditions))
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/venv/lib/python3.11/site-packages/selenium/webdriver/support/wait.py", line 95, in until
    raise TimeoutException(message, screen, stacktrace)

  <class 'selenium.common.exceptions.TimeoutException'> Message:

2023-11-05 06:18:21,614|I| Cleaning up the resources. Display: <pyvirtualdisplay.display.Display object at 0x7f0efda2e810> | Driver: <selenium.webdriver.chrome.webdriver.WebDriver (session="c5e6e12dbf1e0b96cbd33014329261d5")>
2023-11-05 06:18:21,697|I| Logging in failed

Suggest a Fix Not sure about the fix , could this be related to an issue at the IBKR ?

Voyz commented 1 year ago

Hey @Sairav thanks for a detailed report and sorry to hear you're running into these issues.

It seems like this is some connectivity issue with/within IBKR. This may be related to #152.

Next time it happens could you try intentionally logging into your Client Portal with the same credentials in order to force a competing session and see if that helps the issue?

Voyz commented 8 months ago

I'm going to close this issue due to inactivity. Thanks for your contribution and please feel free to request a reopen if you'd like to continue the discussion 👍