Add resource usage logging.

Add log_resource_usage, which prints the current and elapsed user and
system times. Add a usage example in packet_list_model.cpp.

Change-Id: I747161c754a3731e540821715cc9bb10b3dc821d
Reviewed-on: https://code.wireshark.org/review/16383
Petri-Dish: Gerald Combs <gerald@wireshark.org>
Tested-by: Petri Dish Buildbot <buildbot-no-reply@wireshark.org>
Reviewed-by: Gerald Combs <gerald@wireshark.org>
This commit is contained in:
Gerald Combs 2016-07-11 15:40:03 -07:00
parent 3fe92ffabf
commit 479caf15e7
3 changed files with 91 additions and 0 deletions

View File

@ -44,6 +44,13 @@
#include <QModelIndex>
#include <QElapsedTimer>
// Print timing information
//#define DEBUG_PACKET_LIST_MODEL 1
#ifdef DEBUG_PACKET_LIST_MODEL
#include <wsutil/time_util.h>
#endif
PacketListModel::PacketListModel(QObject *parent, capture_file *cf) :
QAbstractItemModel(parent),
max_row_height_(0),
@ -603,6 +610,12 @@ gint PacketListModel::appendPacket(frame_data *fdata)
PacketListRecord *record = new PacketListRecord(fdata);
gint pos = -1;
#ifdef DEBUG_PACKET_LIST_MODEL
if (fdata->num % 10000 == 1) {
log_resource_usage(fdata->num == 1, "%u packets", fdata->num);
}
#endif
physical_rows_ << record;
if (fdata->flags.passed_dfilter || fdata->flags.ref_time) {

View File

@ -22,8 +22,17 @@
#include "config.h"
#include <glib.h>
#include "time_util.h"
#ifndef _WIN32
#include <sys/time.h>
#include <sys/resource.h>
#else
#include <windows.h>
#endif
/* converts a broken down date representation, relative to UTC,
* to a timestamp; it uses timegm() if it's available.
* Copied from Glib source gtimer.c
@ -62,6 +71,54 @@ mktime_utc(struct tm *tm)
#endif /* !HAVE_TIMEGM */
}
static double last_utime = 0.0;
static double last_stime = 0.0;
void log_resource_usage(gboolean reset_delta, const char *format, ...) {
va_list ap;
GString *log_str = g_string_new("");
double utime;
double stime;
#ifndef _WIN32
struct rusage ru;
getrusage(RUSAGE_SELF, &ru);
utime = ru.ru_utime.tv_sec + (ru.ru_utime.tv_usec / 1000000.0);
stime = ru.ru_stime.tv_sec + (ru.ru_stime.tv_usec / 1000000.0);
#else /* _WIN32 */
HANDLE h_proc = GetCurrentProcess();
FILETIME cft, eft, kft, uft;
ULARGE_INTEGER uli_time;
GetProcessTimes(h_proc, &cft, &eft, &kft, &uft);
uli_time.LowPart = uft.dwLowDateTime;
uli_time.HighPart = uft.dwHighDateTime;
utime = uli_time.QuadPart / 10000000.0;
uli_time.LowPart = kft.dwLowDateTime;
uli_time.HighPart = kft.dwHighDateTime;
stime = uli_time.QuadPart / 1000000000.0;
#endif /* _WIN32 */
if (reset_delta || last_utime == 0.0) {
last_utime = utime;
last_stime = stime;
}
g_string_append_printf(log_str, "user %.3f +%.3f sys %.3f +%.3f ",
utime, utime - last_utime, stime, stime - last_stime);
va_start(ap, format);
g_string_append_vprintf(log_str, format, ap);
va_end(ap);
g_warning("%s", log_str->str);
g_string_free(log_str, TRUE);
}
/*
* Editor modelines - http://www.wireshark.org/tools/modelines.html
*

View File

@ -24,9 +24,30 @@
#include "ws_symbol_export.h"
#ifdef __cplusplus
extern "C" {
#endif /* __cplusplus */
#include <time.h>
WS_DLL_PUBLIC
time_t mktime_utc(struct tm *tm);
/** Print the process CPU time followed by a log message.
*
* Print the current process user and system CPU times along with the times
* elapsed since the times were last reset.
*
* @param reset_delta Reset the delta times. This will typically be TRUE when
* logging the first measurement and FALSE thereafter.
* @param format Printf-style format string. Passed to g_string_vprintf.
* @param ... Parameters for the format string.
*/
WS_DLL_PUBLIC
void log_resource_usage(gboolean reset_delta, const char *format, ...);
#ifdef __cplusplus
}
#endif /* __cplusplus */
#endif /* __TIME_UTIL_H__ */