Actions
Bug #17594
closed
no policy generation after accepting many nodes in 6.1
Status:
Released
Priority:
N/A
Assignee:
Category:
Web - Nodes & inventories
Target version:
Pull Request:
Severity:
Major - prevents use of part of Rudder | no simple workaround
UX impact:
User visibility:
Effort required:
Priority:
0
Name check:
To do
Fix check:
Checked
Regression:
Description
I accepted 149 nodes in Rudder 6.1, and got no policy generation at all. It might be worth stating that i was in trace for ldap and dyngroupuploader
Event logs are
Date Actor Type Description 250 2020-06-02 22:22:54+0200 rudder Technique Library updated Technique library updated 249 2020-06-02 22:20:43+0200 admin Node accepted Node RUDDER_TEST_2497 accepted 248 2020-06-02 22:20:42+0200 admin Node accepted Node RUDDER_TEST_2496 accepted 247 2020-06-02 22:20:42+0200 rudder Node Group modified Group sqfdsffd modified 246 2020-06-02 22:20:42+0200 rudder Node Group modified Group All classic Nodes managed by root policy server modified 245 2020-06-02 22:20:42+0200 admin Node accepted Node RUDDER_TEST_2491 accepted 244 2020-06-02 22:20:42+0200 admin Node accepted Node RUDDER_TEST_2490 accepted 243 2020-06-02 22:20:42+0200 rudder Node Group modified Group All classic Nodes modified 242 2020-06-02 22:20:42+0200 admin Node accepted Node RUDDER_TEST_2488 accepted 241 2020-06-02 22:20:42+0200 rudder Node Group modified Group sqfdsffd modified 240 2020-06-02 22:20:42+0200 admin Node accepted Node RUDDER_TEST_2487 accepted 239 2020-06-02 22:20:41+0200 rudder Node Group modified Group All classic Nodes managed by root policy server modified 238 2020-06-02 22:20:41+0200 admin Node accepted Node RUDDER_TEST_2485 accepted 237 2020-06-02 22:20:41+0200 admin Node accepted Node RUDDER_TEST_2482 accepted 236 2020-06-02 22:20:41+0200 rudder Node Group modified Group All classic Nodes modified 235 2020-06-02 22:20:41+0200 admin Node accepted Node RUDDER_TEST_2477 accepted 234 2020-06-02 22:20:41+0200 admin Node accepted Node RUDDER_TEST_2474 accepted
groups are indeed updated
[2020-06-02 22:20:42+0200] INFO scheduled.job - Dynamic group a4503f01-91b0-4237-a69b-24b8cee754cc: added node with id: [ dfd4dede-32c5-4265-8073-18efc3ce98a5,
9ef36460-1cdc-4acd-95ae-27ecfbac9cfa, a6181521-da20-4a09-b7c4-73dd4237e929, 66c9208d-a8dd-4cac-ae8a-6a6a7554f6a5 ], removed: nothing
[2020-06-02 22:20:42+0200] DEBUG com.normation.rudder.services.queries.InternalLDAPQueryProcessor - [130533829852] Start search for { returnType:'NodeReturnType
' with 'Or' criteria [node.nodeHostname eq RUDDER_TEST_2497] }
[2020-06-02 22:20:42+0200] DEBUG com.normation.rudder.services.queries.InternalLDAPQueryProcessor - [130533829852] |- (final query) LDAPObjectType(ou=Nodes,ou=A
ccepted Inventories,ou=Inventories,cn=rudder-configuration,One,LDAPObjectTypeFilter((objectClass=*)),Some((|(nodeHostname=RUDDER_TEST_2497))),DNJoin,Set())
[2020-06-02 22:20:42+0200] DEBUG com.normation.rudder.services.queries.InternalLDAPQueryProcessor - [130533829852] |--- SearchRequest(baseDN='ou=Nodes,ou=Accept
ed Inventories,ou=Inventories,cn=rudder-configuration', scope=ONE, deref=NEVER, sizeLimit=0, timeLimit=0, filter='(&(objectClass=*)(|(nodeHostname=RUDDER_TEST_2
497)))', attrs={isSystem, serializedHeartbeatRunConfiguration, ram, description, osFullName, osName, ipHostNumber, state, policyServerId, machineId, osArchitect
ureType, timezoneName, localAdministratorAccountName, osKernelVersion, windowsKey, customProperty, container, componentSerialNumber, cn, osServicePack, serializ
edAgentRunInterval, windowsUserDomain, serializedNodeProperty, timezoneOffset, keyStatus, createTimestamp, agentName, windowsRegistrationCompany, publicKey, inv
entoryDate, policyMode, manufacturer, osVersion, nodeId, nodeHostname, rudderServerRole, objectClass, windowsId})
[2020-06-02 22:20:42+0200] DEBUG com.normation.rudder.services.queries.InternalLDAPQueryProcessor - [130533829852] |---- after ldap search request 0 result(s)
[2020-06-02 22:20:42+0200] DEBUG com.normation.rudder.services.queries.InternalLDAPQueryProcessor - [130533829852] |---- after post-processing: 0 result(s)
[2020-06-02 22:20:42+0200] DEBUG com.normation.rudder.services.queries.InternalLDAPQueryProcessor - [130533829852] |--- or (base filter): 0
[2020-06-02 22:20:42+0200] TRACE com.normation.rudder.services.queries.InternalLDAPQueryProcessor - [130533829852] |--- or (base filter):
[2020-06-02 22:20:42+0200] DEBUG com.normation.rudder.services.queries.InternalLDAPQueryProcessor - [130533829852] |--- or (special filter): 0
[2020-06-02 22:20:42+0200] TRACE com.normation.rudder.services.queries.InternalLDAPQueryProcessor - [130533829852] |--- or (special filter):
[2020-06-02 22:20:42+0200] DEBUG com.normation.rudder.services.queries.InternalLDAPQueryProcessor - [130533829852] |--- or (total): 0
[2020-06-02 22:20:42+0200] TRACE com.normation.rudder.services.queries.InternalLDAPQueryProcessor - [130533829852] |--- or (total):
[2020-06-02 22:20:42+0200] DEBUG com.normation.rudder.services.queries.InternalLDAPQueryProcessor - [130533829852] |--- results are:
[2020-06-02 22:20:42+0200] DEBUG com.normation.rudder.services.queries.InternalLDAPQueryProcessor - [130533829852] `-> 0 results
[2020-06-02 22:20:42+0200] DEBUG com.normation.rudder.services.queries.AcceptedNodesLDAPQueryProcessor - Result obtained in 23ms for query { returnType:'NodeRet
urnType' with 'Or' criteria [node.nodeHostname eq RUDDER_TEST_2497] }
it never fixes itself, as dynamic groups are now only updated when tree changes
Updated by Nicolas CHARLES over 4 years ago
- Subject changed from no policy generation after accepting nodes in 6.1 to no policy generation after accepting many nodes in 6.1
with only one node, it works
Updated by Nicolas CHARLES over 4 years ago
editing ldap causes a generatio
[2020-06-02 23:13:07+0200] TRACE com.normation.rudder.services.nodes.NodeInfoServiceCachedImpl - Cache check for node info gave 'true' (0 entry returned) [2020-06-02 23:13:52+0200] TRACE com.normation.rudder.services.nodes.NodeInfoServiceCachedImpl - Cache check for node info gave 'true' (0 entry returned) [2020-06-02 23:14:37+0200] TRACE com.normation.rudder.services.nodes.NodeInfoServiceCachedImpl - Cache check for node info gave 'true' (0 entry returned) [2020-06-02 23:15:22+0200] TRACE com.normation.rudder.services.nodes.NodeInfoServiceCachedImpl - Cache check for node info gave 'true' (0 entry returned) [2020-06-02 23:15:40+0200] TRACE com.normation.rudder.services.nodes.NodeInfoServiceCachedImpl - Cache check for node info gave 'true' (0 entry returned) [2020-06-02 23:15:40+0200] DEBUG com.normation.rudder.services.nodes.NodeInfoServiceCachedImpl - NodeInfo cache is up to date, last modification time: '2020-06- 02T22:52:46.000+02:00' for: '20200602205246.148870Z#000000#000#000000','20200602205246.147432Z#000000#000#000000','20200602205246.141533Z#000000#000#000000' [2020-06-02 23:16:07+0200] TRACE com.normation.rudder.services.nodes.NodeInfoServiceCachedImpl - Cache check for node info gave 'false' (1 entry returned) [2020-06-02 23:16:07+0200] INFO scheduled.job - Update in node inventories main information detected: triggering a policy generation [2020-06-02 23:16:07+0200] INFO policy.generation - Start policy generation, checking updated rules
and it unfortunately states
531 2020-06-02 23:16:07+0200 rudder Policy update started manually Manually update policies
Updated by Nicolas CHARLES over 4 years ago
accepting 10 nodes works
[2020-06-02 23:39:44+0200] DEBUG com.normation.rudder.services.nodes.NodeInfoServiceCachedImpl - NodeInfo cache is up to date, last modification time: '2020-06- 02T23:39:42.000+02:00' for: '20200602213942.974042Z#000000#000#000000','20200602213942.972548Z#000000#000#000000','20200602213942.515050Z#000000#000#000000','20 200602213942.513822Z#000000#000#000000','20200602213942.065773Z#000000#000#000000','20200602213942.063976Z#000000#000#000000','20200602213942.057229Z#000000#000 #000000','20200602213942.500795Z#000000#000#000000','20200602213942.952926Z#000000#000#000000' [2020-06-02 23:39:44+0200] DEBUG com.normation.rudder.services.queries.DynGroupUpdaterServiceImpl - Dynamic group a4503f01-91b0-4237-a69b-24b8cee754cc with name sqfdsffd computed in 44 ms [2020-06-02 23:39:44+0200] DEBUG com.normation.rudder.services.queries.DynGroupUpdaterServiceImpl - Dynamic group a4503f01-91b0-4237-a69b-24b8cee754cc with name sqfdsffd updated in 47 ms [2020-06-02 23:39:44+0200] INFO scheduled.job - Dynamic group all-nodes-with-cfengine-agent: added node with id: [ 86cfead0-32c6-4b1c-9327-f92f665fd99f, a79d49 bb-c356-445d-8fa6-324ee189d5dd ], removed: nothing [2020-06-02 23:39:44+0200] INFO scheduled.job - Dynamic group hasPolicyServer-root: added node with id: [ a79d49bb-c356-445d-8fa6-324ee189d5dd ], removed: noth ing [2020-06-02 23:39:44+0200] INFO policy.generation - Start policy generation, checking updated rules [2020-06-02 23:39:44+0200] TRACE com.normation.rudder.services.nodes.NodeInfoServiceCachedImpl - Cache check for node info gave 'true' (0 entry returned) [2020-06-02 23:39:44+0200] DEBUG com.normation.rudder.services.nodes.NodeInfoServiceCachedImpl - NodeInfo cache is up to date, last modification time: '2020-06-02T23:39:42.000+02:00' for: '20200602213942.974042Z#000000#000#000000','20200602213942.972548Z#000000#000#000000','20200602213942.515050Z#000000#000#000000','20200602213942.513822Z#000000#000#000000','20200602213942.065773Z#000000#000#000000','20200602213942.063976Z#000000#000#000000','20200602213942.057229Z#000000#000#000000','20200602213942.500795Z#000000#000#000000','20200602213942.952926Z#000000#000#000000' [2020-06-02 23:39:44+0200] INFO policy.generation - [metrics] Xmx:1015 MB nodes:318 (cached:1) rules:5 (enabled:4) techniques:43 (enabled:43) directives:4 (enabled:4) groups:3 (dynamic:3) parameters:2
accepting 25 nodes does not
[2020-06-02 23:41:00+0200] INFO scheduled.job - Dynamic group all-nodes-with-cfengine-agent: added node with id: [ 2a74ab25-a28f-48f1-bb9d-9c78fb869c69, ae9e774e-123c-4cdf-adf1-45f4ea97d193 ], removed: nothing [2020-06-02 23:41:00+0200] INFO scheduled.job - Dynamic group hasPolicyServer-root: added node with id: [ ae9e774e-123c-4cdf-adf1-45f4ea97d193 ], removed: nothing [2020-06-02 23:41:00+0200] INFO scheduled.job - Dynamic group a4503f01-91b0-4237-a69b-24b8cee754cc: added node with id: [ ae9e774e-123c-4cdf-adf1-45f4ea97d193 ], removed: nothing [2020-06-02 23:41:38+0200] TRACE com.normation.rudder.services.nodes.NodeInfoServiceCachedImpl - Cache check for node info gave 'true' (0 entry returned) [2020-06-02 23:41:39+0200] TRACE com.normation.rudder.services.nodes.NodeInfoServiceCachedImpl - Cache check for node info gave 'true' (0 entry returned) [2020-06-02 23:41:39+0200] DEBUG com.normation.rudder.services.nodes.NodeInfoServiceCachedImpl - NodeInfo cache is up to date, last modification time: '2020-06-02T23:41:00.000+02:00' for: '20200602214100.200899Z#000000#000#000000','20200602214100.199061Z#000000#000#000000','20200602214100.188679Z#000000#000#000000' [2020-06-02 23:42:23+0200] TRACE com.normation.rudder.services.nodes.NodeInfoServiceCachedImpl - Cache check for node info gave 'true' (0 entry returned)
Updated by Nicolas CHARLES over 4 years ago
- Status changed from New to In progress
- Assignee set to Nicolas CHARLES
Updated by Nicolas CHARLES over 4 years ago
- Status changed from In progress to Pending technical review
- Assignee changed from Nicolas CHARLES to François ARMAND
- Pull Request set to https://github.com/Normation/rudder/pull/3040
Updated by Nicolas CHARLES over 4 years ago
it seems to be caused by long policy generation: if a policy generation is in process, dynamic group don't update. Once it's over, dynamic group starts back to be processed
Updated by Nicolas CHARLES over 4 years ago
- Status changed from Pending technical review to Pending release
Applied in changeset rudder|a2f7eae603db3c2011098479954f5a80d7d35f04.
Updated by Vincent MEMBRÉ over 4 years ago
- Status changed from Pending release to Released
This bug has been fixed in Rudder 6.1.0~rc3 which was released today.
Updated by Nicolas CHARLES over 4 years ago
- Fix check changed from To do to Checked
it fixes the issue, yet i do have policy generation during node acceptations
Actions