Skip to content
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

tests/stdlib/tchannels.nim flaky, gives reTimeout #17946

Closed
timotheecour opened this issue May 6, 2021 · 3 comments
Closed

tests/stdlib/tchannels.nim flaky, gives reTimeout #17946

timotheecour opened this issue May 6, 2021 · 3 comments

Comments

@timotheecour
Copy link
Member

timotheecour commented May 6, 2021

I've had several recent unrelated PR's where tests/stdlib/tchannels.nim fails with reTimeout

Example

Current Output

2021-05-06T03:49:30.6771340Z �[32mPASS: �[36mtests/stdlib/tbase64.nim c                                  �[34m ( 1.88 sec)�[0m
2021-05-06T03:49:30.6772236Z �[32mPASS: �[36mtests/stdlib/tbitops.nim c                                  �[34m ( 2.53 sec)�[0m
2021-05-06T03:49:30.6773036Z �[2m�[33mJOINED: �[1m�[36mtests/stdlib/tcgi.nim c�[0m
2021-05-06T03:49:30.6774007Z �[32mPASS: �[36mtests/stdlib/tchannels.nim c                                �[34m ( 2.68 sec)�[0m
2021-05-06T03:49:30.6775490Z �[1m�[31mFAIL: �[36mtests/stdlib/tchannels.nim c�[0m
2021-05-06T03:49:30.6776085Z �[1m�[36mTest "tests/stdlib/tchannels.nim" in category "stdlib"�[0m
2021-05-06T03:49:30.6776754Z �[1m�[31mFailure: reTimeout�[0m
2021-05-06T03:49:30.6777191Z �[33mExpected:�[0m
2021-05-06T03:49:30.6777565Z �[1m
2021-05-06T03:49:30.6777890Z �[0m
2021-05-06T03:49:30.6778268Z �[33mGotten:�[0m
2021-05-06T03:49:30.6778614Z �[1m
2021-05-06T03:49:30.6778958Z �[0m
2021-05-06T03:49:30.6779061Z 
2021-05-06T03:50:00.5902764Z 34m ( 1.25 sec)�[0m
2021-05-06T03:50:00.5904169Z �[32mPASS: �[36mtests/destructor/tgotoexceptions2.nim c                     �[34m ( 1.15 sec)�[0m
2021-05-06T03:50:00.5905185Z �[32mPASS: �[36mtests/destructor/tgotoexceptions3.nim c                     �[34m ( 1.14 sec)�[0m
2021-05-06T03:29:54.4859211Z NOTINBATCH: tests/stdlib/tcgi.nim c
2021-05-06T03:29:54.4862147Z FAIL: tests/stdlib/tchannels.nim c
2021-05-06T03:29:54.4864548Z Test "tests\stdlib\tchannels.nim" in category "stdlib"
2021-05-06T03:29:54.4867044Z Failure: reTimeout
2021-05-06T03:29:54.4869303Z Expected:
2021-05-06T03:29:54.4871155Z 
2021-05-06T03:29:54.4963536Z 
2021-05-06T03:29:54.4965521Z Gotten:
2021-05-06T03:29:54.5247804Z 
2021-05-06T03:29:54.5467815Z 
2021-05-06T03:29:54.5660188Z 
2021-05-06T03:30:09.5000662Z NOTINBATCH: tests/testament/t16576.nim c
2021-05-06T03:30:09.5016037Z NOTINBATCH: tests/testament/tjoinable.nim c
2021-05-06T03:30:09.5016851Z PASS: tests/testament/treject.nim c                                ( 1.51 sec)
2021-05-06T03:30:09.5027858Z PASS: tests/testament/tshould_not_work.nim c                       (65.58 sec)
2021-05-06T03:30:09.5033628Z NOTINBATCH: tests/testament/tspecialpaths.nim c
2021-05-06T03:30:09.5044230Z progress[all]: 112/131 starting: cat: tools
2021-05-06T03:30:09.5049776Z D:\a\1\s\testament\testament.exe --nim:D:\a\1\s\bin\nim.exe --batch:1_3 pcat tools
2021-05-06T03:30:12.5665459Z FAIL: tests/stdlib/tchannels.nim c
2021-05-06T03:30:12.5681477Z Test "tests\stdlib\tchannels.nim" in category "stdlib"
2021-05-06T03:30:12.5783645Z Failure: reTimeout
2021-05-06T03:30:12.5789817Z Expected:
2021-05-06T03:30:12.5797220Z 
2021-05-06T03:30:12.5833465Z 
2021-05-06T03:30:12.5838487Z Gotten:
2021-05-06T03:30:12.5838750Z 
2021-05-06T03:30:12.5839854Z 
2021-05-06T03:30:12.5840400Z 
2021-05-06T03:30:15.1665642Z NOTINBATCH: tests/tools/compile/tdeps.nim c

Expected Output

works

Additional Information

1.5.1 706562f

timotheecour added a commit to timotheecour/Nim that referenced this issue May 6, 2021
…ion for failures; increase timeout tchannels
timotheecour added a commit to timotheecour/Nim that referenced this issue May 6, 2021
…ion for failures; increase timeout tchannels
timotheecour added a commit to timotheecour/Nim that referenced this issue May 6, 2021
…ion for failures; increase timeout tchannels
timotheecour added a commit to timotheecour/Nim that referenced this issue May 8, 2021
…ion for failures; increase timeout tchannels
Araq pushed a commit that referenced this issue May 8, 2021
…work`; mitigate #17946 tchannels timeouts (#17947)

* refs #17946; refactor testament test summary, show test duration for failures; increase timeout tchannels

* revert workarounds from #16698 and add allowPrefixMatch optional param to greedyOrderedSubsetLines

* add test

* workaround for yet another testament bug
@ringabout
Copy link
Member

This issue should be fixed first,

#17407

@GordonBGood
Copy link
Contributor

These semi-random hangs when using threading are a symptom of a data race, and indeed there is a data race in the current version of std/channels as the design wasn't fully considered in the use of dual locks with a read/write FIFO buffer.

When there is just a small window for a race, the longer a test runs and the faster the loops testing the channels, the higher the probability that the race condition will be hit.

I think I've fixed the data race(s) with a new version of std/channels (using a different locking with just one set of lock/signal fields) and I'll check back here and to the linked issues before I PR it to see if it fixes these issues.

As to the slower performance, there was a pre-mature optimization in the inclusion of a memory pool for allocation of channel and channel buffer space that I don't think was necessary; it may be that the slowness is to do with that. My new version (without memory pools) seems to be about the same speed or faster than the old built-in channel version. Of course the very slowest thing one can do with channels is create an un-buffered channel (size of one) and do multiple random locking send/receive operations as that causes locking/signalling on nearly every use; my new version of std/channels drops from a transmission rate of about ten million integers per second to about a million or less for this situation - a drop of about ten times in speed or so. I don't think there is a way to avoid that, as the bottleneck isn't in the channels code but in the implementation of locks and conditions.

@ringabout
Copy link
Member

Ref #18801

narimiran pushed a commit that referenced this issue Nov 9, 2021
 increase timeout for tchannels (#18012)

(cherry picked from commit 2ce592a)
PMunch pushed a commit to PMunch/Nim that referenced this issue Mar 28, 2022
…work`; mitigate nim-lang#17946 tchannels timeouts (nim-lang#17947)

* refs nim-lang#17946; refactor testament test summary, show test duration for failures; increase timeout tchannels

* revert workarounds from nim-lang#16698 and add allowPrefixMatch optional param to greedyOrderedSubsetLines

* add test

* workaround for yet another testament bug
PMunch pushed a commit to PMunch/Nim that referenced this issue Mar 28, 2022
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

No branches or pull requests

3 participants