Filter called more than once...

[Krishna R]

Thanks as usual Havoc.

Yes, your answers are inline with what i had understood. I do have
dbus_threads_init_default()in my code.

Unfortunately it does not happen in my test code and it is difficult to
reproduce. I got a log with verbose turned on. The code is basically calling
read_write_dispatch and check for dispatch_status. The signal sent is
MyModN. Will see if i can reproduce it in a sample. Attached log below, not
sure if it is helpful. Thanks.

536:   UNLOCK: protected_change_watch
536:   LOCK: protected_change_watch
536:  read 181 bytes
536: have 181 bytes, need body 37 + header 144 = 181
536: validating body from pos 0 len 181 sig 'yyyyuua(yv)'
536: p = 0x287ea end = 0x28825 claimed_len 4
536: initially caching field 1
536: initially caching field 2
536: initially caching field 3
536: initially caching field 8
536: initially caching field 7
536: validating body from pos 144 len 37 sig 'uuay'
536: Loaded message 0x16498
536: queueing received message 0x16498
536: Message 0x16498 (4 /com/MyMod/Notify com.MyMod.Notify.Send MyModN
'uuay' reply to 0) added to incoming queue 0x15f30, 1 incoming
536: check_read_watch: fd = 13
536:   setting read watch enabled = 1
536:   UNLOCK: protected_change_watch
536:   LOCK: protected_change_watch
536: check_write_watch(): needed = 0 on connection 0x15f30 watch 0x15c00 fd
= 13 outgoing messages exist 0
536:   UNLOCK: protected_change_watch
536:   LOCK: protected_change_watch
536:  ... leaving do_iteration()
536: _dbus_transport_do_iteration end
536: _dbus_connection_release_io_path locking io_path_mutex
536: _dbus_connection_release_io_path start connection->io_path_acquired = 1
536: _dbus_connection_release_io_path unlocking io_path_mutex
536: _dbus_connection_do_iteration_unlocked end
536:   UNLOCK: _dbus_connection_read_write_dispatch
536: dbus_connection_get_dispatch_status start
536:   LOCK: dbus_connection_get_dispatch_status
536:   UNLOCK: dbus_connection_get_dispatch_status
536: dbus_connection_get_dispatch_status start
536:   LOCK: dbus_connection_get_dispatch_status
536:   UNLOCK: dbus_connection_get_dispatch_status
536: doing dispatch in _dbus_connection_read_write_dispatch
536: dbus_connection_dispatch
536:   LOCK: dbus_connection_dispatch
536:   UNLOCK: _dbus_connection_acquire_dispatch
536: _dbus_connection_acquire_dispatch locking dispatch_mutex
536: _dbus_connection_acquire_dispatch unlocking dispatch_mutex
536:   LOCK: _dbus_connection_acquire_dispatch
536: Message 0x16498 (4 /com/MyMod/Notify com.MyMod.Notify.Send MyModN
'uuay') removed from incoming queue 0x15f30, 0 incoming
536:  dispatching message 0x16498 (4 com.MyMod.Notify.Send MyModN 'uuay')
536:   UNLOCK: dbus_connection_dispatch
536:   running filter on message 0x16498
MYSIGNALHANDLER: THIS IS MY SIGNAL FUNC
536: dispatch status = complete is_connected = 1
536:   UNLOCK: dbus_connection_get_dispatch_status
536:   LOCK: _dbus_connection_read_write_dispatch
536: doing iteration in _dbus_connection_read_write_dispatch
536: _dbus_connection_do_iteration_unlocked start
536:   UNLOCK: _dbus_connection_acquire_io_path
536: _dbus_connection_acquire_io_path locking io_path_mutex
536: _dbus_connection_acquire_io_path start connection->io_path_acquired = 0
timeout = 0
536: _dbus_connection_acquire_io_path end connection->io_path_acquired = 1
we_acquired = 1
536: _dbus_connection_acquire_io_path unlocking io_path_mutex
536:   LOCK: _dbus_connection_acquire_io_path
536: Transport iteration flags 0x6 timeout 0 connected = 1
536:  iteration flags = read timeout = 0 read_watch = 0x15c28 write_watch =
0x15c00 fd = 13
536: unlock socket_do_iteration pre poll
536:   UNLOCK: _dbus_connection_unlock
536: lock socket_do_iteration post poll
536:   LOCK: _dbus_connection_lock
536: in iteration, need_read=0 need_write=0
536: check_write_watch(): needed = 0 on connection 0x15f30 watch 0x15c00 fd
= 13 outgoing messages exist 0
536:   UNLOCK: protected_change_watch
536:   LOCK: protected_change_watch
536:  ... leaving do_iteration()
536: _dbus_transport_do_iteration end
536: _dbus_connection_release_io_path locking io_path_mutex
536: _dbus_connection_release_io_path start connection->io_path_acquired = 1
536: _dbus_connection_release_io_path unlocking io_path_mutex
536: _dbus_connection_do_iteration_unlocked end
536:   UNLOCK: _dbus_connection_read_write_dispatch
536: dbus_connection_get_dispatch_status start
536:   LOCK: dbus_connection_get_dispatch_status
536: dispatch status = complete is_connected = 1
536:   UNLOCK: dbus_connection_get_dispatch_status
536:   running filter on message 0x16498
MYSIGNALHANDLER: THIS IS MY SIGNAL FUNC
536:   running filter on message 0x16498
MYSIGNALHANDLER line 585 : We got a signal we did not care about: Err 0
536:   LOCK: dbus_connection_dispatch
536:   running object path dispatch on message 0x16498 (4
com.MyMod.Notify.Send MyModN 'uuay')
536: 0 handlers in the path tree for this message
536:  considering default Introspect() handler...
536: unlock handle_default_introspect_and_unlock 629
536:   UNLOCK: _dbus_connection_unlock
536:   LOCK: dbus_connection_dispatch
536:   done dispatching 0x16498 (4 com.MyMod.Notify.Send MyModN 'uuay') on
connection 0x15f30
536:  ... done dispatching in dbus_connection_dispatch
536: _dbus_connection_release_dispatch locking dispatch_mutex
536: _dbus_connection_release_dispatch unlocking dispatch_mutex
536: dbus_connection_dispatch before final status update
536: dispatch status = complete is_connected = 1
------------------------------------------------------------------------------------------------------------------------

On 3/6/07, Havoc Pennington <hp at redhat.com> wrote:
>
>
>
> Havoc Pennington wrote:
> >> 1.  It should not call the same recv function again if  it already
> >> returned NOT_YET _HANDLED. Correct?
> >
> > Yes. The only exception I can think of is that if there's an
> > out-of-memory error during dispatch, it's possible the dispatch restarts
> > with the first handler. I'm not sure how this works offhand.
>
> To be clear, in the not-out-of-memory case it sounds like a bug if a
> handler is called twice, but you'll need to track it down at least to
> the point of providing a small compilable test case before anyone else
> is likely to make progress on it...
>
> Also,
>
> > Only dbus_shutdown() which shuts down the entire library (you must
> > free/unref any memory from libdbus that you own, prior to
> dbus_shutdown())
>
> dbus_shutdown() is entirely optional and really intended only for people
> who like to use valgrind or equivalent in the "is everything freed on
> exit" mode (vs. the "is everything reachable from the gc roots" mode).
> It's really a debugging-only thing. There is no reason to use
> dbus_shutdown() unless you enjoy pain. Also, dbus_shutdown() should
> never be used from a library, since the library can't know whether
> anyone is still using libdbus. When used, it should be at the end of
> main() after the rest of the app is shut down already.
>
> Havoc
>
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freedesktop.org/archives/dbus/attachments/20070306/f57e243e/attachment.html