Fix memory leak caused by saving stats counter to persist config #2279

lbudai · 2018-09-14T14:22:54Z

Leak:

start syslog-ng with a simple config

@version: 3.17

options {
  time_reopen(5);
  stats-level(3);
};

source s_file {
  file("/tmp/input-logs.txt" log-iw-size(10));
};

destination d_file {
  file("/tmp/output-logs.txt");
};

destination d_net {
 network("localhost" port(5555) 
        );
};

log {
  source (s_file);
  destination (d_net);
};

reload syslog-ng
Each time a memory-usage counter is written into a variable that is dynamically allocated on the heap and not freeing up (on my machine 8 bytes are leaked for each reload).

Sometimes we need to express that something is equal to TRUE (typically in a unit test). In this cases TRUE is a strict value, 1. Signed-off-by: Laszlo Budai <[email protected]>

Signed-off-by: Laszlo Budai <[email protected]>

lbudai · 2018-09-14T15:59:52Z

kira link : https://ci.syslog-ng.com/jenkins/view/all/job/kira-test-compile-automake-run-testdb/1264/

kira-syslogng · 2018-09-14T16:50:32Z

Build FAILURE

kira-syslogng · 2018-09-14T17:44:08Z

Build FAILURE

lbudai · 2018-09-15T17:41:21Z

hmmm... the reason why Travis/Kira is timeouted is that I have a mutex in a locked state.
The reason of this is that one of the the asserts has failed before the unlock is called... (in c++ this is not an issue as one could use RAII and scope lock). Using cr_expect instead of cr_assert solves this blocking issue.

Signed-off-by: Laszlo Budai <[email protected]>

As set is just an assignment, it breaks SRP. This is not the only reason of this separation: if we have a setter and an init method, then it is possible to init the counter only when it is first registered to stats. Signed-off-by: Laszlo Budai <[email protected]>

… time Signed-off-by: Laszlo Budai <[email protected]>

lbudai · 2018-09-15T17:43:37Z

...and the failing assert was a mistake by myself... now I think it is fixed

kira-syslogng · 2018-09-15T18:25:12Z

Build SUCCESS

… 1st time Signed-off-by: Laszlo Budai <[email protected]>

The way how we are saving the values caused a memory leak. Of course it could be fixed, but there is conceptual issue with this approach: the stats-counters can be re-used after reload (as they are not removed from the global stats-counter table). Signed-off-by: Laszlo Budai <[email protected]>

kira-syslogng · 2018-09-17T13:26:08Z

Build SUCCESS

bazsi · 2018-09-17T15:07:34Z

I would depend on this patch in my threaded logthrdestdriver work, as it wasn't easy to resolve the same
in a multi-worker environment.

So this is not just a minor leak, but helps me a big deal. I'll try to review this tonight.

Thanks for fixing this!

lbudai · 2018-09-17T16:07:59Z

@bazsi: there are some 'ugly' parts in the PR: I didn't want to lock/unlock the stats twice, so I extended the register_stats methods with assigning the counters to the LogQueue.

bazsi · 2018-09-17T19:24:24Z

I like the approach in general, I might give some thought to naming. It is not immediately clear, why the existance of a counter should cause something to be initialized or not.

What if we delegated the stats registration to LogQueue and took care of this initialization there?

e.g. instead of log_queue_set_counters(), we would have

log_queue_register_stats() that would get the initialized StatsClusterKey as argument. This way, the
LogQueue could check the existance of the counters internally and do the initialization only the first time. That logic would then not infect 3 call sites: LogThreadedDestDriver, AFSql (which should be the former), and LogWriter.

What do you think?

OTOH, the patch by itself resolves an issue I am facing in the multithreaded driver, so I'd love to see this go in as soon as possible.

lbudai · 2018-09-17T20:08:00Z

I’m going to check it on tomorrow and move it to LogQueue.
(when a counter exists, the queue resets the counter... this is what I called init, but maybe reset would be a better name ).

lbudai · 2018-09-18T11:28:33Z

@bazsi: in case of dropped counter the ownership is at logwriter/logthrdstdrv/afsql (and I would not touch that part), but the other two counters are owned by the LogQueue, so I'll modify the code.

lbudai · 2018-09-18T15:16:08Z

@bazsi: I think (I'm sure...), later the dropped counter can be removed from the LogQueue, so until that I'd keep this log_queue_set_dropped_counter method.
Thanks for suggesting this change, it's better now (IMHO).

note: in afsql module the stats counter registration point changed, but I think it still works.

kira-syslogng · 2018-09-18T15:28:36Z

Build SUCCESS

Concept: queued_messages and memory_usage counters are used only by the LogQueue, so they can be owned by the LogQueue instances. The dropped_messages counter is owned by the LogWriter/LogThrDestDriver, or AFSqlDestDriver instances, so it won't be registered by this new method. Signed-off-by: Laszlo Budai <[email protected]>

Signed-off-by: Laszlo Budai <[email protected]>

kira-syslogng · 2018-09-18T16:25:22Z

Build SUCCESS

lbudai · 2018-09-18T16:51:47Z

@kira-syslogng retest this please

kira-syslogng · 2018-09-18T17:24:52Z

Build SUCCESS

lbudai · 2018-09-19T08:14:04Z

@kira-syslogng Do perftest

kira-syslogng · 2018-09-19T08:54:44Z

Build SUCCESS

furiel · 2018-09-20T06:40:58Z

logthrdestdrv: init queue counters only when registered for the first time
and
logqueue: do not initialize counters in set method
patches are reverted in the end, (maybe more?). From these, the first one is especially hard to understand and validate by review. Can you rebuild the patchset without such reverts? That would help the review a lot.

furiel · 2018-09-20T06:41:57Z

lib/stats/stats-cluster.c

@@ -244,15 +257,15 @@ stats_cluster_is_alive(StatsCluster *self, gint type)
 {
  g_assert(type < self->counter_group.capacity);

-  return ((1<<type) & self->live_mask);
+  return ((1<<type) & self->live_mask) == (1 << type);


For me: return !!(1<<type) & self->live_mask) would be more readable

furiel · 2018-09-20T06:44:23Z

lib/logqueue.c

+
+  stats_register_counter(stats_level, sc_key, SC_TYPE_QUEUED, &self->queued_messages);
+
+  if (stats_check_level(STATS_LEVEL1))


Why do we need this check? Can we just omit?

No, we cannot: if we wouldn't check this than in case of stats level 0 the need_to_reset_counters would be set to FALSE which would ended in an unitialized queued counter.
(note that stats_counter_set handles the case when NULL ptr passed to it as counter).

furiel · 2018-09-20T06:45:09Z

lib/logqueue.c

+  stats_register_counter(stats_level, sc_key, SC_TYPE_QUEUED, &self->queued_messages);
+
+  if (stats_check_level(STATS_LEVEL1))
+    need_to_reset_counters = !stats_contains_counter(sc_key, SC_TYPE_MEMORY_USAGE);


We could go this check into _reset_counters.

No, it couldn't.
Why?
Because at that point the counter is registered... so it would return TRUE (of course when stats-level is >= 1).

furiel · 2018-09-20T07:03:43Z

lib/stats/stats-cluster.c

@@ -208,6 +208,19 @@ stats_cluster_track_counter(StatsCluster *self, gint type)
  return &self->counter_group.counters[type];
 }

+StatsCounterItem *
+stats_cluster_get_counter(StatsCluster *self, gint type)


In the end, this function is not used. Can you drop the patch?

I want to keep it as I’ll need it later.

lbudai · 2018-09-20T07:14:00Z

@furiel: thanks for the review notes.

I’ll check them but... but I’m not sure I want to rebuild the whole patchset. It is true that I’m blocking on this PR, but for me it is just a marginal issue what I had to solve and I want to focus on other things now.

furiel · 2018-09-20T07:25:52Z

lib/logwriter.c

@@ -1349,17 +1345,11 @@ _register_counters(LogWriter *self)
      stats_register_counter(self->options->stats_level, &sc_key, SC_TYPE_SUPPRESSED, &self->suppressed_messages);
    stats_register_counter(self->options->stats_level, &sc_key, SC_TYPE_DROPPED, &self->dropped_messages);
    stats_register_counter(self->options->stats_level, &sc_key, SC_TYPE_PROCESSED, &self->processed_messages);


These are also common counters. Cant we move these under _register_common_counters?

What do you mean under _common_counters?
_common_counter is at LogQueue implementation, a private (static) method for that, and has nothing to do with LogWriter.

furiel

Thanks, all my questions are answered. Other than that, I had a few optional comments, nothing critical. imho this is ready to go in.

lbudai · 2018-09-20T07:46:16Z

I can do some modifications...

modify the predicate function (return !!x)
modifiy the code and use the stats_cluster_get_counter method

but only in if the PR get merged on today.

I still don't want to rebuild the whole patchset.
I think, the first version could be also merged, but totally agreed with Bazsi that this naming is not the best. Changing the LogQueue interface is not part of the original problem, but a make-things-better changset, or, in other words: it could be part of a separate PR... but I'd not open another PR for it.

lbudai · 2018-09-20T07:49:00Z

@furiel: you were too fast :)
then I'm going to open a PR for addressing those two.

stats/stats-cluster: predicate function should return real bool values

fb58aa5

Sometimes we need to express that something is equal to TRUE (typically in a unit test). In this cases TRUE is a strict value, 1. Signed-off-by: Laszlo Budai <[email protected]>

lbudai requested a review from furiel September 14, 2018 14:22

lbudai changed the title ~~Fix memory leak caused by saving stats counter to persis config~~ Fix memory leak caused by saving stats counter to persist config Sep 14, 2018

stats/stats-cluster: add method for getting a ptr to a StatsCounterItem

273a296

Signed-off-by: Laszlo Budai <[email protected]>

lbudai force-pushed the fix-memory-leak-caused-by-saving-stats-counter-to-persis-config branch 3 times, most recently from 91b2254 to 531c26e Compare September 14, 2018 15:05

lbudai added 3 commits September 15, 2018 19:42

stats/stats-registry: add contains_counter and get_counter methods

8f3747b

Signed-off-by: Laszlo Budai <[email protected]>

logthrdestdrv: init queue counters only when registered for the first…

9a0daa8

… time Signed-off-by: Laszlo Budai <[email protected]>

lbudai force-pushed the fix-memory-leak-caused-by-saving-stats-counter-to-persis-config branch from 531c26e to 74d74cd Compare September 15, 2018 17:42

lbudai added 3 commits September 17, 2018 14:56

afsql: init queue counters only when mem_usage_ctr registered for the…

b929cb8

… 1st time Signed-off-by: Laszlo Budai <[email protected]>

logwriter: init queue ctrs only when mem_usage_ctr registered for the…

b05dfc5

… 1st time Signed-off-by: Laszlo Budai <[email protected]>

lbudai force-pushed the fix-memory-leak-caused-by-saving-stats-counter-to-persis-config branch from 74d74cd to 10c11d7 Compare September 17, 2018 12:57

lbudai added this to the OSE 3.18 milestone Sep 17, 2018

lbudai force-pushed the fix-memory-leak-caused-by-saving-stats-counter-to-persis-config branch from 53e2c00 to 145da81 Compare September 18, 2018 15:10

lbudai added 5 commits September 18, 2018 18:23

logwriter: remove stats counters owned by LogQueue

30c5e1d

Signed-off-by: Laszlo Budai <[email protected]>

logthrdestdrv: remove stats counters owned by LogQueue

1dffd94

Signed-off-by: Laszlo Budai <[email protected]>

afsql: remove stats counters owned by LogQueue

bc885d2

Signed-off-by: Laszlo Budai <[email protected]>

logqueue: remove set_counters/init_counters method

6504f33

Signed-off-by: Laszlo Budai <[email protected]>

lbudai force-pushed the fix-memory-leak-caused-by-saving-stats-counter-to-persis-config branch from 145da81 to 6504f33 Compare September 18, 2018 16:23

bazsi mentioned this pull request Sep 18, 2018

Http multi threading #2291

Merged

Kokan approved these changes Sep 19, 2018

View reviewed changes

gaborznagy requested a review from szemere September 19, 2018 08:42

furiel reviewed Sep 20, 2018

View reviewed changes

furiel approved these changes Sep 20, 2018

View reviewed changes

furiel merged commit cd56c32 into syslog-ng:master Sep 20, 2018

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fix memory leak caused by saving stats counter to persist config #2279

Fix memory leak caused by saving stats counter to persist config #2279

lbudai commented Sep 14, 2018 •

edited

Loading

lbudai commented Sep 14, 2018

kira-syslogng commented Sep 14, 2018

kira-syslogng commented Sep 14, 2018

lbudai commented Sep 15, 2018

lbudai commented Sep 15, 2018

kira-syslogng commented Sep 15, 2018

kira-syslogng commented Sep 17, 2018

bazsi commented Sep 17, 2018

lbudai commented Sep 17, 2018

bazsi commented Sep 17, 2018

lbudai commented Sep 17, 2018

lbudai commented Sep 18, 2018

lbudai commented Sep 18, 2018

kira-syslogng commented Sep 18, 2018

kira-syslogng commented Sep 18, 2018

lbudai commented Sep 18, 2018

kira-syslogng commented Sep 18, 2018

lbudai commented Sep 19, 2018

kira-syslogng commented Sep 19, 2018

furiel commented Sep 20, 2018

furiel Sep 20, 2018

furiel Sep 20, 2018

lbudai Sep 20, 2018

furiel Sep 20, 2018

lbudai Sep 20, 2018

furiel Sep 20, 2018

lbudai Sep 20, 2018

lbudai commented Sep 20, 2018

furiel Sep 20, 2018

lbudai Sep 20, 2018

furiel left a comment

lbudai commented Sep 20, 2018

lbudai commented Sep 20, 2018


		stats_register_counter(stats_level, sc_key, SC_TYPE_QUEUED, &self->queued_messages);

		if (stats_check_level(STATS_LEVEL1))

Fix memory leak caused by saving stats counter to persist config #2279

Fix memory leak caused by saving stats counter to persist config #2279

Conversation

lbudai commented Sep 14, 2018 • edited Loading

lbudai commented Sep 14, 2018

kira-syslogng commented Sep 14, 2018

kira-syslogng commented Sep 14, 2018

lbudai commented Sep 15, 2018

lbudai commented Sep 15, 2018

kira-syslogng commented Sep 15, 2018

kira-syslogng commented Sep 17, 2018

bazsi commented Sep 17, 2018

lbudai commented Sep 17, 2018

bazsi commented Sep 17, 2018

lbudai commented Sep 17, 2018

lbudai commented Sep 18, 2018

lbudai commented Sep 18, 2018

kira-syslogng commented Sep 18, 2018

kira-syslogng commented Sep 18, 2018

lbudai commented Sep 18, 2018

kira-syslogng commented Sep 18, 2018

lbudai commented Sep 19, 2018

kira-syslogng commented Sep 19, 2018

furiel commented Sep 20, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

lbudai commented Sep 20, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

furiel left a comment

Choose a reason for hiding this comment

lbudai commented Sep 20, 2018

lbudai commented Sep 20, 2018

lbudai commented Sep 14, 2018 •

edited

Loading