Skip to content

Commit fa13e2a

Browse files
jcortell68jcortell68
authored
Various improvements to GPA's logging facility (#71)
* Various improvements to GPA's logging facility 1. LogDebugXxxxx() methods are variadic printf based functions, but LogXxxxx() methods are not. Upgraded the latter for consistency and to make it easier to log dynamic non-debug messages 2. The LogDebugXxxxx() methods could trash memory. Should use vsnprintf instead of vsprintf. 3. The LogDebugXxxxx() methods had a lot of redundant/common logic. * Additional logging tweaks When building for host, the need or additional log statement adjustments surfaced. Change-Id: I2855ade49a2e798c046986ad64661eeac54a430d * Improved logging of device ID Change-Id: Ibd51cd822ef47473c71e85c6f97daddb1cdae59f * Init the target buffer of vsnprintf to empty string In the scenario where vsnprintf() fails and doesn't write anything to the target buffer, we are sending the buffer forward for logging. The buffer has uninitialized memory at that point. Best case scenario: we print garbage. Worst case scenario, we do a read overrun and crash (unlikely since it's stack memory).
1 parent a321fd0 commit fa13e2a

File tree

12 files changed

+112
-200
lines changed

12 files changed

+112
-200
lines changed

‎source/gpu_perf_api_common/gpa_hw_info.cc‎

Lines changed: 2 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -216,7 +216,7 @@ bool GpaHwInfo::UpdateDeviceInfoBasedOnDeviceId()
216216
{
217217
if (AMDTDeviceInfoUtils::Instance()->GetDeviceInfo(device_id_, revision_id_, card_info))
218218
{
219-
GPA_LOG_DEBUG_MESSAGE("Found device ID: %X which is generation %d.", card_info.m_deviceID, card_info.m_generation);
219+
GPA_LOG_DEBUG_MESSAGE("Found device ID: %zX which is generation %d.", card_info.m_deviceID, card_info.m_generation);
220220

221221
if (AMDTDeviceInfoUtils::Instance()->GetDeviceInfo(device_id_, revision_id_, device_info))
222222
{
@@ -266,9 +266,7 @@ bool GpaHwInfo::UpdateDeviceInfoBasedOnDeviceId()
266266
// Only emit an error for AMD devices.
267267
if (IsAmd())
268268
{
269-
std::stringstream ss;
270-
ss << "Unrecognized device ID: " << device_id_ << ".";
271-
GPA_LOG_ERROR(ss.str().c_str());
269+
GPA_LOG_ERROR("Unrecognized device ID: 0x%04X", device_id_);
272270
}
273271

274272
return false;

‎source/gpu_perf_api_common/gpu_perf_api.cc‎

Lines changed: 4 additions & 15 deletions
Original file line numberDiff line numberDiff line change
@@ -47,9 +47,7 @@ extern IGpaImplementor* gpa_imp; ///< GPA implementor instance.
4747
} \
4848
if (index >= num_counters) \
4949
{ \
50-
std::stringstream message; \
51-
message << "Parameter '" #index "' is " << index << " but must be less than " << num_counters << "."; \
52-
GPA_LOG_ERROR(message.str().c_str()); \
50+
GPA_LOG_ERROR("Parameter %s is %d but must be less than %d.", #index, index, num_counters); \
5351
return kGpaStatusErrorIndexOutOfRange; \
5452
}
5553

@@ -572,10 +570,7 @@ GPA_LIB_DECL GpaStatus GpaGetCounterIndex(GpaContextId gpa_context_id, const cha
572570

573571
if (!counter_found)
574572
{
575-
std::string message = "Specified counter '";
576-
message += counter_name;
577-
message += "' was not found. Please check spelling or availability.";
578-
GPA_LOG_ERROR(message.c_str());
573+
GPA_LOG_ERROR("Specified counter '%s' was not found. Please check spelling or availability.", counter_name);
579574
return kGpaStatusErrorCounterNotFound;
580575
}
581576

@@ -960,10 +955,7 @@ GPA_LIB_DECL GpaStatus GpaEnableCounterByName(GpaSessionId gpa_session_id, const
960955

961956
if (kGpaStatusOk != status)
962957
{
963-
std::string message = "Specified counter '";
964-
message += counter_name;
965-
message += "' was not found. Please check spelling or availability.";
966-
GPA_LOG_ERROR(message.c_str());
958+
GPA_LOG_ERROR("Specified counter '%s' was not found. Please check spelling or availability.", counter_name);
967959
return kGpaStatusErrorCounterNotFound;
968960
}
969961

@@ -991,10 +983,7 @@ GPA_LIB_DECL GpaStatus GpaDisableCounterByName(GpaSessionId gpa_session_id, cons
991983

992984
if (kGpaStatusOk != status)
993985
{
994-
std::string message = "Specified counter '";
995-
message += counter_name;
996-
message += "' was not found. Please check spelling or availability.";
997-
GPA_LOG_ERROR(message.c_str());
986+
GPA_LOG_ERROR("Specified counter '%s' was not found. Please check spelling or availability.", counter_name);
998987
return kGpaStatusErrorCounterNotFound;
999988
}
1000989

‎source/gpu_perf_api_common/logging.cc‎

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -51,7 +51,7 @@ void GpaTracer::EnterFunction(const char* function_name)
5151
message << function_name;
5252
message << ".";
5353

54-
GPA_LOG_TRACE(message.str().c_str());
54+
GPA_LOG_TRACE("%s", message.str().c_str());
5555
}
5656

5757
++tab_counter->second;
@@ -81,7 +81,7 @@ void GpaTracer::LeaveFunction(const char* function_name)
8181
message << function_name;
8282
message << ".";
8383

84-
GPA_LOG_TRACE(message.str().c_str());
84+
GPA_LOG_TRACE("%s", message.str().c_str());
8585
}
8686
}
8787

@@ -103,7 +103,7 @@ void GpaTracer::OutputFunctionData(const char* data)
103103
message << data;
104104
message << ".";
105105

106-
GPA_LOG_TRACE(message.str().c_str());
106+
GPA_LOG_TRACE("%s", message.str().c_str());
107107
}
108108
}
109109

‎source/gpu_perf_api_common/logging.h‎

Lines changed: 68 additions & 97 deletions
Original file line numberDiff line numberDiff line change
@@ -81,140 +81,111 @@ class GpaLogger : public TSingleton<GpaLogger>
8181
/// @param [in] log_message The message to pass along.
8282
void Log(GpaLoggingType log_type, const char* log_message);
8383

84+
void Logfv(GpaLoggingType type, const char* msg_fmt, va_list args)
85+
{
86+
// If the supplied message type is among those that the user wants be notified of,
87+
// then pass the message along.
88+
if (type & logging_type_)
89+
{
90+
EnterCriticalSection(&lock_handle);
91+
92+
// Format string.
93+
char buffer[1024 * 50];
94+
buffer[0] = '\0';
95+
#ifdef WIN32
96+
vsnprintf_s(buffer, sizeof(buffer), msg_fmt, args);
97+
#else
98+
vsnprintf(buffer, sizeof(buffer), msg_fmt, args);
99+
#endif
100+
Log(type, buffer);
101+
102+
LeaveCriticalSection(&lock_handle);
103+
}
104+
}
105+
106+
void Logf(GpaLoggingType type, const char* msg_fmt, ...) __attribute__((format(printf, 3, 4)))
107+
{
108+
va_list args;
109+
va_start(args, msg_fmt);
110+
Logfv(type, msg_fmt, args);
111+
va_end(args);
112+
}
113+
84114
/// @brief Logs an error message.
85115
///
86-
/// @param [in] message The message to pass along.
87-
inline void LogError(const char* message)
116+
/// @param [in] msg_fmt The message to format and pass along.
117+
inline void LogError(const char* msg_fmt, ...) __attribute__((format(printf, 2, 3)))
88118
{
89-
Log(kGpaLoggingError, message);
119+
va_list args;
120+
va_start(args, msg_fmt);
121+
Logfv(kGpaLoggingError, msg_fmt, args);
122+
va_end(args);
90123
}
91124

92125
/// @brief Logs an informational message.
93126
///
94-
/// @param [in] message The message to pass along.
95-
inline void LogMessage(const char* message)
127+
/// @param [in] msg_fmt The message to format and pass along.
128+
inline void LogMessage(const char* msg_fmt, ...) __attribute__((format(printf, 2, 3)))
96129
{
97-
Log(kGpaLoggingMessage, message);
130+
va_list args;
131+
va_start(args, msg_fmt);
132+
Logfv(kGpaLoggingMessage, msg_fmt, args);
133+
va_end(args);
98134
}
99135

100136
/// @brief Logs a trace message.
101137
///
102-
/// @param [in] message The message to pass along.
103-
inline void LogTrace(const char* message)
138+
/// @param [in] msg_fmt The message to format and pass along.
139+
inline void LogTrace(const char* msg_fmt, ...) __attribute__((format(printf, 2, 3)))
104140
{
105-
Log(kGpaLoggingTrace, message);
141+
va_list args;
142+
va_start(args, msg_fmt);
143+
Logfv(kGpaLoggingTrace, msg_fmt, args);
144+
va_end(args);
106145
}
107146

108147
/// @brief Logs a formatted message in internal builds; does nothing in release.
109148
///
110149
/// @param [in] msg_fmt The message to format and pass along.
111-
void LogDebugMessage(const char* msg_fmt, ...)
150+
void LogDebugMessage(const char* msg_fmt, ...) __attribute__((format(printf, 2, 3)))
112151
{
113-
// If the supplied message type is among those that the user wants be notified of,
114-
// then pass the message along.
115-
if (kGpaLoggingDebugMessage & logging_type_)
116-
{
117-
EnterCriticalSection(&lock_handle);
118-
119-
// Format string.
120-
char buffer[1024 * 50];
121-
va_list arg_list;
122-
va_start(arg_list, msg_fmt);
123-
#ifdef WIN32
124-
vsprintf_s(buffer, msg_fmt, arg_list);
125-
#else
126-
vsprintf(buffer, msg_fmt, arg_list);
127-
#endif
128-
va_end(arg_list);
129-
130-
Log(kGpaLoggingDebugMessage, buffer);
131-
132-
LeaveCriticalSection(&lock_handle);
133-
}
152+
va_list args;
153+
va_start(args, msg_fmt);
154+
Logfv(kGpaLoggingDebugMessage, msg_fmt, args);
155+
va_end(args);
134156
}
135157

136158
/// @brief Logs a formatted error message in debug builds; does nothing in release.
137159
///
138160
/// @param [in] msg_fmt The message to format and pass along.
139-
void LogDebugError(const char* msg_fmt, ...)
161+
void LogDebugError(const char* msg_fmt, ...) __attribute__((format(printf, 2, 3)))
140162
{
141-
// If the supplied message type is among those that the user wants be notified of,
142-
// then pass the message along.
143-
if (kGpaLoggingDebugError & logging_type_)
144-
{
145-
EnterCriticalSection(&lock_handle);
146-
147-
// Format string.
148-
char buffer[1024 * 50];
149-
va_list arg_list;
150-
va_start(arg_list, msg_fmt);
151-
#ifdef WIN32
152-
vsprintf_s(buffer, msg_fmt, arg_list);
153-
#else
154-
vsprintf(buffer, msg_fmt, arg_list);
155-
#endif
156-
va_end(arg_list);
157-
158-
Log(kGpaLoggingDebugError, buffer);
159-
160-
LeaveCriticalSection(&lock_handle);
161-
}
163+
va_list args;
164+
va_start(args, msg_fmt);
165+
Logfv(kGpaLoggingDebugError, msg_fmt, args);
166+
va_end(args);
162167
}
163168

164169
/// @brief Logs a formatted error message in debug builds; does nothing in release.
165170
///
166171
/// @param [in] msg_fmt The message to format and pass along.
167-
void LogDebugTrace(const char* msg_fmt, ...)
172+
void LogDebugTrace(const char* msg_fmt, ...) __attribute__((format(printf, 2, 3)))
168173
{
169-
// If the supplied message type is among those that the user wants be notified of,
170-
// then pass the message along.
171-
if (kGpaLoggingDebugTrace & logging_type_)
172-
{
173-
EnterCriticalSection(&lock_handle);
174-
175-
// Format string.
176-
char buffer[1024 * 50];
177-
va_list arg_list;
178-
va_start(arg_list, msg_fmt);
179-
#ifdef WIN32
180-
vsprintf_s(buffer, msg_fmt, arg_list);
181-
#else
182-
vsprintf(buffer, msg_fmt, arg_list);
183-
#endif
184-
va_end(arg_list);
185-
186-
Log(kGpaLoggingDebugTrace, buffer);
187-
188-
LeaveCriticalSection(&lock_handle);
189-
}
174+
va_list args;
175+
va_start(args, msg_fmt);
176+
Logfv(kGpaLoggingDebugTrace, msg_fmt, args);
177+
va_end(args);
190178
}
191179

192180
/// @brief Logs a formatted message in internal builds; does nothing in public builds.
193181
///
194182
/// @param [in] msg_fmt The message to format and pass along.
195-
void LogDebugCounterDefs(const char* msg_fmt, ...)
183+
void LogDebugCounterDefs(const char* msg_fmt, ...) __attribute__((format(printf, 2, 3)))
196184
{
197-
// If the supplied message type is among those that the user wants be notified of,
198-
// then pass the message along.
199-
if (kGpaLoggingDebugCounterDefinitions & logging_type_)
200-
{
201-
EnterCriticalSection(&lock_handle);
202-
203-
// Format string.
204-
char buffer[1024 * 50];
205-
va_list arg_list;
206-
va_start(arg_list, msg_fmt);
207-
#ifdef WIN32
208-
vsprintf_s(buffer, msg_fmt, arg_list);
209-
#else
210-
vsprintf(buffer, msg_fmt, arg_list);
211-
#endif
212-
va_end(arg_list);
213-
214-
Log(kGpaLoggingDebugCounterDefinitions, buffer);
215-
216-
LeaveCriticalSection(&lock_handle);
217-
}
185+
va_list args;
186+
va_start(args, msg_fmt);
187+
Logfv(kGpaLoggingDebugCounterDefinitions, msg_fmt, args);
188+
va_end(args);
218189
}
219190

220191
/// @brief Checks whether the tracing is enabled or not.

‎source/gpu_perf_api_counter_generator/gl_entry_points.cc‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -124,7 +124,7 @@ namespace ogl_utils
124124
case GL_STACK_UNDERFLOW:
125125
case GL_OUT_OF_MEMORY:
126126
error_found = true;
127-
GPA_LOG_ERROR(error_message.c_str());
127+
GPA_LOG_ERROR("%s", error_message.c_str());
128128
break;
129129

130130
default:

‎source/gpu_perf_api_counter_generator/gpa_counter_scheduler_base.cc‎

Lines changed: 8 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -75,12 +75,9 @@ GpaStatus GpaCounterSchedulerBase::EnableCounter(GpaUInt32 index)
7575
#pragma endregion
7676
if (enabled_public_counter_bits_[index])
7777
{
78-
std::stringstream message;
79-
message << "Counter index " << index << " has already been enabled.";
80-
8178
// We will log this as a debug message rather than an error at this point,
8279
// this error will be reported to the logger from the caller.
83-
GPA_LOG_DEBUG_MESSAGE(message.str().c_str());
80+
GPA_LOG_DEBUG_MESSAGE("Counter index %d has already been enabled.", index);
8481
return kGpaStatusErrorAlreadyEnabled;
8582
}
8683

@@ -108,9 +105,7 @@ GpaStatus GpaCounterSchedulerBase::DisableCounter(GpaUInt32 index)
108105
}
109106
}
110107

111-
std::stringstream message;
112-
message << "Counter index " << index << " was not previously enabled, so it could not be disabled.";
113-
GPA_LOG_ERROR(message.str().c_str());
108+
GPA_LOG_ERROR("Counter index %d was not previously enabled, so it could not be disabled.", index);
114109
return kGpaStatusErrorNotEnabled;
115110
}
116111

@@ -126,10 +121,8 @@ GpaStatus GpaCounterSchedulerBase::GetEnabledIndex(GpaUInt32 enabled_index, GpaU
126121
{
127122
if (enabled_index >= static_cast<GpaUInt32>(enabled_public_indices_.size()))
128123
{
129-
std::stringstream message;
130-
message << "Parameter 'enabled_index' is " << enabled_index << " but must be less than the number of enabled counters ("
131-
<< enabled_public_indices_.size() << ").";
132-
GPA_LOG_ERROR(message.str().c_str());
124+
GPA_LOG_ERROR("Parameter 'enabled_index' is %u but must be less than the number of enabled counters (%zu)",
125+
enabled_index, enabled_public_indices_.size());
133126
return kGpaStatusErrorIndexOutOfRange;
134127
}
135128

@@ -142,10 +135,9 @@ GpaStatus GpaCounterSchedulerBase::IsCounterEnabled(GpaUInt32 counter_index) con
142135
{
143136
if (counter_index >= enabled_public_counter_bits_.size())
144137
{
145-
std::stringstream message;
146-
message << "Parameter 'counter_index' is " << counter_index << " but must be less than the number of enabled counters ("
147-
<< enabled_public_counter_bits_.size() << ").";
148-
GPA_LOG_ERROR(message.str().c_str());
138+
GPA_LOG_ERROR("Parameter 'counter_index' is %u but must be less than the number of enabled counters (%zu)",
139+
counter_index, enabled_public_counter_bits_.size());
140+
149141
return kGpaStatusErrorIndexOutOfRange;
150142
}
151143

@@ -155,9 +147,7 @@ GpaStatus GpaCounterSchedulerBase::IsCounterEnabled(GpaUInt32 counter_index) con
155147
}
156148
else
157149
{
158-
std::stringstream message;
159-
message << "Parameter 'counter_index' (" << counter_index << ") is not an enabled counter.";
160-
GPA_LOG_MESSAGE(message.str().c_str());
150+
GPA_LOG_MESSAGE("Parameter 'counter_index' (%d) is not an enabled counter.", counter_index);
161151
return kGpaStatusErrorCounterNotFound;
162152
}
163153

‎source/gpu_perf_api_counter_generator/gpa_derived_counter.cc‎

Lines changed: 2 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -232,9 +232,8 @@ void GpaDerivedCounters::UpdateAsicSpecificDerivedCounter(const char* counter_na
232232
// Errors aside, the counter will not be found if it's not supported on the ASIC.
233233
// e.g.: there's a discrete counter version, but not an SPM version.
234234
{
235-
std::stringstream o;
236-
o << "Warning: unable to find counter for ASIC-specific update:" << counter_name << ". This may be an unsupported SPM counter.";
237-
GPA_LOG_MESSAGE(o.str().c_str());
235+
GPA_LOG_MESSAGE("Warning: unable to find counter for ASIC-specific update:%s . This may be an unsupported SPM counter.",
236+
counter_name);
238237
}
239238
}
240239

‎source/gpu_perf_api_counter_generator/gpa_derived_counter_evaluator.inc‎

Lines changed: 1 addition & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -868,9 +868,7 @@ static GpaStatus EvaluateExpression(const char* expression,
868868

869869
if (stack.size() != 1)
870870
{
871-
std::stringstream ss;
872-
ss << "Invalid formula: " << expression << ".";
873-
GPA_LOG_ERROR(ss.str().c_str());
871+
GPA_LOG_ERROR("Invalid formula: %s", expression);
874872
status = kGpaStatusErrorInvalidCounterEquation;
875873
}
876874

0 commit comments

Comments
 (0)