Pages

Showing posts with label Sequence Numbers. Show all posts
Showing posts with label Sequence Numbers. Show all posts

Wednesday, 10 March 2021

Logging, Debugging, Timestamps, Sequence Numbers

  1. Logging
    1. Logging Messages
    2. Logging Console
    3. Logging Monitor
    4. Logging Buffer
    5. Logging Monitor
    6. Logging Synchronous
    7. Logging Flash
  2. Debugging
    1. Debugging Using ACLs
    2. Conditional Debugging
  3. Syslog
  4. Filtering
  5. Timestamps
  6. Sequence Numbers

Introduction and Overview

Logging aims to answer the three questions: what, when, who? Log messages are generated by the various services and protocols running on a network device. By default, output from system messages and debug commands is sent to a logging process. The logging process controls the distribution of logging messages to various destinations, such as the logging buffer, terminal lines, syslog server. Messages are also sent to the console. These are then viewed using syslog, local logging, debugs, conditional debugs.

Logging can be used for fault identification, security auditing and network forensics; for monitoring the network and performance of network devices. Additional purposes include regulatory compliance.

Log messages include a timestamp that indicates the time when the log was generated. It is important to note that the system clock should be accurate. This can be done by configuring NTP to provide accurate datetime values. The time must be consistent across all network devices; troubleshooting can be difficult if you cannot correlate timestamps across devices.

Logging Messages

Syslog messages can be output to the console, local buffer or remote syslog server. The messages follow this format:

%FACILITY-SUBFACILITY-SEVERITY-MNEMONIC: message text

Where:

  • FACILITY-SUBFACILITY: protocol, module or process that generated the message.
  • SEVERITY: This is a level from 0 - 7 that specifies how important the message is. The following table displays all the logging severity levels available:

    Level Number Severity Description Syslog Definition
    0 Emergencies System is unusable LOG_EMERG
    1 Alerts Action must be taken immediately LOG_ALERT
    2 Critical Critical conditions LOG_CRIT
    3 Errors Error conditions LOG_ERR
    4 Warnings Warning conditions LOG_WARNING
    5 Notifications Normal but significant conditions LOG_NOTICE
    6 Informational Informational messages LOG_INFO
    7 Debugging Debug-level messages LOG_DEBUG

    When you enable logging for a specific level, it also enables all levels above it. For example, if you enable level 4(warnings), it also will enable levels 0 - 3.

  • MNEMONIC: a code that identifies the action reported
  • Message text: A plain text description of the event

Local Logging

By default, all logging is displayed on the console. This can be turned off with the no logging command. By default, monitor and buffer logging display messages with severity levels of debugging and lower. For SSH/Telnet, the logging session settings can be configured using the command terminal monitor

Logging Console

To enable logging to console, use the command logging console. By default, the logging severity level for console is debugging. To control the logging options, use the command logging console <level>.

Logging Buffer

For local logging, Cisco IOS can save syslog messages to an internal buffer i.e., all the logs are saved on the device itself. You can display these messages by using the show logging command.

These messages are lost when the device is rebooted. The default buffer size is 8192 bytes. When the buffer is full, the older logs get overwritten by the newer ones. The size of the buffer can be increased using the command: logging buffered <size>.

Logging Monitor

By default, the log messages do not appear in the login session of a remote connection through SSH or telnet. To enable logging to remote logins via SSH or telnet, use the command terminal monitor. The default logging severity is debugging. To change the logging severity level of a remote login session, use the command logging monitor <level>.

Logging messages can be disabled from a vty login session using the command terminal no monitor.

Logging Synchronous

By default, logging messages in a login session are displayed in the console session or VTY session as soon as they are generated. This can be a nuisance as the log messages distract a user who is typing at the command line from a console or VTY session as the log messages get displayed inline. The command logging synchronous [level <severity-level>|all] | limit <0-2147483647> enables synchronous logging of messages; where log messages are displayed at the login session but a new line is created for the logging messages so the logging messages do not appear in the middle of a typing session; the command being typed is placed into a new line below the displayed log message. The optional values:

  • level: indicates that messages with a severity level equal to or lower are printed asynchronously. The default is 2.
  • limit: specifies the number of buffers to be queued for the terminal after which new messages are dropped. The default is 20.

Logging Flash

Logs can be stored as files on flash memory. This is accomplished using the command logging file flash:<file-name> <max-file-size> <min-file-size> <severity-level> where:

  • The maximum file size is in the range 4096 - 2147483647 bytes.
  • The default size is 4096.
  • The minimum file-size is in the range 1024 - 2147483647 bytes.
  • The severity-level is in the range 0 - 7.
The command logging file flash:log_message.txt 40960 4096 3 stores log messages in a file in a flash memory.

Debug

Debugging is a powerful tool for troubleshooting complex network issues. It displays detailed information about all supported protocols and features of the network device. Use the debug command with caution on production networks as it is a resource intensive tool and may impact operations. Debugging can disrupt operations under high-CPU load conditions as debugging is processed by the CPU.

Best practices when using debugging include the following:

  • show process cpu sorted: helps understand current CPU utilization. If the router is already loaded, debugging may impact the router.
  • Consider output volume and time before enabling debug. If output is voluminous, this may impact router performance.
  • Excessive console logging can cause the network device to hang as its CPU prioritizes this output. Use vty terminal monitor or logging buffered instead.
  • Disable debug commands after troubleshooting using no debug all or undebug all.

Debugging messages can be enabled using the command debug <command>. The debugging messages can then be sent to a logging service, in this case the console using the command logging console.

The following is an example of the debugging of OSPF: debug ip ospf adj.

Debug using IP Access Lists

Debugging by referencing an IP ACL allows debugging information that matches a configured IP access control list.

access-list 99 permit 10.0.12.0 /30
debug ip packet 99

R1#
*Oct 25 20:44:57.335: IP: s=10.0.12.1 (local), d=224.0.0.5 (GigabitEthernet0/0), len 80, sending broad/multicast, proto=89
*Oct 25 20:44:57.343: IP: s=10.0.12.1 (local), d=224.0.0.5 (GigabitEthernet0/0), len 80, sending full packet, proto=89
R1#
*Oct 25 20:44:59.591: IP: s=10.0.12.2 (GigabitEthernet0/0), d=224.0.0.5, len 80, rcvd 0, proto=89
*Oct 25 20:44:59.595: IP: s=10.0.12.2 (GigabitEthernet0/0), d=224.0.0.5, len 80, input feature, proto=89, packet consumed, MCI Check(101), rtype 0, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
R1#
*Oct 25 20:45:06.699: IP: s=10.0.12.1 (local), d=224.0.0.5 (GigabitEthernet0/0), len 80, sending broad/multicast, proto=89
*Oct 25 20:45:06.707: IP: s=10.0.12.1 (local), d=224.0.0.5 (GigabitEthernet0/0), len 80, sending full packet, proto=89
R1#
*Oct 25 20:45:08.327: IP: s=10.0.12.2 (GigabitEthernet0/0), d=224.0.0.5, len 80, rcvd 0, proto=89
*Oct 25 20:45:08.331: IP: s=10.0.12.2 (GigabitEthernet0/0), d=224.0.0.5, len 80, input feature, proto=89, packet consumed, MCI Check(101), rtype 0, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
R1#
R1#
*Oct 25 20:45:16.083: IP: s=10.0.12.1 (local), d=224.0.0.5 (GigabitEthernet0/0), len 80, sending broad/multicast, proto=89
*Oct 25 20:45:16.091: IP: s=10.0.12.1 (local), d=224.0.0.5 (GigabitEthernet0/0), len 80, sending full packet, proto=89
R1#
*Oct 25 20:45:18.111: IP: s=10.0.12.2 (GigabitEthernet0/0), d=224.0.0.5, len 80, rcvd 0, proto=89
*Oct 25 20:45:18.115: IP: s=10.0.12.2 (GigabitEthernet0/0), d=224.0.0.5, len 80, input feature, proto=89, packet consumed, MCI Check(101), rtype 0, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
R1#
*Oct 25 20:45:25.623: IP: s=10.0.12.1 (local), d=224.0.0.5 (GigabitEthernet0/0), len 80, sending broad/multicast, proto=89
*Oct 25 20:45:25.631: IP: s=10.0.12.1 (local), d=224.0.0.5 (GigabitEthernet0/0), len 80, sending full packet, proto=89
R1#
*Oct 25 20:45:28.115: IP: s=10.0.12.2 (GigabitEthernet0/0), d=224.0.0.5, len 80, rcvd 0, proto=89
*Oct 25 20:45:28.119: IP: s=10.0.12.2 (GigabitEthernet0/0), d=224.0.0.5, len 80, input feature, proto=89, packet consumed, MCI Check(101), rtype 0, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
R1#
*Oct 25 20:45:35.587: IP: s=10.0.12.1 (local), d=224.0.0.5 (GigabitEthernet0/0), len 80, sending broad/multicast, proto=89
*Oct 25 20:45:35.595: IP: s=10.0.12.1 (local), d=224.0.0.5 (GigabitEthernet0/0), len 80, sending full packet, proto=89
R1#
*Oct 25 20:45:38.467: IP: s=10.0.12.2 (GigabitEthernet0/0), d=224.0.0.5, len 80, rcvd 0, proto=89
*Oct 25 20:45:38.471: IP: s=10.0.12.2 (GigabitEthernet0/0), d=224.0.0.5, len 80, input feature, proto=89, packet consumed, MCI Check(101), rtype 0, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
R1#
*Oct 25 20:45:44.623: IP: s=10.0.12.1 (local), d=224.0.0.5 (GigabitEthernet0/0), len 80, sending broad/multicast, proto=89
*Oct 25 20:45:44.631: IP: s=10.0.12.1 (local), d=224.0.0.5 (GigabitEthernet0/0), len 80, sending full packet, proto=89
R1#
*Oct 25 20:45:47.879: IP: s=10.0.12.2 (GigabitEthernet0/0), d=224.0.0.5, len 80, rcvd 0, proto=89
*Oct 25 20:45:47.883: IP: s=10.0.12.2 (GigabitEthernet0/0), d=224.0.0.5, len 80, input feature, proto=89, packet consumed, MCI Check(101), rtype 0, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
R1#
*Oct 25 20:45:54.067: IP: s=10.0.12.1 (local), d=224.0.0.5 (GigabitEthernet0/0), len 80, sending broad/multicast, proto=89
*Oct 25 20:45:54.075: IP: s=10.0.12.1 (local), d=224.0.0.5 (GigabitEthernet0/0), len 80, sending full packet, proto=89
R1#
*Oct 25 20:45:56.971: IP: s=10.0.12.2 (GigabitEthernet0/0), d=224.0.0.5, len 80, rcvd 0, proto=89
*Oct 25 20:45:56.975: IP: s=10.0.12.2 (GigabitEthernet0/0), d=224.0.0.5, len 80, input feature, proto=89, packet consumed, MCI Check(101), rtype 0, forus FALSE, sendself FALSE, mtu 0, fwdchk FALSE
R1#show debug
*Oct 25 20:46:03.483: IP: s=10.0.12.1 (local), d=224.0.0.5 (GigabitEthernet0/0), len 80, sending broad/multicast, proto=89
*Oct 25 20:46:03.491: IP: s=10.0.12.1 (local), d=224.0.0.5 (GigabitEthernet0/0), len 80, sending full packet, proto=89
R1#show debug
Generic IP:
IP packet debugging is on (detailed) for access list 99



R1#

Any debugs that do not match the access control list are not logged.

Conditional Debugs

Conditional debugs generate detailed information about a specific object such as matching a specific interface, username, MAC address, VLAN, etc. Conditional debugs limit the number of debugging messages punted to the CPU. Conditional debugs are configured using the command debug condition <interface>. Conditional debugs can be stacked as such that the debugging messages that are displayed match all conditions in the stack.

debug condition interface gigabitethernet1/0
debug condition ip 10.0.13.2
debug ip ospf hello

The above configuration will generate debug messages if they match all three commands.

To log debug messages for packets matching an ACL and specific interface: debug interface <interface-id>. Verify with show debug.

With conditional debugs, you can attach an access-list to filter debug traffic to permitted traffic in the access-list.

Verification

show debug

To view the debugging messages, use the command show debug. After disabling the debug, ensure that the debug condition is disabled as well.

R1#show debug
OSPF:
OSPF hello debugging is on




Condition 1: interface Gi0/0 (1 flags triggered)
        Flags: Gi0/0
Condition 2: ip 10.0.13.2 (0 flags triggered)

R1#
R1#
R1#
R1#
*Oct 25 21:00:13.142: OSPF-1 HELLO Gi0/0: Rcv hello from 10.0.24.1 area 0 10.0.12.2
R1#
*Oct 25 21:00:18.014: OSPF-1 HELLO Gi0/0: Send hello to 224.0.0.5 area 0 from 10.0.12.1
R1#
*Oct 25 21:00:23.202: OSPF-1 HELLO Gi0/0: Rcv hello from 10.0.24.1 area 0 10.0.12.2
R1#
*Oct 25 21:00:27.638: OSPF-1 HELLO Gi0/0: Send hello to 224.0.0.5 area 0 from 10.0.12.1
R1#
*Oct 25 21:00:32.854: OSPF-1 HELLO Gi0/0: Rcv hello from 10.0.24.1 area 0 10.0.12.2
R1#

Syslog

Logs generated by a device can be sent to a logging buffer whose size can be modified, or an off-box syslog collector. Syslog listens for log messages on UDP port 514. Syslog is the standard for computer message logging. It allows the separation of software which generates messages from the systems that store it and the software that analyzes and reports it. It can be used for the security auditing and system management, debugging messages and analysis. The syslog is supported by a wide range of devices, including routers and receivers over multiple platforms. The syslog is used to integrate the log data from many various types of systems into the central repository.

A rate-limit can be configured for syslogs to limit the rate of messages per second.

The syslogs can be forwarded to a syslog server using the following process

  1. Specify the syslog server: logging host <ip-address>.
  2. Specify the type of messages: the message type to be logged is specified using the command logging trap <severity>.

Filtering Logs

Logging Discriminator

A logging discriminator can be used to filter generated logs based on the text in the log. Log discriminators can be used to filter out specific logs that are repeatedly generated consuming the device log buffer. Some logs have a high severity level but are not so consequential such as up-down messages. It can be applied to the console, monitor, buffer or syslog server.

When creating a log discriminator, be as specific as possible and test the discriminator extensively before deploying it in a production environment. This will minimize the risk of filtering important messages.

To configure a logging discriminator:

  1. Configure the logging discriminator name and filtering options using the command logging discriminator <discriminator-name> <facility> <mnemonics> <message-body> <includes> <severity> <rate-limit> where:
    • facility: (Optional) Message subfilter for the facility pattern in an event message.
    • mnemonics: (Optional) Message subfilter for the mnemonic pattern in an event message.
    • msg-body: (Optional) Message subfilter for the msg-body pattern in an event message.
    • drops: Drops messages that match the pattern, including the specified regular expression.
    • includes: Delivers messages that match the pattern, including the specified regular expression string.
    • string: (Optional) Expression used for message filtering.
    • severity: (Optional) Message subfilter by severity level or group.
    • sev-num: (Optional) Integer that identifies the severity level or multiple levels. Multiple levels must be separated with a comma (,)/
    • rate-limit: (Optional) Specifies a number of messages to be processed within a unit of time.
    • msglimit: (Optional) Integer in the range of 1 to 10000 that identifies the number of messages not to be exceeded.

    logging discriminator NO_CONFIGURED msg-body drops Configured from console by console

  2. Application:
    • To apply the logging discriminator to the console, use the command logging console discriminator <discriminator-name>
    • To apply the logging discriminator to the monitor, use the command logging monitor discriminator <discriminator>.

Verification

Configured logging settings can be viewed using the command show logging.

Timestamps

Timestamps are controlled by the service timestamps command. This command by itself enables the adding of timestamps to debug messages and, by default, sets the timestamps to uptime.

Having logs and debug messages timestamped is extremely important when troubleshooting particularly across different devices. To enable timestamps on logging and debug messages:

  • Debugging messages: the command service timestamps debug datetime msec adds timestamps to debug messages including milliseconds. The datetime option includes the date and the time.
  • Log messages: the command service timestamps log datetime msec adds the timestamps to logging messages. Options include:
    • datetime: This option alone enables the date (day of month and month) and time(hours, minutes and seconds). Additional options include:
      • localtime: use the local timezone for timestamps.
      • msec: include milliseconds in the timestamp.
      • show-timezone: add timezone information to the timestamp.
      • year: include the current year in the timestamp.
    • uptime: does not include additional options as does datetime.

R1(config)#service timestamps debug datetime localtime show-timezone msec
R1(config)#
04:16:27: OSPF-1 HELLO Gi0/0: Send hello to 224.0.0.5 area 0 from 10.0.12.1
R1(config)#
*Oct 25 21:09:52.490 UTC: OSPF-1 HELLO Gi0/0: Rcv hello from 10.0.24.1 area 0 10.0.12.2
R1(config)#
*Oct 25 21:09:57.214 UTC: OSPF-1 HELLO Gi0/0: Send hello to 224.0.0.5 area 0 from 10.0.12.1
R1(config)#service
*Oct 25 21:10:02.322 UTC: OSPF-1 HELLO Gi0/0: Rcv hello from 10.0.24.1 area 0 10.0.12.2
R1(config)#service timestamps log dat
*Oct 25 21:10:06.814 UTC: OSPF-1 HELLO Gi0/0: Send hello to 224.0.0.5 area 0 from 10.0.12.1
R1(config)#service timestamps log datetime msec
R1(config)#do sho
*Oct 25 21:10:11.790 UTC: OSPF-1 HELLO Gi0/0: Rcv hello from 10.0.24.1 area 0 10.0.12.2
R1(config)#do show log
R1(config)#do show loggin
*Oct 25 21:10:16.234 UTC: OSPF-1 HELLO Gi0/0: Send hello to 224.0.0.5 area 0 from 10.0.12.1

R1#show logging
*Oct 25 21:10:25.462 UTC: OSPF-1 HELLO Gi0/0: Send hello to 224.0.0.5 area 0 from 10.0.12.1
Syslog logging: enabled (0 messages dropped, 2 messages rate-limited, 0 flushes, 0 overruns, xml disabled, filtering disabled)

No Active Message Discriminator.



No Inactive Message Discriminator.


    Console logging: level debugging, 2225 messages logged, xml disabled,
                     filtering disabled          
    Monitor logging: level debugging, 0 messages logged, xml disabled,
                     filtering disabled          
    Buffer logging:  level debugging, 2225 messages logged, xml disabled,
                    filtering disabled          
    Exception Logging: size (8192 bytes)        
    Count and timestamp logging messages: disabled
    Persistent logging: disabled                
                                                
No active filter modules.                        
                                                
    Trap logging: level informational, 49 message lines logged
        Logging Source-Interface:       VRF Name:
                                                
Log Buffer (8192 bytes):
F-1 HELLO Gi0/0: Send hello to 224.0.0.5 area 0 from 10.0.12.1
*Oct 25 20:58:28.282: OSPF-1 HELLO Gi0/0: Rcv hello from 10.0.24.1 area 0 10.0.12.2
*Oct 25 20:58:33.750: OSPF-1 HELLO Gi0/0: Send hello to 224.0.0.5 area 0 from 10.0.12.1
*Oct 25 20:58:37.906: OSPF-1 HELLO Gi0/0: Rcv hello from 10.0.24.1 area 0 10.0.12.2
*Oct 25 20:58:42.994: OSPF-1 HELLO Gi0/0: Send hello to 224.0.0.5 area 0 from 10.0.12.1
*Oct 25 20:58:47.490: OSPF-1 HELLO Gi0/0: Rcv hello from 10.0.24.1 area 0 10.0.12.2
*Oct 25 20:58:52.746: OSPF-1 HELLO Gi0/0: Send hello to 224.0.0.5 area 0 from 10.0.12.1
*Oct 25 20:58:57.310: OSPF-1 HELLO Gi0/0: Rcv hello from 10.0.24.1 area 0 10.0.12.2
*Oct 25 20:59:02.742: OSPF-1 HELLO Gi0/0: Send hello to 224.0.0.5 area 0 from 10.0.12.1
*Oct 25 20:59:06.318: OSPF-1 HELLO Gi0/0: Rcv hello from 10.0.24.1 area 0 10.0.12.2
*Oct 25 20:59:11.954: OSPF-1 HELLO Gi0/0: Send hello to 224.0.0.5 area 0 from 10.0.12.1
*Oct 25 20:59:16.218: OSPF-1 HELLO Gi0/0: Rcv hello from 10.0.24.1 area 0 10.0.12.2
*Oct 25 20:59:21.686: OSPF-1 HELLO Gi0/0: Send hello to 224.0.0.5 area 0 from 10.0.12.1
*Oct 25 20:59:25.834: OSPF-1 HELLO Gi0/0: Rcv hello from 10.0.24.1 area 0 10.0.12.2
*Oct 25 20:59:30.922: OSPF-1 HELLO Gi0/0: Send hello to 224.0.0.5 area 0 from 10.0.12.1
*Oct 25 20:59:34.034: OSPF-1 HELLO Gi0/0: Rcv hello from 10.0.24.1 area 0 10.0.12.2
*Oct 25 20:59:40.566: OSPF-1 HELLO Gi0/0: Send hello to 224.0.0.5 area 0 from 10.0.12.1
*Oct 25 20:59:43.534: OSPF-1 HELLO Gi0/0: Rcv hello from 10.0.24.1 area 0 10.0.12.2
*Oct 25 20:59:49.654: OSPF-1 HELLO Gi0/0: Send hello to 224.0.0.5 area 0 from 10.0.12.1
*Oct 25 20:59:53.378: OSPF-1 HELLO Gi0/0: Rcv hello from 10.0.24.1 area 0 10.0.12.2
*Oct 25 20:59:58.906: OSPF-1 HELLO Gi0/0: Send hello to 224.0.0.5 area 0 from 10.0.12.1
*Oct 25 21:00:02.526: OSPF-1 HELLO Gi0/0: Rcv hello from 10.0.24.1 area 0 10.0.12.2
*Oct 25 21:00:08.102: OSPF-1 HELLO Gi0/0: Send hello to 224.0.0.5 area 0 from 10.0.12.

Sequence Numbers

Sequence numbers can be added to log messages based on the time that they were generated. The sequence numbers increment from 1, 2, onwards. If there is more than one log message with the same time stamp, you can display messages with sequence numbers to view these messages. By default, sequence numbers are not added to log messages. Sequence numbers can be added to log messages using the command service sequence-numbers. When enabled, they are prepended to the log message appearing at the start of a log message.

R1(config)#service sequence-numbers

000748: 04:18:31: OSPF-1 HELLO Gi0/0: Send hello to 224.0.0.5 area 0 from 10.0.12.1[OK]
R1(config)#
000749: 04:18:36: OSPF-1 HELLO Gi0/0: Rcv hello from 10.0.24.1 area 0 10.0.12.2
R1(config)#
000750: 04:18:40: OSPF-1 HELLO Gi0/0: Send hello to 224.0.0.5 area 0 from 10.0.12.1
R1(config)#
000751: 04:18:45: OSPF-1 HELLO Gi0/0: Rcv hello from 10.0.24.1 area 0 10.0.12.2
R1(config)#
000752: 04:18:50: OSPF-1 HELLO Gi0/0: Send hello to 224.0.0.5 area 0 from 10.0.12.1
R1(config)#
000753: 04:18:54: OSPF-1 HELLO Gi0/0: Rcv hello from 10.0.24.1 area 0 10.0.12.2
R1(config)#
000754: 04:19:00: OSPF-1 HELLO Gi0/0: Send hello to 224.0.0.5 area 0 from 10.0.12.1

Posted by at No comments:
Labels: , , ,
Location: Kitgum, Uganda
Subscribe to: Posts (Atom)