The logsys implementation uses 3 strlen() api calls during any recording
of a log record into the circular buffer. strlen is expensive, and in
all cases can be avoided. Currently we use strlen() to determine the
length of the subsys, the length of the function name, and the length of
the file name.
Most modern compilers will replace strlen(MACRO) with the appropriate
string length from the expansion of the macro. This allows us to pass
strlen (__FILE__), allowing the C preprocessor to calculate it at
compile time rather the the potentially millions of times per day it
could be calculated during normal operation.
The attached patch adds new "internal ABI" calls to logsys as to
preserve ABI compatibility with older applications that use the current
macros. As a result, this patch also changes the SO micro version for
the logsys shared object name.
Benchmarks pre-change via test/logsysbench:
[r...@bigiron test]# ./logsysbench
heating up cache with logrec functionality
log_rec 1 arguments: 10508153.276 operations/sec
log_rec 2 arguments: 10610912.687 operations/sec
log_rec 3 arguments: 8346019.283 operations/sec
log_rec 4 arguments: 7135181.726 operations/sec
Benchmarks post-change:
[r...@bigiron test]# ./logsysbench
heating up cache with logrec functionality
log_rec 1 arguments: 11758895.605 operations/sec
log_rec 2 arguments: 12229902.601 operations/sec
log_rec 3 arguments: 9585770.116 operations/sec
log_rec 4 arguments: 8095592.759 operations/sec
As can be seen, about a 10% performance improvement.
Regards
-steve
Index: include/corosync/engine/logsys.h
===================================================================
--- include/corosync/engine/logsys.h (revision 2676)
+++ include/corosync/engine/logsys.h (working copy)
@@ -42,6 +42,7 @@
#include <syslog.h>
#include <pthread.h>
#include <limits.h>
+#include <string.h>
#ifdef __cplusplus
extern "C" {
@@ -194,6 +195,35 @@
int file_line,
...);
+extern void _logsys_log_vprintf_two (
+ unsigned int rec_ident,
+ const char *function_name,
+ unsigned int function_name_len,
+ const char *file_name,
+ unsigned int file_name_len,
+ int file_line,
+ const char *format,
+ va_list ap) __attribute__((format(printf, 7, 0)));
+
+extern void _logsys_log_printf_two (
+ unsigned int rec_ident,
+ const char *function_name,
+ unsigned int function_name_len,
+ const char *file_name,
+ unsigned int file_name_len,
+ int file_line,
+ const char *format,
+ ...) __attribute__((format(printf, 7, 8)));
+
+extern void _logsys_log_rec_two (
+ unsigned int rec_ident,
+ const char *function_name,
+ unsigned int function_name_len,
+ const char *file_name,
+ unsigned int file_name_len,
+ int file_line,
+ ...);
+
extern int _logsys_wthread_create (void);
static int logsys_subsys_id __attribute__((unused)) = LOGSYS_MAX_SUBSYS_COUNT;
@@ -350,43 +380,51 @@
#define log_rec(rec_ident, args...) \
do { \
- _logsys_log_rec (rec_ident, __FUNCTION__, \
- __FILE__, __LINE__, ##args, \
- LOGSYS_REC_END); \
+ _logsys_log_rec_two (rec_ident, \
+ __FUNCTION__, strlen (__FUNCTION__) + 1, \
+ __FILE__, strlen (__FILE__) + 1, \
+ __LINE__, ##args, LOGSYS_REC_END); \
} while(0)
#define log_printf(level, format, args...) \
do { \
- _logsys_log_printf ( \
+ _logsys_log_printf_two ( \
LOGSYS_ENCODE_RECID(level, \
logsys_subsys_id, \
LOGSYS_RECID_LOG), \
- __FUNCTION__, __FILE__, __LINE__, \
+ __FUNCTION__, strlen (__FUNCTION__) + 1, \
+ __FILE__, (strlen (__FILE__) + 1), __LINE__, \
format, ##args); \
} while(0)
#define ENTER() do { \
- _logsys_log_rec ( \
+ _logsys_log_rec_two ( \
LOGSYS_ENCODE_RECID(LOGSYS_LEVEL_DEBUG, \
logsys_subsys_id, \
LOGSYS_RECID_ENTER), \
- __FUNCTION__, __FILE__, __LINE__, LOGSYS_REC_END); \
+ __FUNCTION__, strlen (__FUNCTION__) + 1, \
+ __FILE__, strlen (__FILE__) + 1, \
+ __LINE__, LOGSYS_REC_END); \
} while(0)
#define LEAVE() do { \
- _logsys_log_rec ( \
+ _logsys_log_rec_two ( \
LOGSYS_ENCODE_RECID(LOGSYS_LEVEL_DEBUG, \
logsys_subsys_id, \
LOGSYS_RECID_LEAVE), \
- __FUNCTION__, __FILE__, __LINE__, LOGSYS_REC_END); \
+ __FUNCTION__, strlen (__FUNCTION__) + 1, \
+ __FILE__, strlen (__FILE__) + 1, \
+ __LINE__, LOGSYS_REC_END); \
} while(0)
#define TRACE(recid, format, args...) do { \
- _logsys_log_printf ( \
+ _logsys_log_printf_two ( \
LOGSYS_ENCODE_RECID(LOGSYS_LEVEL_DEBUG, \
logsys_subsys_id, \
recid), \
- __FUNCTION__, __FILE__, __LINE__, \
+ __FUNCTION__, strlen (__FUNCTION__) + 1, \
+ __FILE__, strlen (__FILE__), \
+ __LINE__, \
format, ##args); \
} while(0)
Index: exec/logsys.c
===================================================================
--- exec/logsys.c (revision 2676)
+++ exec/logsys.c (working copy)
@@ -142,6 +142,7 @@
*/
struct logsys_logger {
char subsys[LOGSYS_MAX_SUBSYS_NAMELEN]; /* subsystem name */
+ int subsys_strlen;
char *logfile; /* log to file */
FILE *logfile_fp; /* track file descriptor */
unsigned int mode; /* subsystem mode */
@@ -974,6 +975,7 @@
}
strncpy (logsys_loggers[subsysid].subsys, subsys,
LOGSYS_MAX_SUBSYS_NAMELEN);
+ logsys_loggers[subsysid].subsys_strlen = strlen (subsys);
}
/*
@@ -1160,6 +1162,26 @@
...)
{
va_list ap;
+
+ va_start (ap, file_line);
+ _logsys_log_rec_two (rec_ident,
+ function_name, strlen (function_name) + 1,
+ file_name, strlen (file_name) + 1,
+ file_line,
+ ap);
+ va_end (ap);
+}
+
+void _logsys_log_rec_two (
+ unsigned int rec_ident,
+ const char *function_name,
+ unsigned int function_name_len,
+ const char *file_name,
+ unsigned int file_name_len,
+ int file_line,
+ ...)
+{
+ va_list ap;
const void *buf_args[FDMAX_ARGS];
unsigned int buf_len[FDMAX_ARGS];
unsigned int i;
@@ -1195,11 +1217,11 @@
* Encode logsys subsystem identity, filename, and function
*/
buf_args[0] = logsys_loggers[subsysid].subsys;
- buf_len[0] = strlen (logsys_loggers[subsysid].subsys) + 1;
+ buf_len[0] = logsys_loggers[subsysid].subsys_strlen;
buf_args[1] = file_name;
- buf_len[1] = strlen (file_name) + 1;
+ buf_len[1] = file_name_len;
buf_args[2] = function_name;
- buf_len[2] = strlen (function_name) + 1;
+ buf_len[2] = function_name_len;
for (i = 0; i < 3; i++) {
record_reclaim_size += ((buf_len[i] + 3) >> 2) + 1;
}
@@ -1306,10 +1328,12 @@
records_written++;
}
-void _logsys_log_vprintf (
+void _logsys_log_vprintf_two (
unsigned int rec_ident,
const char *function_name,
+ unsigned int function_name_len,
const char *file_name,
+ unsigned int file_name_len,
int file_line,
const char *format,
va_list ap)
@@ -1342,15 +1366,19 @@
short_file_name = file_name;
else
short_file_name++; /* move past the "/" */
+
+ file_name_len = strlen (short_file_name);
#endif /* BUILDING_IN_PLACE */
/*
* Create a log record
*/
- _logsys_log_rec (
+ _logsys_log_rec_two (
rec_ident,
function_name,
+ function_name_len,
short_file_name,
+ file_name_len,
file_line,
logsys_print_buffer, len + 1,
LOGSYS_REC_END);
@@ -1382,11 +1410,29 @@
va_list ap;
va_start (ap, format);
- _logsys_log_vprintf (rec_ident, function_name, file_name, file_line,
- format, ap);
+ _logsys_log_vprintf_two (rec_ident, function_name,
+ strlen (function_name), file_name, strlen (file_name),
+ file_line, format, ap);
va_end (ap);
}
+void _logsys_log_printf_two (
+ unsigned int rec_ident,
+ const char *function_name,
+ unsigned int function_name_len,
+ const char *file_name,
+ unsigned int file_name_len,
+ int file_line,
+ const char *format,
+ ...)
+{
+ va_list ap;
+ va_start (ap, format);
+ _logsys_log_vprintf_two (rec_ident, function_name, function_name_len,
+ file_name, file_name_len, file_line, format, ap);
+ va_end (ap);
+}
+
int _logsys_config_subsys_get (const char *subsys)
{
unsigned int i;
Index: exec/Makefile.am
===================================================================
--- exec/Makefile.am (revision 2676)
+++ exec/Makefile.am (working copy)
@@ -60,14 +60,14 @@
timer.c totemconfig.c mainconfig.c quorum.c schedwrk.c \
../lcr/lcr_ifact.c evil.c syncv2.c
corosync_LDADD = -ltotem_pg -llogsys -lcoroipcs
-corosync_DEPENDENCIES = libtotem_pg.so.$(SONAME) liblogsys.so.$(SONAME) libcoroipcs.so.$(SONAME)
+corosync_DEPENDENCIES = libtotem_pg.so.$(SONAME) liblogsys.so.$(LOGSYS_SONAME) libcoroipcs.so.$(SONAME)
corosync_LDFLAGS = $(OS_DYFLAGS) -L./
TOTEM_OBJS = $(TOTEM_SRC:%.c=%.o)
LOGSYS_OBJS = $(LOGSYS_SRC:%.c=%.o)
COROIPCS_OBJS = $(COROIPCS_SRC:%.c=%.o)
-SHARED_LIBS = $(lib_LIBRARIES:%.a=%.so.$(SONAME))
+SHARED_LIBS = libtotem_pg.so.4.0.0 liblogsys.so.4.1.0 libcoroipcs.so.4.0.0
SHARED_LIBS_SO = $(SHARED_LIBS:%.so.$(SONAME)=%.so)
SHARED_LIBS_SO_TWO = $(SHARED_LIBS:%.so.$(SONAME)=%.so.$(SOMAJOR))
@@ -88,10 +88,10 @@
ln -sf libtotem_pg.so.$(SONAME) libtotem_pg.so
ln -sf libtotem_pg.so.$(SONAME) libtotem_pg.so.$(SOMAJOR)
-liblogsys.so.$(SONAME): $(LOGSYS_OBJS)
+liblogsys.so.$(LOGSYS_SONAME): $(LOGSYS_OBJS)
$(CC) $(LDFLAGS) $(DARWIN_OPTS) $(LOGSYS_OBJS) -o $@ -lpthread
- ln -sf liblogsys.so.$(SONAME) liblogsys.so
- ln -sf liblogsys.so.$(SONAME) liblogsys.so.$(SOMAJOR)
+ ln -sf liblogsys.so.$(LOGSYS_SONAME) liblogsys.so
+ ln -sf liblogsys.so.$(LOGSYS_SONAME) liblogsys.so.$(SOMAJOR)
libcoroipcs.so.$(SONAME): $(COROIPCS_OBJS)
$(CC) $(LDFLAGS) $(DARWIN_OPTS) $(COROIPCS_OBJS) -o $@ -lpthread
@@ -109,10 +109,10 @@
ln -sf libtotem_pg.so.$(SONAME) libtotem_pg.so
ln -sf libtotem_pg.so.$(SONAME) libtotem_pg.so.$(SOMAJOR)
-liblogsys.so.$(SONAME): $(LOGSYS_OBJS)
+liblogsys.so.$(LOGSYS_SONAME): $(LOGSYS_OBJS)
$(LD) -G $(LOGSYS_OBJS) -o $@ -lpthread
- ln -sf liblogsys.so.$(SONAME) liblogsys.so
- ln -sf liblogsys.so.$(SONAME) liblogsys.so.$(SOMAJOR)
+ ln -sf liblogsys.so.$(LOGSYS_SONAME) liblogsys.so
+ ln -sf liblogsys.so.$(LOGSYS_SONAME) liblogsys.so.$(SOMAJOR)
libcoroipcs.so.$(SONAME): $(COROIPCS_OBJS)
$(LD) -G $(COROIPCS_OBJS) -o $@ -lpthread
@@ -131,12 +131,12 @@
ln -sf libtotem_pg.so.$(SONAME) libtotem_pg.so
ln -sf libtotem_pg.so.$(SONAME) libtotem_pg.so.$(SOMAJOR)
-liblogsys.so.$(SONAME): $(LOGSYS_OBJS)
+liblogsys.so.$(LOGSYS_SONAME): $(LOGSYS_OBJS)
$(CC) -shared -o $@ \
-Wl,-soname=liblogsys.so.$(SOMAJOR) \
$^ $(LDFLAGS) -lpthread
- ln -sf liblogsys.so.$(SONAME) liblogsys.so
- ln -sf liblogsys.so.$(SONAME) liblogsys.so.$(SOMAJOR)
+ ln -sf liblogsys.so.$(LOGSYS_SONAME) liblogsys.so
+ ln -sf liblogsys.so.$(LOGSYS_SONAME) liblogsys.so.$(SOMAJOR)
libcoroipcs.so.$(SONAME): $(COROIPCS_OBJS)
$(CC) -shared -o $@ \
Index: configure.ac
===================================================================
--- configure.ac (revision 2676)
+++ configure.ac (working copy)
@@ -176,6 +176,9 @@
# Special for libcpg
CPG_SOMICRO="1"
CPG_SONAME="${SOMAJOR}.${SOMINOR}.${CPG_SOMICRO}"
+# Special for liblogsys
+LOGSYS_SOMINOR="1"
+LOGSYS_SONAME="${SOMAJOR}.${LOGSYS_SOMINOR}.${SOMICRO}"
# local options
AC_ARG_ENABLE([ansi],
@@ -433,6 +436,7 @@
AC_SUBST([SOMICRO])
AC_SUBST([SONAME])
AC_SUBST([CPG_SONAME])
+AC_SUBST([LOGSYS_SONAME])
AC_SUBST([OS_DYFLAGS])
@@ -483,6 +487,7 @@
AC_MSG_RESULT([$PACKAGE build info:])
AC_MSG_RESULT([ Library SONAME = ${SONAME}])
AC_MSG_RESULT([ CPG Library SONAME = ${CPG_SONAME}])
+AC_MSG_RESULT([ logsys Library SONAME = ${LOGSYS_SONAME}])
AC_MSG_RESULT([ Default optimization = ${OPT_CFLAGS}])
AC_MSG_RESULT([ Default debug options = ${GDB_CFLAGS}])
AC_MSG_RESULT([ Extra compiler warnings = ${EXTRA_WARNING}])
_______________________________________________
Openais mailing list
[email protected]
https://lists.linux-foundation.org/mailman/listinfo/openais
