aboutsummaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorMichał Łyszczek <michal.lyszczek@bofc.pl>2019-05-19 13:17:13 +0200
committerMichał Łyszczek <michal.lyszczek@bofc.pl>2019-05-19 13:17:13 +0200
commitd826ec981a19ff7aba3d34dc29f5e5911335ad90 (patch)
tree3d8c945690f028e592c7f7992aa57e75e3018ef4
parentaa129653848fc690e38d98c27ba3efa5e3810006 (diff)
downloadembedlog-d826ec981a19ff7aba3d34dc29f5e5911335ad90.tar.gz
embedlog-d826ec981a19ff7aba3d34dc29f5e5911335ad90.tar.bz2
embedlog-d826ec981a19ff7aba3d34dc29f5e5911335ad90.zip
add thread safety to library
embedlog now can be safely used in multi-thread environment, that implements pthread. Signed-off-by: Michał Łyszczek <michal.lyszczek@bofc.pl>
-rw-r--r--configure.ac28
-rw-r--r--embedlog-sources.mk4
-rw-r--r--include/embedlog.h.in13
-rw-r--r--man/el_init.320
-rw-r--r--man/el_option.359
-rw-r--r--readme.md15
-rw-r--r--src/el-flush.c5
-rw-r--r--src/el-lock.c71
-rw-r--r--src/el-options.c142
-rw-r--r--src/el-pbinary.c11
-rw-r--r--src/el-perror.c4
-rw-r--r--src/el-pmemory.c15
-rw-r--r--src/el-print.c60
-rw-r--r--src/el-private.h18
-rw-r--r--src/el-puts.c57
l---------tst/el-lock.c1
-rw-r--r--tst/test-el-file.c179
-rw-r--r--tst/test-el-options.c2
-rw-r--r--tst/test-el-pbinary.c228
-rw-r--r--tst/test-el-pmemory.c154
-rw-r--r--tst/test-el-print.c226
21 files changed, 1226 insertions, 86 deletions
diff --git a/configure.ac b/configure.ac
index 30bf6fa..c3c7daa 100644
--- a/configure.ac
+++ b/configure.ac
@@ -369,12 +369,35 @@ AC_ARG_ENABLE([reentrant],
AS_IF([test "x$enable_reentrant" = "xyes"],
[
AC_DEFINE([ENABLE_REENTRANT], [1], [Enable reentrant functions])
- AC_CHECK_FUNCS([gmtime_r],,
- AC_MSG_ERROR(not found, needed by --enable-reentrant))
])
###
+# --enable-pthread
+#
+
+
+AC_ARG_ENABLE([pthread],
+ AS_HELP_STRING([--enable-pthread], [Enable thread safety measures]),
+ [], [enable_pthread="yes"])
+
+AM_CONDITIONAL([ENABLE_PTHREAD], [test "x$enable_pthread" = "xyes"])
+ENABLE_PTHREAD=0
+AS_IF([test "x$enable_pthread" = "xyes"],
+[
+ AC_DEFINE([ENABLE_PTHREAD], [1], [Enable thread safety measures])
+ AX_PTHREAD
+ LIBS="$PTHREAD_LIBS $LIBS"
+ CFLAGS="$CFLAGS $PTHREAD_CFLAGS"
+ CC="$PTHREAD_CC"
+ ENABLE_PTHREAD=1
+])
+
+AC_SUBST(ENABLE_PTHREAD)
+
+
+
+###
# VARIABLES=value options
#
@@ -475,6 +498,7 @@ echo "binary logs................. : $enable_binary_logs"
echo "colorize output............. : $enable_colors"
echo "extended colors............. : $enable_colors_extended"
echo "reentrant functions......... : $enable_reentrant"
+echo "enable pthread support...... : $enable_pthread"
echo "maximum prefix length....... : $EL_PREFIX_MAX"
echo "maximum file length......... : $EL_FLEN_MAX"
echo "maximum function namelength. : $EL_FUNCLEN_MAX"
diff --git a/embedlog-sources.mk b/embedlog-sources.mk
index c60f5ea..bb65d6c 100644
--- a/embedlog-sources.mk
+++ b/embedlog-sources.mk
@@ -20,3 +20,7 @@ embedlog_sources += el-pbinary.c \
el-decode-number.c \
el-encode-number.c
endif
+
+if ENABLE_PTHREAD
+embedlog_sources += el-lock.c
+endif
diff --git a/include/embedlog.h.in b/include/embedlog.h.in
index 8559c02..9ec1e8b 100644
--- a/include/embedlog.h.in
+++ b/include/embedlog.h.in
@@ -11,6 +11,10 @@
#include <stdarg.h>
#include <stdio.h>
+#if @ENABLE_PTHREAD@
+# include <pthread.h>
+#endif
+
#ifdef __cplusplus
extern "C" {
#endif
@@ -116,12 +120,14 @@ enum el_option
EL_FSYNC_EVERY = 16,
EL_FSYNC_LEVEL = 17,
+ EL_THREAD_SAFE = 18,
+
/* internal use only, should represent number of options, if
* you add option, increment this by one (or by the number of
* options you add).
*/
- EL_OPT_ERROR = 18
+ EL_OPT_ERROR = 19
};
enum el_option_timestamp
@@ -223,6 +229,11 @@ struct el
el_custom_puts custom_puts;
void *custom_puts_user;
#endif
+
+#if @ENABLE_PTHREAD@
+ pthread_mutex_t lock;
+ int lock_initialized;
+#endif
};
int el_init(void);
diff --git a/man/el_init.3 b/man/el_init.3
index d1ac078..6c52a69 100644
--- a/man/el_init.3
+++ b/man/el_init.3
@@ -26,26 +26,6 @@ Another type are functions that accept additional
argument. These functions are prefixed with
.BR el_o .
.PP
-All functions (el_o or not) are "line" thread-safe (provided that
-.B \-\-enable\-reentrant
-is turned on).
-That means library buffers whole line before it calls
-.B puts
-function, so lines in output will not overlap.
-.PP
-NOTE: this may not be entirely true for every operating system there is! Yes,
-.B embedlog
-will always buffer and print whole lines, but OS may, for example interrupt
-.B puts
-call from thread1, and call
-.B puts
-from thread2.
-In such case output will be mangled with 2 different lines.
-While this situation is very rare, it's only fair to mention it.
-If in doubt, check
-.B stdio
-implementation in your operating system.
-.PP
.BR el_init (3)
initializes static global option structure. This option structure is used by all
functions that don't accept
diff --git a/man/el_option.3 b/man/el_option.3
index 1c94d04..9728e05 100644
--- a/man/el_option.3
+++ b/man/el_option.3
@@ -623,6 +623,65 @@ and
. BR tcsetattr .
. RE
.RE
+.PP
+.BI "EL_THREAD_SAFE (" int " safe)"
+.RS
+By default,
+. B embedlog
+is not thread safe.
+While it may be relatively safe to use it in multi-thread environment
+when you are logging to
+. B stdio
+or
+. BR stderr ,
+this surely isn't the case for more complex outputs like printing to file.
+Also, without
+. B EL_THREAD_SAFE
+calling
+. BR el_pmemory (3)
+may result in interlacing prints.
+. PP
+So, when using embedlog in multi-threaded environment, it is advised to enable
+. B EL_THREAD_SAFE
+by passing 1 as
+. I safe
+argument.
+. B embedlog
+will then
+. BR pthread_mutex_lock ()
+whenever threads access
+. I el
+object.
+. PP
+. B EL_THREAD_SAFE
+call must be performed when no other threads are accessing
+. I el
+object, since at this point it is not possible to lock the mutex.
+Common usage is to enable thread safety at the beggining - right after
+. BR el_init (3),
+and leave it to be destroyed by
+. BR el_cleanup (3).
+. PP
+It is safe to call this option multiple time with same argument.
+.B embedlog
+will not allow for multiple initialization nor destruction of mutex.
+When options is called for the second time with same argument (like 1),
+nothing will happen and funciton will return 0.
+. PP
+. B ERRORS
+. RS
+Function can return errors from
+. BR pthread_mutex_init (),
+and
+. BR pthread_mutex_destroy ().
+. PP
+. B EINVAL
+. RS
+. I safe
+is different than 1 or 0
+. RE
+. RE
+.RE
.SH RETURN VALUE
.PP
On success 0 is returned. -1 is returned when any error occured.
diff --git a/readme.md b/readme.md
index 00add90..19953c3 100644
--- a/readme.md
+++ b/readme.md
@@ -8,7 +8,7 @@ small and fast. Many features can be disabled during compilation to generate
smaller binary. Amount of needed stack memory can be lowered by adjusting
maximum printable size of single log message. Altough logger focuses on embedded
systems, it is general **c/c++** logger that can be used in any application.
-Implemented features are:
+Implemented features are (most of them optionally configured in runtime):
* printing to different outputs (simultaneously) like:
* syslog (very limited, works on *nuttx* for now)
@@ -31,6 +31,7 @@ Implemented features are:
* colorful output (ansi colors) for easy error spotting
* print memory block in wireshark-like output
* fully binary logs with binary data (like CAN frames) to save space
+* full thread safety using *pthread*
Almost all of these features can be disabled to save some precious bytes of
memory.
@@ -245,7 +246,17 @@ extended colors.
Uses reentrant functions where possible. Not available on every platform, but
if enabled, provides thread-safety on line level - that means, lines won't
-overlap with another thread
+overlap with another thread. This is true only when output is *stderr* or
+*stdout*, when output is *file*, you need to use true thread safety with
+the help of **EL_THREAD_SAFE** and **--enable-pthread**.
+
+--enable-pthread (default: enable)
+----------------------------------
+
+ When enabled, you will be able to configure **embedlog** to use
+**EL_THREAD_SAFE**, which will provide full thread safety in all circumstances.
+This is critical if output is other than *stderr* or *stdout* - like *file*,
+as there is internal state in *el* object that is kept between calls.
--enable-portable-snprintf (default: disable)
---------------------------------------------
diff --git a/src/el-flush.c b/src/el-flush.c
index 18a4973..cf1ccc5 100644
--- a/src/el-flush.c
+++ b/src/el-flush.c
@@ -68,10 +68,12 @@
/*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
VALID(EINVAL, el);
- VALID(ENODEV, el->outputs != 0);
+ el_lock(el);
+ VALIDC(ENODEV, el->outputs != 0, el_unlock(el));
rv = 0;
+
#if ENABLE_OUT_STDERR
if (el->outputs & EL_OUT_STDERR)
{
@@ -100,5 +102,6 @@
}
#endif
+ el_unlock(el);
return rv;
}
diff --git a/src/el-lock.c b/src/el-lock.c
new file mode 100644
index 0000000..3ec91ca
--- /dev/null
+++ b/src/el-lock.c
@@ -0,0 +1,71 @@
+/* ==========================================================================
+ Licensed under BSD 2clause license See LICENSE file for more information
+ Author: Michał Łyszczek <michal.lyszczek@bofc.pl>
+ ==========================================================================
+ ----------------------------------------------------------
+ < this simple file, deals with locking and unlocking mutex >
+ ----------------------------------------------------------
+ \ ^__^
+ \ (oo)\_______
+ (__)\ )\/\
+ ||----w |
+ || ||
+ ==========================================================================
+ _ __ __ ____ _ __
+ (_)____ _____ / /__ __ ____/ /___ / __/(_)/ /___ _____
+ / // __ \ / ___// // / / // __ // _ \ / /_ / // // _ \ / ___/
+ / // / / // /__ / // /_/ // /_/ // __/ / __// // // __/(__ )
+ /_//_/ /_/ \___//_/ \__,_/ \__,_/ \___/ /_/ /_//_/ \___//____/
+
+ ========================================================================== */
+
+
+#include "el-private.h"
+
+#include <pthread.h>
+
+
+/* ==========================================================================
+ __ __ _ ____
+ ____ __ __ / /_ / /(_)_____ / __/__ __ ____ _____ _____
+ / __ \ / / / // __ \ / // // ___/ / /_ / / / // __ \ / ___// ___/
+ / /_/ // /_/ // /_/ // // // /__ / __// /_/ // / / // /__ (__ )
+ / .___/ \__,_//_.___//_//_/ \___/ /_/ \__,_//_/ /_/ \___//____/
+ /_/
+ ========================================================================== */
+
+
+/* ==========================================================================
+ Locks mutex on specified "el" object. If mutex is not initialized, that
+ is thread safety is turned off, nothing happens.
+ ========================================================================== */
+
+
+void el_lock
+(
+ struct el *el /* el object to lock */
+)
+{
+ if (el->lock_initialized)
+ {
+ pthread_mutex_lock(&el->lock);
+ }
+}
+
+
+/* ==========================================================================
+ Unlock mutex on specified "el" object. If mutex is not initialized, that
+ is thread safety is turned off, nothing happens.
+ ========================================================================== */
+
+
+void el_unlock
+(
+ struct el *el /* el object to unlock */
+)
+{
+ if (el->lock_initialized)
+ {
+ pthread_mutex_unlock(&el->lock);
+ }
+}
diff --git a/src/el-options.c b/src/el-options.c
index 78666dd..4eae67b 100644
--- a/src/el-options.c
+++ b/src/el-options.c
@@ -118,6 +118,7 @@ static int el_vooption
va_list ap /* option value(s) */
)
{
+ int ret; /* return code from various functions */
int value_int; /* ap value treated as integer */
long value_long; /* ap value treated as long */
const char *value_str; /* ap value treated as string */
@@ -140,7 +141,9 @@ static int el_vooption
case EL_LEVEL:
value_int = va_arg(ap, int);
VALID(EINVAL, value_int <= 7);
+ el_lock(el);
el->level = value_int;
+ el_unlock(el);
return 0;
@@ -158,7 +161,9 @@ static int el_vooption
case EL_FSYNC_LEVEL:
value_int = va_arg(ap, int);
VALID(EINVAL, value_int <= 7);
+ el_lock(el);
el->fsync_level = value_int;
+ el_unlock(el);
return 0;
# endif /* ENABLE_OUT_FILE */
@@ -178,7 +183,9 @@ static int el_vooption
value_int = value_int == EL_OUT_ALL ? VALID_OUTS : value_int;
VALID(EINVAL, (value_int & ~ALL_OUTS) == 0x00);
VALID(ENODEV, (value_int & ~VALID_OUTS) == 0x00);
+ el_lock(el);
el->outputs = value_int;
+ el_unlock(el);
return 0;
@@ -195,7 +202,9 @@ static int el_vooption
value_int = va_arg(ap, int);
VALID(EINVAL, (value_int & ~1) == 0);
+ el_lock(el);
el->print_log_level = value_int;
+ el_unlock(el);
return 0;
@@ -212,7 +221,9 @@ static int el_vooption
value_int = va_arg(ap, int);
VALID(EINVAL, (value_int & ~1) == 0);
+ el_lock(el);
el->print_newline = value_int;
+ el_unlock(el);
return 0;
@@ -229,7 +240,9 @@ static int el_vooption
case EL_PREFIX:
value_str = va_arg(ap, const char *);
+ el_lock(el);
el->prefix = value_str;
+ el_unlock(el);
return 0;
# endif /* ENABLE_PREFIX */
@@ -254,7 +267,9 @@ static int el_vooption
value_int = va_arg(ap, int);
VALID(EINVAL, (value_int & ~1) == 0);
+ el_lock(el);
el->colors = value_int;
+ el_unlock(el);
return 0;
# endif /* ENABLE_COLORS */
@@ -275,7 +290,9 @@ static int el_vooption
value_int = va_arg(ap, int);
VALID(EINVAL, 0 <= value_int && value_int < EL_TS_ERROR);
+ el_lock(el);
el->timestamp = value_int;
+ el_unlock(el);
return 0;
@@ -294,7 +311,9 @@ static int el_vooption
value_int = va_arg(ap, int);
VALID(EINVAL, 0 <= value_int && value_int < EL_TS_FRACT_ERROR);
+ el_lock(el);
el->timestamp_fractions = value_int;
+ el_unlock(el);
return 0;
# endif /* ENABLE_FRACTIONS */
@@ -326,7 +345,9 @@ static int el_vooption
VALID(ENODEV, value_int != EL_TS_TM_CLOCK);
# endif
+ el_lock(el);
el->timestamp_timer = value_int;
+ el_unlock(el);
return 0;
# endif /* ENABLE_TIMESTAMP */
@@ -347,7 +368,9 @@ static int el_vooption
value_int = va_arg(ap, int);
VALID(EINVAL, (value_int & ~1) == 0);
+ el_lock(el);
el->finfo = value_int;
+ el_unlock(el);
return 0;
# endif /* ENABLE_FINFO */
@@ -379,7 +402,9 @@ static int el_vooption
value_int = va_arg(ap, int);
VALID(EINVAL, (value_int & ~1) == 0);
+ el_lock(el);
el->funcinfo = value_int;
+ el_unlock(el);
return 0;
# endif /* __STDC_VERSION__ < 199901L */
@@ -401,8 +426,11 @@ static int el_vooption
case EL_FPATH:
value_str = va_arg(ap, const char *);
VALID(EINVAL, value_str);
+ el_lock(el);
el->fname = value_str;
- return el_file_open(el);
+ ret = el_file_open(el);
+ el_unlock(el);
+ return ret;
/* ==================================================================
@@ -422,22 +450,25 @@ static int el_vooption
value_int = va_arg(ap, int);
VALID(EINVAL, value_int >= 0);
+ el_lock(el);
previous_frotate = el->frotate_number;
el->frotate_number = value_int;
+ ret = 0;
if (previous_frotate == 0 && el->file)
{
/* user turned on file rotation when file is already
* opened without rotation. To prevent weird situations
* and even data loss, we reopen file as opening with
- * log rotation is a bit different. el_file_open
+ * log rotation is a bit different. el_file_open()
* function will close file before reopening
*/
- return el_file_open(el);
+ ret = el_file_open(el);
}
- return 0;
+ el_unlock(el);
+ return ret;
}
@@ -453,7 +484,9 @@ static int el_vooption
case EL_FROTATE_SIZE:
value_long = va_arg(ap, long);
VALID(EINVAL, value_long >= 1);
+ el_lock(el);
el->frotate_size = value_long;
+ el_unlock(el);
return 0;
@@ -469,7 +502,9 @@ static int el_vooption
case EL_FSYNC_EVERY:
value_long = va_arg(ap, long);
VALID(EINVAL, value_long >= 0);
+ el_lock(el);
el->fsync_every = value_long;
+ el_unlock(el);
return 0;
# endif /* ENABLE_OUT_FILE */
@@ -495,7 +530,10 @@ static int el_vooption
VALID(EINVAL, value_str);
- return el_tty_open(el, value_str, speed);
+ el_lock(el);
+ ret = el_tty_open(el, value_str, speed);
+ el_unlock(el);
+ return ret;
}
# endif /* ENABLE_OUT_TTY */
@@ -513,14 +551,90 @@ static int el_vooption
# if ENABLE_OUT_CUSTOM
case EL_CUSTOM_PUTS:
+ el_lock(el);
el->custom_puts = va_arg(ap, el_custom_puts);
el->custom_puts_user = va_arg(ap, void *);
+ el_unlock(el);
return 0;
# endif /* ENABLE_OUT_CUSTOM */
/* ==================================================================
+ __ __ __ ___
+ / /_ / / ____ ___ ___ _ ___/ / ___ ___ _ / _/___
+ / __// _ \ / __// -_)/ _ `// _ / (_-</ _ `// _// -_)
+ \__//_//_//_/ \__/ \_,_/ \_,_/ /___/\_,_//_/ \__/
+
+ ==================================================================
+ param
+ int [0,1]
+
+ description
+ initializes or destroys lock for given "el" object,
+ function does make sure not to double initialize or
+ destroy mutex. This case must be called when no
+ other threads are accessing any of "el" fields.
+ ================================================================== */
+
+
+# if ENABLE_PTHREAD
+
+ case EL_THREAD_SAFE:
+ value_int = va_arg(ap, int);
+
+ if (value_int)
+ {
+ if (el->lock_initialized)
+ {
+ /* lock is already initialized, don't initialize
+ * it again, as this will result in undefined
+ * behaviour
+ */
+
+ return 0;
+ }
+
+ /* lock not initialized, do it now
+ */
+
+ ret = pthread_mutex_init(&el->lock, NULL);
+ if (ret > 0)
+ {
+ /* pthread does not need to set errno, and it
+ * returns errno value as return value from
+ * function, convert it to our standard error
+ * reporting
+ */
+
+ errno = ret;
+ return -1;
+ }
+
+ el->lock_initialized = 1;
+ return 0;
+ }
+
+ /* user wants to disable thread safety
+ */
+
+ if (el->lock_initialized == 0)
+ {
+ /* but lock is not initialized, can't destroy what has
+ * no yet been created.
+ */
+
+ return 0;
+ }
+
+ pthread_mutex_destroy(&el->lock);
+ el->lock_initialized = 0;
+ return 0;
+
+# endif /* ENABLE_PTHREAD */
+
+
+ /* ==================================================================
__ ___ __ __
___/ /___ / _/___ _ __ __ / // /_
/ _ // -_)/ _// _ `// // // // __/
@@ -598,6 +712,11 @@ static int el_vooption
el->fsync_every = 32768;
el->fsync_level = EL_FATAL;
#endif
+
+#if ENABLE_PTHREAD
+ el->lock_initialized = 0;
+#endif
+
return 0;
}
@@ -633,7 +752,9 @@ static int el_vooption
/* ==========================================================================
- cleans up whatever has been initialized/reserved by el_init
+ cleans up whatever has been initialized/reserved by el_init. Due to the
+ nature of pthread, this functions must be called only when no other
+ threads operate on "el" object.
========================================================================== */
@@ -648,7 +769,8 @@ static int el_vooption
/* ==========================================================================
cleans up whatever has been initialized/reserved by el_option and
- el_init calls
+ el_init calls. Due to the nature of pthread, this functions must be
+ called only when no other threads operate on "el" object.
errno
EINVAL el is invalid (null)
@@ -674,6 +796,12 @@ static int el_vooption
}
#endif
+#if ENABLE_PTHREAD
+ if (el->lock_initialized)
+ {
+ pthread_mutex_destroy(&el->lock);
+ }
+#endif
return 0;
}
diff --git a/src/el-pbinary.c b/src/el-pbinary.c
index 4f26012..48f96cf 100644
--- a/src/el-pbinary.c
+++ b/src/el-pbinary.c
@@ -60,7 +60,6 @@
#define FLAG_LEVEL_SHIFT (3)
-
/* ==========================================================================
_ __ ____
____ _____ (_)_ __ ____ _ / /_ ___ / __/__ __ ____ _____ _____
@@ -179,8 +178,9 @@ static size_t el_flags
VALID(EINVAL, mlen);
VALID(EINVAL, memory);
VALID(EINVAL, el);
- VALID(ENODEV, el->outputs);
- VALID(ERANGE, el_log_allowed(el, level));
+ el_lock(el);
+ VALIDC(ENODEV, el->outputs, el_unlock(el));
+ VALIDC(ERANGE, el_log_allowed(el, level), el_unlock(el));
e = 0;
w = el_flags(level, el, buf);
@@ -211,9 +211,10 @@ static size_t el_flags
el->level_current_msg = level;
w += mlen;
- if (el_oputb(el, buf, w) != 0)
+ if (el_oputb_nb(el, buf, w) != 0)
{
el->level_current_msg = EL_DBG;
+ el_unlock(el);
return -1;
}
@@ -222,9 +223,11 @@ static size_t el_flags
if (e)
{
errno = e;
+ el_unlock(el);
return -1;
}
+ el_unlock(el);
return 0;
}
diff --git a/src/el-perror.c b/src/el-perror.c
index dd40823..a9b7372 100644
--- a/src/el-perror.c
+++ b/src/el-perror.c
@@ -64,6 +64,10 @@ static int el_ovperror
e = errno;
rc = 0;
+ /* there is not need to el_lock() mutex here, as el_ovprint()
+ * and el_oprint() will do it for us
+ */
+
if (fmt)
{
/* we print formatted message only when it is supplied by
diff --git a/src/el-pmemory.c b/src/el-pmemory.c
index ba07a84..e86ec02 100644
--- a/src/el-pmemory.c
+++ b/src/el-pmemory.c
@@ -111,7 +111,7 @@ static int el_print_line
/* print constructed line
*/
- return el_oprint(file, num, func, level, el, "0x%04x %-*s %s",
+ return el_oprint_nb(file, num, func, level, el, "0x%04x %-*s %s",
offset, EL_MEM_HEX_LEN, hex_data, char_data);
}
@@ -185,7 +185,9 @@ static int el_pmem
VALID(EINVAL, mem);
VALID(EINVAL, mlen);
VALID(EINVAL, el);
- VALID(ERANGE, el_log_allowed(el, level));
+ el_lock(el);
+ VALIDC(ERANGE, el_log_allowed(el, level), el_unlock(el));
+
/* print log table preamble that is:
*
@@ -197,16 +199,16 @@ static int el_pmem
if (table)
{
rv = 0;
- rv |= el_oprint(file, num, func, level, el, "%.*s %.*s %.*s",
+ rv |= el_oprint_nb(file, num, func, level, el, "%.*s %.*s %.*s",
EL_MEM_OFFSET_LEN - 2, separator,
EL_MEM_HEX_LEN - 1, separator,
EL_MEM_CHAR_LEN, separator);
- rv |= el_oprint(file, num, func, level, el, "%-*s%-*s%s",
+ rv |= el_oprint_nb(file, num, func, level, el, "%-*s%-*s%s",
EL_MEM_OFFSET_LEN, "offset",
EL_MEM_HEX_LEN + 1, "hex", "ascii");
- rv |= el_oprint(file, num, func, level, el, "%.*s %.*s %.*s",
+ rv |= el_oprint_nb(file, num, func, level, el, "%.*s %.*s %.*s",
EL_MEM_OFFSET_LEN - 2, separator,
EL_MEM_HEX_LEN - 1, separator,
EL_MEM_CHAR_LEN, separator);
@@ -246,12 +248,13 @@ static int el_pmem
if (table)
{
- rv |= el_oprint(file, num, func, level, el, "%.*s %.*s %.*s",
+ rv |= el_oprint_nb(file, num, func, level, el, "%.*s %.*s %.*s",
EL_MEM_OFFSET_LEN - 2, separator,
EL_MEM_HEX_LEN - 1, separator,
EL_MEM_CHAR_LEN, separator);
}
+ el_unlock(el);
return rv;
}
diff --git a/src/el-print.c b/src/el-print.c
index 9154d06..255d3b0 100644
--- a/src/el-print.c
+++ b/src/el-print.c
@@ -393,6 +393,34 @@ static size_t el_funcinfo
/* ==========================================================================
+ el_print but with custom el and does not lock mutex.
+ ========================================================================== */
+
+
+int el_oprint_nb
+(
+ const char *file, /* file name to print in log */
+ size_t num, /* line number to print in log */
+ const char *func, /* function name to print */
+ enum el_level level, /* log level to print log with */
+ struct el *el, /* printing style el */
+ const char *fmt, /* message format (man printf) */
+ ... /* additional params for fmt */
+)
+{
+ va_list ap; /* arguments '...' for 'fmt' */
+ int ret; /* return code from el_printfv() */
+ /*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
+
+
+ va_start(ap, fmt);
+ ret = el_ovprint_nb(file, num, func, level, el, fmt, ap);
+ va_end(ap);
+ return ret;
+}
+
+
+/* ==========================================================================
el_print but accepts variadic argument list object instead of '...'
========================================================================== */
@@ -412,6 +440,34 @@ static size_t el_funcinfo
/* ==========================================================================
+ Same as el_ovprint_nb() but can lock mutex.
+ ========================================================================== */
+
+
+/* public api */ int el_ovprint
+(
+ const char *file, /* file name to print in log */
+ size_t num, /* line number to print in log */
+ const char *func, /* function name to print */
+ enum el_level level, /* log level to print log with */
+ struct el *el, /* el defining print style */
+ const char *fmt, /* message format (man printf) */
+ va_list ap /* additional params for fmt */
+)
+{
+ int ret; /* return from el_ovprint_nb() */
+ /*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
+
+
+ VALID(EINVAL, el);
+ el_lock(el);
+ ret = el_ovprint_nb(file, num, func, level, el, fmt, ap);
+ el_unlock(el);
+ return ret;
+}
+
+
+/* ==========================================================================
Prints message formated by 'fmt' and 'ap' with timestamp, 'file' and
line number 'num' information, with specified 'level' into configured
outputs. Function allocates on callers stack EL_BUF_MAX of memory. If
@@ -427,7 +483,7 @@ static size_t el_funcinfo
========================================================================== */
-/* public api */ int el_ovprint
+int el_ovprint_nb
(
const char *file, /* file name to print in log */
size_t num, /* line number to print in log */
@@ -552,7 +608,7 @@ static size_t el_funcinfo
el->level_current_msg = level;
- if (el_oputs(el, buf) != 0)
+ if (el_oputs_nb(el, buf) != 0)
{
el->level_current_msg = EL_DBG;
return -1;
diff --git a/src/el-private.h b/src/el-private.h
index aafe93b..a336c2c 100644
--- a/src/el-private.h
+++ b/src/el-private.h
@@ -309,6 +309,23 @@ void el_file_cleanup(struct el *el);
int el_file_flush(struct el *el);
#endif
+
+int el_oputb_nb(struct el *el, const void *mem, size_t mlen);
+int el_oputs_nb(struct el *el, const char *s);
+int el_ovprint_nb(const char *file, size_t num, const char *func,
+ enum el_level level, struct el *el, const char *fmt, va_list ap);
+int el_oprint_nb(const char *file, size_t num, const char *func,
+ enum el_level level, struct el *el, const char *fmt, ...);
+
+
+#if ENABLE_PTHREAD
+void el_lock(struct el *el);
+void el_unlock(struct el *el);
+#else
+#define el_lock(x)
+#define el_unlock(x)
+#endif
+
#if ENABLE_OUT_TTY
int el_tty_open(struct el *el, const char *dev, unsigned int speed);
@@ -327,5 +344,4 @@ size_t el_encode_number(unsigned long number, void *out);
size_t el_decode_number(const void *number, unsigned long *out);
#endif
-
#endif
diff --git a/src/el-puts.c b/src/el-puts.c
index 742b2bc..b36021e 100644
--- a/src/el-puts.c
+++ b/src/el-puts.c
@@ -59,11 +59,35 @@
/* ==========================================================================
- puts string 's' to all enabled output facilities specified by el
+ Just like el_oputs_nb() but can lock mutex.
========================================================================== */
-int el_oputs
+/* public api */ int el_oputs
+(
+ struct el *el, /* el defining printing style */
+ const char *s /* string to put into output */
+)
+{
+ int ret; /* return from el_oputs_nb() */
+ /*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
+
+
+ el_lock(el);
+ ret = el_oputs_nb(el, s);
+ el_unlock(el);
+ return ret;
+}
+
+
+
+/* ==========================================================================
+ puts string 's' to all enabled output facilities specified by el. Does
+ not do any locking, thus _nb (non blocking).
+ ========================================================================== */
+
+
+int el_oputs_nb
(
struct el *el, /* el defining printing style */
const char *s /* string to put into output */
@@ -148,12 +172,37 @@ int el_oputs
/* ==========================================================================
+ Just like el_oputb_nb() but also can perform pthread locking.
+ ========================================================================== */
+
+
+/* public api */ int el_oputb
+(
+ struct el *el, /* el defining printing style */
+ const void *mem, /* memory location to 'print' */
+ size_t mlen /* size of the mem buffer */
+)
+{
+ int ret; /* return value from el_oputb_nb() */
+ /*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
+
+
+ el_lock(el);
+ ret = el_oputb_nb(el, mem, mlen);
+ el_unlock(el);
+ return ret;
+}
+
+
+/* ==========================================================================
Puts binary data 'mem' of size 'mlen' to enabled output facilities
- specified by 'el object'. No all outputs support printing binary data
+ specified by 'el object'. No all outputs support printing binary data.
+
+ This functions does not do any locking - thus _nb (non blocking).
========================================================================== */
-int el_oputb
+int el_oputb_nb
(
struct el *el, /* el defining printing style */
const void *mem, /* memory location to 'print' */
diff --git a/tst/el-lock.c b/tst/el-lock.c
new file mode 120000
index 0000000..d509131
--- /dev/null
+++ b/tst/el-lock.c
@@ -0,0 +1 @@
+../src/el-lock.c \ No newline at end of file
diff --git a/tst/test-el-file.c b/tst/test-el-file.c
index aa989e1..21d9203 100644
--- a/tst/test-el-file.c
+++ b/tst/test-el-file.c
@@ -1637,6 +1637,181 @@ static void file_sync_level(void)
/* ==========================================================================
+ ========================================================================== */
+
+
+#if ENABLE_PTHREAD
+
+#define max_file_size 200000 /* 200kB */
+#define line_length 7 /* max number will be "999999\n" 0 padded */
+#define number_of_rotation 7
+#define number_of_threads 32
+#define prints_per_rotate (max_file_size / line_length)
+#define total_prints (prints_per_rotate * number_of_rotation)
+#define prints_per_thread (total_prints / number_of_threads)
+
+static int print_check(void)
+{
+ char line[line_length + 1];
+ char expected[line_length + 1];
+ FILE *f;
+ int curr_tid;
+ int curr_mid;
+ /*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
+
+
+ /* concat and sort files, let's take shortcut with system tools,
+ * because why not?
+ */
+
+ system("cat "WORKDIR"/log* | sort > "WORKDIR"/result");
+
+ f = fopen(WORKDIR"/result", "r");
+ if (f == NULL)
+ {
+ fprintf(stderr, WORKDIR"/result does not exist\n");
+ return -1;
+ }
+
+ curr_tid = 0;
+ curr_mid = 0;
+ for (;;)
+ {
+ line[sizeof(line) - 1] = 0x55;
+
+ if (fgets(line, sizeof(line), f) == NULL)
+ {
+ if (feof(f))
+ {
+ /* got all lines without errors
+ */
+
+ break;
+ }
+
+ perror("fgets()");
+ fclose(f);
+ return -1;
+ }
+
+ if (line[sizeof(line) - 1] == '\0' && line[sizeof(line) - 2] != '\n')
+ {
+ fprintf(stderr, "line is too long '%s', thread interlacing?\n",
+ line);
+ fclose(f);
+ return -1;
+ }
+
+ sprintf(expected, "%02d%04d\n", curr_tid, curr_mid);
+ if (strcmp(expected, line) != 0)
+ {
+ fprintf(stderr, "expected different than line: %s != %s\n",
+ expected, line);
+ fclose(f);
+ return -1;
+ }
+
+ if (++curr_mid == prints_per_thread)
+ {
+ ++curr_tid;
+ curr_mid = 0;
+ }
+ }
+
+ if (curr_tid != number_of_threads || curr_mid != 0)
+ {
+ fprintf(stderr, "file didn't contain all entries, tid: %d, mid: %d\n",
+ curr_tid, curr_mid);
+ fclose(f);
+ return -1;
+ }
+
+ fclose(f);
+ return 0;
+}
+
+
+static void *print_t
+(
+ void *arg
+)
+{
+ char msg[line_length + 1];
+ int i;
+ int n;
+ /*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
+
+ n = *(int *)arg;
+
+ for (i = 0; i != prints_per_thread; ++i)
+ {
+ sprintf(msg, "%02d%04d", n, i);
+ el_print(ELN, "%s", msg);
+ }
+
+ return NULL;
+}
+
+
+static void file_print_threaded(void)
+{
+ pthread_t pt[number_of_threads];
+ int i, n[number_of_threads];;
+ /*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
+
+
+ el_init();
+
+ el_option(EL_THREAD_SAFE, 1);
+ el_option(EL_PRINT_LEVEL, 0);
+ el_option(EL_OUT, EL_OUT_FILE);
+
+ /* rotate around 200kB, line is 7 bytes long, so this will
+ * get us 28571 prints before rotation
+ */
+
+ el_option(EL_FROTATE_SIZE, max_file_size);
+ el_option(EL_FROTATE_NUMBER, 99);
+ el_option(EL_FPATH, WORKDIR"/log");
+ el_option(EL_FSYNC_EVERY, max_file_size / 4);
+
+ for (i = 0; i != number_of_threads; ++i)
+ {
+ n[i] = i;
+ pthread_create(&pt[i], NULL, print_t, &n[i]);
+ }
+
+ for (i = 0; i != number_of_threads; ++i)
+ {
+ pthread_join(pt[i], NULL);
+ }
+
+ /* do it before print_check() so any buffered data is flushed
+ * to disk, otherwise files will be incomplete
+ */
+
+ el_flush();
+
+ mt_fok(print_check());
+
+ for (i = 0; i != 99; ++i)
+ {
+ char path[PATH_MAX];
+ /*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
+
+
+ sprintf(path, WORKDIR"/log.%d", i);
+ unlink(path);
+ }
+
+ unlink(WORKDIR"/result");
+ el_cleanup();
+}
+
+#endif /* ENABLE_PTHREAD */
+
+
+/* ==========================================================================
__ __
/ /_ ___ _____ / /_ ____ _ _____ ____ __ __ ____
/ __// _ \ / ___// __/ / __ `// ___// __ \ / / / // __ \
@@ -1651,6 +1826,10 @@ void el_file_test_group(void)
#if ENABLE_OUT_FILE
mkdir(WORKDIR, 0755);
+#if ENABLE_PTHREAD
+ mt_run(file_print_threaded);
+#endif
+
mt_run(file_print_without_init);
mt_run(file_print_after_cleanup);
mt_run(file_print_without_setting_file);
diff --git a/tst/test-el-options.c b/tst/test-el-options.c
index 4ada3de..5f5f684 100644
--- a/tst/test-el-options.c
+++ b/tst/test-el-options.c
@@ -464,6 +464,8 @@ static void options_ooption_test(void)
/*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
+ el_oinit(&opts);
+
#if ENABLE_TIMESTAMP
el_ooption(&opts, EL_TS_TM, EL_TS_TM_TIME);
mt_fail(opts.timestamp_timer == EL_TS_TM_TIME);
diff --git a/tst/test-el-pbinary.c b/tst/test-el-pbinary.c
index ad53645..e7a4f6b 100644
--- a/tst/test-el-pbinary.c
+++ b/tst/test-el-pbinary.c
@@ -706,7 +706,227 @@ static void pbinary_truncate(void)
mt_fok(pbinary_check());
}
-#endif
+
+/* ==========================================================================
+ ========================================================================== */
+
+
+#if ENABLE_PTHREAD
+
+#define total_prints 125000
+#define line_length (2 * sizeof(int) + 2)
+#define number_of_threads 25
+
+#define file_size (total_prints * line_length)
+#define prints_per_rotate (file_size / line_length)
+#define prints_per_thread (total_prints / number_of_threads)
+
+static int sort_pbinary
+(
+ const void *p1,
+ const void *p2
+)
+{
+ int m1[2];
+ int m2[2];
+ /*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
+
+ memcpy(m1, (unsigned char *)p1 + 2, sizeof(m1));
+ memcpy(m2, (unsigned char *)p2 + 2, sizeof(m2));
+
+ if (m1[0] < m2[0])
+ {
+ return -1;
+ }
+
+ if (m1[0] > m2[0])
+ {
+ return 1;
+ }
+
+ /* thread id equal, let message id decide euqualness
+ */
+
+ if (m1[1] < m2[1])
+ {
+ return -1;
+ }
+
+ if (m1[1] > m2[1])
+ {
+ return 1;
+ }
+
+ /* everything is equal, there is bug, upper layer will
+ * take care of it
+ */
+
+ fprintf(stderr, "sort_pbinary, m1 == m2\n");
+ return 0;
+}
+
+
+static int print_check(void)
+{
+ struct stat st;
+ unsigned char *msg;
+ unsigned char *msgsave;
+ int fd;
+ unsigned char flags;
+ unsigned char len;
+ int tid;
+ int mid;
+ int curr_tid;
+ int curr_mid;
+ unsigned i;
+ /*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
+
+
+ stat(logpath, &st);
+
+ if (st.st_size != file_size)
+ {
+ fprintf(stderr, "file size different than expected\n");
+ return -1;
+ }
+
+ fd = open(logpath, O_RDONLY);
+ msg = mmap(NULL, st.st_size, PROT_READ | PROT_WRITE, MAP_PRIVATE, fd, 0);
+ msgsave = msg;
+ curr_tid = 0;
+ curr_mid = 0;
+
+
+ qsort(msg, total_prints, line_length, sort_pbinary);
+
+ for (i = 0; i < file_size; i += line_length)
+ {
+ flags = msg[i + 0];
+ len = msg[i + 1];
+ memcpy(&tid, &msg[i + 2], sizeof(tid));
+ memcpy(&mid, &msg[i + 6], sizeof(mid));
+
+ /* flag should contain only severity level (info == 6)
+ */
+
+ if (flags != 6 << 3)
+ {
+ fprintf(stderr, "incorect flags: %d\n", flags);
+ munmap(msgsave, st.st_size);
+ close(fd);
+ return -1;
+ }
+
+ if (len != 2 * sizeof(int))
+ {
+ fprintf(stderr, "incorect line length: %d\n", len);
+ munmap(msgsave, st.st_size);
+ close(fd);
+ return -1;
+ }
+
+ if (tid != curr_tid)
+ {
+ fprintf(stderr, "msg_tid (%d) != curr_tid (%d)\n",
+ tid, curr_tid);
+ munmap(msgsave, st.st_size);
+ close(fd);
+ return -1;
+ }
+
+ if (mid != curr_mid)
+ {
+ fprintf(stderr, "msg_mid (%d) != curr_mid (%d)\n",
+ mid, curr_mid);
+ munmap(msgsave, st.st_size);
+ close(fd);
+ return -1;
+ }
+
+ if (++curr_mid == prints_per_thread)
+ {
+ ++curr_tid;
+ curr_mid = 0;
+ }
+ }
+
+ if (curr_tid != number_of_threads || curr_mid != 0)
+ {
+ fprintf(stderr, "file didn't contain all entries, tid: %d, mid: %d\n",
+ curr_tid, curr_mid);
+ munmap(msgsave, st.st_size);
+ close(fd);
+ return -1;
+ }
+
+ munmap(msgsave, st.st_size);
+ close(fd);
+ return 0;
+}
+
+static void *print_t
+(
+ void *arg
+)
+{
+ int msg[2];
+ int i;
+ int n;
+ /*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
+
+ n = *(int *)arg;
+
+ for (i = 0; i != prints_per_thread; ++i)
+ {
+ msg[0] = n;
+ msg[1] = i;
+ el_pbinary(EL_INFO, msg, sizeof(msg));
+ }
+
+ return NULL;
+}
+
+
+static void prbinary_threaded(void)
+{
+ pthread_t pt[number_of_threads];
+ int i, j, n[number_of_threads];
+ /*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
+
+
+ unlink(logpath);
+ el_init();
+
+ el_option(EL_THREAD_SAFE, 1);
+ el_option(EL_PRINT_LEVEL, 0);
+ el_option(EL_OUT, EL_OUT_FILE);
+ el_option(EL_FROTATE_NUMBER, 0);
+ el_option(EL_FPATH, logpath);
+ el_option(EL_FSYNC_EVERY, file_size / 4);
+
+ for (i = 0; i != number_of_threads; ++i)
+ {
+ n[i] = i;
+ pthread_create(&pt[i], NULL, print_t, &n[i]);
+ }
+
+ for (i = 0; i != number_of_threads; ++i)
+ {
+ pthread_join(pt[i], NULL);
+ }
+
+ /* do it before print_check() so any buffered data is flushed
+ * to disk, otherwise files will be incomplete
+ */
+
+ el_flush();
+ mt_fok(print_check());
+ el_cleanup();
+}
+
+#endif /* ENABLE_PTHREAD */
+#endif /* ENABLE_BINARY_LOGS */
+
/* ==========================================================================
@@ -722,6 +942,12 @@ static void pbinary_truncate(void)
void el_pbinary_test_group(void)
{
#if ENABLE_BINARY_LOGS
+#if ENABLE_PTHREAD
+
+ mt_run(prbinary_threaded);
+
+#endif
+
mt_run(pbinary_different_clocks);
pbinary_mix_of_everything();
diff --git a/tst/test-el-pmemory.c b/tst/test-el-pmemory.c
index 1bff3ad..5509aeb 100644
--- a/tst/test-el-pmemory.c
+++ b/tst/test-el-pmemory.c
@@ -19,6 +19,9 @@
#include "mtest.h"
#include "embedlog.h"
+#if ENABLE_PTHREAD
+# include <pthread.h>
+#endif
/* ==========================================================================
__ __ __ _
@@ -32,6 +35,7 @@
mt_defs_ext();
static char logbuf[1024 * 1024]; /* output simulation */
+static char ascii[128];
/* ==========================================================================
@@ -194,18 +198,7 @@ static void pmemory_binary_data_with_nulls(void)
static void pmemory_print_ascii_table(void)
{
- char ascii[128 + 1];
- int i;
- /*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
-
- for (i = 0; i != 0x80; ++i)
- {
- ascii[i] = (char)i;
- }
-
- ascii[i] = '\0';
-
- el_pmemory(ELI, ascii, sizeof(ascii) - 1);
+ el_pmemory(ELI, ascii, sizeof(ascii));
mt_fok(strcmp(logbuf,
"0x0000 00 01 02 03 04 05 06 07 08 09 0a 0b 0c 0d 0e 0f ................\n"
"0x0010 10 11 12 13 14 15 16 17 18 19 1a 1b 1c 1d 1e 1f ................\n"
@@ -224,18 +217,7 @@ static void pmemory_print_ascii_table(void)
static void pmemory_print_ascii_table_with_table(void)
{
- char ascii[128 + 1];
- int i;
- /*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
-
- for (i = 0; i != 0x80; ++i)
- {
- ascii[i] = (char)i;
- }
-
- ascii[i] = '\0';
-
- el_pmemory_table(ELI, ascii, sizeof(ascii) - 1);
+ el_pmemory_table(ELI, ascii, sizeof(ascii));
mt_fok(strcmp(logbuf,
"------ ----------------------------------------------- ----------------\n"
"offset hex ascii\n"
@@ -256,6 +238,117 @@ static void pmemory_print_ascii_table_with_table(void)
========================================================================== */
+#if ENABLE_PTHREAD
+
+static const char expected_out[] =
+"0x0000 00 01 02 03 04 05 06 07 08 09 0a 0b 0c 0d 0e 0f ................\n"
+"0x0010 10 11 12 13 14 15 16 17 18 19 1a 1b 1c 1d 1e 1f ................\n"
+"0x0020 20 21 22 23 24 25 26 27 28 29 2a 2b 2c 2d 2e 2f !\"#$%&'()*+,-./\n"
+"0x0030 30 31 32 33 34 35 36 37 38 39 3a 3b 3c 3d 3e 3f 0123456789:;<=>?\n"
+"0x0040 40 41 42 43 44 45 46 47 48 49 4a 4b 4c 4d 4e 4f @ABCDEFGHIJKLMNO\n"
+"0x0050 50 51 52 53 54 55 56 57 58 59 5a 5b 5c 5d 5e 5f PQRSTUVWXYZ[\\]^_\n"
+"0x0060 60 61 62 63 64 65 66 67 68 69 6a 6b 6c 6d 6e 6f `abcdefghijklmno\n"
+"0x0070 70 71 72 73 74 75 76 77 78 79 7a 7b 7c 7d 7e 7f pqrstuvwxyz{|}~.\n";
+
+#define max_size sizeof(logbuf)
+#define number_of_threads 32
+#define print_length (sizeof(expected_out) - 1)
+#define prints_per_thread (max_size / print_length / number_of_threads)
+#define number_of_prints (prints_per_thread * number_of_threads)
+
+static int print_check(void)
+{
+ int i;
+ char *msg;
+ /*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
+
+
+ /* all we care about is that there are no interlaces
+ */
+
+ for (msg = logbuf, i = 0; i != number_of_prints; ++i, msg += print_length)
+ {
+ if (strncmp(msg, expected_out, print_length) != 0)
+ {
+ fprintf(stderr, "message does not match (pass %d) msg: %s\n",
+ i, msg);
+ return -1;
+ }
+ }
+
+ if (*msg != '\0')
+ {
+ fprintf(stderr, "expected null terminator on last msg byte\n");
+ return -1;
+ }
+
+ return 0;
+}
+
+
+static void *print_t
+(
+ void *arg
+)
+{
+ int i;
+ /*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
+
+
+ (void)arg;
+
+
+ for (i = 0; i != prints_per_thread; ++i)
+ {
+ el_pmemory(ELN, ascii, sizeof(ascii));
+ }
+
+ return NULL;
+}
+
+
+static void pmemory_print_threaded(void)
+{
+ pthread_t pt[number_of_threads];
+ int i;
+ /*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
+
+
+ el_init();
+ el_option(EL_THREAD_SAFE, 1);
+ el_option(EL_CUSTOM_PUTS, print_to_buffer, logbuf);
+ el_option(EL_PRINT_LEVEL, 0);
+ el_option(EL_OUT, EL_OUT_CUSTOM);
+ logbuf[0] = '\0';
+
+ for (i = 0; i != number_of_threads; ++i)
+ {
+ pthread_create(&pt[i], NULL, print_t, NULL);
+ }
+
+ for (i = 0; i != number_of_threads; ++i)
+ {
+ pthread_join(pt[i], NULL);
+ }
+
+ /* do it before print_check() so any buffered data is flushed
+ * to disk, otherwise files will be incomplete
+ */
+
+ el_flush();
+
+ mt_fok(print_check());
+
+ el_cleanup();
+}
+
+#endif /* ENABLE_PTHREAD */
+
+
+/* ==========================================================================
+ ========================================================================== */
+
+
static void pmemory_null_memory(void)
{
mt_ferr(el_pmemory(ELI, NULL, 10), EINVAL);
@@ -288,6 +381,19 @@ static void pmemory_zero_size(void)
void el_pmemory_test_group(void)
{
+ int i;
+ /*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
+
+
+ for (i = 0; i != 0x80; ++i)
+ {
+ ascii[i] = (char)i;
+ }
+
+#if ENABLE_PTHREAD
+ mt_run(pmemory_print_threaded);
+#endif
+
mt_prepare_test = &test_prepare;
mt_cleanup_test = &test_cleanup;
diff --git a/tst/test-el-print.c b/tst/test-el-print.c
index 32b0df3..d706e37 100644
--- a/tst/test-el-print.c
+++ b/tst/test-el-print.c
@@ -21,6 +21,10 @@
#include <stdint.h>
#include <math.h>
+#if ENABLE_PTHREAD
+# include <pthread.h>
+#endif
+
#include "mtest.h"
#include "stdlib.h"
#include "embedlog.h"
@@ -47,8 +51,29 @@ struct log_message
mt_defs_ext();
-static char logbuf[1024 * 1024]; /* output simulation */
-static struct rb *expected_logs; /* array of expected logs */
+static char *logbuf; /* output simulation */
+static struct rb *expected_logs; /* array of expected logs */
+
+/* declarations for threaded tests
+ */
+
+#if ENABLE_PTHREAD
+
+#define prints_per_thread 1024
+#define number_of_threads 32
+#define msg_size 31
+
+/* this multiplication must result in number being a power of 2
+ * (2, 4, 8, 16 etc.)
+ */
+
+#define number_of_messages (prints_per_thread * number_of_threads)
+
+static int thread_test;
+static char msgs[number_of_threads][prints_per_thread][msg_size];
+static struct log_message expected_msgs[number_of_threads];
+
+#endif
/* ==========================================================================
@@ -62,6 +87,44 @@ static struct rb *expected_logs; /* array of expected logs */
/* ==========================================================================
+ Extracts thread id from message during thread test.
+ ========================================================================== */
+
+
+static int thread_str_to_int
+(
+ const char *msg
+)
+{
+ char *tids;
+ char mcpy[1024];
+ /*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
+
+
+ /* msg is in format "msg [TTT:III]" where TTT is thread id
+ */
+
+ strcpy(mcpy, msg);
+
+ /* turn : into null
+ */
+
+ tids = strrchr(mcpy, ':');
+ *tids = '\0';
+
+ /* point tids to beginning of thread id
+ */
+
+ tids = strrchr(mcpy, '[') + 1;
+
+ /* convert thread id to int
+ */
+
+ return atoi(tids);
+}
+
+
+/* ==========================================================================
this is custom function that will be called instead of for example puts,
after el_print constructs message. We capture that message and simply
append to logbuf, so we can analyze it later if everything is in order.
@@ -75,6 +138,24 @@ static int print_to_buffer
)
{
strcat(user, s);
+
+#if ENABLE_PTHREAD
+ if (thread_test)
+ {
+ int tid;
+ /*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
+
+
+ /* we can now add previously cached log info to expected logs.
+ * We do it here, so we can be sure it will go into the list
+ * in the same order as "s" into "user" (log_buf).
+ */
+
+ tid = thread_str_to_int(s);
+ rb_write(expected_logs, &expected_msgs[tid], 1);
+ }
+#endif
+
return 0;
}
@@ -545,16 +626,51 @@ static void add_log
const char *msg
)
{
- struct log_message expected;
- /*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
+#if ENABLE_PTHREAD
+ if (thread_test == 0)
+#endif
+ {
+ struct log_message expected;
+ /*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
- expected.file = file;
- expected.line = line;
- expected.func = func;
- expected.level = level;
- expected.msg = msg;
- rb_write(expected_logs, &expected, 1);
+ expected.file = file;
+ expected.line = line;
+ expected.func = func;
+ expected.level = level;
+ expected.msg = msg;
+ rb_write(expected_logs, &expected, 1);
+ }
+#if ENABLE_PTHREAD
+ else
+ {
+ int tid;
+ /*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
+
+
+ /* when threaded test is performed, cache expected logs and
+ * add them in custom print function. This is due to the
+ * fact, that multiple threads can get here, and expected
+ * logs buffer can be in different order than logs in
+ * log_buf. Custom print function should be protected with
+ * mutexes so no such situation should happen there.
+ *
+ * msg is in format "msg [TTT:III]" where TTT is thread id
+ */
+
+ tid = thread_str_to_int(msg);
+
+ /* now cache entries
+ */
+
+ expected_msgs[tid].file = file;
+ expected_msgs[tid].line = line;
+ expected_msgs[tid].func = func;
+ expected_msgs[tid].level = level;
+ expected_msgs[tid].msg = msg;
+ }
+#endif
+
el_print(file, line, func, level, msg);
}
@@ -568,10 +684,10 @@ static void add_log
static void test_prepare(void)
{
el_init();
+ logbuf = calloc(1, 1024 * 1024);
el_option(EL_CUSTOM_PUTS, print_to_buffer, logbuf);
el_option(EL_PRINT_LEVEL, 0);
el_option(EL_OUT, EL_OUT_CUSTOM);
- memset(logbuf, 0, sizeof(logbuf));
expected_logs = rb_new(1024, sizeof(struct log_message), 0);
}
@@ -584,6 +700,7 @@ static void test_prepare(void)
static void test_cleanup(void)
{
el_cleanup();
+ free(logbuf);
rb_destroy(expected_logs);
}
@@ -843,6 +960,87 @@ static void print_finfo(void)
========================================================================== */
+#if ENABLE_PTHREAD
+
+static void *print_t
+(
+ void *arg
+)
+{
+ int i;
+ int n;
+ char *m;
+ /*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
+
+
+ n = *(int *)arg;
+
+ for (i = 0; i != prints_per_thread; ++i)
+ {
+ m = msgs[n][i];
+ sprintf(m, "print_t [%d:%d]", n, i);
+ add_log(ELF, m);
+ }
+
+ return NULL;
+}
+
+static void print_threaded(void)
+{
+ pthread_t pt[number_of_threads];
+ int i, n[number_of_threads];
+ /*~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~*/
+
+
+ el_init();
+
+ /* allocate memory that can hold all messages with full
+ * pre information (timestamp, file info) and message of length
+ * 31 characters
+ */
+
+ logbuf = calloc(1, number_of_messages *
+ (EL_PRE_LEN + EL_COLORS_LEN + msg_size));
+ expected_logs = rb_new(number_of_messages, sizeof(struct log_message), 0);
+
+ el_option(EL_CUSTOM_PUTS, print_to_buffer, logbuf);
+ el_option(EL_PRINT_LEVEL, 1);
+ el_option(EL_TS, EL_TS_LONG);
+ el_option(EL_TS_TM, EL_TS_TM_REALTIME);
+ el_option(EL_TS_FRACT, EL_TS_FRACT_US);
+ el_option(EL_FINFO, 1);
+ el_option(EL_FUNCINFO, 1);
+ el_option(EL_COLORS, 1);
+ el_option(EL_PREFIX, "thread-test");
+ el_option(EL_OUT, EL_OUT_CUSTOM);
+ el_option(EL_LEVEL, EL_DBG);
+ el_option(EL_THREAD_SAFE, 1);
+
+ for (i = 0; i != number_of_threads; ++i)
+ {
+ n[i] = i;
+ pthread_create(&pt[i], NULL, print_t, &n[i]);
+ }
+
+ for (i = 0; i != number_of_threads; ++i)
+ {
+ pthread_join(pt[i], NULL);
+ }
+
+ mt_fok(print_check());
+ rb_destroy(expected_logs);
+ free(logbuf);
+
+ el_cleanup();
+}
+
+#endif /* ENABLE_PTHREAD */
+
+
+/* ==========================================================================
+ ========================================================================== */
+
+
static void print_different_clocks(void)
{
int i;
@@ -1185,6 +1383,12 @@ static void print_prefix_overflow(void)
void el_print_test_group(void)
{
+#if ENABLE_PTHREAD
+ thread_test = 1;
+ mt_run(print_threaded);
+ thread_test = 0;
+#endif
+
mt_run(print_different_clocks);
print_mix_of_everything();