dotnet watch hard exits when it cannot launch browser (due to custom log formatting) in .NET 9

[cfbao]

Describe the bug

If using custom log formatting (e.g. JSON) and "launchBrowser": true in launchSettings.json, dotnet watch will hard exit when it fails to launch the browser.

To Reproduce

• Create a web project using .NET 9 SDK dotnet new web

• Add builder.Logging.AddJsonConsole(); to Program.cs so the full source code is

  var builder = WebApplication.CreateBuilder(args);
  builder.Logging.AddJsonConsole();
  var app = builder.Build();
  app.MapGet("/", () => "Hello World!");
  app.Run();

• Run dotnet watch

• See an exception printed and the process exits with a non-zero return code. The underlying process that directly runs the project may be orphaned.

Note: If doing the same with .NET 8 SDK, you'd only see a message that says "Unable to launch the browser" but the process doesn't exit.

Exceptions (if any)

Unhandled exception. System.FormatException: Input string was not in a correct format. Failure to parse near offset 51. Expected an ASCII digit.
   at System.Text.ValueStringBuilder.AppendFormatHelper(IFormatProvider provider, String format, ReadOnlySpan`1 args)
   at System.String.FormatHelper(IFormatProvider provider, String format, ReadOnlySpan`1 args)
   at System.String.Format(String format, Object[] args)
   at Microsoft.Extensions.Tools.Internal.MessageDescriptor.TryGetMessage(String prefix, Object[] args, String& message)
   at Microsoft.Extensions.Tools.Internal.ConsoleReporter.Report(MessageDescriptor descriptor, String prefix, Object[] args)
   at Microsoft.Extensions.Tools.Internal.IReporter.Report(MessageDescriptor descriptor, Object[] args)
   at Microsoft.Extensions.Tools.Internal.IReporter.Verbose(String message, String emoji)
   at Microsoft.DotNet.Watcher.Tools.BrowserConnector.LaunchBrowser(LaunchSettingsProfile launchProfile, String launchUrl, BrowserRefreshServer server)
   at Microsoft.DotNet.Watcher.Tools.BrowserConnector.<>c__DisplayClass11_0.<GetBrowserLaunchTrigger>g__handler|0(Object sender, DataReceivedEventArgs eventArgs)
   at System.Diagnostics.AsyncStreamReader.FlushMessageQueue(Boolean rethrowInNewThread)
--- End of stack trace from previous location ---
   at System.Threading.ThreadPoolWorkQueue.Dispatch()
   at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()

Further technical details

.NET SDK:
 Version:           9.0.100-rc.2.24474.11
 Commit:            315e1305db
 Workload version:  9.0.100-manifests.cea95dba
 MSBuild version:   17.12.0-preview-24473-03+fea15fbd1

Runtime Environment:
 OS Name:     Windows
 OS Version:  10.0.19045
 OS Platform: Windows
 RID:         win-x64
 Base Path:   C:\Program Files\dotnet\sdk\9.0.100-rc.2.24474.11\

.NET workloads installed:
There are no installed workloads to display.
Configured to use loose manifests when installing new manifests.

Host:
  Version:      9.0.0-rc.2.24473.5
  Architecture: x64
  Commit:       990ebf52fc

.NET SDKs installed:
  8.0.403 [C:\Program Files\dotnet\sdk]
  9.0.100-rc.2.24474.11 [C:\Program Files\dotnet\sdk]

.NET runtimes installed:
  Microsoft.AspNetCore.App 8.0.10 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 9.0.0-rc.2.24474.3 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.NETCore.App 6.0.33 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 8.0.3 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 8.0.10 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 9.0.0-rc.2.24473.5 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.WindowsDesktop.App 8.0.3 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 8.0.10 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 9.0.0-rc.2.24474.4 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]

Other architectures found:
  None

Environment variables:
  Not set

global.json file:
  Not found

Learn more:
  https://aka.ms/dotnet/info

Download .NET:
  https://aka.ms/dotnet/download

[dotnet-issue-labeler]

I couldn't figure out the best area label to add to this issue. If you have write-permissions please help me learn by adding exactly one area label.

[dotnet-issue-labeler]

I couldn't figure out the best area label to add to this issue. If you have write-permissions please help me learn by adding exactly one area label.

[baronfel]

For posterity, here is the output from the sample code above when run:

> dotnet watch
dotnet watch 🔥 Hot reload enabled. For a list of supported edits, see https://aka.ms/dotnet/hot-reload.
  💡 Press "Ctrl + R" to restart.
Using launch settings from E:\Code\Scratch\json-output\Properties\launchSettings.json...
Building...
{"EventId":14,"LogLevel":"Information","Category":"Microsoft.Hosting.Lifetime","Message":"Now listening on: http://localhost:5205","State":{"Message":"Now listening on: http://localhost:5205","address":"http://localhost:5205","{OriginalFormat}":"Now listening on: {address}"}}
Unhandled exception. System.FormatException: Input string was not in a correct format. Failure to parse near offset 51. Expected an ASCII digit.
   at System.Text.ValueStringBuilder.AppendFormatHelper(IFormatProvider provider, String format, ReadOnlySpan`1 args)
   at System.String.FormatHelper(IFormatProvider provider, String format, ReadOnlySpan`1 args)
   at System.String.Format(String format, Object[] args)
   at Microsoft.Extensions.Tools.Internal.MessageDescriptor.TryGetMessage(String prefix, Object[] args, String& message)
   at Microsoft.Extensions.Tools.Internal.ConsoleReporter.Report(MessageDescriptor descriptor, String prefix, Object[] args)
   at Microsoft.Extensions.Tools.Internal.IReporter.Report(MessageDescriptor descriptor, Object[] args)
   at Microsoft.Extensions.Tools.Internal.IReporter.Verbose(String message, String emoji)
   at Microsoft.DotNet.Watcher.Tools.BrowserConnector.LaunchBrowser(LaunchSettingsProfile launchProfile, String launchUrl, BrowserRefreshServer server)
   at Microsoft.DotNet.Watcher.Tools.BrowserConnector.<>c__DisplayClass11_0.<GetBrowserLaunchTrigger>g__handler|0(Object sender, DataReceivedEventArgs eventArgs)
   at System.Diagnostics.AsyncStreamReader.FlushMessageQueue(Boolean rethrowInNewThread)
--- End of stack trace from previous location ---
   at System.Threading.ThreadPoolWorkQueue.Dispatch()
   at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()

[baronfel]

This is happening because a regex is used to scrape the stdout of the running application to get the port the application is bound to. This regex captures too much - in the example stdout I pasted above, the regex captures the following string:

"http://localhost:5205","State":{"Message":"Now listening on: http://localhost:5205","address":"http://localhost:5205","{OriginalFormat}":"Now listening on: {address}"}}"

So either the regex needs to be constrained a bit more, or the kind of allowed output for applications needs to be constrained more, or we need a more resilient signalling mechanism here for detecting the ports that webapps are bound to. Is there any kind of run-time introspection here? Maybe @DamianEdwards knows?

[cfbao]

Just to clarify my intention with this issue:

dotnet watch was failing to launch the browser with JSON formatted logs in .NET 8 already, and it didn't bother me that much.
The new issue in .NET 9 that's causing a lot more pain is the fact that dotnet watch also exits as it fails to launch the browser, which breaks existing projects.

Of course, it'd be ideal if there's a fix that can make dotnet watch launch browser reliably, but if that can't be achieved easily, I'd like to have the .NET 8 behaviour of just printing a warning message and carry on with running the project with hot reload.

[DamianEdwards]

I think the other tools like VS do this detection by attempting to open a socket to the address specified in the launch profile rather than sniffing console output. Once the socket can be opened it assumes the server is now listening and the browser can be launched. We should of course verify that but perhaps we should move watch to the same mechanism.