Fix storm log messages parsing

[andriymoroz-mlnx]

Change-Id: I330a423ac5891d934207e870468c41da5c0aec5b
Signed-off-by: Andriy Moroz [email protected]

Description of PR

Fixes parsing of "storm started/detected/stopped/restored" in the log

Type of change

• Bug fix
• Testbed and Framework(new/improvement)
• Test case(new/improvement)

Approach

How did you do it?

Updated grep search regex to prevent it from matching itself

How did you verify/test it?

Prevent storm from happening or detection. Run this test case and make sure it reports no marker found

Bug explained

If message at "20:44:28.380700" PFC_STORM_START don't appear in syslog (in some reason), Ansible will pick up its own "grep" message at "20:44:40.742762". There will be 12 sec error in time calculation.

Apr  1 20:44:28.380700 PFC_STORM_START DEBUG
Apr  1 20:44:29.061322 arc-switch1029 NOTICE swss#orchagent: :- doTask: Receive notification, storm
Apr  1 20:44:29.061491 arc-switch1029 NOTICE swss#orchagent: :- doTask: PFC Watchdog detected PFC storm on port Ethernet36, queue index 4, queue id 0x150000000001b9 and port id 0x10000000001b2.
Apr  1 20:44:29.062417 arc-switch1029 INFO syncd#supervisord: syncd Apr 01 20:44:29 NOTICE  SAI_UTILS: mlnx_sai_utils.c[2307]- set_dispatch_attrib_handler: Set PRIORITY_FLOW_CONTROL, key:port 12100, val:8
Apr  1 20:44:29.068709 arc-switch1029 INFO syncd#supervisord: syncd Apr 01 20:44:29 NOTICE  SAI_UTILS: mlnx_sai_utils.c[2307]- set_dispatch_attrib_handler: Set BUFFER_PROFILE_ID, key:queue 12100:4, val:BUFFER_PROFILE,(0:0),9,0000,0
Apr  1 20:44:29.074469 arc-switch1029 INFO syncd#supervisord: syncd Apr 01 20:44:29 NOTICE  SAI_UTILS: mlnx_sai_utils.c[2307]- set_dispatch_attrib_handler: Set BUFFER_PROFILE, key:port:9, PG index:4, val:BUFFER_PROFILE,(0:0),a,0000,0
Apr  1 20:44:32.382331 PFC_STORM_END DEBUG
Apr  1 20:44:33.065220 arc-switch1029 NOTICE swss#orchagent: :- doTask: Receive notification, restore
Apr  1 20:44:33.065498 arc-switch1029 NOTICE swss#orchagent: :- doTask: PFC Watchdog storm restored on port Ethernet36, queue index 4, queue id 0x150000000001b9 and port id 0x10000000001b2.
Apr  1 20:44:33.080875 arc-switch1029 INFO syncd#supervisord: syncd Apr 01 20:44:33 NOTICE  SAI_UTILS: mlnx_sai_utils.c[2307]- set_dispatch_attrib_handler: Set BUFFER_PROFILE_ID, key:queue 12100:4, val:BUFFER_PROFILE,(0:0),1,0000,0
Apr  1 20:44:33.084380 arc-switch1029 INFO syncd#supervisord: syncd Apr 01 20:44:33 NOTICE  SAI_UTILS: mlnx_sai_utils.c[2307]- set_dispatch_attrib_handler: Set BUFFER_PROFILE, key:port:9, PG index:4, val:BUFFER_PROFILE,(0:0),7,0000,0
Apr  1 20:44:33.088449 arc-switch1029 INFO syncd#supervisord: syncd Apr 01 20:44:33 NOTICE  SAI_UTILS: mlnx_sai_utils.c[2307]- set_dispatch_attrib_handler: Set PRIORITY_FLOW_CONTROL, key:port 12100, val:24
Apr  1 20:44:40.742762 arc-switch1029 INFO ansible-<stdin>: Invoked with warn=True executable=None chdir=None _raw_params=grep "PFC_STORM_START" /var/log/syslog removes=None creates=None _uses_shell=True
Apr  1 20:44:41.269157 arc-switch1029 INFO ansible-<stdin>: Invoked with warn=True executable=None chdir=None _raw_params=date -d 20:44:28.380700 +'%s%3N' removes=None creates=None _uses_shell=True
Apr  1 20:44:41.832248 arc-switch1029 INFO ansible-<stdin>: Invoked with warn=True executable=None chdir=None _raw_params=grep "detected PFC storm" /var/log/syslog removes=None creates=None _uses_shell=True
Apr  1 20:44:42.376687 arc-switch1029 INFO ansible-<stdin>: Invoked with warn=True executable=None chdir=None _raw_params=date -d 20:44:29.061491 +'%s%3N' removes=None creates=None _uses_shell=True

With the fix applied grep message will look like this
..._raw_params=grep "[P]FC_STORM_START"...
which matches the same as before but didn't match itself