From ae2b42065abbb9591960d26015152df5129b00be Mon Sep 17 00:00:00 2001 From: John Cardinal Date: Wed, 27 Oct 2021 00:11:57 +0000 Subject: [PATCH] Report rendering handler to prevent linux from crashing on too much reporting at once --- .vscode/launch.json | 1 + .../docs/ops-config-environment-variables.md | 3 ++ .../ops-config-report-rendering-timeout.md | 51 +++++++++++++++++++ .../Controllers/ServerStateController.cs | 1 + server/AyaNova/biz/ReportBiz.cs | 21 ++------ ...rocessCache.cs => ReportProcessManager.cs} | 43 ++++++++++++++-- server/AyaNova/util/ServerBootConfig.cs | 7 ++- 7 files changed, 103 insertions(+), 24 deletions(-) create mode 100644 docs/8.0/ayanova/docs/ops-config-report-rendering-timeout.md rename server/AyaNova/util/{ReportingProcessCache.cs => ReportProcessManager.cs} (56%) diff --git a/.vscode/launch.json b/.vscode/launch.json index f5e036fd..47589491 100644 --- a/.vscode/launch.json +++ b/.vscode/launch.json @@ -50,6 +50,7 @@ "AYANOVA_DB_CONNECTION": "Server=localhost;Username=postgres;Password=raven;Database=AyaNova;CommandTimeout=120;", //"AYANOVA_DB_CONNECTION": "Server=localhost;Username=postgres;Password=abraxis;Database=AyaNova;CommandTimeout=120;", "AYANOVA_USE_URLS": "http://*:7575;", + "AYANOVA_REPORT_RENDERING_TIMEOUT": "5000", "AYANOVA_FOLDER_USER_FILES": "c:\\temp\\RavenTestData\\userfiles", "AYANOVA_FOLDER_BACKUP_FILES": "c:\\temp\\RavenTestData\\backupfiles", "AYANOVA_FOLDER_TEMPORARY_SERVER_FILES": "c:\\temp\\RavenTestData\\tempfiles", diff --git a/docs/8.0/ayanova/docs/ops-config-environment-variables.md b/docs/8.0/ayanova/docs/ops-config-environment-variables.md index 0c521bb9..a74adb4c 100644 --- a/docs/8.0/ayanova/docs/ops-config-environment-variables.md +++ b/docs/8.0/ayanova/docs/ops-config-environment-variables.md @@ -33,6 +33,9 @@ These values can all be specified as an environment variable or as a command lin - [AYANOVA_JWT_SECRET](ops-config-jwt-secret.md) - [AYANOVA_USE_URLS](ops-config-use-urls.md) +## REPORTING + +- [AYANOVA_REPORT_RENDERING_TIMEOUT](ops-config-report-rendering-timeout.md) ## SECURITY diff --git a/docs/8.0/ayanova/docs/ops-config-report-rendering-timeout.md b/docs/8.0/ayanova/docs/ops-config-report-rendering-timeout.md new file mode 100644 index 00000000..ec8c383c --- /dev/null +++ b/docs/8.0/ayanova/docs/ops-config-report-rendering-timeout.md @@ -0,0 +1,51 @@ +# REPORT RENDERING TIMEOUT SETTING + +The report rendering timeout value controls how long AyaNova will wait for a prior report to complete rendering when it receives a request to render a subsequent report. + +This avoids a situation where a subsequent user can not get their report because a prior report generation is frozen due to a bug in a report template script or simply selecting too many records to report in a practical amount of time. + +## How timeouts work + +When a report is requested to be rendered AyaNova starts the process and makes note of the time and will process that report indefinitely for as long as it takes to complete. However, if a subsequent report request is made and the first report has not completed yet then AyaNova will use this setting to wait for the first report to process before starting the next one. If the timeout period completes without the first report completed rendering then AyaNova will forcibly stop processing the first report and release the resources dedicated to it and start processing the new report. + +It's important to note that this timeout does not prevent AyaNova from processing a report for any length of time necessary to complete it; this timeout only takes effect if another report is requested to be rendered so if a User has to render a very large report that is known to take longer than the timeout period they would be advised to render that report when no one else is requesting a report (i.e. after hours) + + +The value is specified in **milliseconds** or thousandths of a second. For example a 30 second timeout is 30000 milliseconds. + +## Default + +If no override is specified AyaNova will use the following default value: + +`30000` + +This means AyaNova will wait for a prior report to complete for no longer than 30,000 milliseconds or 30 seconds before it will stop that prior report render and start the new one. + +## Hard cap + +There is a hard cap of 3 minutes or 180000 milliseconds built into AyaNova so specifying a value greater than 180000 milliseconds will be ignored. + +## Overriding + +AyaNova expects this value to be provided by an environment variable or command line parameter named + +`AYANOVA_REPORT_RENDERING_TIMEOUT` + +The value specified should be a string specifying the timeout in **milliseconds**, for example: +`30000` + +Example command line parameter + +`dotnet run --AYANOVA_REPORT_RENDERING_TIMEOUT="30000` + +Example environment variable + +Windows + +`set "AYANOVA_REPORT_RENDERING_TIMEOUT=60000"` + +Linux / MAC + +`export AYANOVA_REPORT_RENDERING_TIMEOUT="120000"` + +If both a command line parameter and an environment variable are set the command line parameter takes precedence. diff --git a/server/AyaNova/Controllers/ServerStateController.cs b/server/AyaNova/Controllers/ServerStateController.cs index 769c459f..e7a2881d 100644 --- a/server/AyaNova/Controllers/ServerStateController.cs +++ b/server/AyaNova/Controllers/ServerStateController.cs @@ -183,6 +183,7 @@ namespace AyaNova.Api.Controllers AYANOVA_DEFAULT_TRANSLATION = ServerBootConfig.AYANOVA_DEFAULT_TRANSLATION, AYANOVA_USE_URLS = ServerBootConfig.AYANOVA_USE_URLS, AYANOVA_DB_CONNECTION = DbUtil.PasswordRedactedConnectionString(ServerBootConfig.AYANOVA_DB_CONNECTION), + AYANOVA_REPORT_RENDERING_TIMEOUT = ServerBootConfig.AYANOVA_REPORT_RENDERING_TIMEOUT, AYANOVA_FOLDER_USER_FILES = ServerBootConfig.AYANOVA_FOLDER_USER_FILES, AYANOVA_FOLDER_BACKUP_FILES = ServerBootConfig.AYANOVA_FOLDER_BACKUP_FILES, AYANOVA_FOLDER_TEMPORARY_SERVER_FILES = ServerBootConfig.AYANOVA_FOLDER_TEMPORARY_SERVER_FILES, diff --git a/server/AyaNova/biz/ReportBiz.cs b/server/AyaNova/biz/ReportBiz.cs index f332ca26..c0f40646 100644 --- a/server/AyaNova/biz/ReportBiz.cs +++ b/server/AyaNova/biz/ReportBiz.cs @@ -417,7 +417,7 @@ namespace AyaNova.Biz //Default timeout for each operation of report generation - var WaitTimeout = new WaitForFunctionOptions() { Timeout = ServerBootConfig.REPORT_RENDERING_OPERATION_TIMEOUT }; + var WaitTimeout = new WaitForFunctionOptions() { Timeout = ServerBootConfig.AYANOVA_REPORT_RENDERING_TIMEOUT }; //includeWoItemDescendants? reportRequest.IncludeWoItemDescendants = report.IncludeWoItemDescendants; @@ -435,7 +435,7 @@ namespace AyaNova.Biz var ReportJSFolderPath = Path.Combine(ServerBootConfig.AYANOVA_CONTENT_ROOT_PATH, "resource", "rpt"); //Ensure last reporting op has completed - ReportingProcessCache.EnsureReporterAvailable(ServerBootConfig.REPORT_RENDERING_OPERATION_TIMEOUT); + await ReportProcessorManager.EnsureReporterAvailableAsync(log); var lo = new LaunchOptions { Headless = true }; bool isWindows = System.Runtime.InteropServices.RuntimeInformation.IsOSPlatform(System.Runtime.InteropServices.OSPlatform.Windows); @@ -493,7 +493,7 @@ namespace AyaNova.Biz using (var page = await browser.NewPageAsync()) { //mark this process so it can be cancelled if it times out - ReportingProcessCache.FlagNewProcess(browser.Process.Id); + ReportProcessorManager.RecordNewReportGeneratorProcess(browser.Process.Id); try { @@ -616,7 +616,6 @@ namespace AyaNova.Biz await page.WaitForExpressionAsync($"ayPreRender({ReportDataObject})", WaitTimeout); //compile the template - //NOTE: TIMEOUT? log.LogDebug($"Calling Handlebars.compile..."); var compileScript = $"Handlebars.compile(`{report.Template}`)(PreParedReportDataObject);"; var compiledHTML = await page.EvaluateExpressionAsync(compileScript); @@ -720,11 +719,6 @@ namespace AyaNova.Biz } catch { - //NOTE: in future may need to kill the chromium process if it's found to be hanging around - //my preliminary thinking is to keep track of the browser.process.processid above and check if still present and zap if so - //maybe *from* the controller (return pid as a return property from here? Kill it if still hanging around) - //https://stackoverflow.com/questions/1642231/how-to-kill-a-c-sharp-process - //This is the error when a helper is used on the template but doesn't exist: //Evaluation failed: d //(it might also mean other things wrong with template) @@ -741,15 +735,6 @@ namespace AyaNova.Biz { log.LogDebug($"Closing browser"); await browser.CloseAsync(); - - //this probably isn't absolutely necessary but insurance - //bugbug: crashes linux? - // var process = System.Diagnostics.Process.GetProcessById(ChromiumProcessID); - // if (ChromiumProcessID > 0 && process?.HasExited == false) - // { - // log.LogError($"Error during render, Chromium process (pid {ChromiumProcessID}) still active, forcing it to stop now"); - // process.Kill(); - // } } } } diff --git a/server/AyaNova/util/ReportingProcessCache.cs b/server/AyaNova/util/ReportProcessManager.cs similarity index 56% rename from server/AyaNova/util/ReportingProcessCache.cs rename to server/AyaNova/util/ReportProcessManager.cs index 6f65007c..3a4fd6af 100644 --- a/server/AyaNova/util/ReportingProcessCache.cs +++ b/server/AyaNova/util/ReportProcessManager.cs @@ -1,6 +1,7 @@ using System; using System.Diagnostics; - +using System.Threading.Tasks; +using Microsoft.Extensions.Logging; namespace AyaNova.Util { @@ -11,18 +12,50 @@ namespace AyaNova.Util /// also zombie process issues in linux etc, this just ensures it's safe /// This is triggered when a report is rendered /// - internal static class ReportingProcessCache + internal static class ReportProcessorManager { internal static int ReporterProcessId { get; set; } = -1; internal static DateTime Started { get; set; } - internal static void EnsureReporterAvailable(int timeOutMilliSeconds) + internal async static Task EnsureReporterAvailableAsync(ILogger log) { - if (ReporterProcess() == null) return; + Process reportProcess = ReporterProcess(); + if (reportProcess == null) + { + return; + } //await it's completion in the specified timeout + int HardTimeout = ServerBootConfig.AYANOVA_REPORT_RENDERING_TIMEOUT; + //don't wait forever, hard cap of 3 minutes regardless of setting + if (HardTimeout > 180000) HardTimeout = 180000; + bool keepOnWaiting = true; + while (keepOnWaiting) + { + //don't check continually + await Task.Delay(500); + //check process is still running + if (reportProcess?.HasExited == false) + { + //time to kill it? + if ((DateTime.UtcNow - Started).TotalMilliseconds > HardTimeout) + { + log.LogInformation($"Report processor did not complete in {HardTimeout}ms and will be force stopped"); + reportProcess.Kill(); + keepOnWaiting = false; + } + } + else + { + log.LogDebug($"EnsureReporterAvailableAsync Reporter processor completed normally"); + keepOnWaiting = false; + } + }; + ReporterProcessId = -1; + Started = DateTime.MinValue; + return; } - internal static void FlagNewProcess(int processId) + internal static void RecordNewReportGeneratorProcess(int processId) { ReporterProcessId = processId; Started = DateTime.UtcNow; diff --git a/server/AyaNova/util/ServerBootConfig.cs b/server/AyaNova/util/ServerBootConfig.cs index e7477a60..6e70a0e6 100644 --- a/server/AyaNova/util/ServerBootConfig.cs +++ b/server/AyaNova/util/ServerBootConfig.cs @@ -14,7 +14,7 @@ namespace AyaNova.Util //############################################################################################################ //STATIC HARD CODED COMPILE TIME DEFAULTS NOT SET THROUGH CONFIG internal const int FAILED_AUTH_DELAY = 3000;//ms - internal const int REPORT_RENDERING_OPERATION_TIMEOUT = 20000;//ms + //UPLOAD LIMITS 1048576 = 1MiB for testing 10737420000 10737418240 10,737,418,240 internal const long MAX_ATTACHMENT_UPLOAD_BYTES = 10737420000;//slight bit of overage as 10737418241=10GiB internal const long MAX_LOGO_UPLOAD_BYTES = 512000;//500KiB limit @@ -60,6 +60,8 @@ namespace AyaNova.Util //API internal static string AYANOVA_JWT_SECRET { get; set; } internal static string AYANOVA_USE_URLS { get; set; } + internal static int AYANOVA_REPORT_RENDERING_TIMEOUT { get; set; } + //DATABASE internal static string AYANOVA_DB_CONNECTION { get; set; } @@ -159,6 +161,9 @@ namespace AyaNova.Util AYANOVA_JWT_SECRET = config.GetValue("AYANOVA_JWT_SECRET"); + int? nTemp = config.GetValue("AYANOVA_REPORT_RENDERING_TIMEOUT"); + AYANOVA_REPORT_RENDERING_TIMEOUT = (null == nTemp) ? 30000 : (int)nTemp; + //DB AYANOVA_DB_CONNECTION = config.GetValue("AYANOVA_DB_CONNECTION"); bTemp = config.GetValue("AYANOVA_PERMANENTLY_ERASE_DATABASE");