[systemd-devel] Disabled event sources / errors on sd-bus break the event loop (Looping too fast)

[Krzysztof Kotlenga]

Krzysztof Kotlenga wrote:

> I recommend the following gdb script, because it provides some
> possibly interesting output:

Slightly fixed version:
https://gist.github.com/pocek/709d8c098d632ed1f21e

The first one was incorrectly printing pending_iteration instead of
prepare_iteration field. Nothing major.

> What's going on with order in that "prepare" Prioq?

I've debugged this a bit more. Two things:

1. I think prepare_prioq_compare function is wrong: "enabled" field
should be the first one to compare.

2. Maybe I don't get something right - please enlighten me if that's the
case - but prioq_put or rather shuffle_up function is buggy. 

Let's start with prepare Prioq like this:
bus-input e=1 pri=0 pi=8 fd=12
bus-input e=1 pri=0 pi=9 fd=18 <- netcat

Now we enter some garbage in netcat:
bus-input e=1 pri=0 pi=9 fd=12
bus-input e=0 pri=0 pi=9 fd=18 <- netcat

BTW, some loop iterations later it is still OK if we have fixed the
order in prepare_prioq_compare (see 1):

bus-input e=1 pri=0 pi=10 fd=12
bus-input e=0 pri=0 pi=9 fd=18 <- netcat

Good! Now let's make another connection. We have a breakpoint in
prepare_prioq_compare.

bus-input e=1 pri=0 pi=11 fd=12
bus-input e=0 pri=0 pi=9 fd=18
(null) e=1 pri=0 pi=0 fd=19 <- new connection, it doesn't have a
                               description set yet.

Backtrace for some context (shortened):
#0  prepare_prioq_compare (a=0x81466e18, b=0x81477490) 
#1  shuffle_up (q=0x81466ee8, idx=2)
#2  prioq_put (q=0x81466ee8, data=0x81477490, idx=0x814774b8)
#3  sd_event_source_set_prepare (s=0x81477490, callback=0x80181f81 <prepare_callback>)
#4  attach_io_events (bus=0x81476d20)
#5  sd_bus_attach_event (bus=0x81476d20, event=0x8140e6e0, priority=0)
#6  bus_on_connection (s=0x81471680, fd=14, revents=1, userdata=0x8140e318)
#7  source_dispatch (s=0x81471680)
#8  sd_event_dispatch (e=0x8140e6e0)
#9  sd_event_run (e=0x8140e6e0, timeout=18446744073709551615)
#10 manager_loop (m=0x8140e318)
#11 main (argc=4, argv=0xbfb1b254)

OK, let's see what we have got here:
(gdb) p x->prepare_index
$2 = 0
(gdb) p y->prepare_index
$3 = 2

So we are comparing the new sd_event_source with the first one in the
queue. This is bad. Let's move to shuffle_up first.

(gdb) frame 1
(gdb) p k
$4 = 0

Right. So shuffle_up doesn't iterate more than once here. It has only
swapped item 0 and 2. The prepare queue looks like this now:

(null) e=1 pri=0 pi=0 fd=19
bus-input e=0 pri=0 pi=9 fd=18
bus-input e=1 pri=0 pi=11 fd=12

It doesn't look like a correct order judging by how prepare_event
(sd-event.c) works. The last bus-input above is pretty much broken
because s->prepare callback won't be called anymore.

Am I wrong to believe that it should have swapped 2 and 1, not 2 and 0?

Lennart, can you fix Prioq or correct me if I'm wrong, please?

> This has been debugged on v225, but AFAICS master has the same issues.

I'm debugging this now on v226 now.

-- 
kjk