auto-start problem in v0.50
John (J5) Palmieri
johnp at redhat.com
Tue Nov 8 07:11:52 PST 2005
Are you autostarting from the system bus? You can't do that unless you
run the system bus as root otherwise everything gets started as the
messagebus user (or dbus user on fedora).
On Tue, 2005-11-08 at 15:15 +0200, Kimmo.Hamalainen at nokia.com wrote:
> Hi,
>
> I have an interesting problem with D-BUS v0.50. A service is authenticated
> and can talk normally in the system bus if I start it manually, but if I
> try to auto-start (activate) it, the authentication fails. It seems that
> the service sends different credentials when it is auto-started. The result
> is the same whether I use DBUS_BUS_SYSTEM or DBUS_BUS_STARTER in the
> service, or whether I run the bus as 'messagebus' or as my user name.
>
> I'm porting software from v0.23, so maybe there's something additional needed
> to configuration files?
>
> Partial debug output from the daemon follows.
>
> -Kimmo
>
> ------ manual starting (succeeds): ---------
>
> 17058: Connection 0x80977f0 authentication expires in 29999 milliseconds
> 17058: Enabled expire timeout with interval 29999
> 17058: _dbus_connection_handle_watch start
> 17058: LOCK: _dbus_connection_handle_watch
> 17058: UNLOCK: _dbus_connection_acquire_io_path
> 17058: _dbus_connection_acquire_io_path locking io_path_mutex
> 17058: _dbus_connection_acquire_io_path start connection->io_path_acquired = 0 timeout = -1
> 17058: _dbus_connection_acquire_io_path end connection->io_path_acquired = 1 we_acquired = 1
> 17058: _dbus_connection_acquire_io_path unlocking io_path_mutex
> 17058: LOCK: _dbus_connection_acquire_io_path
> 17058: handling read watch 0x8097c38 flags = 1
> 17058: read credentials byte
> 17058: Credentials: pid 17876 uid 1000 gid 1000
> 17058: server auth state: waiting for input
> 17058: read 24 bytes in auth phase
> 17058: server: got command "AUTH EXTERNAL 31303030"
> 17058: server: Trying mechanism EXTERNAL
> 17058: server: data: '1000'
> 17058: server: going from state WaitingForAuth to state WaitingForBegin
> 17058: server: authenticated client with UID 1000 matching socket credentials UID 1000
> 17058: server auth state: bytes to send
> 17058: check_read_watch: fd = 7
> 17058: setting read watch enabled = 0
> 17058: UNLOCK: protected_change_watch
> 17058: LOCK: protected_change_watch
> 17058: check_write_watch(): needed = 1 on connection 0x80977f0 watch 0x8097970 fd = 7 outgoing messages exist 0
> 17058: UNLOCK: protected_change_watch
> 17058: LOCK: protected_change_watch
> 17058: do_reading: fd = 7
> 17058: _dbus_connection_release_io_path locking io_path_mutex
> 17058: _dbus_connection_release_io_path start connection->io_path_acquired = 1
> 17058: _dbus_connection_release_io_path unlocking io_path_mutex
> 17058: _dbus_connection_handle_watch middle
> 17058: dispatch status = complete is_connected = 1
>
> --------- activation (fails): -------------
>
> 18442: Credentials: pid 18576 uid 1000 gid 1000
> 18442: server auth state: waiting for input
> 18442: check_read_watch: fd = 9
> 18442: setting read watch enabled = 1
> 18442: UNLOCK: protected_change_watch
> 18442: LOCK: protected_change_watch
> 18442: check_write_watch(): needed = 0 on connection 0x809b300 watch 0x809b0d0 f
> d = 9 outgoing messages exist 0
> 18442: UNLOCK: protected_change_watch
> 18442: LOCK: protected_change_watch
> 18442: do_reading: fd = 9
> 18442: _dbus_connection_release_io_path locking io_path_mutex
> 18442: _dbus_connection_release_io_path start connection->io_path_acquired = 1
> 18442: _dbus_connection_release_io_path unlocking io_path_mutex
> 18442: _dbus_connection_handle_watch middle
> 18442: dispatch status = complete is_connected = 1
> 18442: UNLOCK: _dbus_connection_update_dispatch_status_and_unlock
> 18442: LOCK: dbus_connection_unref
> 18442: UNLOCK: dbus_connection_unref
> 18442: _dbus_connection_handle_watch end
> 18576: wrote credentials byte
> 18576: client auth state: bytes to send
> 18442: _dbus_connection_handle_watch start
> 18442: LOCK: _dbus_connection_handle_watch
> 18442: UNLOCK: _dbus_connection_acquire_io_path
> 18442: _dbus_connection_acquire_io_path locking io_path_mutex
> 18442: _dbus_connection_acquire_io_path start connection->io_path_acquired = 0 t
> imeout = -1
> 18442: _dbus_connection_acquire_io_path end connection->io_path_acquired = 1 we_
> acquired = 1
> 18442: _dbus_connection_acquire_io_path unlocking io_path_mutex
> 18442: LOCK: _dbus_connection_acquire_io_path
> 18442: handling read watch 0x809b0f8 flags = 1
> 18442: server auth state: waiting for input
> 18442: read 18 bytes in auth phase
> 18442: server: got command "AUTH EXTERNAL 30"
> 18442: server: Trying mechanism EXTERNAL
> 18442: server: data: '0'
> 18442: server: credentials uid=1000 gid=1000 do not allow uid=0 gid=4294967295
> 18442: server: Shutting down mechanism EXTERNAL
> 18442: server: going from state WaitingForAuth to state WaitingForAuth
> 18442: server auth state: bytes to send
> 18442: check_read_watch: fd = 9
> 18442: setting read watch enabled = 0
> 18442: UNLOCK: protected_change_watch
> 18442: LOCK: protected_change_watch
> 18442: check_write_watch(): needed = 1 on connection 0x809b300 watch 0x809b0d0 f
> d = 9 outgoing messages exist 0
> 18442: UNLOCK: protected_change_watch
> 18442: LOCK: protected_change_watch
> 18442: do_reading: fd = 9
> 18442: _dbus_connection_release_io_path locking io_path_mutex
> 18442: _dbus_connection_release_io_path start connection->io_path_acquired = 1
> 18442: _dbus_connection_release_io_path unlocking io_path_mutex
> 18442: _dbus_connection_handle_watch middle
> 18442: dispatch status = complete is_connected = 1
> 18442: UNLOCK: _dbus_connection_update_dispatch_status_and_unlock
> 18442: LOCK: dbus_connection_unref
> 18442: UNLOCK: dbus_connection_unref
> 18442: _dbus_connection_handle_watch end
> 18442: _dbus_connection_handle_watch start
> 18442: LOCK: _dbus_connection_handle_watch
> 18442: UNLOCK: _dbus_connection_acquire_io_path
> 18442: _dbus_connection_acquire_io_path locking io_path_mutex
> 18442: _dbus_connection_acquire_io_path start connection->io_path_acquired = 0 t
> imeout = -1
> 18442: _dbus_connection_acquire_io_path end connection->io_path_acquired = 1 we_
> acquired = 1
> 18442: _dbus_connection_acquire_io_path unlocking io_path_mutex
> 18442: LOCK: _dbus_connection_acquire_io_path
> 18442: handling write watch, have_outgoing_messages = 0
> 18442: server auth state: bytes to send
> 18442: server: Sent 36 bytes of: REJECTED EXTERNAL DBUS_COOKIE_SHA1
>
> 18442: server auth state: waiting for input
> 18442: check_read_watch: fd = 9
> 18442: setting read watch enabled = 1
> 18442: UNLOCK: protected_change_watch
> 18442: LOCK: protected_change_watch
> 18442: check_write_watch(): needed = 0 on connection 0x809b300 watch 0x809b0d0 f
> d = 9 outgoing messages exist 0
> 18442: UNLOCK: protected_change_watch
> 18442: LOCK: protected_change_watch
> 18442: Not authenticated, not writing anything
> 18442: check_write_watch(): needed = 0 on connection 0x809b300 watch 0x809b0d0 f
> d = 9 outgoing messages exist 0
> 18442: UNLOCK: protected_change_watch
> 18442: LOCK: protected_change_watch
> 18442: _dbus_connection_release_io_path locking io_path_mutex
> 18442: _dbus_connection_release_io_path start connection->io_path_acquired = 1
> 18442: _dbus_connection_release_io_path unlocking io_path_mutex
> 18442: _dbus_connection_handle_watch middle
> 18442: dispatch status = complete is_connected = 1
> 18442: UNLOCK: _dbus_connection_update_dispatch_status_and_unlock
> 18442: LOCK: dbus_connection_unref
> 18442: UNLOCK: dbus_connection_unref
> 18442: _dbus_connection_handle_watch end
> 18576: client: Sent 18 bytes of: AUTH EXTERNAL 30
>
> 18576: client auth state: waiting for input
> 18576: check_read_watch: fd = 3
> 18576: setting read watch enabled = 1
> 18576: UNLOCK: protected_change_watch
> 18576: LOCK: protected_change_watch
> 18576: check_write_watch(): needed = 0 on connection 0x804b5f8 watch 0x804b298 f
> d = 3 outgoing messages exist 1
> 18576: UNLOCK: protected_change_watch
> 18576: LOCK: protected_change_watch
> 18576: Not authenticated, not writing anything
> 18576: check_write_watch(): needed = 0 on connection 0x804b5f8 watch 0x804b298 f
> d = 3 outgoing messages exist 1
> 18576: UNLOCK: protected_change_watch
> 18576: LOCK: protected_change_watch
> 18576: ... leaving do_iteration()
> 18576: _dbus_transport_do_iteration end
> 18576: _dbus_connection_release_io_path locking io_path_mutex
> 18576: _dbus_connection_release_io_path start connection->io_path_acquired = 1
> 18576: _dbus_connection_release_io_path unlocking io_path_mutex
> 18576: _dbus_connection_do_iteration_unlocked end
> 18576: dbus_connection_send_with_reply middle
> 18576: dispatch status = complete is_connected = 1
> 18576: UNLOCK: _dbus_connection_update_dispatch_status_and_unlock
> 18576: LOCK: dbus_connection_unref
> 18576: UNLOCK: dbus_connection_unref
> 18576: LOCK: dbus_connection_flush
> 18576: doing iteration in dbus_connection_flush
> 18576: _dbus_connection_do_iteration_unlocked start
> 18576: UNLOCK: _dbus_connection_acquire_io_path
> 18576: _dbus_connection_acquire_io_path locking io_path_mutex
> 18576: _dbus_connection_acquire_io_path start connection->io_path_acquired = 0 t
> imeout = -1
> 18576: _dbus_connection_acquire_io_path end connection->io_path_acquired = 1 we_
> acquired = 1
> 18576: _dbus_connection_acquire_io_path unlocking io_path_mutex
> 18576: LOCK: _dbus_connection_acquire_io_path
> 18576: Transport iteration flags 0x7 timeout -1 connected = 1
> 18576: iteration flags = readwrite timeout = -1 read_watch = 0x804b2c0 write_wa
> tch = 0x804b298 fd = 3
> 18576: unlock unix_do_iteration pre poll
> 18576: UNLOCK: _dbus_connection_unlock
> 18576: lock unix_do_iteration post poll
> 18576: LOCK: _dbus_connection_lock
> 18576: in iteration, need_read=1 need_write=0
> 18576: client auth state: waiting for input
> 18576: read 36 bytes in auth phase
> 18576: client: got command "REJECTED EXTERNAL DBUS_COOKIE_SHA1"
> 18576: client: Adding mechanism EXTERNAL to list we will try
> 18576: client: Adding mechanism DBUS_COOKIE_SHA1 to list we will try
> 18576: client: Shutting down mechanism EXTERNAL
> 18576: client: going from state WaitingForData to state WaitingForData
> 18576: client: Trying mechanism EXTERNAL
> 18576: client auth state: bytes to send
> 18576: check_read_watch: fd = 3
> 18576: setting read watch enabled = 0
> 18576: UNLOCK: protected_change_watch
> 18576: LOCK: protected_change_watch
> 18576: check_write_watch(): needed = 1 on connection 0x804b5f8 watch 0x804b298 f
> d = 3 outgoing messages exist 1
> 18576: UNLOCK: protected_change_watch
> 18576: LOCK: protected_change_watch
> 18576: do_reading: fd = 3
> 18576: check_write_watch(): needed = 1 on connection 0x804b5f8 watch 0x804b298 f
> d = 3 outgoing messages exist 1
> 18576: UNLOCK: protected_change_watch
> ...
> _______________________________________________
> dbus mailing list
> dbus at lists.freedesktop.org
> http://lists.freedesktop.org/mailman/listinfo/dbus
--
John (J5) Palmieri <johnp at redhat.com>
More information about the dbus
mailing list