feat(playwright): Log debug info (#924)

* feat(playwright): Log debug info

* debug as string

* debug note

demos/PdfDemo/PdfDemo-Local.csproj

@@ -8,4 +8,8 @@
     <ItemGroup>
       <ProjectReference Include="..\..\src\PlaywrightSharp\PlaywrightSharp.csproj" />
     </ItemGroup>
+    <ItemGroup>
+      <PackageReference Include="Microsoft.Extensions.Logging.Debug" Version="3.1.8" />
+      <PackageReference Include="Microsoft.Extensions.Logging" Version="3.1.8" />
+    </ItemGroup>
 </Project>

demos/PdfDemo/Program.cs

@@ -2,6 +2,7 @@
 using System.IO;
 using System.Linq;
 using System.Threading.Tasks;
+using Microsoft.Extensions.Logging;
 using PlaywrightSharp;
 
 namespace PdfDemo
@@ -12,7 +13,14 @@ static async Task Main(string[] args)
         {
             Console.WriteLine("Installing playwright");
             await Playwright.InstallAsync();
-            using var playwright = await Playwright.CreateAsync();
+            ILoggerFactory loggerFactory = LoggerFactory.Create(builder =>
+            {
+                builder.SetMinimumLevel(LogLevel.Debug);
+                builder.AddDebug();
+                builder.AddFilter((f, _) => f == "PlaywrightSharp.Playwright");
+            });
+
+            using var playwright = await Playwright.CreateAsync(loggerFactory, debug: "pw:api");
             await using var browser = await playwright.Chromium.LaunchAsync(new LaunchOptions { Headless = true });
 
             var page = await browser.NewPageAsync();

docfx_project/examples/Playwright.Logger.md

@@ -0,0 +1,29 @@
+# How to get internal logs
+_Contributors: [Dario Kondratiuk](https://www.hardkoded.com/)_
+
+## Problem
+
+You need to get the internal log information to debug a problem.
+
+## Solution
+
+Playwright Sharp uses a [.NET Logger Factory](https://docs.microsoft.com/en-us/dotnet/api/microsoft.extensions.logging.iloggerfactory?view=dotnet-plat-ext-3.1&WT.mc_id=DT-MVP-5003814) to log the communication between the library and the playwright driver.
+
+It uses two categories:
+ * All the communication between the library and the driver is under the `PlaywrightSharp.Transport.Connection` category.
+ * The debug information coming from the driver, when `debug: "pw:api"` is set, is under the `PlaywrightSharp.Playwright` category. The `debug` argument is a shortcut to the `DEBUG` environment variable Playwright uses to setup its logging tool.
+
+You create an `ILoggerFactory` in the same way you would build a logger in ASP.NET. You can also use extension methods, like [AddDebug](https://docs.microsoft.com/en-us/dotnet/api/microsoft.extensions.logging.debugloggerfactoryextensions.adddebug?view=dotnet-plat-ext-3.1&WT.mc_id=DT-MVP-5003814) to send the log in the output window, or [AddConsole](https://docs.microsoft.com/en-us/dotnet/api/microsoft.extensions.logging.consoleloggerextensions.addconsole?view=dotnet-plat-ext-3.1&WT.mc_id=DT-MVP-5003814) to send it to the console.
+
+```cs
+ILoggerFactory loggerFactory = LoggerFactory.Create(builder =>
+{
+    builder.SetMinimumLevel(LogLevel.Debug);
+    builder.AddDebug();
+    builder.AddFilter((f, _) => f == "PlaywrightSharp.Playwright");
+});
+
+using var playwright = await Playwright.CreateAsync(loggerFactory, debug: "pw:api");
+```
+
+The `debug` is only needed for the `PlaywrightSharp.Playwright` category. `PlaywrightSharp.Transport.Connection` logs will come with no extra argument.

docfx_project/examples/toc.yml

@@ -1,4 +1,6 @@
 - name: Basic Examples
   items:
     - name: How to take screenshots and save it as a file
-      href: Page.ScreenshotAsync.md
+      href: Page.ScreenshotAsync.md
+    - name: How to get internal logs
+      href: Playwright.Logger.md

src/PlaywrightSharp/Playwright.cs

@@ -97,14 +97,23 @@ public IBrowserType this[string browserType]
         /// <param name="browsersPath">Specify a shared folder that playwright will use to download browsers and to look for browsers when launching browser instances.
         /// It is a shortcut to the PLAYWRIGHT_BROWSERS_PATH environment variable.
         /// </param>
+        /// <param name="debug">Enables the playwright driver log. Pass `pw:api` to get the Playwright API log.
+        /// It is a shortcut to the DEBUG=pw:api environment variable.
+        /// </param>
         /// <returns>A <see cref="Task"/> that completes when the playwright driver is ready to be used.</returns>
         public static async Task<IPlaywright> CreateAsync(
             ILoggerFactory loggerFactory = null,
             TransportTaskScheduler scheduler = null,
             string driversLocationPath = null,
             string driverExecutablePath = null,
-            string browsersPath = null)
+            string browsersPath = null,
+            string debug = null)
         {
+            if (!string.IsNullOrEmpty(debug))
+            {
+                Environment.SetEnvironmentVariable("DEBUG", debug);
+            }
+
             var connection = new Connection(loggerFactory, scheduler, driversLocationPath, driverExecutablePath, browsersPath);
 
             var playwright = await connection.WaitForObjectWithKnownName<Playwright>("Playwright").ConfigureAwait(false);

src/PlaywrightSharp/Transport/Connection.cs

@@ -50,6 +50,10 @@ public Connection(
                 Environment.SetEnvironmentVariable(BrowsersPathEnvironmentVariable, Path.GetFullPath(browsersPath));
             }
 
+            _loggerFactory = loggerFactory;
+            _logger = _loggerFactory?.CreateLogger<Connection>();
+            var debugLogger = _loggerFactory?.CreateLogger<Playwright>();
+
             _rootObject = new ChannelOwnerBase(null, this, string.Empty);
 
             _playwrightServerProcess = GetProcess(driversLocationPath, driverExecutablePath);
@@ -58,9 +62,8 @@ public Connection(
             _playwrightServerProcess.Exited += (sender, e) => Close("Process exited");
             _transport = new StdIOTransport(_playwrightServerProcess, scheduler);
             _transport.MessageReceived += Transport_MessageReceived;
+            _transport.LogReceived += (s, e) => debugLogger?.LogInformation(e.Message);
             _transport.TransportClosed += (sender, e) => Close(e.CloseReason);
-            _loggerFactory = loggerFactory;
-            _logger = _loggerFactory?.CreateLogger<Connection>();
         }
 
         /// <inheritdoc cref="IDisposable.Dispose"/>
@@ -88,6 +91,7 @@ internal static async Task InstallAsync(string driverPath = null, string browser
             process.StartInfo.Arguments = "--install";
             process.StartInfo.RedirectStandardOutput = false;
             process.StartInfo.RedirectStandardInput = false;
+            process.StartInfo.RedirectStandardError = false;
             process.EnableRaisingEvents = true;
             process.Exited += (sender, e) => tcs.TrySetResult(true);
             process.Start();
@@ -250,6 +254,7 @@ private static Process GetProcess(string driversLocationPath = null, string driv
                     UseShellExecute = false,
                     RedirectStandardOutput = true,
                     RedirectStandardInput = true,
+                    RedirectStandardError = true,
                     CreateNoWindow = true,
                 },
             };

src/PlaywrightSharp/Transport/IConnectionTransport.cs

@@ -13,6 +13,11 @@ public interface IConnectionTransport
         /// </summary>
         event EventHandler<MessageReceivedEventArgs> MessageReceived;
 
+        /// <summary>
+        /// Occurs when a log message is received.
+        /// </summary>
+        event EventHandler<LogReceivedEventArgs> LogReceived;
+
         /// <summary>
         /// Occurs when the transport is closed.
         /// </summary>

src/PlaywrightSharp/Transport/LogReceivedEventArgs.cs

@@ -0,0 +1,22 @@
+using System;
+
+namespace PlaywrightSharp.Transport
+{
+    /// <summary>
+    /// Log received event arguments.
+    /// <see cref="IConnectionTransport.LogReceived"/>.
+    /// </summary>
+    public class LogReceivedEventArgs : EventArgs
+    {
+        /// <summary>
+        /// Initializes a new instance of the <see cref="LogReceivedEventArgs"/> class.
+        /// </summary>
+        /// <param name="message">Message.</param>
+        public LogReceivedEventArgs(string message) => Message = message;
+
+        /// <summary>
+        /// Transport message.
+        /// </summary>
+        public string Message { get; }
+    }
+}

src/PlaywrightSharp/Transport/StdIOTransport.cs

@@ -18,6 +18,8 @@ internal StdIOTransport(Process process, TransportTaskScheduler scheduler = null
         {
             _process = process;
             scheduler ??= ScheduleTransportTask;
+            process.ErrorDataReceived += (s, e) => LogReceived?.Invoke(this, new LogReceivedEventArgs(e.Data));
+            process.BeginErrorReadLine();
 
             scheduler(GetResponseAsync, _readerCancellationSource.Token);
         }
@@ -29,6 +31,8 @@ internal StdIOTransport(Process process, TransportTaskScheduler scheduler = null
 
         public event EventHandler<TransportClosedEventArgs> TransportClosed;
 
+        public event EventHandler<LogReceivedEventArgs> LogReceived;
+
         public bool IsClosed { get; private set; }
 
         /// <inheritdoc/>