campus days 2013 - instrumentation

Developer

Anders Lybecker

Logging, tracing, instrumentering, debugging og fejlfinding

Technical EvangelistMicrosoft

Agenda

Logging, tracing, instrumentering, debugging og fejlfinding

• Instrumentation• End-to-End Tracing• Historical Debugging• Semantic Logging

Instrumentation

Instrumentation

• The ability to monitor or measure a running system• Trace program flow• Log errors• Diagnose performance issues

• Consumers• System Administrators• Major program flow events• Critical issues• Performance Counters

• Developers• Program flow with state• Verbose – call parameters etc.

• You are blind without!• Fixing bugs faster• Documentation• Quality

Instrumentation - Tools

• Developer• Log files• IntelliTrace• Windows EventLog• Memory Dumps• Event Tracing for Windows

• System Administrators• Windows EventLog• System Service Center

What to Instrument

• Program flow• Major state changes

• Life-cycle events• Start, stop, restart

• Some exceptions• Not validation errors etc.

• Security related events• Login attempts

• Logging• Errors• Focus on external dependencies

• I/O, Database, Web Service Requests

• Correlate entries!!!

How to Log - Log Levels

• Critical• System is unable to run• insufficient resource• access to file system• database connectivity• application start up failures• invalid config settings

• Administrator attention required

• Error• Exceptions that interrupts the user's

actions

• Warning• Resumable “errors”• Login attempts• SLA violation

• Information• Life-cycle events• Major events

• Trace• Program flow with state• Order initiated• Order approved• Order send

• Debug• Verbose “debugging” information• Executed SQL statements• Full HTTP requests• Anything

• s

End-to-End Tracing

DemoTraceSource, E2E format, Service Trace Viewer, Cross-Process Correlation, EventLog, Azure Live Tracing

System.Diagnostics

• Trace/Debug.WriteLine• TraceSource improvements• Service Trace Viewer

• E2E Tracing

• Correlation of events• CorrelationManager

• Common.Logginglog.Debug(m => m("my expensive to calculate argument is: {0}",

CalculateMessageInfo()));

System.ServiceModel.OperationInvoker.CodeGenerationSystem.ServiceModel.RoutingSystem.TransactionsSystem.Web.Services.AsmxSystem.Windows.DataSystem.Windows.DependencyPropertySystem.Windows.DocumentsSystem.Windows.FreezableSystem.Windows.Interop.HwndHostSystem.Windows.MarkupSystem.Windows.Media.AnimationSystem.Windows.NameScopeSystem.Windows.ResourceDictionarySystem.Windows.RoutedEventSystem.Windows.ShellSystem.WorkflowSystem.Workflow.Runtime.HostingSystem.Workflow.RuntimeSystem.Workflow.Runtime.TrackingSystem.Workflow.ActivitiesSystem.Workflow.Activities.RulesSystem.Xaml.Hosting

CardSpaceMicrosoft.Transactions.BridgeSystem.ActivitiesSystem.Activities.Core.PresentationSystem.Activities.DurableInstancingSystem.Activities.PresentationSystem.ComponentModel.CompositionSystem.IdentityModelSystem.IO.LogSystem.NetSystem.Net.CacheSystem.Net.HttpSystem.Net.HttpListenerSystem.Net.SocketsSystem.Net.WebSocketsSystem.RuntimeSystem.Runtime.SerializationSystem.Runtime.Serialization.CodeGenerationSystem.Security.Cryptography.Xml.SignedXmlSystem.ServiceModelSystem.ServiceModel.ActivationSystem.ServiceModel.MessageLogging

Azure Live Tracing

<system.diagnostics> <trace autoflush="true" /> <sources> <source name="MyTraceSource" switchValue="Warning"> <listeners> <add name="azureListener" /> </listeners> </source> </sources> <sharedListeners> <add name="azureListener" type="Microsoft.WindowsAzure.Diagnostics.DiagnosticMonitorTraceListener, Microsoft.WindowsAzure.Diagnostics, …" /> </sharedListeners> </system.diagnostics>

Historical Debugging

File Bug

Resolve as

“No Repro”

Hand-offto Test

Test CodeHand-offto Dev

Investigate Bug

Write Code

It Works on My Machine!

IntelliTrace Capabilities

• Capture debugger state information during program execution

• IL is instrumented via Profiling API• Records program execution flow

• Debugger, ASP.NET, ADO.NET, Exception, File, Registry, etc.

• Records program data• Parameters• Return values

• Low overhead for collection• Visual Studio Ultimate only debugging support

How IntelliTrace WorksApplication

IntelliTrace File

CollectionPlan.xml

IntelliTrace Recorder

DemoIntelliTrace - Historical debugger

Debugging Symbols

• Symbol Files• .PDB files• Used during the debugging process• Includes Source File Names, Line Numbers and

Local Variable Names

• You should always keep your symbol files around

• Symbol Server• Central location for storing your PDB files• Essentially this is just a file share

Microsoft’s public symbol server: http://msdl.microsoft.com/download/symbols

Memory Dump Analysis

Debugging Tools for Windows

• WinDBG, ADPlus, sos, Hawkeye…• .loadby sos clr• !clrstack –s• !do 00f846bc • !dumpstack• !gcroot 00f846bc

DemoDump File Analysis with Visual Studio

Windows Error Reporting (WER)

Event Tracing for Windows

Event Tracing for Windows

• Unified logging facility provided by the OS• Kernel-level buffers• Since Windows 2000• Also used by drivers

• Insanely-fast• 1500-2000 cycles per entry• ~2.5% CPU usage for sustained rate of 10,000 events/sec on a 2GHz PC

• Provider, Consumer, Controller model• Over 700 providers in Win7, ~900 in Win8!

• System-wide collection

System.Diagnostics.Tracing

• Managed support from .NET 4.0+• EventSource• EventListener

• Semantically rich• Strongly-typed!• Captures stack traces

• Works everywhere• Windows Store Apps, Windows Phone, Azure..

• Semantic Logging Application Block

ETW flow

ETL file

ETW

Event Providers

Event Providers

Control/Status

Control/Status

ETW Session

2. Any component that has been instrumented with Event Tracing API

1. Collection of configurable in-memory buffers that is managed

by the kernel

3. Controls logging sessions

and enables/disables

providers

5. GUI trace analysis via graphs and summary

tables

6. CLI trace analysis via

actions

Data flow

XML file

Control/Status

PerfView

PerfViewSystem and

Symbol Information

Merged

ETL file

Control/Status

Post Processing

Action

4. Metadata injection

Demo_NT_SYMBOL_PATH, PerfView, Event Tracing for Windows

What’s new in Visual Studio 2013Debugging and Diagnostics

• Edit and Continue support for x64• Task debugging• Graphics Diagnostics• Code Maps with Call Stacks

DemoParallel Task Debugging

Unhandled ExceptionsSystem.Windows.DispatcherUnhandledException += (sender, e) =>

{// Log it

};

System.AppDomain.CurrentDomain.UnhandledException += (sender, e) =>{

// Log it};

System.Threading.Tasks.TaskScheduler.UnobservedTaskException += (sender, e) =>{

// Log it};

Glimpse

<system.diagnostics> <sources> <source name="Example Source" switchValue="Information"> <listeners> <add name="GlimpseListener"/> </listeners> </source> </sources> <sharedListeners> <add name="GlimpseListener" type="Glimpse.Core.TraceListener, Glimpse.Core"/> </sharedListeners></system.diagnostics>

Logging, tracing, instrumentering, debugging og fejlfinding

• Instrumentation• End-to-End Tracing• Historical Debugging• Semantic Logging

EvaluationCreate a Text message on your phone and send it to 1919 with the content:

DE304 5 5 5 I liked it a lotSession Code

AndersPerformance (1 to 5)

Match of technical

Level(1 to 5)

Relevance(1 to 5) Comments

(optional)

Evaluation Scale: 1 = Very bad 2 = Bad 3 = Relevant 4 = Good 5 = Very Good!

Questions:• Speaker Performance• Relevance according to

your work • Match of technical level

according to published level• Comments

© 2013 Microsoft Corporation. All rights reserved. Microsoft, Windows, Windows Vista and other product names are or may be registered trademarks and/or trademarks in the U.S. and/or other countries.The information herein is for informational purposes only and represents the current view of Microsoft Corporation as of the date of this presentation.  Because Microsoft must respond to changing market conditions, it should not be interpreted to be a commitment on the part of Microsoft, and Microsoft cannot guarantee the accuracy of any information provided after the date of this presentation.  MICROSOFT MAKES NO WARRANTIES, EXPRESS, IMPLIED OR STATUTORY, AS TO THE INFORMATION IN THIS PRESENTATION.

Thank you

“It is a capital mistake to theorize before one has data.”- Sherlock Holmes

Other GREAT web-oriented tools

Dump Files AnalysisDump file summary information

Support for mixed-mode dump files

IL Interpreter for managed property evaluation

Operating system and CLR version information

Module Information

Search modules