Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Already on GitHub? Sign in to your account

[dev.icinga.com #12147] IDO module starts threads before daemonize #4363

Closed
icinga-migration opened this Issue Jul 13, 2016 · 34 comments

Comments

Projects
None yet
1 participant
Member

icinga-migration commented Jul 13, 2016

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

Created by tim_1740 on 2016-07-13 12:35:29 +00:00

Assignee: tim_1740
Status: Resolved (closed on 2016-08-17 15:29:41 +00:00)
Target Version: 2.5.0
Last Update: 2016-08-22 11:45:43 +00:00 (in Redmine)

Icinga Version: 2.4.10
Backport?: Not yet backported
Include in Changelog: 1

Hello,

We are migrating from icinga1 to icinga2, but we are facing a problem.

Our server seems to be powerfull enough (8Go RAM and 12 CPU).

With 27000 services and 663 hosts, it works.

Daemon logs :

[2016-07-13 11:22:29 +0200] information/ConfigItem: Committing config items
[2016-07-13 11:22:36 +0200] information/ConfigItem: Instantiated 2 FileLoggers.
[2016-07-13 11:22:36 +0200] information/ConfigItem: Instantiated 1 Zone.
[2016-07-13 11:22:36 +0200] information/ConfigItem: Instantiated 1 Endpoint.
[2016-07-13 11:22:36 +0200] information/ConfigItem: Instantiated 142 CheckCommands.
[2016-07-13 11:22:36 +0200] information/ConfigItem: Instantiated 2 NotificationCommands.
[2016-07-13 11:22:36 +0200] information/ConfigItem: Instantiated 1 IcingaApplication.
[2016-07-13 11:22:36 +0200] information/ConfigItem: Instantiated 663 Hosts.
[2016-07-13 11:22:36 +0200] information/ConfigItem: Instantiated 3 HostGroups.
[2016-07-13 11:22:36 +0200] information/ConfigItem: Instantiated 1 User.
[2016-07-13 11:22:36 +0200] information/ConfigItem: Instantiated 1 UserGroup.
[2016-07-13 11:22:36 +0200] information/ConfigItem: Instantiated 27402 Services.
[2016-07-13 11:22:36 +0200] information/ConfigItem: Instantiated 3 TimePeriods.
[2016-07-13 11:22:36 +0200] information/ConfigItem: Instantiated 7 ServiceGroups.
[2016-07-13 11:22:36 +0200] information/ConfigItem: Instantiated 1 ExternalCommandListener.
[2016-07-13 11:22:36 +0200] information/ConfigItem: Instantiated 1 IdoMysqlConnection.
[2016-07-13 11:22:36 +0200] information/ScriptGlobal: Dumping variables to file '/var/cache/icinga2/icinga2.var s'
[2016-07-13 11:22:36 +0200] information/ConfigObject: Restoring program state from file '/var/lib/icinga2/icing a2.state'
[2016-07-13 11:22:37 +0200] information/ConfigObject: Restored 28231 objects. Loaded 0 new objects without stat e.
[2016-07-13 11:22:37 +0200] information/ConfigItem: Triggering Start signal for config items
[2016-07-13 11:22:38 +0200] information/ConfigItem: Activated all objects.

Debug logs :

[2016-07-13 11:22:37 +0200] debug/TimePeriod: ---
[2016-07-13 11:22:38 +0200] information/ConfigItem: Activated all objects.
[2016-07-13 11:22:38 +0200] information/DbConnection: Resuming IDO connection: ido-mysql
[2016-07-13 11:22:38 +0200] debug/IdoMysqlConnection: Query: SELECT @@global.max_allowed_packet AS max_allowed_packet
[2016-07-13 11:22:38 +0200] debug/IdoMysqlConnection: Query: SELECT version FROM icinga_dbversion WHERE name='idoutils'
[2016-07-13 11:22:38 +0200] debug/IdoMysqlConnection: Query: SELECT instance_id FROM icinga_instances WHERE instance_name = '*****'
[2016-07-13 11:22:38 +0200] information/IdoMysqlConnection: MySQL IDO instance id: 1 (schema version: '1.14.0')
[2016-07-13 11:22:38 +0200] debug/IdoMysqlConnection: Query: SET SESSION TIME_ZONE='+00:00'
[2016-07-13 11:22:38 +0200] debug/IdoMysqlConnection: Query: BEGIN
[2016-07-13 11:22:38 +0200] notice/DbConnection: Updating programstatus table.
[2016-07-13 11:22:38 +0200] debug/IdoMysqlConnection: Query: COMMIT
[2016-07-13 11:22:38 +0200] debug/IdoMysqlConnection: Query: BEGIN
[2016-07-13 11:22:38 +0200] debug/IdoMysqlConnection: Query: INSERT INTO icinga_conninfo (instance_id, connect_time, last_checkin_time, agent_name, agent_version, connect_type, data_start_time) VALUES (1, NOW (), NOW(), 'icinga2 db_ido_mysql', 'v2.4.10', 'INITIAL', NOW ())
[2016-07-13 11:22:38 +0200] debug/IdoMysqlConnection: Query: DELETE FROM icinga_contact_addresses WHERE instance_id = 1
... Databases updates ...

As you can see, objects are all activated and then the database is updated with this objects.

But when we have a larger scope (3800 hosts, 175000 services), the database is never updated.

Daemon logs :

[2016-07-13 11:46:52 +0200] information/ConfigItem: Committing config items
[2016-07-13 11:47:22 +0200] information/DbConnection: Resuming IDO connection: ido-mysql (* not present in previous logs *)
[2016-07-13 11:49:04 +0200] information/ConfigItem: Instantiated 2 FileLoggers.
[2016-07-13 11:49:04 +0200] information/ConfigItem: Instantiated 1 Zone.
[2016-07-13 11:49:04 +0200] information/ConfigItem: Instantiated 1 Endpoint.
[2016-07-13 11:49:04 +0200] information/ConfigItem: Instantiated 142 CheckCommands.
[2016-07-13 11:49:04 +0200] information/ConfigItem: Instantiated 2 NotificationCommands.
[2016-07-13 11:49:04 +0200] information/ConfigItem: Instantiated 1 IcingaApplication.
[2016-07-13 11:49:04 +0200] information/ConfigItem: Instantiated 3822 Hosts.
[2016-07-13 11:49:04 +0200] information/ConfigItem: Instantiated 69 HostGroups.
[2016-07-13 11:49:04 +0200] information/ConfigItem: Instantiated 1 User.
[2016-07-13 11:49:04 +0200] information/ConfigItem: Instantiated 1 UserGroup.
[2016-07-13 11:49:04 +0200] information/ConfigItem: Instantiated 175563 Services.
[2016-07-13 11:49:04 +0200] information/ConfigItem: Instantiated 3 TimePeriods.
[2016-07-13 11:49:04 +0200] information/ConfigItem: Instantiated 21 ServiceGroups.
[2016-07-13 11:49:04 +0200] information/ConfigItem: Instantiated 1 ExternalCommandListener.
[2016-07-13 11:49:04 +0200] information/ConfigItem: Instantiated 1 IdoMysqlConnection.
[2016-07-13 11:49:04 +0200] information/ScriptGlobal: Dumping variables to file '/var/cache/icinga2/icinga2.vars'
[2016-07-13 11:49:04 +0200] information/ConfigObject: Restoring program state from file '/var/lib/icinga2/icinga2.state'
[2016-07-13 11:49:05 +0200] information/ConfigObject: Restored 28231 objects. Loaded 151400 new objects without state.
[2016-07-13 11:49:05 +0200] information/ConfigItem: Triggering Start signal for config items
[2016-07-13 11:49:12 +0200] information/ConfigItem: Activated all objects.

Debug logs :

[2016-07-13 11:49:05 +0200] debug/TimePeriod: ---
[2016-07-13 11:49:12 +0200] notice/WorkQueue: #2 tasks: 16
[2016-07-13 11:49:12 +0200] information/ConfigItem: Activated all objects.
[2016-07-13 11:49:12 +0200] debug/IcingaApplication: In IcingaApplication::Main()
[2016-07-13 11:49:12 +0200] information/ConfigCompiler: Compiling config file: /var/lib/icinga2/modified-attributes.conf
[2016-07-13 11:49:13 +0200] notice/DbConnection: Updating programstatus table.
[2016-07-13 11:49:20 +0200] notice/ThreadPool: Pool #1: Pending tasks: 0; Average latency: 0ms; Threads: 4; Pool utilization: 0.0282933%
[2016-07-13 11:49:22 +0200] notice/DbConnection: Cleanup (downtimehistory): 172800 now: 1468403362 old: 1.46823e+09
[2016-07-13 11:49:22 +0200] notice/DbConnection: Cleanup (logentries): 2.6784e+06 now: 1468403362 old: 1.46572e+09
[2016-07-13 11:49:22 +0200] notice/WorkQueue: #2 tasks: 45
[2016-07-13 11:49:23 +0200] notice/DbConnection: Updating programstatus table.
[2016-07-13 11:49:32 +0200] notice/WorkQueue: #2 tasks: 72
[2016-07-13 11:49:33 +0200] notice/DbConnection: Updating programstatus table.
[2016-07-13 11:49:35 +0200] notice/ThreadPool: Pool #1: Pending tasks: 0; Average latency: 0ms; Threads: 4; Pool utilization: 0.118823%
[2016-07-13 11:49:42 +0200] notice/WorkQueue: #2 tasks: 99
[2016-07-13 11:49:43 +0200] notice/DbConnection: Updating programstatus table.
[2016-07-13 11:49:50 +0200] notice/ThreadPool: Pool #1: Pending tasks: 0; Average latency: 0ms; Threads: 4; Pool utilization: 0.0333518%

As you can see, objects are activated but the database is never update with them. It loops on WorkQueue/ThreadPool/DbConnection messages, and there is a minimal CPU activity. Nothing append. And new services/hosts/objects are not send into database.

Did you already seen this problem ? What could I try ?

Thank you in advance,

Regards,

Tim

Attachments

Changesets

2016-07-13 12:44:53 +00:00 by gbeutner 1bd235b

Improve IDO performance

refs #12147

2016-07-15 07:40:39 +00:00 by gbeutner 959e250

Avoid duplicate entries in the icinga_objects table for commands

refs #12147

2016-08-02 12:27:20 +00:00 by mfriedrich 53930e3

DB IDO: Ensure that queries are not executed if categories don't match

refs #12147
refs #12147

Relations:

Member

icinga-migration commented Jul 13, 2016

Updated by mfriedrich on 2016-07-13 17:37:48 +00:00

  • Priority changed from Normal to High
  • Target Version set to 2.5.0
Member

icinga-migration commented Jul 13, 2016

Updated by mfriedrich on 2016-07-13 17:39:15 +00:00

It would be helpful if you could provide a full gdb backtrace :)

http://docs.icinga.org/icinga2/latest/doc/module/icinga2/toc\#!/icinga2/latest/doc/module/icinga2/chapter/development#development-debug-gdb-backtrace

Member

icinga-migration commented Jul 14, 2016

Updated by elippmann on 2016-07-14 07:42:26 +00:00

  • Status changed from New to Feedback
  • Assigned to set to tim_1740
Member

icinga-migration commented Jul 14, 2016

Updated by mfriedrich on 2016-07-14 08:58:21 +00:00

  • Relates set to 12149
Member

icinga-migration commented Jul 20, 2016

Updated by mfriedrich on 2016-07-20 08:28:51 +00:00

Can you please test the latest snapshot packages as well? :)

Member

icinga-migration commented Jul 25, 2016

Updated by tim_1740 on 2016-07-25 15:38:27 +00:00

How can I get the latest snapshot packages ?
My repo says I am up to date with 2.4.10. (I am on CentOs7)

Member

icinga-migration commented Jul 25, 2016

Updated by mfriedrich on 2016-07-25 15:41:03 +00:00

You'll need to enable the snapshot repository (and disable the release one). Then you may install the icinga2 snapshot packages.

More instructions over here: http://packages.icinga.org/epel/

Member

icinga-migration commented Jul 26, 2016

Updated by tim_1740 on 2016-07-26 08:50:34 +00:00

I tested with the snapshot version but it seems to be the same problem. (It activated all objects, but never update database)

Then I tried with a smaller environment and I had this error, but it seems to be a different problem :

[2016-07-26 10:40:38 +0200] critical/IdoMysqlConnection: Schema version '1.14.0' does not match the required version '1.14.1' (or newer)! Please check the upgrade documentation.

Regards,

Member

icinga-migration commented Jul 28, 2016

Updated by mfriedrich on 2016-07-28 15:15:21 +00:00

The snapshot packages require an updated schema from the 2.5.0.sql file. The schema is compatible to previous versions (2.4.x) so upgrading and downgrading doesn't hurt.

Member

icinga-migration commented Aug 1, 2016

Updated by tim_1740 on 2016-08-01 15:27:06 +00:00

There is a problem with the upgrade sql. Something with default values :
ERROR 1067 (42000) at line 14: Invalid default value for 'status_update_time'
And if I delete the line 14 and 15 for example, there is the same thing just after :
ERROR 1067 (42000) at line 19: Invalid default value for 'entry_time'

But I think that all this is off topic, because with my complete environment, icinga don't even try to update the database.

Member

icinga-migration commented Aug 1, 2016

Updated by mfriedrich on 2016-08-01 16:05:29 +00:00

  • Status changed from Feedback to Assigned
  • Assigned to changed from tim_1740 to mfriedrich

I'm seeing a similar issue with MySQL only.

Patched debug output for analysing the CanExecuteQuery() calls and query queue reordering.

[2016-08-01 17:44:38 +0200] critical/IdoMysqlConnection: Where: Cannot escape field 'contactgroup_id' for table 'contactgroup_members'.
[2016-08-01 17:44:38 +0200] critical/IdoMysqlConnection: Where: Cannot escape field 'contactgroup_id' for table 'contactgroup_members'.
[2016-08-01 17:44:38 +0200] critical/IdoMysqlConnection: Where: Cannot escape field 'contactgroup_id' for table 'contactgroup_members'.
[2016-08-01 17:44:38 +0200] critical/IdoMysqlConnection: Where: Cannot escape field 'contactgroup_id' for table 'contactgroup_members'.
[2016-08-01 17:44:38 +0200] critical/IdoMysqlConnection: Where: Cannot escape field 'contactgroup_id' for table 'contactgroup_members'.
[2016-08-01 17:44:38 +0200] critical/IdoMysqlConnection: Where: Cannot escape field 'contactgroup_id' for table 'contactgroup_members'.
[2016-08-01 17:44:38 +0200] critical/IdoMysqlConnection: Where: Cannot escape field 'contactgroup_id' for table 'contactgroup_members'.
[2016-08-01 17:44:38 +0200] critical/IdoMysqlConnection: Where: Cannot escape field 'servicegroup_id' for table 'servicegroup_members'.
[2016-08-01 17:44:38 +0200] critical/IdoMysqlConnection: Where: Cannot escape field 'service_id' for table 'service_contacts'.
[2016-08-01 17:44:38 +0200] critical/IdoMysqlConnection: Where: Cannot escape field 'service_id' for table 'service_contactgroups'.
[2016-08-01 17:44:38 +0200] critical/IdoMysqlConnection: Where: Cannot escape field 'servicegroup_id' for table 'servicegroup_members'.
[2016-08-01 17:44:38 +0200] critical/IdoMysqlConnection: Where: Cannot escape field 'service_id' for table 'service_contacts'.
[2016-08-01 17:44:38 +0200] critical/IdoMysqlConnection: Where: Cannot escape field 'service_id' for table 'service_contactgroups'.
[2016-08-01 17:44:38 +0200] critical/IdoMysqlConnection: Where: Cannot escape field 'timeperiod_id' for table 'timeperiod_timeranges'.
[2016-08-01 17:44:38 +0200] critical/IdoMysqlConnection: Where: Cannot escape field 'timeperiod_id' for table 'timeperiod_timeranges'.

All of these items are not present in a fresh DB IDO installation, GetOrCreateByObject() still gets called anyways.
The icinga_objects table is correctly filled in although OnConfigUpdate() does not get called when a new config object is inserted into the config tables (and therefore no comments and downtimes e.g.).

Member

icinga-migration commented Aug 2, 2016

Updated by mfriedrich on 2016-08-02 12:28:45 +00:00

  • Status changed from Assigned to Feedback
  • Assigned to changed from mfriedrich to tim_1740

Ok figured it out. My "categories" attribute was not set accordingly which caused multiple re-enqueues due to a recent change in the code. Although the overall insert works fine.

Could you share your current IdoMysqlConnection object configuration (remove sensitive information such as host, user or passwords).

Member

icinga-migration commented Aug 2, 2016

Updated by tim_1740 on 2016-08-02 14:41:02 +00:00

This is my configuration (/etc/icinga2/features-available/ido-mysql.conf) :

/**** The db_ido_mysql library implements IDO functionality for MySQL. */

library "db_ido_mysql"

object IdoMysqlConnection "ido-mysql" {
user = ""
password = "
"
host = "127.0.0.1"
port = ""
database = "icinga"
table_prefix = "icinga_"
instance_name = "
"
instance_description = "icinga2 instance"
cleanup = {
downtimehistory_age = 48h
logentries_age = 31d
}
categories = DbCatConfig | DbCatState
}

Member

icinga-migration commented Aug 2, 2016

Updated by mfriedrich on 2016-08-02 14:55:43 +00:00

Drop "categories" and try again please.

Member

icinga-migration commented Aug 2, 2016

Updated by tim_1740 on 2016-08-02 15:52:20 +00:00

  • File added debug_icinga2.txt

It's the same without categories.

Daemon logs :

[2016-08-02 17:40:59 +0200] information/cli: Icinga application loader (version: v2.4.10-552-gf2bacb2)
[2016-08-02 17:40:59 +0200] information/cli: Loading configuration file(s).
[2016-08-02 17:40:59 +0200] information/ConfigItem: Committing config item(s).
[2016-08-02 17:41:29 +0200] information/DbConnection: Resuming IDO connection: ido-mysql
[2016-08-02 17:43:14 +0200] information/ConfigItem: Instantiated 1 Zone.
[2016-08-02 17:43:14 +0200] information/ConfigItem: Instantiated 2 FileLoggers.
[2016-08-02 17:43:14 +0200] information/ConfigItem: Instantiated 1 Endpoint.
[2016-08-02 17:43:14 +0200] information/ConfigItem: Instantiated 142 CheckCommands.
[2016-08-02 17:43:14 +0200] information/ConfigItem: Instantiated 2 NotificationCommands.
[2016-08-02 17:43:14 +0200] information/ConfigItem: Instantiated 1 UserGroup.
[2016-08-02 17:43:14 +0200] information/ConfigItem: Instantiated 3826 Hosts.
[2016-08-02 17:43:14 +0200] information/ConfigItem: Instantiated 1 IcingaApplication.
[2016-08-02 17:43:14 +0200] information/ConfigItem: Instantiated 70 HostGroups.
[2016-08-02 17:43:14 +0200] information/ConfigItem: Instantiated 3 TimePeriods.
[2016-08-02 17:43:14 +0200] information/ConfigItem: Instantiated 1 User.
[2016-08-02 17:43:14 +0200] information/ConfigItem: Instantiated 21 ServiceGroups.
[2016-08-02 17:43:14 +0200] information/ConfigItem: Instantiated 175733 Services.
[2016-08-02 17:43:14 +0200] information/ConfigItem: Instantiated 1 IdoMysqlConnection.
[2016-08-02 17:43:14 +0200] information/ConfigItem: Instantiated 1 ExternalCommandListener.
[2016-08-02 17:43:14 +0200] information/ScriptGlobal: Dumping variables to file '/var/cache/icinga2/icinga2.vars'
[2016-08-02 17:43:14 +0200] information/ConfigObject: Restoring program state from file '/var/lib/icinga2/icinga2.state'
[2016-08-02 17:43:18 +0200] information/ConfigObject: Restored 179631 objects. Loaded 175 new objects without state.
[2016-08-02 17:43:18 +0200] information/ConfigItem: Triggering Start signal for config items
[2016-08-02 17:43:25 +0200] information/ConfigItem: Activated all objects.

Debug logs attached. (You can see that nothing is update in database)

Member

icinga-migration commented Aug 2, 2016

Updated by mfriedrich on 2016-08-02 15:59:37 +00:00

Please attach a gdb backtrace from the running process.
http://docs.icinga.org/icinga2/latest/doc/module/icinga2/toc\#!/icinga2/latest/doc/module/icinga2/chapter/development#development-debug-gdb-backtrace

gdb -p $(pidof icinga2) -batch -ex "thread apply all bt full" -ex "detach" -ex "q" > gdb_bt.log
Member

icinga-migration commented Aug 3, 2016

Updated by tim_1740 on 2016-08-03 09:22:55 +00:00

  • File added gdb_bt.log
  • File added gdb_bt_1.log
  • File added gdb_bt_2.log

This is my gdb_bt.log files (attached). But I don't know if it's normal : when I run the gdb command, it lasts only two seconds. With this messages :

warning: the debug information found in "/usr/lib/debug//usr/lib64/icinga2/sbin/icinga2.debug" does not match "/usr/lib64/icinga2/sbin/icinga2" (CRC mismatch).
warning: the debug information found in "/usr/lib/debug/usr/lib64/icinga2/sbin/icinga2.debug" does not match "/usr/lib64/icinga2/sbin/icinga2" (CRC mismatch).
warning: the debug information found in "/usr/lib/debug//usr/lib64/icinga2/libbase.so.debug" does not match "/usr/lib64/icinga2/libbase.so" (CRC mismatch).
...

Then I did it 3 times : just after start, during start and after object activation.

Is it enought for you ?

Member

icinga-migration commented Aug 3, 2016

Updated by mfriedrich on 2016-08-03 09:37:29 +00:00

The first two backtraces are coming from the time when the configuration objects are compiled and then committed. The last one seems to be coming from a running process.

I guess your initial startup is taking quite a long time. Probably it is best to generate a full backtrace from the point in time when IDO Mysql says that it successfully connected to the database, version 1.14.x.

Member

icinga-migration commented Aug 3, 2016

Updated by tim_1740 on 2016-08-03 09:46:15 +00:00

You mean when I see this message :
[2016-07-13 11:22:38 +0200] information/IdoMysqlConnection: MySQL IDO instance id: 1 (schema version: '1.14.0')
in debug logs ?

Because this message never appears with my complete environment. (as you can see in my debug logs)

Member

icinga-migration commented Aug 3, 2016

Updated by mfriedrich on 2016-08-03 10:01:22 +00:00

Strange.

Can you start the instance where IDO is running on in foreground ("icinga2 daemon") and check its output?
In addition, please add again "icinga2 --version".

Member

icinga-migration commented Aug 3, 2016

Updated by tim_1740 on 2016-08-03 12:46:19 +00:00

  • File added debug_log_ok.txt
  • File added gdb_bt_3.log
  1. icinga2 --version

icinga2 - The Icinga 2 network monitoring daemon (version: v2.4.10-579-g1ff6939)

Copyright © 2012-2016 Icinga Development Team (https://www.icinga.org/)
License GPLv2+: GNU GPL version 2 or later <http://gnu.org/licenses/gpl2.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.

Application information:
Installation root: /usr
Sysconf directory: /etc
Run directory: /run
Local state directory: /var
Package data directory: /usr/share/icinga2
State path: /var/lib/icinga2/icinga2.state
Modified attributes path: /var/lib/icinga2/modified-attributes.conf
Objects path: /var/cache/icinga2/icinga2.debug
Vars path: /var/cache/icinga2/icinga2.vars
PID path: /run/icinga2/icinga2.pid

System information:
Platform: CentOS Linux
Platform version: 7 (Core)
Kernel: Linux
Kernel version: 3.10.0-327.el7.x86_64
Architecture: x86_64

I just switch my icinga configuration with less objects and it works fine :

Daemon outputs :

/usr/sbin/icinga2 daemon -d
[2016-08-03 14:28:31 +0200] information/cli: Icinga application loader (version: v2.4.10-579-g1ff6939)
[2016-08-03 14:28:31 +0200] information/cli: Loading configuration file(s).
[2016-08-03 14:28:31 +0200] information/ConfigItem: Committing config item(s).
[2016-08-03 14:28:39 +0200] information/ConfigItem: Instantiated 1 Zone.
[2016-08-03 14:28:39 +0200] information/ConfigItem: Instantiated 2 FileLoggers.
[2016-08-03 14:28:39 +0200] information/ConfigItem: Instantiated 1 Endpoint.
[2016-08-03 14:28:39 +0200] information/ConfigItem: Instantiated 142 CheckCommands.
[2016-08-03 14:28:39 +0200] information/ConfigItem: Instantiated 2 NotificationCommands.
[2016-08-03 14:28:39 +0200] information/ConfigItem: Instantiated 1 UserGroup.
[2016-08-03 14:28:39 +0200] information/ConfigItem: Instantiated 663 Hosts.
[2016-08-03 14:28:39 +0200] information/ConfigItem: Instantiated 1 IcingaApplication.
[2016-08-03 14:28:39 +0200] information/ConfigItem: Instantiated 3 HostGroups.
[2016-08-03 14:28:39 +0200] information/ConfigItem: Instantiated 3 TimePeriods.
[2016-08-03 14:28:39 +0200] information/ConfigItem: Instantiated 1 User.
[2016-08-03 14:28:39 +0200] information/ConfigItem: Instantiated 7 ServiceGroups.
[2016-08-03 14:28:39 +0200] information/ConfigItem: Instantiated 27402 Services.
[2016-08-03 14:28:39 +0200] information/ConfigItem: Instantiated 1 IdoMysqlConnection.
[2016-08-03 14:28:39 +0200] information/ConfigItem: Instantiated 1 ExternalCommandListener.
[2016-08-03 14:28:39 +0200] information/ScriptGlobal: Dumping variables to file '/var/cache/icinga2/icinga2.vars'
[2016-08-03 14:28:39 +0200] information/ConfigObject: Restoring program state from file '/var/lib/icinga2/icinga2.state'
[2016-08-03 14:28:43 +0200] information/ConfigObject: Restored 179806 objects. Loaded 0 new objects without state.
[2016-08-03 14:28:43 +0200] information/ConfigItem: Triggering Start signal for config items
[2016-08-03 14:28:43 +0200] information/ConfigItem: Activated all objects.

I don't know if it's important, but as you can see, the line :

information/DbConnection: Resuming IDO connection: ido-mysql
is not present. (It is present when it don't work)

In debug logs all is ok. (attached)

And gdb backtrace if needed. (attached)

Member

icinga-migration commented Aug 12, 2016

Updated by tim_1740 on 2016-08-12 09:44:23 +00:00

Do you have any news for me?

Regards,

Member

icinga-migration commented Aug 12, 2016

Updated by mfriedrich on 2016-08-12 18:09:57 +00:00

Please try the most recent snapshot packages (from today).

Then please run icinga2 with strace.

strace -f -s 1024 icinga2 daemon -d -xnotice

Furthermore you should see in the debug logs which threads have been started for workqueues (that's our current idea). Please post your findings then here again. Thanks.

Member

icinga-migration commented Aug 16, 2016

Updated by tim_1740 on 2016-08-16 13:30:05 +00:00

  • File added debug.log
  • File added strace_icinga.log

I installed the last snapshot :

  1. icinga2 --version
    icinga2 - The Icinga 2 network monitoring daemon (version: v2.4.10-682-g17544d7)
    ...

But when I run it with strace as you specified, it doesn't work. It's lock on something like that :
[pid 30467] execve("/usr/lib64/icinga2/sbin/icinga2", ["/usr/lib64/icinga2/sbin/icinga2", "--no-stack-rlimit", "daemon", "-d"], [/* 16 vars */] <unfinished ...>
[pid 30473] lseek(11, -1863, SEEK_CUR) = 1082
[pid 30473] read(11,

You can find the complete strace attached if needed.

Then I run it without strace, the debug logs are attached too.

Regards,

Member

icinga-migration commented Aug 17, 2016

Updated by gbeutner on 2016-08-17 07:37:19 +00:00

  • Duplicates set to 12460
Member

icinga-migration commented Aug 17, 2016

Updated by gbeutner on 2016-08-17 07:41:36 +00:00

This is most likely a duplicate of #12460 and should've been fixed by 87bc291.

Member

icinga-migration commented Aug 17, 2016

Updated by tim_1740 on 2016-08-17 11:39:07 +00:00

  • File added debug_logs_with_errors.txt

I just tried with the new snapshot (version: v2.4.10-699-gb26b3a4).

It seems to be better, because the line "information/DbConnection: Resuming IDO connection: ido-mysql" is not present in daemon ouputs.

But I have critical/IdoMysqlConnection erros in debug logs. (see attached)

Regards,

Member

icinga-migration commented Aug 17, 2016

Updated by mfriedrich on 2016-08-17 11:49:12 +00:00

Update your IDO schema.

[2016-08-17 12:25:02 +0200] critical/IdoMysqlConnection: Error "Unknown column 'config_hash' in 'field list'" when executing query "SELECT contactgroup_object_id AS object_id, contactgroup_id, config_hash FROM icinga_contactgroups"
Context:
        (0) Reconnecting to MySQL IDO database 'ido-mysql'
Member

icinga-migration commented Aug 17, 2016

Updated by tim_1740 on 2016-08-17 12:29:59 +00:00

I already did it : information/IdoMysqlConnection: MySQL IDO instance id: 1 (schema version: '1.14.1')

Member

icinga-migration commented Aug 17, 2016

Updated by gbeutner on 2016-08-17 13:28:52 +00:00

You're missing some of the schema updates which were added to the pre-release schema update file after you did your update. Just try to execute the updates again using 'mysql --force ... < /usr/share/icinga2-ido-mysql/schema/upgrade/2.5.0.sql'.

Member

icinga-migration commented Aug 17, 2016

Updated by tim_1740 on 2016-08-17 15:26:27 +00:00

Yeah it works !

My 150000 services, 3800 hosts are insert in database.

Do you think I can use this snapshot for production ?

Thank you for all !

Member

icinga-migration commented Aug 17, 2016

Updated by mfriedrich on 2016-08-17 15:29:41 +00:00

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

Presumingly yes, as there are no more open issues except for documentation. We'll keep on testing the current master further until the release next week.

Member

icinga-migration commented Aug 17, 2016

Updated by gbeutner on 2016-08-17 15:41:00 +00:00

I'd be interested in some benchmark times for this. Can you grep for "Finished reconnecting to" in your icinga2.log? :)

Member

icinga-migration commented Aug 22, 2016

Updated by gbeutner on 2016-08-22 11:45:43 +00:00

  • Subject changed from Database not updated with numerous objects to IDO module starts threads before daemonize

@icinga-migration icinga-migration added this to the 2.5.0 milestone Jan 17, 2017

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment