Delayed match callback with sdbusplus asio APIs

[Lei Yu]

This mail is to describe an issue that the match signal's callback is
delayed if it's using sdbusplus asio APIs.

# TL;DR
If the app is using sync DBus calls and using asio to register a match
callback, the callback may be delayed if it occurs when the sync DBus
call is ongoing.
Note the issue does not occur if it's not using asio APIs.

# Details

Pasted a full buildable source at https://pastebin.com/KEmpvDzp
The code
* Registers a match for host power status, and print the changes.
* Uses a timer to get sensors via sync DBus calls.

With this code, it's very easy to reproduce the above issue in QEMU,
just toggle the `RequestedHostTransition` to On and Off for a few
times:
# busctl set-property xyz.openbmc_project.State.Host0
/xyz/openbmc_project/state/host0 xyz.openbmc_project.State.Host
RequestedHostTransition s xyz.openbmc_project.State.Host.Transition.On
# busctl set-property xyz.openbmc_project.State.Host0
/xyz/openbmc_project/state/host0 xyz.openbmc_project.State.Host
RequestedHostTransition s
xyz.openbmc_project.State.Host.Transition.Off

We can see the journal logs:
# journalctl | grep -e test_asio -e "Moving to \"Off" -e "POWER_OUT set to 0"
Mar 11 04:59:25 power-control[195]: POWER_OUT set to 0
Mar 11 04:59:25 test_asio[23478]: aiso callback, property:
RequestedHostTransition, value:
xyz.openbmc_project.State.Host.Transition.On
Mar 11 04:59:33 power-control[195]: Host0: Moving to "Off" state
Mar 11 04:59:37 power-control[195]: POWER_OUT set to 0
Mar 11 04:59:45 power-control[195]: Host0: Moving to "Off" state
Mar 11 04:59:48 power-control[195]: POWER_OUT set to 0
Mar 11 04:59:56 test_asio[23478]: aiso callback, property:
RequestedHostTransition, value:
xyz.openbmc_project.State.Host.Transition.Off
Mar 11 04:59:56 test_asio[23478]: aiso callback, property:
RequestedHostTransition, value:
xyz.openbmc_project.State.Host.Transition.On
Mar 11 04:59:56 test_asio[23478]: aiso callback, property:
RequestedHostTransition, value:
xyz.openbmc_project.State.Host.Transition.Off
Mar 11 04:59:56 test_asio[23478]: aiso callback, property:
RequestedHostTransition, value:
xyz.openbmc_project.State.Host.Transition.On
Mar 11 04:59:56 test_asio[23478]: aiso callback, property:
RequestedHostTransition, value:
xyz.openbmc_project.State.Host.Transition.Off
Mar 11 04:59:56 power-control[195]: Host0: Moving to "Off" state

In the log, `POWER_OUT set to 0` means RequestedHostTransition is set
to On, and `Host0: Moving to "Off" state` means it's set to Off.
You can see that test_asio's callback is not triggered during
04:59:33~04:59:48, and it's triggered for multiple times on 04:59:56.

# More info
* If the sync DBus calls are removed, the issue is not reproduced.
* If I do not use asio at all, and use sync DBus calls with
`sdeventplus::utility::Timer`, the issue is not reproduced.

That is to say, this issue only occurs when asio and sync DBus calls are mixed.


@Ed Tanous @William Kennington @Patrick Williams Could you kindly
check the above behavior and let's see what could be wrong?

Thanks!

-- 
BRs,
Lei YU