Project

General

Profile

Actions

Bug #12911

closed

During upgrade, jetty doesn't seems to always restart correctly

Added by Nicolas CHARLES over 5 years ago. Updated about 4 years ago.

Status:
Released
Priority:
N/A
Category:
Packaging
Target version:
Severity:
Major - prevents use of part of Rudder | no simple workaround
UX impact:
User visibility:
Operational - other Techniques | Rudder settings | Plugins
Effort required:
Priority:
43
Name check:
Reviewed
Fix check:
Checked
Regression:

Description

Update: it also happens in other upgrade (like 4.3 -> 5.0) and it seems that the cause is jetty not restarting correctly (even if it says so).

After upgrading (on a debian system) from 4.3.2 eo 4.3 nightly (with a DSC plugin present), I have completly broken compliance in the web interface

Reason is not a all the compliance, but the webabb which is in an half broken state, due to error at start:

2018-07-06 15:26:26.545:INFO:oejsh.ContextHandler:Scanner-0: Stopped o.e.j.w.WebAppContext@41394595{/rudder,null,UNAVAILABLE}{/rudder.war}
java.lang.NoClassDefFoundError: cats/effect/internals/NonFatal$
        at cats.effect.internals.IORunLoop$.liftedTree3$1(IORunLoop.scala:207)
        at cats.effect.internals.IORunLoop$.step(IORunLoop.scala:207)
        at cats.effect.IO.unsafeRunTimed(IO.scala:308)
        at cats.effect.IO.unsafeRunSync(IO.scala:243)
        at com.normation.rudder.repository.jdbc.FindExpectedReportsJdbcRepository.getNodeConfigIdInfos(ExpectedReportsJdbcRepository.scala:189)
        at com.normation.rudder.services.reports.DefaultFindRuleNodeStatusReports.$anonfun$getNodeRunInfos$5(ReportingServiceImpl.scala:389)
        at net.liftweb.common.Full.flatMap(Box.scala:856)
        at com.normation.rudder.services.reports.DefaultFindRuleNodeStatusReports.$anonfun$getNodeRunInfos$2(ReportingServiceImpl.scala:386)
        at net.liftweb.common.Full.flatMap(Box.scala:856)
        at com.normation.rudder.services.reports.DefaultFindRuleNodeStatusReports.getNodeRunInfos(ReportingServiceImpl.scala:381)
        at com.normation.rudder.services.reports.DefaultFindRuleNodeStatusReports.$anonfun$findRuleNodeStatusReports$5(ReportingServiceImpl.scala:346)
        at net.liftweb.common.Full.flatMap(Box.scala:856)
        at com.normation.rudder.services.reports.DefaultFindRuleNodeStatusReports.$anonfun$findRuleNodeStatusReports$4(ReportingServiceImpl.scala:344)
        at net.liftweb.common.Full.flatMap(Box.scala:856)
        at com.normation.rudder.services.reports.DefaultFindRuleNodeStatusReports.findRuleNodeStatusReports(ReportingServiceImpl.scala:343)
        at com.normation.rudder.services.reports.DefaultFindRuleNodeStatusReports.findRuleNodeStatusReports$(ReportingServiceImpl.scala:311)
        at com.normation.rudder.services.reports.ReportingServiceImpl.findRuleNodeStatusReports(ReportingServiceImpl.scala:65)
        at com.normation.rudder.services.reports.CachedFindRuleNodeStatusReports.$anonfun$checkAndUpdateCache$6(ReportingServiceImpl.scala:256)
        at net.liftweb.common.Full.flatMap(Box.scala:856)
        at com.normation.rudder.services.reports.CachedFindRuleNodeStatusReports.$anonfun$checkAndUpdateCache$1(ReportingServiceImpl.scala:225)
        at scala.concurrent.BlockContext$DefaultBlockContext$.blockOn(BlockContext.scala:53)
        at scala.concurrent.package$.blocking(package.scala:142)
        at com.normation.rudder.services.reports.CachedFindRuleNodeStatusReports.checkAndUpdateCache(ReportingServiceImpl.scala:217)
        at com.normation.rudder.services.reports.CachedFindRuleNodeStatusReports.$anonfun$invalidate$1(ReportingServiceImpl.scala:207)
        at scala.concurrent.BlockContext$.withBlockContext(BlockContext.scala:81)
        at scala.concurrent.impl.ExecutionContextImpl$DefaultThreadFactory$$anon$2$$anon$4.block(ExecutionContextImpl.scala:76)
        at java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3313)
        at scala.concurrent.impl.ExecutionContextImpl$DefaultThreadFactory$$anon$2.blockOn(ExecutionContextImpl.scala:71)
        at scala.concurrent.package$.blocking(package.scala:142)
        at com.normation.rudder.services.reports.CachedFindRuleNodeStatusReports.invalidate(ReportingServiceImpl.scala:203)
        at com.normation.rudder.services.reports.CachedFindRuleNodeStatusReports.invalidate$(ReportingServiceImpl.scala:203)
        at com.normation.rudder.services.reports.CachedReportingServiceImpl.invalidate(ReportingServiceImpl.scala:77)
        at com.normation.rudder.reports.execution.ReportsExecutionService.$anonfun$hook$9(ReportsExecutionService.scala:216)
        at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:12)
        at scala.concurrent.Future$.$anonfun$apply$1(Future.scala:654)
        at scala.util.Success.$anonfun$map$1(Try.scala:251)
        at scala.util.Success.map(Try.scala:209)
        at scala.concurrent.Future.$anonfun$map$1(Future.scala:288)
        at scala.concurrent.impl.Promise.liftedTree1$1(Promise.scala:29)
        at scala.concurrent.impl.Promise.$anonfun$transform$1(Promise.scala:29)
        at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:60)
        at java.util.concurrent.ForkJoinTask$RunnableExecuteAction.exec(ForkJoinTask.java:1402)
        at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289)
        at java.util.concurrent.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1056)
        at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1692)
        at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157)
Caused by: java.lang.ClassNotFoundException: cats.effect.internals.NonFatal$
        at java.net.URLClassLoader.findClass(URLClassLoader.java:381)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
        at org.eclipse.jetty.webapp.WebAppClassLoader.loadClass(WebAppClassLoader.java:560)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)


Files

2018_07_06.stderrout.log.134836833 (72.8 KB) 2018_07_06.stderrout.log.134836833 Nicolas CHARLES, 2018-07-06 13:55

Related issues 1 (0 open1 closed)

Has duplicate Rudder - Bug #16424: After plugin installation the webapp is super long to restartRejectedActions
Actions #1

Updated by Nicolas CHARLES over 5 years ago

other error:

[2018-07-06 15:26:29] INFO  application - Starting Rudder 4.3.3-SNAPSHOT web application [build timestamp: 20180706-0109]
java.lang.NoClassDefFoundError: bootstrap/liftweb/checks/NcfTechniqueUpgradeError$
        at bootstrap.liftweb.checks.CheckNcfTechniqueUpdate.updateNcfTechniques$1(CheckNcfTechniqueUpdate.scala:114)
        at bootstrap.liftweb.checks.CheckNcfTechniqueUpdate.$anonfun$checks$29(CheckNcfTechniqueUpdate.scala:189)
        at monix.execution.internal.RunnableAction.run(RunnableAction.scala:25)
        at java.util.concurrent.ForkJoinTask$RunnableExecuteAction.exec(ForkJoinTask.java:1402)
        at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289)
        at java.util.concurrent.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1056)
        at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1692)
        at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157)
Caused by: java.lang.ClassNotFoundException: bootstrap.liftweb.checks.NcfTechniqueUpgradeError$
        at java.net.URLClassLoader.findClass(URLClassLoader.java:381)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
        at org.eclipse.jetty.webapp.WebAppClassLoader.loadClass(WebAppClassLoader.java:560)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
        ... 8 more
[2018-07-06 15:26:29] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Node configuration written on filesystem in 6355 ms
[2018-07-06 15:26:29] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Node configuration cached in LDAP in 78 ms
[2018-07-06 15:26:29] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Node configuration written in 6453 ms, start to update expected reports.
Exception in thread "pool-3-thread-11" java.lang.NoClassDefFoundError: net/liftweb/actor/ActorLogger$
        at net.liftweb.actor.SpecializedLiftActor$$anonfun$exceptionHandler$1.applyOrElse(LiftActor.scala:346)
        at net.liftweb.actor.SpecializedLiftActor$$anonfun$exceptionHandler$1.applyOrElse(LiftActor.scala:345)
        at scala.runtime.AbstractPartialFunction.apply(AbstractPartialFunction.scala:34)
        at net.liftweb.actor.SpecializedLiftActor.proc2(LiftActor.scala:325)
        at net.liftweb.actor.SpecializedLiftActor.$anonfun$processMailbox$1(LiftActor.scala:227)
        at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:12)
        at net.liftweb.actor.SpecializedLiftActor.around(LiftActor.scala:241)
        at net.liftweb.actor.SpecializedLiftActor.around$(LiftActor.scala:240)
        at com.normation.rudder.batch.AsyncDeploymentAgent$DeployerAgent$.around(AsyncDeploymentAgent.scala:344)
        at net.liftweb.actor.SpecializedLiftActor.processMailbox(LiftActor.scala:227)
        at net.liftweb.actor.SpecializedLiftActor.$anonfun$$bang$3(LiftActor.scala:190)
        at net.liftweb.actor.LAScheduler$$anon$2$$anon$3.run(LiftActor.scala:76)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.ClassNotFoundException: net.liftweb.actor.ActorLogger$
        at java.net.URLClassLoader.findClass(URLClassLoader.java:381)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
        at org.eclipse.jetty.webapp.WebAppClassLoader.loadClass(WebAppClassLoader.java:560)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
        ... 15 more
Exception in thread "pool-8-thread-3" java.lang.NoClassDefFoundError: net/liftweb/actor/ActorLogger$
        at net.liftweb.actor.SpecializedLiftActor$$anonfun$exceptionHandler$1.applyOrElse(LiftActor.scala:346)
        at net.liftweb.actor.SpecializedLiftActor$$anonfun$exceptionHandler$1.applyOrElse(LiftActor.scala:345)
        at scala.runtime.AbstractPartialFunction.apply(AbstractPartialFunction.scala:34)
        at net.liftweb.actor.SpecializedLiftActor.proc2(LiftActor.scala:325)
        at net.liftweb.actor.SpecializedLiftActor.$anonfun$processMailbox$1(LiftActor.scala:227)
        at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:12)
        at net.liftweb.actor.SpecializedLiftActor.around(LiftActor.scala:241)
        at net.liftweb.actor.SpecializedLiftActor.around$(LiftActor.scala:240)
        at com.normation.rudder.batch.AbstractScheduler$StatusManager.around(AbstractScheduler.scala:112)
        at net.liftweb.actor.SpecializedLiftActor.processMailbox(LiftActor.scala:227)
        at net.liftweb.actor.SpecializedLiftActor.$anonfun$$bang$3(LiftActor.scala:190)
        at net.liftweb.actor.LAScheduler$$anon$2$$anon$3.run(LiftActor.scala:76)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)
Exception in thread "pool-8-thread-5" java.lang.NoClassDefFoundError: net/liftweb/actor/ActorLogger$
        at net.liftweb.actor.SpecializedLiftActor$$anonfun$exceptionHandler$1.applyOrElse(LiftActor.scala:346)
        at net.liftweb.actor.SpecializedLiftActor$$anonfun$exceptionHandler$1.applyOrElse(LiftActor.scala:345)
        at scala.runtime.AbstractPartialFunction.apply(AbstractPartialFunction.scala:34)
        at net.liftweb.actor.SpecializedLiftActor.proc2(LiftActor.scala:325)
...
[2018-07-06 15:27:03] WARN  explain_compliance.a45e71e7-d083-4067-b3e6-c2ba73e996b7 - Received a run at 2018-07-06T15:26:57.000+02:00 for node 'a45e71e7-d083-4067-b3e6-c2ba73e996b7' configId '20180706-152618-56f926c1' which is not known by Rudder, and that node should be sending reports for configId 20180703-142723-aee2855c
Exception in thread "Health Check Thread for LDAPConnectionPool(serverSet=SingleServerSet(server=localhost:389), maxConnections=2)" java.lang.NoClassDefFoundError: com/unboundid/ldap/sdk/LDAPConnectionPoolHealthCheckResult
        at com.unboundid.ldap.sdk.LDAPConnectionPool.invokeHealthCheck(LDAPConnectionPool.java:2979)
        at com.unboundid.ldap.sdk.LDAPConnectionPool.invokeHealthCheck(LDAPConnectionPool.java:2671)
        at com.unboundid.ldap.sdk.LDAPConnectionPool.doHealthCheck(LDAPConnectionPool.java:2641)
        at com.unboundid.ldap.sdk.LDAPConnectionPoolHealthCheckThread.run(LDAPConnectionPoolHealthCheckThread.java:94)
Caused by: java.lang.ClassNotFoundException: com.unboundid.ldap.sdk.LDAPConnectionPoolHealthCheckResult
        at java.net.URLClassLoader.findClass(URLClassLoader.java:381)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
        at org.eclipse.jetty.webapp.WebAppClassLoader.loadClass(WebAppClassLoader.java:560)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
        ... 4 more
Exception in thread "Health Check Thread for LDAPConnectionPool(serverSet=SingleServerSet(server=localhost:389), maxConnections=2)" java.lang.NoClassDefFoundError: com/unboundid/ldap/sdk/LDAPConnectionPoolHealthCheckResult
        at com.unboundid.ldap.sdk.LDAPConnectionPool.invokeHealthCheck(LDAPConnectionPool.java:2979)
        at com.unboundid.ldap.sdk.LDAPConnectionPool.invokeHealthCheck(LDAPConnectionPool.java:2671)
        at com.unboundid.ldap.sdk.LDAPConnectionPool.doHealthCheck(LDAPConnectionPool.java:2641)
        at com.unboundid.ldap.sdk.LDAPConnectionPoolHealthCheckThread.run(LDAPConnectionPoolHealthCheckThread.java:94)
Exception in thread "pool-8-thread-7" java.lang.NoClassDefFoundError: net/liftweb/actor/ActorLogger$
        at net.liftweb.actor.SpecializedLiftActor$$anonfun$exceptionHandler$1.applyOrElse(LiftActor.scala:346)
        at net.liftweb.actor.SpecializedLiftActor$$anonfun$exceptionHandler$1.applyOrElse(LiftActor.scala:345)
        at scala.runtime.AbstractPartialFunction.apply(AbstractPartialFunction.scala:34)
        at net.liftweb.actor.SpecializedLiftActor.proc2(LiftActor.scala:325)
        at net.liftweb.actor.SpecializedLiftActor.$anonfun$processMailbox$1(LiftActor.scala:227)
        at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:12)
        at net.liftweb.actor.SpecializedLiftActor.around(LiftActor.scala:241)
        at net.liftweb.actor.SpecializedLiftActor.around$(LiftActor.scala:240)
        at com.normation.rudder.batch.AutomaticReportsCleaning$LADatabaseCleaner.around(AutomaticReportsCleaner.scala:311)
        at net.liftweb.actor.SpecializedLiftActor.processMailbox(LiftActor.scala:227)
        at net.liftweb.actor.SpecializedLiftActor.$anonfun$$bang$3(LiftActor.scala:190)
        at net.liftweb.actor.LAScheduler$$anon$2$$anon$3.run(LiftActor.scala:76)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)
Exception in thread "pool-8-thread-9" java.lang.NoClassDefFoundError: net/liftweb/actor/ActorLogger$
        at net.liftweb.actor.SpecializedLiftActor$$anonfun$exceptionHandler$1.applyOrElse(LiftActor.scala:346)
        at net.liftweb.actor.SpecializedLiftActor$$anonfun$exceptionHandler$1.applyOrElse(LiftActor.scala:345)
        at scala.runtime.AbstractPartialFunction.apply(AbstractPartialFunction.scala:34)
        at net.liftweb.actor.SpecializedLiftActor.proc2(LiftActor.scala:325)
        at net.liftweb.actor.SpecializedLiftActor.$anonfun$processMailbox$1(LiftActor.scala:227)
        at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:12)
        at net.liftweb.actor.SpecializedLiftActor.around(LiftActor.scala:241)
        at net.liftweb.actor.SpecializedLiftActor.around$(LiftActor.scala:240)
        at com.normation.rudder.batch.AutomaticReportsCleaning$LADatabaseCleaner.around(AutomaticReportsCleaner.scala:311)
        at net.liftweb.actor.SpecializedLiftActor.processMailbox(LiftActor.scala:227)
        at net.liftweb.actor.SpecializedLiftActor.$anonfun$$bang$3(LiftActor.scala:190)
        at net.liftweb.actor.LAScheduler$$anon$2$$anon$3.run(LiftActor.scala:76)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)
Exception in thread "pool-8-thread-11" java.lang.NoClassDefFoundError: net/liftweb/actor/ActorLogger$
        at net.liftweb.actor.SpecializedLiftActor$$anonfun$exceptionHandler$1.applyOrElse(LiftActor.scala:346)
        at net.liftweb.actor.SpecializedLiftActor$$anonfun$exceptionHandler$1.applyOrElse(LiftActor.scala:345)
        at scala.runtime.AbstractPartialFunction.apply(AbstractPartialFunction.scala:34)
        at net.liftweb.actor.SpecializedLiftActor.proc2(LiftActor.scala:325)
        at net.liftweb.actor.SpecializedLiftActor.$anonfun$processMailbox$1(LiftActor.scala:227)
        at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:12)

Actions #2

Updated by Nicolas CHARLES over 5 years ago

retarting the webapp solves the issue

see full log:

[2018-07-06 15:26:14] INFO  application - registered property: user.name="root" 
[2018-07-06 15:26:14] INFO  application - registered property: user.timezone="Europe/Paris" 
[2018-07-06 15:26:14] INFO  bootchecks - Check LDAP and PostgreSQL connection
[2018-07-06 15:26:14] INFO  bootchecks - LDAP and PostgreSQL connection are OK
[2018-07-06 15:26:14] INFO  bootchecks - Check mandatory DIT entries
[2018-07-06 15:26:15] INFO  bootchecks - All the required DIT entries are present in the LDAP directory
[2018-07-06 15:26:15] INFO  bootchecks - Check initialization of User Technique Library
[2018-07-06 15:26:15] INFO  bootchecks - Check event log migration format 5 -> 6
[2018-07-06 15:26:15] INFO  bootchecks - Check existence of at least one archive of the configuration
[2018-07-06 15:26:15] INFO  migration - No migration detected by migration script (table 'migrationeventlog' is empty or does not exist)
[2018-07-06 15:26:15] INFO  bootchecks - First full archive of configuration-repository items done
[2018-07-06 15:26:15] INFO  bootchecks - Check rules archive directory in configuration-repository
[2018-07-06 15:26:15] INFO  bootchecks - Creating directory '/var/rudder/configuration-repository/ruleCategories' exists, done
[2018-07-06 15:26:15] INFO  bootchecks - Check that directive variables use the namespace 'rudder'
[2018-07-06 15:26:15] INFO  migration - Migration of inline variables in Directives to 'rudder' namespace already done, skipping
[2018-07-06 15:26:15] INFO  bootchecks - Check for force reload of Techniques library
[2018-07-06 15:26:15] INFO  bootchecks - Flag file '/opt/rudder/etc/force_technique_reload' found, reload Technique library now
[2018-07-06 15:26:17] INFO  com.normation.cfclerk.services.impl.TechniqueRepositoryImpl - Reloading technique library, found modified technique(s): ['common': updated (1.0: VersionUpdate
d)], ['service_start': deleted (1.0)], ['inventory': updated (1.0: VersionUpdated)]
[2018-07-06 15:26:18] INFO  com.normation.rudder.services.policies.DeployOnTechniqueCallback - Reload Technique library at start up
[2018-07-06 15:26:18] INFO  bootchecks - Successfully reloaded Technique library on start up. now deleting flag file '/opt/rudder/etc/force_technique_reload'
[2018-07-06 15:26:18] INFO  bootchecks - Flag file '/opt/rudder/etc/force_technique_reload' successfully removed
[2018-07-06 15:26:18] INFO  bootchecks - Resume policy update if it was running before shutdown
[2018-07-06 15:26:18] INFO  bootchecks - Flag file '/opt/rudder/etc/policy-update-running' does not exist, No need to start a new policy update
[2018-07-06 15:26:18] INFO  bootchecks - Check that system group / directive / rules for Rudder 4.2 are agent-specific
[2018-07-06 15:26:18] INFO  com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Start policy generation, checking updated rules
[2018-07-06 15:26:18] INFO  bootchecks - Updating system configuration stored in entry 'nodeGroupId=all-nodes-with-cfengine-agent,groupCategoryId=SystemGroups,groupCategoryId=GroupRoot,o
u=Rudder,cn=rudder-configuration': LDIFModifyChangeRecord(dn='nodeGroupId=all-nodes-with-cfengine-agent,groupCategoryId=SystemGroups,groupCategoryId=GroupRoot,ou=Rudder,cn=rudder-configu
ration', mods={LDAPModification(type=replace, attr=jsonNodeGroupQuery, values={'{"select":"nodeAndPolicyServer","composition":"And","where":[ {"objectType":"node","attribute":"agentName" 
,"comparator":"eq","value":"cfengine"} ]}'})})
[2018-07-06 15:26:18] INFO  bootchecks - Regenerate all ncf techniques
[2018-07-06 15:26:18] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Pre-policy-generation scripts hooks ran in 38 ms
[2018-07-06 15:26:18] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Pre-policy-generation modules hooks in 2 ms, start getting all generation related data.
[2018-07-06 15:26:18] INFO  bootchecks - Create system api token
[2018-07-06 15:26:18] INFO  bootchecks - System api token file created in /var/rudder/run/api-token
[2018-07-06 15:26:18] INFO  bootchecks - Update existing API token to 'RW' autorization level.
2018-07-06 15:26:18.394:INFO:oejshC.rudder:main: Initializing Spring root WebApplicationContext
[2018-07-06 15:26:19] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - All relevant information fetched in 905 ms, start names historization.
[2018-07-06 15:26:19] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Historization of names done in 551 ms, start to build rule values.
[2018-07-06 15:26:19] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - RuleVals built in 119 ms, start to expand their values.
[2018-07-06 15:26:20] INFO  com.normation.rudder.domain.nodes.NodeInfo - Node 'agent1' (51afb080-b672-458e-97d8-bd7fb92aac02) is a Dsc node and a we do not know how to generate a hash ye
t
[2018-07-06 15:26:20] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Node contexts built in 856 ms, start to build new node configurations.
[2018-07-06 15:26:20] INFO  application - Loaded authentication provider(s): [file]
[2018-07-06 15:26:21] INFO  application - No master admin account is defined. You can define one with 'rudder.auth.admin.login' and 'rudder.auth.admin.password' properties in the configu
ration file
[2018-07-06 15:26:21] INFO  application - Use configuration file defined by JVM property -Drudder.authFile : /opt/rudder/etc/rudder-users.xml
[2018-07-06 15:26:21] INFO  application - Use configuration file defined by JVM property -Drudder.authFile : /opt/rudder/etc/rudder-users.xml
[2018-07-06 15:26:22] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Node's target configuration built in 1685 ms, start to update rule values.
[2018-07-06 15:26:22] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Not updating non-modified node configuration: [51afb080-b672-458e-97d8-bd7fb92aac02]
[2018-07-06 15:26:22] INFO  com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Configuration of following nodes were updated, their promises are going to be written: [a45e71e7-d083-4067-b3e6-c2ba73e996b7, root]
[2018-07-06 15:26:23] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Reports updated in 49 ms
[2018-07-06 15:26:23] INFO  bootstrap.liftweb.Boot - classpath
[2018-07-06 15:26:24] INFO  application - Application Rudder started
2018-07-06 15:26:24.305:INFO:oejsh.ContextHandler:main: Started o.e.j.w.WebAppContext@41394595{/rudder,file:///var/rudder/tmp/jetty/jetty-rudder.war.dir/webapp/,AVAILABLE}{/rudder.war}
2018-07-06 15:26:24.342:INFO:oejs.AbstractConnector:main: Started ServerConnector@29e58169{HTTP/1.1,[http/1.1]}{127.0.0.1:8080}
2018-07-06 15:26:24.342:INFO:oejs.Server:main: Started @31543ms
2018-07-06 15:26:26.441:INFO:oejshC.rudder:Scanner-0: Closing Spring root WebApplicationContext
2018-07-06 15:26:26.545:INFO:oejsh.ContextHandler:Scanner-0: Stopped o.e.j.w.WebAppContext@41394595{/rudder,null,UNAVAILABLE}{/rudder.war}
java.lang.NoClassDefFoundError: cats/effect/internals/NonFatal$
        at cats.effect.internals.IORunLoop$.liftedTree3$1(IORunLoop.scala:207)
        at cats.effect.internals.IORunLoop$.step(IORunLoop.scala:207)
        at cats.effect.IO.unsafeRunTimed(IO.scala:308)

Actions #3

Updated by Nicolas CHARLES over 5 years ago

For readability: the full log file

Actions #4

Updated by François ARMAND over 5 years ago

It seems that the classpath was utterly broken in the that first run. I'm wondering if jetty was correctly restarted (if not, all the new clases, like the one in NoclassDefFound, would be missing). But it is unlikelly that in that case, rudder would even barelly works.

I checked the dependencies in cat effects etc, everything seems fine for that. So I'm really not sure about what happenned.

Actions #5

Updated by Nicolas CHARLES over 5 years ago

Upgrade output is

root@server:~# apt-get install rudder-server-root
Reading package lists... Done
Building dependency tree       
Reading state information... Done
The following additional packages will be installed:
  ncf ncf-api-virtualenv rudder-agent rudder-inventory-endpoint rudder-inventory-ldap rudder-jetty rudder-reports
  rudder-server-relay rudder-techniques rudder-webapp
Suggested packages:
  cfengine3 cfengine-community
The following packages will be upgraded:
  ncf ncf-api-virtualenv rudder-agent rudder-inventory-endpoint rudder-inventory-ldap rudder-jetty rudder-reports
  rudder-server-relay rudder-server-root rudder-techniques rudder-webapp
11 upgraded, 0 newly installed, 0 to remove and 115 not upgraded.
Need to get 162 MB of archives.
After this operation, 2,201 kB of additional disk space will be used.
Do you want to continue? [Y/n] Y
Get:1 http://www.rudder-project.org/apt-4.3-nightly stretch/main amd64 rudder-server-root all 4.3.3~rc1~git201807052338-stretch0 [5,578 B]
Get:2 http://www.rudder-project.org/apt-4.3-nightly stretch/main amd64 rudder-inventory-endpoint all 4.3.3~rc1~git201807052338-stretch0 [39.4 MB]
Get:3 http://www.rudder-project.org/apt-4.3-nightly stretch/main amd64 rudder-inventory-ldap amd64 4.3.3~rc1~git201807052338-stretch0 [1,008 kB]
Get:4 http://www.rudder-project.org/apt-4.3-nightly stretch/main amd64 rudder-jetty all 4.3.3~rc1~git201807052338-stretch0 [7,898 kB]
Get:5 http://www.rudder-project.org/apt-4.3-nightly stretch/main amd64 rudder-reports all 4.3.3~rc1~git201807052338-stretch0 [7,200 B]
Get:6 http://www.rudder-project.org/apt-4.3-nightly stretch/main amd64 rudder-agent amd64 4.3.3~rc1~git201807052338-stretch0 [3,143 kB]
Get:7 http://www.rudder-project.org/apt-4.3-nightly stretch/main amd64 rudder-webapp all 4.3.3~rc1~git201807052338-stretch0 [98.8 MB]
Get:8 http://www.rudder-project.org/apt-4.3-nightly stretch/main amd64 rudder-server-relay amd64 4.3.3~rc1~git201807052338-stretch0 [4,258 kB]
Get:9 http://www.rudder-project.org/apt-4.3-nightly stretch/main amd64 ncf-api-virtualenv all 4.3.3~rc1~git201807052338-stretch0 [2,690 kB]
Get:10 http://www.rudder-project.org/apt-4.3-nightly stretch/main amd64 rudder-techniques all 4.3.3~rc1~git201807052338-stretch0 [3,068 kB]
Get:11 http://www.rudder-project.org/apt-4.3-nightly stretch/main amd64 ncf all 4.3.3~rc1~git201807052338-stretch0 [1,299 kB]
Fetched 162 MB in 54s (2,975 kB/s)                                                                                     
Reading changelogs... Done
Preconfiguring packages ...
(Reading database ... 42244 files and directories currently installed.)
Preparing to unpack .../00-rudder-server-root_4.3.3~rc1~git201807052338-stretch0_all.deb ...
Unpacking rudder-server-root (4.3.3~rc1~git201807052338-stretch0) over (4.3.2-stretch0) ...
Preparing to unpack .../01-rudder-inventory-endpoint_4.3.3~rc1~git201807052338-stretch0_all.deb ...
Unpacking rudder-inventory-endpoint (4.3.3~rc1~git201807052338-stretch0) over (4.3.2-stretch0) ...
Preparing to unpack .../02-rudder-inventory-ldap_4.3.3~rc1~git201807052338-stretch0_amd64.deb ...
Unpacking rudder-inventory-ldap (4.3.3~rc1~git201807052338-stretch0) over (4.3.2-stretch0) ...
Preparing to unpack .../03-rudder-jetty_4.3.3~rc1~git201807052338-stretch0_all.deb ...
Unpacking rudder-jetty (4.3.3~rc1~git201807052338-stretch0) over (4.3.2-stretch0) ...
Preparing to unpack .../04-rudder-reports_4.3.3~rc1~git201807052338-stretch0_all.deb ...
Unpacking rudder-reports (4.3.3~rc1~git201807052338-stretch0) over (4.3.2-stretch0) ...
Preparing to unpack .../05-rudder-agent_4.3.3~rc1~git201807052338-stretch0_amd64.deb ...
INFO: A back up copy of the /opt/rudder/etc/uuid.hive has been created in /var/backups/rudder
INFO: A back up copy of the /var/rudder/cfengine-community/policy_server.dat has been created in /var/backups/rudder
INFO: A back up copy of the /var/rudder/cfengine-community/ppkeys has been created in /var/backups/rudder
Unpacking rudder-agent (4.3.3~rc1~git201807052338-stretch0) over (4.3.2-stretch0) ...
Preparing to unpack .../06-rudder-webapp_4.3.3~rc1~git201807052338-stretch0_all.deb ...
********************************************************************************
INFO: dpkg may ask you if you want to replace rudder-web.properties or          
INFO: inventory-web.properties with the maintainer version if you modified it.  
INFO:                                                                           
INFO: If you accept, please keep in mind that you will lose any manual          
INFO: modification in this file, like the syslog port or the workflows and will 
INFO: certainly have to add them again.                                         
INFO:                                                                           
INFO: We recommend that you respond NO to this question                         
INFO: ('keep your currently-installed version'). Rudder's upgrade script will   
INFO: take care of this automatically.                                          
INFO:                                                                           
********************************************************************************
Unpacking rudder-webapp (4.3.3~rc1~git201807052338-stretch0) over (4.3.2-stretch0) ...
Preparing to unpack .../07-rudder-server-relay_4.3.3~rc1~git201807052338-stretch0_amd64.deb ...
Unpacking rudder-server-relay (4.3.3~rc1~git201807052338-stretch0) over (4.3.2-stretch0) ...
Preparing to unpack .../08-ncf-api-virtualenv_4.3.3~rc1~git201807052338-stretch0_all.deb ...
Unpacking ncf-api-virtualenv (4.3.3~rc1~git201807052338-stretch0) over (4.3.2-stretch0) ...
Preparing to unpack .../09-rudder-techniques_4.3.3~rc1~git201807052338-stretch0_all.deb ...
Unpacking rudder-techniques (4.3.3~rc1~git201807052338-stretch0) over (4.3.2-stretch0) ...
Preparing to unpack .../10-ncf_4.3.3~rc1~git201807052338-stretch0_all.deb ...
Unpacking ncf (4.3.3~rc1~git201807052338-stretch0) over (4.3.2-stretch0) ...
Setting up rudder-jetty (4.3.3~rc1~git201807052338-stretch0) ...
Setting up ncf (4.3.3~rc1~git201807052338-stretch0) ...
Setting up rudder-techniques (4.3.3~rc1~git201807052338-stretch0) ...
Setting up rudder-inventory-ldap (4.3.3~rc1~git201807052338-stretch0) ...
INFO: Restarting syslogd... Done
INFO: Restarting rudder-slapd... Done
Processing triggers for systemd (232-25+deb9u1) ...
Setting up rudder-agent (4.3.3~rc1~git201807052338-stretch0) ...
ok: Rudder agent is now disabled.
ok: stop service rudder-agent succeeded
INFO: Ensuring correct permissions on the keys directory... Done.
ok: Rudder agent has been enabled but not started, wait for next cron run.
ok: start service rudder-agent succeeded
INFO: Scheduling an inventory during next run...
Setting up rudder-reports (4.3.3~rc1~git201807052338-stretch0) ...
INFO: Waiting for PostgreSQL to be up... Done
Processing triggers for rsyslog (8.24.0-1) ...
Setting up ncf-api-virtualenv (4.3.3~rc1~git201807052338-stretch0) ...
Conf ncf-api-virtualenv already enabled
INFO: Restarting Apache HTTPd... Done
Setting up rudder-server-relay (4.3.3~rc1~git201807052338-stretch0) ...
INFO: Restarting Apache HTTPd... Done
INFO: rudder-server-relay setup complete.
Setting up rudder-inventory-endpoint (4.3.3~rc1~git201807052338-stretch0) ...
INFO: Launching script to check if a migration is needed
INFO: End of migration script
Setting up rudder-webapp (4.3.3~rc1~git201807052338-stretch0) ...
INFO: Restarting syslog...Done
INFO: Restarting Apache HTTPd... Done
INFO: Launching script to check if a migration is needed
INFO: Checking if rudder-web.properties database access credentials are all right... LDAP OK,  SQL OK
INFO: Checking if inventory-web.properties database access credentials are all right... LDAP OK,  SQL skipped
INFO: A Technique library reload is needed and has been scheduled.
[master 950d919] Update technique editor hook "ncf-hooks.d/post.write_technique.10_commit.sh" 
[master ac46493] Update technique editor hook "ncf-hooks.d/post.write_technique.50_rudderify.sh" 
INFO: Alternative source path added: /var/rudder/configuration-repository/ncf
INFO: Alternative source path added: /var/rudder/configuration-repository/ncf
INFO: Alternative source path added: /var/rudder/configuration-repository/ncf
INFO: The /var/rudder/configuration-repository/techniques/ncf_techniques/category.xml file already exists. Not updating.
INFO: Alternative source path added: /var/rudder/configuration-repository/ncf
INFO: Checking PostgreSQL service status... OK
INFO: Checking LDAP service status... OK
[master 8275fa7] Installing rudder-agent-dsc source in configuration-repository
 3 files changed, 63 insertions(+), 19 deletions(-)
 create mode 100644 dsc/ncf/30_generic_methods/service_started.ps1
 delete mode 100644 ncf/50_techniques/service_start/service_start.cf
INFO: An update of Techniques is needed and has been scheduled at next webapp startup.

INFO: The migration has completed successfully.
INFO: End of migration script
[master d0d9cf8] Add ncf hooks to repository
enable /opt/rudder/share/plugins/dsc/rudder-plugin-dsc.jar
[]
Restarting jetty
 $ service rudder-jetty restart
INFO: Restarting Rudder webapp and inventory-endpoint... Done
Setting up rudder-server-root (4.3.3~rc1~git201807052338-stretch0) ...

According to logs, the webapp has restarted a 15:25, so the time of the update

Actions #6

Updated by Vincent MEMBRÉ over 5 years ago

  • Target version changed from 4.3.3 to 4.3.4
Actions #7

Updated by Alexis Mousset over 5 years ago

  • Category set to Packaging
Actions #8

Updated by Benoît PECCATTE over 5 years ago

  • Target version changed from 4.3.4 to 4.3.5
Actions #9

Updated by Vincent MEMBRÉ over 5 years ago

  • Target version changed from 4.3.5 to 4.3.6
Actions #10

Updated by Vincent MEMBRÉ over 5 years ago

  • Target version changed from 4.3.6 to 4.3.7
Actions #11

Updated by François ARMAND over 5 years ago

  • Subject changed from Chaos after upgrading from rudder 4.3.2 to 4.3 nightly to During upgrade, jetty doesn't seems to always restart correctly
  • Description updated (diff)

I also had an instance of such a bad jetty restart leading to chaos (NoSuchMethod errors and the like).

Jetty hadn't restarted correctly in that case, even if the restart command had been done (I was able to tell so because of the comand line in ps aux).

Actions #12

Updated by Vincent MEMBRÉ over 5 years ago

  • Target version changed from 4.3.7 to 4.3.8
Actions #13

Updated by Vincent MEMBRÉ about 5 years ago

  • Target version changed from 4.3.8 to 4.3.9
Actions #14

Updated by Alexis Mousset about 5 years ago

  • Target version changed from 4.3.9 to 4.3.10
Actions #15

Updated by François ARMAND about 5 years ago

  • Target version changed from 4.3.10 to 4.3.11
Actions #16

Updated by Vincent MEMBRÉ almost 5 years ago

  • Target version changed from 4.3.11 to 4.3.12
Actions #17

Updated by Benoît PECCATTE almost 5 years ago

  • Severity set to Minor - inconvenience | misleading | easy workaround
  • User visibility set to Operational - other Techniques | Rudder settings | Plugins
  • Priority changed from 0 to 28
Actions #18

Updated by François ARMAND almost 5 years ago

So, there is a problem with Jetty restarts. Perhaps due to systemd.

We have implemented a workaround for an other bug that also take care of that one (#14281), which mean that the root cause will be harder to find, but at least people won't experience broken rudder for hard to diagnose reason.

I'm putting the "severity" to "major" even if it should be worked around now because there is still a big risk of Rudder not taking into account new properties for no easy to diagnose reason.

Actions #19

Updated by François ARMAND almost 5 years ago

  • Severity changed from Minor - inconvenience | misleading | easy workaround to Major - prevents use of part of Rudder | no simple workaround
  • Priority changed from 28 to 45
Actions #20

Updated by Vincent MEMBRÉ almost 5 years ago

  • Target version changed from 4.3.12 to 4.3.13
  • Priority changed from 45 to 44
Actions #21

Updated by Vincent MEMBRÉ almost 5 years ago

  • Target version changed from 4.3.13 to 4.3.14
Actions #22

Updated by Vincent MEMBRÉ over 4 years ago

  • Target version changed from 4.3.14 to 587
  • Priority changed from 44 to 43
Actions #23

Updated by Vincent MEMBRÉ over 4 years ago

  • Target version changed from 587 to 4.3.14
Actions #24

Updated by Vincent MEMBRÉ over 4 years ago

  • Target version changed from 4.3.14 to 5.0.13
Actions #25

Updated by Vincent MEMBRÉ over 4 years ago

  • Target version changed from 5.0.13 to 5.0.14
Actions #26

Updated by Vincent MEMBRÉ over 4 years ago

  • Target version changed from 5.0.14 to 5.0.15
Actions #27

Updated by Vincent MEMBRÉ over 4 years ago

  • Target version changed from 5.0.15 to 5.0.16
Actions #28

Updated by François ARMAND over 4 years ago

  • Has duplicate Bug #16424: After plugin installation the webapp is super long to restart added
Actions #29

Updated by François ARMAND about 4 years ago

So, I think that the problem is that by default, and we didn't changed that default, jetty scan the directory `/opt/rudder/share/webapp` every second and looks for change in files. In case of change, it redeploys the war, which is totally not supported by rudder/scala/lift/whoever the culprit and breaks loaded classes.

So, I'm almost sure that depending how the package upgrade happens, the war or xml file can be touched (and updated) while jetty is still (or already) started, and so jetty wants to help and redeploy the war and breaks everything.

The faulty config parameter is in `/opt/rudder/etc/rudder-jetty-base/start.ini`: `jetty.deploy.scanInterval`.
We need to set it to 0 (don't scan).

Actions #30

Updated by François ARMAND about 4 years ago

  • Status changed from New to In progress
  • Assignee set to François ARMAND
Actions #31

Updated by François ARMAND about 4 years ago

  • Status changed from In progress to Pending technical review
  • Assignee changed from François ARMAND to Nicolas CHARLES
  • Pull Request set to https://github.com/Normation/rudder-packages/pull/2196
Actions #32

Updated by François ARMAND about 4 years ago

  • Status changed from Pending technical review to Pending release
Actions #34

Updated by François ARMAND about 4 years ago

  • Fix check set to To do
Actions #35

Updated by François ARMAND about 4 years ago

  • Fix check changed from To do to Checked

I can confirm that the option make jetty not redeploy war when it changes on FS.
No other behavior seems to have changed (rudder installs and starts the same, etc).

Actions #36

Updated by Alexis Mousset about 4 years ago

  • Name check set to Reviewed
Actions #37

Updated by Vincent MEMBRÉ about 4 years ago

  • Status changed from Pending release to Released

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

Actions

Also available in: Atom PDF