Skip to content

Add eventType to logs#101

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
Simon Porter (simonporter) merged 8 commits into from
Jul 3, 2017
Merged

Add eventType to logs #101

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
8 commits
Select commit Hold shift + click to select a range
d0467cb
Add missing docs, package info and bugfixes
Jun 30, 2017
2d82253
Add EventType to all tracing, fix trace formatting
Jun 30, 2017
14b269d
Fix typos
Jun 30, 2017
8e06b0c
cr comments
Jul 1, 2017
d97f315
Merge branch 'siport/packageinfo' into siport/eventtype
Jul 1, 2017
d32d68d
Merge branch 'vnext' into siport/eventtype
Jul 1, 2017
bc8dd5a
Fix the possible null ref when cancelling the orchestration
Jul 3, 2017
ee28ab7
Wholesale fix of spelling of Entities
Jul 3, 2017
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
5 changes: 5 additions & 0 deletions Test/DurableTask.Test.Orchestrations/DurableTask.Test.Orchestrations.csproj
View file
Open in desktop
Original file line numberDiff line numberDiff line change
Expand Up@@ -4,6 +4,11 @@
<PropertyGroup>
<TargetFramework>net451</TargetFramework>
</PropertyGroup>

<ItemGroup>
<PackageReference Include="Newtonsoft.Json" version="7.0.1" />
</ItemGroup>

<ItemGroup>
<ProjectReference Include="..\..\src\DurableTask.Core\DurableTask.Core.csproj" />
</ItemGroup>
Expand Down
19 changes: 13 additions & 6 deletions src/DurableTask.Core/Common/Utils.cs
View file
Open in desktop
Original file line numberDiff line numberDiff line change
Expand Up@@ -221,7 +221,10 @@ public static async Task ExecuteWithRetries(Func<Task> retryAction, string sessi
}
catch (Exception exception) when (!Utils.IsFatal(exception))
{
TraceHelper.TraceSession(TraceEventType.Warning, sessionId,
TraceHelper.TraceSession(
TraceEventType.Warning,
"ExecuteWithRetry-Failure",
sessionId,
$"Error attempting operation {operation}. Attempt count: {numberOfAttempts - retryCount}. Exception: {exception.Message}\n\t{exception.StackTrace}");
lastException = exception;
}
Expand All@@ -231,8 +234,8 @@ public static async Task ExecuteWithRetries(Func<Task> retryAction, string sessi

if (retryCount <= 0 && lastException != null)
{
TraceHelper.Trace(TraceEventType.Error, "Exhausted all retries for operation " + operation);
throw TraceHelper.TraceExceptionSession(TraceEventType.Error, sessionId, lastException);
TraceHelper.Trace(TraceEventType.Error, "ExecuteWithRetry-RetriesExhausted", "Exhausted all retries for operation " + operation);
throw TraceHelper.TraceExceptionSession(TraceEventType.Error, "ExecuteWithRetryRetriesExhausted", sessionId, lastException);
}
}

Expand All@@ -254,7 +257,10 @@ public static async Task<T> ExecuteWithRetries<T>(Func<Task<T>> retryAction, str
}
catch (Exception exception) when (!Utils.IsFatal(exception))
{
TraceHelper.TraceSession(TraceEventType.Warning, sessionId,
TraceHelper.TraceSession(
TraceEventType.Warning,
$"ExecuteWithRetry<{typeof(T)}>-Failure",

@rajeevmvRajeev Vokkarne (rajeevmv)Jul 3, 2017

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

typeof [](start = 44, length = 6)

Should this be 'nameof' instead?

@simonporterSimon Porter (simonporter)Jul 3, 2017

Copy link
Copy Markdown
ContributorAuthor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

typeof works in this case as its the signature of the method call rather than a case like a param where nameof would be used

sessionId,
$"Error attempting operation {operation}. Attempt count: {numberOfAttempts - retryCount}. Exception: {exception.Message}\n\t{exception.StackTrace}");
lastException = exception;
}
Expand All@@ -264,8 +270,9 @@ public static async Task<T> ExecuteWithRetries<T>(Func<Task<T>> retryAction, str

if (retryCount <= 0 && lastException != null)
{
TraceHelper.Trace(TraceEventType.Error, "Exhausted all retries for operation " + operation);
throw TraceHelper.TraceExceptionSession(TraceEventType.Error, sessionId, lastException);
var eventType = $"ExecuteWithRetry<{typeof(T)}>-Failure";

@rajeevmvRajeev Vokkarne (rajeevmv)Jul 3, 2017

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

typeof [](start = 52, length = 6)

Same comment as above

TraceHelper.Trace(TraceEventType.Error, eventType, "Exhausted all retries for operation " + operation);
throw TraceHelper.TraceExceptionSession(TraceEventType.Error, eventType, sessionId, lastException);
}

return retVal;
Expand Down
12 changes: 6 additions & 6 deletions src/DurableTask.Core/IOrchestrationServiceInstanceStore.cs
View file
Open in desktop
Original file line numberDiff line numberDiff line change
Expand Up@@ -44,21 +44,21 @@ public interface IOrchestrationServiceInstanceStore
/// Writes a list of history events to instance store
/// </summary>
/// <param name="entities">List of history events to write</param>
Task<object> WriteEntitesAsync(IEnumerable<InstanceEntityBase> entities);
Task<object> WriteEntitiesAsync(IEnumerable<InstanceEntityBase> entities);

/// <summary>
/// Get a list of state events from instance store
/// </summary>
/// <param name="instanceId">The instance id to return state for</param>
/// <param name="executionId">The execution id to return state for</param>
/// <returns>The matching orchestation state or null if not found</returns>
Task<IEnumerable<OrchestrationStateInstanceEntity>> GetEntitesAsync(string instanceId, string executionId);
Task<IEnumerable<OrchestrationStateInstanceEntity>> GetEntitiesAsync(string instanceId, string executionId);

/// <summary>
/// Deletes a list of history events from instance store
/// </summary>
/// <param name="entities">List of history events to delete</param>
Task<object> DeleteEntitesAsync(IEnumerable<InstanceEntityBase> entities);
Task<object> DeleteEntitiesAsync(IEnumerable<InstanceEntityBase> entities);

/// <summary>
/// Gets a list of orchestration states for a given instance
Expand DownExpand Up@@ -96,18 +96,18 @@ public interface IOrchestrationServiceInstanceStore
/// Writes a list of jump start events to instance store
/// </summary>
/// <param name="entities">List of jump start events to write</param>
Task<object> WriteJumpStartEntitesAsync(IEnumerable<OrchestrationJumpStartInstanceEntity> entities);
Task<object> WriteJumpStartEntitiesAsync(IEnumerable<OrchestrationJumpStartInstanceEntity> entities);

/// <summary>
/// Deletes a list of jump start events from instance store
/// </summary>
/// <param name="entities">List of jump start events to delete</param>
Task<object> DeleteJumpStartEntitesAsync(IEnumerable<OrchestrationJumpStartInstanceEntity> entities);
Task<object> DeleteJumpStartEntitiesAsync(IEnumerable<OrchestrationJumpStartInstanceEntity> entities);

/// <summary>
/// Get a list of jump start events from instance store
/// </summary>
/// <returns>List of jump start events</returns>
Task<IEnumerable<OrchestrationJumpStartInstanceEntity>> GetJumpStartEntitesAsync(int top);
Task<IEnumerable<OrchestrationJumpStartInstanceEntity>> GetJumpStartEntitiesAsync(int top);
}
}
2 changes: 1 addition & 1 deletion src/DurableTask.Core/RetryInterceptor.cs
View file
Open in desktop
Original file line numberDiff line numberDiff line change
Expand Up@@ -94,7 +94,7 @@ TimeSpan ComputeNextDelay(int attempt, DateTime firstAttempt, Exception failure)
catch (Exception e) when (!Utils.IsFatal(e))
{
// Catch any exceptions during ComputeNextDelay so we don't override original error with new error
TraceHelper.TraceExceptionInstance(TraceEventType.Error, context.OrchestrationInstance, e);
TraceHelper.TraceExceptionInstance(TraceEventType.Error, "RetryInterceptor-ComputeNextDelayException", context.OrchestrationInstance, e);
}

return nextDelay;
Expand Down
11 changes: 10 additions & 1 deletion src/DurableTask.Core/Serializing/RuntimeStateStreamConverter.cs
View file
Open in desktop
Original file line numberDiff line numberDiff line change
Expand Up@@ -71,7 +71,9 @@ public static async Task<Stream> OrchestrationRuntimeStateToRawStream(

if (runtimeState.CompressedSize > serviceBusSessionSettings.SessionOverflowThresholdInBytes)
{
TraceHelper.TraceSession(TraceEventType.Information,
TraceHelper.TraceSession(
TraceEventType.Information,
"RuntimeStateStreamConverter-SessionStateThresholdExceeded",
sessionId,
$"Session state size of {runtimeState.CompressedSize} exceeded the termination threshold of {serviceBusSessionSettings.SessionOverflowThresholdInBytes} bytes." +
$"Creating an OrchestrationSessionState instance with key for exteranl storage.");
Expand DownExpand Up@@ -99,6 +101,7 @@ async static Task<Stream> CreateStreamForExternalStorageAsync(
string key = orchestrationServiceBlobStore.BuildSessionBlobKey(sessionId);
TraceHelper.TraceSession(
TraceEventType.Information,
"RuntimeStateStreamConverter-SaveSessionToStorage",
sessionId,
$"Saving the serialized stream in external storage with key {key}.");

Expand DownExpand Up@@ -143,6 +146,7 @@ public static async Task<OrchestrationRuntimeState> RawStreamToRuntimeState(Stre
{
TraceHelper.TraceSession(
TraceEventType.Information,
"RuntimeStateStreamConverter-StreamToRuntimeStateSize",
sessionId,
$"Size of session state is {newSessionStateSize}, compressed {rawSessionStateSize}");
return runtimeState;
Expand All@@ -156,6 +160,7 @@ public static async Task<OrchestrationRuntimeState> RawStreamToRuntimeState(Stre

TraceHelper.TraceSession(
TraceEventType.Information,
"RuntimeStateStreamConverter-StreamToRuntimeStateLoadFromStorage",
sessionId,
$"Loading the serialzied stream from external storage with blob key {blobKey}.");

Expand All@@ -171,6 +176,7 @@ static OrchestrationRuntimeState GetOrCreateInstanceState(Stream stateStream, st
{
TraceHelper.TraceSession(
TraceEventType.Information,
"RuntimeStateStreamConverter-GetOrCreateInstanceStateNewSession",
sessionId,
"No session state exists, creating new session state.");
runtimeState = new OrchestrationRuntimeState();
Expand All@@ -181,6 +187,7 @@ static OrchestrationRuntimeState GetOrCreateInstanceState(Stream stateStream, st
{
throw TraceHelper.TraceExceptionSession(
TraceEventType.Error,
"RuntimeStateStreamConverter-GetOrCreateInstanceStatePartiallyConsumed",
sessionId,
new ArgumentException("Stream is partially consumed"));
}
Expand DownExpand Up@@ -228,6 +235,7 @@ static OrchestrationRuntimeState DeserializeToRuntimeStateWithFallback(string se
{
TraceHelper.TraceSession(
TraceEventType.Warning,
"RuntimeStateStreamConverter-DeserializeToRuntimeStateFailed",
sessionId,
$"Failed to deserialize session state to OrchestrationSessionState object: {serializedState}. More info: {exception.StackTrace}");
try
Expand All@@ -241,6 +249,7 @@ static OrchestrationRuntimeState DeserializeToRuntimeStateWithFallback(string se
{
TraceHelper.TraceSession(
TraceEventType.Warning,
"RuntimeStateStreamConverter-DeserializeToRuntimeStateException",
sessionId,
$"Failed to deserialize session state to OrchestrationRuntimeState object: {serializedState}. More info: {e.StackTrace}");

Expand Down
18 changes: 11 additions & 7 deletions src/DurableTask.Core/TaskActivityDispatcher.cs
View file
Open in desktop
Original file line numberDiff line numberDiff line change
Expand Up@@ -94,12 +94,16 @@ async Task OnProcessWorkItemAsync(TaskActivityWorkItem workItem)
OrchestrationInstance orchestrationInstance = taskMessage.OrchestrationInstance;
if (string.IsNullOrWhiteSpace(orchestrationInstance?.InstanceId))
{
throw TraceHelper.TraceException(TraceEventType.Error,
throw TraceHelper.TraceException(
TraceEventType.Error,
"TaskActivityDispatcher-MissingOrchestrationInstance",
new InvalidOperationException("Message does not contain any OrchestrationInstance information"));
}
if (taskMessage.Event.EventType != EventType.TaskScheduled)
{
throw TraceHelper.TraceException(TraceEventType.Critical,
throw TraceHelper.TraceException(
TraceEventType.Critical,
"TaskActivityDispatcher-UnsupportedEventType",
new NotSupportedException("Activity worker does not support event of type: " +
taskMessage.Event.EventType));
}
Expand DownExpand Up@@ -132,13 +136,13 @@ await this.dispatchPipeline.RunAsync(dispatchContext, async _ =>
}
catch (TaskFailureException e)
{
TraceHelper.TraceExceptionInstance(TraceEventType.Error, taskMessage.OrchestrationInstance, e);
TraceHelper.TraceExceptionInstance(TraceEventType.Error, "TaskActivityDispatcher-ProcessTaskFailure", taskMessage.OrchestrationInstance, e);
string details = IncludeDetails ? e.Details : null;
eventToRespond = new TaskFailedEvent(-1, scheduledEvent.EventId, e.Message, details);
}
catch (Exception e) when (!Utils.IsFatal(e))
{
TraceHelper.TraceExceptionInstance(TraceEventType.Error, taskMessage.OrchestrationInstance, e);
TraceHelper.TraceExceptionInstance(TraceEventType.Error, "TaskActivityDispatcher-ProcessException", taskMessage.OrchestrationInstance, e);
string details = IncludeDetails
? $"Unhandled exception while executing task: {e}\n\t{e.StackTrace}"
: null;
Expand DownExpand Up@@ -192,16 +196,16 @@ async void RenewUntil(TaskActivityWorkItem workItem, CancellationToken cancellat

try
{
TraceHelper.Trace(TraceEventType.Information, "Renewing lock for workitem id {0}", workItem.Id);
TraceHelper.Trace(TraceEventType.Information, "TaskActivityDispatcher-RenewLock", "Renewing lock for workitem id {0}", workItem.Id);
workItem = await this.orchestrationService.RenewTaskActivityWorkItemLockAsync(workItem);
renewAt = workItem.LockedUntilUtc.Subtract(TimeSpan.FromSeconds(30));
renewAt = AdjustRenewAt(renewAt);
TraceHelper.Trace(TraceEventType.Information, "Next renew for workitem id '{0}' at '{1}'", workItem.Id, renewAt);
TraceHelper.Trace(TraceEventType.Information, "TaskActivityDispatcher-RenewLockAt", "Next renew for workitem id '{0}' at '{1}'", workItem.Id, renewAt);
}
catch (Exception exception) when (!Utils.IsFatal(exception))
{
// might have been completed
TraceHelper.TraceException(TraceEventType.Warning, exception, "Failed to renew lock for workitem {0}", workItem.Id);
TraceHelper.TraceException(TraceEventType.Warning, "TaskActivityDispatcher-RenewLockFailure", exception, "Failed to renew lock for workitem {0}", workItem.Id);
break;
}
}
Expand Down
1 change: 1 addition & 0 deletions src/DurableTask.Core/TaskOrchestrationContext.cs
View file
Open in desktop
Original file line numberDiff line numberDiff line change
Expand Up@@ -365,6 +365,7 @@ private void LogDuplicateEvent(string source, HistoryEvent historyEvent, int tas
{
TraceHelper.TraceSession(
TraceEventType.Warning,
"TaskOrchestrationContext-DuplicateEvent",
this.OrchestrationInstance.InstanceId,
"Duplicate {0} Event: {1}, type: {2}, ts: {3}",
source,
Expand Down
Loading