diff --git a/Src/Witsml/Helpers/MeasurementHelper.cs b/Src/Witsml/Helpers/MeasurementHelper.cs new file mode 100644 index 000000000..f3295bde4 --- /dev/null +++ b/Src/Witsml/Helpers/MeasurementHelper.cs @@ -0,0 +1,57 @@ +using System; +using System.Diagnostics; +using System.Linq; +using System.Threading.Tasks; + +using Serilog; + +namespace Witsml.Helpers; + +/// +/// The class allows customization of the message for execution time logging. +/// +public class TimeMeasurer +{ + /// + /// Gets or sets a delegate that takes an elapsed time in milliseconds and returns a log message. + /// + public Func LogMessage { get; set; } +} + +/// +/// Measures execution time of code and logging. +/// +public static class MeasurementHelper +{ + private const int MeasuredMethodNameStackTraceFrameDepth = 5; + + /// + /// Measures the execution time of an asynchronous operation and provides the ability to customize the logging message. + /// + /// A delegate representing the asynchronous operation to be measured. + /// The type of result returned by the asynchronous operation. + /// An asynchronous task that represents the result of the measured operation. + public static async Task MeasureExecutionTimeAsync(Func> measureCode) + { + var timeMeasurer = new TimeMeasurer(); + var stopwatch = new Stopwatch(); + var measuredMethodName = new StackTrace().GetFrames().Skip(MeasuredMethodNameStackTraceFrameDepth).FirstOrDefault()?.GetMethod()?.Name; + + stopwatch.Start(); + + TResult result = await measureCode(timeMeasurer); + + stopwatch.Stop(); + + if (timeMeasurer.LogMessage != null) + { + Log.Debug(timeMeasurer.LogMessage(stopwatch.ElapsedMilliseconds)); + } + else + { + Log.Debug("The execution of the method '{MeasuredMethodName}' finished in {ElapsedMilliseconds}ms.", measuredMethodName, stopwatch.ElapsedMilliseconds); + } + + return result; + } +} diff --git a/Src/WitsmlExplorer.Api/Services/MessageObjectService.cs b/Src/WitsmlExplorer.Api/Services/MessageObjectService.cs index ae858c177..7ec16d28c 100644 --- a/Src/WitsmlExplorer.Api/Services/MessageObjectService.cs +++ b/Src/WitsmlExplorer.Api/Services/MessageObjectService.cs @@ -1,11 +1,9 @@ -using System; using System.Collections.Generic; using System.Linq; using System.Threading.Tasks; -using Serilog; - using Witsml.Data; +using Witsml.Helpers; using Witsml.ServiceReference; using WitsmlExplorer.Api.Models; @@ -35,14 +33,16 @@ public async Task GetMessageObject(string wellUid, string wellbor public async Task> GetMessageObjects(string wellUid, string wellboreUid) { - DateTime start = DateTime.Now; - WitsmlMessages witsmlMessage = MessageQueries.GetMessageByWellbore(wellUid, wellboreUid); - WitsmlMessages result = await _witsmlClient.GetFromStoreAsync(witsmlMessage, new OptionsIn(ReturnElements.Requested)); - List messageObjects = result.Messages - .Select(FromWitsml).OrderBy((m) => m.DTim).ToList(); - double elapsed = DateTime.Now.Subtract(start).Milliseconds / 1000.0; - Log.Debug("Fetched {Count} messageobjects from {WellboreName} in {Elapsed} seconds", messageObjects.Count, messageObjects.FirstOrDefault()?.WellboreName, elapsed); - return messageObjects; + return await MeasurementHelper.MeasureExecutionTimeAsync(async (timeMeasurer) => + { + WitsmlMessages witsmlMessage = MessageQueries.GetMessageByWellbore(wellUid, wellboreUid); + WitsmlMessages result = await _witsmlClient.GetFromStoreAsync(witsmlMessage, new OptionsIn(ReturnElements.Requested)); + List messageObjects = result.Messages + .Select(FromWitsml).OrderBy((m) => m.DTim).ToList(); + timeMeasurer.LogMessage = executionTime => + $"Fetched {messageObjects.Count} messageObjects from {messageObjects.FirstOrDefault()?.WellboreName} in {executionTime}ms."; + return messageObjects; + }); } private static MessageObject FromWitsml(WitsmlMessage message) diff --git a/Src/WitsmlExplorer.Api/Services/WellService.cs b/Src/WitsmlExplorer.Api/Services/WellService.cs index 593799484..07afe1158 100644 --- a/Src/WitsmlExplorer.Api/Services/WellService.cs +++ b/Src/WitsmlExplorer.Api/Services/WellService.cs @@ -1,13 +1,9 @@ -using System; -using System.Collections; using System.Collections.Generic; -using System.Diagnostics; using System.Linq; using System.Threading.Tasks; -using Serilog; - using Witsml.Data; +using Witsml.Helpers; using Witsml.ServiceReference; using WitsmlExplorer.Api.Models; @@ -48,30 +44,30 @@ public async Task> GetWells() private async Task> GetWellsInformation(string wellUid = null) { - var stopwatch = new Stopwatch(); - stopwatch.Start(); - WitsmlWells witsmlWells = string.IsNullOrEmpty(wellUid) ? WellQueries.GetAllWitsmlWells() : WellQueries.GetWitsmlWellByUid(wellUid); - WitsmlWells result = await _witsmlClient.GetFromStoreAsync(witsmlWells, new OptionsIn(ReturnElements.Requested)); - List wells = result.Wells - .Select(well => new Well - { - Uid = well.Uid, - Name = well.Name, - Field = well.Field, - Operator = well.Operator, - NumLicense = well.NumLicense, - TimeZone = well.TimeZone, - DateTimeCreation = well.CommonData.DTimCreation, - DateTimeLastChange = well.CommonData.DTimLastChange, - ItemState = well.CommonData.ItemState, - StatusWell = well.StatusWell, - PurposeWell = well.PurposeWell, - Country = well.Country - } - ).ToList(); - stopwatch.Stop(); - Log.Debug("Fetched {Count} wells in {Elapsed} ms", wells.Count, stopwatch.ElapsedMilliseconds); - return wells; + return await MeasurementHelper.MeasureExecutionTimeAsync(async (timeMeasurer) => + { + WitsmlWells witsmlWells = string.IsNullOrEmpty(wellUid) ? WellQueries.GetAllWitsmlWells() : WellQueries.GetWitsmlWellByUid(wellUid); + WitsmlWells result = await _witsmlClient.GetFromStoreAsync(witsmlWells, new OptionsIn(ReturnElements.Requested)); + List wells = result.Wells + .Select(well => new Well + { + Uid = well.Uid, + Name = well.Name, + Field = well.Field, + Operator = well.Operator, + NumLicense = well.NumLicense, + TimeZone = well.TimeZone, + DateTimeCreation = well.CommonData.DTimCreation, + DateTimeLastChange = well.CommonData.DTimLastChange, + ItemState = well.CommonData.ItemState, + StatusWell = well.StatusWell, + PurposeWell = well.PurposeWell, + Country = well.Country + } + ).ToList(); + timeMeasurer.LogMessage = executionTime => $"Fetched {wells.Count} wells in {executionTime} ms."; + return wells; + }); } public async Task GetWell(string wellUid) diff --git a/Src/WitsmlExplorer.Api/Services/WellboreService.cs b/Src/WitsmlExplorer.Api/Services/WellboreService.cs index c8bb5cdfb..9d4546502 100644 --- a/Src/WitsmlExplorer.Api/Services/WellboreService.cs +++ b/Src/WitsmlExplorer.Api/Services/WellboreService.cs @@ -1,12 +1,9 @@ -using System; using System.Collections.Generic; -using System.Diagnostics; using System.Linq; using System.Threading.Tasks; -using Serilog; - using Witsml.Data; +using Witsml.Helpers; using Witsml.ServiceReference; using WitsmlExplorer.Api.Models; @@ -68,29 +65,28 @@ public async Task GetWellbore(string wellUid, string wellboreUid) public async Task> GetWellbores(string wellUid = "") { - var stopwatch = new Stopwatch(); - stopwatch.Start(); - WitsmlWellbores query = WellboreQueries.GetWitsmlWellboreByWell(wellUid); - - WitsmlWellbores result = await _witsmlClient.GetFromStoreAsync(query, new OptionsIn(ReturnElements.Requested)); - List wellbores = result.Wellbores - .Select(witsmlWellbore => - new Wellbore - { - Uid = witsmlWellbore.Uid, - Name = witsmlWellbore.Name, - WellUid = witsmlWellbore.UidWell, - WellName = witsmlWellbore.NameWell, - WellStatus = witsmlWellbore.StatusWellbore, - WellType = witsmlWellbore.TypeWellbore, - IsActive = StringHelpers.ToBooleanSafe(witsmlWellbore.IsActive), - DateTimeLastChange = witsmlWellbore.CommonData.DTimLastChange, - DateTimeCreation = witsmlWellbore.CommonData.DTimCreation - }) - .OrderBy(wellbore => wellbore.Name).ToList(); - stopwatch.Stop(); - Log.Debug("Fetched {Count} wellbores in {Elapsed} ms", wellbores.Count, stopwatch.ElapsedMilliseconds); - return wellbores; + return await MeasurementHelper.MeasureExecutionTimeAsync(async (timeMeasurer) => + { + WitsmlWellbores query = WellboreQueries.GetWitsmlWellboreByWell(wellUid); + WitsmlWellbores result = await _witsmlClient.GetFromStoreAsync(query, new OptionsIn(ReturnElements.Requested)); + List wellbores = result.Wellbores + .Select(witsmlWellbore => + new Wellbore + { + Uid = witsmlWellbore.Uid, + Name = witsmlWellbore.Name, + WellUid = witsmlWellbore.UidWell, + WellName = witsmlWellbore.NameWell, + WellStatus = witsmlWellbore.StatusWellbore, + WellType = witsmlWellbore.TypeWellbore, + IsActive = StringHelpers.ToBooleanSafe(witsmlWellbore.IsActive), + DateTimeLastChange = witsmlWellbore.CommonData.DTimLastChange, + DateTimeCreation = witsmlWellbore.CommonData.DTimCreation + }) + .OrderBy(wellbore => wellbore.Name).ToList(); + timeMeasurer.LogMessage = executionTime => $"Fetched {wellbores.Count} wellbores in {executionTime} ms."; + return wellbores; + }); } } }