socat Connection timed out issue

[peebeejay]

Describe the bug

Once again, thank you for all the fantastic work on this docker image!

I have a container running the ib-gateway-docker image that has been running for a few days. The daily restart occurs at 1AM, and last night, around 1 hour after the restart, a set of errors began to appear, which I can't seem to properly understand. Essentially, what I'd like to figure out is the cause of the issue, and whether the issue is solvable here at the container level, or somewhere deeper in the stack, such as with IBC. Any help would be much appreciated!

Is the issue caused by not waiting for the Forking :::4001 onto 0.0.0.0:4003 > trading mode live line to appear?

Ostensibly, the error message was triggered by a 1-min heartbeat related request that I use for uptime monitoring. The python on the client side that makes this request looks something like this:

from ib_insync import IB
import cronitor

ib_monitor = cronitor.Monitor("ib-monitor")

def connect_ibkr_silent(ib_instance, client_id=1):
    port = getIBPort()

    try:
        ib_instance.connect("127.0.0.1", port, clientId=client_id, timeout=10)
    except Exception as e:
        return

def ping_ib():
    try:
        connect_ibkr_silent(ib_for_ping, client_id=999)
        if ib_for_ping.isConnected():
            logger.trace("Pinging cronitor (ib-monitor)...")
            ib_monitor.ping(env=ENV, name="ibkr")
        ib_for_ping.disconnect()

    except Exception:
        ib_for_ping.disconnect()

The logs from the docker container look something like this:

ib-gateway-1  | 2024-02-08 01:00:06:642 IBC: detected frame entitled: Authenticating...; event=Activated                                                                                                                                                                         
ib-gateway-1  | 2024-02-08 01:00:06:644 IBC: detected frame entitled: Authenticating...; event=Focused                                                                                                                                                                           
ib-gateway-1  | 2024-02-08 01:00:06:644 IBC: detected frame entitled: Authenticating...; event=Opened                                                                                                                                                                            
ib-gateway-1  | LogModuleConfigurator-Init: Log4j Ver2.x found on classpath                                                                                                                                                                                                      
ib-gateway-1  | LogModuleConfigurator-Init: LogModuleConfigurator initialized with Log4j Verd.x                                                                                                                                                                                  
ib-gateway-1  | 2024-02-08 01:00:09:033 IBC: detected frame entitled: Starting application...; event=Lost focus                                                                                                                                                                  
ib-gateway-1  | 2024-02-08 01:00:09:048 IBC: detected dialog entitled: U11****** Trader Workstation Configuration; event=Opened                                                                                                                                                  
ib-gateway-1  | 2024-02-08 01:00:09:048 IBC: detected frame entitled: Starting application...; event=Deactivated                                                                                                                                                                 
ib-gateway-1  | 2024-02-08 01:00:09:048 IBC: Got config dialog from future                                                                                                                                                                                                       
ib-gateway-1  | 2024-02-08 01:00:09:048 IBC: Got config dialog from future                                                                                                                                                                                                       
ib-gateway-1  | 2024-02-08 01:00:09:048 IBC: Got config dialog from future                                                                                                                                                                                                       
ib-gateway-1  | 2024-02-08 01:00:09:048 IBC: detected dialog entitled: U11****** Trader Workstation Configuration; event=Activated                                                                                                                                               
ib-gateway-1  | 2024-02-08 01:00:09:049 IBC: detected dialog entitled: U11****** Trader Workstation Configuration; event=Focused                                                                                                                                                 
ib-gateway-1  | 2024-02-08 01:00:09:050 IBC: detected dialog entitled: U11****** Trader Workstation Configuration; event=Lost focus                                                                                                                                              
ib-gateway-1  | 2024-02-08 01:00:09:050 IBC: detected frame entitled: Starting application...; event=Closed                                                                                                                                                                      
ib-gateway-1  | 2024-02-08 01:00:09:050 IBC: Login has completed                                                                                                                                                                                                                 
ib-gateway-1  | 2024-02-08 01:00:09:051 IBC: detected dialog entitled: U11****** Trader Workstation Configuration; event=Focused                                                                                                                                                 
ib-gateway-1  | 2024-02-08 01:00:09:051 IBC: Setting ReadOnlyApi                                                                                                                                                                                                                 
ib-gateway-1  | 2024-02-08 01:00:09:214 IBC: Read-Only API checkbox is already set to: false                                                                                                                                                                                     
ib-gateway-1  | 2024-02-08 01:00:09:226 IBC: 'Bypass Order Precautions for API Orders' is already selected                                                                                                                                                                       
ib-gateway-1  | 2024-02-08 01:00:09:226 IBC: 'Bypass Bond warning for API Orders' is already selected                                                                                                                                                                            
ib-gateway-1  | 2024-02-08 01:00:09:226 IBC: 'Bypass negative yield to worst confirmation for API Orders' is already selected                                                                                                                                                    
ib-gateway-1  | 2024-02-08 01:00:09:226 IBC: 'Bypass Called Bond warning for API Orders' is already selected                                                                                                                                                                     
ib-gateway-1  | 2024-02-08 01:00:09:226 IBC: 'Bypass "same action pair trade" warning for API orders.' is already selected                                                                                                                                                       
ib-gateway-1  | 2024-02-08 01:00:09:226 IBC: 'Bypass price-based volatility risk warning for API Orders' is already selected                                                                                                                                                     
ib-gateway-1  | 2024-02-08 01:00:09:226 IBC: 'Bypass US Stocks market data in shares warning for API Orders' is already selected                                                                                                                                                 
ib-gateway-1  | 2024-02-08 01:00:09:226 IBC: 'Bypass Redirect Order warning for Stock API Orders' is already selected                                                                                                                                                            
ib-gateway-1  | 2024-02-08 01:00:09:226 IBC: Checkbox 'Bypass No Overfill Protection precaution for destinations where implied natively' not found                                                                                                                               
ib-gateway-1  | 2024-02-08 01:00:09:226 IBC: Setting Auto restart time                                                                                                                                                                                                           
ib-gateway-1  | 2024-02-08 01:00:09:245 IBC: Auto restart time already set to 01:00 AM                                                                                                                                                                                           
ib-gateway-1  | 2024-02-08 01:00:09:262 IBC: Configuration tasks completed                                                                                                                                                                                                       
ib-gateway-1  | 2024-02-08 01:00:09:263 IBC: Click button: OK                                                                                                                                                                                                                    
ib-gateway-1  | 2024-02-08 01:00:09:359 IBC: detected dialog entitled: U11****** Trader Workstation Configuration; event=Lost focus                                                                                                                                              
ib-gateway-1  | 2024-02-08 01:00:09:359 IBC: detected dialog entitled: U11****** Trader Workstation Configuration; event=Deactivated                                                                                                                                             
ib-gateway-1  | 2024-02-08 01:00:09:359 IBC: detected dialog entitled: U11****** Trader Workstation Configuration; event=Closed                                                                                                                                                  
ib-gateway-1  | 2024-02-08 01:00:09:370 IBC: detected dialog entitled: Pending Tasks; event=Closed                                                                                                                                                                               
ib-gateway-1  | 2024/02/08 01:57:50 socat[24203] E connect(5, AF=2 127.0.0.1:4001, 16): Connection timed out                                                                                                                                                                     
ib-gateway-1  | 2024/02/08 01:58:53 socat[24204] E connect(5, AF=2 127.0.0.1:4001, 16): Connection timed out                                                                                                                                                                     
ib-gateway-1  | 2024/02/08 01:59:00 socat[24205] E connect(5, AF=2 127.0.0.1:4001, 16): Connection timed out                                                                                                                                                                     
ib-gateway-1  | 2024/02/08 02:00:11 socat[24206] E connect(5, AF=2 127.0.0.1:4001, 16): Connection timed out                                                                                                                                                                     
ib-gateway-1  | 2024/02/08 02:01:21 socat[24207] E connect(5, AF=2 127.0.0.1:4001, 16): Connection timed out                                                                                                                                                                     
ib-gateway-1  | 2024/02/08 02:02:33 socat[24208] E connect(5, AF=2 127.0.0.1:4001, 16): Connection timed out                                                                                                                                                                     
ib-gateway-1  | 2024/02/08 02:03:42 socat[24209] E connect(5, AF=2 127.0.0.1:4001, 16): Connection timed out                                                                                                                                                                     
ib-gateway-1  | 2024/02/08 02:04:52 socat[24210] E connect(5, AF=2 127.0.0.1:4001, 16): Connection timed out                                                                                                                                                                     
ib-gateway-1  | 2024/02/08 02:06:03 socat[24211] E connect(5, AF=2 127.0.0.1:4001, 16): Connection timed out                                                                                                                                                                     
ib-gateway-1  | 2024/02/08 02:07:13 socat[24212] E connect(5, AF=2 127.0.0.1:4001, 16): Connection timed out                                                                                                                                                                     
ib-gateway-1  | 2024/02/08 02:08:25 socat[24213] E connect(5, AF=2 127.0.0.1:4001, 16): Connection timed out                                                                                                                                                                     
ib-gateway-1  | 2024/02/08 02:08:58 socat[24214] E connect(5, AF=2 127.0.0.1:4001, 16): Connection timed out                                                                                                                                                                     
ib-gateway-1  | 2024/02/08 02:09:34 socat[24215] E connect(5, AF=2 127.0.0.1:4001, 16): Connection timed out                                                                                                                                                                     
ib-gateway-1  | 2024/02/08 02:10:46 socat[24216] E connect(5, AF=2 127.0.0.1:4001, 16): Connection timed out                                                                                                                                                                     
ib-gateway-1  | 2024/02/08 02:11:56 socat[24217] E connect(5, AF=2 127.0.0.1:4001, 16): Connection timed out                                                                                                                                                                     
ib-gateway-1  | 2024/02/08 02:13:05 socat[24218] E connect(5, AF=2 127.0.0.1:4001, 16): Connection timed out                                                                                                                                                                     
ib-gateway-1  | 2024/02/08 02:14:17 socat[24219] E connect(5, AF=2 127.0.0.1:4001, 16): Connection timed out                                                                                                                                                                     
ib-gateway-1  | 2024/02/08 02:15:27 socat[24220] E connect(5, AF=2 127.0.0.1:4001, 16): Connection timed out                                                                                                                                                                     
ib-gateway-1  | 2024/02/08 02:16:38 socat[24221] E connect(5, AF=2 127.0.0.1:4001, 16): Connection timed out                                                                                                                                                                     
ib-gateway-1  | 2024/02/08 02:17:48 socat[24222] E connect(5, AF=2 127.0.0.1:4001, 16): Connection timed out                                                                                                                                                                     
ib-gateway-1  | 2024/02/08 02:18:58 socat[24223] E connect(5, AF=2 127.0.0.1:4001, 16): Connection timed out                                                                                                                                                                     
ib-gateway-1  | 2024/02/08 02:19:10 socat[24224] E connect(5, AF=2 127.0.0.1:4001, 16): Connection timed out                                                                                                                                                                     

To Reproduce

docker run command: docker compose up

docker-compose.yml

version: "3.4"

name: ib-gateway-prod
services:
  ib-gateway:
    platform: linux/x86_64
    restart: always
    build:
      context: ./stable
      tags:
        - "ghcr.io/gnzsnz/ib-gateway:stable"
    image: ghcr.io/gnzsnz/ib-gateway:stable
    environment:
      TWS_USERID: ${TWS_USERID}
      TWS_PASSWORD: ${TWS_PASSWORD}
      TRADING_MODE: ${TRADING_MODE:-paper}
      TWS_SETTINGS_PATH: ${TWS_SETTINGS_PATH:-}
      READ_ONLY_API: ${READ_ONLY_API:-}
      VNC_SERVER_PASSWORD: ${VNC_SERVER_PASSWORD:-}
      TWOFA_TIMEOUT_ACTION: ${TWOFA_TIMEOUT_ACTION:-exit}
      BYPASS_WARNING: ${BYPASS_WARNING:-}
      AUTO_RESTART_TIME: ${AUTO_RESTART_TIME:-}
      AUTO_LOGOFF_TIME: ${AUTO_LOGOFF_TIME:-}
      SAVE_TWS_SETTINGS: ${SAVE_TWS_SETTINGS:-}
      RELOGIN_AFTER_TWOFA_TIMEOUT: ${RELOGIN_AFTER_TWOFA_TIMEOUT:-no}
      TWOFA_EXIT_INTERVAL: ${TWOFA_EXIT_INTERVAL:-60}
      TIME_ZONE: ${TIME_ZONE:-Etc/UTC}
      TZ: ${TIME_ZONE:-Etc/UTC}
      CUSTOM_CONFIG: ${CUSTOM_CONFIG:-NO}
      JAVA_HEAP_SIZE: ${JAVA_HEAP_SIZE:-}
      SSH_TUNNEL: ${SSH_TUNNEL:-}
      SSH_OPTIONS: ${SSH_OPTIONS:-}
      SSH_ALIVE_INTERVAL: ${SSH_ALIVE_INTERVAL:-}
      SSH_ALIVE_COUNT: ${SSH_ALIVE_COUNT:-}
      SSH_PASSPHRASE: ${SSH_PASSPHRASE:-}
      SSH_REMOTE_PORT: ${SSH_REMOTE_PORT:-}
      SSH_USER_TUNNEL: ${SSH_USER_TUNNEL:-}
      SSH_RESTART: ${SSH_RESTART:-}
      SSH_VNC_PORT: ${SSH_VNC_PORT:-}
    ports:
      - "127.0.0.1:4001:4003"
      # - "127.0.0.1:4002:4004"
      # - "127.0.0.1:5900:5900"

docker compose config

name: ib-gateway-prod
services:
  ib-gateway:
    build:
      context: /home/ethter2/quant/git/trading-infra/cruncher/services/ib-gateway-docker/prod/stable
      dockerfile: Dockerfile
      tags:
        - ghcr.io/gnzsnz/ib-gateway:stable
    environment:
      AUTO_LOGOFF_TIME: ""
      AUTO_RESTART_TIME: 01:00 AM
      BYPASS_WARNING: "yes"
      CUSTOM_CONFIG: "NO"
      JAVA_HEAP_SIZE: "1024"
      READ_ONLY_API: "no"
      RELOGIN_AFTER_TWOFA_TIMEOUT: "yes"
      SAVE_TWS_SETTINGS: ""
      SSH_ALIVE_COUNT: ""
      SSH_ALIVE_INTERVAL: ""
      SSH_OPTIONS: ""
      SSH_PASSPHRASE: ""
      SSH_REMOTE_PORT: ""
      SSH_RESTART: ""
      SSH_TUNNEL: ""
      SSH_USER_TUNNEL: ""
      SSH_VNC_PORT: ""
      TIME_ZONE: America/New_York
      TRADING_MODE: live
      TWOFA_EXIT_INTERVAL: "60"
      TWOFA_TIMEOUT_ACTION: restart
      TWS_PASSWORD: <HIDDEN>
      TWS_SETTINGS_PATH: ""
      TWS_USERID: <HIDDEN>
      TZ: America/New_York
      VNC_SERVER_PASSWORD: ""
    image: ghcr.io/gnzsnz/ib-gateway:stable
    networks:
      default: null
    platform: linux/x86_64
    ports:
      - mode: ingress
        host_ip: 127.0.0.1
        target: 4003
        published: "4001"
        protocol: tcp
    restart: always
networks:
  default:
    name: ib-gateway-prod_default

Expected

I expect these errors to not occur and for the connection to be more stable. Perhaps also expect that the logs say more about this particular issue.

Container logs

See above

Versions

Please complete the following information:

• OS: Ubuntu 20.04.6 LTS
• Docker version: Docker version 24.0.5, build 24.0.5-0ubuntu1~20.04.1
• Image Tag (docker image inspect ghcr.io/gnzsnz/ib-gateway:tag): stable
• Image Digest (docker images --digests): sha256:5b45bc84ad3e2ff363723592cb5df118d17ace67dcb676ffc6a3a9405da08968

[gnzsnz]

hi,

based on what i can see on the log, it seems that

• ib gateway is running, or was running until at 01:00:09, at 01:57:50
• socat is running, the error is coming from socat. socat is receiving messages forwarding it to port 4001, but is not getting a reply. so it's not due to "Forking :::4001..."
• if socat is working, then the issue is on 127.0.0.1:4001 which is the ibgateway port listening on localhost. so ibgateway is not listening. why? i don't know there is nothing on the log to diagnose that.
• data connection between ibgateway and IBKR seems to be OK. it would be in the logs if it's not.

what could be the cause, well i don't know much details, but i would start looking at

• how are you doing the heartbeat? are you requesting bars periodically?

The advantage of reqRealTimeBars is that it behaves more robust when the connection to the IB server farms is interrupted. After the connection is restored, the bars from during the network outage will be backfilled and the live bars will resume.

reqHistoricalData + keepUpToDate will, at the moment of writing, leave the whole API inoperable after a network interruption.

• are you using async?

The One Rule:

While some of the request methods are blocking from the perspective of the user, the framework will still keep spinning in the background and handle all messages received from TWS/IBG. It is important to not block the framework from doing its work. If, for example, the user code spends much time in a calculation, or uses time.sleep() with a long delay, the framework will stop spinning, messages accumulate and things may go awry.

The one rule when working with the IB class is therefore that user code may not block for too long.

hope it helps

[peebeejay]

if socat is working, then the issue is on 127.0.0.1:4001 which is the ibgateway port listening on localhost. so ibgateway is not listening. why? i don't know there is nothing on the log to diagnose that.
data connection between ibgateway and IBKR seems to be OK. it would be in the logs if it's not.

Hm, from your deductions it seems that some sort of port-related misbehavior is occurring on the part of IB gateway after the nightly restart. I'm going to take a deeper look at this today & see if I can replicate locally during the day.

how are you doing the heartbeat? are you requesting bars periodically?

I've just been using the python code in a literal sense that I posted above lol. In the past, the function called reqCurrentTime, but I felt that for now, I can rely on ib_insync to keep isConnected in sync.

are you using async?

Currently not using async. Restarting my trading system doesn't fix the issue, so from that I infer that it's likely not due to an async blocking issue in ib_insync. 🤔

Ty for the response though, I really appreciate it. I'll report back with any interesting results as they come.

[tomer-ds]

Hm, from your deductions it seems that some sort of port-related misbehavior is occurring on the part of IB gateway after the nightly restart.

Did you find any of that "misbehavior"?
I am seeing very similar logs and issues also for stable version after nightly restart.
I also get this nice exception. Could it maybe be related?

2024-08-05 12:08:04.950	2024-08-05 09:08:04:949 IBC: Re-starting session
2024-08-05 12:08:04.958	2024-08-05 09:08:04:958 IBC: Ensuring /home/ibgateway/Jts/jts.ini contains required minimal lines
2024-08-05 12:08:04.959	2024-08-05 09:08:04:958 IBC: Found setting: [Logon]/s3store=true
2024-08-05 12:08:04.959	2024-08-05 09:08:04:959 IBC: Found setting: [Logon]/Locale=en
2024-08-05 12:08:04.959	2024-08-05 09:08:04:959 IBC: Found setting: [Logon]/displayedproxymsg=1
2024-08-05 12:08:04.959	2024-08-05 09:08:04:959 IBC: Found setting: [Logon]/UseSSL=true
2024-08-05 12:08:04.960	2024-08-05 09:08:04:959 IBC: Found setting: [IBGateway]/ApiOnly=true
2024-08-05 12:08:04.960	2024-08-05 09:08:04:960 IBC: Found setting: [IBGateway]/TrustedIPs=127.0.0.1
2024-08-05 12:08:04.960	2024-08-05 09:08:04:960 IBC: Confirmed /home/ibgateway/Jts/jts.ini contains required minimal lines
2024-08-05 12:08:04.960	2024-08-05 09:08:04:960 IBC: Starting Gateway
2024-08-05 12:08:07.228	2024/08/05 09:08:07 socat[3146] E connect(5, AF=2 127.0.0.1:4002, 16): Connection refused
2024-08-05 12:08:08.122	2024-08-05 09:08:08:121 IBC: Getting config dialog
2024-08-05 12:08:08.122	2024-08-05 09:08:08:122 IBC: Creating config dialog future
2024-08-05 12:08:08.124	2024-08-05 09:08:08:124 IBC: Getting config dialog
2024-08-05 12:08:08.125	2024-08-05 09:08:08:125 IBC: Waiting for config dialog future to complete
2024-08-05 12:08:08.125	2024-08-05 09:08:08:125 IBC: Getting main window
2024-08-05 12:08:08.126	2024-08-05 09:08:08:125 IBC: Creating main window future
2024-08-05 12:08:10.152	java.lang.InterruptedException
2024-08-05 12:08:10.152		at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:998)
2024-08-05 12:08:10.152		at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304)
2024-08-05 12:08:10.152		at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:231)
2024-08-05 12:08:10.152		at com.sun.javafx.application.PlatformImpl.waitForStart(PlatformImpl.java:256)
2024-08-05 12:08:10.152		at com.sun.javafx.application.PlatformImpl.runLater(PlatformImpl.java:277)
2024-08-05 12:08:10.152		at com.sun.javafx.application.PlatformImpl.runLater(PlatformImpl.java:268)
2024-08-05 12:08:10.152		at com.sun.javafx.application.PlatformImpl.checkIdle(PlatformImpl.java:392)
2024-08-05 12:08:10.153		at com.sun.javafx.application.PlatformImpl.setImplicitExit(PlatformImpl.java:346)
2024-08-05 12:08:10.153		at javafx.application.Platform.setImplicitExit(Platform.java:138)
2024-08-05 12:08:10.153		at twslaunch.gstat.j.a(j.java:88)
2024-08-05 12:08:10.153		at twslaunch.gstat.a.d(a.java:215)
2024-08-05 12:08:10.153		at twslaunch.gstat.a.g(a.java:117)
2024-08-05 12:08:10.153		at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
2024-08-05 12:08:10.153		at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
2024-08-05 12:08:10.153		at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
2024-08-05 12:08:10.153		at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
2024-08-05 12:08:10.153		at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
2024-08-05 12:08:10.153		at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2024-08-05 12:08:10.153		at java.lang.Thread.run(Thread.java:748)
2024-08-05 12:08:11.870	2024-08-05 09:08:11:870 IBC: detected frame entitled: Loading...; event=Activated
2024-08-05 12:08:11.871	2024-08-05 09:08:11:871 IBC: detected frame entitled: Loading...; event=Focused
2024-08-05 12:08:11.872	2024-08-05 09:08:11:872 IBC: detected frame entitled: Loading...; event=Opened
2024-08-05 12:08:11.873	2024-08-05 09:08:11:872 IBC: Found Gateway main window
2024-08-05 12:08:11.873	2024-08-05 09:08:11:873 IBC: detected frame entitled: Loading...; event=Lost focus
2024-08-05 12:08:11.873	2024-08-05 09:08:11:873 IBC: Got main window from future
2024-08-05 12:08:11.873	2024-08-05 09:08:11:873 IBC: detected frame entitled: Loading...; event=Deactivated
2024-08-05 12:08:11.874	2024-08-05 09:08:11:873 IBC: Invoking config dialog menu
2024-08-05 12:08:11.874	2024-08-05 09:08:11:874 IBC: detected frame entitled: IB Gateway; event=Activated
2024-08-05 12:08:11.882	2024-08-05 09:08:11:882 IBC: detected frame entitled: IB Gateway; event=Focused
2024-08-05 12:08:11.883	2024-08-05 09:08:11:882 IBC: detected frame entitled: IB Gateway; event=Opened
2024-08-05 12:08:11.883	2024-08-05 09:08:11:883 IBC: Login dialog WINDOW_OPENED: LoginState is LOGGED_OUT
2024-08-05 12:08:12.046	2024-08-05 09:08:12:046 IBC: detected frame entitled: IB Gateway; event=Lost focus
2024-08-05 12:08:12.047	2024-08-05 09:08:12:047 IBC: detected frame entitled: IB Gateway; event=Deactivated
2024-08-05 12:08:12.055	2024-08-05 09:08:12:054 IBC: detected frame entitled: Authenticating...; event=Activated
2024-08-05 12:08:12.055	2024-08-05 09:08:12:055 IBC: detected frame entitled: Authenticating...; event=Focused
2024-08-05 12:08:12.055	2024-08-05 09:08:12:055 IBC: detected frame entitled: Authenticating...; event=Opened
2024-08-05 12:08:12.056	2024-08-05 09:08:12:056 IBC: detected frame entitled: Authenticating...; event=Lost focus
2024-08-05 12:08:12.056	2024-08-05 09:08:12:056 IBC: detected frame entitled: Authenticating...; event=Deactivated
2024-08-05 12:08:12.056	2024-08-05 09:08:12:056 IBC: detected dialog entitled: Re-login is required; event=Activated
2024-08-05 12:08:12.065	2024-08-05 09:08:12:065 IBC: detected dialog entitled: Re-login is required; event=Focused
2024-08-05 12:08:12.065	2024-08-05 09:08:12:065 IBC: detected dialog entitled: Re-login is required; event=Opened
2024-08-05 12:08:12.066	2024-08-05 09:08:12:065 IBC: Re-login to session
2024-08-05 12:08:12.066	2024-08-05 09:08:12:066 IBC: Click button: Re-login
2024-08-05 12:08:12.160	2024-08-05 09:08:12:160 IBC: detected dialog entitled: Re-login is required; event=Lost focus
2024-08-05 12:08:12.161	2024-08-05 09:08:12:161 IBC: detected dialog entitled: Re-login is required; event=Deactivated
2024-08-05 12:08:12.162	2024-08-05 09:08:12:162 IBC: detected dialog entitled: Re-login is required; event=Closed
2024-08-05 12:08:12.701	2024-08-05 09:08:12:701 IBC: detected frame entitled: IB Gateway; event=Activated
2024-08-05 12:08:12.702	2024-08-05 09:08:12:702 IBC: detected frame entitled: IB Gateway; event=Focused
2024-08-05 12:08:12.739	2024-08-05 09:08:12:739 IBC: detected frame entitled: IB Gateway; event=Lost focus
2024-08-05 12:08:12.740	2024-08-05 09:08:12:740 IBC: detected frame entitled: IB Gateway; event=Deactivated
2024-08-05 12:08:12.741	2024-08-05 09:08:12:741 IBC: detected dialog entitled: Login failed; event=Activated
2024-08-05 12:08:12.742	2024-08-05 09:08:12:742 IBC: detected dialog entitled: Login failed; event=Focused
2024-08-05 12:08:12.742	2024-08-05 09:08:12:742 IBC: detected dialog entitled: Login failed; event=Opened
2024-08-05 12:08:12.742	2024-08-05 09:08:12:742 IBC: Login failed
2024-08-05 12:08:12.742	2024-08-05 09:08:12:742 IBC: Ensure login frame visible
2024-08-05 12:08:12.744	2024-08-05 09:08:12:744 IBC: Click button: OK
2024-08-05 12:08:12.827	2024-08-05 09:08:12:827 IBC: detected dialog entitled: Login failed; event=Lost focus
2024-08-05 12:08:12.831	2024-08-05 09:08:12:831 IBC: detected dialog entitled: Login failed; event=Deactivated
2024-08-05 12:08:12.832	2024-08-05 09:08:12:832 IBC: detected dialog entitled: Login failed; event=Closed
2024-08-05 12:08:17.238	2024/08/05 09:08:17 socat[3199] E connect(5, AF=2 127.0.0.1:4002, 16): Connection refused
2024-08-05 12:08:27.242	2024/08/05 09:08:27 socat[3200] E connect(5, AF=2 127.0.0.1:4002, 16): Connection refused

[gnzsnz]

there is a 2024-08-05 12:08:12.742 2024-08-05 09:08:12:742 IBC: Login failed in the log. that explain your issue. the java exception happens from time to time, it's coming from IBC, nothing that i can fix. I haven't had any impact from it, so i just ignore it.

[tomer-ds]

But doesn't IBC attempt to recover from a failed login?
Maybe my login retry is misconfigured?

[gnzsnz]

I'm removing the "bug" label, as so far we can't say this is caused by the container code base. if your investigation shows that it is please feel free to add it again.