{"id":21,"date":"2009-07-03T11:07:55","date_gmt":"2009-07-03T10:07:55","guid":{"rendered":"http:\/\/mccltd.net\/blog\/?p=21"},"modified":"2009-07-04T10:31:30","modified_gmt":"2009-07-04T09:31:30","slug":"annotating-troubleshooting-sessions","status":"publish","type":"post","link":"http:\/\/darenmatthews.com\/blog\/?p=21","title":{"rendered":"Annotating Troubleshooting Sessions"},"content":{"rendered":"<p><strong>When capturing log sessions during an outage or debug session it&#8217;s crucial to keep a history of what was done when and in what order.<\/strong> This helps in post mortem analysis after the event or session is over. There are a couple of standard things to do to help this such as:<\/p>\n<ul>\n<li>NTP time sync all devices in the network to get them on a single time source<\/li>\n<li>Enable syslog for all devices in the network<\/li>\n<li>Allocate some local log space on each local device based on a percentage of free memory available on the device<\/li>\n<li>Always have trend graphs from some polling mechanism for CPU levels, memory usage, traffic rates, etc.<\/li>\n<\/ul>\n<p>In addition to these here are a few other tips that really help TAC analyse log and debug sessions that are collected:<!--more--><\/p>\n<ul>\n<li>Annotate the local log and      syslog output using the <strong>send log<\/strong> command<\/li>\n<\/ul>\n<pre>CE_#send log \"Shutting down interface now!\"<\/pre>\n<pre>CE_#config t<\/pre>\n<pre>Enter configuration commands, one per line.\u00a0 End with CNTL\/Z.<\/pre>\n<pre>CE_(config)#int e 0\/0<\/pre>\n<pre>CE_(config-if)#shut<\/pre>\n<pre>CE_(config-if)#end<\/pre>\n<pre>CE_#sh log<\/pre>\n<pre>%SYS-7-USERLOG: Message from 0(): \"Shutting down interface now!\"<\/pre>\n<pre>00:00:46:\u00a0%SYS-5-CONFIG_I: Configured from console by console<\/pre>\n<pre>00:00:47:\u00a0%LINK-5-CHANGED: Interface Ethernet0\/0, changed state to<\/pre>\n<pre>administratively down<\/pre>\n<pre>00:00:48:\u00a0%LINEPROTO-5-UPDOWN: Line protocol on Interface Ethernet0\/0,<\/pre>\n<pre>changed state to down<\/pre>\n<p>By using the <strong>send log &lt;message&gt;<\/strong> the output is sent to the local log as well as to the syslog so there is a historical view of what was done and why. View it as &#8220;Thinking out loud and capturing the thought process&#8221; so it can be followed later. Without it it&#8217;s very hard to remember exactly what was done when and why.<\/p>\n<ul>\n<li>Annotate the logging or      debug session as things are learned or events happen using the <strong>!&lt;message&gt;<\/strong> CLI<\/li>\n<\/ul>\n<pre>CE_#!Troubleshooting RIP routers being lost<\/pre>\n<pre>CE_#!checking # of routers learned before cable is pulled<\/pre>\n<pre>CE_#sh ip ro summ<\/pre>\n<pre>IP routing table name is default (0x0)<\/pre>\n<pre>IP routing table maximum-paths is 32<\/pre>\n<pre>Route Source\u00a0\u00a0\u00a0 Networks\u00a0\u00a0\u00a0 Subnets\u00a0\u00a0\u00a0\u00a0 Replicates\u00a0 Overhead\u00a0\u00a0\u00a0 Memory<\/pre>\n<pre>(bytes)<\/pre>\n<pre>connected\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 2\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 104\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 344<\/pre>\n<pre>static\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 0<\/pre>\n<pre>rip\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 0\u00a0\u00a0\u00a0 \u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a01\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 52\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 172<\/pre>\n<pre>eigrp 1\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 0<\/pre>\n<pre>internal\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 1\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 528<\/pre>\n<pre>Total\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 1\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 3\u00a0\u00a0\u00a0\u00a0 \u00a0\u00a0\u00a0\u00a0\u00a0\u00a00\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 156\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 1044<\/pre>\n<pre>CE_#!Only one RIP route...wait some more time for network to converge<\/pre>\n<ul>\n<li>Capture date, time, and CPU      automatically when running CLI commands during a session by enabling <strong>terminal      exec prompt timestamp<\/strong><\/li>\n<\/ul>\n<pre>CE_#term exec prompt timestamp<\/pre>\n<pre>CE_#sh user<\/pre>\n<pre>Load for five secs: 3%\/0%; one minute: 1%; five minutes: 1%<\/pre>\n<pre>Time source is hardware calendar, *14:02:40.623 EST Mon Oct 20 2008<\/pre>\n<pre>\u00a0\u00a0\u00a0\u00a0Line\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 User\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 Host(s)\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 Idle\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 Location<\/pre>\n<pre>*\u00a0 0 con 0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 idle\u00a0\u00a0\u00a0\u00a0 \u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a000:00:00<\/pre>\n<pre>\u00a0\u00a0Interface\u00a0\u00a0\u00a0 User\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 Mode\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 Idle\u00a0\u00a0\u00a0\u00a0 Peer Address<\/pre>\n<pre>CE_#<\/pre>\n<p>Notice the Load and Time as the output for each command. It will be printed automatically every time a CLI command is entered.<\/p>\n<p>This is very useful because it allows deltas of counters between outputs to have some rate context by comparing the time difference between outputs.<\/p>\n<p>Without that when looking at a raw capture log it&#8217;s impossible to tell how much time elapsed between outputs.<\/p>\n<p>When using the above in conjunction with &#8220;|&#8221; don&#8217;t forget to include the &#8220;Load for five|Time source is&#8221; to capture it while filtering other output.<\/p>\n","protected":false},"excerpt":{"rendered":"<p>When capturing log sessions during an outage or debug session it&#8217;s crucial to keep a history of what was done when and in what order. This helps in post mortem analysis after the event or session is over. There are a couple of standard things to do to help this such as: NTP time sync [&hellip;]<\/p>\n","protected":false},"author":1,"featured_media":0,"comment_status":"closed","ping_status":"open","sticky":false,"template":"","format":"standard","meta":[],"categories":[83],"tags":[3],"_links":{"self":[{"href":"http:\/\/darenmatthews.com\/blog\/index.php?rest_route=\/wp\/v2\/posts\/21"}],"collection":[{"href":"http:\/\/darenmatthews.com\/blog\/index.php?rest_route=\/wp\/v2\/posts"}],"about":[{"href":"http:\/\/darenmatthews.com\/blog\/index.php?rest_route=\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"http:\/\/darenmatthews.com\/blog\/index.php?rest_route=\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"http:\/\/darenmatthews.com\/blog\/index.php?rest_route=%2Fwp%2Fv2%2Fcomments&post=21"}],"version-history":[{"count":6,"href":"http:\/\/darenmatthews.com\/blog\/index.php?rest_route=\/wp\/v2\/posts\/21\/revisions"}],"predecessor-version":[{"id":80,"href":"http:\/\/darenmatthews.com\/blog\/index.php?rest_route=\/wp\/v2\/posts\/21\/revisions\/80"}],"wp:attachment":[{"href":"http:\/\/darenmatthews.com\/blog\/index.php?rest_route=%2Fwp%2Fv2%2Fmedia&parent=21"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"http:\/\/darenmatthews.com\/blog\/index.php?rest_route=%2Fwp%2Fv2%2Fcategories&post=21"},{"taxonomy":"post_tag","embeddable":true,"href":"http:\/\/darenmatthews.com\/blog\/index.php?rest_route=%2Fwp%2Fv2%2Ftags&post=21"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}