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.

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

Jump to bottom

System.Text.RegularExpressions.RegexMatchTimeoutException #4159

Closed
thomhurst opened this issue Nov 26, 2024 · 7 comments · Fixed by #4160 or #4189
Closed

System.Text.RegularExpressions.RegexMatchTimeoutException #4159

thomhurst opened this issue Nov 26, 2024 · 7 comments · Fixed by #4160 or #4189
Labels
Area: Terminal reporter Area: Testing Platform Belongs to the Microsoft.Testing.Platform core library In-PR

Comments

@thomhurst
Copy link
Contributor

thomhurst commented Nov 26, 2024 •
edited
Loading

Seems to be affecting Macs again: https://github.com/thomhurst/TUnit/actions/runs/12029859325/job/33536030398

Happening since upgrading to 1.5.0-preview.24575.7

Error: Unhandled exception. System.Text.RegularExpressions.RegexMatchTimeoutException: The Regex engine has timed out while trying to match a pattern to an input string. This can occur for many reasons, including very large inputs or excessive backtracking caused by nested quantifiers, back-references and other factors.
   at System.Text.RegularExpressions.RegexRunner.<CheckTimeout>g__ThrowRegexTimeout|25_0()
   at System.Text.RegularExpressions.Generated.<RegexGenerator_g>F06D33C3F8C8C3FD257C1A1967E3A3BAC4BE9C8EC41CC9366C764C2205C68F0CE__GetFrameRegex_1.RunnerFactory.Runner.TryMatchAtCurrentPosition(ReadOnlySpan`1) in /_/artifacts/obj/Microsoft.Testing.Platform/Release/net8.0/System.Text.RegularExpressions.Generator/System.Text.RegularExpressions.Generator.RegexGenerator/RegexGenerator.g.cs:line 639
   at System.Text.RegularExpressions.Generated.<RegexGenerator_g>F06D33C3F8C8C3FD257C1A1967E3A3BAC4BE9C8EC41CC9366C764C2205C68F0CE__GetFrameRegex_1.RunnerFactory.Runner.Scan(ReadOnlySpan`1) in /_/artifacts/obj/Microsoft.Testing.Platform/Release/net8.0/System.Text.RegularExpressions.Generator/System.Text.RegularExpressions.Generator.RegexGenerator/RegexGenerator.g.cs:line 537
   at System.Text.RegularExpressions.Regex.ScanInternal(RegexRunnerMode, Boolean, String, Int32, RegexRunner, ReadOnlySpan`1, Boolean)
   at System.Text.RegularExpressions.Regex.RunSingleMatch(RegexRunnerMode, Int32, String, Int32, Int32, Int32)
   at System.Text.RegularExpressions.Regex.Match(String)
   at Microsoft.Testing.Platform.OutputDevice.Terminal.TerminalTestReporter.AppendStackFrame(ITerminal, String) in /_/src/Platform/Microsoft.Testing.Platform/OutputDevice/Terminal/TerminalTestReporter.cs:line 650
   at Microsoft.Testing.Platform.OutputDevice.Terminal.TerminalTestReporter.FormatStackTrace(ITerminal, FlatException[], Int32) in /_/src/Platform/Microsoft.Testing.Platform/OutputDevice/Terminal/TerminalTestReporter.cs:line 601
   at Microsoft.Testing.Platform.OutputDevice.Terminal.TerminalTestReporter.RenderTestCompleted(ITerminal , String , String, String, String , TestOutcome, TimeSpan, FlatException[] , String, String, String, String) in /_/src/Platform/Microsoft.Testing.Platform/OutputDevice/Terminal/TerminalTestReporter.cs:line 517
   at Microsoft.Testing.Platform.OutputDevice.Terminal.TerminalTestReporter.<>c__DisplayClass27_0.<TestCompleted>b__0(ITerminal terminal) in /_/src/Platform/Microsoft.Testing.Platform/OutputDevice/Terminal/TerminalTestReporter.cs:line 439
   at Microsoft.Testing.Platform.OutputDevice.Terminal.TestProgressStateAwareTerminal.WriteToTerminal(Action`1) in /_/src/Platform/Microsoft.Testing.Platform/OutputDevice/Terminal/TestProgressStateAwareTerminal.cs:line 129
   at Microsoft.Testing.Platform.OutputDevice.Terminal.TerminalTestReporter.TestCompleted(String , String, String, String, String , TestOutcome, TimeSpan, FlatException[] , String, String, String, String) in /_/src/Platform/Microsoft.Testing.Platform/OutputDevice/Terminal/TerminalTestReporter.cs:line 439
   at Microsoft.Testing.Platform.OutputDevice.Terminal.TerminalTestReporter.TestCompleted(String , String, String, String, String , TestOutcome, TimeSpan, String, Exception, String, String, String, String) in /_/src/Platform/Microsoft.Testing.Platform/OutputDevice/Terminal/TerminalTestReporter.cs:line 386
   at Microsoft.Testing.Platform.OutputDevice.TerminalOutputDevice.ConsumeAsync(IDataProducer, IData, CancellationToken) in /_/src/Platform/Microsoft.Testing.Platform/OutputDevice/TerminalOutputDevice.cs:line 458
   at Microsoft.Testing.Platform.Messages.AsyncConsumerDataProcessor.ConsumeAsync() in /_/src/Platform/Microsoft.Testing.Platform/Messages/ChannelConsumerDataProcessor.cs:line 74
   at Microsoft.Testing.Platform.Messages.AsyncConsumerDataProcessor.DrainDataAsync() in /_/src/Platform/Microsoft.Testing.Platform/Messages/ChannelConsumerDataProcessor.cs:line 146
   at Microsoft.Testing.Platform.Messages.AsynchronousMessageBus.DrainDataAsync() in /_/src/Platform/Microsoft.Testing.Platform/Messages/AsynchronousMessageBus.cs:line 177
   at Microsoft.Testing.Platform.Messages.MessageBusProxy.DrainDataAsync() in /_/src/Platform/Microsoft.Testing.Platform/Messages/MessageBusProxy.cs:line 39
   at Microsoft.Testing.Platform.Hosts.CommonTestHost.NotifyTestSessionEndAsync(SessionUid, BaseMessageBus, ServiceProvider, CancellationToken) in /_/src/Platform/Microsoft.Testing.Platform/Hosts/CommonTestHost.cs:line 192
   at Microsoft.Testing.Platform.Hosts.CommonTestHost.ExecuteRequestAsync(IPlatformOutputDevice, ITestSessionContext, ServiceProvider, BaseMessageBus, ITestFramework, ClientInfo) in /_/src/Platform/Microsoft.Testing.Platform/Hosts/CommonTestHost.cs:line 133
   at Microsoft.Testing.Platform.Hosts.ConsoleTestHost.InternalRunAsync() in /_/src/Platform/Microsoft.Testing.Platform/Hosts/ConsoleTestHost.cs:line 85
   at Microsoft.Testing.Platform.Hosts.ConsoleTestHost.InternalRunAsync() in /_/src/Platform/Microsoft.Testing.Platform/Hosts/ConsoleTestHost.cs:line 117
   at Microsoft.Testing.Platform.Hosts.CommonTestHost.RunTestAppAsync(CancellationToken) in /_/src/Platform/Microsoft.Testing.Platform/Hosts/CommonTestHost.cs:line 106
   at Microsoft.Testing.Platform.Hosts.CommonTestHost.RunAsync() in /_/src/Platform/Microsoft.Testing.Platform/Hosts/CommonTestHost.cs:line 34
   at Microsoft.Testing.Platform.Hosts.CommonTestHost.RunAsync() in /_/src/Platform/Microsoft.Testing.Platform/Hosts/CommonTestHost.cs:line 72
   at Microsoft.Testing.Platform.Builder.TestApplication.RunAsync() in /_/src/Platform/Microsoft.Testing.Platform/Builder/TestApplication.cs:line 244
   at TestingPlatformEntryPoint.Main(String[]) in /_/TUnit.TestProject/obj/Release/net8.0/osx-x64/TestPlatformEntryPoint.cs:line 16
   at TestingPlatformEntryPoint.<Main>(String[])

Exceptions within Console/Display classes should probably be logged but swallowed - Currently they break test execution.

Offending line is here: https://github.com/Microsoft/testfx/blob/eaf26c33a6e9e4e7ff37b3447ef0ca856e6b4239/src/Platform/Microsoft.Testing.Platform/OutputDevice/Terminal/TerminalTestReporter.cs#L54

It's got a 1 second timeout on it. I guess due to constrained system resources this is being hit.
This was referenced Nov 26, 2024
Closed
Merged
@nohwnd
Copy link
Member

nohwnd commented Nov 27, 2024

Exceptions within Console/Display classes should probably be logged but swallowed - Currently they break test execution.

That is unfortunate, but imho the correct way to do this. Otherwise you would not see it and we have no other way of receiving that kind of information.

@nohwnd
Copy link
Member

nohwnd commented Nov 27, 2024

I've added 1000ms timeout because that seemed like lightyears in regex matching, especially on the source generated. I would start by wrapping the match into try catch, and report the string that is being matched.

Great that you are already consuning preview, so we can debug this with a simpler loop.

@nohwnd nohwnd mentioned this issue Nov 27, 2024
Merged
@nohwnd
Copy link
Member

nohwnd commented Nov 27, 2024

There should be new package in the preview channel in about half an hour, please update when convenient for you. Hopefully we will see what the source of the timeout is.

@thomhurst
Copy link
Contributor Author

@nohwnd

  Error: Unhandled Exception: 
  System.Text.RegularExpressions.RegexMatchTimeoutException: Parsing stack trace 
  line with regex timed out. Input: '   at 
  System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task) + 0xbe'
   ---> System.Text.RegularExpressions.RegexMatchTimeoutException: The Regex 
  engine has timed out while trying to match a pattern to an input string. This 
  can occur for many reasons, including very large inputs or excessive 
  backtracking caused by nested quantifiers, back-references and other factors.
     at 
  System.Text.RegularExpressions.RegexRunner.g__ThrowRegexTimeout|25
  _0() + 0x5f
     at 
  System.Text.RegularExpressions.Generated.F06D33C3F8C8C3FD257C1
  A1967E3A3BAC4BE9C8EC41CC9366C764C2205C68F0CE__GetFrameRegex_1.RunnerFactory.Runn
  er.TryMatchAtCurrentPosition(ReadOnlySpan`1) + 0xbbd
     at 
  System.Text.RegularExpressions.Generated.F06D33C3F8C8C3FD257C1
  A1967E3A3BAC4BE9C8EC41CC9366C764C2205C68F0CE__GetFrameRegex_1.RunnerFactory.Runn
  er.Scan(ReadOnlySpan`1) + 0x35
     at System.Text.RegularExpressions.Regex.ScanInternal(RegexRunnerMode, 
  Boolean, String, Int32, RegexRunner, ReadOnlySpan`1, Boolean) + 0x36
     at System.Text.RegularExpressions.Regex.RunSingleMatch(RegexRunnerMode, 
  Int32, String, Int32, Int32, Int32) + 0x157
     at System.Text.RegularExpressions.Regex.Match(String) + 0x3e
     at 
  Microsoft.Testing.Platform.OutputDevice.Terminal.TerminalTestReporter.AppendStac
  kFrame(ITerminal, String) + 0x115
     --- End of inner exception stack trace ---
     at 
  System.Text.RegularExpressions.RegexRunner.g__ThrowRegexTimeout|25
  _0() + 0x5f
     at 
  System.Text.RegularExpressions.Generated.F06D33C3F8C8C3FD257C1
  A1967E3A3BAC4BE9C8EC41CC9366C764C2205C68F0CE__GetFrameRegex_1.RunnerFactory.Runn
  er.TryMatchAtCurrentPosition(ReadOnlySpan`1) + 0xbbd
     at 
  System.Text.RegularExpressions.Generated.F06D33C3F8C8C3FD257C1
  A1967E3A3BAC4BE9C8EC41CC9366C764C2205C68F0CE__GetFrameRegex_1.RunnerFactory.Runn
  er.Scan(ReadOnlySpan`1) + 0x35
     at System.Text.RegularExpressions.Regex.ScanInternal(RegexRunnerMode, 
  Boolean, String, Int32, RegexRunner, ReadOnlySpan`1, Boolean) + 0x36
     at System.Text.RegularExpressions.Regex.RunSingleMatch(RegexRunnerMode, 
  Int32, String, Int32, Int32, Int32) + 0x157
     at System.Text.RegularExpressions.Regex.Match(String) + 0x3e
     at 
  Microsoft.Testing.Platform.OutputDevice.Terminal.TerminalTestReporter.AppendStac
  kFrame(ITerminal, String) + 0x115
  --- End of stack trace from previous location ---
     at 
  Microsoft.Testing.Platform.OutputDevice.Terminal.TerminalTestReporter.AppendStac
  kFrame(ITerminal, String) + 0x9e8
     at 
  Microsoft.Testing.Platform.OutputDevice.Terminal.TerminalTestReporter.FormatStac
  kTrace(ITerminal, FlatException[], Int32) + 0x11a
     at 
  Microsoft.Testing.Platform.OutputDevice.Terminal.TerminalTestReporter.RenderTest
  Completed(ITerminal, String, String, String, String, TestOutcome, TimeSpan, 
  FlatException[], String, String, String, String) + 0x783
     at 
  Microsoft.Testing.Platform.OutputDevice.Terminal.TerminalTestReporter.<>c__Displ
  ayClass27_0.b__0(ITerminal terminal) + 0x63
     at 
  Microsoft.Testing.Platform.OutputDevice.Terminal.TestProgressStateAwareTerminal.
  WriteToTerminal(Action`1) + 0x94
     at 
  Microsoft.Testing.Platform.OutputDevice.Terminal.TerminalTestReporter.TestComple
  ted(String, String, String, String, String, TestOutcome, TimeSpan, FlatException
  [], String, String, String, String) + 0x3d2
     at 
  Microsoft.Testing.Platform.OutputDevice.TerminalOutputDevice.d__57
  .MoveNext() + 0x407
  --- End of stack trace from previous location ---
     at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() + 0x1c
     at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task) + 
  0xbe
     at 
  System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotificat
  ion(Task, ConfigureAwaitOptions) + 0x4e
     at 
  Microsoft.Testing.Platform.Messages.AsyncConsumerDataProcessor.d__
  12.MoveNext() + 0x2ca
  --- End of stack trace from previous location ---
     at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() + 0x1c
     at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task) + 
  0xbe
     at 
  System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotificat
  ion(Task, ConfigureAwaitOptions) + 0x4e
     at 
  Microsoft.Testing.Platform.Messages.AsyncConsumerDataProcessor.d
  __14.MoveNext() + 0x1f0
  --- End of stack trace from previous location ---
     at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() + 0x1c
     at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task) + 
  0xbe
     at 
  System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotificat
  ion(Task, ConfigureAwaitOptions) + 0x4e
     at 
  Microsoft.Testing.Platform.Messages.AsynchronousMessageBus.d__17
  .MoveNext() + 0x775
  --- End of stack trace from previous location ---
     at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() + 0x1c
     at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task) + 
  0xbe
     at 
  System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotificat
  ion(Task, ConfigureAwaitOptions) + 0x4e
     at 
  Microsoft.Testing.Platform.Messages.MessageBusProxy.d__6.MoveNex
  t() + 0xaa
  --- End of stack trace from previous location ---
     at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() + 0x1c
     at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task) + 
  0xbe
     at 
  System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotificat
  ion(Task, ConfigureAwaitOptions) + 0x4e
     at 
  Microsoft.Testing.Platform.Hosts.CommonTestHost.d__16
  .MoveNext() + 0xd2
  --- End of stack trace from previous location ---
     at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() + 0x1c
     at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task) + 
  0xbe
     at 
  System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotificat
  ion(Task, ConfigureAwaitOptions) + 0x4e
     at 
  Microsoft.Testing.Platform.Hosts.CommonTestHost.d__12.MoveN
  ext() + 0x318
  --- End of stack trace from previous location ---
     at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() + 0x1c
     at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task) + 
  0xbe
     at 
  System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotificat
  ion(Task, ConfigureAwaitOptions) + 0x4e
     at 
  Microsoft.Testing.Platform.Hosts.ConsoleTestHost.d__10.MoveNex
  t() + 0x867
  --- End of stack trace from previous location ---
     at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() + 0x1c
     at 
  Microsoft.Testing.Platform.Hosts.ConsoleTestHost.d__10.MoveNex
  t() + 0x10b3
  --- End of stack trace from previous location ---
     at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() + 0x1c
     at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task) + 
  0xbe
     at 
  System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotificat
  ion(Task, ConfigureAwaitOptions) + 0x4e
     at 
  Microsoft.Testing.Platform.Hosts.CommonTestHost.d__10.MoveNext(
  ) + 0x233
  --- End of stack trace from previous location ---
     at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() + 0x1c
     at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task) + 
  0xbe
     at 
  System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotificat
  ion(Task, ConfigureAwaitOptions) + 0x4e
     at Microsoft.Testing.Platform.Hosts.CommonTestHost.d__8.MoveNext() 
  + 0x18e
  --- End of stack trace from previous location ---
     at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() + 0x1c
     at Microsoft.Testing.Platform.Hosts.CommonTestHost.d__8.MoveNext() 
  + 0x722
  --- End of stack trace from previous location ---
     at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() + 0x1c
     at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task) + 
  0xbe
     at 
  System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotificat
  ion(Task, ConfigureAwaitOptions) + 0x4e
     at 
  Microsoft.Testing.Platform.Builder.TestApplication.d__17.MoveNext() + 
  0xaf
  --- End of stack trace from previous location ---
     at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() + 0x1c
     at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task) + 
  0xbe
     at 
  System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotificat
  ion(Task, ConfigureAwaitOptions) + 0x4e
     at TestingPlatformEntryPoint.d__0.MoveNext() + 0x224
  --- End of stack trace from previous location ---
     at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() + 0x1c
     at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task) + 
  0xbe
     at 
  System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotificat
  ion(Task, ConfigureAwaitOptions) + 0x4e
     at TestingPlatformEntryPoint.(String[] args) + 0x2e
     at TUnit!+0xed2b6c

@Evangelink Evangelink added Area: Testing Platform Belongs to the Microsoft.Testing.Platform core library Area: Terminal reporter and removed Needs: Triage 🔍 labels Nov 27, 2024
@Evangelink Evangelink reopened this Nov 27, 2024
@markples
Copy link
Member

outsider here, hoping to not distract -

How constrained does this mean? Is the system just totally trashed (swapping, etc.)?

I guess due to constrained system resources this is being hit.

It skips a test after 6 seconds and then takes over 3 minutes to pass one test. Is that expected?

  [+0/x0/?0] TUnit.Engine.Tests.dll (net8.0|arm64)(3s)
  [+0/x0/?0] TUnit.Engine.Tests.dll (net8.0|arm64)(6s)
  Skipping JsonOutputTests.Test...
  skipped Test (0ms)
  [+0/x0/?1] TUnit.Engine.Tests.dll (net8.0|arm64)(9s)
...
  [+0/x0/?1] TUnit.Engine.Tests.dll (net8.0|arm64)(3m 27s) 
  [+1/x0/?1] TUnit.Engine.Tests.dll (net8.0|arm64)(3m 30s)

@nohwnd
Copy link
Member

nohwnd commented Nov 28, 2024

Yeah I was looking at how long the tests run as well, but there was no complain from OP about the testing being slow, and I don't know their tests.

I've discussed the timeout issue internally, and the implementation of the timeout is not super helpful, because it uses wallclock time rather than how much time the regex actually spent executing on cpu. So if the thread / runner gets suspended, the regex will still time out. In all our tries we could not get the regex itself to run over 1ms, which is still more than I would expect on matching a single line. And the regex is linear, so it should be okay, to simply remove the timeout.

@thomhurst
Copy link
Contributor Author

Removing the timeout sounds sensible to me

@nohwnd nohwnd mentioned this issue Nov 28, 2024
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
Area: Terminal reporter Area: Testing Platform Belongs to the Microsoft.Testing.Platform core library In-PR
Projects
None yet
Milestone
No milestone
4 participants
@nohwnd @Evangelink @markples @thomhurst