Improve debuggablity

[yue-fred-gao]

Debuggability at SONIC-VPP SAI layer is poor. If we turn on syncd debug log, it becomes too chatty because that's the level logged by SWSS_LOG_ENTER. And the latter doesn't print arguments. Also, major operations are not logged either.

Proposals

1. Use SWSS_LOG_INFO. It is not turned on by default and it is above debug level so won't be overwhelmed by debug messages.
2. All VPP API calls should be logged as INFO with parameters.
3. Create/set/remove requests from syncd should be logged as INFO with arguments
4. Other important logs can be added as needed.

[alkama-hasan]

If it make sense which i think so. please assign to me i can work on this. i was exploring how to start on this repo i think this could be a good issue to start

[yue-fred-gao]

If it make sense which i think so. please assign to me i can work on this. i was exploring how to start on this repo i think this could be a good issue to start

This is great! Thanks for volunteering.

[alkama-hasan]

@yue-fred-gao thanks for assigining the issue.
i was going through it just clarifying

1. did you mean replace all SWSS_LOG_ENTER with SWSS_LOG_INFO ?
2. As i saw under platform/sarvpp/vpplib/ many file has this logging mechanism not all of them are calling any intermediary vpp api call (defined in SaiVPPXlate.cpp) so you mean which ever function calls this we should log with some parameter ?
   what parameter is it all which is being used to call vpp api?
   for example: like this ?

vpp_status = vpp_vxlan_tunnel_add_del(&req, 1, &sw_if_index);
vpp_ip_addr_t_to_string(&req.src_address, src_ip_str, INET6_ADDRSTRLEN);
vpp_ip_addr_t_to_string(&req.dst_address, dst_ip_str, INET6_ADDRSTRLEN);    
SWSS_LOG_INFO("create vxlan tunnel src %s dst %s vni %d: sw_if_index,%d,

any more further input will be appreciated thanks

[yue-fred-gao]

Hi @alkama-hasan,

I feel SWSS_LOG_ENTER doesn't give much information but can be very distracting by overloading log buffers. So I think we can leave them as is.
For 1 in the proposal, I think we can change all current SWSS_LOG_DEBUG in sonic-vpp code to SWSS_LOG_INFO.
For 2, in SaiVppXlate.c, SAIVPP_DEBUG is a dummy and can only be enabled by changing code. Can we point it to SWSS_LOG_INFO instead? I see SAIVPP_DEBUG is mostly used by reply handlers. It's better to add SAIVPP_DEBUG to action APIs like create_bvi_interface. It is overkill to log all arguments in such logs so a handful of key arguments is enough. You can use your judgement to decide what are key arguments. If we find it not sufficient in some cases, we can always amend it.
For 3, it seems already taken care in VirtualSwitchInterface.
For 4, it has to be investigated case by case. You can do it in best effort or leave it for future completely.

For your second question, not all logs are tied to SaiVppXlate API calls. Some of the logs are used to record important decisions. For example, if we decide not to program a route, we need to record the reason and decision. logs from SaiVppXlate.c should offset some need to log from callers in platform/sarvpp/vpplib so caller doesn't need to log the request and result any more.

I hope this answers your question.