Skip to content
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.

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

More logging improvements. #3001

Merged
merged 1 commit into from
May 26, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
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
22 changes: 14 additions & 8 deletions src/Microsoft.DotNet.Interactive/KernelCommandExtensions.cs
Original file line number Diff line number Diff line change
Expand Up @@ -12,24 +12,30 @@ internal static class KernelCommandExtensions
internal static void StampRoutingSlipAndLog(this KernelCommand command, Uri uri)
{
command.RoutingSlip.Stamp(uri);
Logger.Log.RoutingSlipInfo(command);
Logger.Log.RoutingSlipInfo(command, uri);
}

internal static void StampRoutingSlipAsAndLog(this KernelCommand command, Uri uri, string tag)
{
command.RoutingSlip.StampAs(uri, tag);
Logger.Log.RoutingSlipInfo(command);
Logger.Log.RoutingSlipInfo(command, uri, tag);
}

internal static void StampRoutingSlipAsArrivedAndLog(this KernelCommand command, Uri uri)
{
command.RoutingSlip.StampAsArrived(uri);
Logger.Log.RoutingSlipInfo(command);
Logger.Log.RoutingSlipInfo(command, uri, tag: "arrived");
}

private static void RoutingSlipInfo(this Logger logger, KernelCommand command) =>
logger.Info(
"➡️ {0} {1}",
command.GetType().Name,
command.RoutingSlip);
private static void RoutingSlipInfo(this Logger logger, KernelCommand command, Uri uri, string tag = null)
{
if (string.IsNullOrEmpty(tag))
{
logger.Info("➡️ {0} {1}", command.GetType().Name, uri.ToString());
}
else
{
logger.Info("➡️ {0} {1} ({2})", command.GetType().Name, uri.ToString(), tag);
}
}
}
24 changes: 18 additions & 6 deletions src/Microsoft.DotNet.Interactive/KernelEventExtensions.cs
Original file line number Diff line number Diff line change
Expand Up @@ -65,13 +65,25 @@ private static IReadOnlyCollection<Diagnostic> RemapDiagnosticsFromLanguageNode(

internal static void StampRoutingSlipAndLog(this KernelEvent @event, Uri uri)
{
if (@event.RoutingSlip.Count == 0)
{
// Log detailed event info if this is the first time the routing slip is being updated.
Logger.Log.Info("{event}", @event);
}

@event.RoutingSlip.Stamp(uri);
Logger.Log.RoutingSlipInfo(@event);
Logger.Log.RoutingSlipInfo(@event, uri);
}

private static void RoutingSlipInfo(this Logger logger, KernelEvent @event) =>
logger.Info(
"⬅️ {0} {1}",
@event.GetType().Name,
@event.RoutingSlip);
private static void RoutingSlipInfo(this Logger logger, KernelEvent @event, Uri uri, string tag = null)
{
if (string.IsNullOrEmpty(tag))
{
logger.Info("⬅️ {0} {1}", @event.GetType().Name, uri.ToString());
}
else
{
logger.Info("⬅️ {0} {1} ({2})", @event.GetType().Name, uri.ToString(), tag);
}
}
}
4 changes: 0 additions & 4 deletions src/Microsoft.DotNet.Interactive/KernelInvocationContext.cs
Original file line number Diff line number Diff line change
Expand Up @@ -39,10 +39,6 @@ private KernelInvocationContext(KernelCommand command)
{
var operation = new OperationLogger(
args: new object[] { command },
exitArgs: () => new[]
{
(nameof(KernelCommand), (object)command)
},
category: nameof(KernelInvocationContext),
logOnStart: true);

Expand Down
5 changes: 0 additions & 5 deletions src/dotnet-interactive/CommandLine/CommandLineParser.cs
Original file line number Diff line number Diff line change
Expand Up @@ -514,11 +514,6 @@ private static CompositeKernel CreateKernel(
.AddConnectionOptions(new JupyterHttpKernelConnectionOptions())
.AddConnectionOptions(new JupyterLocalKernelConnectionOptions()));

if (startupOptions.Verbose)
{
kernel.LogEventsToPocketLogger();
}

SetUpFormatters(frontendEnvironment);

kernel.DefaultKernelName = defaultKernelName;
Expand Down
49 changes: 44 additions & 5 deletions src/dotnet-interactive/Pocket/Format.CustomizeLogString.cs
Original file line number Diff line number Diff line change
Expand Up @@ -153,10 +153,6 @@ private static void AppendLogString(this TextWriter writer, KernelEvent @event)
writer.Write(completionsProduced.LinePositionSpan?.ToString());
break;

case DiagnosticLogEntryProduced diagnosticLogEntryProduced:
writer.Write(diagnosticLogEntryProduced.Message.TruncateForDisplay());
break;

case DiagnosticsProduced diagnosticsProduced:
var diagnostics = diagnosticsProduced.Diagnostics;
if (diagnostics.Any()) // TODO: How come we produce empty DiagnosticsProduced events?
Expand Down Expand Up @@ -199,8 +195,51 @@ private static void AppendLogString(this TextWriter writer, KernelEvent @event)
writer.Write(inputProduced.Value.TruncateForDisplay());
break;

case KernelInfoProduced kernelInfoProduced:
writer.AppendProperties(
(nameof(kernelInfoProduced.KernelInfo.LocalName), kernelInfoProduced.KernelInfo.LocalName),
(nameof(kernelInfoProduced.KernelInfo.Uri), kernelInfoProduced.KernelInfo.Uri.ToString()),
(nameof(kernelInfoProduced.KernelInfo.IsComposite), kernelInfoProduced.KernelInfo.IsComposite.ToString()),
(nameof(kernelInfoProduced.KernelInfo.IsProxy), kernelInfoProduced.KernelInfo.IsProxy.ToString()),
(nameof(kernelInfoProduced.KernelInfo.RemoteUri), kernelInfoProduced.KernelInfo.RemoteUri?.ToString()));
break;

case KernelReady kernelReady:
writer.Write('(');
writer.Write(kernelReady.KernelInfos.Length);
writer.Write(" Kernels)");
break;

case PackageAdded packageAdded:
writer.Write(packageAdded.PackageReference);
writer.Write(packageAdded.PackageReference.ToString());
break;

case SignatureHelpProduced signatureHelpProduced:
writer.Write('(');
writer.Write(signatureHelpProduced.Signatures?.Count ?? 0);
writer.Write(" Signatures)");
writer.AppendProperties(
(nameof(signatureHelpProduced.ActiveSignatureIndex), signatureHelpProduced.ActiveSignatureIndex.ToString()),
(nameof(signatureHelpProduced.ActiveParameterIndex), signatureHelpProduced.ActiveParameterIndex.ToString()));
break;

case ValueInfosProduced valueInfosProduced:
writer.Write('(');
writer.Write(valueInfosProduced.ValueInfos.Count);
writer.Write(" Values)");
break;

case ValueProduced valueProduced:
writer.Write(valueProduced.Name);
writer.Write(" '");
writer.Write(valueProduced.FormattedValue.Value.TruncateForDisplay());
writer.Write("' (");
writer.Write(valueProduced.FormattedValue.MimeType);
writer.Write(')');
break;

case WorkingDirectoryChanged workingDirectoryChanged:
writer.Write(workingDirectoryChanged.WorkingDirectory.TruncateForDisplay());
break;

// Base event types.
Expand Down