Bug #10434: Error on one inventory when trying to accept 100 inventories at the same time - Rudder - Issue Tracker

Actions

Copy link

Bug #10434

closed

Error on one inventory when trying to accept 100 inventories at the same time

Added by Nicolas CHARLES over 7 years ago. Updated almost 3 years ago.

Status:

Rejected

Priority:

N/A

Assignee:

Category:

Web - Nodes & inventories

Target version:

6.1.19

Pull Request:

Severity:

Minor - inconvenience | misleading | easy workaround

UX impact:

User visibility:

Operational - other Techniques | Technique editor | Rudder settings

Effort required:

Priority:

Name check:

Fix check:

Regression:

Description

On 4.1, when trying to accept 500 inventories, there is one which is failing with following error message in the web interface
Error when trying to accept node xxxx <- The connection is not established

Error in log is

[2017-03-15 22:28:42] ERROR com.normation.rudder.services.servers.NewNodeManagerImpl - Unit acceptor error for node NodeId(44936c20-2e1a-4673-bb49-eb6fa4faad39) <- Error when trying to accept node 44936c20-2e1a-4673-bb49-eb6fa4faad39 <- The connection is not established.

Don't know which connection - slapd doesn't complain at all

Related issues 1 (1 open — 0 closed)

Actions

Copy link

Updated by Nicolas CHARLES over 7 years ago

Subject changed from Error on one inventory when trying to accept 500 inventories at the same time to Error on one inventory when trying to accept 100 inventories at the same time
Description updated (diff)

Actions

Copy link

Updated by Nicolas CHARLES over 7 years ago

Here is the error
Error when trying to accept node 9c4d80a6-00fb-4a7e-96a2-bda4a27c00ea <- The connection is not established.

2017-03-16 13:25:06] DEBUG com.zaxxer.hikari.pool.PoolBase - HikariPool-1 - Reset (autoCommit) on connection org.postgresql.jdbc4.Jdbc4Connection@25a32fb
[2017-03-16 13:25:06] DEBUG com.normation.rudder.services.servers.NewNodeManagerImpl - Pre accepted phase: accept_or_refuse_new_node:historize_inventory
[2017-03-16 13:25:06] DEBUG com.normation.rudder.services.servers.NewNodeManagerImpl - Pre accepted phase: accept_new_server:ou=node
[2017-03-16 13:25:06] DEBUG com.normation.rudder.services.servers.NewNodeManagerImpl - Pre accepted phase: accept_new_server:inventory
[2017-03-16 13:25:06] DEBUG com.normation.rudder.services.servers.NewNodeManagerImpl - Pre accepted phase: accept_new_server:check_hostname_unicity
[2017-03-16 13:25:06] DEBUG com.normation.rudder.services.servers.NewNodeManagerImpl - Exception in unit acceptor accept_new_server:inventory
com.unboundid.ldap.sdk.LDAPSearchException: The connection is not established.
        at com.unboundid.ldap.sdk.LDAPConnection.search(LDAPConnection.java:3645)
        at com.unboundid.ldap.sdk.LDAPConnection.getEntry(LDAPConnection.java:1712)
        at com.normation.ldap.sdk.RoLDAPConnection.get(LDAPConnection.scala:314)
        at com.normation.ldap.sdk.ReadOnlyEntryLDAPConnection.exists(LDAPConnection.scala:126)
        at com.normation.ldap.sdk.ReadOnlyEntryLDAPConnection.exists$(LDAPConnection.scala:126)
        at com.normation.ldap.sdk.RoLDAPConnection.exists(LDAPConnection.scala:283)
        at com.normation.inventory.ldap.core.FullInventoryRepositoryImpl.$anonfun$getExistingMachineDN$1(FullInventoryRepositoryImpl.scala:98)
        at scala.collection.TraversableLike.$anonfun$map$1(TraversableLike.scala:234)
        at scala.collection.immutable.List.foreach(List.scala:378)
        at scala.collection.TraversableLike.map(TraversableLike.scala:234)
        at scala.collection.TraversableLike.map$(TraversableLike.scala:227)
        at scala.collection.immutable.List.map(List.scala:284)
        at com.normation.inventory.ldap.core.FullInventoryRepositoryImpl.getExistingMachineDN(FullInventoryRepositoryImpl.scala:96)
        at com.normation.inventory.ldap.core.FullInventoryRepositoryImpl.$anonfun$move$4(FullInventoryRepositoryImpl.scala:188)
        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 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:164)
        at com.normation.rudder.web.snippet.node.AcceptNode.$anonfun$addNodes$1$adapted(AcceptNode.scala:162)
        at scala.collection.immutable.List.foreach(List.scala:378)
        at com.normation.rudder.web.snippet.node.AcceptNode.addNodes(AcceptNode.scala:162)
        at com.normation.rudder.web.snippet.node.AcceptNode.$anonfun$listNode$6(AcceptNode.scala:313)
        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 net.liftweb.http.LiftSession.$anonfun$runParams$8(LiftSession.scala:558)
        at net.liftweb.http.LiftSession.$anonfun$runParams$17(LiftSession.scala:571)
       at scala.collection.immutable.List.map(List.scala:272)
        at net.liftweb.http.LiftSession.$anonfun$runParams$13(LiftSession.scala:571)
        at scala.collection.immutable.List.flatMap(List.scala:324)
        at net.liftweb.http.LiftSession.runParams(LiftSession.scala:561)
        at net.liftweb.http.LiftSession.processRequest(LiftSession.scala:1038)
        at net.liftweb.http.LiftServlet.net$liftweb$http$LiftServlet$$dispatchStatefulRequest(LiftServlet.scala:543)
        at net.liftweb.http.LiftServlet$StatefulResponse$.$anonfun$process$3(LiftServlet.scala:385)
        at net.liftweb.http.S.wrapQuery(S.scala:1562)
        at net.liftweb.http.S.$anonfun$_nest2InnerInit$2(S.scala:1729)
        at net.liftweb.http.S.doAround(S.scala:1491)
        at net.liftweb.http.S.$anonfun$_nest2InnerInit$1(S.scala:1717)
        at net.liftweb.util.ThreadGlobal.doWith(ThreadGlobal.scala:71)
        at net.liftweb.http.S._nest2InnerInit(S.scala:1716)
        at net.liftweb.http.S.$anonfun$_innerInit$5(S.scala:1762)
        at net.liftweb.util.ThreadGlobal.doWith(ThreadGlobal.scala:71)
        at net.liftweb.http.S.$anonfun$withReq$2(S.scala:1773)
        at net.liftweb.util.ThreadGlobal.doWith(ThreadGlobal.scala:71)
        at net.liftweb.http.S.withReq(S.scala:1772)
        at net.liftweb.http.S.withReq$(S.scala:1770)
        at net.liftweb.http.S$.withReq(S.scala:47)
(snip)
        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)
Caused by: com.unboundid.ldap.sdk.LDAPException: The connection is not established.
        at com.unboundid.ldap.sdk.LDAPConnection.registerResponseAcceptor(LDAPConnection.java:4476)
        at com.unboundid.ldap.sdk.SearchRequest.processAsync(SearchRequest.java:1373)
        at com.unboundid.ldap.sdk.SearchRequest.process(SearchRequest.java:1135)
        at com.unboundid.ldap.sdk.LDAPConnection.search(LDAPConnection.java:3635)
        ... 199 common frames omitted
[2017-03-16 13:25:06] ERROR com.normation.rudder.services.servers.NewNodeManagerImpl - Error when trying to accept node 9c4d80a6-00fb-4a7e-96a2-bda4a27c00ea. Rollbacking. <- The connection is not established.
[2017-03-16 13:25:06] DEBUG com.normation.rudder.services.servers.NewNodeManagerImpl - 
*****************************************************
Rollbacking
*****************************************************
[2017-03-16 13:25:06] DEBUG com.normation.rudder.services.servers.NewNodeManagerImpl - Rollbacking accept_new_server:check_hostname_unicity for 9c4d80a6-00fb-4a7e-96a2-bda4a27c00ea
[2017-03-16 13:25:06] DEBUG com.normation.rudder.services.servers.NewNodeManagerImpl - Rollbacking accept_new_server:inventory for 9c4d80a6-00fb-4a7e-96a2-bda4a27c00ea
[2017-03-16 13:25:06] DEBUG com.normation.rudder.services.servers.AcceptInventory - Succesfully rollbacked NodeId(9c4d80a6-00fb-4a7e-96a2-bda4a27c00ea) for process 'accept_new_server:inventory'
[2017-03-16 13:25:06] DEBUG com.normation.rudder.services.servers.NewNodeManagerImpl - Rollbacking accept_new_server:ou=node for 9c4d80a6-00fb-4a7e-96a2-bda4a27c00ea
[2017-03-16 13:25:06] DEBUG com.normation.rudder.services.servers.AcceptFullInventoryInNodeOu - Succesfully rollbacked NodeId(9c4d80a6-00fb-4a7e-96a2-bda4a27c00ea) for process 'accept_new_server:ou=node'
[2017-03-16 13:25:06] DEBUG com.normation.rudder.services.servers.NewNodeManagerImpl - Rollbacking accept_or_refuse_new_node:historize_inventory for 9c4d80a6-00fb-4a7e-96a2-bda4a27c00ea
[2017-03-16 13:25:06] ERROR com.normation.rudder.services.servers.NewNodeManagerImpl - Unit acceptor error for node NodeId(9c4d80a6-00fb-4a7e-96a2-bda4a27c00ea) <- Error when trying to accept node 9c4d80a6-00fb-4a7e-96a2-bda4a27c00ea <- The connection is not established.
[2017-03-16 13:25:06] DEBUG com.normation.rudder.services.servers.NewNodeManagerImpl - Pre accepted phase: accept_or_refuse_new_node:historize_inventory
[2017-03-16 13:25:06] DEBUG com.normation.rudder.services.servers.NewNodeManagerImpl - Pre accepted phase: accept_new_server:ou=node
[2017-03-16 13:25:06] DEBUG com.normation.rudder.services.servers.NewNodeManagerImpl - Pre accepted phase: accept_new_server:inventory
[2017-03-16 13:25:06] DEBUG com.normation.rudder.services.servers.NewNodeManagerImpl - Pre accepted phase: accept_new_server:check_hostname_unicity
[2017-03-16 13:25:06] DEBUG com.normation.rudder.services.servers.NewNodeManagerImpl - Unit acceptors ok for NodeId(7bb32578-d893-4f56-8555-bdc2b5ca680c)
[2017-03-16 13:25:06] INFO  com.normation.rudder.services.servers.NewNodeManagerImpl - New node accepted and managed by Rudder: 7bb32578-d893-4f56-8555-bdc2b5ca680c
[2017-03-16 13:25:07] DEBUG com.zaxxer.hikari.pool.PoolBase - HikariPool-1 - Reset (autoCommit) on connection org.postgresql.jdbc4.Jdbc4Connection@152da6f4
[2017-03-16 13:25:07] DEBUG com.zaxxer.hikari.pool.PoolBase - HikariPool-1 - Reset (autoCommit) on connection org.postgresql.jdbc4.Jdbc4Connection@152da6f4
[2017-03-16 13:25:07] DEBUG com.zaxxer.hikari.pool.PoolBase - HikariPool-1 - Reset (autoCommit) on connection org.postgresql.jdbc4.Jdbc4Connection@152da6f4
[2017-03-16 13:25:07] DEBUG com.zaxxer.hikari.pool.PoolBase - HikariPool-1 - Reset (autoCommit) on connection org.postgresql.jdbc4.Jdbc4Connection@152da6f4
[2017-03-16 13:25:07] DEBUG com.normation.rudder.web.snippet.node.AcceptNode - Successfully added node '7bb32578-d893-4f56-8555-bdc2b5ca680c'

Actions

Copy link

Updated by Nicolas CHARLES over 7 years ago

Meanwhile, on slapd:


Mar 16 13:24:59 dhcp240 rudder-slapd[20817]: <= mdb_equality_candidates: (container) not indexed
Mar 16 13:24:59 dhcp240 rudder-slapd[20817]: <= mdb_equality_candidates: (container) not indexed
Mar 16 13:24:59 dhcp240 rudder-slapd[20817]: <= mdb_equality_candidates: (isDynamic) not indexed
Mar 16 13:24:59 dhcp240 rudder-slapd[20817]: <= mdb_equality_candidates: (nodeGroupId) not indexed
Mar 16 13:24:59 dhcp240 rudder-slapd[20817]: <= mdb_equality_candidates: (cn) not indexed
Mar 16 13:24:59 dhcp240 rudder-slapd[20817]: <= mdb_equality_candidates: (directiveId) not indexed
Mar 16 13:24:59 dhcp240 rudder-slapd[20817]: <= mdb_equality_candidates: (nodeHostname) not indexed
Mar 16 13:24:59 dhcp240 rudder-slapd[20817]: <= mdb_equality_candidates: (container) not indexed
Mar 16 13:24:59 dhcp240 rudder-slapd[20817]: <= mdb_equality_candidates: (container) not indexed
Mar 16 13:24:59 dhcp240 rudder-slapd[20817]: <= mdb_equality_candidates: (container) not indexed
Mar 16 13:24:59 dhcp240 rudder-slapd[20817]: <= mdb_equality_candidates: (container) not indexed
Mar 16 13:24:59 dhcp240 rudder-slapd[20817]: <= mdb_equality_candidates: (container) not indexed
Mar 16 13:24:59 dhcp240 rudder-slapd[20817]: <= mdb_equality_candidates: (container) not indexed
Mar 16 13:25:21 dhcp240 rudder-slapd[20817]: <= mdb_equality_candidates: (container) not indexed
Mar 16 13:25:21 dhcp240 rudder-slapd[20817]: <= mdb_equality_candidates: (container) not indexed
Mar 16 13:25:21 dhcp240 rudder-slapd[20817]: <= mdb_equality_candidates: (container) not indexed
Mar 16 13:25:21 dhcp240 rudder-slapd[20817]: <= mdb_equality_candidates: (container) not indexed
Mar 16 13:25:21 dhcp240 rudder-slapd[20817]: <= mdb_equality_candidates: (container) not indexed
Mar 16 13:25:21 dhcp240 rudder-slapd[20817]: <= mdb_equality_candidates: (container) not indexed
Mar 16 13:25:21 dhcp240 rudder-slapd[20817]: <= mdb_equality_candidates: (container) not indexed
Mar 16 13:25:21 dhcp240 rudder-slapd[20817]: <= mdb_equality_candidates: (container) not indexed
Mar 16 13:25:21 dhcp240 rudder-slapd[20817]: <= mdb_equality_candidates: (container) not indexed

Actions

Copy link

Updated by François ARMAND over 7 years ago

User visibility changed from Infrequent - complex configurations | third party integrations to Operational - other Techniques | Technique editor | Rudder settings

Actions

Copy link

Updated by Benoît PECCATTE over 7 years ago

Priority set to 17

Actions

Copy link

Updated by Vincent MEMBRÉ over 7 years ago

Target version changed from 4.1.0 to 4.1.1

Actions

Copy link

Updated by François ARMAND over 7 years ago

Related to Architecture #5367: Make node acceptance process asynchronous added

Actions

Copy link

Updated by Vincent MEMBRÉ over 7 years ago

Target version changed from 4.1.1 to 4.1.2

Actions

Copy link

Updated by Vincent MEMBRÉ over 7 years ago

Target version changed from 4.1.2 to 4.1.3

Actions

Copy link

#10

Updated by Vincent MEMBRÉ over 7 years ago

Target version changed from 4.1.3 to 4.1.4
Priority changed from 17 to 16

Actions

Copy link

#11

Updated by Vincent MEMBRÉ over 7 years ago

Target version changed from 4.1.4 to 4.1.5

Actions

Copy link

#12

Updated by Alexis Mousset over 7 years ago

Target version changed from 4.1.5 to 4.1.6

Actions

Copy link

#13

Updated by Benoît PECCATTE over 7 years ago

Priority changed from 16 to 31

Actions

Copy link

#14

Updated by Vincent MEMBRÉ over 7 years ago

Target version changed from 4.1.6 to 4.1.7
Priority changed from 31 to 30

Actions

Copy link

#15

Updated by Vincent MEMBRÉ about 7 years ago

Target version changed from 4.1.7 to 4.1.8

Actions

Copy link

#16

Updated by Vincent MEMBRÉ about 7 years ago

Target version changed from 4.1.8 to 4.1.9
Priority changed from 30 to 29

Actions

Copy link

#17

Updated by Vincent MEMBRÉ almost 7 years ago

Target version changed from 4.1.9 to 4.1.10

Actions

Copy link

#18

Updated by Vincent MEMBRÉ almost 7 years ago

Target version changed from 4.1.10 to 4.1.11
Priority changed from 29 to 27

Actions

Copy link

#19

Updated by Vincent MEMBRÉ over 6 years ago

Target version changed from 4.1.11 to 4.1.12

Actions

Copy link

#20

Updated by Vincent MEMBRÉ over 6 years ago

Target version changed from 4.1.12 to 4.1.13

Actions

Copy link

#21

Updated by Vincent MEMBRÉ over 6 years ago

Target version changed from 4.1.13 to 4.1.14

Actions

Copy link

#22

Updated by Benoît PECCATTE over 6 years ago

Target version changed from 4.1.14 to 4.1.15

Actions

Copy link

#23

Updated by Vincent MEMBRÉ about 6 years ago

Target version changed from 4.1.15 to 4.1.16

Actions

Copy link

#24

Updated by Vincent MEMBRÉ about 6 years ago

Target version changed from 4.1.16 to 4.1.17

Actions

Copy link

#25

Updated by Vincent MEMBRÉ almost 6 years ago

Target version changed from 4.1.17 to 4.1.18
Priority changed from 27 to 0

Actions

Copy link

#26

Updated by Vincent MEMBRÉ almost 6 years ago

Target version changed from 4.1.18 to 4.1.19

Actions

Copy link

#27

Updated by Alexis Mousset almost 6 years ago

Target version changed from 4.1.19 to 4.1.20

Actions

Copy link

#28

Updated by François ARMAND over 5 years ago

Target version changed from 4.1.20 to 4.1.21

Actions

Copy link

#29

Updated by Vincent MEMBRÉ over 5 years ago

Target version changed from 4.1.21 to 4.1.22

Actions

Copy link

#30

Updated by Vincent MEMBRÉ over 5 years ago

Target version changed from 4.1.22 to 4.1.23

Actions

Copy link

#31

Updated by Vincent MEMBRÉ over 5 years ago

Target version changed from 4.1.23 to 4.1.24

Actions

Copy link

#32

Updated by Vincent MEMBRÉ over 5 years ago

Target version changed from 4.1.24 to 588

Actions

Copy link

#33

Updated by Nicolas CHARLES over 5 years ago

Target version changed from 588 to 5.0.13

i think i've seen it also in 5.0, retargeting

Actions

Copy link

#34

Updated by Félix DALLIDET over 5 years ago

I tried to reproduce, but unfortunately, adding 1000 of inventories in one go in the incoming folder lead to NullPointerException so I wasn't able to test.

[2019-07-09 12:18:41] INFO  com.normation.inventory.provisioning.endpoint.config.PropertyPlaceholderConfig - Use configuration file defined by JVM property -Dinventoryweb.configFile : /opt/rudder/etc/inventory-web.properties
[2019-07-09 12:18:43] INFO  inventory-processing - Incoming inventory watcher started - process existing inventories
java.lang.NullPointerException
>-at sun.nio.fs.UnixPath.toUnixPath(UnixPath.java:198)
>-at sun.nio.fs.UnixPath.resolve(UnixPath.java:397)
>-at sun.nio.fs.UnixPath.resolve(UnixPath.java:43)
>-at better.files.FileMonitor.$anonfun$process$1(FileMonitor.scala:33)
>-at better.files.FileMonitor.$anonfun$process$1$adapted(FileMonitor.scala:31)
>-at scala.collection.Iterator.foreach(Iterator.scala:937)
>-at scala.collection.Iterator.foreach$(Iterator.scala:937)
>-at scala.collection.AbstractIterator.foreach(Iterator.scala:1425)
>-at scala.collection.IterableLike.foreach(IterableLike.scala:70)
>-at scala.collection.IterableLike.foreach$(IterableLike.scala:69)
>-at scala.collection.AbstractIterable.foreach(Iterable.scala:54)
>-at better.files.FileMonitor.process(FileMonitor.scala:31)
>-at com.normation.inventory.provisioning.endpoint.Watchers$$anon$1$$anon$2.$anonfun$run$3(InventoryFileWatcher.scala:112)
>-at com.normation.inventory.provisioning.endpoint.Watchers$$anon$1$$anon$2.$anonfun$run$3$adapted(InventoryFileWatcher.scala:112)

Actions

Copy link

#35