[phosphor-logging] About the "Stop emitting Entry propChanged before ifacesAdded" change reason

[phosphor-logging] About the "Stop emitting Entry propChanged before ifacesAdded" change reason

[CS20 CHMa0]

[-- Attachment #1: Type: text/plain, Size: 1654 bytes --]

Hi Matt,
I meet an issue in bmcweb while update service handle firmware update error
https://github.com/openbmc/bmcweb/blob/master/redfish-core/lib/update_service.hpp#L321

After I  revert the change or try to change the match rule from 'PropertiesChanged' to 'InterfacesAdded',
the error handler work well in update service.
     fwUpdateErrorMatcher = std::make_unique<sdbusplus::bus::match::match>(
         *crow::connections::systemBus,
-        "type='signal',member='PropertiesChanged',path_namespace='/xyz/"
-        "openbmc_project/logging/entry',"
-        "arg0='xyz.openbmc_project.Logging.Entry'",
+        "interface='org.freedesktop.DBus.ObjectManager',type='signal',"
+        "member='InterfacesAdded',"
+        "path='/xyz/openbmc_project/logging'",

May I ask the reason why you update the change?  https://gerrit.openbmc-project.xyz/c/openbmc/phosphor-logging/+/46055


Thanks
Brian
________________________________
The privileged confidential information contained in this email is intended for use only by the addressees as indicated by the original sender of this email. If you are not the addressee indicated in this email or are not responsible for delivery of the email to such a person, please kindly reply to the sender indicating this fact and delete all copies of it from your computer and network server immediately. Your cooperation is highly appreciated. It is advised that any unauthorized use of confidential information of Nuvoton is strictly prohibited; and any information in this email irrelevant to the official business of Nuvoton shall be deemed as neither given nor endorsed by Nuvoton.

[-- Attachment #2: Type: text/html, Size: 4790 bytes --]

Re: [phosphor-logging] About the "Stop emitting Entry propChanged before ifacesAdded" change reason

[Matt Spinler]

On 10/20/2021 3:39 AM, CS20 CHMa0 wrote:
> Hi Matt, I meet an issue in bmcweb while update service handle 
> firmware update error 
> https://github.com/openbmc/bmcweb/blob/master/redfish-core/lib/update_service.hpp#L321 
> After I revert the change or try to change the match rule from 
> 'PropertiesChanged' ZjQcmQRYFpfptBannerStart
> This Message Is From an External Sender
> This message came from outside your organization.
> ZjQcmQRYFpfptBannerEnd
>
> Hi Matt,
>
> I meet an issue in bmcweb while update service handle firmware update 
> error
>
> https://github.com/openbmc/bmcweb/blob/master/redfish-core/lib/update_service.hpp#L321 
> <https://github.com/openbmc/bmcweb/blob/master/redfish-core/lib/update_service.hpp#L321> 
>
>
> After I  revert the change or try to change the match rule from 
> 'PropertiesChanged' to 'InterfacesAdded',
>
> the error handler work well in update service.
>
>      fwUpdateErrorMatcher = 
> std::make_unique<sdbusplus::bus::match::match>(
>
>          *crow::connections::systemBus,
>
> - "type='signal',member='PropertiesChanged',path_namespace='/xyz/"
>
> -        "openbmc_project/logging/entry',"
>
> - "arg0='xyz.openbmc_project.Logging.Entry'",
>
> + "interface='org.freedesktop.DBus.ObjectManager',type='signal',"
>
> +        "member='InterfacesAdded',"
>
> + "path='/xyz/openbmc_project/logging'",
>
> May I ask the reason why you update the change? 
> https://gerrit.openbmc-project.xyz/c/openbmc/phosphor-logging/+/46055 
> <https://gerrit.openbmc-project.xyz/c/openbmc/phosphor-logging/+/46055>
>

Hi,
I guess I saw this as a bug fix.  The code creates the interface on 
D-Bus with the defer-interfaces-added parameter set to true so it 
wouldn't emit interfacesAdded at the point, then sets all the property 
values, and then explicitly emits the IA signal.   Others can chime in, 
but I didn't see it as proper D-Bus behavior to emit propertiesChanged 
before InterfacesAdded, since in fact no property is changing after the 
interface was added.

It seems like every application does their own thing here, so maybe we 
can come up with some official best practices for how to emit signals 
for new interfaces (unless it's there and I missed it).


> Thanks
>
> Brian
>
> ------------------------------------------------------------------------
> The privileged confidential information contained in this email is 
> intended for use only by the addressees as indicated by the original 
> sender of this email. If you are not the addressee indicated in this 
> email or are not responsible for delivery of the email to such a 
> person, please kindly reply to the sender indicating this fact and 
> delete all copies of it from your computer and network server 
> immediately. Your cooperation is highly appreciated. It is advised 
> that any unauthorized use of confidential information of Nuvoton is 
> strictly prohibited; and any information in this email irrelevant to 
> the official business of Nuvoton shall be deemed as neither given nor 
> endorsed by Nuvoton. 

Re: [phosphor-logging] About the "Stop emitting Entry propChanged before ifacesAdded" change reason

[Patrick Williams]

[-- Attachment #1: Type: text/plain, Size: 846 bytes --]

On Wed, Oct 20, 2021 at 10:13:06AM -0500, Matt Spinler wrote:
> values, and then explicitly emits the IA signal.   Others can chime in, 
> but I didn't see it as proper D-Bus behavior to emit propertiesChanged 
> before InterfacesAdded, since in fact no property is changing after the 
> interface was added.

Correct.  PropertiesChanged signals should not show up before InterfacesAdded.

> It seems like every application does their own thing here, so maybe we 
> can come up with some official best practices for how to emit signals 
> for new interfaces (unless it's there and I missed it).

I'll admit the sdbusplus API is not great for this and a lot of applications do
it wrong.  There was this issue on the backlog to come up with something
"better": https://github.com/openbmc/sdbusplus/issues/53

-- 
Patrick Williams

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

RE: [phosphor-logging] About the "Stop emitting Entry propChanged before ifacesAdded" change reason

[CS20 CHMa0]

Hi Matt and Patrick,
Thanks for your apply, it seems very reasonable.
I think the bmcweb code need some update to avoid using wrong behavior.

-----Original Message-----
From: Patrick Williams [mailto:patrick@stwcx.xyz]
Sent: Thursday, October 21, 2021 1:18 AM
To: Matt Spinler <mspinler@linux.ibm.com>
Cc: CS20 CHMa0 <CHMA0@nuvoton.com>; openbmc@lists.ozlabs.org
Subject: Re: [phosphor-logging] About the "Stop emitting Entry propChanged before ifacesAdded" change reason

On Wed, Oct 20, 2021 at 10:13:06AM -0500, Matt Spinler wrote:
> values, and then explicitly emits the IA signal.   Others can chime
> in, but I didn't see it as proper D-Bus behavior to emit
> propertiesChanged before InterfacesAdded, since in fact no property is
> changing after the interface was added.

Correct.  PropertiesChanged signals should not show up before InterfacesAdded.

> It seems like every application does their own thing here, so maybe we
> can come up with some official best practices for how to emit signals
> for new interfaces (unless it's there and I missed it).

I'll admit the sdbusplus API is not great for this and a lot of applications do it wrong.  There was this issue on the backlog to come up with something
"better": https://github.com/openbmc/sdbusplus/issues/53

--
Patrick Williams
________________________________
________________________________
 The privileged confidential information contained in this email is intended for use only by the addressees as indicated by the original sender of this email. If you are not the addressee indicated in this email or are not responsible for delivery of the email to such a person, please kindly reply to the sender indicating this fact and delete all copies of it from your computer and network server immediately. Your cooperation is highly appreciated. It is advised that any unauthorized use of confidential information of Nuvoton is strictly prohibited; and any information in this email irrelevant to the official business of Nuvoton shall be deemed as neither given nor endorsed by Nuvoton.

RE: [phosphor-logging] About the "Stop emitting Entry propChanged before ifacesAdded" change reason

[CS20 CHMa0]

Hi Ed,
Before I upload the commit, I also consider revert the change in phosphor logging.
But I think it is reasonable to update bmcweb if it not used the good API.

-----Original Message-----
From: Patrick Williams [mailto:patrick@stwcx.xyz]
Sent: Thursday, October 21, 2021 1:18 AM
To: Matt Spinler <mspinler@linux.ibm.com>
Cc: CS20 CHMa0 <CHMA0@nuvoton.com>; openbmc@lists.ozlabs.org
Subject: Re: [phosphor-logging] About the "Stop emitting Entry propChanged before ifacesAdded" change reason

On Wed, Oct 20, 2021 at 10:13:06AM -0500, Matt Spinler wrote:
> values, and then explicitly emits the IA signal.   Others can chime
> in, but I didn't see it as proper D-Bus behavior to emit
> propertiesChanged before InterfacesAdded, since in fact no property is
> changing after the interface was added.

Correct.  PropertiesChanged signals should not show up before InterfacesAdded.

> It seems like every application does their own thing here, so maybe we
> can come up with some official best practices for how to emit signals
> for new interfaces (unless it's there and I missed it).

I'll admit the sdbusplus API is not great for this and a lot of applications do it wrong.  There was this issue on the backlog to come up with something
"better": https://github.com/openbmc/sdbusplus/issues/53

--
Patrick Williams
________________________________
________________________________
 The privileged confidential information contained in this email is intended for use only by the addressees as indicated by the original sender of this email. If you are not the addressee indicated in this email or are not responsible for delivery of the email to such a person, please kindly reply to the sender indicating this fact and delete all copies of it from your computer and network server immediately. Your cooperation is highly appreciated. It is advised that any unauthorized use of confidential information of Nuvoton is strictly prohibited; and any information in this email irrelevant to the official business of Nuvoton shall be deemed as neither given nor endorsed by Nuvoton.

Re: [phosphor-logging] About the "Stop emitting Entry propChanged before ifacesAdded" change reason

[Ed Tanous]

On Wed, Oct 20, 2021 at 10:18 AM Patrick Williams <patrick@stwcx.xyz> wrote:
>
> On Wed, Oct 20, 2021 at 10:13:06AM -0500, Matt Spinler wrote:
> > values, and then explicitly emits the IA signal.   Others can chime in,
> > but I didn't see it as proper D-Bus behavior to emit propertiesChanged
> > before InterfacesAdded, since in fact no property is changing after the
> > interface was added.
>
> Correct.  PropertiesChanged signals should not show up before InterfacesAdded.

But they should still show up eventually (after the InterfacesAdded),
right?  The patchset here seems to be under the impression that
PropertyChanged is never emitted when the object is added, which seems
incorrect, or at the very least is a breaking behavioral change.
https://gerrit.openbmc-project.xyz/c/openbmc/bmcweb/+/48231

>
> > It seems like every application does their own thing here, so maybe we
> > can come up with some official best practices for how to emit signals
> > for new interfaces (unless it's there and I missed it).
>
> I'll admit the sdbusplus API is not great for this and a lot of applications do
> it wrong.  There was this issue on the backlog to come up with something
> "better": https://github.com/openbmc/sdbusplus/issues/53
>
> --
> Patrick Williams

Re: [phosphor-logging] About the "Stop emitting Entry propChanged before ifacesAdded" change reason

[Patrick Williams]

[-- Attachment #1: Type: text/plain, Size: 3055 bytes --]

On Thu, Nov 04, 2021 at 12:39:05PM -0700, Ed Tanous wrote:
> On Wed, Oct 20, 2021 at 10:18 AM Patrick Williams <patrick@stwcx.xyz> wrote:
> >
> > On Wed, Oct 20, 2021 at 10:13:06AM -0500, Matt Spinler wrote:
> > > values, and then explicitly emits the IA signal.   Others can chime in,
> > > but I didn't see it as proper D-Bus behavior to emit propertiesChanged
> > > before InterfacesAdded, since in fact no property is changing after the
> > > interface was added.
> >
> > Correct.  PropertiesChanged signals should not show up before InterfacesAdded.
> 
> But they should still show up eventually (after the InterfacesAdded),
> right?  

I'm not positive what you're asking.  Does it happen or should it be done?  What
I tried to describe is what correct behavior would look like.

My understanding is that if you don't have a service name, no signals will be
emitted.  I don't recall where I've seen that in code before.

If you have a service name, but the object does not have an object manager in
the path, then no InterfacesAdded signals will be emitted.  Many processes put
this into the root, so this isn't an issue.

PropertiesChanged and InterfacesAdded are independent from a sd_bus perspective
(and they belong to two different Interfaces anyhow).  If you call
sd_bus_emit_properties_changed before calling sd_bus_emit_interfaces_added or
sd_bus_emit_object_added you will still get signals emitted for the properties
changed (I confirmed this in the systemd repo).

There is no queueing or deferring of the PropertiesChanged signals until after
the InterfacesAdded.

To me, it does not make any sense to emit signals for PropertiesChanged prior to
actually informing the world that the interface exists via InterfacesAdded.
You'll end up sending out signals for properties which nobody even knows they
exist anyhow.

It is _also_ a bad idea to send out InterfacesAdded signals before you have
fully constructed and initialized your object.  This can cause other processes
to act on the property information they received via the InterfacesAdded signal
but with half-constructed / invalid property state.

> The patchset here seems to be under the impression that
> PropertyChanged is never emitted when the object is added, which seems
> incorrect, or at the very least is a breaking behavioral change.
> https://gerrit.openbmc-project.xyz/c/openbmc/bmcweb/+/48231

The PropertyChanged signal is only emitted if the property changes *after* the
object was fully formed (by sending out its InterfacesAdded).  The
PropertyChanged signals are not queued up from the time the object is first
added until after InterfacesAdded is emitted, which is what it sort of sounded
like you were implying might happen.

I'm not sure why you are saying it is breaking behavioral change, other than it
might have use to work this way, but that way it use to work didn't make any
sense from a dbus perspective.  This proposed change in bmcweb seems
conceptually reasonable.

-- 
Patrick Williams

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: [phosphor-logging] About the "Stop emitting Entry propChanged before ifacesAdded" change reason

[Bills, Jason M]

On 11/4/2021 3:19 PM, Patrick Williams wrote:
> On Thu, Nov 04, 2021 at 12:39:05PM -0700, Ed Tanous wrote:
>> On Wed, Oct 20, 2021 at 10:18 AM Patrick Williams <patrick@stwcx.xyz> wrote:
>>>
>>> On Wed, Oct 20, 2021 at 10:13:06AM -0500, Matt Spinler wrote:
>>>> values, and then explicitly emits the IA signal.   Others can chime in,
>>>> but I didn't see it as proper D-Bus behavior to emit propertiesChanged
>>>> before InterfacesAdded, since in fact no property is changing after the
>>>> interface was added.
>>>
>>> Correct.  PropertiesChanged signals should not show up before InterfacesAdded.
>>
>> But they should still show up eventually (after the InterfacesAdded),
>> right?
> 
> I'm not positive what you're asking.  Does it happen or should it be done?  What
> I tried to describe is what correct behavior would look like.
> 
> My understanding is that if you don't have a service name, no signals will be
> emitted.  I don't recall where I've seen that in code before.
> 
> If you have a service name, but the object does not have an object manager in
> the path, then no InterfacesAdded signals will be emitted.  Many processes put
> this into the root, so this isn't an issue.
> 
> PropertiesChanged and InterfacesAdded are independent from a sd_bus perspective
> (and they belong to two different Interfaces anyhow).  If you call
> sd_bus_emit_properties_changed before calling sd_bus_emit_interfaces_added or
> sd_bus_emit_object_added you will still get signals emitted for the properties
> changed (I confirmed this in the systemd repo).
> 
> There is no queueing or deferring of the PropertiesChanged signals until after
> the InterfacesAdded.
> 
> To me, it does not make any sense to emit signals for PropertiesChanged prior to
> actually informing the world that the interface exists via InterfacesAdded.
> You'll end up sending out signals for properties which nobody even knows they
> exist anyhow.
> 
> It is _also_ a bad idea to send out InterfacesAdded signals before you have
> fully constructed and initialized your object.  This can cause other processes
> to act on the property information they received via the InterfacesAdded signal
> but with half-constructed / invalid property state.
> 
>> The patchset here seems to be under the impression that
>> PropertyChanged is never emitted when the object is added, which seems
>> incorrect, or at the very least is a breaking behavioral change.
>> https://gerrit.openbmc-project.xyz/c/openbmc/bmcweb/+/48231
> 
> The PropertyChanged signal is only emitted if the property changes *after* the
> object was fully formed (by sending out its InterfacesAdded).  The
> PropertyChanged signals are not queued up from the time the object is first
> added until after InterfacesAdded is emitted, which is what it sort of sounded
> like you were implying might happen.
> 
> I'm not sure why you are saying it is breaking behavioral change, other than it
> might have use to work this way, but that way it use to work didn't make any
> sense from a dbus perspective.  This proposed change in bmcweb seems
> conceptually reasonable.
> 
I'm not sure if it's what we're talking about here with the behavioral 
change, but in sdbusplus when a new interface is initialized, by default 
it will also send a PropertiesChanged signal for newly added properties.

There is a 'skipPropertyChangedSignal' parameter that can be set to 
'true' to skip the ProperitesChanged and only send InterfacesAdded:
bool initialize(const bool skipPropertyChangedSignal = false)

https://github.com/openbmc/sdbusplus/blob/master/include/sdbusplus/asio/object_server.hpp#L740

I think there are some components that depend on the default behavior 
and only watch for PropertiesChanged rather than InterfacesAdded.

Re: [phosphor-logging] About the "Stop emitting Entry propChanged before ifacesAdded" change reason

[Patrick Williams]

[-- Attachment #1: Type: text/plain, Size: 2003 bytes --]

On Thu, Nov 04, 2021 at 03:36:51PM -0600, Bills, Jason M wrote:

> I'm not sure if it's what we're talking about here with the behavioral 
> change, but in sdbusplus when a new interface is initialized, by default 
> it will also send a PropertiesChanged signal for newly added properties.
> 
> There is a 'skipPropertyChangedSignal' parameter that can be set to 
> 'true' to skip the ProperitesChanged and only send InterfacesAdded:
> bool initialize(const bool skipPropertyChangedSignal = false)
> 
> https://github.com/openbmc/sdbusplus/blob/master/include/sdbusplus/asio/object_server.hpp#L740
> 
> I think there are some components that depend on the default behavior 
> and only watch for PropertiesChanged rather than InterfacesAdded.

This behavior is only in the ASIO object_server implementation, which means it
only covers a subset of daemons.  I really don't know why this was ever added.
There is nothing in the dbus spec to suggest that you should emit a flood of
PropertyChanged signals when starting up.  Maybe this is part of the cause of
some of the boot up performance issues.

We should probably change the defaults to `true` on this and see what breaks.
The commit[1] where this 'skipPropertyChangedSignal' argument was added gave
this as the rationale:

    InterfacesAdded signal itself will send out all propety
    details and it's values during start-up of a D-Bus daemon service.
    Sending properties changed signal confuses the signal handler
    as it can't differentiate between service restart or real
    property change event.

The original code that added the `initialize` method and the
send-signals-for-all-properties behavior was the very first commit[2] James made
so it doesn't give us a whole lot of history or rationale.

1. https://github.com/openbmc/sdbusplus/commit/1ecde800380fbe9c9ce7c8a908aa55aeddb92c1d
2. https://github.com/openbmc/sdbusplus/commit/fce038ad5ac9f458b03d55b441253a9c05dadc3e

-- 
Patrick Williams

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: [phosphor-logging] About the "Stop emitting Entry propChanged before ifacesAdded" change reason

[Ed Tanous]

On Thu, Nov 4, 2021 at 2:19 PM Patrick Williams <patrick@stwcx.xyz> wrote:
>
> On Thu, Nov 04, 2021 at 12:39:05PM -0700, Ed Tanous wrote:
> > On Wed, Oct 20, 2021 at 10:18 AM Patrick Williams <patrick@stwcx.xyz> wrote:
> > >
> > > On Wed, Oct 20, 2021 at 10:13:06AM -0500, Matt Spinler wrote:
> > > > values, and then explicitly emits the IA signal.   Others can chime in,
> > > > but I didn't see it as proper D-Bus behavior to emit propertiesChanged
> > > > before InterfacesAdded, since in fact no property is changing after the
> > > > interface was added.
> > >
> > > Correct.  PropertiesChanged signals should not show up before InterfacesAdded.
> >
> > But they should still show up eventually (after the InterfacesAdded),
> > right?
>
> I'm not positive what you're asking.  Does it happen or should it be done?  What
> I tried to describe is what correct behavior would look like.
>
> My understanding is that if you don't have a service name, no signals will be
> emitted.  I don't recall where I've seen that in code before.
>
> If you have a service name, but the object does not have an object manager in
> the path, then no InterfacesAdded signals will be emitted.  Many processes put
> this into the root, so this isn't an issue.
>
> PropertiesChanged and InterfacesAdded are independent from a sd_bus perspective
> (and they belong to two different Interfaces anyhow).  If you call
> sd_bus_emit_properties_changed before calling sd_bus_emit_interfaces_added or
> sd_bus_emit_object_added you will still get signals emitted for the properties
> changed (I confirmed this in the systemd repo).
>
> There is no queueing or deferring of the PropertiesChanged signals until after
> the InterfacesAdded.
>
> To me, it does not make any sense to emit signals for PropertiesChanged prior to
> actually informing the world that the interface exists via InterfacesAdded.
> You'll end up sending out signals for properties which nobody even knows they
> exist anyhow.
>
> It is _also_ a bad idea to send out InterfacesAdded signals before you have
> fully constructed and initialized your object.  This can cause other processes
> to act on the property information they received via the InterfacesAdded signal
> but with half-constructed / invalid property state.
>
> > The patchset here seems to be under the impression that
> > PropertyChanged is never emitted when the object is added, which seems
> > incorrect, or at the very least is a breaking behavioral change.
> > https://gerrit.openbmc-project.xyz/c/openbmc/bmcweb/+/48231
>
> The PropertyChanged signal is only emitted if the property changes *after* the
> object was fully formed (by sending out its InterfacesAdded).  The
> PropertyChanged signals are not queued up from the time the object is first
> added until after InterfacesAdded is emitted, which is what it sort of sounded
> like you were implying might happen.
>

My only concern here is that this would require everyone that
implements a Log to implement ObjectManager, which might be
reasonable, but we should document as part of which interfaces
actually REQUIRE ObjectManager.  As written, the above patch would
break if a logging implementation chose to not implement
ObjectManager, which I think is legal in the dbus interfaces today.
This I think is the first place where we would explicitly require an
object manager (maybe we did before for sensors?).

> I'm not sure why you are saying it is breaking behavioral change, other than it
> might have use to work this way, but that way it use to work didn't make any
> sense from a dbus perspective.

I say breaking change as in there was a user facing feature that is
now broken because of this patch.  I'm not making any statement about
which is correct in terms of the dbus interface.  Maybe "regression"
is the better word?

> This proposed change in bmcweb seems
> conceptually reasonable.
>
> --
> Patrick Williams