Skip to content

Solved DuplexPipe test failure #860

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
wants to merge 1 commit into
base: main
Choose a base branch
from
Open

Conversation

amibar
Copy link

@amibar amibar commented Nov 23, 2021

Hi,

Looking into the code I found a possible solution to the DuplexPipe test.

In the SimpleMessagePipe test the Server calls to WaitForConnectionAsync and then calls to MessagePipe.ReceiveAsync so the server pipe is connected.
In the DuplexPipe, MessagePipe.DuplexAsync calls to MessagePipe.ReceiveAsync before the server pipe is connected, this throws exception that ruins the receiving loop.

Postponing the call to MessagePipe.DuplexAsync to after the server.WaitForConnectionAsync call, solves this issue.

Here is a PR that fixes it.

Thanks,
Ami

@amibar
Copy link
Author

amibar commented Nov 23, 2021

The AppVeyor doesn't like this fix, I am trying to figure out why.

@amibar
Copy link
Author

amibar commented Nov 23, 2021

Hi @mgravell,

My solution solves the issue, but the build machine doesn't stand the pipe tests.
To overcome it you can either enlarge the timeout of the tests, or run the pipe tests in stand alone dll so they won't run in parallel with other tests.

After spending a lot of time playing with the build, I got to the conclusion that the named pipe tests fail because the build machine doesn't have enough resources to execute the test in a timely manner so they fail on timeout. (You can see what I tested here https://github.com/amibar/protobuf-net/commits/pipes)

I checked two main scearios, the original one and the Examples tests with only the message pipe tests, the paragraphs below are taken from the builds logs.

As you can see when the Examples has many tests, the pipe tests takes a lot of time.

DuplexPipe test log when running all Examples tests: (4916d30)
00:00:27.3383586 DuplexPipe (3204:16 U): Creating server...
00:00:27.3387114 DuplexPipe (3204:16 U): Creating client...
00:00:27.3388122 DuplexPipe (3204:16 U): [Client] connecting...
00:00:27.3446872 DuplexPipe (3204:20 P): [Server] waiting for connection...
00:00:27.3513649 DuplexPipe (3204:16 U): [Client] sending ping 0...
00:00:27.3621826 DuplexPipe (3204:20 P): [Server] connected; receiving...
00:00:27.4006789 DuplexPipe (3204:16 U): [Client] received pong 0...
00:00:27.4007596 DuplexPipe (3204:16 U): [Client] sending ping 1...
00:00:59.1972137 DuplexPipe (3204:16 U): [Client] received pong 1...
00:00:59.1977433 DuplexPipe (3204:16 U): [Client] sending ping 2...
00:01:28.5110520 DuplexPipe (3204:16 U): [Client] received pong 2...
00:01:28.5115776 DuplexPipe (3204:16 U): [Client] sending ping 3...
00:01:33.1511291 DuplexPipe (3204:16 U): [Client] received pong 3...
00:01:33.1512092 DuplexPipe (3204:16 U): [Client] sending ping 4...
00:01:33.1516026 DuplexPipe (3204:16 U): [Client] received pong 4...
00:01:33.1545119 DuplexPipe (3204:16 U): [Client] end
00:01:33.1549472 DuplexPipe (3204:13 P): [Server] done
00:01:33.1551098 DuplexPipe (3204:16 U): [Server] end

The DuplexPipe test when only the pipe tests are in the Examples: (26ac5d1)
00:00:00.5703577 DuplexPipe (5620:16 U): Creating server...
00:00:00.5705956 DuplexPipe (5620:16 U): Creating client...
00:00:00.5706345 DuplexPipe (5620:16 U): [Client] connecting...
00:00:00.6010638 DuplexPipe (5620:11 P): [Server] waiting for connection...
00:00:00.6055221 DuplexPipe (5620:11 P): [Server] connected; receiving...
00:00:00.6055306 DuplexPipe (5620:16 U): [Client] sending ping 0...
00:00:00.8800315 DuplexPipe (5620:15 U): [Client] received pong 0...
00:00:00.8802175 DuplexPipe (5620:15 U): [Client] sending ping 1...
00:00:00.8810154 DuplexPipe (5620:15 U): [Client] received pong 1...
00:00:00.8811071 DuplexPipe (5620:15 U): [Client] sending ping 2...
00:00:00.8814514 DuplexPipe (5620:15 U): [Client] received pong 2...
00:00:00.8815339 DuplexPipe (5620:15 U): [Client] sending ping 3...
00:00:00.8819124 DuplexPipe (5620:15 U): [Client] received pong 3...
00:00:00.8819876 DuplexPipe (5620:15 U): [Client] sending ping 4...
00:00:00.8823650 DuplexPipe (5620:15 U): [Client] received pong 4...
00:00:00.8842012 DuplexPipe (5620:15 U): [Client] end
00:00:00.8845755 DuplexPipe (5620:11 P): [Server] done
00:00:00.8847211 DuplexPipe (5620:15 U): [Server] end

Regards,
Ami

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

1 participant