Actions
Bug #16117
closedLDAP password not updated cause major slowdown of webapp
Pull Request:
Severity:
Critical - prevents main use of Rudder | no workaround | data loss | security
UX impact:
User visibility:
First impressions of Rudder
Effort required:
Priority:
124
Name check:
To do
Fix check:
To do
Regression:
Description
On a debian10 rudder server, without any nodes, installed for some hours, without any config done my webapp suddenly went super slow.
I have got logs in the webapp like:
[2019-11-05 15:31:50+0000] ERROR report - Could not get node executions reports from the RudderSysEvents table cause is: Could not get node execution status <- Error when retrieving 'executionStatus' from db: HikariPool-1 - Connection is not available, request timed out after 30000ms. [2019-11-05 15:31:50+0000] WARN application - [Store Agent Run Times] Task frequency is set too low! Last task took 31364 ms but tasks are scheduled every 5000 ms. Adjust rudder.batch.storeAgentRunTimes.updateInterval if this problem persists. [2019-11-05 15:32:13+0000] ERROR scheduledJob - could not fetch last id, don't log anything, wait next run, cause is Error when parsing property 'reportLoggerLastId' [2019-11-05 15:32:27+0000] ERROR report - Could not get node executions reports from the RudderSysEvents table cause is: Could not get node execution status <- Error when retrieving 'executionStatus' from db: HikariPool-1 - Connection is not available, request timed out after 30000ms. [2019-11-05 15:32:27+0000] WARN application - [Store Agent Run Times] Task frequency is set too low! Last task took 31344 ms but tasks are scheduled every 5000 ms. Adjust rudder.batch.storeAgentRunTimes.updateInterval if this problem persists. [2019-11-05 15:33:03+0000] ERROR report - Could not get node executions reports from the RudderSysEvents table cause is: Could not get node execution status <- Error when retrieving 'executionStatus' from db: HikariPool-1 - Connection is not available, request timed out after 30000ms. [2019-11-05 15:33:03+0000] WARN application - [Store Agent Run Times] Task frequency is set too low! Last task took 31394 ms but tasks are scheduled every 5000 ms. Adjust rudder.batch.storeAgentRunTimes.updateInterval if this problem persists. [2019-11-05 15:33:40+0000] ERROR report - Could not get node executions reports from the RudderSysEvents table cause is: Could not get node execution status <- Error when retrieving 'executionStatus' from db: HikariPool-1 - Connection is not available, request timed out after 30000ms. [2019-11-05 15:33:40+0000] WARN application - [Store Agent Run Times] Task frequency is set too low! Last task took 31368 ms but tasks are scheduled every 5000 ms. Adjust rudder.batch.storeAgentRunTimes.updateInterval if this problem persists. [2019-11-05 15:33:47+0000] ERROR scheduledJob - could not fetch last id, don't log anything, wait next run, cause is Error when parsing property 'reportLoggerLastId' [2019-11-05 15:34:16+0000] ERROR report - Could not get node executions reports from the RudderSysEvents table cause is: Could not get node execution status <- Error when retrieving 'executionStatus' from db: HikariPool-1 - Connection is not available, request timed out after 30000ms. [2019-11-05 15:34:16+0000] WARN application - [Store Agent Run Times] Task frequency is set too low! Last task took 31371 ms but tasks are scheduled every 5000 ms. Adjust rudder.batch.storeAgentRunTimes.updateInterval if this problem persists. [2019-11-05 15:34:47+0000] INFO scheduledJob - Purged 0 unreferenced softwares [2019-11-05 15:34:52+0000] ERROR report - Could not get node executions reports from the RudderSysEvents table cause is: Could not get node execution status <- Error when retrieving 'executionStatus' from db: HikariPool-1 - Connection is not available, request timed out after 30000ms. [2019-11-05 15:34:52+0000] WARN application - [Store Agent Run Times] Task frequency is set too low! Last task took 31368 ms but tasks are scheduled every 5000 ms. Adjust rudder.batch.storeAgentRunTimes.updateInterval if this problem persists. [2019-11-05 15:35:21+0000] ERROR scheduledJob - could not fetch last id, don't log anything, wait next run, cause is Error when parsing property 'reportLoggerLastId' [2019-11-05 15:35:29+0000] ERROR report - Could not get node executions reports from the RudderSysEvents table cause is: Could not get node execution status <- Error when retrieving 'executionStatus' from db: HikariPool-1 - Connection is not available, request timed out after 30000ms. [2019-11-05 15:35:29+0000] WARN application - [Store Agent Run Times] Task frequency is set too low! Last task took 31367 ms but tasks are scheduled every 5000 ms. Adjust rudder.batch.storeAgentRunTimes.updateInterval if this problem persists. [2019-11-05 15:36:05+0000] ERROR report - Could not get node executions reports from the RudderSysEvents table cause is: Could not get node execution status <- Error when retrieving 'executionStatus' from db: HikariPool-1 - Connection is not available, request timed out after 30000ms. [2019-11-05 15:36:05+0000] WARN application - [Store Agent Run Times] Task frequency is set too low! Last task took 31368 ms but tasks are scheduled every 5000 ms. Adjust rudder.batch.storeAgentRunTimes.updateInterval if this problem persists. [2019-11-05 15:36:41+0000] ERROR report - Could not get node executions reports from the RudderSysEvents table cause is: Could not get node execution status <- Error when retrieving 'executionStatus' from db: HikariPool-1 - Connection is not available, request timed out after 30000ms. [2019-11-05 15:36:41+0000] WARN application - [Store Agent Run Times] Task frequency is set too low! Last task took 31356 ms but tasks are scheduled every 5000 ms. Adjust rudder.batch.storeAgentRunTimes.updateInterval if this problem persists. [2019-11-05 15:36:55+0000] ERROR scheduledJob - could not fetch last id, don't log anything, wait next run, cause is Error when parsing property 'reportLoggerLastId' [2019-11-05 15:37:18+0000] ERROR report - Could not get node executions reports from the RudderSysEvents table cause is: Could not get node execution status <- Error when retrieving 'executionStatus' from db: HikariPool-1 - Connection is not available, request timed out after 30000ms. [2019-11-05 15:37:18+0000] WARN application - [Store Agent Run Times] Task frequency is set too low! Last task took 31387 ms but tasks are scheduled every 5000 ms. Adjust rudder.batch.storeAgentRunTimes.updateInterval if this problem persists. [2019-11-05 15:37:54+0000] ERROR report - Could not get node executions reports from the RudderSysEvents table cause is: Could not get node execution status <- Error when retrieving 'executionStatus' from db: HikariPool-1 - Connection is not available, request timed out after 30000ms. [2019-11-05 15:37:54+0000] WARN application - [Store Agent Run Times] Task frequency is set too low! Last task took 30003 ms but tasks are scheduled every 5000 ms. Adjust rudder.batch.storeAgentRunTimes.updateInterval if this problem persists. [2019-11-05 15:38:28+0000] ERROR scheduledJob - could not fetch last id, don't log anything, wait next run, cause is Error when parsing property 'reportLoggerLastId' [2019-11-05 15:38:32+0000] ERROR report - Could not get node executions reports from the RudderSysEvents table cause is: Could not get node execution status <- Error when retrieving 'executionStatus' from db: HikariPool-1 - Connection is not available, request timed out after 30000ms. [2019-11-05 15:38:32+0000] WARN application - [Store Agent Run Times] Task frequency is set too low! Last task took 31366 ms but tasks are scheduled every 5000 ms. Adjust rudder.batch.storeAgentRunTimes.updateInterval if this problem persists. [2019-11-05 15:39:08+0000] ERROR report - Could not get node executions reports from the RudderSysEvents table cause is: Could not get node execution status <- Error when retrieving 'executionStatus' from db: HikariPool-1 - Connection is not available, request timed out after 30000ms. [2019-11-05 15:39:08+0000] WARN application - [Store Agent Run Times] Task frequency is set too low! Last task took 31336 ms but tasks are scheduled every 5000 ms. Adjust rudder.batch.storeAgentRunTimes.updateInterval if this problem persists. [2019-11-05 15:39:45+0000] ERROR report - Could not get node executions reports from the RudderSysEvents table cause is: Could not get node execution status <- Error when retrieving 'executionStatus' from db: HikariPool-1 - Connection is not available, request timed out after 30000ms. [2019-11-05 15:39:45+0000] WARN application - [Store Agent Run Times] Task frequency is set too low! Last task took 31403 ms but tasks are scheduled every 5000 ms. Adjust rudder.batch.storeAgentRunTimes.updateInterval if this problem persists. [2019-11-05 15:40:02+0000] ERROR scheduledJob - could not fetch last id, don't log anything, wait next run, cause is Error when parsing property 'reportLoggerLastId' [2019-11-05 15:40:21+0000] ERROR report - Could not get node executions reports from the RudderSysEvents table cause is: Could not get node execution status <- Error when retrieving 'executionStatus' from db: HikariPool-1 - Connection is not available, request timed out after 30000ms. [2019-11-05 15:40:21+0000] WARN application - [Store Agent Run Times] Task frequency is set too low! Last task took 31365 ms but tasks are scheduled every 5000 ms. Adjust rudder.batch.storeAgentRunTimes.updateInterval if this problem persists. [2019-11-05 15:40:57+0000] ERROR report - Could not get node executions reports from the RudderSysEvents table cause is: Could not get node execution status <- Error when retrieving 'executionStatus' from db: HikariPool-1 - Connection is not available, request timed out after 30000ms. [2019-11-05 15:40:57+0000] WARN application - [Store Agent Run Times] Task frequency is set too low! Last task took 31366 ms but tasks are scheduled every 5000 ms. Adjust rudder.batch.storeAgentRunTimes.updateInterval if this problem persists. [2019-11-05 15:41:34+0000] ERROR report - Could not get node executions reports from the RudderSysEvents table cause is: Could not get node execution status <- Error when retrieving 'executionStatus' from db: HikariPool-1 - Connection is not available, request timed out after 30000ms. [2019-11-05 15:41:34+0000] WARN application - [Store Agent Run Times] Task frequency is set too low! Last task took 31372 ms but tasks are scheduled every 5000 ms. Adjust rudder.batch.storeAgentRunTimes.updateInterval if this problem persists. [2019-11-05 15:41:36+0000] ERROR scheduledJob - could not fetch last id, don't log anything, wait next run, cause is Error when parsing property 'reportLoggerLastId' [2019-11-05 15:42:10+0000] ERROR report - Could not get node executions reports from the RudderSysEvents table cause is: Could not get node execution status <- Error when retrieving 'executionStatus' from db: HikariPool-1 - Connection is not available, request timed out after 30000ms. [2019-11-05 15:42:10+0000] WARN application - [Store Agent Run Times] Task frequency is set too low! Last task took 31367 ms but tasks are scheduled every 5000 ms. Adjust rudder.batch.storeAgentRunTimes.updateInterval if this problem persists. [2019-11-05 15:42:34+0000] WARN com.normation.rudder.web.snippet.SendMetricsPopup - Could not get last application start event, do not display 'metrics' popup <- Error when retrieving event logs for change request with request: select eventtype, id, modificationid, principal, creationdate, causeid, severity, reason, data from eventlog where eventType = 'ApplicationStarted' order by creationDate desc limit 1 [2019-11-05 15:42:34+0000] ERROR com.normation.rudder.web.snippet.HomePage - Failure(HikariPool-1 - Connection is not available, request timed out after 30001ms.,Full(java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30001ms.),Empty) [2019-11-05 15:42:46+0000] ERROR report - Could not get node executions reports from the RudderSysEvents table cause is: Could not get node execution status <- Error when retrieving 'executionStatus' from db: HikariPool-1 - Connection is not available, request timed out after 30000ms. [2019-11-05 15:42:46+0000] WARN application - [Store Agent Run Times] Task frequency is set too low! Last task took 31368 ms but tasks are scheduled every 5000 ms. Adjust rudder.batch.storeAgentRunTimes.updateInterval if this problem persists. [2019-11-05 15:42:48+0000] WARN com.normation.rudder.web.snippet.SendMetricsPopup - Could not get last application start event, do not display 'metrics' popup <- Error when retrieving event logs for change request with request: select eventtype, id, modificationid, principal, creationdate, causeid, severity, reason, data from eventlog where eventType = 'ApplicationStarted' order by creationDate desc limit 1 [2019-11-05 15:43:06+0000] ERROR com.normation.rudder.web.snippet.HomePage - Failure(HikariPool-1 - Connection is not available, request timed out after 30000ms.,Full(java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms.),Empty) [2019-11-05 15:43:10+0000] ERROR scheduledJob - could not fetch last id, don't log anything, wait next run, cause is Error when parsing property 'reportLoggerLastId' [2019-11-05 15:43:10+0000] WARN com.normation.rudder.web.snippet.SendMetricsPopup - Could not get last application start event, do not display 'metrics' popup <- Error when retrieving event logs for change request with request: select eventtype, id, modificationid, principal, creationdate, causeid, severity, reason, data from eventlog where eventType = 'ApplicationStarted' order by creationDate desc limit 1 [2019-11-05 15:43:11+0000] WARN com.normation.rudder.web.snippet.SendMetricsPopup - Could not get last application start event, do not display 'metrics' popup <- Error when retrieving event logs for change request with request: select eventtype, id, modificationid, principal, creationdate, causeid, severity, reason, data from eventlog where eventType = 'ApplicationStarted' order by creationDate desc limit 1 [2019-11-05 15:43:11+0000] WARN com.normation.rudder.web.snippet.SendMetricsPopup - Could not get last application start event, do not display 'metrics' popup <- Error when retrieving event logs for change request with request: select eventtype, id, modificationid, principal, creationdate, causeid, severity, reason, data from eventlog where eventType = 'ApplicationStarted' order by creationDate desc limit 1 [2019-11-05 15:43:11+0000] WARN com.normation.rudder.web.snippet.SendMetricsPopup - Could not get last application start event, do not display 'metrics' popup <- Error when retrieving event logs for change request with request: select eventtype, id, modificationid, principal, creationdate, causeid, severity, reason, data from eventlog where eventType = 'ApplicationStarted' order by creationDate desc limit 1 [2019-11-05 15:43:12+0000] WARN com.normation.rudder.web.snippet.SendMetricsPopup - Could not get last application start event, do not display 'metrics' popup <- Error when retrieving event logs for change request with request: select eventtype, id, modificationid, principal, creationdate, causeid, severity, reason, data from eventlog where eventType = 'ApplicationStarted' order by creationDate desc limit 1 [2019-11-05 15:43:12+0000] WARN com.normation.rudder.web.snippet.SendMetricsPopup - Could not get last application start event, do not display 'metrics' popup <- Error when retrieving event logs for change request with request: select eventtype, id, modificationid, principal, creationdate, causeid, severity, reason, data from eventlog where eventType = 'ApplicationStarted' order by creationDate desc limit 1 [2019-11-05 15:43:23+0000] ERROR report - Could not get node executions reports from the RudderSysEvents table cause is: Could not get node execution status <- Error when retrieving 'executionStatus' from db: HikariPool-1 - Connection is not available, request timed out after 30000ms. [2019-11-05 15:43:23+0000] WARN application - [Store Agent Run Times] Task frequency is set too low! Last task took 31366 ms but tasks are scheduled every 5000 ms. Adjust rudder.batch.storeAgentRunTimes.updateInterval if this problem persists. [2019-11-05 15:43:37+0000] ERROR com.normation.rudder.web.snippet.HomePage - Failure(HikariPool-1 - Connection is not available, request timed out after 30000ms.,Full(java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms.),Empty)
Also, the message "HikariPool-1 - Connection is not available, request timed out after 30000ms." sometimes pop as a javascript alert in the web interface.
Files
Updated by Nicolas CHARLES about 5 years ago
I reproduced with a fresh install
Issue is a change in the passwords by the agent, that does not restart the webapp
Updated by Nicolas CHARLES about 5 years ago
- Related to Bug #16125: Agent doesn't correctly restart the service when it update the passwords added
Updated by Vincent MEMBRÉ about 5 years ago
- Target version changed from 6.0.0~beta1 to 6.0.0
Updated by François ARMAND about 5 years ago
- Related to Bug #16332: We need to restart rudder-jetty when ldap password is updated added
Updated by François ARMAND about 5 years ago
- Subject changed from awfully slow webapp in 6.0 to LDAP password not updated cause major slowdown of webapp
Updated by Alexis Mousset about 5 years ago
- Status changed from New to Rejected
Should be fixed by #16332.
Actions