gbsyncd calling setAPILogLevel Multiple times causing multiple syslog entries

[anamehra]

Description

gbsyncd logs syslog for log level change multiple times for each port.

Apr 10 17:06:44.625513 sfd-vt2-lc0 NOTICE gbsyncd2#GBSAI[14]: :- setApiLogLevel: Setting SAI loglevel SAI_LOG_LEVEL_CRITICAL on SAI_API_SWITCH
Apr 10 17:06:44.630240 sfd-vt2-lc0 NOTICE gbsyncd2#GBSAI[14]: :- setApiLogLevel: Setting SAI loglevel SAI_LOG_LEVEL_NOTICE on SAI_API_SWITCH
Apr 10 17:06:44.809120 sfd-vt2-lc0 NOTICE gbsyncd1#GBSAI[13]: :- setApiLogLevel: Setting SAI loglevel SAI_LOG_LEVEL_CRITICAL on SAI_API_SWITCH
Apr 10 17:06:44.813808 sfd-vt2-lc0 NOTICE gbsyncd1#GBSAI[13]: :- setApiLogLevel: Setting SAI loglevel SAI_LOG_LEVEL_NOTICE on SAI_API_SWITCH
Apr 10 17:06:44.873738 sfd-vt2-lc0 NOTICE gbsyncd1#GBSAI[13]: :- setApiLogLevel: Setting SAI loglevel SAI_LOG_LEVEL_CRITICAL on SAI_API_SWITCH
Apr 10 17:06:44.878821 sfd-vt2-lc0 NOTICE gbsyncd1#GBSAI[13]: :- setApiLogLevel: Setting SAI loglevel SAI_LOG_LEVEL_NOTICE on SAI_API_SWITCH
Apr 10 17:06:45.151382 sfd-vt2-lc0 NOTICE gbsyncd0#GBSAI[13]: :- setApiLogLevel: Setting SAI loglevel SAI_LOG_LEVEL_CRITICAL on SAI_API_SWITCH
Apr 10 17:06:45.155944 sfd-vt2-lc0 NOTICE gbsyncd0#GBSAI[13]: :- setApiLogLevel: Setting SAI loglevel SAI_LOG_LEVEL_NOTICE on SAI_API_SWITCH
Apr 10 17:06:45.219019 sfd-vt2-lc0 NOTICE gbsyncd0#GBSAI[13]: :- setApiLogLevel: Setting SAI loglevel SAI_LOG_LEVEL_CRITICAL on SAI_API_SWITCH
Apr 10 17:06:45.224247 sfd-vt2-lc0 NOTICE gbsyncd0#GBSAI[13]: :- setApiLogLevel: Setting SAI loglevel SAI_LOG_LEVEL_NOTICE on SAI_API_SWITCH
Apr 10 17:06:45.610170 sfd-vt2-lc0 NOTICE gbsyncd1#GBSAI[13]: :- setApiLogLevel: Setting SAI loglevel SAI_LOG_LEVEL_CRITICAL on SAI_API_SWITCH
Apr 10 17:06:45.616672 sfd-vt2-lc0 NOTICE gbsyncd1#GBSAI[13]: :- setApiLogLevel: Setting SAI loglevel SAI_LOG_LEVEL_NOTICE on SAI_API_SWITCH
Apr 10 17:06:45.946728 sfd-vt2-lc0 NOTICE gbsyncd0#GBSAI[13]: :- setApiLogLevel: Setting SAI loglevel SAI_LOG_LEVEL_CRITICAL on SAI_API_SWITCH
Apr 10 17:06:45.951048 sfd-vt2-lc0 NOTICE gbsyncd0#GBSAI[13]: :- setApiLogLevel: Setting SAI loglevel SAI_LOG_LEVEL_NOTICE on SAI_API_SWITCH

The logs are being printed from here:

sonic-sairedis/SaiDiscovery.cpp at 90ba09a1bfd5f578fecd4ffda27e6c16d6d79c0c · sonic-net/sonic-sairedis

From syslogs, looks like the discover is called for each port and the log level is changed to CRITICAL and back to NOTICE in the function.

Feb 14 00:25:38.092104 sfd-vt2-lc0 NOTICE gbsyncd1#GBSAI[13]: :- discover: SAI_OBJECT_TYPE_PORT: 1 Feb 14 00:25:38.092116 sfd-vt2-lc0 NOTICE gbsyncd1#GBSAI[13]: :- onPostPortCreate: discovered 1 new objects (including port) after creating port VID: oid:0x601010000000023 Feb 14 00:25:38.092121 sfd-vt2-lc0 NOTICE gbsyncd1#GBSAI[13]: :- onPostPortCreate: putting ALL new discovered objects to redis for port oid:0x601010000000023 Feb 14 00:25:38.246972 sfd-vt2-lc0 NOTICE gbsyncd2#GBSAI[17]: :- discover: discover took 0.007814 sec Feb 14 00:25:38.246972 sfd-vt2-lc0 NOTICE gbsyncd2#GBSAI[17]: :- discover: discovered objects count: 1 Feb 14 00:25:38.247022 sfd-vt2-lc0 NOTICE gbsyncd2#GBSAI[17]: :- discover: SAI_OBJECT_TYPE_PORT: 1 Feb 14 00:25:38.247022 sfd-vt2-lc0 NOTICE gbsyncd2#GBSAI[17]: :- onPostPortCreate: discovered 1 new objects (including port) after creating port VID: oid:0xc01010000000023 Feb 14 00:25:38.247022 sfd-vt2-lc0 NOTICE gbsyncd2#GBSAI[17]: :- onPostPortCreate: putting ALL new discovered objects to redis for port oid:0xc01010000000023

Is this expected as this fills the syslogs with these repeated logs?

Steps to reproduce the issue:

1. 2. 3.

Describe the results you received:

Describe the results you expected:

Output of show version:

(paste your output here)

Output of show techsupport:

(paste your output here or download and attach the file here )

Additional information you deem important (e.g. issue happens only occasionally):

[anamehra]

@abdosi , created this issue for the gbsyncd log issue.

[shyam77git]

@jimmyzhai - could you please update as to when this be taken up and fixed? These messages are showing up ~ 1400+ times for gbsyncd docker container on a board. Having three gbsyncd instances on a board/LC make it around ~4200+

Issues with these repeated logs: [1] Fills up the syslog buffer quickly [2] Consumes CPU cycles while the system is coming up, which could have been avoided. During this time, there is already a lot of initialization, route learning, interface bring-up notifications happening. Important tasks are not provide CPU cycles impacting the work-flow, system bring-up, interface coming up on time etc.

[anamehra]

Hi @abdosi , as discussed, we need to get this issue proritized in an effort to cleanup bringup logs and reduce any small or big load on CPU. Thanks!

[abdosi]

@kcudnik can you please guide/help us here ?

[abdosi]

@lguohan for viz.

[kcudnik]

Im not familiar with gbsyncd, that's front swss repo, can you do git blame on that core and assign owner ?