sendChunk, releaseChunk latencies

[niclar]

Required information

Operating system: Ubuntu 22.04.4 LTS

Compiler version: clang 18.1.4

Eclipse iceoryx version: main / b9ab7ee6ce1835c63b3fc7fb4033c31e4418d5cd

Observed result or behaviour:

Function = iox::popo::PublisherPortUser::tryAllocateChunk(unsigned long, unsigned int, unsigned int, unsigned int) [1110310]
     nsecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 0        |                                        |
      1024 -> 2047       : 0        |                                        |
      2048 -> 4095       : 948      |****************************************|
      4096 -> 8191       : 9        |                                        |
      8192 -> 16383      : 5        |                                        |

avg = 5813 nsecs, total: 23929310 nsecs, count: 4116

Function = iox::popo::PublisherPortUser::sendChunk(iox::mepoo::ChunkHeader*) [1110310]
     nsecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 0        |                                        |
      1024 -> 2047       : 0        |                                        |
      2048 -> 4095       : 0        |                                        |
      4096 -> 8191       : 4        |*                                       |
      8192 -> 16383      : 123      |****************************************|
     16384 -> 32767      : 70       |**********************                  |
     32768 -> 65535      : 3        |                                        |
     65536 -> 131071     : 1        |                                        |

Expected result or behaviour: sendChunk latencies are way up there (as is tryAllocateChunk in my mind), especially the tails, even though we're sending with ~1000 untyped publishers split over four threads all set to iox::popo::ConsumerTooSlowPolicy::DISCARD_OLDEST_DATA (& historyCapacity = 0)

Conditions where it occurred / Performed steps: Publishing with high frequency

Additional helpful information

Built with;

            -DINTROSPECTION=ON
            -DIOX_MAX_PUBLISHERS=4096
            -DIOX_MAX_SUBSCRIBERS=4096
            -DIOX_MAX_SUBSCRIBERS_PER_PUBLISHER=64
            -DIOX_MAX_CHUNKS_ALLOCATED_PER_PUBLISHER_SIMULTANEOUSLY=16
            -DIOX_MAX_CHUNKS_HELD_PER_SUBSCRIBER_SIMULTANEOUSLY=256
            -DIOX_MAX_CLIENTS_PER_SERVER=512
            -DIOX_MAX_NUMBER_OF_NOTIFIERS=512

-Roudi runs on a dedicated core and the publishers on four dedicated cores

[niclar]

got a measurment on the releaseChunk just now, equally bad...

Function = iox::popo::SubscriberPortUser::releaseChunk(iox::mepoo::ChunkHeader const*) [1110310]
     nsecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 0        |                                        |
      1024 -> 2047       : 0        |                                        |
      2048 -> 4095       : 0        |                                        |
      4096 -> 8191       : 14368    |****************************************|
      8192 -> 16383      : 1043     |**                                      |
     16384 -> 32767      : 173      |                                        |
     32768 -> 65535      : 5        |                                        |
     65536 -> 131071     : 1        |                                        |
    131072 -> 262143     : 1        |                                        |

[niclar]

maybe related to https://github.com/eclipse-iceoryx/iceoryx/issues/2221 ? -Because slow consumers (with the DISCARD_OLDEST_DATA setting on publisher & subscriber, and subscriber queueCapacity=256) can't ever trigger this right ?

[elBoberido]

I don't think it is related to #2221 since it also effects the allocation not only the release of the chunks.

Do the publisher allocate from the same mempool? If this is the case, they compete for the same chunk and there is also high contention which slow down each other. You could try to create multiple mempools with slightly different chunk sizes and let each core allocate from a different mempool.

Do you also use the WaitSet/Listener? This might introduce additional latencies due to context switches.

How many subscriber does a publisher have?

Do you have multiple publisher publishing to the same topic?

[elBoberido]

Oh, can you also check with dmesg whether the TSC clock is deactivated?

It would also be helpful to check with https://github.com/KDAB/hotspot where the bottleneck lies.

It helped us to indemnify why my new shiny AMD Ryzen laptop was slower with iceoryx2 than my 6 year old Intel Laptop. It seems on some AMD CPUs the TSC clock is deactivated which results in a context switch each time clock_gettime was used.

[niclar]

Thanks for the reply. The publishers allocate the same two sized chunks yes (size2, size3). It's a bit unpractical to add padding just to facilitate mempool partitioning though. If contention can lead to significant overhead I guess the framework should maybe provide support for mempool partitioning (by id or name) ? (On a related issue we'll jack in a blocking notification callback and issue a PR.)

Yes using the 4 listeners on separate cores in this case receiving high frequency publications (size1). Will try investigate the overhead of that using hotspot...

Half of the publishers per core/listener have one subscriber (size3) the other half three subscribers (size2).

There's one publisher publishing on a shared topic (alerts) but it does so very infrequent and not during the above measurements.

The TSC clock is active on our EPYC CPU.

[elBoberido]

The issue with the contention is fixed in iceoryx2. There, each publisher has it's own data segment. With iceoryx2 we try to fix all the issues which user encounter when iceoryx is pushed to its limits.