Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Authentication process failed #141

Closed
thisIsLoading opened this issue May 21, 2023 · 5 comments
Closed

Authentication process failed #141

thisIsLoading opened this issue May 21, 2023 · 5 comments
Labels
bug Something isn't working

Comments

@thisIsLoading
Copy link

Describe the bug
fresh install, first start, was following the guide, results in:

2023-05-21 12:20:01,298|I| ############ Starting IBeam version 0.4.4 ############
2023-05-21T12:20:01.299715145Z 2023-05-21 12:20:01,299|I| Secrets source: env
2023-05-21T12:20:01.300445726Z 2023-05-21 12:20:01,300|I| Health server started at port=5001
2023-05-21T12:20:01.300518964Z 2023-05-21 12:20:01,300|I| Environment variable configuration:
2023-05-21T12:20:01.300531689Z {'INPUTS_DIR': '/srv/inputs/', 'OUTPUTS_DIR': '/srv/outputs', 'GATEWAY_DIR': '/srv/clientportal.gw', 'CHROME_DRIVER_PATH': '/usr/bin/chromedriver', 'GATEWAY_STARTUP': 20, 'GATEWAY_PROCESS_MATCH': 'ibgroup.web.core.clientportal.gw.GatewayStart', 'MAINTENANCE_INTERVAL': 60, 'SPAWN_NEW_PROCESSES': False, 'LOG_LEVEL': 'INFO', 'LOG_TO_FILE': True, 'LOG_FORMAT': '%(asctime)s|%(levelname)-.1s| %(message)s', 'REQUEST_RETRIES': 1, 'REQUEST_TIMEOUT': 15, 'RESTART_FAILED_SESSIONS': True, 'RESTART_WAIT': 15, 'IBEAM_HEALTH_SERVER_PORT': 5001, 'GATEWAY_BASE_URL': 'https://localhost:5000', 'ROUTE_AUTH': '/sso/Login?forwardTo=22&RL=1&ip2loc=on', 'ROUTE_USER': '/v1/api/one/user', 'ROUTE_VALIDATE': '/v1/portal/sso/validate', 'ROUTE_REAUTHENTICATE': '/v1/portal/iserver/reauthenticate?force=true', 'ROUTE_AUTH_STATUS': '/v1/api/iserver/auth/status', 'ROUTE_TICKLE': '/v1/api/tickle', 'ROUTE_LOGOUT': '/v1/api/logout', 'USER_NAME_EL': None, 'PASSWORD_EL': 'password', 'SUBMIT_EL': 'button.btn.btn-lg.btn-primary', 'ERROR_EL': None, 'SUCCESS_EL_TEXT': 'Client login succeeds', 'OAUTH_TIMEOUT': 15, 'PAGE_LOAD_TIMEOUT': 15, 'ERROR_SCREENSHOTS': False, 'MAX_FAILED_AUTH': 5, 'MAX_IMMEDIATE_ATTEMPTS': 10, 'IBKEY_PROMO_EL_CLASS': 'ibkey-promo-skip', 'TWO_FA_EL_ID': 'twofactbase', 'TWO_FA_NOTIFICATION_EL': 'login-step-notification', 'TWO_FA_INPUT_EL_ID': 'chlginput', 'TWO_FA_HANDLER': None, 'STRICT_TWO_FA_CODE': True, 'TWO_FA_SELECT_EL_ID': 'sf_select', 'TWO_FA_SELECT_TARGET': 'IB Key'}
2023-05-21T12:20:01.300880007Z 2023-05-21 12:20:01,300|I| Gateway not found, starting new one...
2023-05-21T12:20:01.300921506Z 2023-05-21 12:20:01,300|I| Note that the Gateway log below may display "Open https://localhost:5000 to login" - ignore this command.
2023-05-21T12:20:01.300958826Z 2023-05-21 12:20:01,300|I| Starting Gateway as Linux process with params: ['bash', 'bin/run.sh', 'root/conf.yaml']
2023-05-21T12:20:01.305436881Z running  
2023-05-21T12:20:01.305452721Z  runtime path : root:dist/ibgroup.web.core.iblink.router.clientportal.gw.jar:build/lib/runtime/*
2023-05-21T12:20:01.305454915Z  config file  : root/conf.yaml
2023-05-21T12:20:01.568683131Z WARNING: An illegal reflective access operation has occurred
2023-05-21T12:20:01.568719530Z 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)
2023-05-21T12:20:01.568727204Z WARNING: Please consider reporting this to the maintainers of io.netty.util.internal.ReflectionUtil
2023-05-21T12:20:01.568732555Z WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
2023-05-21T12:20:01.568737945Z WARNING: All illegal access operations will be denied in a future release
2023-05-21T12:20:01.710159082Z  -> mount demo on /demo
2023-05-21T12:20:01.717720707Z Java Version: 11.0.18
2023-05-21T12:20:01.717752217Z ****************************************************
2023-05-21T12:20:01.717757717Z version: 485dc2d762781c4ff3954ac4fb66a9469a1405f7 Mon, 20 Mar 2023 14:39:35 -0400
2023-05-21T12:20:01.717765732Z ****************************************************
2023-05-21T12:20:01.717782023Z This is the Client Portal Gateway
2023-05-21T12:20:01.717809996Z for any issues, please contact api@ibkr.com
2023-05-21T12:20:01.717823191Z and include a copy of your logs
2023-05-21T12:20:01.717827159Z ****************************************************
2023-05-21T12:20:01.717832889Z https://www.interactivebrokers.com/api/doc.html
2023-05-21T12:20:01.717877053Z ****************************************************
2023-05-21T12:20:01.717902491Z Open https://localhost:5000 to login
2023-05-21T12:20:01.717912330Z App demo is available after you login under: https://localhost:5000/demo#/
2023-05-21T12:20:02.302435096Z 2023-05-21 12:20:02,302|I| Gateway started with pid: 13
2023-05-21T12:20:03.723170548Z 2023-05-21 12:20:03,722|I| Gateway connection established
2023-05-21T12:20:04.255202890Z 2023-05-21 12:20:04,255|I| No active sessions, logging in...
2023-05-21T12:20:04.255281048Z 2023-05-21 12:20:04,255|I| Loading auth webpage at https://localhost:5000/sso/Login?forwardTo=22&RL=1&ip2loc=on
2023-05-21T12:20:05.300855686Z 2023-05-21 12:20:05,298|E| Error encountered during authentication
2023-05-21T12:20:05.300887256Z Traceback (most recent call last):
2023-05-21T12:20:05.300891584Z   File "/srv/ibeam/src/authenticate.py", line 243, in authenticate_gateway
2023-05-21T12:20:05.300895542Z     driver = start_driver(base_url, driver_path)
2023-05-21T12:20:05.300899509Z              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2023-05-21T12:20:05.300902936Z   File "/srv/ibeam/src/authenticate.py", line 432, in start_driver
2023-05-21T12:20:05.300906462Z     driver = new_chrome_driver(driver_path)
2023-05-21T12:20:05.300909889Z              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2023-05-21T12:20:05.300913285Z   File "/srv/ibeam/src/authenticate.py", line 64, in new_chrome_driver
2023-05-21T12:20:05.300917022Z     driver = webdriver.Chrome(driver_path, options=options)
2023-05-21T12:20:05.300921160Z              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2023-05-21T12:20:05.300926099Z   File "/opt/venv/lib/python3.11/site-packages/selenium/webdriver/chrome/webdriver.py", line 76, in __init__
2023-05-21T12:20:05.300932121Z     RemoteWebDriver.__init__(
2023-05-21T12:20:05.300937290Z   File "/opt/venv/lib/python3.11/site-packages/selenium/webdriver/remote/webdriver.py", line 157, in __init__
2023-05-21T12:20:05.300941819Z     self.start_session(capabilities, browser_profile)
2023-05-21T12:20:05.300946187Z   File "/opt/venv/lib/python3.11/site-packages/selenium/webdriver/remote/webdriver.py", line 252, in start_session
2023-05-21T12:20:05.300950716Z     response = self.execute(Command.NEW_SESSION, parameters)
2023-05-21T12:20:05.300955074Z                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2023-05-21T12:20:05.300959522Z   File "/opt/venv/lib/python3.11/site-packages/selenium/webdriver/remote/webdriver.py", line 319, in execute
2023-05-21T12:20:05.300965905Z     response = self.command_executor.execute(driver_command, params)
2023-05-21T12:20:05.300971215Z                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2023-05-21T12:20:05.300975743Z   File "/opt/venv/lib/python3.11/site-packages/selenium/webdriver/remote/remote_connection.py", line 374, in execute
2023-05-21T12:20:05.300980602Z     return self._request(command_info[0], url, body=data)
2023-05-21T12:20:05.301001031Z            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2023-05-21T12:20:05.301006191Z   File "/opt/venv/lib/python3.11/site-packages/selenium/webdriver/remote/remote_connection.py", line 397, in _request
2023-05-21T12:20:05.301011230Z     resp = self._conn.request(method, url, body=body, headers=headers)
2023-05-21T12:20:05.301016881Z            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2023-05-21T12:20:05.301021510Z   File "/opt/venv/lib/python3.11/site-packages/urllib3/_request_methods.py", line 118, in request
2023-05-21T12:20:05.301027291Z     return self.request_encode_body(
2023-05-21T12:20:05.301033542Z            ^^^^^^^^^^^^^^^^^^^^^^^^^
2023-05-21T12:20:05.301038392Z   File "/opt/venv/lib/python3.11/site-packages/urllib3/_request_methods.py", line 217, in request_encode_body
2023-05-21T12:20:05.301044152Z     return self.urlopen(method, url, **extra_kw)
2023-05-21T12:20:05.301048972Z            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2023-05-21T12:20:05.301054272Z   File "/opt/venv/lib/python3.11/site-packages/urllib3/poolmanager.py", line 422, in urlopen
2023-05-21T12:20:05.301059852Z     conn = self.connection_from_host(u.host, port=u.port, scheme=u.scheme)
2023-05-21T12:20:05.301064882Z            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2023-05-21T12:20:05.301070592Z   File "/opt/venv/lib/python3.11/site-packages/urllib3/poolmanager.py", line 303, in connection_from_host
2023-05-21T12:20:05.301075542Z     return self.connection_from_context(request_context)
2023-05-21T12:20:05.301081443Z            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2023-05-21T12:20:05.301086633Z   File "/opt/venv/lib/python3.11/site-packages/urllib3/poolmanager.py", line 328, in connection_from_context
2023-05-21T12:20:05.301150784Z     return self.connection_from_pool_key(pool_key, request_context=request_context)
2023-05-21T12:20:05.301214004Z            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2023-05-21T12:20:05.301258007Z   File "/opt/venv/lib/python3.11/site-packages/urllib3/poolmanager.py", line 351, in connection_from_pool_key
2023-05-21T12:20:05.301328490Z     pool = self._new_pool(scheme, host, port, request_context=request_context)
2023-05-21T12:20:05.301376691Z            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2023-05-21T12:20:05.301402430Z   File "/opt/venv/lib/python3.11/site-packages/urllib3/poolmanager.py", line 265, in _new_pool
2023-05-21T12:20:05.301430012Z     return pool_cls(host, port, **request_context)
2023-05-21T12:20:05.301510284Z            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2023-05-21T12:20:05.301545711Z   File "/opt/venv/lib/python3.11/site-packages/urllib3/connectionpool.py", line 196, in __init__
2023-05-21T12:20:05.301620031Z     timeout = Timeout.from_float(timeout)
2023-05-21T12:20:05.301667070Z               ^^^^^^^^^^^^^^^^^^^^^^^^^^^
2023-05-21T12:20:05.301695183Z   File "/opt/venv/lib/python3.11/site-packages/urllib3/util/timeout.py", line 190, in from_float
2023-05-21T12:20:05.301716634Z     return Timeout(read=timeout, connect=timeout)
2023-05-21T12:20:05.301737062Z            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2023-05-21T12:20:05.301772109Z   File "/opt/venv/lib/python3.11/site-packages/urllib3/util/timeout.py", line 119, in __init__
2023-05-21T12:20:05.301809760Z     self._connect = self._validate_timeout(connect, "connect")
2023-05-21T12:20:05.301848784Z                     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2023-05-21T12:20:05.301898227Z   File "/opt/venv/lib/python3.11/site-packages/urllib3/util/timeout.py", line 156, in _validate_timeout
2023-05-21T12:20:05.301917664Z     raise ValueError(
2023-05-21T12:20:05.301979651Z ValueError: Timeout value connect was <object object at 0x7fef62088590>, but it must be an int, float or None.
2023-05-21T12:20:05.302008065Z 
2023-05-21T12:20:05.302027682Z The above exception was the direct cause of the following exception:
2023-05-21T12:20:05.302059893Z 
2023-05-21T12:20:05.302089038Z Traceback (most recent call last):
2023-05-21T12:20:05.302124024Z   File "/srv/ibeam/src/authenticate.py", line 412, in authenticate_gateway
2023-05-21T12:20:05.302155243Z     raise RuntimeError('Error encountered during authentication') from e
2023-05-21T12:20:05.302180461Z RuntimeError: Error encountered during authentication
2023-05-21T12:20:05.302206209Z 2023-05-21 12:20:05,300|I| Cleaning up the resources. Display: <pyvirtualdisplay.display.Display object at 0x7fef6079a210> | Driver: None
2023-05-21T12:20:05.305270271Z 2023-05-21 12:20:05,305|I| Authentication process failed
2023-05-21T12:20:05.309274602Z 2023-05-21 12:20:05,309|I| Starting maintenance with interval 60 seconds

To Reproduce
Create a docker-compose.yml file with the following contents:

version: "2.1"

services:
  ibeam:
    image: voyz/ibeam
    container_name: ibeam
    env_file:
      - env.list
    ports:
      - 5000:5000
      - 5001:5001
    network_mode: bridge # Required due to clientportal.gw IP whitelist
    restart: 'no' # Prevents IBEAM_MAX_FAILED_AUTH from being exceeded

Create an env.list file in the same directory with the following contents:

IBEAM_ACCOUNT=your_account123
IBEAM_PASSWORD=your_password123

Run the following command:

docker-compose up -d

Expected behavior
A clear and concise description of what you expected to happen.

Environment
IBeam version: 0.4.4
Docker image or standalone: voyz/ibeam
OS: Manjaro Linux

Additional context
n/a

Suggest a Fix
n/a
@thisIsLoading thisIsLoading added the bug Something isn't working label May 21, 2023
@thisIsLoading
Copy link
Author

0.4.5-rc2 seems to fix that but introduces a authentication loop(?)

2023-05-21 13:18:46,900|I| ############ Starting IBeam version 0.4.5-rc1 ############
2023-05-21T13:18:46.902567171Z 2023-05-21 13:18:46,902|I| Secrets source: env
2023-05-21T13:18:46.903228383Z 2023-05-21 13:18:46,903|I| Health server started at port=5001
2023-05-21T13:18:46.903296772Z 2023-05-21 13:18:46,903|I| Environment variable configuration:
2023-05-21T13:18:46.903314466Z {'INPUTS_DIR': '/srv/inputs/', 'OUTPUTS_DIR': '/srv/outputs', 'GATEWAY_DIR': '/srv/clientportal.gw', 'CHROME_DRIVER_PATH': '/usr/bin/chromedriver', 'GATEWAY_STARTUP': 20, 'GATEWAY_PROCESS_MATCH': 'ibgroup.web.core.clientportal.gw.GatewayStart', 'MAINTENANCE_INTERVAL': 60, 'SPAWN_NEW_PROCESSES': False, 'LOG_LEVEL': 'INFO', 'LOG_TO_FILE': True, 'LOG_FORMAT': '%(asctime)s|%(levelname)-.1s| %(message)s', 'REQUEST_RETRIES': 1, 'REQUEST_TIMEOUT': 15, 'RESTART_FAILED_SESSIONS': True, 'RESTART_WAIT': 15, 'IBEAM_HEALTH_SERVER_PORT': 5001, 'GATEWAY_BASE_URL': 'https://localhost:5000', 'ROUTE_AUTH': '/sso/Login?forwardTo=22&RL=1&ip2loc=on', 'ROUTE_USER': '/v1/api/one/user', 'ROUTE_VALIDATE': '/v1/portal/sso/validate', 'ROUTE_REAUTHENTICATE': '/v1/portal/iserver/reauthenticate?force=true', 'ROUTE_AUTH_STATUS': '/v1/api/iserver/auth/status', 'ROUTE_TICKLE': '/v1/api/tickle', 'ROUTE_LOGOUT': '/v1/api/logout', 'USER_NAME_EL': None, 'PASSWORD_EL': 'password', 'SUBMIT_EL': 'button.btn.btn-lg.btn-primary', 'ERROR_EL': None, 'SUCCESS_EL_TEXT': 'Client login succeeds', 'OAUTH_TIMEOUT': 15, 'PAGE_LOAD_TIMEOUT': 15, 'ERROR_SCREENSHOTS': False, 'MAX_FAILED_AUTH': 5, 'MAX_IMMEDIATE_ATTEMPTS': 10, 'IBKEY_PROMO_EL_CLASS': 'ibkey-promo-skip', 'TWO_FA_EL_ID': 'twofactbase', 'TWO_FA_NOTIFICATION_EL': 'login-step-notification', 'TWO_FA_INPUT_EL_ID': 'chlginput', 'TWO_FA_HANDLER': None, 'STRICT_TWO_FA_CODE': True, 'TWO_FA_SELECT_EL_ID': 'sf_select', 'TWO_FA_SELECT_TARGET': 'IB Key'}
2023-05-21T13:18:46.903635393Z 2023-05-21 13:18:46,903|I| Gateway not found, starting new one...
2023-05-21T13:18:46.903678736Z 2023-05-21 13:18:46,903|I| Note that the Gateway log below may display "Open https://localhost:5000 to login" - ignore this command.
2023-05-21T13:18:46.903734671Z 2023-05-21 13:18:46,903|I| Starting Gateway as Linux process with params: ['bash', 'bin/run.sh', 'root/conf.yaml']
2023-05-21T13:18:46.907963087Z running  
2023-05-21T13:18:46.907986922Z  runtime path : root:dist/ibgroup.web.core.iblink.router.clientportal.gw.jar:build/lib/runtime/*
2023-05-21T13:18:46.907991361Z  config file  : root/conf.yaml
2023-05-21T13:18:47.178661549Z WARNING: An illegal reflective access operation has occurred
2023-05-21T13:18:47.178690304Z 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)
2023-05-21T13:18:47.178693099Z WARNING: Please consider reporting this to the maintainers of io.netty.util.internal.ReflectionUtil
2023-05-21T13:18:47.178695063Z WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
2023-05-21T13:18:47.178696866Z WARNING: All illegal access operations will be denied in a future release
2023-05-21T13:18:47.329919535Z  -> mount demo on /demo
2023-05-21T13:18:47.337997940Z Java Version: 11.0.18
2023-05-21T13:18:47.338019261Z ****************************************************
2023-05-21T13:18:47.338037545Z version: 485dc2d762781c4ff3954ac4fb66a9469a1405f7 Mon, 20 Mar 2023 14:39:35 -0400
2023-05-21T13:18:47.338044078Z ****************************************************
2023-05-21T13:18:47.338064176Z This is the Client Portal Gateway
2023-05-21T13:18:47.338082050Z for any issues, please contact api@ibkr.com
2023-05-21T13:18:47.338090856Z and include a copy of your logs
2023-05-21T13:18:47.338108520Z ****************************************************
2023-05-21T13:18:47.338132515Z https://www.interactivebrokers.com/api/doc.html
2023-05-21T13:18:47.338140741Z ****************************************************
2023-05-21T13:18:47.338174956Z Open https://localhost:5000 to login
2023-05-21T13:18:47.338195334Z App demo is available after you login under: https://localhost:5000/demo#/
2023-05-21T13:18:47.905037924Z 2023-05-21 13:18:47,904|I| Gateway started with pid: 13
2023-05-21T13:18:49.121062731Z 2023-05-21 13:18:49,120|I| Gateway connection established
2023-05-21T13:18:49.636231549Z 2023-05-21 13:18:49,636|I| No active sessions, logging in...
2023-05-21T13:18:49.636267938Z 2023-05-21 13:18:49,636|I| Loading auth webpage at https://localhost:5000/sso/Login?forwardTo=22&RL=1&ip2loc=on
2023-05-21T13:18:55.126600661Z 2023-05-21 13:18:55,126|I| Gateway auth webpage loaded
2023-05-21T13:18:55.126649233Z 2023-05-21 13:18:55,126|I| Login attempt number 1
2023-05-21T13:19:00.243496893Z 2023-05-21 13:19:00,243|I| Submitting the form
2023-05-21T13:19:01.913134667Z 2023-05-21 13:19:01,913|I| Webpage displayed "Client login succeeds"
2023-05-21T13:19:03.913423740Z 2023-05-21 13:19:03,913|I| Cleaning up the resources. Display: <pyvirtualdisplay.display.Display object at 0x7f9999c32f50> | Driver: <selenium.webdriver.chrome.webdriver.WebDriver (session="ae3101405df6d31af168ae3fad262920")>
2023-05-21T13:19:03.995790906Z 2023-05-21 13:19:03,995|I| Authentication process succeeded
2023-05-21T13:19:07.469798240Z 2023-05-21 13:19:07,469|E| Gateway session active but not authenticated
2023-05-21T13:19:07.469835630Z 2023-05-21 13:19:07,469|I| Logging out and restarting the Gateway
2023-05-21T13:19:07.958406329Z 2023-05-21 13:19:07,958|I| Gateway logout successful
2023-05-21T13:19:08.444244420Z 2023-05-21 13:19:08,444|I| Gateway session found but not authenticated, authenticating...
2023-05-21T13:19:08.444286109Z 2023-05-21 13:19:08,444|I| Loading auth webpage at https://localhost:5000/sso/Login?forwardTo=22&RL=1&ip2loc=on
2023-05-21T13:19:13.061593099Z 2023-05-21 13:19:13,061|I| Gateway auth webpage loaded
2023-05-21T13:19:13.061622484Z 2023-05-21 13:19:13,061|I| Login attempt number 1
2023-05-21T13:19:18.140280332Z 2023-05-21 13:19:18,140|I| Submitting the form
2023-05-21T13:19:20.193602024Z 2023-05-21 13:19:20,193|I| Webpage displayed "Client login succeeds"
2023-05-21T13:19:22.193910990Z 2023-05-21 13:19:22,193|I| Cleaning up the resources. Display: <pyvirtualdisplay.display.Display object at 0x7f9999c4aed0> | Driver: <selenium.webdriver.chrome.webdriver.WebDriver (session="f5d88e8edc8e0d5a3d523b91dc1f06af")>
2023-05-21T13:19:22.237184902Z 2023-05-21 13:19:22,237|I| Authentication process succeeded
2023-05-21T13:19:25.705098442Z 2023-05-21 13:19:25,704|E| Gateway session active but not authenticated
2023-05-21T13:19:25.705138989Z 2023-05-21 13:19:25,705|I| Logging out and restarting the Gateway
2023-05-21T13:19:26.172520596Z 2023-05-21 13:19:26,172|I| Gateway logout successful
2023-05-21T13:19:27.608216482Z 2023-05-21 13:19:27,608|I| Gateway session found but not authenticated, authenticating...
2023-05-21T13:19:27.608245808Z 2023-05-21 13:19:27,608|I| Loading auth webpage at https://localhost:5000/sso/Login?forwardTo=22&RL=1&ip2loc=on
2023-05-21T13:19:32.157488003Z 2023-05-21 13:19:32,157|I| Gateway auth webpage loaded
2023-05-21T13:19:32.157587852Z 2023-05-21 13:19:32,157|I| Login attempt number 1

@demansou
Copy link

demansou commented May 22, 2023 •
edited

I thought I was going insane. Have a VNet to run my software and was triple checking my network outbound/inbound rules and port mappings.

Seems issue is also present using latest on Azure.

2023-05-22 05:09:13,975|I| Loading auth webpage at https://localhost:5000/sso/Login?forwardTo=22&RL=1&ip2loc=on
2023-05-22 05:09:15,043|E| Error encountered during authentication
Traceback (most recent call last):
File "/srv/ibeam/src/authenticate.py", line 243, in authenticate_gateway
driver = start_driver(base_url, driver_path)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/srv/ibeam/src/authenticate.py", line 432, in start_driver
driver = new_chrome_driver(driver_path)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/srv/ibeam/src/authenticate.py", line 64, in new_chrome_driver
driver = webdriver.Chrome(driver_path, options=options)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/venv/lib/python3.11/site-packages/selenium/webdriver/chrome/webdriver.py", line 76, in init
RemoteWebDriver.init(
File "/opt/venv/lib/python3.11/site-packages/selenium/webdriver/remote/webdriver.py", line 157, in init
self.start_session(capabilities, browser_profile)
File "/opt/venv/lib/python3.11/site-packages/selenium/webdriver/remote/webdriver.py", line 252, in start_session
response = self.execute(Command.NEW_SESSION, parameters)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/venv/lib/python3.11/site-packages/selenium/webdriver/remote/webdriver.py", line 319, in execute
response = self.command_executor.execute(driver_command, params)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/venv/lib/python3.11/site-packages/selenium/webdriver/remote/remote_connection.py", line 374, in execute
return self._request(command_info[0], url, body=data)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/venv/lib/python3.11/site-packages/selenium/webdriver/remote/remote_connection.py", line 397, in _request
resp = self._conn.request(method, url, body=body, headers=headers)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/venv/lib/python3.11/site-packages/urllib3/_request_methods.py", line 118, in request
return self.request_encode_body(
^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/venv/lib/python3.11/site-packages/urllib3/_request_methods.py", line 217, in request_encode_body
return self.urlopen(method, url, **extra_kw)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/venv/lib/python3.11/site-packages/urllib3/poolmanager.py", line 422, in urlopen
conn = self.connection_from_host(u.host, port=u.port, scheme=u.scheme)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/venv/lib/python3.11/site-packages/urllib3/poolmanager.py", line 303, in connection_from_host
return self.connection_from_context(request_context)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/venv/lib/python3.11/site-packages/urllib3/poolmanager.py", line 328, in connection_from_context
return self.connection_from_pool_key(pool_key, request_context=request_context)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/venv/lib/python3.11/site-packages/urllib3/poolmanager.py", line 351, in connection_from_pool_key
pool = self._new_pool(scheme, host, port, request_context=request_context)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/venv/lib/python3.11/site-packages/urllib3/poolmanager.py", line 265, in _new_pool
return pool_cls(host, port, **request_context)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/venv/lib/python3.11/site-packages/urllib3/connectionpool.py", line 196, in init
timeout = Timeout.from_float(timeout)
^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/venv/lib/python3.11/site-packages/urllib3/util/timeout.py", line 190, in from_float
return Timeout(read=timeout, connect=timeout)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/venv/lib/python3.11/site-packages/urllib3/util/timeout.py", line 119, in init
self._connect = self._validate_timeout(connect, "connect")
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/venv/lib/python3.11/site-packages/urllib3/util/timeout.py", line 156, in _validate_timeout
raise ValueError(
ValueError: Timeout value connect was <object object at 0x7f24e7ca87e0>, but it must be an int, float or None.
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/srv/ibeam/src/authenticate.py", line 412, in authenticate_gateway
raise RuntimeError('Error encountered during authentication') from e
RuntimeError: Error encountered during authentication
2023-05-22 05:09:15,047|I| Cleaning up the resources. Display: <pyvirtualdisplay.display.Display object at 0x7f24e63b1ed0> | Driver: None
2023-05-22 05:09:15,052|I| Authentication process failed

Using Linux Azure Container Instance

Name
ibeam
Image
voyz/ibeam
Ports
5000, 5001
CPU cores
1
Memory
1.5 GiB
GPU SKU
None
GPU count
0
Commands
(no commands)

Unfortunately I can't reproduce this on my M2 Pro MBP using Docker Desktop. On Mac, port 5000 is reserved, so I've remapped to 5001 & 5002.

version: "3.4"

services:
  ibeam:
    image: voyz/ibeam
    container_name: ibeam
    env_file:
      - env.list
    ports:
      - 5001:5000
      - 5002:5001
    network_mode: bridge # Required due to clientportal.gw IP whitelist
    restart: 'no' # Prevents IBEAM_MAX_FAILED_AUTH from being exceeded

EDIT: I forced the image to be voyz/ibeam:0.4.5-rc2

Authentication seems to work but it's acting a bit strange:

2023-05-22 05:51:41,180|I| Gateway auth webpage loaded
2023-05-22 05:51:41,181|I| Login attempt number 1
2023-05-22 05:51:46,431|I| Submitting the form
2023-05-22 05:51:47,267|I| Webpage displayed "Client login succeeds"
2023-05-22 05:51:49,268|I| Cleaning up the resources. Display: <pyvirtualdisplay.display.Display object at 0x7fa9b6665390> | Driver: <selenium.webdriver.chrome.webdriver.WebDriver (session="05a51efbe8c70b3c5f8d98dd5b1d24f6")>
2023-05-22 05:51:49,337|I| Authentication process succeeded
2023-05-22 05:51:52,516|E| Gateway session active but not authenticated
2023-05-22 05:51:52,517|I| Logging out and restarting the Gateway
2023-05-22 05:51:52,677|I| Gateway logout successful
2023-05-22 05:51:52,772|I| Gateway session found but not authenticated, authenticating...
2023-05-22 05:51:52,773|I| Loading auth webpage at https://localhost:5000/sso/Login?forwardTo=22&RL=1&ip2loc=on
2023-05-22 05:51:55,217|I| Gateway auth webpage loaded
2023-05-22 05:51:55,218|I| Login attempt number 1
2023-05-22 05:52:00,486|I| Submitting the form
2023-05-22 05:52:01,311|I| Webpage displayed "Client login succeeds"
2023-05-22 05:52:03,311|I| Cleaning up the resources. Display: <pyvirtualdisplay.display.Display object at 0x7fa9b6664550> | Driver: <selenium.webdriver.chrome.webdriver.WebDriver (session="b778cfea8bbbf2a1adb0723efaf48052")>
2023-05-22 05:52:03,366|I| Authentication process succeeded
2023-05-22 05:52:06,472|I| Gateway running and authenticated.
2023-05-22 05:52:06,478|I| Starting maintenance with interval 60 seconds
2023-05-22 05:53:06,479|I| Maintenance
2023-05-22 05:53:06,582|I| Gateway session found but not authenticated, authenticating...
2023-05-22 05:53:06,583|I| Loading auth webpage at https://localhost:5000/sso/Login?forwardTo=22&RL=1&ip2loc=on
2023-05-22 05:53:09,065|I| Gateway auth webpage loaded
2023-05-22 05:53:09,065|I| Login attempt number 1
2023-05-22 05:53:14,323|I| Submitting the form
2023-05-22 05:53:15,108|I| Webpage displayed "Client login succeeds"
2023-05-22 05:53:17,109|I| Cleaning up the resources. Display: <pyvirtualdisplay.display.Display object at 0x7fa9b667d790> | Driver: <selenium.webdriver.chrome.webdriver.WebDriver (session="84d5caade73fae7aaca58f0e6825aff1")>
2023-05-22 05:53:17,166|I| Authentication process succeeded
2023-05-22 05:53:20,287|E| Gateway session active but not authenticated
2023-05-22 05:53:20,287|I| Logging out and restarting the Gateway
2023-05-22 05:53:20,377|I| Gateway logout successful
2023-05-22 05:53:20,504|I| Gateway session found but not authenticated, authenticating...
2023-05-22 05:53:20,505|I| Loading auth webpage at https://localhost:5000/sso/Login?forwardTo=22&RL=1&ip2loc=on
2023-05-22 05:53:22,616|I| Gateway auth webpage loaded
2023-05-22 05:53:22,616|I| Login attempt number 1
2023-05-22 05:53:27,848|I| Submitting the form
2023-05-22 05:53:28,857|I| Webpage displayed "Client login succeeds"
2023-05-22 05:53:30,858|I| Cleaning up the resources. Display: <pyvirtualdisplay.display.Display object at 0x7fa9b68ba450> | Driver: <selenium.webdriver.chrome.webdriver.WebDriver (session="9ce452fe151699fee450df8d12a64c02")>
2023-05-22 05:53:30,905|I| Authentication process succeeded
2023-05-22 05:53:33,990|I| Gateway running and authenticated

No big issues here as everything works fine on my laptop. I'm just trying to deploy my trading strategy to Azure. Might just force v0.4.3 for now since the issue seems to be 0.4.4.

@Voyz
Copy link
Owner

Voyz commented May 23, 2023

Hey @thisIsLoading many thanks for reporting this issue in so much detail 👍 It is the same issue that's described in #140 therefore I'm going to close this one. Nevertheless, thank you for reporting and providing all the info. Also thanks @demansou for sharing your experience.

Just to clarify:

0.4.5-rc2 seems to fix that but introduces a authentication loop(?)

  • Indeed it attempts to fix that problem
  • From what we know, the 'authentication loop' is unrelated from this or other version, and it's just something that sometimes happens with the IBKR CP Web API.

@Voyz Voyz closed this as completed May 23, 2023
@Voyz
Copy link
Owner

Voyz commented Jun 27, 2023

hey @thisIsLoading and @demansou - there is a new WIP version v0.5.0 of IBeam that introduces a new login logic, which should help reduce some of the issues we've been struggling with.

Run the most recent voyz/ibeam:0.5.0-rc* tag of v0.5.0 and set IBEAM_AUTHENTICATION_STRATEGY to B.

See #147 for more details and report any observations directly there.

Thanks 🙏

@demansou
Copy link

Thank you for the hard work! I've been stable with 0.4.5-rc2 so I'll try testing this next weekend!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@demansou @Voyz @thisIsLoading