Skip to content

Commit 57f1905

Browse files
lplewalplewa
committed
use logger instead of perror
Signed-off-by: Łukasz Plewa <lukasz.plewa@intel.com>
1 parent 67dbedc commit 57f1905

File tree

7 files changed

+350
-55
lines changed

7 files changed

+350
-55
lines changed

‎benchmark/ubench.c

Lines changed: 0 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -44,7 +44,6 @@
4444
#define DISJOINT_POOL_MAX_POOLABLE_SIZE (2 * ALLOC_SIZE)
4545
#define DISJOINT_POOL_CAPACITY (N_ITERATIONS + 10)
4646
#define DISJOINT_POOL_MIN_BUCKET_SIZE (ALLOC_SIZE)
47-
#define DISJOINT_POOL_TRACE (0)
4847

4948
typedef struct alloc_s {
5049
void *ptr;
@@ -115,7 +114,6 @@ static umf_os_memory_provider_params_t UMF_OS_MEMORY_PROVIDER_PARAMS = {
115114
/* .numa_mode = */ UMF_NUMA_MODE_DEFAULT,
116115

117116
// others
118-
/* .traces = */ OS_MEMORY_PROVIDER_TRACE,
119117
};
120118

121119
static void *w_umfMemoryProviderAlloc(void *provider, size_t size,
@@ -237,7 +235,6 @@ UBENCH_EX(simple, disjoint_pool_with_os_memory_provider) {
237235
DISJOINT_POOL_MAX_POOLABLE_SIZE;
238236
disjoint_memory_pool_params.Capacity = DISJOINT_POOL_CAPACITY;
239237
disjoint_memory_pool_params.MinBucketSize = DISJOINT_POOL_MIN_BUCKET_SIZE;
240-
disjoint_memory_pool_params.PoolTrace = DISJOINT_POOL_TRACE;
241238

242239
umf_memory_pool_handle_t disjoint_pool;
243240
umf_result = umfPoolCreate(umfDisjointPoolOps(), os_memory_provider,

‎scripts/docs_config/introduction.rst

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -105,12 +105,12 @@ By default, there is a guarantee that *error* messages are flushed immediately.
105105

106106
Loggers redirect messages to *stdout*, *stderr*, or a file
107107

108-
By default, no messages are printed. To enable logger you have to set **UMF_LOG** environment variable which have following syntax for setting logger options:
108+
By default, only fatal messages are printed. To enable logger you have to set **UMF_LOG** environment variable which have following syntax for setting logger options:
109109

110-
"[level:debug|info|warning|error];[flush:debug|info|warning|error];[output:stdout|stderr|file,<path>];[timestamp:yes|no];[pid:yes|no]"
110+
"[level:debug|info|warning|error|fatal];[flush:debug|info|warning|error|fatal];[output:stdout|stderr|file,<path>];[timestamp:yes|no];[pid:yes|no]"
111111

112112
* level - a log level, meaning that only messages from this level and above are printed.
113-
Possible values, from the lowest level to the highest one: *debug*, *info*, *warning*, *error*,
113+
Possible values, from the lowest level to the highest one: *debug*, *info*, *warning*, *error*, *fatal*
114114
* flush - a flush level, meaning that messages at this level and above are guaranteed to be flushed immediately,
115115
possible values are the same as above,
116116
* output - indicates where messages should be printed.

‎src/provider/provider_os_memory.c

Lines changed: 6 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -311,8 +311,7 @@ static void print_numa_nodes(os_memory_provider_t *os_provider, void *addr,
311311
int ret = hwloc_get_area_memlocation(os_provider->topo, addr, 1, nodeset,
312312
HWLOC_MEMBIND_BYNODESET);
313313
if (ret) {
314-
LOG_DEBUG("cannot print assigned NUMA node (errno = %i)", errno);
315-
perror("get_mempolicy()");
314+
LOG_PDEBUG("cannot print assigned NUMA node (errno = %i)", errno);
316315
} else {
317316
if (hwloc_bitmap_list_snprintf(os_provider->nodeset_str_buf,
318317
NODESET_STR_BUF_LEN, nodeset)) {
@@ -422,7 +421,7 @@ static umf_result_t os_alloc(void *provider, size_t size, size_t alignment,
422421
ret = os_mmap_aligned(NULL, size, alignment, page_size, protection, &addr);
423422
if (ret) {
424423
os_store_last_native_error(UMF_OS_RESULT_ERROR_ALLOC_FAILED, errno);
425-
perror("memory allocation failed");
424+
LOG_PERR("memory allocation failed");
426425

427426
return UMF_RESULT_ERROR_MEMORY_PROVIDER_SPECIFIC;
428427
}
@@ -455,7 +454,7 @@ static umf_result_t os_alloc(void *provider, size_t size, size_t alignment,
455454

456455
if (ret) {
457456
os_store_last_native_error(UMF_OS_RESULT_ERROR_BIND_FAILED, errno);
458-
perror("binding memory to NUMA node failed");
457+
LOG_PERR("binding memory to NUMA node failed");
459458
// TODO: (errno == 0) when hwloc_set_area_membind() fails on Windows - ignore this temporarily
460459
if (errno != ENOSYS &&
461460
errno != 0) { // ENOSYS - Function not implemented
@@ -483,7 +482,7 @@ static umf_result_t os_free(void *provider, void *ptr, size_t size) {
483482
// ignore error when size == 0
484483
if (ret && (size > 0)) {
485484
os_store_last_native_error(UMF_OS_RESULT_ERROR_FREE_FAILED, errno);
486-
perror("memory deallocation failed");
485+
LOG_PERR("memory deallocation failed");
487486

488487
return UMF_RESULT_ERROR_MEMORY_PROVIDER_SPECIFIC;
489488
}
@@ -555,7 +554,7 @@ static umf_result_t os_purge_lazy(void *provider, void *ptr, size_t size) {
555554
if (os_purge(ptr, size, UMF_PURGE_LAZY)) {
556555
os_store_last_native_error(UMF_OS_RESULT_ERROR_PURGE_LAZY_FAILED,
557556
errno);
558-
perror("lazy purging failed");
557+
LOG_PERR("lazy purging failed");
559558

560559
return UMF_RESULT_ERROR_MEMORY_PROVIDER_SPECIFIC;
561560
}
@@ -571,7 +570,7 @@ static umf_result_t os_purge_force(void *provider, void *ptr, size_t size) {
571570
if (os_purge(ptr, size, UMF_PURGE_FORCE)) {
572571
os_store_last_native_error(UMF_OS_RESULT_ERROR_PURGE_FORCE_FAILED,
573572
errno);
574-
perror("force purging failed");
573+
LOG_PERR("force purging failed");
575574
return UMF_RESULT_ERROR_MEMORY_PROVIDER_SPECIFIC;
576575
}
577576
return UMF_RESULT_SUCCESS;

‎src/utils/utils_assert.h

Lines changed: 7 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,7 @@
1010
#ifndef UMF_ASSERT_H
1111
#define UMF_ASSERT_H 1
1212

13+
#include "utils_log.h"
1314
#include <stdint.h>
1415
#include <stdio.h>
1516
#include <stdlib.h>
@@ -29,9 +30,8 @@ extern "C" {
2930
#define ASSERT(x) \
3031
do { \
3132
if (!(x)) { \
32-
fprintf(stderr, \
33-
"Assertion failed: " #x " at " __FILE__ " line %d.\n", \
34-
__LINE__); \
33+
LOG_FATAL("Assertion failed: " #x " at " __FILE__ " line %d.", \
34+
__LINE__); \
3535
abort(); \
3636
} \
3737
} while (0)
@@ -40,10 +40,9 @@ extern "C" {
4040
long X = (x); \
4141
long Y = (y); \
4242
if (X == Y) { \
43-
fprintf(stderr, \
44-
"Assertion failed: " #x " != " #y \
45-
", both are %ld, at " __FILE__ " line %d.\n", \
46-
X, __LINE__); \
43+
LOG_FATAL("Assertion failed: " #x " != " #y \
44+
", both are %ld, at " __FILE__ " line %d.", \
45+
X, __LINE__); \
4746
abort(); \
4847
} \
4948
} while (0)
@@ -52,8 +51,7 @@ extern "C" {
5251
#define UMF_CHECK(condition, errorStatus) \
5352
do { \
5453
if (!(condition)) { \
55-
fprintf(stderr, "UMF check failed: " #condition " in %s\n", \
56-
__func__); \
54+
LOG_FATAL("UMF check failed: " #condition " in %s", __func__); \
5755
return errorStatus; \
5856
} \
5957
} while (0)

‎src/utils/utils_log.c

Lines changed: 101 additions & 21 deletions
Original file line numberDiff line numberDiff line change
@@ -20,6 +20,7 @@
2020
#include <pthread.h>
2121
#endif
2222

23+
#include <errno.h>
2324
#include <stdarg.h>
2425
#include <stdio.h>
2526
#include <string.h>
@@ -54,14 +55,17 @@ static const char *level_to_str(util_log_level_t l) {
5455
return "INFO";
5556
case LOG_WARNING:
5657
return "WARN";
58+
case LOG_FATAL:
59+
return "FATAL";
5760
default:
5861
ASSERT(0);
5962
return "";
6063
}
6164
}
6265

63-
void util_log(util_log_level_t level, const char *format, ...) {
64-
if (!loggerConfig.output) {
66+
static void util_log_internal(util_log_level_t level, int perror,
67+
const char *format, va_list args) {
68+
if (!loggerConfig.output && level != LOG_FATAL) {
6569
return; //logger not enabled
6670
}
6771
if (level < loggerConfig.level) {
@@ -82,17 +86,73 @@ void util_log(util_log_level_t level, const char *format, ...) {
8286
#endif
8387

8488
char buffer[LOG_MAX];
85-
va_list args;
86-
va_start(args, format);
87-
int ret = vsnprintf(buffer, sizeof(buffer), format, args);
88-
const char *overflow = "";
89-
if (ret >= (intptr_t)sizeof(buffer)) {
89+
char *b_pos = buffer;
90+
int b_size = sizeof(buffer);
91+
92+
int tmp = vsnprintf(buffer, sizeof(buffer), format, args);
93+
ASSERT(tmp > 0);
94+
95+
b_pos += (int)tmp;
96+
b_size -= (int)tmp;
97+
98+
const char *postfix = "";
99+
100+
if (perror) {
101+
if (b_size > 2) {
102+
strncat(b_pos, ": ", b_size);
103+
b_pos += 2;
104+
b_size -= 2;
105+
#if defined(_WIN32)
106+
char err[80]; // max size according to msdn
107+
if (strerror_s(err, sizeof(err), errno)) {
108+
*err = '\0';
109+
postfix = "[strerror_s failed]";
110+
}
111+
#elif defined(__APPLE__)
112+
char err[1024]; // max size according to manpage.
113+
int saveno = errno;
114+
errno = 0;
115+
if (strerror_r(saveno, err, sizeof(err))) {
116+
/* should never happen */
117+
*err = '\0';
118+
postfix = "[strerror_r failed]";
119+
}
120+
121+
if (errno == ERANGE) {
122+
postfix = "[truncated...]";
123+
}
124+
errno = saveno;
125+
#else
126+
char err_buff[1024]; // max size according to manpage.
127+
int saveno = errno;
128+
errno = 0;
129+
char *err = strerror_r(saveno, err_buff, sizeof(err_buff));
130+
if (errno == ERANGE) {
131+
postfix = "[truncated...]";
132+
}
133+
errno = saveno;
134+
#endif
135+
strncpy(b_pos, err, b_size);
136+
size_t err_size = strlen(err);
137+
b_pos += err_size;
138+
b_size -= (int)err_size;
139+
if (b_size <= 0) {
140+
buffer[LOG_MAX - 1] =
141+
'\0'; //strncpy do not add \0 in case of overflow
142+
}
143+
} else {
144+
postfix = "[truncated...]";
145+
}
146+
}
147+
148+
if (b_size <= 0) {
90149
//TODO: alloc bigger buffer with base alloc
91-
overflow = "[truncated...]";
150+
postfix = "[truncated...]";
92151
}
93-
va_end(args);
152+
94153
char header[LOG_HEADER];
95154
char *h_pos = header;
155+
int h_size = sizeof(header);
96156
memset(header, 0, sizeof(header));
97157

98158
if (loggerConfig.timestamp) {
@@ -104,32 +164,48 @@ void util_log(util_log_level_t level, const char *format, ...) {
104164
localtime_r(&now, &tm_info);
105165
#endif
106166

107-
ASSERT((intptr_t)sizeof(header) > (h_pos - header));
108-
h_pos += strftime(h_pos, sizeof(header) - (h_pos - header),
109-
"%Y-%m-%dT%H:%M:%S ", &tm_info);
167+
ASSERT(h_size > 0);
168+
tmp = (int)strftime(h_pos, h_size, "%Y-%m-%dT%H:%M:%S ", &tm_info);
169+
h_pos += tmp;
170+
h_size -= tmp;
110171
}
111172

112173
if (loggerConfig.pid) {
113-
ASSERT((intptr_t)sizeof(header) > (h_pos - header));
114-
h_pos += snprintf(h_pos, sizeof(header) - (h_pos - header),
115-
"PID:%-6lu TID:%-6lu ", (unsigned long)pid,
116-
(unsigned long)tid);
174+
ASSERT(h_size > 0);
175+
tmp = snprintf(h_pos, h_size, "PID:%-6lu TID:%-6lu ",
176+
(unsigned long)pid, (unsigned long)tid);
177+
h_pos += tmp;
178+
h_size -= tmp;
117179
}
118180

119181
// We take twice header size here to ensure that
120-
// we have space for log level and overflow string
182+
// we have space for log level and postfix string
121183
// otherwise -Wformat-truncation might be thrown by compiler
122184
char logLine[LOG_MAX + LOG_HEADER * 2];
123185
snprintf(logLine, sizeof(logLine), "[%s%-5s UMF] %s%s\n", header,
124-
level_to_str(level), buffer, overflow);
125-
126-
fputs(logLine, loggerConfig.output);
186+
level_to_str(level), buffer, postfix);
187+
FILE *out = loggerConfig.output ? loggerConfig.output : stderr;
188+
fputs(logLine, out);
127189

128190
if (level >= loggerConfig.flushLevel) {
129-
fflush(loggerConfig.output);
191+
fflush(out);
130192
}
131193
}
132194

195+
void util_log(util_log_level_t level, const char *format, ...) {
196+
va_list args;
197+
va_start(args, format);
198+
util_log_internal(level, 0, format, args);
199+
va_end(args);
200+
}
201+
202+
void util_plog(util_log_level_t level, const char *format, ...) {
203+
va_list args;
204+
va_start(args, format);
205+
util_log_internal(level, 1, format, args);
206+
va_end(args);
207+
}
208+
133209
static const char *bool_to_str(int b) { return b ? "yes" : "no"; }
134210

135211
void util_log_init(void) {
@@ -199,6 +275,8 @@ void util_log_init(void) {
199275
loggerConfig.level = LOG_WARNING;
200276
} else if (util_parse_var(envVar, "level:error", NULL)) {
201277
loggerConfig.level = LOG_ERROR;
278+
} else if (util_parse_var(envVar, "level:fatal", NULL)) {
279+
loggerConfig.level = LOG_FATAL;
202280
}
203281

204282
if (util_parse_var(envVar, "flush:debug", NULL)) {
@@ -209,6 +287,8 @@ void util_log_init(void) {
209287
loggerConfig.flushLevel = LOG_WARNING;
210288
} else if (util_parse_var(envVar, "flush:error", NULL)) {
211289
loggerConfig.flushLevel = LOG_ERROR;
290+
} else if (util_parse_var(envVar, "flush:fatal", NULL)) {
291+
loggerConfig.flushLevel = LOG_FATAL;
212292
}
213293

214294
LOG_INFO(

‎src/utils/utils_log.h

Lines changed: 24 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -14,19 +14,38 @@
1414
extern "C" {
1515
#endif
1616

17-
typedef enum { LOG_DEBUG, LOG_INFO, LOG_WARNING, LOG_ERROR } util_log_level_t;
17+
typedef enum {
18+
LOG_DEBUG,
19+
LOG_INFO,
20+
LOG_WARNING,
21+
LOG_ERROR,
22+
LOG_FATAL
23+
} util_log_level_t;
24+
25+
#define LOG_DEBUG(...) util_log(LOG_DEBUG, __VA_ARGS__);
26+
#define LOG_INFO(...) util_log(LOG_INFO, __VA_ARGS__);
27+
#define LOG_WARN(...) util_log(LOG_WARNING, __VA_ARGS__);
28+
#define LOG_ERR(...) util_log(LOG_ERROR, __VA_ARGS__);
29+
#define LOG_FATAL(...) util_log(LOG_FATAL, __VA_ARGS__);
30+
31+
#define LOG_PDEBUG(...) util_plog(LOG_DEBUG, __VA_ARGS__);
32+
#define LOG_PINFO(...) util_plog(LOG_INFO, __VA_ARGS__);
33+
#define LOG_PWARN(...) util_plog(LOG_WARNING, __VA_ARGS__);
34+
#define LOG_PERR(...) util_plog(LOG_ERROR, __VA_ARGS__);
35+
#define LOG_PFATAL(...) util_plog(LOG_FATAL, __VA_ARGS__);
1836

1937
void util_log_init(void);
2038
#ifdef _WIN32
2139
void util_log(util_log_level_t level, const char *format, ...);
40+
void util_plog(util_log_level_t level, const char *format, ...);
2241
#else
2342
void util_log(util_log_level_t level, const char *format, ...)
2443
__attribute__((format(printf, 2, 3)));
44+
void util_plog(util_log_level_t level, const char *format, ...)
45+
__attribute__((format(printf, 2, 3)));
2546
#endif
26-
#define LOG_DEBUG(...) util_log(LOG_DEBUG, __VA_ARGS__);
27-
#define LOG_INFO(...) util_log(LOG_INFO, __VA_ARGS__);
28-
#define LOG_WARN(...) util_log(LOG_WARNING, __VA_ARGS__);
29-
#define LOG_ERR(...) util_log(LOG_ERROR, __VA_ARGS__);
47+
48+
void util_log_init(void);
3049

3150
#ifdef __cplusplus
3251
}

0 commit comments

Comments
 (0)