Re: Adding support for custom SEL records

[Patrick Williams <patrick@stwcx.xyz>]

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

On Wed, Oct 19, 2022 at 09:50:47AM -0600, Bills, Jason M wrote:

> Intel had a requirement to support storing at least 4000 log entries. 
> At the time, we were able to get about 400 entries on D-Bus before D-Bus 
> performance became unusable.
> 
> That was before dbus-broker, so it could perhaps be better today.

I was surprised that there would be much performance impact to dbus as a
whole because there should not be any impact to the bus because one
process decided to host a bunch of objects.  I can understand _that_
process becoming slower if there are algorithmic problems with it.

I did an experiment on an AST2600 system where I modified phosphor-logging
to support 20k log entries and then created 10k of them.

```
$ cat meta-facebook/recipes-phosphor/logging/phosphor-logging_%.bbappend
FILESEXTRAPATHS:prepend := "${THISDIR}/${PN}:"

EXTRA_OEMESON += "-Derror_cap=20000"
```

What I've found can be summarized as follows:

   - Overall there is no impact to the dbus by creating a large number
     of log entries.  Interactions with other daemons happen just fine
     with no performance impact.

   - Creating 10k log entries does take a while.  Most of this time is
     observed (via top) in jffs2 but there is also some peaky objmgr
     activity.  There might be some improvements to be had there, but I
     don't think anyone is intending to create 10k events in the span of
     a minute.

   - Dumping all the events from phosphor-logging is slow when there are
     10k of them.  It took 8-11s.  I didn't have `strace` installed, but
     it seemed like much of this was coming from `busctl` processing the
     result and not from the bus transfer itself, but more investigation
     would be required.

   - Deleting all 10k of the events timed out at a dbus level, but still
     succeeded.  Almost all of the time was spent in jffs2.

I'm not suggesting there aren't optimizations we can do to
phosphor-logging, but it doesn't seem like dbus itself is a direct
concern.

```
    # busctl call xyz.openbmc_project.Logging \
            /xyz/openbmc_project/logging \
            xyz.openbmc_project.Collection.DeleteAll \
            DeleteAll

    # time busctl call xyz.openbmc_project.Logging \
            /xyz/openbmc_project/logging \
            org.freedesktop.DBus.ObjectManager \
            GetManagedObjects > /dev/null

    real    0m0.017s
    user    0m0.015s
    sys    0m0.001s

    # time busctl tree xyz.openbmc_project.VirtualSensor > /dev/null

    real    0m0.025s
    user    0m0.019s
    sys    0m0.001s    

    ### Create 10000 log entries.
    # for i in $(seq 0 10000) ; do busctl call \
        xyz.openbmc_project.Logging /xyz/openbmc_project/logging \
        xyz.openbmc_project.Logging.Create Create ssa{ss} \
        "Hello.$i" \
        "xyz.openbmc_project.Logging.Entry.Level.Warning" 0 ;
      done

    # time busctl call xyz.openbmc_project.Logging \
            /xyz/openbmc_project/logging \
            org.freedesktop.DBus.ObjectManager \
            GetManagedObjects > /dev/null

    real    0m11.722s
    user    0m9.130s
    sys    0m0.071s

    # time busctl tree xyz.openbmc_project.VirtualSensor > /dev/null

    real    0m0.024s
    user    0m0.019s
    sys    0m0.001s
```

-- 
Patrick Williams

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