Service state change is not emitted on net.connman.Service

Service state change is not emitted on net.connman.Service

[Jakub Jirutka]

Hi,

I wrote a daemon [1] that integrates ConnMan with resolvconf(9) using the DBus API. It monitors the PropertyChanged signal on the net.connman.Service interface and acts when the state of a service changes to ready, online or disconnect.

This works correctly with WiFi (iwd) and VPN (openvpn), but not with Ethernet. If I disconnect the cable, the status change to "disconnect" is emitted for /net/connman/service/ethernet_*, but after I connect it back, nothing is emitted (only the transition to the "online" state, unless I was already "online" via another device). I does emit the ServiceChanged signal on the net.connman.Manager interface, but this one is unsuitable for my purpose (for example, doesn’t work well for WiFi).

A few relevant lines from the debug log:

    src/rtnl.c:rtnl_message() NEWROUTE len 116 type 24 flags 0x0400 seq 0 pid 0
    ...
    src/service.c:__connman_service_create_from_network() network 0x7fe43db0a260
    ...
    src/service.c:__connman_service_ipconfig_indicate_state() service 0x7fe43daf9d70 (ethernet_482ae3a31df2_cable) old state 1 (idle) new state 3 (configuration) type 1 (IPv4)
    src/service.c:service_indicate_state() service 0x7fe43daf9d70 old idle - new configuration/idle => configuration
    ...
    src/service.c:service_indicate_state() service 0x7fe43daf9d70 old configuration - new ready/configuration => ready

Function `service_indicate_state()` (service.c:5976) calls `state_changed()` (service.c:1657 [2]) where the DBus signal should be emitted… but it’s not, due to `allow_property_changed()`:

    1657 | static void state_changed(struct connman_service *service)
    ...  | ...
    1667 |     if (!allow_property_changed(service))  <--- HERE
    1668 |         return;
    1669 |
    1670 |     connman_dbus_property_changed_basic(service->path,
    1671 |             CONNMAN_SERVICE_INTERFACE, "State",
    1672 |             DBUS_TYPE_STRING, &str);

Function `allow_property_changed()` performs a lookup in the `services_notify->add` hash table and returns false if the service path is found there. The service is added there in `service_schedule_added()` (service.c:4998) which is called near the end of the `__connman_service_create_from_network()` function (service.c:7531).
Function `service_schedule_added()` also calls `service_schedule_changed()` (service.c:4829) which schedules `service_send_changed()` (service.c:4802) to be called after 100 ms(?) timeout. This function then removes the service from the `services_notify->add` hash table.
Meanwhile, the service is connected and all the PropertyChanged messages are lost. 

This condition has been added by Patrik Flykt, ten years ago in 83cab654f1f78d49bd848b87cea645078f82f13e [3] with message:

    service: Send updated properties after ServicesChanged
    Updated service properties are not sent before the new service
    has been announced in a 'ServicesChanged' signal.

I don’t know the context and real intention of this change, but the described behaviour of the API seems to be wrong, or at least unexpected and inconsistent between various service types.


Can you please fix this problem or explain me how it can be fixed?

Thanks,
Jakub

[1]: https://github.com/jirutka/connman-resolvconf
[2]: https://git.kernel.org/pub/scm/network/connman/connman.git/tree/src/service.c?h=1.41&id=4a27c58ad8b1afd980ebe122ca178c7f659c025e#n1667
[3]: https://git.kernel.org/pub/scm/network/connman/connman.git/commit/?id=83cab654f1f78d49bd848b87cea645078f82f13e

Re: Service state change is not emitted on net.connman.Service

[Daniel Wagner]

Hi Jakub,

On Thu, Jun 09, 2022 at 03:46:07AM +0200, Jakub Jirutka wrote:
> Can you please fix this problem or explain me how it can be fixed?

This allowed_property_changed is pretty funky indeed. It got added to
filter out p2p events which were not supposed to be seen. At least
this is what I read from the git history.

Anyway, 100ms timeout has really the small of a hack IMO. It seems
ConnMan lacks the ability to order signals. From your description, it
sounds like the Ethernet events are within the timeout limit.

Not really sure how to address this though. Maybe do not call
service_schedule_changed() in __connman_service_create_from_network()
and instead send the ServiceChanged first?

Thanks,
Daniel

Re: Service state change is not emitted on net.connman.Service

[Jakub Jirutka]

[-- Attachment #1.1.1: Type: text/plain, Size: 3588 bytes --]

Hi Daniel,

I dug up more relevant commits that explains this matter a bit.

2012-02-20 Patrik Flykt 1af75231e5cfaad061b9a2f58589b3fb6f37fd2e [1]:
 > service: Implement ServicesAdded and ServicesRemoved signals
 >
 > When services are added or removed, collect them into separate
 > lists in order to send as many as possible in one go and with
 > then removed ones sent first. Add a wait of 100ms to collect
 > more services in one batch. When removing a service check
 > whether it was also on the added list; if so, remove it from
 > that list.

^ This commit added that weird 100 ms timeout for sending signals.

2012-04-03 Patrik Flykt 365528e5155e1a1efe4aa81018d99502aaaf8558 [2]:
 > service: Add ServicesChanged signal
 >
 > Send ServicesChanged signal instead of consecutive ServicesAdded and
 > ServicesRemoved signals.

2012-08-20 Patrik Flykt 83cab654f1f78d49bd848b87cea645078f82f13e [3]:
 > service: Send updated properties after ServicesChanged
 >
 > Updated service properties are not sent before the new service
 > has been announced in a 'ServicesChanged' signal.

^ This commit added that allow_property_changed gate that causes 
PropertyChanged signals within 100 ms to be thrown away.

2015-08-12 Patrik Flykt 22d4605ae647db5d90c88d9f66164c66867334ed [4]:
 > service: Do not send PropertyChanged signals before service is
 > announced
 >
 > Send no service PropertyChanged signals before the service is
 > announced in ServicesChanged. Move the ServicesChanged adding right
 > after registering a service to D-Bus, as any ipconfig state updates in
 > between caused service PropertyChanged signals to be sent as the
 > service was missing from the new services hash for ServicesChanged
 > signal.

^ This commit moved `service_schedule_added` in 
`__connman_service_create_from_network` *after* autoconnect (now 
trigger_autoconnect). If I revert this change, the PropertyChanged 
signals that I miss are sent.


 > Not really sure how to address this though. Maybe do not call
 > service_schedule_changed() in __connman_service_create_from_network()
 > and instead send the ServiceChanged first?
Does this effectively mean remove the 100 ms timeout and send 
ServicesChanged right away?


I’m beginning to think that throwing away the PropertyChanged signals 
within 100 ms wasn’t the original intention. It’s a result of two 
requirements that are implemented in a contradictory way:

1. Don’t send ServicesChanged right after each change, but aggregate the 
changes within 100 ms interval and order service removals first.
2. Avoid sending PropertyChanged for a service before the 
ServicesChanged signal with this service listed is sent.

I would start by asking if both of these requirements are still valid.
Why sending PropertyChanged before the service is announced in 
ServicesChanged is a problem?

If these two requirements still apply, what about postponing 
PropertyChanged instead of throwing them away, i.e. accumulate them in a 
queue and send after the related ServicesChanged is sent?

Jakub

[1]: 
https://git.kernel.org/pub/scm/network/connman/connman.git/commit/?id=1af75231e5cfaad061b9a2f58589b3fb6f37fd2e
[2]: 
https://git.kernel.org/pub/scm/network/connman/connman.git/commit/?id=365528e5155e1a1efe4aa81018d99502aaaf8558
[3]: 
https://git.kernel.org/pub/scm/network/connman/connman.git/commit/?id=83cab654f1f78d49bd848b87cea645078f82f13e
[3]: 
https://git.kernel.org/pub/scm/network/connman/connman.git/commit/?id=22d4605ae647db5d90c88d9f66164c66867334ed

[-- Attachment #1.1.2: OpenPGP public key --]
[-- Type: application/pgp-keys, Size: 5277 bytes --]

[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 659 bytes --]

Re: Service state change is not emitted on net.connman.Service

[Daniel Wagner]

Hi Jakub,

On Wed, Jul 13, 2022 at 03:23:21AM +0200, Jakub Jirutka wrote:
> I’m beginning to think that throwing away the PropertyChanged signals within
> 100 ms wasn’t the original intention. It’s a result of two requirements that
> are implemented in a contradictory way:
> 
> 1. Don’t send ServicesChanged right after each change, but aggregate the
> changes within 100 ms interval and order service removals first.
> 2. Avoid sending PropertyChanged for a service before the ServicesChanged
> signal with this service listed is sent.
> 
> I would start by asking if both of these requirements are still valid.
> Why sending PropertyChanged before the service is announced in
> ServicesChanged is a problem?
> 
> If these two requirements still apply, what about postponing PropertyChanged
> instead of throwing them away, i.e. accumulate them in a queue and send
> after the related ServicesChanged is sent?

I came to the same conclusion. Those requirements are contradicting
each other. The 100ms requirement sounds like a fix for an UI which
can't handle it correctly. I think I would just remove the 100ms thing
:)

Daniel