@cryptotaxi247 / netdata-1 / commits / 151a6038b

Protect shared variables with log lock. (#13306)

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" ```

vkalintiris committed Jul 7, 2022 at 15:56 UTC 151a6038b63e8739bfed9d62c63165c17426a403
2 files changed +34 -11
libnetdata/log/log.c
+32 -6
@@ -681,6 +681,26 @@ int error_log_limit(int reset) {
681 return 0;
682 }
683
684 +void error_log_limit_reset(void) {
685 + log_lock();
686 +
687 + error_log_errors_per_period = error_log_errors_per_period_backup;
688 + error_log_limit(1);
689 +
690 + log_unlock();
691 +}
692 +
693 +void error_log_limit_unlimited(void) {
694 + log_lock();
695 +
696 + error_log_errors_per_period = error_log_errors_per_period_backup;
697 + error_log_limit(1);
698 +
699 + error_log_errors_per_period = ((error_log_errors_per_period_backup * 10) < 10000) ? 10000 : (error_log_errors_per_period_backup * 10);
700 +
701 + log_unlock();
702 +}
703 +
704 // ----------------------------------------------------------------------------
705 // debug log
706
@@ -712,8 +732,13 @@ void info_int( const char *file, const char *function, const unsigned long line,
732 {
733 va_list args;
734
735 + log_lock();
736 +
737 // prevent logging too much
716 - if(error_log_limit(0)) return;
738 + if (error_log_limit(0)) {
739 + log_unlock();
740 + return;
741 + }
742
743 if(error_log_syslog) {
744 va_start( args, fmt );
@@ -724,8 +749,6 @@ void info_int( const char *file, const char *function, const unsigned long line,
749 char date[LOG_DATE_LENGTH];
750 log_date(date, LOG_DATE_LENGTH);
751
727 - log_lock();
728 -
752 va_start( args, fmt );
753 #ifdef NETDATA_INTERNAL_CHECKS
754 fprintf(stderr, "%s: %s INFO : %s : (%04lu@%-20.20s:%-15.15s): ", date, program_name, netdata_thread_tag(), line, file, function);
@@ -771,8 +794,13 @@ void error_int( const char *prefix, const char *file, const char *function, cons
794
795 va_list args;
796
797 + log_lock();
798 +
799 // prevent logging too much
775 - if(error_log_limit(0)) return;
800 + if (error_log_limit(0)) {
801 + log_unlock();
802 + return;
803 + }
804
805 if(error_log_syslog) {
806 va_start( args, fmt );
@@ -783,8 +811,6 @@ void error_int( const char *prefix, const char *file, const char *function, cons
811 char date[LOG_DATE_LENGTH];
812 log_date(date, LOG_DATE_LENGTH);
813
786 - log_lock();
787 -
814 va_start( args, fmt );
815 #ifdef NETDATA_INTERNAL_CHECKS
816 fprintf(stderr, "%s: %s %-5.5s : %s : (%04lu@%-20.20s:%-15.15s): ", date, program_name, prefix, netdata_thread_tag(), line, file, function);
libnetdata/log/log.h
+2 -5
@@ -74,11 +74,8 @@ extern void reopen_all_log_files();
74
75 static inline void debug_dummy(void) {}
76
77 -#define error_log_limit_reset() do { error_log_errors_per_period = error_log_errors_per_period_backup; error_log_limit(1); } while(0)
78 -#define error_log_limit_unlimited() do { \
79 - error_log_limit_reset(); \
80 - error_log_errors_per_period = ((error_log_errors_per_period_backup * 10) < 10000) ? 10000 : (error_log_errors_per_period_backup * 10); \
81 - } while(0)
77 +void error_log_limit_reset(void);
78 +void error_log_limit_unlimited(void);
79
80 #ifdef NETDATA_INTERNAL_CHECKS
81 #define debug(type, args...) do { if(unlikely(debug_flags & type)) debug_int(__FILE__, __FUNCTION__, __LINE__, ##args); } while(0)