[c-nsp] ASR920 and EEM:Mandatory.dualrate_eem.tcl

[Aaron]

Any unexpected config change should be an automatic tac case.
Totally unexpected. Reminds me of the days when swapping a flash card on a
gsr could crash it.
This is a new one .

On Monday, August 26, 2019, Gert Doering <gert at greenie.muc.de> wrote:

> Hi,
>
> does anyone know what "EEM:Mandatory.dualrate_eem.tcl" is?
>
> We have an ASR920 that grew an unexpected config change upon insertion
> of a DAC cable into port ten0/0/12, and "unexpected config change" always
> triggers an investigation here (who, why, what).  One part of it was
> somewhat related
>
>  interface TenGigabitEthernet0/0/12
>   description ...
>   no ip address
> + negotiation auto
>   service instance 200 ethernet
>
> ... but the other part was more interesting
>
>  line vty 0 4
>   access-class 9 in
> - exec-timeout 240 0
>   ipv6 access-class VTY-v6 in
> - transport input telnet ssh
> + transport preferred none
> + transport input none
> + transport output none
>   escape-character 3
>
> "uh, what?".  So we investigated and found a few log messages about that
> script...
>
> Aug 20 13:45:30 CEST: %TRANSCEIVER-6-INSERTED:  F0: iomd:  transceiver
> module inserted in TenGigabitEthernet0/0/12
> <SNIP>
> Aug 20 13:45:45 CEST: %IOSXE_SPA-6-DUAL_RATE_CHANGE:
> TenGigabitEthernet0/0/12: MODE_1G
> Aug 20 13:45:47 CEST: %SYS-5-CONFIG_I: Configured from console by  on vty1
> (EEM:Mandatory.dualrate_eem.tcl)
> Aug 20 13:46:14 CEST: %SYS-5-CONFIG_I: Configured from console by  on vty1
> (EEM:Mandatory.dualrate_eem.tcl)
> Aug 20 13:46:15 CEST: %SYS-5-CONFIG_I: Configured from console by  on vty0
> (EEM:Mandatory.dualrate_eem.tcl)
> Aug 20 13:46:17 CEST: %TRANSCEIVER-6-REMOVED:  F0: iomd:  Transceiver
> module removed from TenGigabitEthernet0/0/12
> Aug 20 13:46:20 CEST: %IOSXE-5-PLATFORM:  F0: Aug 20 13:46:20
> %SYSTEM-3-SYSTEM_SHELL_LOG: Shell started: vty 1
> Aug 20 13:46:20 CEST: %IOSXE-5-PLATFORM:  F0: Aug 20 13:46:20
> %SYSTEM-3-SYSTEM_SHELL_LOG: 2019/08/20 13:46:19 : Shell access was granted
> to user <anon>; Trace file: , /harddisk/tracelogs/system_
> shell_R0-0.2264_0.20190820134619.bin
> ug 20 13:46:26 CEST: %HA_EM-6-LOG: Mandatory.dualrate_eem.tcl:
> DUAL_RATE_CHANGE Re-configuration of interface TenGigabitEthernet0/0/12 to
> start re-configuring
> Aug 20 13:46:28 CEST: %SYS-5-CONFIG_I: Configured from console by  on vty1
> (EEM:Mandatory.dualrate_eem.tcl)
> Aug 20 13:46:39 CEST: %SYS-5-CONFIG_C: Running-config file is Modified
>
>
> ... and 441 (!!) lines in the tacacs command accounting log, which
> mostly looked like "it replayed the whole config, line by line"...
> until it hit the vty section, which then got messed up...
>
> Aug 20 13:47:08 router     unknown tty3    EEM:Mandatory.dualrate_eem.tcl
> stop    task_id=2166    timezone=CEST   service=shell
> start_time=1566301628    priv-lvl=15     cmd=configure terminal <cr>
> Aug 20 13:47:09 router     unknown tty3    EEM:Mandatory.dualrate_eem.tcl
> stop    task_id=2167    timezone=CEST   service=shell
> start_time=1566301629    priv-lvl=15     cmd=line vty 0 4 <cr>
> Aug 20 13:47:09 router     unknown tty3    EEM:Mandatory.dualrate_eem.tcl
> stop    task_id=2168    timezone=CEST   service=shell
> start_time=1566301629    priv-lvl=15     cmd=no login authentication <cr>
> Aug 20 13:47:09 router     unknown tty3    EEM:Mandatory.dualrate_eem.tcl
> stop    task_id=2169    timezone=CEST   service=shell
> start_time=1566301629    priv-lvl=15     cmd=no authorization exec <cr>
> Aug 20 13:47:09 router     unknown tty3    EEM:Mandatory.dualrate_eem.tcl
> stop    task_id=2170    timezone=CEST   service=shell
> start_time=1566301629    priv-lvl=15     cmd=no authorization commands 15
> <cr>
> Aug 20 13:47:10 router     unknown tty3    EEM:Mandatory.dualrate_eem.tcl
> stop    task_id=2171    timezone=CEST   service=shell
> start_time=1566301630    priv-lvl=15     cmd=no transport preferred <cr>
> ...
> Aug 20 13:47:10 router     unknown tty3    EEM:Mandatory.dualrate_eem.tcl
> stop    task_id=2174    timezone=CEST   service=shell
> start_time=1566301630    priv-lvl=15     cmd=no exec-timeout <cr>
> Aug 20 13:47:11 router     unknown tty3    EEM:Mandatory.dualrate_eem.tcl
> stop    task_id=2175    timezone=CEST   service=shell
> start_time=1566301631    priv-lvl=1      cmd=no length <cr>
> Aug 20 13:47:11 router     unknown tty2    EEM:Mandatory.dualrate_eem.tcl
> stop    task_id=2177    timezone=CEST   service=shell
> start_time=1566301631    priv-lvl=15     cmd=write memory <cr>
>
>
> shall I state that I find this a somewhat surprising behaviour?
>
> Haven't opened a TAC case yet (no time) but hopefully someone here
> has see this before and found some more useful results.
>
> gert
> --
> "If was one thing all people took for granted, was conviction that if you
>  feed honest figures into a computer, honest figures come out. Never
> doubted
>  it myself till I met a computer with a sense of humor."
>                              Robert A. Heinlein, The Moon is a Harsh
> Mistress
>
> Gert Doering - Munich, Germany
> gert at greenie.muc.de
>