diff --git a/.editorconfig b/.editorconfig index d9f8964..11c56a5 100644 --- a/.editorconfig +++ b/.editorconfig @@ -1,4 +1,13 @@ -[*.cs] + +root = true + +[*] +indent_style = space +indent_size = 4 +insert_final_newline = true +end_of_line = crlf + +[*.cs] # IDE0055: Fix formatting dotnet_diagnostic.IDE0055.severity = none diff --git a/ChromiumHtmlToPdf.sln b/ChromiumHtmlToPdf.sln index 3dde25d..1d2f01e 100644 --- a/ChromiumHtmlToPdf.sln +++ b/ChromiumHtmlToPdf.sln @@ -7,6 +7,11 @@ Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "ChromiumHtmlToPdfLib", "Chr EndProject Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "ChromiumHtmlToPdfConsole", "ChromiumHtmlToPdfConsole\ChromiumHtmlToPdfConsole.csproj", "{0ECDC06A-D578-4F2C-A742-A5EFD5EA2C6F}" EndProject +Project("{2150E333-8FDC-42A3-9474-1A3956D46DE8}") = "Solution Items", "Solution Items", "{3B2D53A2-692C-4A5A-89D8-3ABC3F8EE848}" + ProjectSection(SolutionItems) = preProject + .editorconfig = .editorconfig + EndProjectSection +EndProject Global GlobalSection(SolutionConfigurationPlatforms) = preSolution Debug|Any CPU = Debug|Any CPU diff --git a/ChromiumHtmlToPdfLib/Browser.cs b/ChromiumHtmlToPdfLib/Browser.cs index bd6c426..995db0e 100644 --- a/ChromiumHtmlToPdfLib/Browser.cs +++ b/ChromiumHtmlToPdfLib/Browser.cs @@ -181,11 +181,13 @@ internal async Task NavigateToAsync( CancellationToken cancellationToken = default) { var navigationError = string.Empty; + var navigationErrorTemplate = string.Empty; + object?[] navigationErrorArgs = []; var absoluteUri = uri?.AbsoluteUri.Substring(0, uri.AbsoluteUri.LastIndexOf('/') + 1); if (uri?.RequestHeaders?.Count > 0) { - _logger?.WriteToLog("Setting request headers"); + _logger?.Info("Setting request headers"); var networkMessage = new Message { Method = "Network.setExtraHTTPHeaders" }; networkMessage.AddParameter("headers", uri.RequestHeaders); await _pageConnection.SendForResponseAsync(networkMessage, cancellationToken).ConfigureAwait(false); @@ -193,12 +195,12 @@ internal async Task NavigateToAsync( if (logNetworkTraffic) { - _logger?.WriteToLog("Enabling network traffic logging"); + _logger?.Info("Enabling network traffic logging"); var networkMessage = new Message { Method = "Network.enable" }; await _pageConnection.SendForResponseAsync(networkMessage, cancellationToken).ConfigureAwait(false); } - _logger?.WriteToLog(useCache ? "Enabling caching" : "Disabling caching"); + _logger?.Info(useCache ? "Enabling caching" : "Disabling caching"); var cacheMessage = new Message { Method = "Network.setCacheDisabled" }; cacheMessage.Parameters.Add("cacheDisabled", !useCache); @@ -207,17 +209,17 @@ internal async Task NavigateToAsync( // Enables issuing of requestPaused events. A request will be paused until client calls one of failRequest, fulfillRequest or continueRequest/continueWithAuth if (urlBlacklist?.Count > 0) { - _logger?.WriteToLog("Enabling Fetch to block url's that are in the url blacklist"); + _logger?.Info("Enabling Fetch to block url's that are in the url blacklist"); await _pageConnection.SendForResponseAsync(new Message { Method = "Fetch.enable" }, cancellationToken).ConfigureAwait(false); } // Enables page domain notifications - _logger?.WriteToLog("Enabling page domain notifications"); + _logger?.Info("Enabling page domain notifications"); await _pageConnection.SendForResponseAsync(new Message { Method = "Page.enable" }, cancellationToken).ConfigureAwait(false); var lifecycleEventEnabledMessage = new Message { Method = "Page.setLifecycleEventsEnabled" }; lifecycleEventEnabledMessage.AddParameter("enabled", true); - _logger?.WriteToLog("Enabling page lifecycle events"); + _logger?.Info("Enabling page lifecycle events"); await _pageConnection.SendForResponseAsync(lifecycleEventEnabledMessage, cancellationToken).ConfigureAwait(false); var waitForMessage = new SemaphoreSlim(1); @@ -240,17 +242,17 @@ internal async Task NavigateToAsync( // Navigates current page to the given URL var pageNavigateMessage = new Message { Method = "Page.navigate" }; pageNavigateMessage.AddParameter("url", uri.ToString()); - _logger?.WriteToLog($"Navigating to url '{uri}'"); + _logger?.Info("Navigating to url '{uri}'", uri); await _pageConnection.SendAsync(pageNavigateMessage).ConfigureAwait(false); } else if (!string.IsNullOrWhiteSpace(html)) { - _logger?.WriteToLog("Getting page frame tree"); + _logger?.Info("Getting page frame tree"); var pageGetFrameTree = new Message { Method = "Page.getFrameTree" }; var frameTree = await _pageConnection.SendForResponseAsync(pageGetFrameTree, cancellationToken).ConfigureAwait(false); var frameResult = FrameTree.FromJson(frameTree); - _logger?.WriteToLog("Setting document content"); + _logger?.Info("Setting document content"); var pageSetDocumentContent = new Message { Method = "Page.setDocumentContent" }; pageSetDocumentContent.AddParameter("frameId", frameResult.Result.FrameTree.Frame.Id); @@ -258,7 +260,7 @@ internal async Task NavigateToAsync( await _pageConnection.SendAsync(pageSetDocumentContent).ConfigureAwait(false); // When using setDocumentContent a Page.frameNavigated event is never fired, so we have to set the waitForNetworkIdle to true our self pageLoadingState = PageLoadingState.WaitForNetworkIdle; - _logger?.WriteToLog("Document content set"); + _logger?.Info("Document content set"); } else throw new ArgumentException("Uri and html are both null"); @@ -285,42 +287,68 @@ internal async Task NavigateToAsync( { case "Network.requestWillBeSent": var requestWillBeSent = RequestWillBeSent.FromJson(data); - _logger?.WriteToLog($"Request sent with request id {requestWillBeSent.Params.RequestId} for url '{requestWillBeSent.Params.Request.Url}' with method {requestWillBeSent.Params.Request.Method} and type {requestWillBeSent.Params.Type}"); + _logger?.Info("Request sent with request id {requestId} for url '{url}' with method {method} and type {type}", + requestWillBeSent.Params.RequestId, + requestWillBeSent.Params.Request.Url, + requestWillBeSent.Params.Request.Method, + requestWillBeSent.Params.Type); break; case "Network.dataReceived": var dataReceived = DataReceived.FromJson(data); - _logger?.WriteToLog($"Data received for request id {dataReceived.Params.RequestId} with a length of {FileManager.GetFileSizeString(dataReceived.Params.DataLength, CultureInfo.InvariantCulture)}"); + _logger?.Info("Data received for request id {requestId} with a length of {length}", + dataReceived.Params.RequestId, + FileManager.GetFileSizeString(dataReceived.Params.DataLength, CultureInfo.InvariantCulture)); break; case "Network.responseReceived": var responseReceived = ResponseReceived.FromJson(data); var response = responseReceived.Params.Response; - var logMessage = $"{(response.FromDiskCache ? "Cached response" : "Response")} received for request id {responseReceived.Params.RequestId} and url '{response.Url}'"; - - if (!string.IsNullOrWhiteSpace(response.RemoteIpAddress)) - logMessage += $" from ip {response.RemoteIpAddress} on port {response.RemotePort} with status {response.Status}{(!string.IsNullOrWhiteSpace(response.StatusText) ? $" and response text '{response.StatusText}'" : string.Empty)}"; + if (string.IsNullOrWhiteSpace(response.RemoteIpAddress)) + _logger?.Info((response.FromDiskCache ? "Cached response" : "Response") + " received for request id {requestId} and url '{url}'", + responseReceived.Params.RequestId, + response.Url); + else if (string.IsNullOrWhiteSpace(response.StatusText)) + _logger?.Info((response.FromDiskCache ? "Cached response" : "Response") + " received for request id {requestId} and url '{url}' from ip {ip} on port {port} with status {status}", + responseReceived.Params.RequestId, + response.Url, + response.RemoteIpAddress, + response.RemotePort, + response.Status); + else + _logger?.Info((response.FromDiskCache ? "Cached response" : "Response") + " received for request id {requestId} and url '{url}' from ip {ip} on port {port} with status {status} and response text '{statusText}'", + responseReceived.Params.RequestId, + response.Url, + response.RemoteIpAddress, + response.RemotePort, + response.Status, + response.StatusText); - _logger?.WriteToLog(logMessage); break; case "Network.loadingFinished": var loadingFinished = LoadingFinished.FromJson(data); - _logger?.WriteToLog($"Loading finished for request id {loadingFinished.Params.RequestId} " + - $"{(loadingFinished.Params.EncodedDataLength > 0 ? $"with an encoded data length of {FileManager.GetFileSizeString(loadingFinished.Params.EncodedDataLength, CultureInfo.InvariantCulture)}" : string.Empty)}"); + + if (loadingFinished.Params.EncodedDataLength > 0) + _logger?.Info("Loading finished for request id {requestId} with an encoded data length of {length}", + loadingFinished.Params.RequestId, + FileManager.GetFileSizeString(loadingFinished.Params.EncodedDataLength, CultureInfo.InvariantCulture)); + else + _logger?.Info("Loading finished for request id {requestId}", loadingFinished.Params.RequestId); break; case "Network.loadingFailed": var loadingFailed = LoadingFailed.FromJson(data); - _logger?.WriteToLog($"Loading failed for request id {loadingFailed.Params.RequestId} " + - $"and type {loadingFailed.Params.Type} " + - $"with error '{loadingFailed.Params.ErrorText}'"); + _logger?.Error("Loading failed for request id {requestId} and type {type} with error '{error}'", + loadingFailed.Params.RequestId, + loadingFailed.Params.Type, + loadingFailed.Params.ErrorText); break; case "Network.requestServedFromCache": var requestServedFromCache = RequestServedFromCache.FromJson(data); - _logger?.WriteToLog($"The request with id {requestServedFromCache.Params.RequestId} is served from cache"); + _logger?.Info("The request with id {requestId} is served from cache", requestServedFromCache.Params.RequestId); break; case "Fetch.requestPaused": @@ -337,11 +365,11 @@ internal async Task NavigateToAsync( isAbsoluteFileUri || isSafeUrl) { if (isSafeUrl) - _logger?.WriteToLog($"The url '{url}' has been allowed because it is on the safe url list"); + _logger?.Info("The url '{url}' has been allowed because it is on the safe url list", url); else if (isAbsoluteFileUri) - _logger?.WriteToLog($"The file url '{url}' has been allowed because it start with the absolute uri '{absoluteUri}'"); + _logger?.Info("The file url '{url}' has been allowed because it start with the absolute uri '{absoluteUri}'", url, absoluteUri); else - _logger?.WriteToLog($"The url '{url}' has been allowed because it did not match anything on the url blacklist"); + _logger?.Info("The url '{url}' has been allowed because it did not match anything on the url blacklist", url); var fetchContinue = new Message { Method = "Fetch.continueRequest" }; fetchContinue.Parameters.Add("requestId", requestId); @@ -349,7 +377,7 @@ internal async Task NavigateToAsync( } else { - _logger?.WriteToLog($"The url '{url}' has been blocked by url blacklist pattern '{matchedPattern}'"); + _logger?.Warn("The url '{url}' has been blocked by url blacklist pattern '{matchedPattern}'", url, matchedPattern); var fetchFail = new Message { Method = "Fetch.failRequest" }; fetchFail.Parameters.Add("requestId", requestId); @@ -367,7 +395,7 @@ internal async Task NavigateToAsync( case "Page.loadEventFired": if (!waitForNetworkIdle) { - _logger?.WriteToLog("The 'Page.loadEventFired' event has been fired, the page is now fully loaded"); + _logger?.Info("The 'Page.loadEventFired' event has been fired, the page is now fully loaded"); pageLoadingState = PageLoadingState.Done; } @@ -384,23 +412,23 @@ internal async Task NavigateToAsync( // detect a fully-loaded page). case "Page.lifecycleEvent" when page.Params?.Name == "DOMContentLoaded": - _logger?.WriteToLog("The 'Page.lifecycleEvent' with param name 'DomContentLoaded' has been fired, the dom content is now loaded and parsed, waiting for stylesheets, images and sub frames to finish loading"); + _logger?.Info("The '{method}' with param name '{paramName}' has been fired, the dom content is now loaded and parsed, waiting for stylesheets, images and sub frames to finish loading", page.Method, page.Params?.Name); if (mediaLoadTimeout.HasValue && !mediaLoadTimeoutStopwatch.IsRunning) { - _logger?.WriteToLog($"Media load timeout has a value of {mediaLoadTimeout.Value} milliseconds, starting stopwatch"); + _logger?.Info("Media load timeout has a value of {timeout} milliseconds, starting stopwatch", mediaLoadTimeout.Value); mediaLoadTimeoutStopwatch.Start(); } break; case "Page.frameNavigated": - _logger?.WriteToLog("The 'Page.frameNavigated' event has been fired, waiting for the 'Page.lifecycleEvent' with name 'networkIdle'"); + _logger?.Info("The '{method}' event has been fired, waiting for the 'Page.lifecycleEvent' with name 'networkIdle'", page.Method); pageLoadingState = PageLoadingState.WaitForNetworkIdle; break; case "Page.lifecycleEvent" when page.Params?.Name == "networkIdle" && pageLoadingState == PageLoadingState.WaitForNetworkIdle: - _logger?.WriteToLog("The 'Page.lifecycleEvent' event with name 'networkIdle' has been fired, the page is now fully loaded and the network is idle"); + _logger?.Info("The '{method}' event with name '{eventName}' has been fired, the page is now fully loaded and the network is idle", page.Method, page.Params?.Name); pageLoadingState = PageLoadingState.Done; break; @@ -410,6 +438,8 @@ internal async Task NavigateToAsync( !pageNavigateResponse.Result!.ErrorText!.Contains("net::ERR_BLOCKED_BY_CLIENT")) { navigationError = $"{pageNavigateResponse.Result.ErrorText} occurred when navigating to the page '{uri}'"; + navigationErrorTemplate = "{error} occurred when navigating to the page '{uri}'"; + navigationErrorArgs = [pageNavigateResponse.Result.ErrorText, uri]; pageLoadingState = PageLoadingState.BlockedByClient; } @@ -423,7 +453,7 @@ internal async Task NavigateToAsync( if (mediaLoadTimeoutStopwatch.IsRunning && mediaLoadTimeoutStopwatch.ElapsedMilliseconds >= mediaLoadTimeout!.Value) { - _logger?.WriteToLog($"Media load timeout of {mediaLoadTimeout.Value} milliseconds reached, stopped loading page"); + _logger?.Warn("Media load timeout of {timeout} milliseconds reached, stopped loading page", mediaLoadTimeout.Value); mediaLoadTimeoutStopwatch.Stop(); pageLoadingState = PageLoadingState.MediaLoadTimeout; } @@ -434,7 +464,7 @@ internal async Task NavigateToAsync( if (pageLoadingState == PageLoadingState.MediaLoadTimeout) { - _logger?.WriteToLog("Stopping loading the rest of the page with injecting javascript 'window.stop()'"); + _logger?.Warn("Stopping loading the rest of the page with injecting javascript 'window.stop()'"); await RunJavascriptAsync("window.stop();", cancellationToken).ConfigureAwait(false); } @@ -450,20 +480,20 @@ internal async Task NavigateToAsync( // Disables the fetch domain if (urlBlacklist?.Count > 0) { - _logger?.WriteToLog("Disabling Fetch"); + _logger?.Info("Disabling Fetch"); await _pageConnection.SendForResponseAsync(new Message { Method = "Fetch.disable" }, cancellationToken).ConfigureAwait(false); } if (logNetworkTraffic) { - _logger?.WriteToLog("Disabling network traffic logging"); + _logger?.Info("Disabling network traffic logging"); var networkMessage = new Message { Method = "Network.disable" }; await _pageConnection.SendForResponseAsync(networkMessage, cancellationToken).ConfigureAwait(false); } if (!string.IsNullOrEmpty(navigationError)) { - _logger?.WriteToLog(navigationError); + _logger?.Error(navigationErrorTemplate, navigationErrorArgs); throw new ChromiumNavigationException(navigationError); } } @@ -578,9 +608,10 @@ public async Task RunJavascriptAsync(string script, CancellationToken cancellati var evaluate = Evaluate.FromJson(result); var internalResult = evaluate.Result?.Result?.ToString(); - _logger?.WriteToLog(!string.IsNullOrEmpty(internalResult) - ? $"Javascript result:{Environment.NewLine}{internalResult}" - : "Javascript did not return any result"); + if (!string.IsNullOrEmpty(internalResult)) + _logger?.Info($"Javascript result:{Environment.NewLine}{{result}}", internalResult); + else + _logger?.Info("Javascript did not return any result"); } #endregion @@ -670,13 +701,13 @@ internal async Task PrintToPdfAsync(Stream outputStream, if (!outputStream.CanWrite) throw new ConversionException("The output stream is not writable, please provide a writable stream"); - _logger?.WriteToLog("Resetting output stream to position 0"); + _logger?.Info("Resetting output stream to position 0"); message = new Message { Method = "IO.read" }; message.AddParameter("handle", printToPdfResponse.Result.Stream!); message.AddParameter("size", 1048576); // Get the pdf in chunks of 1MB - _logger?.WriteToLog($"Reading generated PDF from IO stream with handle id {printToPdfResponse.Result.Stream}"); + _logger?.Info("Reading generated PDF from IO stream with handle id {stream}", printToPdfResponse.Result.Stream); outputStream.Position = 0; while (true) @@ -691,18 +722,18 @@ internal async Task PrintToPdfAsync(Stream outputStream, if (length > 0) { - _logger?.WriteToLog($"PDF chunk received with id {ioReadResponse.Id} and length {FileManager.GetFileSizeString(length, CultureInfo.InvariantCulture)}, writing it to output stream"); + _logger?.Info("PDF chunk received with id {id} and length {length}, writing it to output stream", ioReadResponse.Id, FileManager.GetFileSizeString(length, CultureInfo.InvariantCulture)); await outputStream.WriteAsync(bytes, 0, length, cancellationToken).ConfigureAwait(false); } if (!ioReadResponse.Result.Eof) continue; - _logger?.WriteToLog("Last chunk received"); - _logger?.WriteToLog($"Closing stream with id {printToPdfResponse.Result.Stream}"); + _logger?.Info("Last chunk received"); + _logger?.Info("Closing stream with id {stream}", printToPdfResponse.Result.Stream); message = new Message { Method = "IO.close" }; message.AddParameter("handle", printToPdfResponse.Result.Stream!); await _pageConnection.SendForResponseAsync(message, cancellationToken).ConfigureAwait(false); - _logger?.WriteToLog("Stream closed"); + _logger?.Info("Stream closed"); break; } } @@ -786,4 +817,4 @@ public async ValueTask DisposeAsync() } #endif #endregion -} \ No newline at end of file +} diff --git a/ChromiumHtmlToPdfLib/Connection.cs b/ChromiumHtmlToPdfLib/Connection.cs index d23e2ec..5492f7d 100644 --- a/ChromiumHtmlToPdfLib/Connection.cs +++ b/ChromiumHtmlToPdfLib/Connection.cs @@ -110,7 +110,7 @@ internal Connection(string url, int timeout, Logger? logger) _url = url; _timeout = timeout; _logger = logger; - _logger?.WriteToLog($"Creating new websocket connection to url '{url}'"); + _logger?.Info("Creating new websocket connection to url '{url}'", url); _webSocket = new ClientWebSocket(); _receiveLoopCts = new CancellationTokenSource(); OpenWebSocketAsync().GetAwaiter().GetResult(); @@ -156,6 +156,10 @@ private static async Task ReceiveLoop(object? stateData) { // Ignore } + catch (OperationCanceledException) + { + // Ignore + } catch (Exception exception) { WebSocketOnError(state.Logger, new ErrorEventArgs(exception)); @@ -177,12 +181,12 @@ private async Task OpenWebSocketAsync() { if (_webSocket.State is WebSocketState.Open or WebSocketState.Connecting) return; - _logger?.WriteToLog($"Opening websocket connection with a timeout of {_timeout} milliseconds"); + _logger?.Info("Opening websocket connection with a timeout of {timeout} milliseconds", _timeout); try { await _webSocket.ConnectAsync(new Uri(_url), new CancellationTokenSource(_timeout).Token).ConfigureAwait(false); - _logger?.WriteToLog("Websocket opened"); + _logger?.Info("Websocket opened"); } catch (Exception exception) { @@ -199,7 +203,7 @@ private static void WebSocketOnMessageReceived(Logger? logger, Action on var error = CheckForError(response); if (!string.IsNullOrEmpty(error)) - logger?.WriteToLog(error!); + logger?.Error("{error}", error); onMessageReceived(response); } @@ -211,7 +215,7 @@ private void OnMessageReceived(string response) private static void WebSocketOnError(Logger? logger, ErrorEventArgs e) { - logger?.WriteToLog(ExceptionHelpers.GetInnerException(e.Exception)); + logger?.Error(e.Exception, "{exception}", ExceptionHelpers.GetInnerException(e.Exception)); } private void WebSocketOnClosed(EventArgs e) @@ -329,11 +333,11 @@ public async Task InternalDisposeAsync() _receiveLoopCts.Cancel(); - _logger?.WriteToLog($"Disposing websocket connection to url '{_url}'"); + _logger?.Info("Disposing websocket connection to url '{url}'", _url); if (_webSocket.State == WebSocketState.Open) { - _logger?.WriteToLog("Closing web socket"); + _logger?.Info("Closing web socket"); try { @@ -342,14 +346,14 @@ public async Task InternalDisposeAsync() } catch (Exception exception) { - _logger?.WriteToLog($"An error occurred while closing the web socket, error: '{ExceptionHelpers.GetInnerException(exception)}'"); + _logger?.Error("An error occurred while closing the web socket, error: '{error}'", ExceptionHelpers.GetInnerException(exception)); } - _logger?.WriteToLog("Websocket connection closed"); + _logger?.Info("Websocket connection closed"); WebSocketOnClosed(EventArgs.Empty); _webSocket.Dispose(); - _logger?.WriteToLog("Web socket connection disposed"); + _logger?.Info("Web socket connection disposed"); } _disposed = true; @@ -378,4 +382,4 @@ public async ValueTask DisposeAsync() } #endif #endregion -} \ No newline at end of file +} diff --git a/ChromiumHtmlToPdfLib/Converter.cs b/ChromiumHtmlToPdfLib/Converter.cs index 8dff5ee..0bf9031 100644 --- a/ChromiumHtmlToPdfLib/Converter.cs +++ b/ChromiumHtmlToPdfLib/Converter.cs @@ -288,7 +288,7 @@ public List PreWrapExtensions set { _preWrapExtensions = value; - _logger?.WriteToLog($"Setting pre wrap extension to '{string.Join(", ", value)}'"); + _logger?.Info("Setting pre wrap extension to '{extensions}'", value); } } @@ -433,14 +433,18 @@ private WebProxy? WebProxy if (networkCredential != null) { - _logger?.WriteToLog( - $"Setting up web proxy with server '{_proxyServer}' and user '{_userName}'{(!string.IsNullOrEmpty(networkCredential.Domain) ? $" on domain '{networkCredential.Domain}'" : string.Empty)}"); + if (!string.IsNullOrEmpty(networkCredential.Domain)) + _logger?.Info( + "Setting up web proxy with server '{proxyServer}' and user '{userName}' on domain '{domain}'", _proxyServer, _userName, networkCredential.Domain); + else + _logger?.Info( + "Setting up web proxy with server '{proxyServer}' and user '{userName}'", _proxyServer, _userName); _webProxy = new WebProxy(_proxyServer, true, bypassList, networkCredential); } else { _webProxy = new WebProxy(_proxyServer, true, bypassList) { UseDefaultCredentials = true }; - _logger?.WriteToLog($"Setting up web proxy with server '{_proxyServer}' with default credentials"); + _logger?.Info("Setting up web proxy with server '{proxyServer}' with default credentials", _proxyServer); } return _webProxy; @@ -623,14 +627,14 @@ private async Task StartChromiumHeadlessAsync(CancellationToken cancellationToke { if (IsChromiumRunning) { - _logger?.WriteToLog($"{BrowserName} is already running on process id {_chromiumProcess.Id} ... skipped"); + _logger?.Info("{browser} is already running on process id {processId} ... skipped", BrowserName, _chromiumProcess.Id); return; } var workingDirectory = Path.GetDirectoryName(_chromiumExeFileName); - _logger?.WriteToLog($"Starting {BrowserName} from location '{_chromiumExeFileName}' with working directory '{workingDirectory}'"); - _logger?.WriteToLog($"\"{_chromiumExeFileName}\" {string.Join(" ", DefaultChromiumArguments)}"); + _logger?.Info("Starting {browser} from location '{exePath}' with working directory '{workingDirectory}'", BrowserName, _chromiumExeFileName, workingDirectory); + _logger?.Info("\"{exePath}\" {arguments}", _chromiumExeFileName, string.Join(" ", DefaultChromiumArguments)); _chromiumProcess = new Process(); var processStartInfo = new ProcessStartInfo @@ -657,15 +661,15 @@ private async Task StartChromiumHeadlessAsync(CancellationToken cancellationToke if (!string.IsNullOrWhiteSpace(domain) && RuntimeInformation.IsOSPlatform(OSPlatform.Windows)) { - _logger?.WriteToLog($"Starting {BrowserName} with username '{userName}' on domain '{domain}'"); + _logger?.Info("Starting {browser} with username '{userName}' on domain '{domain}'", BrowserName, userName, domain); processStartInfo.Domain = domain; } else { if (!string.IsNullOrWhiteSpace(domain) && !RuntimeInformation.IsOSPlatform(OSPlatform.Windows)) - _logger?.WriteToLog($"Ignoring domain '{domain}' because this is only supported on Windows"); + _logger?.Warn("Ignoring domain '{domain}' because this is only supported on Windows", domain); - _logger?.WriteToLog($"Starting {BrowserName} with username '{userName}'"); + _logger?.Info("Starting {browser} with username '{userName}'", BrowserName, userName); } processStartInfo.UseShellExecute = false; @@ -685,7 +689,7 @@ private async Task StartChromiumHeadlessAsync(CancellationToken cancellationToke processStartInfo.LoadUserProfile = true; } else - _logger?.WriteToLog("Ignoring password and loading user profile because this is only supported on Windows"); + _logger?.Warn("Ignoring password and loading user profile because this is only supported on Windows"); } using var chromiumWaitSignal = new SemaphoreSlim(0, 1); @@ -711,11 +715,11 @@ private async Task StartChromiumHeadlessAsync(CancellationToken cancellationToke } catch (Exception exception) { - _logger?.WriteToLog($"Could not start the {BrowserName} process due to the following reason: {ExceptionHelpers.GetInnerException(exception)}"); + _logger?.Error(exception, "Could not start the {browser} process due to the following reason: {exception}", BrowserName, ExceptionHelpers.GetInnerException(exception)); throw; } - _logger?.WriteToLog($"{BrowserName} process started"); + _logger?.Info("{browser} process started", BrowserName); if (!_userProfileSet) _chromiumProcess.BeginErrorReadLine(); @@ -748,7 +752,7 @@ private async Task StartChromiumHeadlessAsync(CancellationToken cancellationToke if (!string.IsNullOrEmpty(chromeException)) throw new ChromiumException(chromeException!); - _logger?.WriteToLog($"{BrowserName} started"); + _logger?.Info("{browser} started", BrowserName); return; #region Method internal events @@ -757,9 +761,11 @@ void OnChromiumProcessOnExited(object? o, EventArgs eventArgs) try { if (_chromiumProcess == null) return; - _logger?.WriteToLog($"{BrowserName} exited unexpectedly, arguments used: {string.Join(" ", DefaultChromiumArguments)}"); - _logger?.WriteToLog($"Process id: {_chromiumProcess.Id}"); - _logger?.WriteToLog($"Process exit time: {_chromiumProcess.ExitTime:yyyy-MM-ddTHH:mm:ss.fff}"); + + _logger?.Warn(@"{browser} exited unexpectedly, arguments used: {arguments} +Process id: {processId} +Process exit time: {exitTime}", BrowserName, string.Join(" ", DefaultChromiumArguments), _chromiumProcess.Id, _chromiumProcess.ExitTime); + var exception = ExceptionHelpers.GetInnerException(Marshal.GetExceptionForHR(_chromiumProcess.ExitCode)); chromeException = $"{BrowserName} exited unexpectedly{(!string.IsNullOrWhiteSpace(exception) ? ", {exception}" : string.Empty)}"; _cancellationTokenSource?.Cancel(); @@ -775,7 +781,7 @@ void OnChromiumProcessOnErrorDataReceived(object _, DataReceivedEventArgs args) { if (string.IsNullOrEmpty(args.Data) || args.Data.StartsWith("[")) return; - _logger?.WriteToLog($"Received Chromium error data: '{args.Data}'"); + _logger?.Error("Received Chromium error data: '{error}'", args.Data); if (!args.Data.StartsWith("DevTools listening on")) return; var uri = new Uri(args.Data.Replace("DevTools listening on ", string.Empty)); @@ -799,7 +805,7 @@ private async Task ReadDevToolsActiveFileAsync(CancellationToken cance var tempTimeout = _conversionTimeout ?? 10000; var timeout = tempTimeout; - _logger?.WriteToLog($"Waiting until file '{_devToolsActivePortFile}' exists with a timeout of {tempTimeout} milliseconds"); + _logger?.Info("Waiting until file '{lockFile}' exists with a timeout of {timeout} milliseconds", _devToolsActivePortFile, tempTimeout); while (true) { @@ -840,9 +846,9 @@ private async Task ReadDevToolsActiveFileAsync(CancellationToken cance /// From where we did get the uri private void ConnectToDevProtocol(Uri uri, string readUriFrom) { - _logger?.WriteToLog($"Connecting to dev protocol on uri '{uri}', got uri from {readUriFrom}"); + _logger?.Info("Connecting to dev protocol on uri '{uri}', got uri from {readUriFrom}", uri, readUriFrom); _browser = new Browser(uri, WebSocketTimeout, _logger); - _logger?.WriteToLog("Connected to dev protocol"); + _logger?.Info("Connected to dev protocol"); } #endregion @@ -868,7 +874,7 @@ private static void CheckIfOutputFolderExists(string outputFile) [MemberNotNull(nameof(_defaultChromiumArgument))] public void ResetChromiumArguments() { - _logger?.WriteToLog("Resetting Chromium arguments to default"); + _logger?.Info("Resetting Chromium arguments to default"); _defaultChromiumArgument = new List(); @@ -895,7 +901,7 @@ public void ResetChromiumArguments() if (RuntimeInformation.IsOSPlatform(OSPlatform.Linux)) { - _logger?.WriteToLog("Detected Linux operating system, adding the parameter '--no-sandbox'"); + _logger?.Info("Detected Linux operating system, adding the parameter '--no-sandbox'"); AddChromiumArgument("--no-sandbox"); } @@ -929,7 +935,7 @@ public void RemoveChromiumArgument(string argument) if (!_defaultChromiumArgument.Contains(argument)) return; _defaultChromiumArgument.Remove(argument); - _logger?.WriteToLog($"Removed Chromium argument '{argument}'"); + _logger?.Info("Removed Chromium argument '{argument}'", argument); } #endregion @@ -954,11 +960,11 @@ public void AddChromiumArgument(string argument) if (!_defaultChromiumArgument.Contains(argument, StringComparison.CurrentCultureIgnoreCase)) { - _logger?.WriteToLog($"Adding Chromium argument '{argument}'"); + _logger?.Info("Adding Chromium argument '{argument}'", argument); _defaultChromiumArgument.Add(argument); } else - _logger?.WriteToLog($"The Chromium argument '{argument}' has already been set, ignoring it"); + _logger?.Info("The Chromium argument '{argument}' has already been set, ignoring it", argument); } /// @@ -985,12 +991,12 @@ public void AddChromiumArgument(string argument, string value) { if (!_defaultChromiumArgument[i].StartsWith(argument + "=")) continue; - _logger?.WriteToLog($"Updating Chromium argument '{_defaultChromiumArgument[i]}' with value '{value}'"); + _logger?.Info("Updating Chromium argument '{argument}' with value '{value}'", _defaultChromiumArgument[i], value); _defaultChromiumArgument[i] = $"{argument}=\"{value}\""; return; } - _logger?.WriteToLog($"Adding Chromium argument '{argument}=\"{value}\"'"); + _logger?.Info("Adding Chromium argument '{argument}=\"{value}\"'", argument, value); _defaultChromiumArgument.Add($"{argument}=\"{value}\""); } #endregion @@ -1337,7 +1343,7 @@ private async Task ConvertAsync( case ".url": if (GetUrlFromFile(inputUri.AbsolutePath, out var url)) { - _logger?.WriteToLog($"Read url '{url}' from URL file '{inputUri.AbsolutePath}'"); + _logger?.Info("Read url '{url}' from URL file '{path}'", url, inputUri.AbsolutePath); inputUri = new ConvertUri(url); } @@ -1359,7 +1365,7 @@ private async Task ConvertAsync( if (inputUri.IsFile && CheckForPreWrap(inputUri, out var preWrapFile)) { inputUri = new ConvertUri(preWrapFile); - _logger?.WriteToLog($"Adding url '{inputUri}' to the safe url list"); + _logger?.Info("Adding url '{url}' to the safe url list", inputUri); safeUrls.Add(inputUri.ToString()); } @@ -1372,24 +1378,24 @@ private async Task ConvertAsync( var result = await documentHelper.SanitizeHtmlAsync(inputUri, Sanitizer, safeUrls, cancellationToken).ConfigureAwait(false); if (result.Success) { - _logger?.WriteToLog($"Sanitization was successful changing input uri '{inputUri}' to '{result.OutputUri}'"); + _logger?.Info("Sanitization was successful changing input uri '{inputUri}' to '{outputUri}'", inputUri, result.OutputUri); inputUri = result.OutputUri; safeUrls = result.SafeUrls; } else { - _logger?.WriteToLog($"Adding url '{inputUri}' to the safe url list"); + _logger?.Info("Adding url '{url}' to the safe url list", inputUri); safeUrls.Add(inputUri.ToString()); } } if (pageSettings.PaperFormat == PaperFormat.FitPageToContent) { - _logger?.WriteToLog("The paper format 'FitPageToContent' is set, modifying html so that the PDF fits the HTML content"); + _logger?.Info("The paper format 'FitPageToContent' is set, modifying html so that the PDF fits the HTML content"); var result = await documentHelper.FitPageToContentAsync(inputUri, cancellationToken).ConfigureAwait(false); if (result.Success) { - _logger?.WriteToLog($"Fitting the page to the content was successful changing input uri '{inputUri}' to '{result.OutputUri}'"); + _logger?.Info("Fitting the page to the content was successful changing input uri '{inputUri}' to '{outputUri}'", inputUri, result.OutputUri); inputUri = result.OutputUri; safeUrls.Add(input.ToString()!); } @@ -1410,7 +1416,7 @@ private async Task ConvertAsync( if (result.Success) { - _logger?.WriteToLog($"Image validation was successful changing input uri '{inputUri}' to '{result.OutputUri}'"); + _logger?.Info("Image validation was successful changing input uri '{inputUri}' to '{outputUri}'", inputUri, result.OutputUri); inputUri = result.OutputUri; safeUrls.Add(inputUri.ToString()); } @@ -1427,14 +1433,17 @@ private async Task ConvertAsync( if (conversionTimeout <= 1) throw new ArgumentOutOfRangeException($"The value for {nameof(countdownTimer)} has to be a value equal to 1 or greater"); - _logger?.WriteToLog($"Conversion timeout set to {conversionTimeout.Value} milliseconds"); + _logger?.Info("Conversion timeout set to {timeout} milliseconds", conversionTimeout.Value); countdownTimer = new CountdownTimer(conversionTimeout.Value); countdownTimer.Start(); } if (inputUri != null) - _logger?.WriteToLog($"Loading {(inputUri.IsFile ? $"file {inputUri.OriginalString}" : $"url {inputUri}")}"); + if (inputUri.IsFile) + _logger?.Info("Loading file {path}", inputUri.OriginalString); + else + _logger?.Info("Loading url {url}", inputUri); await _browser!.NavigateToAsync(safeUrls, _useCache, inputUri, html, countdownTimer, mediaLoadTimeout, _urlBlacklist, LogNetworkTraffic, WaitForNetworkIdle, cancellationToken).ConfigureAwait(false); @@ -1442,30 +1451,33 @@ private async Task ConvertAsync( { if (conversionTimeout.HasValue) { - _logger?.WriteToLog("Conversion timeout paused because we are waiting for a window.status"); + _logger?.Info("Conversion timeout paused because we are waiting for a window.status"); countdownTimer!.Stop(); } - _logger?.WriteToLog($"Waiting for window.status '{waitForWindowStatus}' or a timeout of {waitForWindowsStatusTimeout} milliseconds"); + _logger?.Info("Waiting for window.status '{status}' or a timeout of {timeout} milliseconds", waitForWindowStatus, waitForWindowsStatusTimeout); var match = await _browser.WaitForWindowStatusAsync(waitForWindowStatus!, waitForWindowsStatusTimeout, cancellationToken).ConfigureAwait(false); - _logger?.WriteToLog(!match ? "Waiting timed out" : $"Window status equaled {waitForWindowStatus}"); + if (!match) + _logger?.Info("Waiting timed out"); + else + _logger?.Info("Window status equaled {status}", waitForWindowStatus); if (conversionTimeout.HasValue) { - _logger?.WriteToLog("Conversion timeout started again because we are done waiting for a window.status"); + _logger?.Info("Conversion timeout started again because we are done waiting for a window.status"); countdownTimer!.Start(); } } if (inputUri != null) - _logger?.WriteToLog($"{(inputUri.IsFile ? "File" : "Url")} loaded"); + _logger?.Info($"{(inputUri.IsFile ? "File" : "Url")} loaded"); if (!string.IsNullOrWhiteSpace(RunJavascript)) { - _logger?.WriteToLog("Start running javascript"); - _logger?.WriteToLog($"Javascript code:{Environment.NewLine}{RunJavascript}"); + _logger?.Info("Start running javascript"); + _logger?.Info($"Javascript code:{Environment.NewLine}{{code}}", RunJavascript); await _browser.RunJavascriptAsync(RunJavascript!, cancellationToken).ConfigureAwait(false); - _logger?.WriteToLog("Done running javascript"); + _logger?.Info("Done running javascript"); } if (CaptureSnapshot) @@ -1473,7 +1485,7 @@ private async Task ConvertAsync( if (SnapshotStream == null) throw new ConversionException("The property CaptureSnapshot has been set to true but there is no stream assigned to the SnapshotStream"); - _logger?.WriteToLog("Taking snapshot of the page"); + _logger?.Info("Taking snapshot of the page"); var snapshot = await _browser.CaptureSnapshotAsync(countdownTimer, cancellationToken).ConfigureAwait(false); using var memoryStream = new MemoryStream(snapshot.Bytes); @@ -1485,20 +1497,20 @@ private async Task ConvertAsync( await memoryStream.CopyToAsync(SnapshotStream, cancellationToken).ConfigureAwait(false); #endif - _logger?.WriteToLog("Taken"); + _logger?.Info("Taken"); } switch (outputFormat) { case OutputFormat.Pdf: - _logger?.WriteToLog("Converting to PDF"); + _logger?.Info("Converting to PDF"); await _browser.PrintToPdfAsync(outputStream, pageSettings, countdownTimer, cancellationToken).ConfigureAwait(false); break; case OutputFormat.Image: { - _logger?.WriteToLog("Converting to image"); + _logger?.Info("Converting to image"); var snapshot = await _browser.CaptureScreenshotAsync(countdownTimer, cancellationToken).ConfigureAwait(false); using var memoryStream = new MemoryStream(snapshot.Bytes); @@ -1514,11 +1526,11 @@ private async Task ConvertAsync( } } - _logger?.WriteToLog("Converted"); + _logger?.Info("Converted"); } catch (Exception exception) { - _logger?.WriteToLog($"Error: {ExceptionHelpers.GetInnerException(exception)}'"); + _logger?.Error(exception, "Error: {exception}'", ExceptionHelpers.GetInnerException(exception)); if (exception.Message != "Input string was not in a correct format.") throw; @@ -1530,14 +1542,14 @@ private async Task ConvertAsync( CurrentTempDirectory.Refresh(); if (CurrentTempDirectory.Exists && !DoNotDeleteTempDirectory) { - _logger?.WriteToLog($"Deleting temporary folder '{CurrentTempDirectory.FullName}'"); + _logger?.Info("Deleting temporary folder '{folder}'", CurrentTempDirectory.FullName); try { CurrentTempDirectory.Delete(true); } catch (Exception e) { - _logger?.WriteToLog($"Error '{ExceptionHelpers.GetInnerException(e)}'"); + _logger?.Error(e, "Error '{exception}'", ExceptionHelpers.GetInnerException(e)); } } } @@ -1564,7 +1576,7 @@ private void WriteSnapShot(string outputFile) SnapshotStream.CopyTo(fileStream); } - _logger?.WriteToLog($"Page snapshot written to output file '{snapShotOutputFile}'"); + _logger?.Info("Page snapshot written to output file '{path}'", snapShotOutputFile); } #endregion @@ -1922,7 +1934,7 @@ await ConvertToPdfAsync(inputUri, memoryStream, pageSettings, waitForWindowStatu await memoryStream.CopyToAsync(fileStream, cancellationToken).ConfigureAwait(false); #endif - _logger?.WriteToLog($"PDF written to output file '{outputFile}'"); + _logger?.Info("PDF written to output file '{path}'", outputFile); if (CaptureSnapshot) WriteSnapShot(outputFile); @@ -2061,7 +2073,7 @@ await ConvertToPdfAsync(html, memoryStream, pageSettings, waitForWindowStatus, await memoryStream.CopyToAsync(fileStream, cancellationToken).ConfigureAwait(false); #endif - _logger?.WriteToLog($"PDF written to output file '{outputFile}'"); + _logger?.Info("PDF written to output file '{path}'", outputFile); } if (CaptureSnapshot) @@ -2489,7 +2501,7 @@ await ConvertToImageAsync(inputUri, memoryStream, pageSettings, waitForWindowSta await using var fileStream = File.Open(outputFile, FileMode.Create); await memoryStream.CopyToAsync(fileStream, cancellationToken).ConfigureAwait(false); #endif - _logger?.WriteToLog($"Image written to output file '{outputFile}'"); + _logger?.Info("Image written to output file '{path}'", outputFile); if (CaptureSnapshot) WriteSnapShot(outputFile); @@ -2566,7 +2578,7 @@ await ConvertToImageAsync(html, memoryStream, pageSettings, waitForWindowStatus, await memoryStream.CopyToAsync(fileStream, cancellationToken).ConfigureAwait(false); #endif - _logger?.WriteToLog($"Image written to output file '{outputFile}'"); + _logger?.Info("Image written to output file '{path}'", outputFile); if (CaptureSnapshot) WriteSnapShot(outputFile); @@ -2616,7 +2628,7 @@ private void KillProcessAndChildren(int processId) catch (Exception exception) { if (!exception.Message.Contains("is not running")) - _logger?.WriteToLog(exception.Message); + _logger?.Error(exception, "{error}", exception.Message); } } #endregion @@ -2634,7 +2646,7 @@ private async Task InternalDisposeAsync() if (_browser != null) try { - _logger?.WriteToLog($"Closing {BrowserName} browser gracefully"); + _logger?.Info("Closing {browser} browser gracefully", BrowserName); #if (NETSTANDARD2_0) _browser.Dispose(); #else @@ -2644,7 +2656,7 @@ private async Task InternalDisposeAsync() } catch (Exception exception) { - _logger?.WriteToLog($"An error occurred while trying to close {BrowserName} gracefully, error '{ExceptionHelpers.GetInnerException(exception)}'"); + _logger?.Error(exception, "An error occurred while trying to close {browser} gracefully, error '{exception}'", BrowserName, ExceptionHelpers.GetInnerException(exception)); } var counter = 0; @@ -2654,7 +2666,7 @@ private async Task InternalDisposeAsync() { if (!IsChromiumRunning) { - _logger?.WriteToLog($"{BrowserName} closed gracefully"); + _logger?.Info("{browser} closed gracefully", BrowserName); break; } @@ -2665,9 +2677,9 @@ private async Task InternalDisposeAsync() if (IsChromiumRunning) { // Sometimes Chrome does not close all processes so kill them - _logger?.WriteToLog($"{BrowserName} did not close gracefully, closing it by killing it's process on id '{_chromiumProcess.Id}'"); + _logger?.Warn("{browser} did not close gracefully, closing it by killing it's process on id '{processId}'", BrowserName, _chromiumProcess.Id); KillProcessAndChildren(_chromiumProcess.Id); - _logger?.WriteToLog($"{BrowserName} killed"); + _logger?.Warn("{browser} killed", BrowserName); _chromiumProcess = null; } @@ -2701,4 +2713,4 @@ public async ValueTask DisposeAsync() } #endregion #endif -} \ No newline at end of file +} diff --git a/ChromiumHtmlToPdfLib/Helpers/DocumentHelper.cs b/ChromiumHtmlToPdfLib/Helpers/DocumentHelper.cs index 4a92d5c..46536bd 100644 --- a/ChromiumHtmlToPdfLib/Helpers/DocumentHelper.cs +++ b/ChromiumHtmlToPdfLib/Helpers/DocumentHelper.cs @@ -44,6 +44,7 @@ using AngleSharp.Html.Dom; using AngleSharp.Io.Network; using ChromiumHtmlToPdfLib.Loggers; +using ChromiumHtmlToPdfLib.Protocol; using ChromiumHtmlToPdfLib.Settings; using Ganss.Xss; using Svg; @@ -180,11 +181,11 @@ public DocumentHelper( _logger = logger; if (useCache) - _logger?.WriteToLog($"Setting cache directory to '{cacheDirectory.FullName}' with a size of {FileManager.GetFileSizeString(cacheSize, CultureInfo.InvariantCulture)}"); + _logger?.Info("Setting cache directory to '{path}' with a size of {size}", cacheDirectory.FullName, FileManager.GetFileSizeString(cacheSize, CultureInfo.InvariantCulture)); if (!imageLoadTimeout.HasValue) return; _imageLoadTimeout = imageLoadTimeout.Value; - _logger?.WriteToLog($"Setting image load timeout to '{_imageLoadTimeout}' milliseconds"); + _logger?.Info("Setting image load timeout to '{timeout}' milliseconds", _imageLoadTimeout); } #endregion @@ -233,54 +234,54 @@ public async Task SanitizeHtmlAsync(ConvertUri inputUri, Htm } catch (Exception exception) { - _logger?.WriteToLog($"Exception occurred in AngleSharp: {ExceptionHelpers.GetInnerException(exception)}"); + _logger?.Error(exception, "Exception occurred in AngleSharp: {exception}", ExceptionHelpers.GetInnerException(exception)); return new SanitizeHtmlResult(false, inputUri, safeUrls); } - _logger?.WriteToLog("Sanitizing HTML"); + _logger?.Info("Sanitizing HTML"); sanitizer ??= new HtmlSanitizer(); void OnSanitizerOnFilterUrl(object? _, FilterUrlEventArgs args) { if (args.OriginalUrl == args.SanitizedUrl) return; - _logger?.WriteToLog($"URL sanitized from '{args.OriginalUrl}' to '{args.SanitizedUrl}'"); + _logger?.Warn("URL sanitized from '{sourceUrl}' to '{sanitizedUrl}'", args.OriginalUrl, args.SanitizedUrl); htmlChanged = true; } void OnSanitizerOnRemovingAtRule(object? _, RemovingAtRuleEventArgs args) { - _logger?.WriteToLog($"Removing CSS at-rule '{args.Rule.CssText}' from tag '{args.Tag.TagName}'"); + _logger?.Warn("Removing CSS at-rule '{rule}' from tag '{tag}'", args.Rule.CssText, args.Tag.TagName); htmlChanged = true; } void OnSanitizerOnRemovingAttribute(object? _, RemovingAttributeEventArgs args) { - _logger?.WriteToLog($"Removing attribute '{args.Attribute.Name}' from tag '{args.Tag.TagName}', reason '{args.Reason}'"); + _logger?.Warn("Removing attribute '{attr}' from tag '{tag}', reason '{reason}'", args.Attribute.Name, args.Tag.TagName, args.Reason); htmlChanged = true; } void OnSanitizerOnRemovingComment(object? _, RemovingCommentEventArgs args) { - _logger?.WriteToLog($"Removing comment '{args.Comment.TextContent}'"); + _logger?.Info("Removing comment '{comment}'", args.Comment.TextContent); htmlChanged = true; } void OnSanitizerOnRemovingCssClass(object? _, RemovingCssClassEventArgs args) { - _logger?.WriteToLog($"Removing CSS class '{args.CssClass}' from tag '{args.Tag.TagName}', reason '{args.Reason}'"); + _logger?.Warn("Removing CSS class '{class}' from tag '{tag}', reason '{reason}'", args.CssClass, args.Tag.TagName, args.Reason); htmlChanged = true; } void OnSanitizerOnRemovingStyle(object? _, RemovingStyleEventArgs args) { - _logger?.WriteToLog($"Removing style '{args.Style.Name}' from tag '{args.Tag.TagName}', reason '{args.Reason}'"); + _logger?.Warn("Removing style '{style}' from tag '{tag}', reason '{reason}'", args.Style.Name, args.Tag.TagName, args.Reason); htmlChanged = true; } void OnSanitizerOnRemovingTag(object? _, RemovingTagEventArgs args) { - _logger?.WriteToLog($"Removing tag '{args.Tag.TagName}', reason '{args.Reason}'"); + _logger?.Warn("Removing tag '{tag}', reason '{reason}'", args.Tag.TagName, args.Reason); htmlChanged = true; } @@ -301,13 +302,13 @@ void OnSanitizerOnRemovingTag(object? _, RemovingTagEventArgs args) if (!htmlChanged) { - _logger?.WriteToLog("HTML did not need any sanitization"); + _logger?.Info("HTML did not need any sanitization"); return new SanitizeHtmlResult(false, inputUri, safeUrls); } } catch (Exception exception) { - _logger?.WriteToLog($"Exception occurred in HtmlSanitizer: {ExceptionHelpers.GetInnerException(exception)}"); + _logger?.Error(exception, "Exception occurred in HtmlSanitizer: {exception}", ExceptionHelpers.GetInnerException(exception)); return new SanitizeHtmlResult(false, inputUri, safeUrls); } finally @@ -321,12 +322,12 @@ void OnSanitizerOnRemovingTag(object? _, RemovingTagEventArgs args) sanitizer.RemovingTag -= OnSanitizerOnRemovingTag; } - _logger?.WriteToLog("HTML sanitized"); + _logger?.Info("HTML sanitized"); var sanitizedOutputFile = GetTempFile(".htm"); var outputUri = new ConvertUri(sanitizedOutputFile, inputUri.Encoding); var url = outputUri.ToString(); - _logger?.WriteToLog($"Adding url '{url}' to the safe url list"); + _logger?.Info("Adding url '{url}' to the safe url list", url); safeUrls.Add(url); try @@ -349,13 +350,13 @@ void OnSanitizerOnRemovingTag(object? _, RemovingTagEventArgs args) if (src.StartsWith("http://", StringComparison.InvariantCultureIgnoreCase) || src.StartsWith("https://", StringComparison.InvariantCultureIgnoreCase)) continue; - _logger?.WriteToLog($"Updating image source to '{src}' and adding it to the safe url list"); + _logger?.Info("Updating image source to '{url}' and adding it to the safe url list", src); safeUrls.Add(src); image.Source = src; } } - _logger?.WriteToLog($"Writing sanitized webpage to '{sanitizedOutputFile}'"); + _logger?.Info("Writing sanitized webpage to '{path}'", sanitizedOutputFile); #if (NETSTANDARD2_0) using var fileStream = new FileStream(sanitizedOutputFile, FileMode.CreateNew, FileAccess.Write); @@ -381,12 +382,12 @@ void OnSanitizerOnRemovingTag(object? _, RemovingTagEventArgs args) document.ToHtml(textWriter, new HtmlMarkupFormatter()); } - _logger?.WriteToLog("Sanitized webpage written"); + _logger?.Info("Sanitized webpage written"); return new SanitizeHtmlResult(true, outputUri, safeUrls); } catch (Exception exception) { - _logger?.WriteToLog($"Could not write new html file '{sanitizedOutputFile}', error: {ExceptionHelpers.GetInnerException(exception)}"); + _logger?.Error(exception, "Could not write new html file '{path}', error: {exception}", sanitizedOutputFile, ExceptionHelpers.GetInnerException(exception)); return new SanitizeHtmlResult(false, inputUri, safeUrls); } } @@ -480,7 +481,7 @@ public async Task FitPageToContentAsync(ConvertUri input } catch (Exception exception) { - _logger?.WriteToLog($"Exception occurred in AngleSharp: {ExceptionHelpers.GetInnerException(exception)}"); + _logger?.Error(exception, "Exception occurred in AngleSharp: {exception}", ExceptionHelpers.GetInnerException(exception)); return new FitPageToContentResult(false, inputUri); } @@ -489,7 +490,7 @@ public async Task FitPageToContentAsync(ConvertUri input try { - _logger?.WriteToLog($"Writing changed webpage to '{outputFile}'"); + _logger?.Info("Writing changed webpage to '{path}'", outputFile); #if (NETSTANDARD2_0) using var fileStream = new FileStream(outputFile, FileMode.CreateNew, FileAccess.Write); @@ -515,12 +516,12 @@ public async Task FitPageToContentAsync(ConvertUri input document.ToHtml(textWriter, new HtmlMarkupFormatter()); } - _logger?.WriteToLog("Changed webpage written"); + _logger?.Info("Changed webpage written"); return new FitPageToContentResult(true, outputUri); } catch (Exception exception) { - _logger?.WriteToLog($"Could not write new html file '{outputFile}', error: {ExceptionHelpers.GetInnerException(exception)}"); + _logger?.Error(exception, "Could not write new html file '{path}', error: {exception}", outputFile, ExceptionHelpers.GetInnerException(exception)); return new FitPageToContentResult(false, inputUri); } } @@ -561,7 +562,7 @@ public async Task ValidateImagesAsync( await using var webpage = inputUri.IsFile ? OpenFileStream(inputUri.OriginalString) : await OpenDownloadStream(inputUri).ConfigureAwait(false); #endif - _logger?.WriteToLog($"DPI settings for image, x: '{graphics.DpiX}' and y: '{graphics.DpiY}'"); + _logger?.Info("DPI settings for image, x: '{dpiX}' and y: '{dpiY}'", graphics.DpiX, graphics.DpiY); var maxWidth = (pageSettings.PaperWidth - pageSettings.MarginLeft - pageSettings.MarginRight) * graphics.DpiX; var maxHeight = (pageSettings.PaperHeight - pageSettings.MarginTop - pageSettings.MarginBottom) * graphics.DpiY; @@ -584,11 +585,11 @@ public async Task ValidateImagesAsync( } catch (Exception exception) { - _logger?.WriteToLog($"Exception occurred in AngleSharp: {ExceptionHelpers.GetInnerException(exception)}"); + _logger?.Error(exception, "Exception occurred in AngleSharp: {exception}", ExceptionHelpers.GetInnerException(exception)); return new ValidateImagesResult(false, inputUri); } - _logger?.WriteToLog("Validating all images if they need to be rotated and if they fit the page"); + _logger?.Info("Validating all images if they need to be rotated and if they fit the page"); var unchangedImages = new List(); var absoluteUri = inputUri.AbsoluteUri.Substring(0, inputUri.AbsoluteUri.LastIndexOf('/') + 1); @@ -599,7 +600,7 @@ public async Task ValidateImagesAsync( if (string.IsNullOrWhiteSpace(htmlImage.Source)) { - _logger?.WriteToLog($"HTML image tag '{htmlImage.TagName}' has no image source '{htmlImage.Source}'"); + _logger?.Warn("HTML image tag '{tag}' has no image source '{source}'", htmlImage.TagName, htmlImage.Source); continue; } @@ -612,15 +613,15 @@ public async Task ValidateImagesAsync( if (!RegularExpression.IsRegExMatch(urlBlacklist, source, out var matchedPattern) || isAbsoluteUri || isSafeUrl) { if (isAbsoluteUri) - _logger?.WriteToLog($"The url '{source}' has been allowed because it start with the absolute uri '{absoluteUri}'"); + _logger?.Info("The url '{source}' has been allowed because it start with the absolute uri '{absoluteUri}'", source, absoluteUri); else if (isSafeUrl) - _logger?.WriteToLog($"The url '{source}' has been allowed because it is on the safe url list"); + _logger?.Info("The url '{source}' has been allowed because it is on the safe url list", source); else - _logger?.WriteToLog($"The url '{source}' has been allowed because it did not match anything on the url blacklist"); + _logger?.Info("The url '{source}' has been allowed because it did not match anything on the url blacklist", source); } else { - _logger?.WriteToLog($"The url '{source}' has been blocked by url blacklist pattern '{matchedPattern}'"); + _logger?.Warn("The url '{source}' has been blocked by url blacklist pattern '{pattern}'", source, matchedPattern); continue; } @@ -643,13 +644,13 @@ public async Task ValidateImagesAsync( { htmlImage.DisplayWidth = image.Width; htmlImage.DisplayHeight = image.Height; - _logger?.WriteToLog($"Image rotated and saved to location '{fileName}'"); + _logger?.Info("Image rotated and saved to location '{path}'", fileName); image.Save(fileName); htmlImage.DisplayWidth = image.Width; htmlImage.DisplayHeight = image.Height; htmlImage.SetStyle(string.Empty); var newSrc = new Uri(fileName).ToString(); - _logger?.WriteToLog($"Adding url '{newSrc}' to the safe url list"); + _logger?.Info("Adding url '{url}' to the safe url list", newSrc); safeUrls.Add(newSrc); htmlImage.Source = newSrc; htmlChanged = true; @@ -672,7 +673,7 @@ public async Task ValidateImagesAsync( } catch (Exception exception) { - _logger?.WriteToLog($"Could not get computed style from html image, exception: '{exception.Message}'"); + _logger?.Error(exception, "Could not get computed style from html image, exception: '{error}'", exception.Message); } if (style != null) @@ -700,14 +701,14 @@ public async Task ValidateImagesAsync( var ratio = maxWidth / image.Width; - _logger?.WriteToLog($"Rescaling image with current width {image.Width}, height {image.Height} and ratio {ratio}"); + _logger?.Info("Rescaling image with current width {width}, height {height} and ratio {ratio}", image.Width, image.Height, ratio); var newWidth = (int)(image.Width * ratio); if (newWidth == 0) newWidth = 1; var newHeight = (int)(image.Height * ratio); if (newHeight == 0) newHeight = 1; - _logger?.WriteToLog($"Image rescaled to new width {newWidth} and height {newHeight}"); + _logger?.Info("Image rescaled to new width {width} and height {height}", newWidth, newHeight); htmlImage.DisplayWidth = newWidth; htmlImage.DisplayHeight = newHeight; htmlImage.SetStyle(string.Empty); @@ -733,7 +734,7 @@ public async Task ValidateImagesAsync( if (image == null) { - _logger?.WriteToLog($"Could not load unchanged image from location '{unchangedImage.Source}'"); + _logger?.Warn("Could not load unchanged image from location '{location}'", unchangedImage.Source); continue; } @@ -748,11 +749,11 @@ public async Task ValidateImagesAsync( var newSrc = new Uri(fileName).ToString(); safeUrls.Add(newSrc); unchangedImage.Source = newSrc; - _logger?.WriteToLog($"Unchanged image saved to location '{fileName}'"); + _logger?.Info("Unchanged image saved to location '{path}'", fileName); } catch (Exception exception) { - _logger?.WriteToLog($"Could not write unchanged image because of an exception: {ExceptionHelpers.GetInnerException(exception)}"); + _logger?.Error(exception, "Could not write unchanged image because of an exception: {exception}", ExceptionHelpers.GetInnerException(exception)); } } @@ -762,7 +763,7 @@ public async Task ValidateImagesAsync( try { - _logger?.WriteToLog($"Writing changed webpage to '{outputFile}'"); + _logger?.Info("Writing changed webpage to '{path}'", outputFile); #if (NETSTANDARD2_0) using var fileStream = new FileStream(outputFile, FileMode.CreateNew, FileAccess.Write); @@ -789,13 +790,13 @@ public async Task ValidateImagesAsync( document.ToHtml(textWriter, new HtmlMarkupFormatter()); } - _logger?.WriteToLog("Changed webpage written"); + _logger?.Info("Changed webpage written"); return new ValidateImagesResult(true, outputUri); } catch (Exception exception) { - _logger?.WriteToLog($"Could not write new html file '{outputFile}', error: {ExceptionHelpers.GetInnerException(exception)}"); + _logger?.Error(exception, "Could not write new html file '{path}', error: {exception}", outputFile, ExceptionHelpers.GetInnerException(exception)); return new ValidateImagesResult(false, inputUri); } } @@ -812,7 +813,7 @@ public async Task ValidateImagesAsync( { if (imageSource.StartsWith("data:", StringComparison.InvariantCultureIgnoreCase)) { - _logger?.WriteToLog("Decoding image from base64 string"); + _logger?.Info("Decoding image from base64 string"); try { @@ -821,19 +822,19 @@ public async Task ValidateImagesAsync( using var stream = new MemoryStream(binaryData); var image = Image.FromStream(stream); - _logger?.WriteToLog("Image decoded"); + _logger?.Info("Image decoded"); return image; } catch (Exception exception) { - _logger?.WriteToLog($"Error decoding image: {ExceptionHelpers.GetInnerException(exception)}"); + _logger?.Error(exception, "Error decoding image: {exception}", ExceptionHelpers.GetInnerException(exception)); return null; } } try { - _logger?.WriteToLog($"Getting image from url '{imageSource}'"); + _logger?.Info("Getting image from url '{url}'", imageSource); var imageUri = new Uri(imageSource); @@ -873,17 +874,17 @@ public async Task ValidateImagesAsync( } case "file": - _logger?.WriteToLog("Ignoring local file"); + _logger?.Warn("Ignoring local file"); break; default: - _logger?.WriteToLog($"Unsupported scheme {imageUri.Scheme} to get image"); + _logger?.Warn("Unsupported scheme {scheme} to get image", imageUri.Scheme); return null; } } catch (Exception exception) { - _logger?.WriteToLog($"Getting image failed with exception: {ExceptionHelpers.GetInnerException(exception)}"); + _logger?.Error(exception, "Getting image failed with exception: {exception}", ExceptionHelpers.GetInnerException(exception)); } return null; @@ -909,12 +910,12 @@ private bool RotateImageByExifOrientationData(Image image, bool updateExifData = if (item?.Value == null) { - _logger?.WriteToLog("Could not get orientation information from exif"); + _logger?.Info("Could not get orientation information from exif"); return false; } RotateFlipType rotateFlipType; - _logger?.WriteToLog("Checking image rotation"); + _logger?.Info("Checking image rotation"); switch (item.Value[0]) { @@ -948,7 +949,7 @@ private bool RotateImageByExifOrientationData(Image image, bool updateExifData = return false; image.RotateFlip(rotateFlipType); - _logger?.WriteToLog($"Image rotated with {rotateFlipType}"); + _logger?.Info("Image rotated with {rotationType}", rotateFlipType); // Remove Exif orientation tag (if requested) if (updateExifData) image.RemovePropertyItem(orientationId); @@ -966,13 +967,13 @@ private bool RotateImageByExifOrientationData(Image image, bool updateExifData = { try { - _logger?.WriteToLog($"Opening stream to file '{fileName}'"); + _logger?.Info("Opening stream to file '{path}'", fileName); var result = File.OpenRead(fileName); return result; } catch (Exception exception) { - _logger?.WriteToLog($"Opening stream failed with exception: {ExceptionHelpers.GetInnerException(exception)}"); + _logger?.Error(exception, "Opening stream failed with exception: {exception}", ExceptionHelpers.GetInnerException(exception)); return null; } } @@ -994,18 +995,21 @@ private bool RotateImageByExifOrientationData(Image image, bool updateExifData = if (_stopwatch != null && checkTimeout) { var timeLeft = TimeLeft; - _logger?.WriteToLog($"Opening stream to url '{sourceUri}'{(_imageLoadTimeout != 0 ? $" with a timeout of {timeLeft} milliseconds" : string.Empty)}"); + if (_imageLoadTimeout != 0) + _logger?.Info("Opening stream to url '{url}' with a timeout of {timeout} milliseconds", sourceUri, timeLeft); + else + _logger?.Info("Opening stream to url '{url}'", sourceUri); if (timeLeft == 0) { - _logger?.WriteToLog($"Image load has timed out, skipping opening stream to url '{sourceUri}'"); + _logger?.Error("Image load has timed out, skipping opening stream to url '{url}'", sourceUri); return null; } client.Timeout = TimeSpan.FromMilliseconds(timeLeft); } else - _logger?.WriteToLog($"Opening stream to url '{sourceUri}'"); + _logger?.Info("Opening stream to url '{url}'", sourceUri); var response = await client.GetAsync(sourceUri).ConfigureAwait(false); @@ -1013,7 +1017,7 @@ private bool RotateImageByExifOrientationData(Image image, bool updateExifData = } catch (Exception exception) { - _logger?.WriteToLog($"Opening stream failed with exception: {ExceptionHelpers.GetInnerException(exception)}"); + _logger?.Error(exception, "Opening stream failed with exception: {exception}", ExceptionHelpers.GetInnerException(exception)); return null; } } diff --git a/ChromiumHtmlToPdfLib/Helpers/FileCacheHandler.cs b/ChromiumHtmlToPdfLib/Helpers/FileCacheHandler.cs index f6fc964..4ad6e59 100644 --- a/ChromiumHtmlToPdfLib/Helpers/FileCacheHandler.cs +++ b/ChromiumHtmlToPdfLib/Helpers/FileCacheHandler.cs @@ -122,7 +122,7 @@ internal FileCacheHandler( if (!_cacheDirectory.Exists) { - _logger?.WriteToLog($"Creating cache directory '{_cacheDirectory.FullName}'"); + _logger?.Info("Creating cache directory '{path}'", _cacheDirectory.FullName); _cacheDirectory.Create(); } @@ -158,7 +158,7 @@ protected override Task SendAsync(HttpRequestMessage reques IsFromCache = true; - _logger?.WriteToLog("Returned item from cache"); + _logger?.Info("Returned item from cache"); return Task.FromResult(cachedResponse); } @@ -171,11 +171,11 @@ protected override Task SendAsync(HttpRequestMessage reques response.Content.ReadAsStreamAsync().GetAwaiter().GetResult().CopyTo(memoryStream); FileCache.Add(key, memoryStream.ToArray(), new CacheItemPolicy { SlidingExpiration = TimeSpan.FromDays(1) }); - _logger?.WriteToLog("Added item to cache"); + _logger?.Info("Added item to cache"); response.Content = new StreamContent(new MemoryStream(memoryStream.ToArray())); return Task.FromResult(response); } #endregion -} \ No newline at end of file +} diff --git a/ChromiumHtmlToPdfLib/Helpers/PreWrapper.cs b/ChromiumHtmlToPdfLib/Helpers/PreWrapper.cs index 5552f50..c4bbe53 100644 --- a/ChromiumHtmlToPdfLib/Helpers/PreWrapper.cs +++ b/ChromiumHtmlToPdfLib/Helpers/PreWrapper.cs @@ -131,20 +131,20 @@ public string WrapFile(string inputFile, Encoding? encoding) var title = WebUtility.HtmlEncode(temp); var tempFile = GetTempFile; - _logger?.WriteToLog($"Reading text file '{inputFile}'"); + _logger?.Info("Reading text file '{path}'", inputFile); if (encoding == null) { using var fileStream = File.OpenRead(inputFile); - _logger?.WriteToLog("Trying to detect encoding"); + _logger?.Info("Trying to detect encoding"); var result = CharsetDetector.DetectFromStream(fileStream); encoding = result.Detected.Encoding; - _logger?.WriteToLog(result.Detected.StatusLog); + _logger?.Info("{statusLog}", result.Detected.StatusLog); } var streamReader = new StreamReader(inputFile, encoding); - _logger?.WriteToLog($"File is '{streamReader.CurrentEncoding.WebName}' encoded"); + _logger?.Info("File is '{encoding}' encoded", streamReader.CurrentEncoding.WebName); var writeEncoding = new UnicodeEncoding(!BitConverter.IsLittleEndian, true); @@ -182,9 +182,9 @@ public string WrapFile(string inputFile, Encoding? encoding) writer.WriteLine(""); } - _logger?.WriteToLog($"File pre wrapped and written to temporary file '{tempFile}'"); + _logger?.Info("File pre wrapped and written to temporary file '{path}'", tempFile); return tempFile; } #endregion -} \ No newline at end of file +} diff --git a/ChromiumHtmlToPdfLib/Loggers/Logger.cs b/ChromiumHtmlToPdfLib/Loggers/Logger.cs index acdcf4e..d6be05c 100644 --- a/ChromiumHtmlToPdfLib/Loggers/Logger.cs +++ b/ChromiumHtmlToPdfLib/Loggers/Logger.cs @@ -35,10 +35,6 @@ namespace ChromiumHtmlToPdfLib.Loggers; internal class Logger { #region Fields - /// - /// Used to make the logging thread safe - /// - private static readonly object LoggerLock = new(); /// /// When set then logging is written to this ILogger instance @@ -65,29 +61,81 @@ internal Logger(ILogger? logger, string? instanceId) } #endregion - #region WriteToLog + #region Log Methods + /// + /// Writes a line to the with + /// + /// The message to write + /// Message arguments + public void Info(string message, params object?[] args) + { + if (InternalLogger == null) return; + + try + { + using var _ = InstanceId == null ? null : InternalLogger.BeginScope(InstanceId); + InternalLogger.LogInformation(message, args); + } + catch (ObjectDisposedException) + { + // Ignore + } + } + + /// + /// Writes a line to the with + /// + /// The message to write + /// Message arguments + public void Warn(string message, params object?[] args) + { + if (InternalLogger == null) return; + + try + { + using var _ = InstanceId == null ? null : InternalLogger.BeginScope(InstanceId); + InternalLogger.LogWarning(message, args); + } + catch (ObjectDisposedException) + { + // Ignore + } + } + + /// + /// Writes a line to the with + /// + /// The message to write + /// Message arguments + public void Error(string message, params object?[] args) + { + if (InternalLogger == null) return; + + try + { + using var _ = InstanceId == null ? null : InternalLogger.BeginScope(InstanceId); + InternalLogger.LogError(message, args); + } + catch (ObjectDisposedException) + { + // Ignore + } + } + /// - /// Writes a line to the + /// Writes a line to the with /// + /// Exception to attach to log entry /// The message to write - internal void WriteToLog(string message) + /// Message arguments + public void Error(Exception ex, string message, params object?[] args) { if (InternalLogger == null) return; try { - if (InstanceId == null) - { - InternalLogger.LogInformation(message); - } - else - { - lock (LoggerLock) - { - using var _ = InternalLogger.BeginScope(InstanceId); - InternalLogger.LogInformation(message); - } - } + using var _ = InstanceId == null ? null : InternalLogger.BeginScope(InstanceId); + InternalLogger.LogError(ex, message, args); } catch (ObjectDisposedException) { @@ -95,4 +143,4 @@ internal void WriteToLog(string message) } } #endregion -} \ No newline at end of file +} diff --git a/ChromiumHtmlToPdfLib/Loggers/Stream.cs b/ChromiumHtmlToPdfLib/Loggers/Stream.cs index 73d5691..58d5105 100644 --- a/ChromiumHtmlToPdfLib/Loggers/Stream.cs +++ b/ChromiumHtmlToPdfLib/Loggers/Stream.cs @@ -37,7 +37,7 @@ public class Stream : ILogger, IDisposable { #region Fields private System.IO.Stream? _stream; - private string? _instanceId; + private readonly IExternalScopeProvider _scopeProvider = new LoggerExternalScopeProvider(); #endregion #region Constructors @@ -61,8 +61,7 @@ public Stream(System.IO.Stream stream) public IDisposable? BeginScope(TState state) where TState : notnull { - _instanceId = state.ToString(); - return null; + return _scopeProvider.Push(state); } #endregion @@ -91,11 +90,16 @@ public bool IsEnabled(LogLevel logLevel) public void Log(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func formatter) { + if (_stream == null || !_stream.CanWrite) return; + var message = $"{formatter(state, exception)}"; - if (_stream == null || !_stream.CanWrite) return; + string? instanceId = null; + // assign state always as ForEachScope enumerates from outer to inner scope + _scopeProvider.ForEachScope((state, _) => instanceId = state as string, (object?)null); + var line = - $"{DateTime.Now:yyyy-MM-ddTHH:mm:ss.fff}{(_instanceId != null ? $" - {_instanceId}" : string.Empty)} - {message}{Environment.NewLine}"; + $"{DateTime.Now:yyyy-MM-ddTHH:mm:ss.fff}{(instanceId != null ? $" - {instanceId}" : string.Empty)} - {message}{Environment.NewLine}"; var bytes = Encoding.UTF8.GetBytes(line); _stream.Write(bytes, 0, bytes.Length); _stream.Flush();