Complete pending write operations before canceling io. #628

cwgreene · 2022-10-27T17:56:25Z

PR Summary

Resolve Early Cancellation of pipelines.
PowerShell/Win32-OpenSSH#2012

PR Context

As described in PowerShell/Win32-OpenSSH#2012 when a process such as git uses ssh as a channel, WinSSH will prematurely terminate before flushing all data to the pipe. This results in the error Early EOF.

To fix this issue, when closing the pipe, we first complete write operations to it before cancelling IO on it, rather than afterwards (tbh the current logic makes no sense). That said, I believe a simpler way of addressing the issue is simply to remove the IO cancel completely, though this may make the process slightly less responsive to Ctrl-C.

cwgreene · 2022-10-27T22:00:12Z

@microsoft-github-policy-service agree company="The Trade Desk"

cwgreene · 2022-10-27T22:01:44Z

contrib/win32/win32compat/termio.c

+	// This call is likely racy, there's no guarantee
+	// that a thread has begun IO operations when it's called.
+	// Why stop io operations when we're going to close it anyhow?
 	CancelIoEx(WINHANDLE(pio), NULL);


Hi, this comment is mostly here because I'm unsure about what CancelIoEx is supposed to be doing here. If it is needed, I think its not doing what its supposed to be doing because of the possible race condition. If it is not needed, then I believe that this PR can be simplified to just removing it.

We will take the change as it is. You can delete this comment.

TBBle · 2022-10-29T10:17:25Z

microsoft-github-policy-service agree [company="The Trade Desk"]

Missing an @?

cwgreene · 2022-10-30T17:01:19Z

microsoft-github-policy-service agree [company="The Trade Desk"]

Missing an @?

Thanks @TBBle misinterpreted your comment there the first time :) Fixed, thank you.

cwgreene · 2022-10-30T17:03:11Z

Current error is:

"The RPC server is unavailable"

I do not believe that this is something which I have the power to correct, let me know if I am in error and I will dig into this more. :)

tgauth · 2022-10-31T17:06:33Z

Current error is:

"The RPC server is unavailable"

I do not believe that this is something which I have the power to correct, let me know if I am in error and I will dig into this more. :)

Might be an intermittent AppVeyor thing. Could you push another (empty) commit, or close then re-open the PR to re-trigger AppVeyor?

vvuk · 2022-11-29T03:13:15Z

Note -- I can confirm that this patch seems to fix the early-eof issue that's been plaguing git + windows-openssh. At least, it's fixed with all 3 git pulls that I was able to consistently reproduce the issue with with an older version of ssh. It would be great to get this merged ASAP and a new version of openssh published, windows git users would be very grateful :)

cwgreene · 2022-12-10T08:40:02Z

I am happy to make any changes, or update comments. The main reason for the comments was that I was seeking clarification. Let me know if there are any updates that would be desired.

cwgreene · 2023-01-22T01:43:08Z

Hallo! Pinging @tgauth. Any advice on next steps?

vthiebaut10 · 2023-01-22T01:50:11Z

Hi @cwgreene - I'm sorry for the delay. I'll take some time reviewing your PR next Community Day on Monday.

vthiebaut10 · 2023-01-30T16:32:41Z

@cwgreene - Just an update: I've been reviewing this PR and I understand how it fixes the race condition that is happening when cloning a large repo with git. But because this change has the potential to cause a regression in other scenarios, I need to spend some more time investigating it before merging it. This will probably take a while, but hopefully we can finalize this review before the next release.

cwgreene · 2023-01-30T17:54:51Z

@vthiebaut10 understood. Is there anything that I can do on my end to facilitate that?

cwgreene · 2023-01-30T18:39:13Z

What are the scenarios which we should consider that are at risk of regression?

smuehlst · 2023-02-03T15:54:08Z

I built my own copy of ssh.exe from @cwgreene's branch, and I also can confirm that it fixes the fetch-pack: unexpected disconnect while reading sideband packet error for me where git pull with the standard Windows ssh.exe fails.

vvuk · 2023-03-01T18:09:18Z

There was a beta release last week -- why wasn't this included? I understand that maintaining a project like this is complex, but this issue has been outstanding for years (since 2019!), and @cwgreene finally provided a resolution. This should have been the first fix to go into a new beta release. What's the hold up here?

cwgreene · 2023-03-14T17:22:57Z

@vthiebaut10 Hello! Happy Pi Day! Is there anything I can do to assist in moving this along?

gruselglatz · 2023-03-17T08:44:53Z

#667

vthiebaut10 · 2023-03-17T14:37:26Z

I'm sorry for the late response. Our team is investigating this issue, and it seems to be more complicated than initially thought. We will update this issue as soon as we are more certain of the correct approach for resolving this issue.

cwgreene · 2023-03-17T15:22:54Z

What have you found out so far?

PaulHigin · 2023-03-20T16:32:48Z

@cwgreene We are concerned about this change because performing a wait before the CancelIOEx() function could cause a hang or other regressions. Our understanding of this function as an implementation of POSIX fd close is that it should abruptly terminate any queued or pending operations (see linux man page for close). This is what the function currently does, which we think is correct, so we are now thinking that there may be a different problem with our async write and select implementation. We are investigating but have no new information yet.

cwgreene · 2023-03-24T15:08:27Z

Hi @PaulHigin! Thanks for the information.

It's been several months since I looked at this, so I'll review, however, I believe that in the case of a pipe (which is how git is communicating with ssh), as long as the pipe isn't full, the kernel will always complete the the 'write' operation to the pipe before returning from write even in O_NONBLOCK mode (which is set on pipes, and I seem to recall that this code path only gets involved when O_NONBLOCK is set).

On the close man page

https://man7.org/linux/man-pages/man2/close.2.html

I don't see anything says that close will immediately halt any pending write operations. It does mention that operations on a regular file are not guaranteed to flush; however, a pipe is not a regular file.

Do we need special casing logic here to handle pipes?

vvuk · 2023-03-24T15:54:12Z

FWIW, my understanding is the same as @cwgreene's. write has no async beheaviour itself, whenever it returns all operations are complete (or would block). So the only issue is if one thread calls close() on a fd that another thread is in the middle of a write() operation to. If this is actually happening, it's inherently a race -- it's going to be valid to implement that any in-progress write would complete before a close (because that's what might happen much of the time during the race anyway).

cwgreene · 2023-03-25T16:53:44Z

Note also, if we look a little further up the call stack to this function we find this:

	if (pio->type == SOCK_FD)
		r = socketio_close(pio);
	else
		r = fileio_close(pio);		 // This is path we take here

So I don't believe changing this code path should affect network operations, as sockets are handled differently. This should reduce the cases we need to think about in determining the blast radius.

PaulHigin · 2023-03-29T21:04:12Z

@cwgreene I spent some more time looking into this and I see your point about this only affecting pipe fds. Also, I notice that higher layer close functions do perform a pending operation drain, so I am thinking it is the right thing to do it here also with this fix. I just wonder if we should also drain any pending read operations. I think the 'CancelOperationEx' needs to be called to ensure the file close completes.

vthiebaut10

@cwgreene Thank you for your patience. We will be merging your change and it will be available in the next release. I'm leaving a few comments that I'd like you to consider before we merge.
Thanks!

vthiebaut10 · 2023-04-04T20:22:18Z

contrib/win32/win32compat/termio.c

+		WaitForSingleObject(pio->write_overlapped.hEvent, INFINITE);
+
+		/* drain queued APCs */
+		SleepEx(0, TRUE);


Is there a reason why you added this call to SleepEx to this if statement block?

vthiebaut10 · 2023-04-04T20:32:43Z

contrib/win32/win32compat/termio.c

@@ -260,6 +260,18 @@ int
 syncio_close(struct w32_io* pio)
 {
 	debug4("syncio_close - pio:%p", pio);
+
+	/* Flush descriptor.*/


Similar justification as:

openssh-portable/contrib/win32/win32compat/fileio.c

Lines 1089 to 1100 in cdee736

/*

* we report to POSIX app that an async write has completed as soon its

* copied to internal buffer. The app may subsequently try to close the

* fd thinking everything is written. IF the Windows handle is closed

* now, the pipe/file io write operation may terminate prematurely.

* To compensate for the discrepency

* wait here until async write has completed.

* If you see any process waiting here indefinitely - its because no one

* is draining from other end of the pipe/file. This is an unfortunate

* consequence that should otherwise have very little impact on practical

* scenarios.

*/

Suggested change

/* Flush descriptor.*/

/*

* Wait for io write operation that is called by worker thread to terminate

* to avoid the write operation being terminated prematurely by CancelIoEx.

* If you see any process waiting here indefinitely - its because no one

* is draining from other end of the pipe. This is an unfortunate

* consequence that should otherwise have very little impact on practical

* scenarios.

*/

Feel free to modify this comment with any details that you think is relevant.

This comment is similar to alternate path code for the file close operation, so I think it makes sense have it here as well, since we are using the same wait pattern.

Yes, this was basically to perform the same logic before and after. My understanding/recollection is the sleep is actually needed to ensure that the queue actually gets drained.

I'm just wondering if the queue needs to be drained immediately after the write operation terminates, or if we can just have one SleepEx call once both the read and write operation have terminated. I don't think it hurts to have it there, so I am good to merge as is. But I'm just wondering if it's needed.

vthiebaut10 · 2023-04-04T20:44:37Z

contrib/win32/win32compat/termio.c

+	// This call is likely racy, there's no guarantee
+	// that a thread has begun IO operations when it's called.
+	// Why stop io operations when we're going to close it anyhow?
 	CancelIoEx(WINHANDLE(pio), NULL);


We will take the change as it is. You can delete this comment.

PaulHigin · 2023-04-04T23:33:31Z

@vthiebaut10 I agree with this change overall, so if @cwgreene is unavailable to make these extra minor comment change suggestions, I think we can just make them ourselves and perform the merge.

cwgreene · 2023-04-05T00:30:24Z

Hi! I can remove the comment (thank you for responding to it :) ) in a few hours if that works for you, otherwise, happy with the above recommnedations. :)

cwgreene · 2023-04-05T00:33:46Z

Actually, one moment I can remove the comment now.

cwgreene · 2023-04-05T00:47:21Z

Updated comment to use vthiebaut10 wording.

Complete pending write operations before canceling io.

31aad0c

cwgreene commented Oct 27, 2022

View reviewed changes

cwgreene closed this Nov 3, 2022

cwgreene reopened this Nov 3, 2022

vthiebaut10 self-requested a review November 17, 2022 18:28

cwgreene mentioned this pull request Dec 14, 2022

libwinpthread seems to be causing issues when cloning repositories in 2.33.0.2 git-for-windows/git#3444

Closed

1 task

vthiebaut10 reviewed Apr 4, 2023

View reviewed changes

christophergreenettd added 2 commits April 4, 2023 17:35

Removed comment, question has been addressed in mr.

c73e80b

include useful comment from vthiebaut10

5ed0a40

vthiebaut10 approved these changes Apr 5, 2023

View reviewed changes

PaulHigin approved these changes Apr 5, 2023

View reviewed changes

PaulHigin merged commit 33a141f into PowerShell:latestw_all Apr 6, 2023

tgauth mentioned this pull request Apr 10, 2023

Early EOF errors when running git fetch over ssh #667

Closed

3 tasks

	/*
	* we report to POSIX app that an async write has completed as soon its
	* copied to internal buffer. The app may subsequently try to close the
	* fd thinking everything is written. IF the Windows handle is closed
	* now, the pipe/file io write operation may terminate prematurely.
	* To compensate for the discrepency
	* wait here until async write has completed.
	* If you see any process waiting here indefinitely - its because no one
	* is draining from other end of the pipe/file. This is an unfortunate
	* consequence that should otherwise have very little impact on practical
	* scenarios.
	*/

-	/* Flush descriptor.*/
+	/*
+        * Wait for io write operation that is called by worker thread to terminate
+        * to avoid the write operation being terminated prematurely by CancelIoEx.
+	* If you see any process waiting here indefinitely - its because no one
+	* is draining from other end of the pipe. This is an unfortunate
+	* consequence that should otherwise have very little impact on practical
+	* scenarios.
+	*/

Complete pending write operations before canceling io. #628

Complete pending write operations before canceling io. #628

Conversation

cwgreene commented Oct 27, 2022 • edited Loading

PR Summary

PR Context

cwgreene commented Oct 27, 2022 • edited Loading

cwgreene Oct 27, 2022

Choose a reason for hiding this comment

vthiebaut10 Apr 4, 2023

Choose a reason for hiding this comment

TBBle commented Oct 29, 2022

cwgreene commented Oct 30, 2022 • edited Loading

cwgreene commented Oct 30, 2022

tgauth commented Oct 31, 2022

vvuk commented Nov 29, 2022

cwgreene commented Dec 10, 2022

cwgreene commented Jan 22, 2023

vthiebaut10 commented Jan 22, 2023

vthiebaut10 commented Jan 30, 2023

cwgreene commented Jan 30, 2023

cwgreene commented Jan 30, 2023

smuehlst commented Feb 3, 2023

vvuk commented Mar 1, 2023

cwgreene commented Mar 14, 2023

gruselglatz commented Mar 17, 2023

vthiebaut10 commented Mar 17, 2023

cwgreene commented Mar 17, 2023

PaulHigin commented Mar 20, 2023

cwgreene commented Mar 24, 2023 • edited Loading

vvuk commented Mar 24, 2023

cwgreene commented Mar 25, 2023

PaulHigin commented Mar 29, 2023

vthiebaut10 left a comment

Choose a reason for hiding this comment

vthiebaut10 Apr 4, 2023 • edited Loading

Choose a reason for hiding this comment

vthiebaut10 Apr 4, 2023

Choose a reason for hiding this comment

PaulHigin Apr 4, 2023

Choose a reason for hiding this comment

cwgreene Apr 5, 2023

Choose a reason for hiding this comment

vthiebaut10 Apr 5, 2023

Choose a reason for hiding this comment

vthiebaut10 Apr 4, 2023

Choose a reason for hiding this comment

PaulHigin commented Apr 4, 2023

cwgreene commented Apr 5, 2023 • edited Loading

cwgreene commented Apr 5, 2023

cwgreene commented Apr 5, 2023

cwgreene commented Oct 27, 2022 •

edited

Loading

cwgreene commented Oct 27, 2022 •

edited

Loading

cwgreene commented Oct 30, 2022 •

edited

Loading

cwgreene commented Mar 24, 2023 •

edited

Loading

vthiebaut10 Apr 4, 2023 •

edited

Loading

cwgreene commented Apr 5, 2023 •

edited

Loading