Slow timeout when trying to connect to an invalid IP address

[scaramallion]

From #615

python -m pynetdicom echoscu [invalid IP] 11112 -d -ta 5

Should immediately fail due to non-existent IP, but doesn't.

[r1b]

Howdy - also experiencing this issue. My 2c:

#565 and #600 are close to being right except:

• A separate value for "connection timeout" should be set instead of reusing the network timeout (semantically a read / write inactivity timeout)
• The timeout needs to be cleared with socket.settimeout(None) after connect succeeds. This is because python uses the timeout for all other blocking socket operations (like reads and writes) but we're currently handling that elsewhere.

If you'd like I can propose a fix in a PR. Thanks!

[scaramallion]

Sure, that'd be great

[r1b]

@scaramallion one complication here is that we don't want the acse_timeout and the new connection_timeout to run concurrently - using dcmtk echoscu i see that the association timeout doesn't kick in until a connection has been established:

$ time /usr/local/opt/dcmtk/bin/echoscu -ta 5 -to 10 169.42.95.87 4444
F: Association Request Failed: 0006:031b Failed to establish association
F: 0006:0317 Peer aborted Association (or never connected)
F: 0006:031c TCP Initialization Error: Operation now in progress (Timeout)

real    0m10.027s
user    0m0.020s
sys     0m0.003s

---

the way things currently work, the ACSE provider doesn't know anything about the underlying socket and starts its timer as soon as it attempts to establish an association:

https://github.com/pydicom/pynetdicom/blob/master/pynetdicom/acse.py#L425-L426

open to any suggestions on how to proceed - i'm not sure what the right thing to do here is

[r1b]

my best guess rn is "the DUL should not be marked ready until the transport connection is open"

[scaramallion]

After writing all the below, the simplest simplest way is to probably just put None on DUL.to_user_queue when the connection fails so the blocking rsp = self.dul.receive_pdu(...) returns. Maybe see if there's a way to get a better log message in that case.

---

The state machine for the start of association requests is

Sta1 + Evt1 -> AE-1 -> Sta4
Sta4 + Evt2 -> AE-2 -> Sta5

Where

Sta1: Idle
Sta4: Awaiting transport connection opening to complete (from local transport service)
Sta5: Awaiting A-ASSOCIATE-AC or A-ASSOCIATE-RJ PDU

Evt1: A-ASSOCIATE request received from local user)
Evt2: Transport connection confirmation from local transport service

So while we're operating in Sta4, the ACSE timeout should be idle until Evt2 occurs and we reach Sta5. There seems to be a step missing in _negotiate_as_requestor() after sending the A-ASSOCIATE request primitive to the DUL in send_request() and prior to rsp = self.dul.receive_pdu(wait=True, timeout=self.acse_timeout) where we wait until the connection has been made.

I'd be inclined to put in a timeout check (based on network_timeout?) in between that waits on Sta5.

self.send_request()

while self.assoc.dul.state_machine.state != 'Sta5':
    # wait until timeout expires

evt.trigger(self.assoc, evt.EVT_REQUESTED, {})

It's probably better to use a threading event there with the other end tied to the socket.connect() code so the ACSE only containues once the connection request is made or failed.

Alternatively you could just lock the thread into the socket.connect() code until timeout... but that might have weird effects when running an AE with multiple SCPs that needs to make association requests.

I really hate threading....

[scaramallion]

Fixed with #618