Skip to content

[syncd] Clean up log messages and add performance timer for bulk route create #864

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
kcudnik merged 3 commits into from
Jul 21, 2021
Merged

[syncd] Clean up log messages and add performance timer for bulk route create #864

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
142a8b4
[syncd] Change translate new RID log to info level
kcudnik Jul 16, 2021
9e402ba
[syncd] Timer WD update log messages to more readable
kcudnik Jul 16, 2021
4ebf266
[syncd] Add performance timer for bulk route create
kcudnik Jul 16, 2021
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
15 changes: 12 additions & 3 deletions syncd/Syncd.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -917,6 +917,10 @@ sai_status_t Syncd::processBulkCreateEntry(
entries[it].vr_id = m_translator->translateVidToRid(entries[it].vr_id);
}

static PerformanceIntervalTimer timer("Syncd::processBulkCreateEntry(route_entry) CREATE");
Copy link
Copy Markdown
Contributor

@qiluo-msft qiluo-msft Jul 17, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

static

Better to use class static member. There could be multiple Syncd instances, right?

Copy link
Copy Markdown
Collaborator Author

@kcudnik kcudnik Jul 17, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

per process, no, i will fix that on the road, so far here are many performance counters instantiated like here


timer.start();

status = m_vendorSai->bulkCreate(
object_count,
entries.data(),
Expand All @@ -925,6 +929,9 @@ sai_status_t Syncd::processBulkCreateEntry(
mode,
statuses.data());

timer.stop();

timer.inc(object_count);
}
break;

Expand Down Expand Up @@ -1444,7 +1451,8 @@ sai_status_t Syncd::processBulkOidCreate(

if (status == SAI_STATUS_NOT_IMPLEMENTED || status == SAI_STATUS_NOT_SUPPORTED)
{
SWSS_LOG_ERROR("bulkCreate api is not implemented or not supported, object_type = %u", objectType);
SWSS_LOG_ERROR("bulkCreate api is not implemented or not supported, object_type = %s",
sai_serialize_object_type(objectType).c_str());
return status;
}

Expand Down Expand Up @@ -1501,7 +1509,8 @@ sai_status_t Syncd::processBulkOidRemove(

if (status == SAI_STATUS_NOT_IMPLEMENTED || status == SAI_STATUS_NOT_SUPPORTED)
{
SWSS_LOG_ERROR("bulkRemove api is not implemented or not supported, object_type = %u", objectType);
SWSS_LOG_ERROR("bulkRemove api is not implemented or not supported, object_type = %s",
sai_serialize_object_type(objectType).c_str());
return status;
}

Expand Down Expand Up @@ -4307,7 +4316,7 @@ static void timerWatchdogCallback(
{
SWSS_LOG_ENTER();

SWSS_LOG_ERROR("main loop execution exceeded %ld us", span);
SWSS_LOG_ERROR("main loop execution exceeded %ld ms", span/1000);
}

void Syncd::run()
Expand Down
6 changes: 2 additions & 4 deletions syncd/TimerWatchdog.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -86,8 +86,6 @@ void TimerWatchdog::threadFunction()

if (span < 0 && start > m_lastCheckTimestamp)
{
SWSS_LOG_NOTICE(" span < 0 = %ld at %ld", span, now);

// this means start > end, so new function is currently executing,
// or that function hanged, so see how long that function is
// executing, this negative span can be arbitrary long even hours,
Expand All @@ -96,7 +94,7 @@ void TimerWatchdog::threadFunction()

span = now - start; // this must be always non negative

SWSS_LOG_NOTICE(" new span = %ld", span);
SWSS_LOG_NOTICE("time span %ld ms", span/1000);

if (span < 0)
SWSS_LOG_THROW("negative span 'now - start': %ld - %ld", now, start);
Expand All @@ -107,7 +105,7 @@ void TimerWatchdog::threadFunction()

// function probably hanged

SWSS_LOG_WARN("time (span < 0) watchdog exceeded %ld microseconds", span);
SWSS_LOG_WARN("timespan WD exceeded %ld ms", span/1000);

auto callback = m_callback;

Expand Down
2 changes: 1 addition & 1 deletion syncd/VirtualOidTranslator.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -135,7 +135,7 @@ sai_object_id_t VirtualOidTranslator::translateRidToVid(

vid = m_virtualObjectIdManager->allocateNewObjectId(object_type, switchVid); // TODO to std::function or separate object

SWSS_LOG_DEBUG("translated RID %s to VID %s",
SWSS_LOG_INFO("translated RID %s to VID %s",
sai_serialize_object_id(rid).c_str(),
sai_serialize_object_id(vid).c_str());

Expand Down