diff --git a/server/AyaNova/biz/PMBiz.cs b/server/AyaNova/biz/PMBiz.cs index b0e4cf26..912e6b8b 100644 --- a/server/AyaNova/biz/PMBiz.cs +++ b/server/AyaNova/biz/PMBiz.cs @@ -4149,7 +4149,7 @@ namespace AyaNova.Biz // private async Task TravelPopulateVizFields(PMItemTravel o, bool calculateTotalsOnly = false) { - if (calculateTotalsOnly == false) + if (calculateTotalsOnly == false) { if (o.UserId != null) { @@ -5048,10 +5048,10 @@ namespace AyaNova.Biz .Where(z => z.GenerateDate < DateTime.UtcNow && (z.StopGeneratingDate == null || z.StopGeneratingDate > DateTime.UtcNow) && z.Active == true) .Select(z => z.Id) .ToListAsync(); -#if (DEBUG) - if (l.Count > 0) - log.LogInformation($"Found {l.Count} ready to generate PM orders"); -#endif + // #if (DEBUG) + // if (l.Count > 0) + // log.LogInformation($"Found {l.Count} ready to generate PM orders"); + // #endif //process those pms foreach (long pmid in l) @@ -5063,9 +5063,9 @@ namespace AyaNova.Biz -#if (DEBUG) - log.LogInformation($"processing pm id {pmid}"); -#endif + // #if (DEBUG) + // log.LogInformation($"processing pm id {pmid}"); + // #endif var p = await ct.PM.AsSplitQuery() .Include(w => w.Items.OrderBy(item => item.Sequence)) .ThenInclude(wi => wi.Expenses) @@ -5184,9 +5184,9 @@ namespace AyaNova.Biz try { await ct.SaveChangesAsync(); -#if (DEBUG) - log.LogInformation($"updated PM after successful generation {p.Serial}"); -#endif + // #if (DEBUG) + // log.LogInformation($"updated PM after successful generation {p.Serial}"); + // #endif } catch (Exception ex) { @@ -5564,21 +5564,13 @@ namespace AyaNova.Biz } } - //wo.Items.Add(woi); + } - // WorkOrderBiz biz = WorkOrderBiz.GetBiz(ct); - // var NewObject = await biz.WorkOrderCreateAsync(wo, false); - // if (NewObject == null) - // { - // var err = $"PMBiz::NewServiceWorkOrderFromPMAsync error creating from PM {p.Serial}\r\n{biz.GetErrorsAsString()}"; - // log.LogError(err); - // await NotifyEventHelper.AddGeneralNotifyEvent(AyaType.PM, p.Id, NotifyEventType.PMGenerationFailed, $"Error generating Work order from PM {p.Serial}\r\n{biz.GetErrorsAsString()}", "Preventive Maintenance"); - // return false; - // } -#if (DEBUG) - log.LogInformation($"PMBiz::NewServiceWorkOrderFromPMAsync created new workorder {NewWoHeader.Serial}"); -#endif + + // #if (DEBUG) + // log.LogInformation($"PMBiz::NewServiceWorkOrderFromPMAsync created new workorder {NewWoHeader.Serial}"); + // #endif return true; } #endregion diff --git a/server/AyaNova/biz/ReportBiz.cs b/server/AyaNova/biz/ReportBiz.cs index 679e098e..441e3763 100644 --- a/server/AyaNova/biz/ReportBiz.cs +++ b/server/AyaNova/biz/ReportBiz.cs @@ -10,7 +10,6 @@ using AyaNova.Models; using EnumsNET; using PuppeteerSharp; using Newtonsoft.Json.Linq; -using System.Threading; using System; namespace AyaNova.Biz @@ -59,39 +58,7 @@ namespace AyaNova.Biz } } - // //////////////////////////////////////////////////////////////////////////////////////////////// - // //DUPLICATE - // // - // internal async Task DuplicateAsync(long id) - // { - // Report dbObject = await GetAsync(id, false); - // if (dbObject == null) - // { - // AddError(ApiErrorCode.NOT_FOUND, "id"); - // return null; - // } - // Report newObject = new Report(); - - // CopyObject.Copy(dbObject, newObject); - // string newUniqueName = string.Empty; - // bool NotUnique = true; - // long l = 1; - // do - // { - // newUniqueName = Util.StringUtil.UniqueNameBuilder(dbObject.Name, l++, 255); - // NotUnique = await ct.Report.AnyAsync(z => z.Name == newUniqueName); - // } while (NotUnique); - // newObject.Name = newUniqueName; - // newObject.Id = 0; - // newObject.Concurrency = 0; - // await ct.Report.AddAsync(newObject); - // await ct.SaveChangesAsync(); - // await EventLogProcessor.LogEventToDatabaseAsync(new Event(UserId, newObject.Id, BizType, AyaEvent.Created), ct); - // await SearchIndexAsync(newObject, true); - // return newObject; - // } - - + //////////////////////////////////////////////////////////////////////////////////////////////// //IMPORT // @@ -115,35 +82,7 @@ namespace AyaNova.Biz } while (NotUnique); newObject.Name = newUniqueName; - // This was stupid considering JObject can serialize directly to a report type - //but leaving in for a little while just to be sure it's all good - - // newObject.Active = (bool)o["Active"]; - // newObject.JsHelpers = (string)o["JsHelpers"]; - // newObject.JsPrerender = (string)o["JsPrerender"]; - // newObject.Notes = (string)o["Notes"]; - // newObject.AType = (AyaType)(int)o["AType"]; - // newObject.RenderType = (ReportRenderType)(int)o["RenderType"]; - // newObject.Roles = (AuthorizationRoles)(int)o["Roles"]; - // newObject.Style = (string)o["Style"]; - // newObject.Template = (string)o["Template"]; - // //pdf options - // newObject.HeaderTemplate = (string)o["HeaderTemplate"]; - // newObject.FooterTemplate = (string)o["FooterTemplate"]; - // newObject.MarginOptionsBottom = (string)o["MarginOptionsBottom"]; - // newObject.MarginOptionsLeft = (string)o["MarginOptionsLeft"]; - // newObject.MarginOptionsRight = (string)o["MarginOptionsRight"]; - // newObject.MarginOptionsTop = (string)o["MarginOptionsTop"]; - // newObject.PageRanges = (string)o["PageRanges"]; - - // newObject.PaperFormat = (ReportPaperFormat)(int)o["PaperFormat"]; - // newObject.DisplayHeaderFooter = (bool)o["DisplayHeaderFooter"]; - // newObject.Landscape = (bool)o["Landscape"]; - // newObject.PreferCSSPageSize = (bool)o["PreferCSSPageSize"]; - // newObject.PrintBackground = (bool)o["PrintBackground"]; - // newObject.Scale = (decimal)o["Scale"]; - - + await ValidateAsync(newObject, null); if (HasErrors) return false; await ct.Report.AddAsync(newObject); @@ -384,14 +323,16 @@ namespace AyaNova.Biz public async Task RenderReport(DataListReportRequest reportRequest, DateTime renderTimeOutExpiry, string apiUrl) { - var log = AyaNova.Util.ApplicationLogging.CreateLogger($"ReportBiz::RenderReport id {reportRequest.ReportId}, timeout @ {renderTimeOutExpiry.ToString()}"); - // #if (DEBUG) - // log.LogInformation($"DBG: ReportBiz::RenderReport called"); - // #endif + var log = AyaNova.Util.ApplicationLogging.CreateLogger("RenderReport"); + log.LogDebug($"ReportBiz::RenderReport id {reportRequest.ReportId}, timeout @ {renderTimeOutExpiry.ToString()}"); + + + //Customer User Report? bool RequestIsCustomerWorkOrderReport = false; if (reportRequest.ReportId == -100) { + log.LogTrace("customer user report requested"); //get the user and workorder data and set the actual report id or return null if not found var woTags = await ct.WorkOrder.AsNoTracking().Where(x => x.Id == reportRequest.SelectedRowIds[0]).Select(x => x.Tags).FirstOrDefaultAsync(); if (woTags == null) return null; @@ -405,9 +346,7 @@ namespace AyaNova.Biz throw new ReportRenderTimeOutException(); //get report, vet security, see what we need before init in case of issue - // #if (DEBUG) - // log.LogInformation($"DBG: ReportBiz::RenderReport get report from db"); - // #endif + log.LogTrace($"get report from db"); var report = await ct.Report.FirstOrDefaultAsync(z => z.Id == reportRequest.ReportId); if (report == null) { @@ -427,6 +366,7 @@ namespace AyaNova.Biz if (!RequestIsCustomerWorkOrderReport && !AyaNova.Api.ControllerHelpers.Authorized.HasReadFullRole(effectiveRoles, report.AType)) { + log.LogTrace($"bail: user unauthorized"); AddError(ApiErrorCode.NOT_AUTHORIZED, null, $"User not authorized for {report.AType} type object"); return null; } @@ -434,6 +374,7 @@ namespace AyaNova.Biz //Client meta data is required if (reportRequest.ClientMeta == null) { + log.LogTrace($"bail: ClientMeta parameter is missing"); AddError(ApiErrorCode.VALIDATION_MISSING_PROPERTY, null, "ClientMeta parameter is missing and required to render report"); return null; } @@ -447,10 +388,12 @@ namespace AyaNova.Biz // #if (DEBUG) // log.LogInformation($"DBG: ReportBiz::RenderReport GetReportData"); // #endif - var ReportData = await GetReportData(reportRequest, renderTimeOutExpiry, RequestIsCustomerWorkOrderReport);//###### TODO: SLOW NEEDS TIMEOUT HERE ONCE IT WORKS IS SUPPORTED + log.LogDebug("Getting report data now"); + var ReportData = await GetReportData(reportRequest, renderTimeOutExpiry, RequestIsCustomerWorkOrderReport); //if GetReportData errored then will return null so need to return that as well here if (ReportData == null) { + log.LogTrace($"bail: ReportData == null"); return null; } // #if (DEBUG) @@ -463,11 +406,11 @@ namespace AyaNova.Biz bool AutoDownloadChromium = true; if (string.IsNullOrWhiteSpace(ServerBootConfig.AYANOVA_REPORT_RENDER_BROWSER_PATH)) { - log.LogDebug($"Using default Chromium browser (downloaded)"); + log.LogTrace($"Using default Chromium browser (downloaded)"); } else { - log.LogDebug($"Using user specified Chromium browser at {ServerBootConfig.AYANOVA_REPORT_RENDER_BROWSER_PATH}"); + log.LogTrace($"Using user specified Chromium browser at {ServerBootConfig.AYANOVA_REPORT_RENDER_BROWSER_PATH}"); AutoDownloadChromium = false; } @@ -498,7 +441,7 @@ namespace AyaNova.Biz // #if (DEBUG) // log.LogInformation($"DBG: ReportBiz::calling browserfetcher"); // #endif - log.LogDebug($"Windows: Calling browserFetcher download async now:"); + log.LogTrace($"Windows: Calling browserFetcher download async now:"); await new BrowserFetcher().DownloadAsync(BrowserFetcher.DefaultChromiumRevision); } @@ -520,20 +463,15 @@ namespace AyaNova.Biz throw new ReportRenderTimeOutException(); //API DOCS http://www.puppeteersharp.com/api/index.html - log.LogDebug($"Launching headless Browser now:"); - // #if (DEBUG) - // log.LogInformation($"DBG: ReportBiz::launching browser now"); - // #endif + log.LogTrace($"Launching headless Browser now:"); using (var browser = await Puppeteer.LaunchAsync(lo)) - //using (var page = await browser.NewPageAsync()) using (var page = (await browser.PagesAsync())[0]) { - //track this process so it can be cancelled if it times out + //track this process for timeout purposes ReportRenderManager.AddProcess(browser.Process.Id, renderTimeOutExpiry, log); page.DefaultTimeout = 0;//infinite timeout as we are controlling how long the process can live for with the reportprocessmanager try { - //info and error logging page.Console += async (sender, args) => { @@ -558,7 +496,7 @@ namespace AyaNova.Biz } }; - log.LogDebug($"Preparing page: adding base reporting scripts to page"); + log.LogTrace($"Preparing page: adding base reporting scripts to page"); if (DateTime.UtcNow > renderTimeOutExpiry) throw new ReportRenderTimeOutException(); @@ -586,7 +524,7 @@ namespace AyaNova.Biz await page.EvaluateExpressionAsync("ayRegisterHelpers();"); if (DateTime.UtcNow > renderTimeOutExpiry) throw new ReportRenderTimeOutException(); - log.LogDebug($"Preparing page: adding this report's scripts, style and templates to page"); + log.LogTrace($"Preparing page: adding this report's scripts, style and templates to page"); //add report pre-render, helpers and style if (string.IsNullOrWhiteSpace(report.JsPrerender)) @@ -601,12 +539,12 @@ namespace AyaNova.Biz if (!string.IsNullOrWhiteSpace(report.Style)) await page.AddStyleTagAsync(new AddTagOptions() { Content = report.Style }); - log.LogDebug($"Preparing page: adding Client meta data"); + log.LogTrace($"Preparing page: adding Client meta data"); //Client meta data to JSON string var clientMeta = reportRequest.ClientMeta.ToString(); - log.LogDebug($"Preparing page: adding Server meta data"); + log.LogTrace($"Preparing page: adding Server meta data"); //Server meta data var logo = await ct.Logo.AsNoTracking().SingleOrDefaultAsync(); @@ -623,7 +561,7 @@ namespace AyaNova.Biz var HasStreetAddress = !string.IsNullOrWhiteSpace(ServerGlobalBizSettings.Cache.Address) ? "true" : "false"; var serverMeta = $"{{ayApiUrl:`{apiUrl}`, HasSmallLogo:{HasSmallLogo}, HasMediumLogo:{HasMediumLogo}, HasLargeLogo:{HasLargeLogo},CompanyName: `{AyaNova.Core.License.ActiveKey.RegisteredTo}`,CompanyWebAddress:`{ServerGlobalBizSettings.Cache.WebAddress}`,CompanyEmailAddress:`{ServerGlobalBizSettings.Cache.EmailAddress}`,CompanyPhone1:`{ServerGlobalBizSettings.Cache.Phone1}`,CompanyPhone2:`{ServerGlobalBizSettings.Cache.Phone2}`,HasPostalAddress:{HasPostalAddress},CompanyPostAddress:`{ServerGlobalBizSettings.Cache.PostAddress}`,CompanyPostCity:`{ServerGlobalBizSettings.Cache.PostCity}`,CompanyPostRegion:`{ServerGlobalBizSettings.Cache.PostRegion}`,CompanyPostCountry:`{ServerGlobalBizSettings.Cache.PostCountry}`,CompanyPostCode:`{ServerGlobalBizSettings.Cache.PostCode}`,HasStreetAddress:{HasStreetAddress},CompanyAddress:`{ServerGlobalBizSettings.Cache.Address}`,CompanyCity:`{ServerGlobalBizSettings.Cache.City}`,CompanyRegion:`{ServerGlobalBizSettings.Cache.Region}`,CompanyCountry:`{ServerGlobalBizSettings.Cache.Country}`,CompanyLatitude:{ServerGlobalBizSettings.Cache.Latitude},CompanyLongitude:{ServerGlobalBizSettings.Cache.Longitude}}}"; - log.LogDebug($"Preparing page: adding Report meta data"); + log.LogTrace($"Preparing page: adding Report meta data"); //Custom fields definition for report usage string CustomFieldsTemplate = "null"; @@ -643,26 +581,20 @@ namespace AyaNova.Biz if (DateTime.UtcNow > renderTimeOutExpiry) throw new ReportRenderTimeOutException(); - // #if (DEBUG) - // //view page contents - // var pagecontent = await page.GetContentAsync(); - // #endif + //#### DEBUGGING TOOL: view page contents + // var pagecontent = await page.GetContentAsync(); + //prePareData / preRender var ReportDataObject = $"{{ ayReportData:{ReportData}, ayReportMetaData:{reportMeta}, ayClientMetaData:{clientMeta}, ayServerMetaData:{serverMeta} }}"; - log.LogDebug($"Calling ayPreRender..."); - // #if (DEBUG) - // log.LogInformation($"DBG: ReportBiz::RenderReport - preRender"); - // #endif - //PRE_RENDER (WITH TIMEOUT???) + log.LogTrace($"Calling ayPreRender..."); + await page.WaitForExpressionAsync($"ayPreRender({ReportDataObject})"); if (DateTime.UtcNow > renderTimeOutExpiry) throw new ReportRenderTimeOutException(); //compile the template - log.LogDebug($"Calling Handlebars.compile..."); - // #if (DEBUG) - // log.LogInformation($"DBG: ReportBiz::RenderReport - compiling handlebars template"); - // #endif + log.LogTrace($"Calling Handlebars.compile..."); + var compileScript = $"Handlebars.compile(`{report.Template}`)(PreParedReportDataObject);"; if (DateTime.UtcNow > renderTimeOutExpiry) throw new ReportRenderTimeOutException(); @@ -670,16 +602,14 @@ namespace AyaNova.Biz if (DateTime.UtcNow > renderTimeOutExpiry) throw new ReportRenderTimeOutException(); //render report as HTML - log.LogDebug($"Setting page content to compiled HTML"); - // #if (DEBUG) - // log.LogInformation($"DBG: ReportBiz::RenderReport - settting html on page contents"); - // #endif + log.LogTrace($"Setting page content to compiled HTML"); + await page.SetContentAsync(compiledHTML); //add style (after page or it won't work) if (!string.IsNullOrWhiteSpace(report.Style)) { - log.LogDebug($"Adding report template Style CSS"); + log.LogTrace($"Adding report template Style CSS"); await page.AddStyleTagAsync(new AddTagOptions { Content = report.Style }); } @@ -689,10 +619,8 @@ namespace AyaNova.Biz //Set PDF options //https://pptr.dev/#?product=Puppeteer&version=v5.3.0&show=api-pagepdfoptions - log.LogDebug($"Resolving PDF Options from report settings"); - // #if (DEBUG) - // log.LogInformation($"DBG: ReportBiz::RenderReport - settting pdf options"); - // #endif + log.LogTrace($"Resolving PDF Options from report settings"); + var PdfOptions = new PdfOptions() { }; PdfOptions.DisplayHeaderFooter = report.DisplayHeaderFooter; @@ -769,30 +697,29 @@ namespace AyaNova.Biz if (DateTime.UtcNow > renderTimeOutExpiry) throw new ReportRenderTimeOutException(); //render to pdf and return - log.LogDebug($"Calling render page contents to PDF"); - // #if (DEBUG) - // log.LogInformation($"DBG: ReportBiz::RenderReport - rendering to pdf"); - // #endif + log.LogTrace($"Calling render page contents to PDF"); await page.PdfAsync(outputFullPath, PdfOptions);//###### TODO: SLOW NEEDS TIMEOUT HERE ONCE SUPPORTED, open bug: https://github.com/hardkoded/puppeteer-sharp/issues/1710 - log.LogDebug($"Closing Page and Browser"); + log.LogTrace($"Closing Page and Browser"); await page.CloseAsync(); await browser.CloseAsync(); - log.LogDebug($"Completed, returning results"); + log.LogTrace($"Completed, returning results"); return outputFileName; } catch (ReportRenderTimeOutException) { throw; } - catch(PuppeteerSharp.TargetClosedException){ + catch (PuppeteerSharp.TargetClosedException) + { //we closed it because the timeout hit and the CoreJobReportRenderEngineProcessCleanup job cleaned it out //so return the error the client expects in this scenario - throw new ReportRenderTimeOutException(); + throw new ReportRenderTimeOutException(); } catch (Exception ex) { + log.LogDebug(ex, $"Error during report rendering"); //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) @@ -801,7 +728,6 @@ namespace AyaNova.Biz log.LogInformation($"Exception caught while rendering report \"{report.Name}\", report Page console log:"); log.LogInformation(PageLog.ToString()); } - log.LogInformation(ex, "Error during report render:"); // var v=await page.GetContentAsync();//for debugging purposes throw; @@ -811,11 +737,12 @@ namespace AyaNova.Biz // #if (DEBUG) // log.LogInformation($"DBG: ReportBiz::RenderReport - closing browser"); // #endif - log.LogDebug($"Closing browser"); + log.LogTrace($"Closing Page and Browser"); if (!page.IsClosed) await page.CloseAsync(); if (!browser.IsClosed) await browser.CloseAsync(); + log.LogTrace($"Calling ReportRenderManager.RemoveProcess to stop tracking this process"); ReportRenderManager.RemoveProcess(browser.Process.Id, log); } } diff --git a/server/AyaNova/util/ReportProcessManager.cs b/server/AyaNova/util/ReportProcessManager.cs index 66478937..1a8de74c 100644 --- a/server/AyaNova/util/ReportProcessManager.cs +++ b/server/AyaNova/util/ReportProcessManager.cs @@ -42,9 +42,9 @@ namespace AyaNova.Util { if (i.Expires < dtNow) { -#if (DEBUG) - log.LogInformation($"DBG: KillExpiredRenders attempting kill of expired process {i.ReporterProcessId}"); -#endif +// #if (DEBUG) +// log.LogInformation($"DBG: KillExpiredRenders attempting kill of expired process {i.ReporterProcessId}"); +// #endif ForceCloseProcess(i, log); } }