[PATCH 1/2] hostname: Add more debug in soft failure cases

[PATCH 1/2] hostname: Add more debug in soft failure cases

[Bastien Nocera]

So it's easier to debug problems with the hostname plugin.
---
 plugins/hostname.c | 10 ++++++++--
 1 file changed, 8 insertions(+), 2 deletions(-)

diff --git a/plugins/hostname.c b/plugins/hostname.c
index 4f9dfe6d8..f876d0afb 100644
--- a/plugins/hostname.c
+++ b/plugins/hostname.c
@@ -82,8 +82,10 @@ static void update_name(struct btd_adapter *adapter, gpointer user_data)
 {
 	const char *hostname = get_hostname();
 
-	if (hostname == NULL)
+	if (hostname == NULL) {
+		DBG ("No hostname available yet");
 		return;
+	}
 
 	if (btd_adapter_is_default(adapter)) {
 		DBG("name: %s", hostname);
@@ -281,13 +283,16 @@ static int hostname_init(void)
 
 	hostname_client = g_dbus_client_new(conn, "org.freedesktop.hostname1",
 						"/org/freedesktop/hostname1");
-	if (!hostname_client)
+	if (!hostname_client) {
+		DBG("Failed to get hostname client");
 		return -EIO;
+	}
 
 	hostname_proxy = g_dbus_proxy_new(hostname_client,
 						"/org/freedesktop/hostname1",
 						"org.freedesktop.hostname1");
 	if (!hostname_proxy) {
+		DBG("Failed to get hostname proxy");
 		g_dbus_client_unref(hostname_client);
 		hostname_client = NULL;
 		return -EIO;
@@ -297,6 +302,7 @@ static int hostname_init(void)
 
 	err = btd_register_adapter_driver(&hostname_driver);
 	if (err < 0) {
+		DBG("Failed to register adapter driver");
 		g_dbus_proxy_unref(hostname_proxy);
 		hostname_proxy = NULL;
 		g_dbus_client_unref(hostname_client);
-- 
2.14.1

[PATCH 2/2] hostname: Fix "BlueZ 5.XX" adapter name on startup

[Bastien Nocera]

The hostname plugin listens to property changes from systemd-hostnamed
but doesn't fetch initial values. This means that unless the
PrettyHostname or StaticHostname changes, the default adapter will be
called "BlueZ 5.XX" matching the version number.

This is the case since the hostname plugin replaced the adaptername
plugin in 2012.

Fetch the initial values for PrettyHostname, StaticHostname and
Chassis when the plugin is initiated, so as to make the values
available for adapter setup.
---
 plugins/hostname.c | 4 ++++
 1 file changed, 4 insertions(+)

diff --git a/plugins/hostname.c b/plugins/hostname.c
index f876d0afb..db9187378 100644
--- a/plugins/hostname.c
+++ b/plugins/hostname.c
@@ -307,6 +307,10 @@ static int hostname_init(void)
 		hostname_proxy = NULL;
 		g_dbus_client_unref(hostname_client);
 		hostname_client = NULL;
+	} else {
+		g_dbus_proxy_refresh_property(hostname_proxy, "PrettyHostname");
+		g_dbus_proxy_refresh_property(hostname_proxy, "StaticHostname");
+		g_dbus_proxy_refresh_property(hostname_proxy, "Chassis");
 	}
 
 	return err;
-- 
2.14.1

Re: [PATCH 2/2] hostname: Fix "BlueZ 5.XX" adapter name on startup

[Marcel Holtmann]

Hi Bastien,

> The hostname plugin listens to property changes from systemd-hostnamed
> but doesn't fetch initial values. This means that unless the
> PrettyHostname or StaticHostname changes, the default adapter will be
> called "BlueZ 5.XX" matching the version number.
> 
> This is the case since the hostname plugin replaced the adaptername
> plugin in 2012.
> 
> Fetch the initial values for PrettyHostname, StaticHostname and
> Chassis when the plugin is initiated, so as to make the values
> available for adapter setup.
> ---
> plugins/hostname.c | 4 ++++
> 1 file changed, 4 insertions(+)
> 
> diff --git a/plugins/hostname.c b/plugins/hostname.c
> index f876d0afb..db9187378 100644
> --- a/plugins/hostname.c
> +++ b/plugins/hostname.c
> @@ -307,6 +307,10 @@ static int hostname_init(void)
> 		hostname_proxy = NULL;
> 		g_dbus_client_unref(hostname_client);
> 		hostname_client = NULL;
> +	} else {
> +		g_dbus_proxy_refresh_property(hostname_proxy, "PrettyHostname");
> +		g_dbus_proxy_refresh_property(hostname_proxy, "StaticHostname");
> +		g_dbus_proxy_refresh_property(hostname_proxy, "Chassis");
> 	}

I am 100% certain that I tested this since this would be a really dumb plugin otherwise. However is it possible that when calling GetManagedObjects the values are not returned correctly? Can we check that. Or does the property watch has an issue not calling the callback correctly.

Regards

Marcel

Re: [PATCH 2/2] hostname: Fix "BlueZ 5.XX" adapter name on startup

[Bastien Nocera]

On Wed, 2017-09-20 at 17:48 +0200, Marcel Holtmann wrote:
> Hi Bastien,
> 
> > The hostname plugin listens to property changes from systemd-
> > hostnamed
> > but doesn't fetch initial values. This means that unless the
> > PrettyHostname or StaticHostname changes, the default adapter will
> > be
> > called "BlueZ 5.XX" matching the version number.
> > 
> > This is the case since the hostname plugin replaced the adaptername
> > plugin in 2012.
> > 
> > Fetch the initial values for PrettyHostname, StaticHostname and
> > Chassis when the plugin is initiated, so as to make the values
> > available for adapter setup.
> > ---
> > plugins/hostname.c | 4 ++++
> > 1 file changed, 4 insertions(+)
> > 
> > diff --git a/plugins/hostname.c b/plugins/hostname.c
> > index f876d0afb..db9187378 100644
> > --- a/plugins/hostname.c
> > +++ b/plugins/hostname.c
> > @@ -307,6 +307,10 @@ static int hostname_init(void)
> > 		hostname_proxy = NULL;
> > 		g_dbus_client_unref(hostname_client);
> > 		hostname_client = NULL;
> > +	} else {
> > +		g_dbus_proxy_refresh_property(hostname_proxy,
> > "PrettyHostname");
> > +		g_dbus_proxy_refresh_property(hostname_proxy,
> > "StaticHostname");
> > +		g_dbus_proxy_refresh_property(hostname_proxy,
> > "Chassis");
> > 	}
> 
> I am 100% certain that I tested this since this would be a really
> dumb plugin otherwise.

You don't say ;)

>  However is it possible that when calling GetManagedObjects the
> values are not returned correctly?

get_managed_objects() in gdbus/client.c is never called for this
GDBusClient.

>  Can we check that. Or does the property watch has an issue not
> calling the callback correctly.

The property watch code in add_property() and in properties_changed()
is never called either.

This is the debug I used:
https://github.com/hadess/bluez/commit/54ce125be92700f0fba64c7892d3a4296441bc7c

The only debug message I actually see after reverting the patch you're
commenting on is:
** Message: g_dbus_proxy_set_property_watch() success

Cheers

Re: [PATCH 2/2] hostname: Fix "BlueZ 5.XX" adapter name on startup

[Marcel Holtmann]

Hi Bastien,

>>> The hostname plugin listens to property changes from systemd-
>>> hostnamed
>>> but doesn't fetch initial values. This means that unless the
>>> PrettyHostname or StaticHostname changes, the default adapter will
>>> be
>>> called "BlueZ 5.XX" matching the version number.
>>> 
>>> This is the case since the hostname plugin replaced the adaptername
>>> plugin in 2012.
>>> 
>>> Fetch the initial values for PrettyHostname, StaticHostname and
>>> Chassis when the plugin is initiated, so as to make the values
>>> available for adapter setup.
>>> ---
>>> plugins/hostname.c | 4 ++++
>>> 1 file changed, 4 insertions(+)
>>> 
>>> diff --git a/plugins/hostname.c b/plugins/hostname.c
>>> index f876d0afb..db9187378 100644
>>> --- a/plugins/hostname.c
>>> +++ b/plugins/hostname.c
>>> @@ -307,6 +307,10 @@ static int hostname_init(void)
>>> 		hostname_proxy = NULL;
>>> 		g_dbus_client_unref(hostname_client);
>>> 		hostname_client = NULL;
>>> +	} else {
>>> +		g_dbus_proxy_refresh_property(hostname_proxy,
>>> "PrettyHostname");
>>> +		g_dbus_proxy_refresh_property(hostname_proxy,
>>> "StaticHostname");
>>> +		g_dbus_proxy_refresh_property(hostname_proxy,
>>> "Chassis");
>>> 	}
>> 
>> I am 100% certain that I tested this since this would be a really
>> dumb plugin otherwise.
> 
> You don't say ;)
> 
>> However is it possible that when calling GetManagedObjects the
>> values are not returned correctly?
> 
> get_managed_objects() in gdbus/client.c is never called for this
> GDBusClient.

Hmmm, you should either come via service_connect callback or when setting the proxy handlers. Seems setting the property watch is not triggering the initial GetManagedObjects. And most likely the service_connect is not triggered correctly either. Something is fishy here and it is too long ago that I wrote that code to remember. Maybe we changed something and accidentally broke some expected behavior.

Maybe Luiz and Johan can have a look at this as well, but I have the feeling this should be a fix in the gdbus code.

Regards

Marcel

Re: [PATCH 2/2] hostname: Fix "BlueZ 5.XX" adapter name on startup

[Luiz Augusto von Dentz]

H Bastien,

On Wed, Sep 20, 2017 at 7:59 PM, Marcel Holtmann <marcel@holtmann.org> wrot=
e:
> Hi Bastien,
>
>>>> The hostname plugin listens to property changes from systemd-
>>>> hostnamed
>>>> but doesn't fetch initial values. This means that unless the
>>>> PrettyHostname or StaticHostname changes, the default adapter will
>>>> be
>>>> called "BlueZ 5.XX" matching the version number.
>>>>
>>>> This is the case since the hostname plugin replaced the adaptername
>>>> plugin in 2012.
>>>>
>>>> Fetch the initial values for PrettyHostname,StaticHostname and
>>>> Chassis when the plugin is initiated, so as to make the values
>>>> available for adapter setup.
>>>> ---
>>>> plugins/hostname.c | 4 ++++
>>>> 1 file changed, 4 insertions(+)
>>>>
>>>> diff --git a/plugins/hostname.c b/plugins/hostname.c
>>>> index f876d0afb..db9187378 100644
>>>> --- a/plugins/hostname.c
>>>> +++ b/plugins/hostname.c
>>>> @@ -307,6 +307,10 @@ static int hostname_init(void)
>>>>             hostname_proxy =3D NULL;
>>>>             g_dbus_client_unref(hostname_client);
>>>>             hostname_client =3D NULL;
>>>> +   } else {
>>>>+           g_dbus_proxy_refresh_property(hostname_proxy,
>>>> "PrettyHostname");
>>>> +           g_dbus_proxy_refresh_property(hostname_proxy,
>>>> "StaticHostname");
>>>> +           g_dbus_proxy_refresh_property(hostname_proxy,
>>>> "Chassis");
>>>>     }
>>>
>>> I am 100% certain that I tested this since this would be a really
>>> dumb plugin otherwise.
>>
>> You don't say ;)
>>
>>> However is it possible that when calling GetManagedObjects the
>>> values are not returned correctly?
>>
>> get_managed_objects() in gdbus/client.c is never called for this
>> GDBusClient.

I guess this can only occur if the bus name does not exist, perhaps it
has not been activated yet, that would explain why calling refresh
would work since that activate the bus name. I wonder if GetNameOwner
is not enough to activate a service? Well perhaps we should use
StartServiceByName then but it doesn't return the bus id so it only
works if the service has activated since we have subscribed to
NameOwnerChanged but in case it is already running we still have to
call GetNameOwner. Btw is this running with dbus-daemon or the new
dbus-broker? Perhaps the later doesn't active things in the same way
dbus-daemon would.


> Hmmm, you should either come via service_connect callback or when setting=
 the proxy handlers. Seems setting the property watch is not triggering the=
 initial GetManagedObjects. And most likely the service_connect is not trig=
gered correctly either. Something is fishy here and it is too long ago that=
 I wrote that code to remember. Maybe we changed something and accidentally=
 broke some expected behavior.
>
> Maybe Luiz and Johan can have a look at this as well, but I have the feel=
ing this should be a fix in the gdbus code.gdbus
>
> Regards
>
> Marcel
>
> --
> To unsubscribe from this list: send the line "unsubscribe linux-bluetooth=
" inlinux-bluetooth" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html



--=20
Luiz Augusto von Dentz

Re: [PATCH 2/2] hostname: Fix "BlueZ 5.XX" adapter name on startup

[Bastien Nocera]

On Wed, 2017-09-20 at 21:57 +0300, Luiz Augusto von Dentz wrote:
> H Bastien,
> 
> On Wed, Sep 20, 2017 at 7:59 PM, Marcel Holtmann <marcel@holtmann.org
> > wrote:
> > Hi Bastien,
> > 
> > > > > The hostname plugin listens to property changes from systemd-
> > > > > hostnamed
> > > > > but doesn't fetch initial values. This means that unless the
> > > > > PrettyHostname or StaticHostname changes, the default adapter
> > > > > will
> > > > > be
> > > > > called "BlueZ 5.XX" matching the version number.
> > > > > 
> > > > > This is the case since the hostname plugin replaced the
> > > > > adaptername
> > > > > plugin in 2012.
> > > > > 
> > > > > Fetch the initial values for PrettyHostname,StaticHostname
> > > > > and
> > > > > Chassis when the plugin is initiated, so as to make the
> > > > > values
> > > > > available for adapter setup.
> > > > > ---
> > > > > plugins/hostname.c | 4 ++++
> > > > > 1 file changed, 4 insertions(+)
> > > > > 
> > > > > diff --git a/plugins/hostname.c b/plugins/hostname.c
> > > > > index f876d0afb..db9187378 100644
> > > > > --- a/plugins/hostname.c
> > > > > +++ b/plugins/hostname.c
> > > > > @@ -307,6 +307,10 @@ static int hostname_init(void)
> > > > >             hostname_proxy = NULL;
> > > > >             g_dbus_client_unref(hostname_client);
> > > > >             hostname_client = NULL;
> > > > > +   } else {
> > > > > +           g_dbus_proxy_refresh_property(hostname_proxy,
> > > > > "PrettyHostname");
> > > > > +           g_dbus_proxy_refresh_property(hostname_proxy,
> > > > > "StaticHostname");
> > > > > +           g_dbus_proxy_refresh_property(hostname_proxy,
> > > > > "Chassis");
> > > > >     }
> > > > 
> > > > I am 100% certain that I tested this since this would be a
> > > > really
> > > > dumb plugin otherwise.
> > > 
> > > You don't say ;)
> > > 
> > > > However is it possible that when calling GetManagedObjects the
> > > > values are not returned correctly?
> > > 
> > > get_managed_objects() in gdbus/client.c is never called for this
> > > GDBusClient.
> 
> I guess this can only occur if the bus name does not exist, perhaps
> it
> has not been activated yet, that would explain why calling refresh
> would work since that activate the bus name. I wonder if GetNameOwner
> is not enough to activate a service?

It's not enough, GetNameOwner is a call to the daemon, the service
isn't involved at all. You need to start it by hand.

A few bindings will allow you to choose whether to autostart the
service if the target service doesn't exist when calling remote
methods.

>  Well perhaps we should use
> StartServiceByName then but it doesn't return the bus id so it only
> works if the service has activated since we have subscribed to
> NameOwnerChanged but in case it is already running we still have to
> call GetNameOwner. Btw is this running with dbus-daemon or the new
> dbus-broker? Perhaps the later doesn't active things in the same way
> dbus-daemon would.

It goes without saying that I wouldn't be sending bug reports like this
one if I was using dbus-broker.

The plugin seems to work correctly in
df0ad3ecb625b5968522acce8b7d33d68f30b4cb (plus build fixes), and
systemd-hostnamed is autostarted.

I tried bisecting, but ended up screwing up at some point, and didn't
fancy restarting again (after about 15 iterations, and having to
cherry-pick different build fixes every time, sigh), so I started
testing individual releases.

(4 other working versions)
5.46 works
5.47 fails

And after that:
ef024c2c44b4f0dab3c054d062a911cacef1fdc9 is the first bad commit
commit ef024c2c44b4f0dab3c054d062a911cacef1fdc9
Author: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>
Date:   Fri Aug 11 15:39:15 2017 +0300

    gdbus: Fix calling GetAll while GetManagedObjects is pending
    
    If proxies are created while the client is not ready put them into a
    pending list so only if they are not found in GetManagedObject reply
    call GetAll.

:040000 040000 01462de94f24f0f561aab0be34bcfc0935718da7 6917c7faea1135c53fc1d8d9d43d6347952e5d40 M	gdbus

Cheers

Re: [PATCH 2/2] hostname: Fix "BlueZ 5.XX" adapter name on startup

[Bastien Nocera]

On Fri, 2017-09-22 at 15:13 +0200, Bastien Nocera wrote:
<snip>
> ef024c2c44b4f0dab3c054d062a911cacef1fdc9 is the first bad commit
> commit ef024c2c44b4f0dab3c054d062a911cacef1fdc9
> Author: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>
> Date:   Fri Aug 11 15:39:15 2017 +0300
> 
>     gdbus: Fix calling GetAll while GetManagedObjects is pending
>     
>     If proxies are created while the client is not ready put them
> into a
>     pending list so only if they are not found in GetManagedObject
> reply
>     call GetAll.

Any updates on this?

Re: [PATCH 2/2] hostname: Fix "BlueZ 5.XX" adapter name on startup

[Bastien Nocera]

Hey,

On Fri, 2017-09-22 at 15:13 +0200, Bastien Nocera wrote:
> 
<snip>
> It goes without saying that I wouldn't be sending bug reports like this
> one if I was using dbus-broker.
> 
> The plugin seems to work correctly in
> df0ad3ecb625b5968522acce8b7d33d68f30b4cb (plus build fixes), and
> systemd-hostnamed is autostarted.
> 
> I tried bisecting, but ended up screwing up at some point, and didn't
> fancy restarting again (after about 15 iterations, and having to
> cherry-pick different build fixes every time, sigh), so I started
> testing individual releases.
> 
> (4 other working versions)
> 5.46 works
> 5.47 fails
> 
> And after that:
> ef024c2c44b4f0dab3c054d062a911cacef1fdc9 is the first bad commit
> commit ef024c2c44b4f0dab3c054d062a911cacef1fdc9
> Author: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>
> Date:   Fri Aug 11 15:39:15 2017 +0300
> 
>     gdbus: Fix calling GetAll while GetManagedObjects is pending
>     
>     If proxies are created while the client is not ready put them into a
>     pending list so only if they are not found in GetManagedObject reply
>     call GetAll.
> 
> :040000 040000 01462de94f24f0f561aab0be34bcfc0935718da7 6917c7faea1135c53fc1d8d9d43d6347952e5d40 M	gdbus

As discussed on IRC, this is still broken and should really be fixed
before the release. In the worst case, my work-around earlier in the
thread could also be applied if we're strapped for time.