09-02-2020 05:04 AM
Hello experts,
I am scratching my head trying to figure out if someone has logged into one of our voice gateways and issued commands without us knowing. This is highly unlikely, but after our network guys enabled archiving on the gateway, we are seeing some strange commands. Showing up in the logs (see snippet below).
This is a Cisco 2911 running 15.7(3)M4a and is configured with an ISDN PRI (20 channels) back hauled to CUCM 12.5 using MGCP.
The question is, how does MGCP work its magic behind the scenes in a failover / WAN outage event? Does it actually try bind layer 3 and shut/no shut the serial interface? There is no evidence of anyone logging into this router during the timestamps in the logs below so we need to understand if this is merely MGCP doing its work and we are now catching it via archiving? Or is something else going on here?
002574: *Aug 27 12:26:29.086 EDT: %PARSER-5-CFGLOG_LOGGEDCMD: User:vty0 logged command:interface Serial0/0/0:15
002575: *Aug 27 12:26:29.086 EDT: %PARSER-5-CFGLOG_LOGGEDCMD: User:vty0 logged command:no isdn bind-l3 ccm-manager
002576: *Aug 27 12:26:29.086 EDT: %SYS-5-CONFIG_I: Configured from console by vty0
002578: *Aug 27 12:26:32.286 EDT: %PARSER-5-CFGLOG_LOGGEDCMD: User:vty0 logged command:interface Serial0/0/0:15
002579: *Aug 27 12:26:32.286 EDT: %PARSER-5-CFGLOG_LOGGEDCMD: User:vty0 logged command:no shutdown
002580: *Aug 27 12:26:32.286 EDT: %SYS-5-CONFIG_I: Configured from console by vty0
002582: *Aug 27 12:28:29.686 EDT: %PARSER-5-CFGLOG_LOGGEDCMD: User:vty0 logged command:interface Serial0/0/0:15
002583: *Aug 27 12:28:29.686 EDT: %PARSER-5-CFGLOG_LOGGEDCMD: User:vty0 logged command:shutdown
002584: *Aug 27 12:28:29.686 EDT: %SYS-5-CONFIG_I: Configured from console by vty0
002585: *Aug 27 12:28:30.386 EDT: %PARSER-5-CFGLOG_LOGGEDCMD: User:vty0 logged command:interface Serial0/0/0:15
002586: *Aug 27 12:28:30.386 EDT: %PARSER-5-CFGLOG_LOGGEDCMD: User:vty0 logged command:isdn bind-l3 ccm-manager
002587: *Aug 27 12:28:30.386 EDT: %SYS-5-CONFIG_I: Configured from console by vty0
002589: *Aug 27 12:28:34.086 EDT: %PARSER-5-CFGLOG_LOGGEDCMD: User:vty0 logged command:interface Serial0/0/0:15
002590: *Aug 27 12:28:34.086 EDT: %PARSER-5-CFGLOG_LOGGEDCMD: User:vty0 logged command:no shutdown
Solved! Go to Solution.
09-03-2020 10:43 AM - edited 09-03-2020 10:48 AM
I would say it’s the MGCP fallback mechanism for the gateway to operate the ISDN link in SRST mode that would be at play here.
For more information please check this document, https://community.cisco.com/t5/collaboration-voice-and-video/understanding-mgcp-gateway-fallback-process/ta-p/3121714
09-02-2020 05:29 AM
These are manual configurations changes. User:vty0 (ssh/telent)
interface Serial0/0/0:15
no isdn bind-l3 ccm-manager
interface Serial0/0/0:15
no shutdown
interface Serial0/0/0:15
shutdown
interface Serial0/0/0:15
isdn bind-l3 ccm-manager
interface Serial0/0/0:15
no shutdown
09-02-2020 06:23 AM
Nithin,
Thank you for your response. At first glance, this is what we suspect as well. However, there is no indication of anyone logging in via SSH before these time stamps. On Aug 26th, July 30th and July 7, we witness the same results. Looking at Aug 26th logs (sent to Splunk) I can see that the interface goes administratively down, followed by the same interface, no shut commands issue. However, there are no logs of users logging in before or after these same commands and issued.
1) %LINK-5-CHANGED: Interface Serial0/0/0:15, changed state to administratively down
2) %PARSER-5-CFGLOG_LOGGEDCMD: User:vty0 logged command:interface Serial0/0/0:15
3) %PARSER-5-CFGLOG_LOGGEDCMD: User:vty0 logged command:no shutdown
4) %SYS-5-CONFIG_I: Configured from console by vty0
09-02-2020 09:27 AM
MGCP will not issue below commands.
interface Serial0/0/0:15
no shutdown.
09-03-2020 08:08 AM
Anyone else have any thoughts?
We ran a simulated WAN outage effectively disconnecting the voice gateway from its ability to talk to call manager. After regaining connectivity and reviewing the logs, we can see that the same shut, no isdn bind-l3 ccm-manager followed by the shut, isdn bind-l3 ccm-manager, no shut commands in the logs.
002699: *Sep 3 10:26:49.213 EDT: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet0/1, changed state to down
002700: *Sep 3 10:26:50.213 EDT: %LINK-3-UPDOWN: Interface GigabitEthernet0/1, changed state to down
002701: *Sep 3 10:26:50.213 EDT: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet0/0, changed state to down
002702: *Sep 3 10:26:51.229 EDT: %LINK-3-UPDOWN: Interface GigabitEthernet0/0, changed state to down
002703: *Sep 3 10:26:54.281 EDT: %LINEPROTO-5-UPDOWN: Line protocol on Interface Port-channel1, changed state to down
002704: *Sep 3 10:27:43.385 EDT: %PARSER-5-CFGLOG_LOGGEDCMD: User:vty0 logged command:interface Serial0/0/0:15
002705: *Sep 3 10:27:43.385 EDT: %PARSER-5-CFGLOG_LOGGEDCMD: User:vty0 logged command:shutdown
002706: *Sep 3 10:27:43.385 EDT: %SYS-5-CONFIG_I: Configured from console by vty0
002707: *Sep 3 10:27:44.085 EDT: %PARSER-5-CFGLOG_LOGGEDCMD: User:vty0 logged command:interface Serial0/0/0:15
002708: *Sep 3 10:27:44.085 EDT: %PARSER-5-CFGLOG_LOGGEDCMD: User:vty0 logged command:no isdn bind-l3 ccm-manager
002709: *Sep 3 10:27:44.085 EDT: %SYS-5-CONFIG_I: Configured from console by vty0
002710: *Sep 3 10:27:45.385 EDT: %LINK-5-CHANGED: Interface Serial0/0/0:15, changed state to administratively down
002711: *Sep 3 10:27:47.285 EDT: %PARSER-5-CFGLOG_LOGGEDCMD: User:vty0 logged command:interface Serial0/0/0:15
002712: *Sep 3 10:27:47.285 EDT: %PARSER-5-CFGLOG_LOGGEDCMD: User:vty0 logged command:no shutdown
002713: *Sep 3 10:27:47.285 EDT: %SYS-5-CONFIG_I: Configured from console by vty0
002714: *Sep 3 10:27:49.285 EDT: %LINK-3-UPDOWN: Interface Serial0/0/0:15, changed state to up
002715: *Sep 3 10:29:42.213 EDT: %LINK-3-UPDOWN: Interface GigabitEthernet0/0, changed state to up
002716: *Sep 3 10:29:42.333 EDT: %LINK-3-UPDOWN: Interface GigabitEthernet0/1, changed state to up
002717: *Sep 3 10:29:43.213 EDT: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet0/0, changed state to up
002718: *Sep 3 10:29:43.333 EDT: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet0/1, changed state to up
002719: *Sep 3 10:29:45.333 EDT: %LINEPROTO-5-UPDOWN: Line protocol on Interface Port-channel1, changed state to up
09-03-2020 10:43 AM - edited 09-03-2020 10:48 AM
I would say it’s the MGCP fallback mechanism for the gateway to operate the ISDN link in SRST mode that would be at play here.
For more information please check this document, https://community.cisco.com/t5/collaboration-voice-and-video/understanding-mgcp-gateway-fallback-process/ta-p/3121714
09-05-2020 12:21 AM - edited 09-05-2020 12:29 AM
As @Roger Kallberg mentioned it's MGCP fallback process. Please ignore my previous reply.
I tested this on my lab gateway and I have noticed that during the Wan outage, router will remove the isdn bind-l3 CCM command. and once the connections is restored, it will readd the isdn bind-l3 CCM command. lab router logs below. so . its MGCP fallback process.
+++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
MGCP REGISTERED STATUS
+++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
XXX#sh run int ser0/1/0:15
Building configuration...
Current configuration : 151 bytes
!
interface Serial0/1/0:15
encapsulation hdlc
isdn switch-type primary-net5
isdn incoming-voice voice
isdn bind-l3 ccm-manager
no cdp enable
end
XXX#sh ccm-manager
MGCP Domain Name: XXX.XXX.om
Priority Status Host
============================================================
Primary Registered 10.60.51.10
First Backup None
Second Backup None
Current active Call Manager: 10.60.51.10
Backhaul/Redundant link port: 2428
Failover Interval: 30 seconds
Keepalive Interval: 15 seconds
Last keepalive sent: 11:05:27 GMT Sep 5 2020 (elapsed time: 00:00:11)
Last MGCP traffic time: 11:05:27 GMT Sep 5 2020 (elapsed time: 00:00:11)
Last failover time: None
Last switchback time: None
Switchback mode: Immediate
MGCP Fallback mode: Enabled/OFF
Last MGCP Fallback start time: 11:01:43 GMT Sep 5 2020
Last MGCP Fallback end time: 11:03:57 GMT Sep 5 2020
MGCP Download Tones: Disabled
TFTP retry count to shut Ports: 2
Backhaul Link info:
+++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
FALLBACK
+++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
XXX#sh ccm-manager
MGCP Domain Name:XXX.XXX.om
Priority Status Host
============================================================
Primary Down 10.60.51.10
First Backup None
Second Backup None
Current active Call Manager: None
Backhaul/Redundant link port: 2428
Failover Interval: 30 seconds
Keepalive Interval: 15 seconds
Last keepalive sent: 11:05:42 GMT Sep 5 2020 (elapsed time: 00:01:08)
Last MGCP traffic time: 11:05:27 GMT Sep 5 2020 (elapsed time: 00:01:23)
Last failover time: None
Last switchback time: None
Switchback mode: Immediate
MGCP Fallback mode: Enabled/ON
Last MGCP Fallback start time: 11:06:14 GMT Sep 5 2020
Last MGCP Fallback end time: 11:03:57 GMT Sep 5 2020
MGCP Download Tones: Disabled
TFTP retry count to shut Ports: 2
FAX mode: cisco
Log Buffer (4096 bytes):
changed state to administratively down
Sep 5 07:01:32.988: %SYS-5-CONFIG_I: Configured from console by console
Sep 5 07:01:33.683: %ISDN-6-LAYER2UP: Layer 2 for Interface Se0/1/0:15, TEI 0 changed to up
Sep 5 07:01:34.988: %LINK-3-UPDOWN: Interface Serial0/1/0:15, changed state to up
Sep 5 07:01:34.988: %LINK-3-UPDOWN: Interface Serial0/1/0:0, changed state to down
Sep 5 07:01:34.988: %LINK-3-UPDOWN: Interface Serial0/1/0:1, changed state to down
Sep 5 07:01:34.988: %LINK-3-UPDOWN: Interface Serial0/1/0:2, changed state to down
Sep 5 07:01:34.988: %LINK-3-UPDOWN: Interface Serial0/1/0:3, changed state to down
Sep 5 07:01:34.988: %LINK-3-UPDOWN: Interface Serial0/1/0:4, changed state to down
Sep 5 07:01:34.988: %LINK-3-UPDOWN: Interface Serial0/1/0:5, changed state to down
Sep 5 07:01:34.988: %LINK-3-UPDOWN: Interface Serial0/1/0:6, changed state to down
Sep 5 07:01:34.988: %LINK-3-UPDOWN: Interface Serial0/1/0:7, changed state to down
Sep 5 07:01:34.988: %LINK-3-UPDOWN: Interface Serial0/1/0:8, changed state to down
Sep 5 07:01:34.988: %LINK-3-UPDOWN: Interface Serial0/1/0:9, changed state to down
Sep 5 07:03:25.199: %SYS-5-CONFIG_I: Configured from console by mhdcisco on vty0 (10.212.134.200)
Sep 5 07:03:42.104: %SYS-5-CONFIG_I: Configured from console by console
Sep 5 07:03:42.105: %ISDN-6-LAYER2DOWN: Layer 2 for Interface Se0/1/0:15, TEI 0 changed to down
Sep 5 07:03:42.806: %SYS-5-CONFIG_I: Configured from console by console
Sep 5 07:03:44.104: %LINK-5-CHANGED: Interface Serial0/1/0:15, changed state to administratively down
Sep 5 07:03:46.509: %SYS-5-CONFIG_I: Configured from console by console
Sep 5 07:03:48.508: %LINK-3-UPDOWN: Interface Serial0/1/0:15, changed state to up
Sep 5 07:03:48.508: %LINK-3-UPDOWN: Interface Serial0/1/0:0, changed state to down
Sep 5 07:03:48.508: %LINK-3-UPDOWN: Interface Serial0/1/0:1, changed state to down
Sep 5 07:03:48.508: %LINK-3-UPDOWN: Interface Serial0/1/0:2, changed state to down
Sep 5 07:03:48.508: %LINK-3-UPDOWN: Interface Serial0/1/0:3, changed state to down
Sep 5 07:03:48.508: %LINK-3-UPDOWN: Interface Serial0/1/0:4, changed state to down
Sep 5 07:03:48.508: %LINK-3-UPDOWN: Interface Serial0/1/0:5, changed state to down
Sep 5 07:03:48.508: %LINK-3-UPDOWN: Interface Serial0/1/0:6, changed state to down
Sep 5 07:03:48.508: %LINK-3-UPDOWN: Interface Serial0/1/0:7, changed state to down
Sep 5 07:03:48.508: %LINK-3-UPDOWN: Interface Serial0/1/0:8, changed state to down
Sep 5 07:03:48.508: %LINK-3-UPDOWN: Interface Serial0/1/0:9, changed state to down
Sep 5 07:03:50.924: %ISDN-6-LAYER2UP: Layer 2 for Interface Se0/1/0:15, TEI 0 changed to up
Sep 5 07:05:59.214: %SYS-5-CONFIG_I: Configured from console by console
Sep 5 07:05:59.215: %ISDN-6-LAYER2DOWN: Layer 2 for Interface Se0/1/0:15, TEI 0 changed to down
Sep 5 07:05:59.916: %SYS-5-CONFIG_I: Configured from console by console
Sep 5 07:06:01.213: %LINK-5-CHANGED: Interface Serial0/1/0:15, changed state to administratively down
Sep 5 07:06:03.119: %SYS-5-CONFIG_I: Configured from console by console
XXX#sh isd status
Global ISDN Switchtype = primary-net5
ISDN Serial0/1/0:15 interface
dsl 0, interface ISDN Switchtype = primary-net5
Layer 1 Status:
ACTIVE
Layer 2 Status:
TEI = 0, Ces = 1, SAPI = 0, State = MULTIPLE_FRAME_ESTABLISHED
Layer 3 Status:
0 Active Layer 3 Call(s)
Active dsl 0 CCBs = 0
The Free Channel Mask: 0x800003FF
Number of L2 Discards = 0, L2 Session ID = 7
Total Allocated ISDN CCBs = 0
XXX#sh controlle
XXX#sh inter ser
XXX#sh run int ser0/1/0:15
Building configuration...
Current configuration : 125 bytes
!
interface Serial0/1/0:15
encapsulation hdlc
isdn switch-type primary-net5
isdn incoming-voice voice
no cdp enable
end
09-08-2020 04:41 AM
Roger,
Thank you for that link. I have reviewed that document once before and we assumed that MGCP fallback was causing these commands. However that link/document does not go into further detail of "how" MGCP actually accomplishes the failover other than a high level process.
In any event, the main concern was that someone had access to our network, which was proved to not be the case. Thanks for your help.
Discover and save your favorite ideas. Come back to expert answers, step-by-step guides, recent topics, and more.
New here? Get started with these tips. How to use Community New member guide