Bug 8284 - Unhelpful logging if XML-RPC channel breaks
Summary: Unhelpful logging if XML-RPC channel breaks
Status: NEW
Alias: None
Product: ThinLinc
Classification: Unclassified
Component: Client (show other bugs)
Version: trunk
Hardware: PC Unknown
: P2 Normal
Target Milestone: MediumPrio
Assignee: Bugzilla mail exporter
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2024-01-08 10:16 CET by Pierre Ossman
Modified: 2024-01-09 13:09 CET (History)
0 users

See Also:
Acceptance Criteria:


Attachments

Description Pierre Ossman cendio 2024-01-08 10:16:15 CET
If there is some error that causes the XML-RPC channel to close unexpectedly, then we just get this in tlclient.log:

> 2024-01-08T10:11:49: Calling XML-RPC method 'reconnect_session'
> 2024-01-08T10:11:57: Error in XmlRpcClient::writeRequest: write error (error 9).
> 2024-01-08T10:11:57: Call to XML-RPC method 'reconnect_session' failed
> 2024-01-08T10:11:58: ServiceProcess: select error (Bad file descriptor) for service ssh

errno 9 is EBADF, so that is obviously not the original issue.

It turns out that xmlrpc++ has some reconnect logic that is enabled by default. It cannot work in our scenario, though, so it only gets as far as closing the existing file descriptors.

Ideally, we don't want it to ever close our file descriptors. Unfortunately, I don't see any way of guaranteeing that.

In this scenario, though, it is sufficient to disable the reconnect logic by calling setKeepOpen(false). After doing that, we get some more useful information in the log:

> 2024-01-08T10:06:39: Calling XML-RPC method 'reconnect_session'
> 2024-01-08T10:06:47: Error in XmlRpcClient::readHeader: error while reading header (error 11) on fd 9.
> 2024-01-08T10:06:47: Call to XML-RPC method 'reconnect_session' failed
> 2024-01-08T10:06:47: ServiceProcess: Recieved EOF on stdout for service ssh
> 2024-01-08T10:06:47: ssh[E]: Traceback (most recent call last):
> 2024-01-08T10:06:47: ssh[E]:   File "/usr/bin/thinlinc-login", line 223, in <module>
> 2024-01-08T10:06:47: ssh[E]:     IIIi1111iiIi1 ( )
> 2024-01-08T10:06:47: ssh[E]:   File "/usr/bin/thinlinc-login", line 200, in IIIi1111iiIi1
> 2024-01-08T10:06:47: ssh[E]:     IIi1I1I1i . sendall ( Iii1I1I1 )
> 2024-01-08T10:06:47: ssh[E]: BrokenPipeError: [Errno 32] Broken pipe
> 2024-01-08T10:06:47: ssh[E]: sys:1: ResourceWarning: unclosed <socket.socket fd=4, family=1, type=1, proto=0, laddr=b'\x000d642', raddr=/var/run/thinlinc/master/1000>
> 2024-01-08T10:06:47: ssh[E]: debug1: client_input_channel_req: channel 0 rtype exit-status reply 0
> 2024-01-08T10:06:47: ssh[E]: debug1: client_input_channel_req: channel 0 rtype eow@openssh.com reply 0
> 2024-01-08T10:06:47: ssh[E]: 
> 2024-01-08T10:06:47: ssh[E]: COMMAND_EXITSTATUS: 1
> 2024-01-08T10:06:47: ssh[E]: debug1: channel 0: free: client-session, nchannels 1
> 2024-01-08T10:06:47: ssh[E]: Transferred: sent 3438416, received 14028 bytes, in 7.8 seconds
> 2024-01-08T10:06:47: ssh[E]: Bytes per second: sent 443457.8, received 1809.2
> 2024-01-08T10:06:47: ssh[E]: debug1: Exit status 0
> 2024-01-08T10:06:47: ServiceProcess: Recieved EOF on stderr for service ssh

Note You need to log in before you can comment on or make changes to this bug.