Actions
Bug #10165
closedIncomplete inventory for one node - race condition?
Pull Request:
Severity:
UX impact:
User visibility:
Effort required:
Priority:
Name check:
Fix check:
Regression:
Description
Some fields were missing in the displayed inventory of a node (machine type, manufacturer, while they were in the inventory file, and the other identical machines). It fixed itself after a second inventory.
Log excerpt:
# grep -R 10289d03 /var/log/rudder/webapp/ /var/log/rudder/webapp/2017_02_09.stderrout.log:[2017-02-09 13:50:41] INFO com.normation.inventory.provisioning.endpoint.FusionReportEndpoint - New input inventory: 'relay-10289d03-99b3-483e-a7de-0160101927de.ocs' /var/log/rudder/webapp/2017_02_09.stderrout.log:[2017-02-09 13:50:42] INFO com.normation.inventory.provisioning.endpoint.FusionReportEndpoint - Inventory 'relay-10289d03-99b3-483e-a7de-0160101927de.ocs' parsed in 1 second and 583 milliseconds ms, now checking signature /var/log/rudder/webapp/2017_02_09.stderrout.log:[2017-02-09 13:50:43] INFO com.normation.inventory.provisioning.endpoint.FusionReportEndpoint - Inventory 'relay-10289d03-99b3-483e-a7de-0160101927de.ocs' signature checked in 395 milliseconds ms, now saving /var/log/rudder/webapp/2017_02_09.stderrout.log:[2017-02-09 14:35:30] ERROR com.normation.ldap.sdk.RwLDAPConnection - Exception ignored (by configuration) when trying to add entry 'nodeId=10289d03-99b3-483e-a7de-0160101927de,ou=Nodes,cn=rudder-configuration'. Reported exception was: entry already exists /var/log/rudder/webapp/2017_02_09.stderrout.log:[2017-02-09 14:35:30] ERROR com.normation.rudder.services.servers.NewNodeManagerImpl - Error when trying to accept node 10289d03-99b3-483e-a7de-0160101927de. Rollbacking. <- Error when executing accept node process named accept_new_server:inventory <- Can not move 'nodeId=10289d03-99b3-483e-a7de-0160101927de,ou=Nodes,ou=Pending Inventories,ou=Inventories,cn=rudder-configuration' to new parent 'ou=Nodes,ou=Accepted Inventories,ou=Inventories,cn=rudder-configuration': no such object /var/log/rudder/webapp/2017_02_09.stderrout.log:[2017-02-09 14:35:30] ERROR com.normation.inventory.ldap.core.FullInventoryRepositoryImpl - Error when updating the container value when moving nodes '10289d03-99b3-483e-a7de-0160101927de' <- Can not apply modifiction on 'nodeId=10289d03-99b3-483e-a7de-0160101927de,ou=Nodes,ou=Accepted Inventories,ou=Inventories,cn=rudder-configuration': no such object /var/log/rudder/webapp/2017_02_09.stderrout.log:[2017-02-09 14:35:30] INFO com.normation.rudder.services.servers.NewNodeManagerImpl - New node accepted and managed by Rudder: 10289d03-99b3-483e-a7de-0160101927de /var/log/rudder/webapp/2017_02_09.stderrout.log:[2017-02-09 14:35:30] ERROR com.normation.rudder.services.servers.NewNodeManagerImpl - Unit acceptor error for node NodeId(10289d03-99b3-483e-a7de-0160101927de) <- Error when trying to accept node 10289d03-99b3-483e-a7de-0160101927de <- Error when executing accept node process named accept_new_server:inventory <- Can not move 'nodeId=10289d03-99b3-483e-a7de-0160101927de,ou=Nodes,ou=Pending Inventories,ou=Inventories,cn=rudder-configuration' to new parent 'ou=Nodes,ou=Accepted Inventories,ou=Inventories,cn=rudder-configuration': no such object /var/log/rudder/webapp/2017_02_09.stderrout.log:[2017-02-09 14:35:30] ERROR com.normation.rudder.web.snippet.node.AcceptNode - Something bad happened while searching for node 10289d03-99b3-483e-a7de-0160101927de to log the acceptation, search 10289d03-99b3-483e-a7de-0160101927de /var/log/rudder/webapp/2017_02_09.stderrout.log:[2017-02-09 14:45:15] INFO com.normation.rudder.services.servers.NewNodeManagerImpl - New node accepted and managed by Rudder: 10289d03-99b3-483e-a7de-0160101927de /var/log/rudder/webapp/2017_02_09.stderrout.log:[2017-02-09 14:45:15] INFO com.normation.rudder.batch.UpdateDynamicGroups$LAUpdateDyngroupManager - Dynamic group hasPolicyServer-root: added node with id: [ 10289d03-99b3-483e-a7de-0160101927de ], removed: nothing /var/log/rudder/webapp/2017_02_09.stderrout.log:[2017-02-09 14:45:16] INFO com.normation.rudder.services.policies.nodeconfig.NodeConfigurationServiceImpl - Configuration of following nodes were updated, their promises are going to be written: [10289d03-99b3-483e-a7de-0160101927de, root] /var/log/rudder/webapp/2017_02_09.stderrout.log:[2017-02-09 14:45:35] WARN explain_compliance.10289d03-99b3-483e-a7de-0160101927de - Can not get compliance for node with ID '10289d03-99b3-483e-a7de-0160101927de' because it has no configuration id initialised nor sent reports (node just added ?) /var/log/rudder/webapp/2017_02_09.stderrout.log:[2017-02-09 14:46:31] INFO com.normation.rudder.services.policies.nodeconfig.NodeConfigurationServiceImpl - Configuration of following nodes were updated, their promises are going to be written: [10289d03-99b3-483e-a7de-0160101927de] /var/log/rudder/webapp/2017_02_09.stderrout.log:[2017-02-09 14:52:45] INFO com.normation.rudder.batch.UpdateDynamicGroups$LAUpdateDyngroupManager - Dynamic group hasPolicyServer-10289d03-99b3-483e-a7de-0160101927de: added node with id: [ 3e9baed9-21d6-4090-9830-c51874dc2eef ], removed: nothing /var/log/rudder/webapp/2017_02_09.stderrout.log:[2017-02-09 14:52:59] INFO com.normation.rudder.services.policies.nodeconfig.NodeConfigurationServiceImpl - Configuration of following nodes were updated, their promises are going to be written: [3e9baed9-21d6-4090-9830-c51874dc2eef, 10289d03-99b3-483e-a7de-0160101927de, root] /var/log/rudder/webapp/2017_02_09.stderrout.log:[2017-02-09 15:18:07] INFO com.normation.inventory.provisioning.endpoint.FusionReportEndpoint - New input inventory: 'relay-10289d03-99b3-483e-a7de-0160101927de.ocs' /var/log/rudder/webapp/2017_02_09.stderrout.log:[2017-02-09 15:18:07] INFO com.normation.inventory.provisioning.endpoint.FusionReportEndpoint - Inventory 'relay-10289d03-99b3-483e-a7de-0160101927de.ocs' parsed in 453 milliseconds ms, now checking signature /var/log/rudder/webapp/2017_02_09.stderrout.log:[2017-02-09 15:18:07] INFO com.normation.inventory.provisioning.endpoint.FusionReportEndpoint - Inventory 'relay-10289d03-99b3-483e-a7de-0160101927de.ocs' signature checked in 223 milliseconds ms, now saving
Acceptation:
[2017-02-09 13:50:41] INFO com.normation.inventory.provisioning.endpoint.FusionReportEndpoint - New input inventory: 'relay-10289d03-99b3-483e-a7de-0160101927de.ocs' [2017-02-09 13:50:42] INFO com.normation.inventory.provisioning.endpoint.FusionReportEndpoint - Inventory 'relay-10289d03-99b3-483e-a7de-0160101927de.ocs' parsed in 1 second and 583 milliseconds ms, now checking signature [2017-02-09 13:50:43] INFO com.normation.inventory.provisioning.endpoint.FusionReportEndpoint - Inventory 'relay-10289d03-99b3-483e-a7de-0160101927de.ocs' signature checked in 395 milliseconds ms, now saving [2017-02-09 13:50:43] INFO com.normation.inventory.provisioning.endpoint.FusionReportEndpoint - New input inventory: 'server-root.ocs' [2017-02-09 13:50:44] INFO com.normation.inventory.provisioning.endpoint.FusionReportEndpoint - Inventory 'server-root.ocs' parsed in 1 second and 261 milliseconds ms, now checking signature [2017-02-09 13:50:45] INFO com.normation.inventory.provisioning.endpoint.FusionReportEndpoint - Inventory 'server-root.ocs' signature checked in 508 milliseconds ms, now saving [2017-02-09 13:50:50] INFO com.normation.inventory.provisioning.endpoint.FusionReportEndpoint - Report file processed in 6 seconds and 540 milliseconds ms [2017-02-09 13:50:51] INFO com.normation.inventory.provisioning.endpoint.FusionReportEndpoint - Report file processed in 1 second and 460 milliseconds ms [2017-02-09 14:35:30] ERROR com.normation.ldap.sdk.RwLDAPConnection - Exception ignored (by configuration) when trying to add entry 'nodeId=10289d03-99b3-483e-a7de-0160101927de,ou=Nodes,cn=rudder-configuration'. Reported exception was: entry already exists com.unboundid.ldap.sdk.LDAPException: entry already exists >-at com.unboundid.ldap.sdk.LDAPConnection.add(LDAPConnection.java:1959) >-at com.normation.ldap.sdk.RwLDAPConnection.$anonfun$addAction$3(LDAPConnection.scala:524) >-at scala.util.control.Exception$Catch.apply(Exception.scala:224) >-at com.normation.ldap.sdk.RwLDAPConnection.$anonfun$addAction$1(LDAPConnection.scala:524) >-at com.normation.ldap.sdk.RwLDAPConnection.applyMod(LDAPConnection.scala:489) >-at com.normation.ldap.sdk.RwLDAPConnection.$anonfun$applyAdd$2(LDAPConnection.scala:535) >-at com.normation.ldap.sdk.RwLDAPConnection.save(LDAPConnection.scala:598) >-at com.normation.rudder.services.servers.AcceptFullInventoryInNodeOu.$anonfun$acceptOne$9(NewNodeManager.scala:731) >-at com.normation.ldap.sdk.LDAPConnectionProvider.$anonfun$flatMap$1(LDAPConnectionProvider.scala:117) >-at com.normation.ldap.sdk.LDAPConnectionProvider.withCon(LDAPConnectionProvider.scala:154) >-at com.normation.ldap.sdk.LDAPConnectionProvider.withCon$(LDAPConnectionProvider.scala:143) >-at com.normation.ldap.sdk.RWPooledSimpleAuthConnectionProvider.withCon(LDAPConnectionProvider.scala:385) >-at com.normation.ldap.sdk.LDAPConnectionProvider.flatMap(LDAPConnectionProvider.scala:116) >-at com.normation.ldap.sdk.LDAPConnectionProvider.flatMap$(LDAPConnectionProvider.scala:115) >-at com.normation.ldap.sdk.RWPooledSimpleAuthConnectionProvider.flatMap(LDAPConnectionProvider.scala:385) >-at com.normation.rudder.services.servers.AcceptFullInventoryInNodeOu.acceptOne(NewNodeManager.scala:730) >-at com.normation.rudder.services.servers.ComposedNewNodeManager.$anonfun$acceptOne$1(NewNodeManager.scala:425) >-at com.normation.utils.Control$.$anonfun$sequence$1(Control.scala:54) >-at scala.collection.immutable.List.foreach(List.scala:378) >-at com.normation.utils.Control$.sequence(Control.scala:54) >-at com.normation.rudder.services.servers.ComposedNewNodeManager.acceptOne(NewNodeManager.scala:423) >-at com.normation.rudder.services.servers.ComposedNewNodeManager.accept(NewNodeManager.scala:475) >-at com.normation.rudder.services.servers.ComposedNewNodeManager.accept$(NewNodeManager.scala:441) >-at com.normation.rudder.services.servers.NewNodeManagerImpl.accept(NewNodeManager.scala:155) >-at com.normation.rudder.web.snippet.node.AcceptNode.$anonfun$addNodes$1(AcceptNode.scala:163) >-at com.normation.rudder.web.snippet.node.AcceptNode.$anonfun$addNodes$1$adapted(AcceptNode.scala:161) >-at scala.collection.immutable.List.foreach(List.scala:378) >-at com.normation.rudder.web.snippet.node.AcceptNode.addNodes(AcceptNode.scala:161) >-at com.normation.rudder.web.snippet.node.AcceptNode.$anonfun$listNode$6(AcceptNode.scala:312) >-at net.liftweb.http.S$NFuncHolder.$anonfun$apply$3(S.scala:185) >-at scala.collection.immutable.List.map(List.scala:272) >-at net.liftweb.http.S$NFuncHolder.apply(S.scala:185) >-at net.liftweb.http.S$ProxyFuncHolder.apply(S.scala:114) .... >-at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:667) >-at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:52) >-at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608) >-at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543) >-at java.lang.Thread.run(Thread.java:745) [2017-02-09 14:35:30] ERROR com.normation.rudder.services.servers.NewNodeManagerImpl - Error when trying to accept node 10289d03-99b3-483e-a7de-0160101927de. Rollbacking. <- Error when executing accept node process named accept_new_server:inventory <- Can not move 'nodeId=10289d03-99b3-483e-a7de-0160101927de,ou=Nodes,ou=Pending Inventories,ou=Inventories,cn=rudder-configuration' to new parent 'ou=Nodes,ou=Accepted Inventories,ou=Inventories,cn=rudder-configuration': no such object [2017-02-09 14:35:30] ERROR com.normation.inventory.ldap.core.FullInventoryRepositoryImpl - Error when updating the container value when moving nodes '10289d03-99b3-483e-a7de-0160101927de' <- Can not apply modifiction on 'nodeId=10289d03-99b3-483e-a7de-0160101927de,ou=Nodes,ou=Accepted Inventories,ou=Inventories,cn=rudder-configuration': no such object [2017-02-09 14:35:30] ERROR com.normation.inventory.ldap.core.FullInventoryRepositoryImpl - Exception was: com.unboundid.ldap.sdk.LDAPException: no such object >-at com.unboundid.ldap.sdk.LDAPConnection.modify(LDAPConnection.java:2754) >-at com.normation.ldap.sdk.RwLDAPConnection.$anonfun$modifyAction$3(LDAPConnection.scala:541) >-at scala.util.control.Exception$Catch.apply(Exception.scala:224) >-at com.normation.ldap.sdk.RwLDAPConnection.$anonfun$modifyAction$1(LDAPConnection.scala:541) >-at com.normation.ldap.sdk.RwLDAPConnection.applyMod(LDAPConnection.scala:489) >-at com.normation.ldap.sdk.RwLDAPConnection.$anonfun$applyModify$2(LDAPConnection.scala:552) >-at com.normation.ldap.sdk.RwLDAPConnection.modify(LDAPConnection.scala:564) >-at com.normation.inventory.ldap.core.FullInventoryRepositoryImpl.$anonfun$updateNodes$2(FullInventoryRepositoryImpl.scala:148) >-at com.normation.utils.Control$.$anonfun$bestEffort$1(Control.scala:111) >-at scala.collection.immutable.List.foreach(List.scala:378) >-at com.normation.utils.Control$.bestEffort(Control.scala:111) >-at com.normation.inventory.ldap.core.FullInventoryRepositoryImpl.updateNodes(FullInventoryRepositoryImpl.scala:147) >-at com.normation.inventory.ldap.core.FullInventoryRepositoryImpl.$anonfun$move$9(FullInventoryRepositoryImpl.scala:216) >-at net.liftweb.common.Full.flatMap(Box.scala:808) >-at com.normation.inventory.ldap.core.FullInventoryRepositoryImpl.$anonfun$move$4(FullInventoryRepositoryImpl.scala:187) >-at net.liftweb.common.Full.flatMap(Box.scala:808) >-at com.normation.inventory.ldap.core.FullInventoryRepositoryImpl.move(FullInventoryRepositoryImpl.scala:181) >-at com.normation.inventory.ldap.core.FullInventoryRepositoryImpl.$anonfun$move$15(FullInventoryRepositoryImpl.scala:408) >-at net.liftweb.common.Full.flatMap(Box.scala:808) >-at net.liftweb.common.Box$WithFilter.flatMap(Box.scala:475) >-at com.normation.inventory.ldap.core.FullInventoryRepositoryImpl.$anonfun$move$13(FullInventoryRepositoryImpl.scala:407) >-at net.liftweb.common.Full.map(Box.scala:806) >-at com.normation.inventory.ldap.core.FullInventoryRepositoryImpl.$anonfun$move$12(FullInventoryRepositoryImpl.scala:400) >-at net.liftweb.common.Full.flatMap(Box.scala:808) >-at com.normation.inventory.ldap.core.FullInventoryRepositoryImpl.move(FullInventoryRepositoryImpl.scala:397) >-at com.normation.rudder.services.servers.AcceptInventory.acceptOne(NewNodeManager.scala:657) >-at com.normation.rudder.services.servers.ComposedNewNodeManager.$anonfun$acceptOne$1(NewNodeManager.scala:425) >-at com.normation.utils.Control$.$anonfun$sequence$1(Control.scala:54) >-at scala.collection.immutable.List.foreach(List.scala:378) ... >-at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:464) >-at org.eclipse.jetty.server.AbstractHttpConnection.content(AbstractHttpConnection.java:924) >-at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.content(AbstractHttpConnection.java:985) >-at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:861) >-at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:236) >-at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82) >-at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:667) >-at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:52) >-at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608) >-at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543) >-at java.lang.Thread.run(Thread.java:745) [2017-02-09 14:35:30] INFO com.normation.rudder.services.servers.NewNodeManagerImpl - New node accepted and managed by Rudder: 10289d03-99b3-483e-a7de-0160101927de [2017-02-09 14:35:30] ERROR com.normation.rudder.services.servers.NewNodeManagerImpl - Unit acceptor error for node NodeId(10289d03-99b3-483e-a7de-0160101927de) <- Error when trying to accept node 10289d03-99b3-483e-a7de-0160101927de <- Error when executing accept node process named accept_new_server:inventory <- Can not move 'nodeId=10289d03-99b3-483e-a7de-0160101927de,ou=Nodes,ou=Pending Inventories,ou=Inventories,cn=rudder-configuration' to new parent 'ou=Nodes,ou=Accepted Inventories,ou=Inventories,cn=rudder-configuration': no such object [2017-02-09 14:35:30] ERROR com.normation.rudder.web.snippet.node.AcceptNode - Something bad happened while searching for node 10289d03-99b3-483e-a7de-0160101927de to log the acceptation, search 10289d03-99b3-483e-a7de-0160101927de [2017-02-09 14:40:23] INFO com.normation.cfclerk.services.impl.TechniqueRepositoryImpl - Reloading technique library, found modified technique(s): ['ffrfrezf': updated (1.0: VersionAdded)] [2017-02-09 14:40:23] INFO com.normation.rudder.services.policies.TechniqueAcceptationUpdater - Automatically adding technique 'ffrfrezf' in category 'User Techniques (4a63c5a3-347c-4a75-9786-e59b534f2944)' of active techniques library
Actions