[dev.icinga.com #2244] segfaults with event_profiling_enabled=1 => deprecate feature, does-not-work

[icinga-migration]

This issue has been migrated from Redmine: https://dev.icinga.com/issues/2244

Created by formorer on 2012-01-04 12:24:57 +00:00

Assignee: mfriedrich
Status: Resolved (closed on 2013-06-22 18:35:49 +00:00)
Target Version: 1.10
Last Update: 2013-06-22 18:35:49 +00:00 (in Redmine)

Icinga Version: 1.6.1
OS Version: Debian Wheezy

---

Icinga segfaults with event profiling enabled. Here are the steps
to reproduce the problem:

• setup blank Wheezy test system
• aptitude install icinga
• applied the config changes from icinga.cfg.diff
  (- event_profiling_enabled=1 on its own would suffice for triggering)
• /etc/init.d/icinga restart
• wait 10 seconds
• Segfault

This has been tested against 1.6.1. Attached are a number of files:

• /var/log/icinga/icinga.log attached: segfault after 10 seconds
• /var/log/icinga/icinga.debug attached
• icinga last tries to write status data to a temp file
• /var/cache/icinga/icinga.tmpm6C2OC attached
• apparently some profiling data wrongly leaks into this file
• icinga.cfg.diff - the config diff to reproduce the segfault

See Debian Bug #614356 for more information.

Attachments

• icinga.log formorer - 2012-01-04 12:24:58 +00:00
• icinga.debug formorer - 2012-01-04 12:24:58 +00:00
• icinga.tmpm6C2OC formorer - 2012-01-04 12:24:58 +00:00
• icinga.cfg.diff formorer - 2012-01-04 12:24:58 +00:00

Changesets

2013-06-22 18:31:00 +00:00 by (unknown) 65876df

core: remove event_profiling_enabled functionality causing core dumps

since noone ever cared to even fix it, it's now deprecated and removed
from the core. thanks for nothing.

whatthecommit:

sometimes you just herp the derp so hard it herpderps

fixes #2244

2013-06-30 15:13:14 +00:00 by (unknown) b8ec7f4

core/ido: generic deprecation warning

refs #2244
refs #4363

---

Relations:

• relates #312
• blocks #2244

[icinga-migration]

Updated by mfriedrich on 2012-01-27 20:41:40 +00:00

• Status changed from New to Assigned
• Assigned to set to mfriedrich

[icinga-migration]

Updated by mfriedrich on 2012-02-05 14:28:35 +00:00

gdb tells more.

(gdb) bt

#0  0x00007ffff73f80f8 in _IO_vfprintf_internal (s=0x72fb40, format=0x48dc2d "\tPROFILE_COUNTER_%s=%d\n", ap=0x7fffffffe1f0) at vfprintf.c:1620
#1  0x00007ffff74011e8 in __fprintf (stream=0x20, format=0x48dc3e "%s=%d\n") at fprintf.c:33
#2  0x000000000044721d in profiler_output (fp=0x72fb40) at profiler.c:182
#3  0x0000000000474c3f in xsddefault_save_status_data () at ../xdata/xsddefault.c:472
#4  0x0000000000473146 in update_all_status_data () at ../common/statusdata.c:95
#5  0x0000000000430920 in handle_timed_event (event=0x6d4f50) at events.c:1528
#6  0x0000000000431159 in event_execution_loop () at events.c:1173
#7  0x00000000004158da in main (argc=, argv=, env=) at icinga.c:883

[icinga-migration]

Updated by mfriedrich on 2012-02-05 15:49:28 +00:00

the segfault is somewhere in between the logic on filling the profiler array with "unknown" events (not those actually added) in order to prevent the array counter being wrong, accessing an unknown place.
as well as the actual output receives profiler[c].name which does not hold a NULL string, but \0 terminated string literal running into a sigsegv.

a possible diff for that does not work yet. might be better to rewrite the algorithm of holding and adding events for the profiler to a (doubly) linked list instead of the array itsself, dynamically adding only those events which are initialized in profiler_init().

either way, profiler[c] as struct needs a fix then.

diff --git a/base/profiler.c b/base/profiler.c
index b550050..1704a34 100644
--- a/base/profiler.c
+++ b/base/profiler.c
@@ -155,16 +155,16 @@ void profiler_rename(int p, char * name) {
 void profiler_update(int event, struct timeval start) {
        static int counter;
        struct timeval end;
+       char * temp_name;
        gettimeofday(&end, NULL);

        //We do this to prevent segfaulting since it could be a we end up with a sparse array
        //It's ugly but it saves having to try and know everything that may be profiled in advance.
        //It's only slow the first time a new event type is profiled.
        while (event > profiler_item_count) {
-               char name[20];
-               memset(name, '\0', 20);
-               sprintf(name, "UNKNOWN_%d", counter++);
-               profiler_add(event, (char*)&name);
+               asprintf(&temp_name, "UNKNOWN_%d", counter++);
+               profiler_add(event, temp_name);
+               my_free(temp_name);
        }

        if (profiler[event].state) {
@@ -174,13 +174,22 @@ void profiler_update(int event, struct timeval start) {
 }

 void profiler_output(FILE* fp) {
-       int c;
+       int c = 0;
+       char * name = NULL;
+       int counter;
+       double elapsed;
+
        for (c = 0; c < profiler_item_count; c++) {
                //Only print those that are turned on.
                if (profiler[c].state) {
                        if (profiler[c].name) {
-                               fprintf(fp, "\tPROFILE_COUNTER_%s=%d\n", profiler[c].name, profiler[c].counter);
-                               fprintf(fp, "\tPROFILE_ELAPSED_%s=%f\n", profiler[c].name, profiler[c].elapsed);
+                               name = profiler[c].name;
+                               counter = profiler[c].counter;
+                               elapsed = profiler[c].elapsed;
+                               fprintf(fp, "\tPROFILE_COUNTER_%s=%d\n", name, counter);
+                               fprintf(fp, "\tPROFILE_ELAPSED_%s=%f\n", name, elapsed);
+                               //fprintf(fp, "\tPROFILE_COUNTER_%s=%d\n", profiler[c].name, profiler[c].counter);
+                               //fprintf(fp, "\tPROFILE_ELAPSED_%s=%f\n", profiler[c].name, profiler[c].elapsed);
                        }
                }
        }

[icinga-migration]

Updated by mfriedrich on 2012-07-20 18:21:44 +00:00

• Assigned to changed from mfriedrich to h4ck3rm1k3

[icinga-migration]

Updated by mfriedrich on 2012-08-22 16:31:45 +00:00

• Icinga Version set to 1
• OS Version set to Debian Wheezy

status?

[icinga-migration]

Updated by mfriedrich on 2013-04-10 19:37:53 +00:00

status?

[icinga-migration]

Updated by mfriedrich on 2013-05-05 18:05:23 +00:00

since this still happens, and noone seems to care anyways, i vote for removal of this feature, solving this bug in an unpleasant way.

[icinga-migration]

Updated by mfriedrich on 2013-05-05 18:09:04 +00:00

• Subject changed from segfaults with event_profiling_enabled=1 to segfaults with event_profiling_enabled=1 => deprecate feature, does-not-work
• Assigned to changed from h4ck3rm1k3 to mfriedrich
• Priority changed from Normal to Low
• Target Version set to 1.10

moved for deprecation in 1.10

[icinga-migration]

Updated by RangerNS on 2013-05-28 14:07:44 +00:00

I also ran into this problem, first with a CentOS 1.8.4 RPM, and then a fresh build of 1.9.1. I can't comment on the proposed fix, only saying that this happens in the wild. I had no specific desire for event_profiling_enabled=1, just exploring, so I'd be happy with this broken feature being removed.

[icinga-migration]

Updated by mfriedrich on 2013-05-29 10:48:24 +00:00

I was not able to contact the original author of that patch for some years now, so it's best to just remove it. Seems it worked a while back, but noone could make much use of it either. Not even helped during development.

[icinga-migration]

Updated by Anonymous on 2013-06-22 18:35:49 +00:00

• Status changed from Assigned to Resolved
• Done % changed from 0 to 100

Applied in changeset 65876df.