Skip to content

Commit

Permalink
Protect shared variables with log lock. (netdata#13306)
Browse files Browse the repository at this point in the history
Fixes reports by helgrind:

```
==00:00:00:01.769 44512== Possible data race during read of size 8 at 0x9767B0 by thread #4
==00:00:00:01.769 44512== Locks held: none
==00:00:00:01.769 44512==    at 0x17CB56: error_log_limit (log.c:627)
==00:00:00:01.769 44512==    by 0x17CEC0: info_int (log.c:716)
==00:00:00:01.769 44512==    by 0x18949F: thread_start (threads.c:173)
==00:00:00:01.769 44512==    by 0x484A486: ??? (in /usr/libexec/valgrind/vgpreload_helgrind-amd64-linux.so)
==00:00:00:01.769 44512==    by 0x4E9CD7F: start_thread (pthread_create.c:481)
==00:00:00:01.769 44512==    by 0x532F76E: clone (clone.S:95)
==00:00:00:01.769 44512==
==00:00:00:01.769 44512== This conflicts with a previous write of size 8 by thread #3
==00:00:00:01.769 44512== Locks held: none
==00:00:00:01.769 44512==    at 0x17CB61: error_log_limit (log.c:627)
==00:00:00:01.769 44512==    by 0x17CEC0: info_int (log.c:716)
==00:00:00:01.769 44512==    by 0x18949F: thread_start (threads.c:173)
==00:00:00:01.769 44512==    by 0x484A486: ??? (in /usr/libexec/valgrind/vgpreload_helgrind-amd64-linux.so)
==00:00:00:01.769 44512==    by 0x4E9CD7F: start_thread (pthread_create.c:481)
==00:00:00:01.769 44512==    by 0x532F76E: clone (clone.S:95)
==00:00:00:01.769 44512==  Address 0x9767b0 is 0 bytes inside data symbol "counter.1"
```

```
==00:00:00:44.536 47685==  Lock at 0x976720 was first observed
==00:00:00:44.536 47685==    at 0x48477EF: ??? (in /usr/libexec/valgrind/vgpreload_helgrind-amd64-linux.so)
==00:00:00:44.536 47685==    by 0x17BBF4: __netdata_mutex_lock (locks.c:86)
==00:00:00:44.536 47685==    by 0x17C514: log_lock (log.c:471)
==00:00:00:44.536 47685==    by 0x17CEC0: info_int (log.c:715)
==00:00:00:44.536 47685==    by 0x458C9E: compute_multidb_diskspace (rrdenginelib.c:279)
==00:00:00:44.536 47685==    by 0x15B170: get_netdata_configured_variables (main.c:671)
==00:00:00:44.536 47685==    by 0x15CE6C: main (main.c:1263)
==00:00:00:44.536 47685==  Address 0x976720 is 0 bytes inside data symbol "log_mutex"
==00:00:00:44.536 47685==
==00:00:00:44.536 47685== Possible data race during write of size 8 at 0x9767A0 by thread #1
==00:00:00:44.536 47685== Locks held: none
==00:00:00:44.536 47685==    at 0x17CB39: error_log_limit (log.c:621)
==00:00:00:44.536 47685==    by 0x15E234: signals_handle (signals.c:258)
==00:00:00:44.536 47685==    by 0x15D880: main (main.c:1534)
==00:00:00:44.536 47685==
==00:00:00:44.536 47685== This conflicts with a previous read of size 8 by thread #9
==00:00:00:44.536 47685== Locks held: 1, at address 0x976720
==00:00:00:44.536 47685==    at 0x17CAA3: error_log_limit (log.c:604)
==00:00:00:44.536 47685==    by 0x17CECA: info_int (log.c:718)
==00:00:00:44.536 47685==    by 0x4624D2: rrdset_done_push (rrdpush.c:344)
==00:00:00:44.536 47685==    by 0x36190C: rrdset_done (rrdset.c:1351)
==00:00:00:44.536 47685==    by 0x1B07E7: Chart::update(unsigned long) (plugin_profile.cc:82)
==00:00:00:44.536 47685==    by 0x1B01D4: updateCharts(std::vector<Chart*, std::allocator<Chart*> >, unsigned long) (plugin_profile.cc:126)
==00:00:00:44.536 47685==    by 0x1B02AC: profile_main (plugin_profile.cc:144)
==00:00:00:44.536 47685==    by 0x1895D4: thread_start (threads.c:185)
==00:00:00:44.536 47685==  Address 0x9767a0 is 0 bytes inside data symbol "start.3"
```
  • Loading branch information
vkalintiris authored Jul 7, 2022
1 parent 473f449 commit 151a603
Show file tree
Hide file tree
Showing 2 changed files with 34 additions and 11 deletions.
38 changes: 32 additions & 6 deletions libnetdata/log/log.c
Original file line number Diff line number Diff line change
Expand Up @@ -681,6 +681,26 @@ int error_log_limit(int reset) {
return 0;
}

void error_log_limit_reset(void) {
log_lock();

error_log_errors_per_period = error_log_errors_per_period_backup;
error_log_limit(1);

log_unlock();
}

void error_log_limit_unlimited(void) {
log_lock();

error_log_errors_per_period = error_log_errors_per_period_backup;
error_log_limit(1);

error_log_errors_per_period = ((error_log_errors_per_period_backup * 10) < 10000) ? 10000 : (error_log_errors_per_period_backup * 10);

log_unlock();
}

// ----------------------------------------------------------------------------
// debug log

Expand Down Expand Up @@ -712,8 +732,13 @@ void info_int( const char *file, const char *function, const unsigned long line,
{
va_list args;

log_lock();

// prevent logging too much
if(error_log_limit(0)) return;
if (error_log_limit(0)) {
log_unlock();
return;
}

if(error_log_syslog) {
va_start( args, fmt );
Expand All @@ -724,8 +749,6 @@ void info_int( const char *file, const char *function, const unsigned long line,
char date[LOG_DATE_LENGTH];
log_date(date, LOG_DATE_LENGTH);

log_lock();

va_start( args, fmt );
#ifdef NETDATA_INTERNAL_CHECKS
fprintf(stderr, "%s: %s INFO : %s : (%04lu@%-20.20s:%-15.15s): ", date, program_name, netdata_thread_tag(), line, file, function);
Expand Down Expand Up @@ -771,8 +794,13 @@ void error_int( const char *prefix, const char *file, const char *function, cons

va_list args;

log_lock();

// prevent logging too much
if(error_log_limit(0)) return;
if (error_log_limit(0)) {
log_unlock();
return;
}

if(error_log_syslog) {
va_start( args, fmt );
Expand All @@ -783,8 +811,6 @@ void error_int( const char *prefix, const char *file, const char *function, cons
char date[LOG_DATE_LENGTH];
log_date(date, LOG_DATE_LENGTH);

log_lock();

va_start( args, fmt );
#ifdef NETDATA_INTERNAL_CHECKS
fprintf(stderr, "%s: %s %-5.5s : %s : (%04lu@%-20.20s:%-15.15s): ", date, program_name, prefix, netdata_thread_tag(), line, file, function);
Expand Down
7 changes: 2 additions & 5 deletions libnetdata/log/log.h
Original file line number Diff line number Diff line change
Expand Up @@ -74,11 +74,8 @@ extern void reopen_all_log_files();

static inline void debug_dummy(void) {}

#define error_log_limit_reset() do { error_log_errors_per_period = error_log_errors_per_period_backup; error_log_limit(1); } while(0)
#define error_log_limit_unlimited() do { \
error_log_limit_reset(); \
error_log_errors_per_period = ((error_log_errors_per_period_backup * 10) < 10000) ? 10000 : (error_log_errors_per_period_backup * 10); \
} while(0)
void error_log_limit_reset(void);
void error_log_limit_unlimited(void);

#ifdef NETDATA_INTERNAL_CHECKS
#define debug(type, args...) do { if(unlikely(debug_flags & type)) debug_int(__FILE__, __FUNCTION__, __LINE__, ##args); } while(0)
Expand Down

0 comments on commit 151a603

Please sign in to comment.