[dev.icinga.com #8488] Figure out why 'node update-config' becomes slow over time

[icinga-migration]

This issue has been migrated from Redmine: https://dev.icinga.com/issues/8488

Created by mfriedrich on 2015-02-20 08:49:37 +00:00

Assignee: mfriedrich
Status: Resolved (closed on 2015-02-23 14:54:55 +00:00)
Target Version: 2.3.0
Last Update: 2015-02-23 14:55:05 +00:00 (in Redmine)

Icinga Version: 2.2.0-495-g09204e8
Backport?: Not yet backported
Include in Changelog: 1

---

Once generating a large change set from the api repository, we'll run into performance issues with inserting new changes.

There are 2 possible bottlenecks already identified:

• CheckChangeExists() always parses the entire file set (that should be cached in a local array)
• GetObjects() always parses the file structure of available config files in repository.d (that is already read inside the update-config command, and should be passed directly)

Though there is more to profile and possibly fix.

Attachments

• Auswahl_201.png mfriedrich - 2015-02-20 19:19:03 +00:00
• Auswahl_202.png mfriedrich - 2015-02-20 20:04:15 +00:00

Changesets

2015-02-20 16:05:00 +00:00 by mfriedrich 9ae9204

Cli: Don't parse objects/changes on each AddObject() call

refs #8488

2015-02-20 20:01:07 +00:00 by mfriedrich 23005e1

Cli: Don't validate config objects in 'node update-config'

refs #8488

2015-02-20 20:34:59 +00:00 by mfriedrich 4e1c754

Cli: Don't validate config objects in 'node update-config'

refs #8488

[icinga-migration]

Updated by mfriedrich on 2015-02-20 16:35:21 +00:00

One possible spot: GetBlackAndWhiteList() gets called each time a blacklist is checked against.

[icinga-migration]

Updated by mfriedrich on 2015-02-20 19:19:45 +00:00

• File added Auswahl_201.png

  #!/bin/bash

  valgrind
  -v
  --trace-children=yes
  --tool=callgrind
  --simulate-cache=yes
  --collect-jumps=yes
  --dump-instr=yes
  --dump-line=yes
  /home/michi/coding/icinga/icinga2/debug/Bin/Debug/icinga2 node update-config

AddObject() calls the config validation every time (which is only reasonable when adding objects through the cli command line).

[icinga-migration]

Updated by mfriedrich on 2015-02-20 20:04:29 +00:00

• File added Auswahl_202.png

After disabling the config validation for node update-config (we know what we dump), the problem goes further with CheckChangeExists and the Dictionary items being fetched.

[icinga-migration]

Updated by mfriedrich on 2015-02-20 20:08:40 +00:00

real    0m9.590s
user    0m9.034s
sys 0m0.415s
nbmif ~ # time icinga2 node update-config 

information/ConfigItem: Checked 1 ApiListener(s).
information/ConfigItem: Checked 5 Endpoint(s).
information/ConfigItem: Checked 5 Zone(s).
information/ConfigItem: Checked 45 CheckCommand(s).
information/ConfigItem: Checked 2 NotificationCommand(s).
information/ConfigItem: Checked 3 TimePeriod(s).
information/ConfigItem: Checked 1 CheckerComponent(s).
information/ConfigItem: Checked 1 ExternalCommandListener(s).
information/ConfigItem: Checked 2 FileLogger(s).
information/ConfigItem: Checked 1 IdoMysqlConnection(s).
information/ConfigItem: Checked 1 LivestatusListener(s).
information/ConfigItem: Checked 1 NotificationComponent(s).
information/ConfigItem: Checked 1 StatusDataWriter(s).
information/ConfigItem: Checked 65 Host(s).
information/ConfigItem: Checked 1422 Service(s).
information/ConfigItem: Checked 2 HostGroup(s).
information/ConfigItem: Checked 3 ServiceGroup(s).
information/ConfigItem: Checked 1 User(s).
information/ConfigItem: Checked 12 Notification(s).
information/ConfigItem: Checked 1 UserGroup(s).
information/ConfigItem: Checked 1 IcingaApplication(s).
information/ConfigItem: Checked 60 Dependency(s).

[icinga-migration]

Updated by mfriedrich on 2015-02-20 20:34:20 +00:00

Previous run took hours, now its down to 23 minutes for 20k objects.

real    22m29.284s
user    22m18.931s
sys 0m7.281s

information/ConfigItem: Checked 1 ApiListener(s).
information/ConfigItem: Checked 5 Endpoint(s).
information/ConfigItem: Checked 5 Zone(s).
information/ConfigItem: Checked 45 CheckCommand(s).
information/ConfigItem: Checked 2 NotificationCommand(s).
information/ConfigItem: Checked 3 TimePeriod(s).
information/ConfigItem: Checked 1 CheckerComponent(s).
information/ConfigItem: Checked 1 ExternalCommandListener(s).
information/ConfigItem: Checked 2 FileLogger(s).
information/ConfigItem: Checked 1 IdoMysqlConnection(s).
information/ConfigItem: Checked 1 LivestatusListener(s).
information/ConfigItem: Checked 1 NotificationComponent(s).
information/ConfigItem: Checked 1 StatusDataWriter(s).
information/ConfigItem: Checked 3005 Host(s).
information/ConfigItem: Checked 17032 Service(s).
information/ConfigItem: Checked 2 HostGroup(s).
information/ConfigItem: Checked 3 ServiceGroup(s).
information/ConfigItem: Checked 1 User(s).
information/ConfigItem: Checked 12 Notification(s).
information/ConfigItem: Checked 1 UserGroup(s).
information/ConfigItem: Checked 1 IcingaApplication(s).
information/ConfigItem: Checked 3000 Dependency(s).

[icinga-migration]

Updated by mfriedrich on 2015-02-20 20:38:02 +00:00

• Assigned to changed from mfriedrich to tobiasvdk
• Target Version set to 2.3.0

Please test the recent patches.

[icinga-migration]

Updated by tobiasvdk on 2015-02-23 14:43:47 +00:00

• Assigned to changed from tobiasvdk to mfriedrich

It's much faster now. I don't have the exact time before the patch because it took more than 10 minutes (and I killed the task).

$ time sudo icinga2 node update-config



real    2m49.901s
user    2m44.804s
sys 0m3.864s

$ sudo icinga2 object list | grep -c ^Object
69040

[icinga-migration]

Updated by mfriedrich on 2015-02-23 14:54:55 +00:00

• Status changed from Assigned to Resolved
• Done % changed from 0 to 100