auto-start problem in v0.50
Kimmo.Hamalainen at nokia.com
Kimmo.Hamalainen at nokia.com
Tue Nov 8 07:23:26 PST 2005
But it does not start the service at all -- not even as 'messagebus'
user. Even if I run the bus as a normal user. Maybe it needs 'root'
access all the time, and autostart fails always if it's not root...
> -----Original Message-----
> From: ext John (J5) Palmieri [mailto:johnp at redhat.com]
> Sent: 08 November, 2005 17:12
> To: Hamalainen Kimmo (Nokia-M/Helsinki)
> Cc: dbus at lists.freedesktop.org
> Subject: Re: auto-start problem in v0.50
>
>
> 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