Skip to content

Add 'good vs bad' trace for shaky test -- and solve it #54

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.

Sign up for GitHub

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

Merged
abelbraaksma merged 7 commits into from
Oct 31, 2022
Merged

Add 'good vs bad' trace for shaky test -- and solve it #54

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
7 commits
Select commit Hold shift + click to select a range
97b4bc5
Add 'good vs bad' trace for shaky test
abelbraaksma Oct 30, 2022
73fe5c5
Improve analysis logs
abelbraaksma Oct 31, 2022
90e20b4
Add minimal repro test that immediately fails
abelbraaksma Oct 31, 2022
d5d49df
Fix issue #54, set 'completed' correctly for empty sequences
abelbraaksma Oct 31, 2022
8d67c15
Cleanup code, get rid of redundant log statements and improve signatu…
abelbraaksma Oct 31, 2022
a6abba9
reset ncrunch log setting
abelbraaksma Oct 31, 2022
82028a8
Rename and cleanup test
abelbraaksma Oct 31, 2022
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
23 changes: 23 additions & 0 deletions src/FSharpy.TaskSeq.Test/TaskSeq.StateTransitionBug.Tests.CE.fs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -48,6 +48,10 @@ let ``CE empty taskSeq, GetAsyncEnumerator multiple times and then MoveNextAsyn
do! Assert.moveNextAndCheck false enumerator
}

// FIXED!
// Previously: shaky test. Appears that this occasionally raises a NullReferenceException,
// esp when there's stress (i.e. run all at the same time).
// See https://github.com/abelbraaksma/TaskSeq/pull/54
[<Theory; ClassData(typeof<TestEmptyVariants>)>]
let ``CE empty taskSeq, GetAsyncEnumerator + MoveNextAsync multiple times`` variant = task {
let tskSeq = Gen.getEmptyVariant variant
Expand All @@ -60,6 +64,25 @@ let ``CE empty taskSeq, GetAsyncEnumerator + MoveNextAsync multiple times`` vari
do! Assert.moveNextAndCheck false enumerator2 // new hone should also work without raising
}

// FIXED!
// This is the simpler version of the above test.
[<Fact>]
let ``BUG #54 CE with empty taskSeq and Delay, crash after GetAsyncEnumerator + MoveNextAsync 2x`` () = task {
// See: https://github.com/abelbraaksma/TaskSeq/pull/54
let tskSeq = taskSeq { do! Task.Delay(50) |> Task.ofTask }

use enumerator1 = tskSeq.GetAsyncEnumerator()
let! (hasNext: bool) = enumerator1.MoveNextAsync()
hasNext |> should be False

use enumerator1 = tskSeq.GetAsyncEnumerator()
let! (hasNext: bool) = enumerator1.MoveNextAsync()
hasNext |> should be False

let! (hasNext: bool) = enumerator1.MoveNextAsync() // fail here
hasNext |> should be False
}

[<Theory; ClassData(typeof<TestEmptyVariants>)>]
let ``CE empty taskSeq, GetAsyncEnumerator + MoveNextAsync 100x in a loop`` variant = task {
let tskSeq = Gen.getEmptyVariant variant
Expand Down
56 changes: 56 additions & 0 deletions ...aces/TRACE_FAIL 'CE empty taskSeq, GetAsyncEnumerator + MoveNextAsync multiple times'.txt
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,56 @@
at AfterCode<_, _>, after F# inits the sm, and we can attach extra info
MoveNextAsync...
at MoveNextAsync: normal resumption scenario
at MoveNextAsync: start calling builder.MoveNext()
Resuming at resumption point 0
at Run.MoveNext start
at Bind
at Bind: with __stack_fin = false
at Bind: calling AwaitUnsafeOnCompleted
at Run.MoveNext, __stack_code_fin=False
at Run.MoveNext, await
at MoveNextAsync: done calling builder.MoveNext()
at MoveNextAsyncResult: case pending/faulted/cancelled...
at Bind: with __stack_fin = true
at Bind: with getting result from awaiter
at Bind: calling continuation
at Bind
at Bind: with __stack_fin = false
at Bind: calling AwaitUnsafeOnCompleted
at Run.MoveNext, __stack_code_fin=False
at Run.MoveNext, await
at Bind: with __stack_fin = true
at Bind: with getting result from awaiter
at Bind: calling continuation
at Bind
at Bind: with __stack_fin = false
at Bind: calling AwaitUnsafeOnCompleted
at Run.MoveNext, __stack_code_fin=False
at Run.MoveNext, await
at Bind: with __stack_fin = true
at Bind: with getting result from awaiter
at Bind: calling continuation
at Zero()
at Run.MoveNext, __stack_code_fin=True
at Run.MoveNext, done
Getting result for token on 'None' branch, status: Succeeded
GetAsyncEnumerator, cloning...
MoveNextAsync...
at MoveNextAsync: normal resumption scenario
at MoveNextAsync: start calling builder.MoveNext()
at Bind: with __stack_fin = true
at Bind: with getting result from awaiter
Setting exception of PromiseOfValueOrEnd to: Object reference not set to an instance of an object.
at MoveNextAsync: done calling builder.MoveNext()
at MoveNextAsyncResult: case pending/faulted/cancelled...
Getting result for token on 'None' branch, status: Faulted
Error 'Object reference not set to an instance of an object.' for token: 2
DisposeAsync...
DisposeAsync...
Setting exception of PromiseOfValueOrEnd to: An attempt was made to transition a task to a final state when it had already completed.
System.NullReferenceException: Object reference not set to an instance of an object.
at FSharpy.Tests.Bug #42 -- synchronous.CE empty taskSeq\, GetAsyncEnumerator - MoveNextAsync multiple times@54.MoveNext() in D:\Projects\OpenSource\Abel\TaskSeq\src\FSharpy.TaskSeq.Test\TaskSeq.StateTransitionBug.Tests.CE.fs:line 62
at Xunit.Sdk.TestInvoker`1.<>c__DisplayClass48_0.<<InvokeTestMethodAsync>b__1>d.MoveNext() in /_/src/xunit.execution/Sdk/Frameworks/Runners/TestInvoker.cs:line 264
--- End of stack trace from previous location ---
at Xunit.Sdk.ExecutionTimer.AggregateAsync(Func`1 asyncAction) in /_/src/xunit.execution/Sdk/Frameworks/ExecutionTimer.cs:line 48
at Xunit.Sdk.ExceptionAggregator.RunAsync(Func`1 code) in /_/src/xunit.core/Sdk/ExceptionAggregator.cs:line 90
76 changes: 76 additions & 0 deletions ...s/TRACE_SUCCESS 'CE empty taskSeq, GetAsyncEnumerator + MoveNextAsync multiple times'.txt
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,76 @@
at AfterCode<_, _>, after F# inits the sm, and we can attach extra info
MoveNextAsync...
at MoveNextAsync: normal resumption scenario
at MoveNextAsync: start calling builder.MoveNext()
Resuming at resumption point 0
at Run.MoveNext start
at Bind
at Bind: with __stack_fin = false
at Bind: calling AwaitUnsafeOnCompleted
at Run.MoveNext, __stack_code_fin=False
at Run.MoveNext, await
at MoveNextAsync: done calling builder.MoveNext()
at MoveNextAsyncResult: case pending/faulted/cancelled...
at Bind: with __stack_fin = true
at Bind: with getting result from awaiter
at Bind: calling continuation
at Bind
at Bind: with __stack_fin = false
at Bind: calling AwaitUnsafeOnCompleted
at Run.MoveNext, __stack_code_fin=False
at Run.MoveNext, await
at Bind: with __stack_fin = true
at Bind: with getting result from awaiter
at Bind: calling continuation
at Bind
at Bind: with __stack_fin = false
at Bind: calling AwaitUnsafeOnCompleted
at Run.MoveNext, __stack_code_fin=False
at Run.MoveNext, await
at Bind: with __stack_fin = true
at Bind: with getting result from awaiter
at Bind: calling continuation
at Zero()
at Run.MoveNext, __stack_code_fin=True
at Run.MoveNext, done
Getting result for token on 'None' branch, status: Succeeded
GetAsyncEnumerator, cloning...
MoveNextAsync...
at MoveNextAsync: completed = true
MoveNextAsync...
at MoveNextAsync: normal resumption scenario
at MoveNextAsync: start calling builder.MoveNext()
Resuming at resumption point 0
at Run.MoveNext start
at Bind
at Bind: with __stack_fin = false
at Bind: calling AwaitUnsafeOnCompleted
at Run.MoveNext, __stack_code_fin=False
at Run.MoveNext, await
at MoveNextAsync: done calling builder.MoveNext()
at MoveNextAsyncResult: case pending/faulted/cancelled...
at Bind: with __stack_fin = true
at Bind: with getting result from awaiter
at Bind: calling continuation
at Bind
at Bind: with __stack_fin = false
at Bind: calling AwaitUnsafeOnCompleted
at Run.MoveNext, __stack_code_fin=False
at Run.MoveNext, await
at Bind: with __stack_fin = true
at Bind: with getting result from awaiter
at Bind: calling continuation
at Bind
at Bind: with __stack_fin = false
at Bind: calling AwaitUnsafeOnCompleted
at Run.MoveNext, __stack_code_fin=False
at Run.MoveNext, await
at Bind: with __stack_fin = true
at Bind: with getting result from awaiter
at Bind: calling continuation
at Zero()
at Run.MoveNext, __stack_code_fin=True
at Run.MoveNext, done
Getting result for token on 'None' branch, status: Succeeded
DisposeAsync...
DisposeAsync...
60 changes: 60 additions & 0 deletions src/FSharpy.TaskSeq.Test/fail-trace.txt
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,60 @@
6 (false): at AfterCode<_, _>, after F# inits the sm, and we can attach extra info
6 (false): GetAsyncEnumerator, start cloning...
6 (false): GetAsyncEnumerator, finished cloning...
6 (false): MoveNextAsync...
6 (false): at MoveNextAsync: normal resumption scenario
6 (false): at MoveNextAsync: start calling builder.MoveNext()
6 (false): at IAsyncStateMatchine.MoveNext
6 (false): Resuming at resumption point 0
6 (false): at Run.MoveNext start
6 (false): at Bind
6 (false): at Bind: with __stack_fin = false
6 (false): at Bind: calling AwaitUnsafeOnCompleted
6 (false): at Run.MoveNext, __stack_code_fin=False
6 (false): at Run.MoveNext, await
6 (false): at MoveNextAsync: done calling builder.MoveNext()
6 (false): at MoveNextAsyncResult: case Pending...
13 (false): at IAsyncStateMatchine.MoveNext
13 (false): at Bind: with __stack_fin = true
13 (false): at Bind: with getting result from awaiter
13 (false): at Bind: calling continuation
13 (false): at Zero()
13 (false): at Run.MoveNext, __stack_code_fin=True
13 (false): at Run.MoveNext, done
14 (false): Getting result for token on 'None' branch, status: Succeeded
15 (false): GetAsyncEnumerator, start cloning...
15 (false): GetAsyncEnumerator, finished cloning...
15 (false): MoveNextAsync...
15 (false): at MoveNextAsync: normal resumption scenario
15 (false): at MoveNextAsync: start calling builder.MoveNext()
15 (false): at IAsyncStateMatchine.MoveNext
15 (false): at Bind: with __stack_fin = true
15 (false): at Bind: with getting result from awaiter
15 (false): Exception dump:
15 (false): System.NullReferenceException: Object reference not set to an instance of an object.
at FSharpy.Tests.TestUtils.Gen.getEmptyVariant@308-15.MoveNext() in D:\Projects\OpenSource\Abel\TaskSeq\src\FSharpy.TaskSeq.Test\TestUtils.fs:line 309
15 (false): Setting exception of PromiseOfValueOrEnd to: Object reference not set to an instance of an object.
15 (false): at MoveNextAsync: done calling builder.MoveNext()
15 (false): at MoveNextAsyncResult: case Faulted...
15 (false): Getting result for token on 'None' branch, status: Faulted
15 (false): Error 'Object reference not set to an instance of an object.' for token: 3
15 (false): DisposeAsync...
15 (false): DisposeAsync...
13 (false): Exception dump:
13 (false): System.InvalidOperationException: An attempt was made to transition a task to a final state when it had already completed.
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.SetExistingTaskResult(Task`1 task, TResult result)
at System.Runtime.CompilerServices.AsyncIteratorMethodBuilder.Complete()
at FSharpy.Tests.TestUtils.Gen.getEmptyVariant@308-15.MoveNext() in D:\Projects\OpenSource\Abel\TaskSeq\src\FSharpy.TaskSeq.Test\TestUtils.fs:line 309
13 (false): Setting exception of PromiseOfValueOrEnd to: An attempt was made to transition a task to a final state when it had already completed.
13 (false): at IAsyncStatemachine EXCEPTION!!!
13 (false): System.InvalidOperationException: Operation is not valid due to the current state of the object.
at System.Threading.Tasks.Sources.ManualResetValueTaskSourceCore`1.SignalCompletion()
at System.Threading.Tasks.Sources.ManualResetValueTaskSourceCore`1.SetException(Exception error)
at FSharpy.Tests.TestUtils.Gen.getEmptyVariant@308-15.MoveNext() in D:\Projects\OpenSource\Abel\TaskSeq\src\FSharpy.TaskSeq.Test\TestUtils.fs:line 309
at FSharpy.TaskSeqBuilders.TaskSeq`2.System.Runtime.CompilerServices.IAsyncStateMachine.MoveNext() in D:\Projects\OpenSource\Abel\TaskSeq\src\FSharpy.TaskSeq\TaskSeqBuilder.fs:line 249
System.NullReferenceException: Object reference not set to an instance of an object.
at FSharpy.Tests.Bug #42 -- synchronous.CE empty taskSeq\, GetAsyncEnumerator - MoveNextAsync multiple times@52.MoveNext() in D:\Projects\OpenSource\Abel\TaskSeq\src\FSharpy.TaskSeq.Test\TaskSeq.StateTransitionBug.Tests.CE.fs:line 60
at Xunit.Sdk.TestInvoker`1.<>c__DisplayClass48_0.<<InvokeTestMethodAsync>b__1>d.MoveNext() in /_/src/xunit.execution/Sdk/Frameworks/Runners/TestInvoker.cs:line 264
--- End of stack trace from previous location ---
at Xunit.Sdk.ExecutionTimer.AggregateAsync(Func`1 asyncAction) in /_/src/xunit.execution/Sdk/Frameworks/ExecutionTimer.cs:line 48
at Xunit.Sdk.ExceptionAggregator.RunAsync(Func`1 code) in /_/src/xunit.core/Sdk/ExceptionAggregator.cs:line 90
51 changes: 51 additions & 0 deletions src/FSharpy.TaskSeq.Test/success-trace.txt
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,51 @@
6 (false): at AfterCode<_, _>, after F# inits the sm, and we can attach extra info
6 (false): GetAsyncEnumerator, start cloning...
6 (false): GetAsyncEnumerator, finished cloning...
6 (false): MoveNextAsync...
6 (false): at MoveNextAsync: normal resumption scenario
6 (false): at MoveNextAsync: start calling builder.MoveNext()
6 (false): at IAsyncStateMatchine.MoveNext
6 (false): Resuming at resumption point 0
6 (false): at Run.MoveNext start
6 (false): at Bind
6 (false): at Bind: with __stack_fin = false
6 (false): at Bind: calling AwaitUnsafeOnCompleted
6 (false): at Run.MoveNext, __stack_code_fin=False
6 (false): at Run.MoveNext, await
6 (false): at MoveNextAsync: done calling builder.MoveNext()
6 (false): at MoveNextAsyncResult: case Pending...
13 (false): at IAsyncStateMatchine.MoveNext
13 (false): at Bind: with __stack_fin = true
13 (false): at Bind: with getting result from awaiter
13 (false): at Bind: calling continuation
13 (false): at Zero()
13 (false): at Run.MoveNext, __stack_code_fin=True
13 (false): at Run.MoveNext, done
14 (false): Getting result for token on 'None' branch, status: Succeeded
15 (false): GetAsyncEnumerator, start cloning...
15 (false): GetAsyncEnumerator, finished cloning...
15 (false): MoveNextAsync...
15 (false): at MoveNextAsync: completed = true
15 (false): MoveNextAsync...
15 (false): at MoveNextAsync: normal resumption scenario
15 (false): at MoveNextAsync: start calling builder.MoveNext()
15 (false): at IAsyncStateMatchine.MoveNext
15 (false): Resuming at resumption point 0
15 (false): at Run.MoveNext start
15 (false): at Bind
15 (false): at Bind: with __stack_fin = false
15 (false): at Bind: calling AwaitUnsafeOnCompleted
15 (false): at Run.MoveNext, __stack_code_fin=False
15 (false): at Run.MoveNext, await
15 (false): at MoveNextAsync: done calling builder.MoveNext()
15 (false): at MoveNextAsyncResult: case Pending...
9 (true): at IAsyncStateMatchine.MoveNext
9 (true): at Bind: with __stack_fin = true
9 (true): at Bind: with getting result from awaiter
9 (true): at Bind: calling continuation
9 (true): at Zero()
9 (true): at Run.MoveNext, __stack_code_fin=True
9 (true): at Run.MoveNext, done
9 (true): Getting result for token on 'None' branch, status: Succeeded
9 (true): DisposeAsync...
9 (true): DisposeAsync...
Loading