Make intentional desktop session disconnections end gracefully

[ibeckermayer]

Currently when a desktop session is disconnected (either by closing the tab or by hitting disconnect in the menu), they remain active under the hood until the monitor times out, at which point they fail and typically print a bunch of failed to send PNG frame error logs:

2022-06-21T17:26:49-04:00 ERRO [WINDOWS_D] failed to send PNG frame (448,640)-(512,704): write tcp [::1]:3028->[::1]:49548: write: broken pipe client-ip:::1 desktop-addr:172.16.97.147:3389 desktop-name:WIN-1E6JDI6PHQA-teleport-dev pid:42806.1 rdp-addr:172.16.97.147:3389 rdpclient/client.go:457

An initial thought was that this was caused by the change in the websocket library we're using, however this behavior exists on branch/v10 but not on branch/v9, and the websocket library is constant between them, so it's likely some other more recent change.

[zmb3]

Was just talking to @xacrimon about this. The new session tracker system might be the cause, but that should also be on branch/v9..

[ibeckermayer]

The failed to send PNG frame message seems to show up a bunch of times in a row primarily when the session is closed during smartcard login on branch/v10. On branch/v9, the message doesn't get repeated.

On both branches, when the session is closed after the login is complete, I've experienced long delays (~30s) between the TDP input streaming finished and RDP output streaming finished logs, but sometimes there is also no delay (both branches). On branch/v10 it seems like handle_bitmap (which is where the "failed to send PNG frame" message comes from) is called repeatedly. It's still unclear to me how this is possible, given that handle_bitmap is called from the loop in read_rdp_output_inner, which locks the client and is meant to break and return the first time handle_bitmap fails (full snippet does not get displayed inline):

teleport/lib/srv/desktop/rdp/rdpclient/src/lib.rs

Lines 609 to 658 in 8c2ced7

	fn read_rdp_output_inner(client: &Client) -> Option<String> {
	let tcp_fd = client.tcp_fd;
	let client_ref = client.go_ref;
	// Read incoming events.
	//
	// Wait for some data to be available on the TCP socket FD before consuming it. This prevents
	// us from locking the mutex in Client permanently while no data is available.
	while wait_for_fd(tcp_fd as usize) {
	let mut err = CGOErrCode::ErrCodeSuccess;
	let res = client
	.rdp_client
	.lock()
	.unwrap()
	.read(|rdp_event| match rdp_event {
	RdpEvent::Bitmap(bitmap) => {
	let mut cbitmap = match CGOBitmap::try_from(bitmap) {
	Ok(cb) => cb,
	Err(e) => {
	error!(
	"failed to convert RDP bitmap to CGO representation: {:?}",
	e
	);
	return;
	}
	};
	unsafe {
	err = handle_bitmap(client_ref, &mut cbitmap) as CGOErrCode;
	};
	}
	// These should never really be sent by the server to us.
	RdpEvent::Pointer(_) => {
	debug!("got unexpected pointer event from RDP server, ignoring");
	}
	RdpEvent::Key(_) => {
	debug!("got unexpected keyboard event from RDP server, ignoring");
	}
	});
	match res {
	Err(RdpError::Io(io_err)) if io_err.kind() == ErrorKind::UnexpectedEof => return None,
	Err(e) => {
	return Some(format!("RDP read failed: {:?}", e));
	}
	_ => {}
	}
	if err != CGOErrCode::ErrCodeSuccess {
	return Some("failed forwarding RDP bitmap frame".to_string());
	}
	}
	None
	}

Update: I figured out how the repeated messages are possible. The callback which calls handle_bitmap is ultimately called by read_fast_path, which reads the stream and breaks it up into chunks, calling callback repeatedly. So while I don't know why in branch/v10 we are winding up with longer messages that need to be broken into many chunks as compared with branch/v9, I can create a fix for the logging issue.

https://github.com/gravitational/rdp-rs/blob/6075679e7c9bd8e3c2136a87f097d05c7db3235f/src/core/global.rs#L805-L820