Network Management

NCM How to Read a Session Trace

What is a Session Trace? A Session Trace logs all communication between NCM and the target device, once enabled. This will work only for console communications - where NCM is actively logging into the device to run commands, in order to download, upload or change a configuration. If NCM is manipulating the configuration via SNMP, then you will not see a session trace for that communication.

First published date

10/23/2018 3:40 PM

Last published date

9/8/2023 11:52 AM

Overview

What is a Session Trace?

A Session Trace logs all communication between NCM and the target device, once enabled. This will work only for console communications - where NCM is actively logging into the device to run commands, in order to download, upload or change a configuration. If NCM is manipulating the configuration via SNMP, then you will not see a session trace for that communication.

Please refer to the below article to enable (or disable) tracing:

Generate session trace logs

Product section

Network Configuration Manager

Resolution

Reading a Session Trace - Initial Communication 


1) The first few lines of a session trace will include details about the version of NCM, the template being used, and some additional details about the device connection settings, for example:

[22/10/2012 16:18:22] -----------------NCM 7.1-------------------
[22/10/2012 16:18:22] UseCustomMorePromptBehaviour: False
[22/10/2012 16:18:22] MorePromptKey: 
[22/10/2012 16:18:22] Login Attempts: 1
[22/10/2012 16:18:22] Custom UserName Prompt: 
[22/10/2012 16:18:22] Device Template: Cisco IOS-1.3.6.1.4.1.9.ConfigMgmt-Commands
[22/10/2012 16:18:22] System Name: Tex-3750.aus.lab
[22/10/2012 16:18:22] System Description: Cisco IOS Software, C3750 Software (C3750-IPSERVICESK9-M), Version 12.2(50)SE3, RELEASE SOFTWARE (fc1)
Technical Support: http://www.cisco.com/techsupport
Copyright (c) 1986-2009 by Cisco Systems, Inc.
Compiled Wed 22-Jul-09 06:19 by prod_rel_team
[22/10/2012 16:18:22] System OID: 1.3.6.1.4.1.9.1.516
[22/10/2012 16:18:22] OS Image: C3750-IPSERVICESK9-M
[22/10/2012 16:18:22] OS Version: 12.2(50)SE3, RELEASE SOFTWARE (fc1)

[22/10/2012 16:18:22] Menu-Based mode=False
[22/10/2012 16:18:22] FreezeLoginForPreCommands mode= False
[22/10/2012 16:18:22]

 

 

2) Communication in a session trace is marked by the following:

-->  A line received by NCM from the device

<--  A line or character sent to the device from NCM

3) When NCM connects to a device successfully, you will see something similar to the following logged, detailing the protocol used for the connection:

[22/10/2012 16:18:22] 
-->StateChange: Connecting to server<--

[22/10/2012 16:18:22] 
-->StateChange: Connected to server - idle<--

[22/10/2012 16:18:22] Solarwinds.Net SWTelnet9 Version 9.0.27
[22/10/2012 16:18:22] Connected!
[22/10/2012 16:18:24] TimerTick: mstrData=<> State=3 - Connected to server - idle
[22/10/2012 16:18:24] Pending Disconnect = False

At this point, NCM has successfully connected, and is ready to begin sending commands to the device. The first thing NCM will do when it logs into any device is send a 'CRLF' character ('Enter') to the device to initiate communication. The device will then respond with its banner or username/password challenge.

[22/10/2012 16:18:24] Sending to get a banner!
[22/10/2012 16:18:24] <--

[22/10/2012 16:18:25]

 

4) At this point, the session trace requires careful reading, as the communication between NCM and the device will very much depend on the NCM device command template, and on the device configuration itself.

Session Trace examples 


Example 1: Logging into a device when NCM has not been configured with the device enable password. 

Session Trace

[22/10/2012 16:18:22] -----------------NCM 7.1-------------------
[22/10/2012 16:18:22] UseCustomMorePromptBehaviour: False
[22/10/2012 16:18:22] MorePromptKey: 
[22/10/2012 16:18:22] Login Attempts: 1
[22/10/2012 16:18:22] Custom UserName Prompt: 
[22/10/2012 16:18:22] Device Template: Cisco IOS-1.3.6.1.4.1.9.ConfigMgmt-Commands
[22/10/2012 16:18:22] System Name: Tex-3750.aus.lab
[22/10/2012 16:18:22] System Description: Cisco IOS Software, C3750 Software (C3750-IPSERVICESK9-M), Version 12.2(50)SE3, RELEASE SOFTWARE (fc1)
Technical Support: http://www.cisco.com/techsupport
Copyright (c) 1986-2009 by Cisco Systems, Inc.
Compiled Wed 22-Jul-09 06:19 by prod_rel_team
[22/10/2012 16:18:22] System OID: 1.3.6.1.4.1.9.1.516
[22/10/2012 16:18:22] OS Image: C3750-IPSERVICESK9-M
[22/10/2012 16:18:22] OS Version: 12.2(50)SE3, RELEASE SOFTWARE (fc1)

[22/10/2012 16:18:22] Menu-Based mode=False
[22/10/2012 16:18:22] FreezeLoginForPreCommands mode= False
[22/10/2012 16:18:22] 
-->StateChange: Connecting to server<--

[22/10/2012 16:18:22] 
-->StateChange: Connected to server - idle<--

[22/10/2012 16:18:22] Solarwinds.Net SWTelnet9 Version 9.0.27
[22/10/2012 16:18:22] Connected!
[22/10/2012 16:18:24] TimerTick: mstrData=<> State=3 - Connected to server - idle
[22/10/2012 16:18:24] Pending Disconnect = False
[22/10/2012 16:18:24] Sending to get a banner!
[22/10/2012 16:18:24] <--

[22/10/2012 16:18:25] --> 
[22/10/2012 16:18:25] --> 
[22/10/2012 16:18:25] --> Authorized Users Only
[22/10/2012 16:18:25] --> 
[22/10/2012 16:18:25] --> 
[22/10/2012 16:18:25] --> Tex-3750>
[22/10/2012 16:18:25] ProcessLogin State: 0
[22/10/2012 16:18:25] --> 
[22/10/2012 16:18:25] --> 
[22/10/2012 16:18:25] ProcessLogin State: 0
[22/10/2012 16:18:25] --->Tex-3750>
[22/10/2012 16:18:25] ProcessLogin State: 0
[22/10/2012 16:18:26] TimerTick: mstrData=<Tex-3750>> State=3 - Connected to server - idle
[22/10/2012 16:18:26] Pending Disconnect = False
[22/10/2012 16:18:26] TimerTick: Send to CRLF get prompt again
[22/10/2012 16:18:26] <--

[22/10/2012 16:18:26] --> 
[22/10/2012 16:18:26] --> Tex-3750>
[22/10/2012 16:18:26] ProcessLogin State: 0
[22/10/2012 16:18:26] Custom Prompt detector detect # prompt
[22/10/2012 16:18:26] no credentials needed - Command mode prompt detected
[22/10/2012 16:18:26] Prompt is being set to : Tex-3750>
[22/10/2012 16:18:26] Logging into Enable Mode
[22/10/2012 16:18:26] <-- enable

[22/10/2012 16:18:26] --->e
[22/10/2012 16:18:26] ProcessLogin State: 5
[22/10/2012 16:18:26] --->n
[22/10/2012 16:18:26] ProcessLogin State: 5
[22/10/2012 16:18:26] --->ab
[22/10/2012 16:18:26] ProcessLogin State: 5
[22/10/2012 16:18:26] --->le
[22/10/2012 16:18:26] ProcessLogin State: 5
[22/10/2012 16:18:26] Enable command echo detected
[22/10/2012 16:18:26] --> 
[22/10/2012 16:18:26] --> 
[22/10/2012 16:18:26] ProcessLogin State: 5
[22/10/2012 16:18:26] Enable command echo detected
[22/10/2012 16:18:26] --->Password: 
[22/10/2012 16:18:26] ProcessLogin State: 5
[22/10/2012 16:18:26] <--

[22/10/2012 16:18:27] --> 
[22/10/2012 16:18:27] --> Password: 
[22/10/2012 16:18:27] ProcessLogin State: 6
[22/10/2012 16:18:27] Cannot Login to Enable Mode
[22/10/2012 16:18:28] TimerTick: mstrData=<Password: > State=3 - Connected to server - idle
[22/10/2012 16:18:28] Pending Disconnect = True
[22/10/2012 16:18:28] Disconnected - From: 10.199.1.10 


 Expand for explanation of the Session Trace

Detail

See points 1-4 above for explanations of initial communication.

Device sends banner, NCM processes this and confirms it is still connected:
[22/10/2012 16:18:25] --> 
[22/10/2012 16:18:25] --> 
[22/10/2012 16:18:25] --> Authorized Users Only
[22/10/2012 16:18:25] --> 
[22/10/2012 16:18:25] --> 
[22/10/2012 16:18:25] --> Tex-3750>
[22/10/2012 16:18:25] ProcessLogin State: 0
[22/10/2012 16:18:25] --> 
[22/10/2012 16:18:25] --> 
[22/10/2012 16:18:25] ProcessLogin State: 0
[22/10/2012 16:18:25] --->Tex-3750>
[22/10/2012 16:18:25] ProcessLogin State: 0
[22/10/2012 16:18:26] TimerTick: mstrData=<Tex-3750>> State=3 - Connected to server - idle
[22/10/2012 16:18:26] Pending Disconnect = False

NCM Sends a basic 'Enter' / CRLF again, to reconfirm the prompt, and confirms that the prompt was detected, so no initial login details are required.
[22/10/2012 16:18:26] TimerTick: Send to CRLF get prompt again
[22/10/2012 16:18:26] <--

[22/10/2012 16:18:26] --> 
[22/10/2012 16:18:26] --> Tex-3750>
[22/10/2012 16:18:26] ProcessLogin State: 0
[22/10/2012 16:18:26] Custom Prompt detector detect # prompt
[22/10/2012 16:18:26] no credentials needed - Command mode prompt detected
[22/10/2012 16:18:26] Prompt is being set to : Tex-3750>

NCM begins to log into Enable Mode - it sends 'enable', then waits for the echo and response.
[22/10/2012 16:18:26] Logging into Enable Mode
[22/10/2012 16:18:26] <-- enable

[22/10/2012 16:18:26] --->e
[22/10/2012 16:18:26] ProcessLogin State: 5
[22/10/2012 16:18:26] --->n
[22/10/2012 16:18:26] ProcessLogin State: 5
[22/10/2012 16:18:26] --->ab
[22/10/2012 16:18:26] ProcessLogin State: 5
[22/10/2012 16:18:26] --->le

Note: It's common to see a device echo back the command with a few letters at a time like above. If this was on the screen, the user would see 'enable' echoed correctly.
[22/10/2012 16:18:26] ProcessLogin State: 5
[22/10/2012 16:18:26] Enable command echo detected
[22/10/2012 16:18:26] --> 
[22/10/2012 16:18:26] --> 
[22/10/2012 16:18:26] ProcessLogin State: 5
[22/10/2012 16:18:26] Enable command echo detected

The device has echoed the enable command, and requested a password. However, in this trace, NCM simply sends 'enter' (note the new line, but no characters before this)
[22/10/2012 16:18:26] --->Password: 
[22/10/2012 16:18:26] ProcessLogin State: 5
[22/10/2012 16:18:26] <--

[22/10/2012 16:18:27] -->

The device was not expecting a blank password, so it repeats the request for a password
[22/10/2012 16:18:27] --> Password: 
[22/10/2012 16:18:27] ProcessLogin State: 6

At this point, NCM processes the second request for a password as a failure to log in, and disconnects from the device.
[22/10/2012 16:18:27] Cannot Login to Enable Mode
[22/10/2012 16:18:28] TimerTick: mstrData=<Password: > State=3 - Connected to server - idle
[22/10/2012 16:18:28] Pending Disconnect = True
[22/10/2012 16:18:28] Disconnected - From: 10.199.1.10

Example 2: Logging into a device when NCM has been configured with the wrong enable password 


Session Trace

[04/12/2012 18:05:49] -----------------NCM 7.1.1-------------------
[04/12/2012 18:05:49] UseCustomMorePromptBehaviour: False
[04/12/2012 18:05:49] MorePromptKey: 
[04/12/2012 18:05:49] Login Attempts: 1
[04/12/2012 18:05:49] Custom UserName Prompt: 
[04/12/2012 18:05:49] Device Template: 
[04/12/2012 18:05:49] System Name: 
[04/12/2012 18:05:49] System Description: 
[04/12/2012 18:05:49] System OID: 
[04/12/2012 18:05:49] OS Image: 
[04/12/2012 18:05:49] OS Version:

[04/12/2012 18:05:49] Menu-Based mode=False
[04/12/2012 18:05:49] FreezeLoginForPreCommands mode= False
[04/12/2012 18:05:49] 
-->StateChange: Connecting to server<--

[04/12/2012 18:05:49] 
-->StateChange: Connected to server - idle<--

[04/12/2012 18:05:49] Solarwinds.Net SWTelnet9 Version 9.0.27
[04/12/2012 18:05:49] Connected!
[04/12/2012 18:05:49] --> 
[04/12/2012 18:05:49] --> 
[04/12/2012 18:05:49] --> User Access Verification
[04/12/2012 18:05:49] --> 
[04/12/2012 18:05:49] --> Username: 
[04/12/2012 18:05:49] ProcessLogin State: 0
[04/12/2012 18:05:49] UserName Prompt detected: Username: 
[04/12/2012 18:05:49] Send user name
[04/12/2012 18:05:49] <-- admin

[04/12/2012 18:05:50] --> admin
[04/12/2012 18:05:50] --> Password: 
[04/12/2012 18:05:50] ProcessLogin State: 2
[04/12/2012 18:05:50] Standard password prompt detected
[04/12/2012 18:05:50] <-- ********

[04/12/2012 18:05:51] TimerTick: mstrData=<> State=3 - Connected to server - idle
[04/12/2012 18:05:51] Pending Disconnect = False
[04/12/2012 18:05:52] --> 
[04/12/2012 18:05:52] --> % Login invalid
[04/12/2012 18:05:52] --> 
[04/12/2012 18:05:52] --> Username: 
[04/12/2012 18:05:52] ProcessLogin State: 3
[04/12/2012 18:05:52] Cannot Log into router
[04/12/2012 18:05:53] TimerTick: mstrData=<Username: > State=3 - Connected to server - idle
[04/12/2012 18:05:53] Pending Disconnect = True
[04/12/2012 18:05:53] Disconnected - From: 10.199.1.1
[04/12/2012 18:05:53] Disconnecting


 Expand for explanation of the Session Trace

 

 Detail

See points 1-4 above for explanations of initial communication.

Device sends banner & Login Prompt, NCM processes this login challenge:

[04/12/2012 18:05:49] Connected!
[04/12/2012 18:05:49] --> 
[04/12/2012 18:05:49] --> 
[04/12/2012 18:05:49] --> User Access Verification
[04/12/2012 18:05:49] --> 
[04/12/2012 18:05:49] --> Username: 
[04/12/2012 18:05:49] ProcessLogin State: 0
[04/12/2012 18:05:49] UserName Prompt detected: Username:

NCM Sends the configured User name, and waits for the device to echo this and send the password prompt
[04/12/2012 18:05:49] Send user name
[04/12/2012 18:05:49] <-- admin

[04/12/2012 18:05:50] --> admin
[04/12/2012 18:05:50] --> Password:

NCM receives the Password prompt, processes this, and sends the configured password to the device (note, the password is starred in session traces)
[04/12/2012 18:05:50] ProcessLogin State: 2
[04/12/2012 18:05:50] Standard password prompt detected

[04/12/2012 18:05:50] <-- ********

[04/12/2012 18:05:51] TimerTick: mstrData=<> State=3 - Connected to server - idle
[04/12/2012 18:05:51] Pending Disconnect = False

The device responds with a login Invalid prompt, and repeats the login challenge
[04/12/2012 18:05:52] --> 
[04/12/2012 18:05:52] --> % Login invalid
[04/12/2012 18:05:52] --> 
[04/12/2012 18:05:52] --> Username:

NCM processes the login failure, and disconnects from the device
[04/12/2012 18:05:52] ProcessLogin State: 3
[04/12/2012 18:05:52] Cannot Log into router
[04/12/2012 18:05:53] TimerTick: mstrData=<Username: > State=3 - Connected to server - idle
[04/12/2012 18:05:53] Pending Disconnect = True
[04/12/2012 18:05:53] Disconnected - From: 10.199.1.1
[04/12/2012 18:05:53] Disconnecting

 

Example 3: Using the wrong command to display the configuration on a device (incorrect device command template selected) 


Session Trace

[06/11/2012 20:02:55] -----------------NCM 7.1-------------------
[06/11/2012 20:02:55] UseCustomMorePromptBehaviour: False
[06/11/2012 20:02:55] MorePromptKey: 
[06/11/2012 20:02:55] Login Attempts: 1
[06/11/2012 20:02:55] Custom UserName Prompt: 
[06/11/2012 20:02:55] Device Template: Cisco IOS-1.3.6.1.4.1.9.ConfigMgmt-Commands
[06/11/2012 20:02:55] System Name: Tok-ASA5505.default.domain.invalid
[06/11/2012 20:02:55] System Description: Cisco Adaptive Security Appliance Version 8.2(4)
[06/11/2012 20:02:55] System OID: 1.3.6.1.4.1.9.1.745
[06/11/2012 20:02:55] OS Image: 
[06/11/2012 20:02:55] OS Version: 8.2(4)

[06/11/2012 20:02:55] Menu-Based mode=False
[06/11/2012 20:02:55] FreezeLoginForPreCommands mode= False
[06/11/2012 20:02:55] 
-->StateChange: Connecting to server<--

[06/11/2012 20:02:55] 
-->StateChange: Connected to server - idle<--

[06/11/2012 20:02:55] Solarwinds.Net SWTelnet9 Version 9.0.27
[06/11/2012 20:02:55] Connected!
[06/11/2012 20:02:55] --> welcome to the cloud
[06/11/2012 20:02:55] --> Line1
[06/11/2012 20:02:55] --> Line2
[06/11/2012 20:02:55] --> Line3
[06/11/2012 20:02:55] --> 
[06/11/2012 20:02:55] --> 
[06/11/2012 20:02:55] --> User Access Verification
[06/11/2012 20:02:55] --> 
[06/11/2012 20:02:55] --> Password: 
[06/11/2012 20:02:55] ProcessLogin State: 0
[06/11/2012 20:02:55] Standard password prompt detected
[06/11/2012 20:02:55] <-- password

[06/11/2012 20:02:55] --> 
[06/11/2012 20:02:55] --> hello
[06/11/2012 20:02:55] --> Type help or '?' for a list of available commands.
[06/11/2012 20:02:55] --> 
[06/11/2012 20:02:55] --> Tok-ASA5505> 
[06/11/2012 20:02:55] ProcessLogin State: 3
[06/11/2012 20:02:55] Command mode prompt detected at LoginState_Password 
[06/11/2012 20:02:55] Prompt is being set to : Tok-ASA5505>
[06/11/2012 20:02:55] Logged into Router
[06/11/2012 20:02:55] <--

[06/11/2012 20:02:55] --> 
[06/11/2012 20:02:55] --> 
[06/11/2012 20:02:55] Start check prompt for menu-based device
[06/11/2012 20:02:55] Process Line = <>
[06/11/2012 20:02:55] Process Line = <>
[06/11/2012 20:02:56] --> 
[06/11/2012 20:02:56] --> Tok-ASA5505> 
[06/11/2012 20:02:56] Start check prompt for menu-based device
[06/11/2012 20:02:56] Process Line = <>
[06/11/2012 20:02:56] Process Line = <Tok-ASA5505> >
[06/11/2012 20:02:56] Fuzzy match detector start detecting prompt. String1=tok-asa5505> String2=tok-asa5505>
[06/11/2012 20:02:56] <-- terminal width 0

[06/11/2012 20:02:56] --->t
[06/11/2012 20:02:56] Start check prompt for menu-based device
[06/11/2012 20:02:56] Process Line = <t>
[06/11/2012 20:02:56] Fuzzy match detector start detecting prompt. String1=t String2=tok-asa5505>
[06/11/2012 20:02:56] Pushing back: <t>
[06/11/2012 20:02:56] mPrompt is : <Tok-ASA5505>>
[06/11/2012 20:02:56] --> erminal width 0
[06/11/2012 20:02:56] --> ^
[06/11/2012 20:02:56] --> ERROR: % Invalid input detected at '^' marker.
[06/11/2012 20:02:56] --> 
[06/11/2012 20:02:56] --> Tok-ASA5505> 
[06/11/2012 20:02:56] Incomplete buffer with prompt is detected - save all lines to echo buffer
[06/11/2012 20:02:56] Echo not detected yet. Push back data to echo buffer, EchoBuffer = <<<terminal width 0 ^ ERROR: % Invalid input detected at '^' marker. Tok-ASA5505> >>>
[06/11/2012 20:02:56] Start detecting command echo in echo buffer...
[06/11/2012 20:02:56] Echo is detected, EchoBuffer = <<<terminal width 0 ^ ERROR: % Invalid input detected at '^' marker. Tok-ASA5505> >>>
[06/11/2012 20:02:56] Remove Prompt - detected prompt line via RegEx
[06/11/2012 20:02:56] Remove Prompt - prompt line is on invalid place, Save It. value=terminal width 0 ^ ERROR: % Invalid input detected at '^' marker. Tok-ASA5505> FoundPromptLine=Tok-ASA5505> 
[06/11/2012 20:02:56] Echo and prompt are removed if they exist, out buffer = <<<^ ERROR: % Invalid input detected at '^' marker. Tok-ASA5505> >>>
[06/11/2012 20:02:56] Start check prompt for menu-based device
[06/11/2012 20:02:56] Process Line = <^>
[06/11/2012 20:02:56] Fuzzy match detector start detecting prompt. String1=^ String2=tok-asa5505>
[06/11/2012 20:02:56] Save Command Output: ^
[06/11/2012 20:02:56] Process Line = <ERROR: % Invalid input detected at '^' marker.>
[06/11/2012 20:02:56] Fuzzy match detector start detecting prompt. String1=error:%invalidinputdetectedat'^'marker. String2=tok-asa5505>
[06/11/2012 20:02:56] Save Command Output: ERROR: % Invalid input detected at '^' marker.
[06/11/2012 20:02:56] Process Line = <>
[06/11/2012 20:02:56] Process Line = <Tok-ASA5505> >
[06/11/2012 20:02:56] Fuzzy match detector start detecting prompt. String1=tok-asa5505> String2=tok-asa5505>
[06/11/2012 20:02:56] <-- terminal length 0

[06/11/2012 20:02:56] Process Line = <>
[06/11/2012 20:02:56] --->t
[06/11/2012 20:02:56] Start check prompt for menu-based device
[06/11/2012 20:02:56] Process Line = <t>
[06/11/2012 20:02:56] Fuzzy match detector start detecting prompt. String1=t String2=tok-asa5505>
[06/11/2012 20:02:56] Pushing back: <t>
[06/11/2012 20:02:56] mPrompt is : <Tok-ASA5505>>
[06/11/2012 20:02:57] TimerTick: mstrData=<t> State=3 - Connected to server - idle
[06/11/2012 20:02:57] Pending Disconnect = False
[06/11/2012 20:02:57] Fuzzy match detector start detecting prompt. String1=t String2=tok-asa5505>
[06/11/2012 20:02:57] TimerTick: Just tick-tockin away. ..
[06/11/2012 20:02:57] --> erminal length 0
[06/11/2012 20:02:57] --> ^
[06/11/2012 20:02:57] --> ERROR: % Invalid input detected at '^' marker.
[06/11/2012 20:02:57] --> 
[06/11/2012 20:02:57] --> Tok-ASA5505> 
[06/11/2012 20:02:57] Incomplete buffer with prompt is detected - save all lines to echo buffer
[06/11/2012 20:02:57] Echo not detected yet. Push back data to echo buffer, EchoBuffer = <<<terminal length 0 ^ ERROR: % Invalid input detected at '^' marker. Tok-ASA5505> >>>
[06/11/2012 20:02:57] Start detecting command echo in echo buffer...
[06/11/2012 20:02:57] Echo is detected, EchoBuffer = <<<terminal length 0 ^ ERROR: % Invalid input detected at '^' marker. Tok-ASA5505> >>>
[06/11/2012 20:02:57] Remove Prompt - detected prompt line via RegEx
[06/11/2012 20:02:57] Remove Prompt - prompt line is on invalid place, Save It. value=terminal length 0 ^ ERROR: % Invalid input detected at '^' marker. Tok-ASA5505> FoundPromptLine=Tok-ASA5505> 
[06/11/2012 20:02:57] Echo and prompt are removed if they exist, out buffer = <<<^ ERROR: % Invalid input detected at '^' marker. Tok-ASA5505> >>>
[06/11/2012 20:02:57] Start check prompt for menu-based device
[06/11/2012 20:02:57] Process Line = <^>
[06/11/2012 20:02:57] Fuzzy match detector start detecting prompt. String1=^ String2=tok-asa5505>
[06/11/2012 20:02:57] Save Command Output: ^
[06/11/2012 20:02:57] Process Line = <ERROR: % Invalid input detected at '^' marker.>
[06/11/2012 20:02:57] Fuzzy match detector start detecting prompt. String1=error:%invalidinputdetectedat'^'marker. String2=tok-asa5505>
[06/11/2012 20:02:57] Save Command Output: ERROR: % Invalid input detected at '^' marker.
[06/11/2012 20:02:57] Process Line = <>
[06/11/2012 20:02:57] Process Line = <Tok-ASA5505> >
[06/11/2012 20:02:57] Fuzzy match detector start detecting prompt. String1=tok-asa5505> String2=tok-asa5505>
[06/11/2012 20:02:57] <-- Show running

[06/11/2012 20:02:57] Process Line = <>
[06/11/2012 20:02:57] --->S
[06/11/2012 20:02:57] Start check prompt for menu-based device
[06/11/2012 20:02:57] Process Line = <S>
[06/11/2012 20:02:57] Fuzzy match detector start detecting prompt. String1=s String2=tok-asa5505>
[06/11/2012 20:02:57] Pushing back: <S>
[06/11/2012 20:02:57] mPrompt is : <Tok-ASA5505>>
[06/11/2012 20:02:57] --> how running
[06/11/2012 20:02:57] --> 
[06/11/2012 20:02:57] Complete buffer is detected - save all lines to echo buffer
[06/11/2012 20:02:57] Echo not detected yet. Push back data to echo buffer, EchoBuffer = <<<Show running >>>
[06/11/2012 20:02:57] Start detecting command echo in echo buffer...
[06/11/2012 20:02:57] Echo is detected, EchoBuffer = <<<Show running >>>
[06/11/2012 20:02:57] Remove Prompt - prompt not found via RegEx
[06/11/2012 20:02:57] Echo and prompt are removed if they exist, out buffer = <<<>>>
[06/11/2012 20:02:57] Start check prompt for menu-based device
[06/11/2012 20:02:59] TimerTick: mstrData=<S> State=3 - Connected to server - idle
[06/11/2012 20:02:59] Pending Disconnect = False
[06/11/2012 20:02:59] Fuzzy match detector start detecting prompt. String1=s String2=tok-asa5505>
[06/11/2012 20:02:59] TimerTick: Just tick-tockin away. ..
[06/11/2012 20:02:59] ---> 
[06/11/2012 20:02:59] Start check prompt for menu-based device
[06/11/2012 20:02:59] Process Line = < >
[06/11/2012 20:02:59] Config Prompt detector error: Invalid procedure call or argumentCurrentLine: 
[06/11/2012 20:02:59] Fuzzy match detector start detecting prompt. String1= String2=tok-asa5505>
[06/11/2012 20:02:59] Pushing back: < >
[06/11/2012 20:02:59] mPrompt is : <Tok-ASA5505>>
[06/11/2012 20:02:59] --> ^
[06/11/2012 20:02:59] --> ERROR: % Invalid input detected at '^' marker.
[06/11/2012 20:02:59] --> 
[06/11/2012 20:02:59] --> Tok-ASA5505> 
[06/11/2012 20:02:59] Start check prompt for menu-based device
[06/11/2012 20:02:59] Process Line = < ^>
[06/11/2012 20:02:59] Fuzzy match detector start detecting prompt. String1=^ String2=tok-asa5505>
[06/11/2012 20:02:59] Save Command Output: ^
[06/11/2012 20:02:59] Process Line = <ERROR: % Invalid input detected at '^' marker.>
[06/11/2012 20:02:59] Fuzzy match detector start detecting prompt. String1=error:%invalidinputdetectedat'^'marker. String2=tok-asa5505>
[06/11/2012 20:02:59] Save Command Output: ERROR: % Invalid input detected at '^' marker.
[06/11/2012 20:02:59] Process Line = <>
[06/11/2012 20:02:59] Process Line = <Tok-ASA5505> >
[06/11/2012 20:02:59] Fuzzy match detector start detecting prompt. String1=tok-asa5505> String2=tok-asa5505>
[06/11/2012 20:02:59] SendNextCommand Done: Disconnecting
[06/11/2012 20:03:01] TimerTick: mstrData=<Tok-ASA5505> > State=3 - Connected to server - idle
[06/11/2012 20:03:01] Pending Disconnect = True
[06/11/2012 20:03:01] Disconnected - From: 10.199.2.30


 Expand for explanation of the Session Trace

 

 Detail

See points 1-4 above for explanations of initial communication.

Device sends banner & Login Prompt, NCM provides the correct login username and password, and is provided with the device command prompt:

[06/11/2012 20:02:55] Connected!
[06/11/2012 20:02:55] --> welcome to the cloud
[06/11/2012 20:02:55] --> Line1
[06/11/2012 20:02:55] --> Line2
[06/11/2012 20:02:55] --> Line3
[06/11/2012 20:02:55] --> 
[06/11/2012 20:02:55] --> 
[06/11/2012 20:02:55] --> User Access Verification
[06/11/2012 20:02:55] --> 
[06/11/2012 20:02:55] --> Password: 
[06/11/2012 20:02:55] ProcessLogin State: 0
[06/11/2012 20:02:55] Standard password prompt detected
[06/11/2012 20:02:55] <-- password

[06/11/2012 20:02:55] --> 
[06/11/2012 20:02:55] --> hello
[06/11/2012 20:02:55] --> Type help or '?' for a list of available commands.
[06/11/2012 20:02:55] --> 
[06/11/2012 20:02:55] --> Tok-ASA5505>

NCM detects the command prompt, and sets a variable to remember this, so that it can match for it later. It sends a few empty commands (enter key), to confirm the prompt before setting the variable.

[06/11/2012 20:02:55] ProcessLogin State: 3
[06/11/2012 20:02:55] Command mode prompt detected at LoginState_Password 
[06/11/2012 20:02:55] Prompt is being set to : Tok-ASA5505>
[06/11/2012 20:02:55] Logged into Router
[06/11/2012 20:02:55] <--

[06/11/2012 20:02:55] --> 
[06/11/2012 20:02:55] --> 
[06/11/2012 20:02:55] Start check prompt for menu-based device
[06/11/2012 20:02:55] Process Line = <>
[06/11/2012 20:02:55] Process Line = <>
[06/11/2012 20:02:56] --> 
[06/11/2012 20:02:56] --> Tok-ASA5505> 
[06/11/2012 20:02:56] Start check prompt for menu-based device
[06/11/2012 20:02:56] Process Line = <>
[06/11/2012 20:02:56] Process Line = <Tok-ASA5505> >
[06/11/2012 20:02:56] Fuzzy match detector start detecting prompt. String1=tok-asa5505> String2=tok-asa5505>

NCM sends the command 'terminal width 0', as part of setting the device to display the entire configuration in one go, so that it will not need to 'spacebar' through '--More–' prompts. Unfortunately, the device does not understand this command, and the device echoes the entire command back to NCM, along with an error message.
[06/11/2012 20:02:56] <-- terminal width 0

[06/11/2012 20:02:56] --->t
[06/11/2012 20:02:56] Start check prompt for menu-based device
[06/11/2012 20:02:56] Process Line = <t>
[06/11/2012 20:02:56] Fuzzy match detector start detecting prompt. String1=t String2=tok-asa5505>
[06/11/2012 20:02:56] Pushing back: <t>
[06/11/2012 20:02:56] mPrompt is : <Tok-ASA5505>>
[06/11/2012 20:02:56] --> erminal width 0
[06/11/2012 20:02:56] --> ^
[06/11/2012 20:02:56] --> ERROR: % Invalid input detected at '^' marker.
[06/11/2012 20:02:56] --> 
[06/11/2012 20:02:56] --> Tok-ASA5505>

NCM must now process all lines received from the device, including the error message, and the command it initially sent. It must find the prompt before it can send the next command.
[06/11/2012 20:02:56] Incomplete buffer with prompt is detected - save all lines to echo buffer
[06/11/2012 20:02:56] Echo not detected yet. Push back data to echo buffer, EchoBuffer = <<<terminal width 0 ^ ERROR: % Invalid input detected at '^' marker. Tok-ASA5505> >>>
[06/11/2012 20:02:56] Start detecting command echo in echo buffer...
[06/11/2012 20:02:56] Echo is detected, EchoBuffer = <<<terminal width 0 ^ ERROR: % Invalid input detected at '^' marker. Tok-ASA5505> >>>
[06/11/2012 20:02:56] Remove Prompt - detected prompt line via RegEx
[06/11/2012 20:02:56] Remove Prompt - prompt line is on invalid place, Save It. value=terminal width 0 ^ ERROR: % Invalid input detected at '^' marker. Tok-ASA5505> FoundPromptLine=Tok-ASA5505> 
[06/11/2012 20:02:56] Echo and prompt are removed if they exist, out buffer = <<<^ ERROR: % Invalid input detected at '^' marker. Tok-ASA5505> >>>
[06/11/2012 20:02:56] Start check prompt for menu-based device
[06/11/2012 20:02:56] Process Line = <^>
[06/11/2012 20:02:56] Fuzzy match detector start detecting prompt. String1=^ String2=tok-asa5505>
[06/11/2012 20:02:56] Save Command Output: ^
[06/11/2012 20:02:56] Process Line = <ERROR: % Invalid input detected at '^' marker.>
[06/11/2012 20:02:56] Fuzzy match detector start detecting prompt. String1=error:%invalidinputdetectedat'^'marker. String2=tok-asa5505>
[06/11/2012 20:02:56] Save Command Output: ERROR: % Invalid input detected at '^' marker.
[06/11/2012 20:02:56] Process Line = <>
[06/11/2012 20:02:56] Process Line = <Tok-ASA5505> >
[06/11/2012 20:02:56] Fuzzy match detector start detecting prompt. String1=tok-asa5505> String2=tok-asa5505>

The same thing happens when NCM attempts to send the 'terminal length 0' command. The terminal width 0 and terminal length 0 is set as part of the 'RESET' command in the device command template. As this device does not understand it, it would make sense to remove those commands from the device command template when the user creates a new command template for this particular device.
[06/11/2012 20:02:56] <-- terminal length 0

[06/11/2012 20:02:56] Process Line = <>
[06/11/2012 20:02:56] --->t
[06/11/2012 20:02:56] Start check prompt for menu-based device
[06/11/2012 20:02:56] Process Line = <t>
[06/11/2012 20:02:56] Fuzzy match detector start detecting prompt. String1=t String2=tok-asa5505>
[06/11/2012 20:02:56] Pushing back: <t>
[06/11/2012 20:02:56] mPrompt is : <Tok-ASA5505>>
[06/11/2012 20:02:57] TimerTick: mstrData=<t> State=3 - Connected to server - idle
[06/11/2012 20:02:57] Pending Disconnect = False
[06/11/2012 20:02:57] Fuzzy match detector start detecting prompt. String1=t String2=tok-asa5505>
[06/11/2012 20:02:57] TimerTick: Just tick-tockin away. ..
[06/11/2012 20:02:57] --> erminal length 0
[06/11/2012 20:02:57] --> ^
[06/11/2012 20:02:57] --> ERROR: % Invalid input detected at '^' marker.
[06/11/2012 20:02:57] --> 
[06/11/2012 20:02:57] --> Tok-ASA5505> 
[06/11/2012 20:02:57] Incomplete buffer with prompt is detected - save all lines to echo buffer
[06/11/2012 20:02:57] Echo not detected yet. Push back data to echo buffer, EchoBuffer = <<<terminal length 0 ^ ERROR: % Invalid input detected at '^' marker. Tok-ASA5505> >>>
[06/11/2012 20:02:57] Start detecting command echo in echo buffer...
[06/11/2012 20:02:57] Echo is detected, EchoBuffer = <<<terminal length 0 ^ ERROR: % Invalid input detected at '^' marker. Tok-ASA5505> >>>
[06/11/2012 20:02:57] Remove Prompt - detected prompt line via RegEx
[06/11/2012 20:02:57] Remove Prompt - prompt line is on invalid place, Save It. value=terminal length 0 ^ ERROR: % Invalid input detected at '^' marker. Tok-ASA5505> FoundPromptLine=Tok-ASA5505> 
[06/11/2012 20:02:57] Echo and prompt are removed if they exist, out buffer = <<<^ ERROR: % Invalid input detected at '^' marker. Tok-ASA5505> >>>
[06/11/2012 20:02:57] Start check prompt for menu-based device
[06/11/2012 20:02:57] Process Line = <^>
[06/11/2012 20:02:57] Fuzzy match detector start detecting prompt. String1=^ String2=tok-asa5505>
[06/11/2012 20:02:57] Save Command Output: ^
[06/11/2012 20:02:57] Process Line = <ERROR: % Invalid input detected at '^' marker.>
[06/11/2012 20:02:57] Fuzzy match detector start detecting prompt. String1=error:%invalidinputdetectedat'^'marker. String2=tok-asa5505>
[06/11/2012 20:02:57] Save Command Output: ERROR: % Invalid input detected at '^' marker.
[06/11/2012 20:02:57] Process Line = <>
[06/11/2012 20:02:57] Process Line = <Tok-ASA5505> >

NCM finds the prompt, and proceeds on to requesting the configuration from the device. The fact that the Reset commands failed is not really an issue - if it can display the configuration, NCM will be capably of navigating the 'more' prompt for most device types. However, it might mean that the 'more' prompt would be saved in the backed up configurations.

NCM sends the 'show running' command to the device, and waits for this to be echoed, and for the device to begin displaying the configuration
[06/11/2012 20:02:57] Fuzzy match detector start detecting prompt. String1=tok-asa5505> String2=tok-asa5505>
[06/11/2012 20:02:57] <-- Show running

[06/11/2012 20:02:57] Process Line = <>
[06/11/2012 20:02:57] --->S
[06/11/2012 20:02:57] Start check prompt for menu-based device
[06/11/2012 20:02:57] Process Line = <S>
[06/11/2012 20:02:57] Fuzzy match detector start detecting prompt. String1=s String2=tok-asa5505>
[06/11/2012 20:02:57] Pushing back: <S>
[06/11/2012 20:02:57] mPrompt is : <Tok-ASA5505>>
[06/11/2012 20:02:57] --> how running
[06/11/2012 20:02:57] --> 
[06/11/2012 20:02:57] Complete buffer is detected - save all lines to echo buffer
[06/11/2012 20:02:57] Echo not detected yet. Push back data to echo buffer, EchoBuffer = <<<Show running >>>
[06/11/2012 20:02:57] Start detecting command echo in echo buffer...
[06/11/2012 20:02:57] Echo is detected, EchoBuffer = <<<Show running >>>
[06/11/2012 20:02:57] Remove Prompt - prompt not found via RegEx
[06/11/2012 20:02:57] Echo and prompt are removed if they exist, out buffer = <<<>>>

There's a 2 second jump in the timing here, and NCM logs 'just tick-tockin' away' to note the long delay in response time from the device 
[06/11/2012 20:02:57] Start check prompt for menu-based device
[06/11/2012 20:02:59] TimerTick: mstrData=<S> State=3 - Connected to server - idle
[06/11/2012 20:02:59] Pending Disconnect = False
[06/11/2012 20:02:59] Fuzzy match detector start detecting prompt. String1=s String2=tok-asa5505>
[06/11/2012 20:02:59] TimerTick: Just tick-tockin away. ..
[06/11/2012 20:02:59] ---> 
[06/11/2012 20:02:59] Start check prompt for menu-based device
[06/11/2012 20:02:59] Process Line = < >
[06/11/2012 20:02:59] Config Prompt detector error: Invalid procedure call or argumentCurrentLine: 
[06/11/2012 20:02:59] Fuzzy match detector start detecting prompt. String1= String2=tok-asa5505>
[06/11/2012 20:02:59] Pushing back: < >
[06/11/2012 20:02:59] mPrompt is : <Tok-ASA5505>>

The device finally completes its response, but unfortunately, it didn't understand the 'show running' command.
[06/11/2012 20:02:59] --> ^
[06/11/2012 20:02:59] --> ERROR: % Invalid input detected at '^' marker.
[06/11/2012 20:02:59] --> 
[06/11/2012 20:02:59] --> Tok-ASA5505>

NCM processes the response, and disconnects from the device
[06/11/2012 20:02:59] Start check prompt for menu-based device
[06/11/2012 20:02:59] Process Line = < ^>
[06/11/2012 20:02:59] Fuzzy match detector start detecting prompt. String1=^ String2=tok-asa5505>
[06/11/2012 20:02:59] Save Command Output: ^
[06/11/2012 20:02:59] Process Line = <ERROR: % Invalid input detected at '^' marker.>
[06/11/2012 20:02:59] Fuzzy match detector start detecting prompt. String1=error:%invalidinputdetectedat'^'marker. String2=tok-asa5505>
[06/11/2012 20:02:59] Save Command Output: ERROR: % Invalid input detected at '^' marker.
[06/11/2012 20:02:59] Process Line = <>
[06/11/2012 20:02:59] Process Line = <Tok-ASA5505> >
[06/11/2012 20:02:59] Fuzzy match detector start detecting prompt. String1=tok-asa5505> String2=tok-asa5505>
[06/11/2012 20:02:59] SendNextCommand Done: Disconnecting
[06/11/2012 20:03:01] TimerTick: mstrData=<Tok-ASA5505> > State=3 - Connected to server - idle
[06/11/2012 20:03:01] Pending Disconnect = True
[06/11/2012 20:03:01] Disconnected - From: 10.199.2.30