Rudder

Is there something special with these inventories?

Is it easely reproducible (or something link to the system state, like load, etc) ?

There are a lot of virtual machines there - hence the slowing

on 5.0, it still happens

15:16:43.247 [monix-io-37]     TRACE inventory-processing - Start post processing of inventory 'rmm-xxxxxxxxx-xxxxxxxx.ocs' for node 'yyyyyy-yyyyyyyy'
15:16:43.248 [inventory-wait-sig-32] DEBUG inventory-processing - Inventory 'rmm-xxxxxxxxx-xxxxxxxx.ocs' for node 'yyyyyy-yyyyyyyy' pre-processed in 1 second and 147 milliseconds ms
15:16:43.248 [monix-io-37]     TRACE com.normation.inventory.ldap.provisioning.DefaultReportSaver - Precommit 'pre_commit_inventory:check_os_type_is_known': 0 ms
15:16:43.250 [inventory-wait-sig-32] TRACE inventory-processing - Inventory 'rmm-xxxxxxxxx-xxxxxxxx.ocs' for Node 'yyyyyy-yyyyyyyy' added to processing queue.
15:16:53.788 [monix-io-37]     TRACE com.normation.inventory.ldap.provisioning.DefaultReportSaver - Precommit 'pre_commit_inventory:merge_uuid': 10540 ms
15:16:53.788 [monix-io-37]     TRACE com.normation.inventory.ldap.provisioning.DefaultReportSaver - Precommit 'pre_commit_inventory:check_machine_cn': 0 ms
15:16:53.788 [monix-io-37]     TRACE com.normation.inventory.ldap.provisioning.DefaultReportSaver - Precommit 'pre_commit_inventory:set_last_inventory_date': 0 ms
15:16:53.788 [monix-io-37]     TRACE com.normation.inventory.ldap.provisioning.DefaultReportSaver - Precommit 'pre_commit_inventory:add_ip_values': 0 ms
15:16:53.790 [monix-io-37]     TRACE com.normation.inventory.ldap.provisioning.DefaultReportSaver - Precommit 'pre_commit_inventory:log_inventory': 1 ms
15:16:53.791 [monix-io-37]     TRACE com.normation.inventory.ldap.provisioning.DefaultReportSaver - Pre commit report: 10543 ms
15:16:53.791 [monix-io-37]     TRACE com.normation.inventory.ldap.provisioning.DefaultReportSaver - Saving software: 0 ms
15:16:53.830 [monix-io-37]     TRACE com.normation.inventory.ldap.provisioning.DefaultReportSaver - Saving machine: 39 ms
15:16:53.932 [monix-io-37]     TRACE com.normation.inventory.ldap.provisioning.DefaultReportSaver - Saving node: 102 ms
15:16:53.933 [monix-io-37]     TRACE com.normation.inventory.ldap.provisioning.DefaultReportSaver - Saving vms: 1 ms
15:16:53.934 [monix-io-37]     TRACE com.normation.inventory.ldap.provisioning.DefaultReportSaver - Commit report: 144 ms
15:16:53.936 [monix-io-37]     TRACE com.normation.inventory.ldap.provisioning.DefaultReportSaver - Post commit report: 2 ms
15:16:53.937 [monix-io-37]     DEBUG inventory-processing - Report saved.
15:16:53.937 [monix-io-37]     INFO  inventory-processing - Report 'rmm-xxxxxxxxx-xxxxxxxx.ocs' for node 'rmm-p1196662pl.ads.local' [yyyyyy-yyyyyyyy] (signature:undefined) processed in 10 seconds and 690 milliseconds ms

the cost is in this part

    val mergedSoftwares = softwareIdFinder.tryWith(report.applications.toSet) match {
      case eb: EmptyBox =>
        val e = eb ?~! "Error when trying to find existing software UUIDs" 
        logger.error(e.messageChain)
        return e
      case Full(s) => s
    }

DEBUG com.normation.inventory.ldap.provisioning.UuidMergerPreCommit - merge software 10853 ms

adding indexes
index cn eq
index softwareVersion eq

makes it goes from 10s to 860ms

we used to haveindex, then removed them by replacing them by caching https://issues.rudder.io/issues/5965
now we use mdb, which doesn't have cache. Maybe adding indexes would be a good idea...

I've been playing with method NameAndVersionIdFinder.tryWith , to make it faster, and I'm facing a puzzle: batching the query makes ldap faster (559ms vs 10s), yet the whole method is slower: either foldLeft or flatMap gets much slower. Actually, that's because it starts returning data as soon as it gets some, and slapd continues in background to process the data

so here the only solution I have is to add more indexes

adding more RAM and CPUs to the system marginally improve perfs.
As data all fit in RAM, i don't get to read from disk, but slapd is still crunhcing at 80-100% CPUs while processing data

SO, I was able to make 6.2 quick.

For that, I:

- copied binaries from VM6.1 /opt/rudder/libexec, /opt/rudder/lib/liblmdb.so, /opt/rudder/lib/ldap
- copied data from VM6.1: /var/rudder/ldap/openldap-data
- restart everything.

Things are very quick at first (a lot in 100 ms range), and then seems to stabiliez around 1-2s (perhaps it's just due to inventories number of software. Since it's real data, they may have an impact).

BUT: when I switched just the lmdb binary back to 6.2, things get much worse, and switching again to 6.1 didn't heal them. I had to restart with data from 6.1 too. So it seems that lmdb binary or something in rudder code 6.2 make things go slower in a way that I still don't know how to reverse.

I confirm that I can add as many inventories as I want in VM6.1 with code from HEAD 6.2 and the timing are:

- majority 50-150ms,
- 99% < 300ms
- max 800ms

So, I copied inventory.schem and rudder.schem in VM6.1 and I lost one order of magnitude in perf:

- 5% <1s
- majority between 2-6s
- some up to 8-10s

It may be because a lot of software must be updated to add `sourceName` and `sourceVersion` attributes, but there may be more to that too.

SO.

There is a problem in the merge of software and they are never merged, always new one are created. That cause explosion in the number of software and saving soft is slower than doing nothing in any case.

This bug has been fixed in Rudder 6.2.1 which was released today.

• 6.2.1 changelog
• Upgrade manual