Project

General

Profile

Actions
Copy link

Bug #20520

open

Error while importing ncf techniques using the restore from latest commit feature

Added by Félix DALLIDET over 2 years ago. Updated about 3 hours ago.

Status:
New
Priority:
N/A
Assignee:
-
Category:
Server components
Target version:
7.3.15
Pull Request:
Severity:
UX impact:
User visibility:
Effort required:
Priority:
0
Name check:
To do
Fix check:
To do
Regression:
No

Description

To test some exporting scripts, I did manually the following:

  • Apply a git patch to my Rudder
  • Commit it
  • Via the interface, restore the Rudder state from the latest commit

And there my technique was broken and not detected by the webapp, even if it was well committed. See the attached screenshot
Running rudder server reload-techniques fixes the issue, but it should be done automatically.

Complete webapp logs:

2022-01-05 10:45:26.163:INFO:oejs.SetUIDListener:main: Setting umask=07
2022-01-05 10:45:26.167:INFO:oejs.Server:main: jetty-9.4.44.v20210927; built: 2021-09-27T23:02:44.612Z; git: 8da83308eeca865e495e53ef315a249d63ba9332; jvm 11.0.11+9-post-Debian-1deb10u1
2022-01-05 10:45:26.223:INFO:oejdp.ScanningAppProvider:main: Deployment monitor [file:///opt/rudder/share/webapps/] at interval 0
2022-01-05 10:45:29.084:INFO:oejw.StandardDescriptorProcessor:main: NO JSP Support for /rudder, did not find org.eclipse.jetty.jsp.JettyJspServlet
Use configuration file defined by JVM property -Dlogback.configurationFile : /opt/rudder/etc/logback.xml
2022-01-05 10:45:29.610:INFO:oejs.session:main: DefaultSessionIdManager workerName=node0
2022-01-05 10:45:29.610:INFO:oejs.session:main: No SessionScavenger set, using defaults
2022-01-05 10:45:29.611:INFO:oejs.session:main: node0 Scavenging every 600000ms
[2022-01-05 10:45:30+0100] INFO  application - Rudder starts with PID 11432 on 1 cores
[2022-01-05 10:45:30+0100] INFO  application - Use configuration file defined by JVM property -Drudder.configFile : /opt/rudder/etc/rudder-web.properties
[2022-01-05 10:45:31+0100] INFO  application - Global exception handler configured to stop Rudder on: java.lang.Error
[2022-01-05 10:45:33+0100] INFO  application - Property 'rudder.batch.delete.software.interval' is missing or empty in rudder.configFile. Default to 24 hours.
[2022-01-05 10:45:33+0100] INFO  application - Property 'metrics.healthcheck.scheduler.period' is missing or empty in rudder.configFile. Default to 6 hours.
[2022-01-05 10:45:33+0100] INFO  application - Using 'move' behavior when a node is deleted
[2022-01-05 10:45:33+0100] INFO  application - Starting Rudder 7.0.0~rc2 web application [build timestamp: 2021-12-16T00:28:37Z]
[2022-01-05 10:45:50+0100] INFO  report - Disable automatic database archive sinces property rudder.batch.reportsCleaner.archive.TTL is 0 or negative
[2022-01-05 10:45:51+0100] WARN  healthcheck - CPU cores: Only one core, recommended value is at least 2
[2022-01-05 10:45:51+0100] INFO  git-repository - Automatic git-gc starts on fact-repository (schedule 'sec min h dayMonth month DayWeek': '0 42 3 * * ?')
[2022-01-05 10:45:51+0100] INFO  git-repository - Automatic git-gc starts on configuration-repository (schedule 'sec min h dayMonth month DayWeek': '0 42 3 * * ?')
[2022-01-05 10:45:52+0100] INFO  scheduled.job - Starting [Store Agent Run Times] scheduler with a period of 5 s
[2022-01-05 10:45:52+0100] INFO  application - List of registered properties:
[2022-01-05 10:45:52+0100] INFO  application - registered property: awt.toolkit="sun.awt.X11.XToolkit" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: file.encoding="UTF-8" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: file.separator="/" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: history.inventories.rootdir="/var/rudder/inventories/historical" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: inventories.root.directory="/var/rudder/inventories" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: inventories.watcher.period.garbage.old="5 minutes" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: inventories.watcher.waitForSignatureDuration="10 seconds" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: inventory.parse.parallelization="0.5x" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: java.awt.graphicsenv="sun.awt.X11GraphicsEnvironment" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: java.awt.printerjob="sun.print.PSPrinterJob" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: java.class.path="/opt/rudder/jetty/start.jar" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: java.class.version="55.0" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: java.home="/usr/lib/jvm/java-11-openjdk-amd64" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: java.io.tmpdir="/var/rudder/tmp/jetty" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: java.library.path="/usr/java/packages/lib:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: java.runtime.name="OpenJDK Runtime Environment" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: java.runtime.version="11.0.11+9-post-Debian-1deb10u1" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: java.specification.name="Java Platform API Specification" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: java.specification.vendor="Oracle Corporation" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: java.specification.version="11" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: java.vendor.url.bug="https://bugs.debian.org/openjdk-11" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: java.version="11.0.11" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: java.vm.compressedOopsMode="32-bit" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: java.vm.info="mixed mode, sharing" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: java.vm.name="OpenJDK 64-Bit Server VM" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: java.vm.specification.name="Java Virtual Machine Specification" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: java.vm.specification.vendor="Oracle Corporation" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: java.vm.specification.version="11" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: java.vm.vendor="Debian" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: java.vm.version="11.0.11+9-post-Debian-1deb10u1" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: jdk.debug="release" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: jetty.base="/opt/rudder/etc/rudder-jetty-base" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: jetty.build="8da83308eeca865e495e53ef315a249d63ba9332" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: jetty.git.hash="8da83308eeca865e495e53ef315a249d63ba9332" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: jetty.home="/opt/rudder/jetty" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: jetty.tag.version="jetty-9.4.44.v20210927" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: jetty.version="9.4.44.v20210927" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: ldap.authdn="cn=manager,cn=rudder-configuration" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: ldap.authpw=**********
[2022-01-05 10:45:52+0100] INFO  application - registered property: ldap.host="localhost" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: ldap.maxPoolSize="2" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: ldap.port="389" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: ldif.tracelog.rootdir="/var/rudder/inventories/debug" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: line.separator="\n" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: logback.configurationFile="/opt/rudder/etc/logback.xml" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: os.arch="amd64" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: os.name="Linux" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: os.version="4.19.0-17-amd64" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: path.separator=":" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.auth.provider="file" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.authFile="/opt/rudder/etc/rudder-users.xml" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.autoArchiveItems="true" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.batch.check.node.cache.interval="15 s" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.batch.databasecleaner.runtime.day="sunday" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.batch.databasecleaner.runtime.hour="0" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.batch.databasecleaner.runtime.minute="0" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.batch.dyngroup.updateInterval="5" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.batch.purge.inventories.delete.TTL="7" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.batch.purge.inventories.delete.interval="24" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.batch.reports.logInterval="1" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.batch.reportsCleaner.deleteLogReport.TTL="2x" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.batch.reportscleaner.archive.TTL="0" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.batch.reportscleaner.compliancelevels.delete.TTL="8" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.batch.reportscleaner.delete.TTL="4" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.batch.reportscleaner.frequency="daily" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.batch.storeAgentRunTimes.maxBatchSize="5" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.batch.storeAgentRunTimes.maxDays="0" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.batch.storeAgentRunTimes.maxMinutes="30" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.batch.storeAgentRunTimes.updateInterval="5" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.batch.techniqueLibrary.updateInterval="5" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.config.repo.new.file.group.owner="rudder" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.configFile="/opt/rudder/etc/rudder-web.properties" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.debug.nodeconfiguration.path="/var/log/rudder/nodeConfigurations" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.dir.backup="/var/rudder/share/backup/" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.dir.dependencies="/var/rudder/tools" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.dir.gitRoot="/var/rudder/configuration-repository" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.dir.lock="/var/rudder/lock/" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.dir.shared.files.folder="/var/rudder/configuration-repository/shared-files" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.generated.policies.group.owner="rudder-policy-reader" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.git.gc="0 42 3 * * ?" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.hooks.ignore-suffixes=".swp, ~, .bak, .cfnew   , .cfsaved  , .cfedited, .cfdisabled, .cfmoved,.dpkg-old, .dpkg-dist, .dpkg-new, .dpkg-tmp,.disable , .disabled , _disable , _disabled,.ucf-old , .ucf-dist , .ucf-new ,.rpmnew  , .rpmsave  , .rpmorig" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.jdbc.batch.max.size="500" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.jdbc.driver="org.postgresql.Driver" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.jdbc.maxPoolSize="25" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.jdbc.password=**********
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.jdbc.url="jdbc:postgresql://localhost:5432/rudder" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.jdbc.username="rudder" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.jvm.fatal.exceptions="" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.lang.test-loop.exec="true" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.nodes.delete.defaultMode="move" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.policy.distribution.port.cfengine="5309" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.policy.distribution.port.https="443" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.postgresql.local="true" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.relayd.reload="/opt/rudder/bin/rudder relay reload -p" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.server.relay.api="https://localhost/rudder/relay-api" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.webdav.password=**********
[2022-01-05 10:45:52+0100] INFO  application - registered property: rudder.webdav.user="rudder" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: run.mode="production" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: sun.arch.data.model="64" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: sun.boot.library.path="/usr/lib/jvm/java-11-openjdk-amd64/lib" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: sun.cpu.endian="little" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: sun.cpu.isalist="" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: sun.io.unicode.encoding="UnicodeLittle" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: sun.java.command="/opt/rudder/jetty/start.jar OPTIONS=Server jetty.state=/opt/rudder/etc/rudder-jetty-base/rudder-jetty.state jetty-started.xml start-log-file=/var/log/rudder/webapp/java.log" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: sun.java.launcher="SUN_STANDARD" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: sun.jnu.encoding="ANSI_X3.4-1968" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: sun.management.compiler="HotSpot 64-Bit Tiered Compilers" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: sun.os.patch.level="unknown" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: user.country="US" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: user.dir="/opt/rudder/etc/rudder-jetty-base" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: user.home="/root" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: user.language="en" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: user.name="root" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: user.timezone="Europe/Paris" 
[2022-01-05 10:45:52+0100] INFO  application - registered property: waiting.inventory.queue.size="5" 
[2022-01-05 10:45:52+0100] INFO  application - Plugin's license directory: '/opt/rudder/etc/plugins/licenses/'
[2022-01-05 10:45:52+0100] INFO  bootchecks - Check LDAP and PostgreSQL connection
[2022-01-05 10:45:52+0100] INFO  bootchecks - LDAP and PostgreSQL connection are OK
[2022-01-05 10:45:52+0100] INFO  bootchecks - Check if migration of system configuration object and allowed networks to Rudder 7.0 format is needed
[2022-01-05 10:45:52+0100] INFO  bootchecks - Check mandatory DIT entries
[2022-01-05 10:45:53+0100] INFO  bootchecks - All the required DIT entries are present in the LDAP directory
[2022-01-05 10:45:53+0100] INFO  bootchecks - Check initialization of User Technique Library
[2022-01-05 10:45:53+0100] INFO  bootchecks - Check that `rudder` global parameter matches default value
[2022-01-05 10:45:53+0100] INFO  bootchecks - Check event log migration format 5 -> 6
[2022-01-05 10:45:53+0100] INFO  bootchecks - Check existence of at least one archive of the configuration
[2022-01-05 10:45:54+0100] INFO  bootchecks - First full archive of configuration-repository items done
[2022-01-05 10:45:54+0100] INFO  bootchecks - Check for force reload of Techniques library
[2022-01-05 10:45:54+0100] INFO  bootchecks - Flag file '/opt/rudder/etc/force_technique_reload' found, reload Technique library now
[2022-01-05 10:45:54+0100] INFO  bootchecks - Successfully reloaded Technique library on start up. now deleting flag file '/opt/rudder/etc/force_technique_reload'
[2022-01-05 10:45:54+0100] INFO  bootchecks - Flag file '/opt/rudder/etc/force_technique_reload' successfully removed
[2022-01-05 10:45:54+0100] INFO  bootchecks - Regenerate all ncf techniques
[2022-01-05 10:45:54+0100] INFO  migration - No migration detected by migration script (table 'migrationeventlog' is empty or does not exist)
[2022-01-05 10:45:56+0100] INFO  bootchecks - started
[2022-01-05 10:45:57+0100] INFO  bootchecks - techniques - update
[2022-01-05 10:45:58+0100] INFO  bootchecks - methods
[2022-01-05 10:45:59+0100] INFO  bootchecks - techniques - read
[2022-01-05 10:45:59+0100] INFO  bootchecks - Trigger policy update automatically at start
[2022-01-05 10:45:59+0100] INFO  bootchecks - Create system api token
[2022-01-05 10:45:59+0100] INFO  bootchecks - System api token file created in /var/rudder/run/api-token
[2022-01-05 10:45:59+0100] INFO  bootchecks - Load node compliance cache
2022-01-05 10:45:59.326:INFO:oejshC.rudder:main: Initializing Spring root WebApplicationContext
[2022-01-05 10:45:59+0100] INFO  policy.generation - Start policy generation, checking updated rules
[2022-01-05 10:46:02+0100] INFO  policy.generation - [metrics] Xmx:1015 MB nodes:1 (cached:1) rules:5 (enabled:4) techniques:49 (enabled:49) directives:9 (enabled:9) groups:3 (dynamic:3) parameters:2
[2022-01-05 10:46:05+0100] INFO  application - Configured authentication provider(s): [rootAdmin, file]
[2022-01-05 10:46:06+0100] 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 configuration file
[2022-01-05 10:46:06+0100] INFO  application - Add backend providers 'Default authentication backends provider: 'file','rootAdmin'
[2022-01-05 10:46:06+0100] INFO  application - Using configuration file defined by JVM property -Drudder.authFile : /opt/rudder/etc/rudder-users.xml
[2022-01-05 10:46:07+0100] INFO  policy.generation - No node configuration was updated, no policies to write
[2022-01-05 10:46:07+0100] DEBUG explain_compliance - Updated node configuration ids: 
[2022-01-05 10:46:08+0100] INFO  bootstrap.liftweb.Boot - classpath
[2022-01-05 10:46:08+0100] INFO  org.reflections.Reflections - Reflections took 402 ms to scan 3 urls, producing 22 keys and 71 values 
[2022-01-05 10:46:08+0100] INFO  application.plugin - Initializing plugin 'rudder-plugin-dsc': 2.0.0
[2022-01-05 10:46:10+0100] INFO  application - INFO Configure inventory processing with parallelism of '1' and queue size of '5'
[2022-01-05 10:46:11+0100] INFO  scheduled.job.metrics - Starting node count historization batch (min:15 m; max:4 h)
[2022-01-05 10:46:11+0100] INFO  inventory-processing - Incoming inventory watcher started - process existing inventories
[2022-01-05 10:46:11+0100] INFO  application - Application Rudder started
2022-01-05 10:46:12.025:INFO:oejsh.ContextHandler:main: Started o.e.j.w.WebAppContext@1018bde2{/rudder,file:///var/rudder/tmp/jetty/jetty-rudder.war.dir/webapp/,AVAILABLE}{/opt/rudder/share/webapps/rudder.war}
2022-01-05 10:46:12.112:INFO:oejs.AbstractConnector:main: Started ServerConnector@7688ebe6{HTTP/1.1, (http/1.1)}{127.0.0.1:8080}
2022-01-05 10:46:12.112:INFO:oejs.Server:main: Started @47505ms
[2022-01-05 10:46:12+0100] INFO  policy.generation.timing - Timing summary:
[2022-01-05 10:46:12+0100] INFO  policy.generation.timing - Run pre-gen scripts hooks     :        548 ms
[2022-01-05 10:46:12+0100] INFO  policy.generation.timing - Run pre-gen modules hooks     :         12 ms
[2022-01-05 10:46:12+0100] INFO  policy.generation.timing - Fetch all information         :       2531 ms
[2022-01-05 10:46:12+0100] INFO  policy.generation.timing - Build current rule values     :        260 ms
[2022-01-05 10:46:12+0100] INFO  policy.generation.timing - Build target configuration    :       1539 ms
[2022-01-05 10:46:12+0100] INFO  policy.generation.timing - Write node configurations     :       4663 ms
[2022-01-05 10:46:12+0100] INFO  policy.generation.timing - Save expected reports         :          1 ms
[2022-01-05 10:46:12+0100] INFO  policy.generation.timing - Run post generation hooks     :        412 ms
[2022-01-05 10:46:12+0100] INFO  policy.generation.timing - Number of nodes updated       :          0   
[2022-01-05 10:46:12+0100] INFO  policy.generation.timing - Policy generation succeeded in:       13 s
[2022-01-05 10:46:12+0100] INFO  policy.generation.manager - Successful policy update '8' [started 2022-01-05 10:45:59 - ended 2022-01-05 10:46:12]
[2022-01-05 10:46:20+0100] INFO  scheduled.job - Update in node inventories main information detected: triggering a policy generation
[2022-01-05 10:46:20+0100] INFO  policy.generation - Start policy generation, checking updated rules
[2022-01-05 10:46:20+0100] INFO  policy.generation - [metrics] Xmx:1015 MB nodes:1 (cached:1) rules:5 (enabled:4) techniques:49 (enabled:49) directives:9 (enabled:9) groups:3 (dynamic:3) parameters:2
[2022-01-05 10:46:20+0100] INFO  policy.generation - No node configuration was updated, no policies to write
[2022-01-05 10:46:20+0100] DEBUG explain_compliance - Updated node configuration ids: 
[2022-01-05 10:46:21+0100] INFO  policy.generation.timing - Timing summary:
[2022-01-05 10:46:21+0100] INFO  policy.generation.timing - Run pre-gen scripts hooks     :          3 ms
[2022-01-05 10:46:21+0100] INFO  policy.generation.timing - Run pre-gen modules hooks     :          0 ms
[2022-01-05 10:46:21+0100] INFO  policy.generation.timing - Fetch all information         :        201 ms
[2022-01-05 10:46:21+0100] INFO  policy.generation.timing - Build current rule values     :         14 ms
[2022-01-05 10:46:21+0100] INFO  policy.generation.timing - Build target configuration    :        150 ms
[2022-01-05 10:46:21+0100] INFO  policy.generation.timing - Write node configurations     :        645 ms
[2022-01-05 10:46:21+0100] INFO  policy.generation.timing - Save expected reports         :          0 ms
[2022-01-05 10:46:21+0100] INFO  policy.generation.timing - Run post generation hooks     :        328 ms
[2022-01-05 10:46:21+0100] INFO  policy.generation.timing - Number of nodes updated       :          0   
[2022-01-05 10:46:21+0100] INFO  policy.generation.timing - Policy generation succeeded in:        1 s
[2022-01-05 10:46:21+0100] INFO  policy.generation.manager - Successful policy update '9' [started 2022-01-05 10:46:20 - ended 2022-01-05 10:46:21]
[2022-01-05 10:54:35+0100] INFO  compliance - [metrics] global compliance (number of components): undefined
[2022-01-05 10:54:36+0100] INFO  application.plugin - Plugin 'rudder-plugin-dsc' has a license and the license signature is valid.
[2022-01-05 11:00:38+0100] INFO  inventory-processing - Watch new inventory file 'AGENT1-149dedb2-9469-4fc8-998f-7c7b2e26d8a2.ocs' with signature available: process.
[2022-01-05 11:00:42+0100] INFO  inventory-processing - Inventory 'AGENT1-149dedb2-9469-4fc8-998f-7c7b2e26d8a2.ocs' for node 'agent1' [149dedb2-9469-4fc8-998f-7c7b2e26d8a2] (signature:certified) processed in 2 seconds and 447 milliseconds
[2022-01-05 11:03:16+0100] INFO  nodes - New node accepted and managed by Rudder: 149dedb2-9469-4fc8-998f-7c7b2e26d8a2
[2022-01-05 11:03:17+0100] WARN  explain_compliance.149dedb2-9469-4fc8-998f-7c7b2e26d8a2 - Can not get compliance for node with ID '149dedb2-9469-4fc8-998f-7c7b2e26d8a2' because it has no configuration id initialised nor sent reports (node just added ?)
[2022-01-05 11:03:17+0100] WARN  explain_compliance.149dedb2-9469-4fc8-998f-7c7b2e26d8a2 - Can not get compliance for node with ID '149dedb2-9469-4fc8-998f-7c7b2e26d8a2' because it has no configuration id initialised nor sent reports (node just added ?)
[2022-01-05 11:03:17+0100] INFO  scheduled.job - Dynamic group all-nodes-with-dsc-agent: added node with id: [ 149dedb2-9469-4fc8-998f-7c7b2e26d8a2 ], removed: nothing
[2022-01-05 11:03:17+0100] INFO  policy.generation - Start policy generation, checking updated rules
[2022-01-05 11:03:17+0100] INFO  policy.generation - [metrics] Xmx:1015 MB nodes:2 (cached:1) rules:5 (enabled:4) techniques:49 (enabled:49) directives:9 (enabled:9) groups:3 (dynamic:3) parameters:2
[2022-01-05 11:03:17+0100] INFO  policy.generation - Configuration of 2 nodes were updated, their policies are going to be written
[2022-01-05 11:03:17+0100] DEBUG explain_compliance - Updated node configuration ids: [root:20220105-103331-8da5001a->20220105-110317-d9186617][149dedb2-9469-4fc8-998f-7c7b2e26d8a2:???->20220105-110317-141c3e1b]
[2022-01-05 11:03:20+0100] INFO  scheduled.job - Update in node inventories main information detected: triggering a policy generation
[2022-01-05 11:03:21+0100] INFO  policy.generation.timing - Timing summary:
[2022-01-05 11:03:21+0100] INFO  policy.generation.timing - Run pre-gen scripts hooks     :          8 ms
[2022-01-05 11:03:21+0100] INFO  policy.generation.timing - Run pre-gen modules hooks     :          0 ms
[2022-01-05 11:03:21+0100] INFO  policy.generation.timing - Fetch all information         :         95 ms
[2022-01-05 11:03:21+0100] INFO  policy.generation.timing - Build current rule values     :          2 ms
[2022-01-05 11:03:21+0100] INFO  policy.generation.timing - Build target configuration    :         20 ms
[2022-01-05 11:03:21+0100] INFO  policy.generation.timing - Write node configurations     :       3761 ms
[2022-01-05 11:03:21+0100] INFO  policy.generation.timing - Save expected reports         :         14 ms
[2022-01-05 11:03:21+0100] INFO  policy.generation.timing - Run post generation hooks     :        135 ms
[2022-01-05 11:03:21+0100] INFO  policy.generation.timing - Number of nodes updated       :          2   
[2022-01-05 11:03:21+0100] INFO  policy.generation.timing - Policy generation succeeded in:        4 s
[2022-01-05 11:03:21+0100] INFO  policy.generation.manager - Successful policy update '10' [started 2022-01-05 11:03:17 - ended 2022-01-05 11:03:21]
[2022-01-05 11:03:21+0100] INFO  policy.generation - Start policy generation, checking updated rules
[2022-01-05 11:03:21+0100] INFO  policy.generation - [metrics] Xmx:1015 MB nodes:2 (cached:2) rules:5 (enabled:4) techniques:49 (enabled:49) directives:9 (enabled:9) groups:3 (dynamic:3) parameters:2
[2022-01-05 11:03:21+0100] INFO  policy.generation - No node configuration was updated, no policies to write
[2022-01-05 11:03:21+0100] DEBUG explain_compliance - Updated node configuration ids: 
[2022-01-05 11:03:22+0100] INFO  policy.generation.timing - Timing summary:
[2022-01-05 11:03:22+0100] INFO  policy.generation.timing - Run pre-gen scripts hooks     :          1 ms
[2022-01-05 11:03:22+0100] INFO  policy.generation.timing - Run pre-gen modules hooks     :          0 ms
[2022-01-05 11:03:22+0100] INFO  policy.generation.timing - Fetch all information         :         78 ms
[2022-01-05 11:03:22+0100] INFO  policy.generation.timing - Build current rule values     :          2 ms
[2022-01-05 11:03:22+0100] INFO  policy.generation.timing - Build target configuration    :         11 ms
[2022-01-05 11:03:22+0100] INFO  policy.generation.timing - Write node configurations     :        390 ms
[2022-01-05 11:03:22+0100] INFO  policy.generation.timing - Save expected reports         :          0 ms
[2022-01-05 11:03:22+0100] INFO  policy.generation.timing - Run post generation hooks     :         82 ms
[2022-01-05 11:03:22+0100] INFO  policy.generation.timing - Number of nodes updated       :          0   
[2022-01-05 11:03:22+0100] INFO  policy.generation.timing - Policy generation succeeded in:           
[2022-01-05 11:03:22+0100] INFO  policy.generation.manager - Successful policy update '11' [started 2022-01-05 11:03:21 - ended 2022-01-05 11:03:22]
[2022-01-05 11:04:41+0100] INFO  policy.generation - Node 'agent1' (149dedb2-9469-4fc8-998f-7c7b2e26d8a2) is a DSC node and a we do not know how to generate a hash yet
[2022-01-05 11:04:45+0100] INFO  compliance - [metrics] global compliance (number of components): undefined
[2022-01-05 11:11:03+0100] WARN  com.normation.appconfig.GenericConfigService - Error when trying the read rudderc targets from settings (using default: cfengine): (Accumulated: Inconsistency: (expected '"' got 'c'))
[2022-01-05 11:11:03+0100] ERROR techniques.writer - An error occurred when compiling technique 'Deploy firefox' (id : 'BundleName(Deploy_firefox)') with rudderc, error details in /var/log/rudder/rudderc/failures/2022-01-05T11:11:03.435+01:00_Deploy_firefox.log, falling back to old saving process
[2022-01-05 11:11:04+0100] INFO  techniques.reader - Reloading technique library, found modified technique(s): ['Deploy_firefox': updated (1.0: added)]
[2022-01-05 11:11:04+0100] INFO  com.normation.rudder.services.policies.TechniqueAcceptationUpdater - Automatically adding technique 'Deploy_firefox' in category 'User Techniques (ncf_techniques)' of active techniques library
[2022-01-05 11:11:05+0100] INFO  com.normation.rudder.services.policies.DeployOnTechniqueCallback - Update Technique library after creating files for ncf Technique Deploy firefox
[2022-01-05 11:11:05+0100] INFO  policy.generation - Start policy generation, checking updated rules
[2022-01-05 11:11:05+0100] INFO  policy.generation - [metrics] Xmx:1015 MB nodes:2 (cached:2) rules:5 (enabled:4) techniques:50 (enabled:50) directives:9 (enabled:9) groups:3 (dynamic:3) parameters:2
[2022-01-05 11:11:05+0100] INFO  policy.generation - No node configuration was updated, no policies to write
[2022-01-05 11:11:05+0100] DEBUG explain_compliance - Updated node configuration ids: 
[2022-01-05 11:11:05+0100] INFO  policy.generation.timing - Timing summary:
[2022-01-05 11:11:05+0100] INFO  policy.generation.timing - Run pre-gen scripts hooks     :          1 ms
[2022-01-05 11:11:05+0100] INFO  policy.generation.timing - Run pre-gen modules hooks     :          0 ms
[2022-01-05 11:11:05+0100] INFO  policy.generation.timing - Fetch all information         :         77 ms
[2022-01-05 11:11:05+0100] INFO  policy.generation.timing - Build current rule values     :          2 ms
[2022-01-05 11:11:05+0100] INFO  policy.generation.timing - Build target configuration    :         16 ms
[2022-01-05 11:11:05+0100] INFO  policy.generation.timing - Write node configurations     :        319 ms
[2022-01-05 11:11:05+0100] INFO  policy.generation.timing - Save expected reports         :          0 ms
[2022-01-05 11:11:05+0100] INFO  policy.generation.timing - Run post generation hooks     :         59 ms
[2022-01-05 11:11:05+0100] INFO  policy.generation.timing - Number of nodes updated       :          0   
[2022-01-05 11:11:05+0100] INFO  policy.generation.timing - Policy generation succeeded in:           
[2022-01-05 11:11:05+0100] INFO  policy.generation.manager - Successful policy update '12' [started 2022-01-05 11:11:05 - ended 2022-01-05 11:11:05]
[2022-01-05 11:11:17+0100] INFO  policy.generation - Start policy generation, checking updated rules
[2022-01-05 11:11:17+0100] INFO  policy.generation - [metrics] Xmx:1015 MB nodes:2 (cached:2) rules:5 (enabled:5) techniques:50 (enabled:50) directives:10 (enabled:10) groups:3 (dynamic:3) parameters:2
[2022-01-05 11:11:17+0100] INFO  policy.generation - Configuration of 2 nodes were updated, their policies are going to be written
[2022-01-05 11:11:17+0100] DEBUG explain_compliance - Updated node configuration ids: [root:20220105-110317-d9186617->20220105-111117-4f49da25][149dedb2-9469-4fc8-998f-7c7b2e26d8a2:20220105-110317-141c3e1b->20220105-111117-3746871a]
[2022-01-05 11:11:20+0100] INFO  policy.generation.timing - Timing summary:
[2022-01-05 11:11:20+0100] INFO  policy.generation.timing - Run pre-gen scripts hooks     :          4 ms
[2022-01-05 11:11:20+0100] INFO  policy.generation.timing - Run pre-gen modules hooks     :          0 ms
[2022-01-05 11:11:20+0100] INFO  policy.generation.timing - Fetch all information         :         77 ms
[2022-01-05 11:11:20+0100] INFO  policy.generation.timing - Build current rule values     :          2 ms
[2022-01-05 11:11:20+0100] INFO  policy.generation.timing - Build target configuration    :         47 ms
[2022-01-05 11:11:20+0100] INFO  policy.generation.timing - Write node configurations     :       2368 ms
[2022-01-05 11:11:20+0100] INFO  policy.generation.timing - Save expected reports         :          0 ms
[2022-01-05 11:11:20+0100] INFO  policy.generation.timing - Run post generation hooks     :        447 ms
[2022-01-05 11:11:20+0100] INFO  policy.generation.timing - Number of nodes updated       :          2   
[2022-01-05 11:11:20+0100] INFO  policy.generation.timing - Policy generation succeeded in:        3 s
[2022-01-05 11:11:20+0100] INFO  policy.generation.manager - Successful policy update '13' [started 2022-01-05 11:11:17 - ended 2022-01-05 11:11:20]
[2022-01-05 11:15:51+0100] INFO  techniques.reader - Reloading technique library, no modified techniques found
[2022-01-05 11:15:51+0100] INFO  com.normation.rudder.services.policies.DeployOnTechniqueCallback - Automatic batch update at 20220105T111550.600+0100
[2022-01-05 11:45:50+0100] INFO  inventory-processing - [purge unreferenced software] Start gathering information about node's software
[2022-01-05 11:45:50+0100] INFO  inventory-processing - [purge unreferenced software] Found 54 unreferenced software in ou=software, going to delete them
[2022-01-05 11:45:50+0100] INFO  inventory-processing.timing - [purge unreferenced software] Deleted 54 software in 192ms
[2022-01-05 15:21:37+0100] INFO  compliance - [metrics] global compliance (number of components): 2 [p:0 s:0 r:0 e:0 u:0 m:1 nr:1 na:0 rd:0 c:0 ana:0 nc:0 ae:0 bpm:0]
[2022-01-05 15:22:19+0100] INFO  inventory-processing - Watch new inventory file 'server-root.ocs' with signature available: process.
[2022-01-05 15:22:20+0100] INFO  scheduled.job - Update in node inventories main information detected: triggering a policy generation
[2022-01-05 15:22:20+0100] INFO  policy.generation - Start policy generation, checking updated rules
[2022-01-05 15:22:20+0100] INFO  policy.generation - [metrics] Xmx:1015 MB nodes:2 (cached:2) rules:5 (enabled:5) techniques:50 (enabled:50) directives:10 (enabled:10) groups:3 (dynamic:3) parameters:2
[2022-01-05 15:22:20+0100] INFO  policy.generation - Configuration of 1 nodes were updated, their policies are going to be written
[2022-01-05 15:22:20+0100] DEBUG explain_compliance - Updated node configuration ids: [root:20220105-111117-4f49da25->20220105-152220-db63e4d6]
[2022-01-05 15:22:20+0100] INFO  inventory-processing - Inventory 'server-root.ocs' for node 'server.rudder.local' [root] (signature:certified) processed in 1 second and 251 milliseconds
[2022-01-05 15:22:22+0100] INFO  policy.generation.timing - Timing summary:
[2022-01-05 15:22:22+0100] INFO  policy.generation.timing - Run pre-gen scripts hooks     :          1 ms
[2022-01-05 15:22:22+0100] INFO  policy.generation.timing - Run pre-gen modules hooks     :          0 ms
[2022-01-05 15:22:22+0100] INFO  policy.generation.timing - Fetch all information         :         19 ms
[2022-01-05 15:22:22+0100] INFO  policy.generation.timing - Build current rule values     :          1 ms
[2022-01-05 15:22:22+0100] INFO  policy.generation.timing - Build target configuration    :         35 ms
[2022-01-05 15:22:22+0100] INFO  policy.generation.timing - Write node configurations     :       2184 ms
[2022-01-05 15:22:22+0100] INFO  policy.generation.timing - Save expected reports         :          1 ms
[2022-01-05 15:22:22+0100] INFO  policy.generation.timing - Run post generation hooks     :         82 ms
[2022-01-05 15:22:22+0100] INFO  policy.generation.timing - Number of nodes updated       :          1   
[2022-01-05 15:22:22+0100] INFO  policy.generation.timing - Policy generation succeeded in:        2 s
[2022-01-05 15:22:22+0100] INFO  policy.generation.manager - Successful policy update '14' [started 2022-01-05 15:22:20 - ended 2022-01-05 15:22:22]
[2022-01-05 15:24:42+0100] WARN  com.normation.appconfig.GenericConfigService - Error when trying the read rudderc targets from settings (using default: cfengine): (Accumulated: Inconsistency: (expected '"' got 'c'))
[2022-01-05 15:24:43+0100] ERROR techniques.writer - An error occurred when compiling technique 'abcde' (id : 'BundleName(abcde)') with rudderc, error details in /var/log/rudder/rudderc/failures/2022-01-05T15:24:43.529+01:00_abcde.log, falling back to old saving process
[2022-01-05 15:24:44+0100] INFO  techniques.reader - Reloading technique library, found modified technique(s): ['abcde': updated (1.0: added)]
[2022-01-05 15:24:44+0100] INFO  com.normation.rudder.services.policies.TechniqueAcceptationUpdater - Automatically adding technique 'abcde' in category 'User Techniques (ncf_techniques)' of active techniques library
[2022-01-05 15:24:44+0100] INFO  com.normation.rudder.services.policies.DeployOnTechniqueCallback - Update Technique library after creating files for ncf Technique abcde
[2022-01-05 15:24:44+0100] INFO  policy.generation - Start policy generation, checking updated rules
[2022-01-05 15:24:44+0100] INFO  policy.generation - [metrics] Xmx:1015 MB nodes:2 (cached:2) rules:5 (enabled:5) techniques:51 (enabled:51) directives:10 (enabled:10) groups:3 (dynamic:3) parameters:2
[2022-01-05 15:24:44+0100] INFO  policy.generation - No node configuration was updated, no policies to write
[2022-01-05 15:24:44+0100] DEBUG explain_compliance - Updated node configuration ids: 
[2022-01-05 15:24:44+0100] INFO  policy.generation.timing - Timing summary:
[2022-01-05 15:24:44+0100] INFO  policy.generation.timing - Run pre-gen scripts hooks     :          0 ms
[2022-01-05 15:24:44+0100] INFO  policy.generation.timing - Run pre-gen modules hooks     :          0 ms
[2022-01-05 15:24:44+0100] INFO  policy.generation.timing - Fetch all information         :         20 ms
[2022-01-05 15:24:44+0100] INFO  policy.generation.timing - Build current rule values     :          1 ms
[2022-01-05 15:24:44+0100] INFO  policy.generation.timing - Build target configuration    :          8 ms
[2022-01-05 15:24:44+0100] INFO  policy.generation.timing - Write node configurations     :        343 ms
[2022-01-05 15:24:44+0100] INFO  policy.generation.timing - Save expected reports         :          0 ms
[2022-01-05 15:24:44+0100] INFO  policy.generation.timing - Run post generation hooks     :         67 ms
[2022-01-05 15:24:44+0100] INFO  policy.generation.timing - Number of nodes updated       :          0   
[2022-01-05 15:24:44+0100] INFO  policy.generation.timing - Policy generation succeeded in:           
[2022-01-05 15:24:44+0100] INFO  policy.generation.manager - Successful policy update '15' [started 2022-01-05 15:24:44 - ended 2022-01-05 15:24:44]
[2022-01-05 15:25:12+0100] INFO  policy.generation - Start policy generation, checking updated rules
[2022-01-05 15:25:12+0100] INFO  policy.generation - [metrics] Xmx:1015 MB nodes:2 (cached:2) rules:5 (enabled:5) techniques:51 (enabled:51) directives:11 (enabled:11) groups:3 (dynamic:3) parameters:2
[2022-01-05 15:25:12+0100] INFO  policy.generation - Configuration of 2 nodes were updated, their policies are going to be written
[2022-01-05 15:25:12+0100] DEBUG explain_compliance - Updated node configuration ids: [root:20220105-152220-db63e4d6->20220105-152512-a06190de][149dedb2-9469-4fc8-998f-7c7b2e26d8a2:20220105-111117-3746871a->20220105-152512-984285d7]
[2022-01-05 15:25:15+0100] INFO  policy.generation.timing - Timing summary:
[2022-01-05 15:25:15+0100] INFO  policy.generation.timing - Run pre-gen scripts hooks     :          1 ms
[2022-01-05 15:25:15+0100] INFO  policy.generation.timing - Run pre-gen modules hooks     :          0 ms
[2022-01-05 15:25:15+0100] INFO  policy.generation.timing - Fetch all information         :         30 ms
[2022-01-05 15:25:15+0100] INFO  policy.generation.timing - Build current rule values     :          2 ms
[2022-01-05 15:25:15+0100] INFO  policy.generation.timing - Build target configuration    :         58 ms
[2022-01-05 15:25:15+0100] INFO  policy.generation.timing - Write node configurations     :       2750 ms
[2022-01-05 15:25:15+0100] INFO  policy.generation.timing - Save expected reports         :          1 ms
[2022-01-05 15:25:15+0100] INFO  policy.generation.timing - Run post generation hooks     :        104 ms
[2022-01-05 15:25:15+0100] INFO  policy.generation.timing - Number of nodes updated       :          2   
[2022-01-05 15:25:15+0100] INFO  policy.generation.timing - Policy generation succeeded in:        3 s
[2022-01-05 15:25:15+0100] INFO  policy.generation.manager - Successful policy update '16' [started 2022-01-05 15:25:12 - ended 2022-01-05 15:25:15]
[2022-01-05 15:25:51+0100] INFO  techniques.reader - Reloading technique library, no modified techniques found
[2022-01-05 15:25:51+0100] INFO  com.normation.rudder.services.policies.DeployOnTechniqueCallback - Automatic batch update at 20220105T152550.734+0100
[2022-01-05 15:32:21+0100] INFO  git-policy-archive - Importing full archive with id 'HEAD'
[2022-01-05 15:32:21+0100] INFO  git-policy-archive - Importing rules archive with id 'HEAD'
[2022-01-05 15:32:21+0100] INFO  git-policy-archive - Importing rule categories archive with id 'HEAD'
[2022-01-05 15:32:21+0100] INFO  git-policy-archive - Importing technique library archive with id 'HEAD'
[2022-01-05 15:32:22+0100] INFO  git-policy-archive - Importing groups archive with id 'HEAD'
[2022-01-05 15:32:22+0100] INFO  git-policy-archive - Importing Parameters archive with id 'HEAD'
[2022-01-05 15:32:22+0100] INFO  policy.generation - Start policy generation, checking updated rules
[2022-01-05 15:32:22+0100] INFO  policy.generation - [metrics] Xmx:1015 MB nodes:2 (cached:2) rules:5 (enabled:5) techniques:50 (enabled:50) directives:10 (enabled:10) groups:3 (dynamic:3) parameters:2
[2022-01-05 15:32:22+0100] INFO  policy.generation - Configuration of 2 nodes were updated, their policies are going to be written
[2022-01-05 15:32:22+0100] DEBUG explain_compliance - Updated node configuration ids: [root:20220105-152512-a06190de->20220105-153222-db63e4d6][149dedb2-9469-4fc8-998f-7c7b2e26d8a2:20220105-152512-984285d7->20220105-153222-3746871a]
[2022-01-05 15:32:24+0100] INFO  policy.generation.timing - Timing summary:
[2022-01-05 15:32:24+0100] INFO  policy.generation.timing - Run pre-gen scripts hooks     :          1 ms
[2022-01-05 15:32:24+0100] INFO  policy.generation.timing - Run pre-gen modules hooks     :          0 ms
[2022-01-05 15:32:24+0100] INFO  policy.generation.timing - Fetch all information         :         23 ms
[2022-01-05 15:32:24+0100] INFO  policy.generation.timing - Build current rule values     :          2 ms
[2022-01-05 15:32:24+0100] INFO  policy.generation.timing - Build target configuration    :         20 ms
[2022-01-05 15:32:24+0100] INFO  policy.generation.timing - Write node configurations     :       2005 ms
[2022-01-05 15:32:24+0100] INFO  policy.generation.timing - Save expected reports         :          1 ms
[2022-01-05 15:32:24+0100] INFO  policy.generation.timing - Run post generation hooks     :        197 ms
[2022-01-05 15:32:24+0100] INFO  policy.generation.timing - Number of nodes updated       :          2   
[2022-01-05 15:32:24+0100] INFO  policy.generation.timing - Policy generation succeeded in:        2 s
[2022-01-05 15:32:24+0100] INFO  policy.generation.manager - Successful policy update '17' [started 2022-01-05 15:32:22 - ended 2022-01-05 15:32:24]
[2022-01-05 15:32:24+0100] INFO  policy.generation - Start policy generation, checking updated rules
[2022-01-05 15:32:24+0100] INFO  policy.generation - [metrics] Xmx:1015 MB nodes:2 (cached:2) rules:5 (enabled:5) techniques:50 (enabled:50) directives:10 (enabled:10) groups:3 (dynamic:3) parameters:2
[2022-01-05 15:32:24+0100] INFO  policy.generation - No node configuration was updated, no policies to write
[2022-01-05 15:32:24+0100] DEBUG explain_compliance - Updated node configuration ids: 
[2022-01-05 15:32:25+0100] INFO  policy.generation.timing - Timing summary:
[2022-01-05 15:32:25+0100] INFO  policy.generation.timing - Run pre-gen scripts hooks     :          1 ms
[2022-01-05 15:32:25+0100] INFO  policy.generation.timing - Run pre-gen modules hooks     :          0 ms
[2022-01-05 15:32:25+0100] INFO  policy.generation.timing - Fetch all information         :         19 ms
[2022-01-05 15:32:25+0100] INFO  policy.generation.timing - Build current rule values     :          1 ms
[2022-01-05 15:32:25+0100] INFO  policy.generation.timing - Build target configuration    :          8 ms
[2022-01-05 15:32:25+0100] INFO  policy.generation.timing - Write node configurations     :        375 ms
[2022-01-05 15:32:25+0100] INFO  policy.generation.timing - Save expected reports         :          0 ms
[2022-01-05 15:32:25+0100] INFO  policy.generation.timing - Run post generation hooks     :        422 ms
[2022-01-05 15:32:25+0100] INFO  policy.generation.timing - Number of nodes updated       :          0   
[2022-01-05 15:32:25+0100] INFO  policy.generation.timing - Policy generation succeeded in:           
[2022-01-05 15:32:25+0100] INFO  policy.generation.manager - Successful policy update '18' [started 2022-01-05 15:32:24 - ended 2022-01-05 15:32:25]
[2022-01-05 15:35:51+0100] INFO  techniques.reader - Reloading technique library, found modified technique(s): ['abcde': deleted (1.0)]
[2022-01-05 15:35:51+0100] INFO  com.normation.rudder.services.policies.DeployOnTechniqueCallback - Automatic batch update at 20220105T153550.735+0100
[2022-01-05 15:35:51+0100] INFO  policy.generation - Start policy generation, checking updated rules
[2022-01-05 15:35:51+0100] INFO  policy.generation - [metrics] Xmx:1015 MB nodes:2 (cached:2) rules:5 (enabled:5) techniques:50 (enabled:50) directives:10 (enabled:10) groups:3 (dynamic:3) parameters:2
[2022-01-05 15:35:51+0100] INFO  policy.generation - No node configuration was updated, no policies to write
[2022-01-05 15:35:51+0100] DEBUG explain_compliance - Updated node configuration ids: 
[2022-01-05 15:35:52+0100] INFO  policy.generation.timing - Timing summary:
[2022-01-05 15:35:52+0100] INFO  policy.generation.timing - Run pre-gen scripts hooks     :          1 ms
[2022-01-05 15:35:52+0100] INFO  policy.generation.timing - Run pre-gen modules hooks     :          0 ms
[2022-01-05 15:35:52+0100] INFO  policy.generation.timing - Fetch all information         :         16 ms
[2022-01-05 15:35:52+0100] INFO  policy.generation.timing - Build current rule values     :          1 ms
[2022-01-05 15:35:52+0100] INFO  policy.generation.timing - Build target configuration    :          6 ms
[2022-01-05 15:35:52+0100] INFO  policy.generation.timing - Write node configurations     :        289 ms
[2022-01-05 15:35:52+0100] INFO  policy.generation.timing - Save expected reports         :          0 ms
[2022-01-05 15:35:52+0100] INFO  policy.generation.timing - Run post generation hooks     :        300 ms
[2022-01-05 15:35:52+0100] INFO  policy.generation.timing - Number of nodes updated       :          0   
[2022-01-05 15:35:52+0100] INFO  policy.generation.timing - Policy generation succeeded in:           
[2022-01-05 15:35:52+0100] INFO  policy.generation.manager - Successful policy update '19' [started 2022-01-05 15:35:51 - ended 2022-01-05 15:35:52]
[2022-01-05 15:36:21+0100] INFO  git-policy-archive - Importing full archive with id 'HEAD'
[2022-01-05 15:36:21+0100] INFO  git-policy-archive - Importing rules archive with id 'HEAD'
[2022-01-05 15:36:21+0100] INFO  git-policy-archive - Importing rule categories archive with id 'HEAD'
[2022-01-05 15:36:22+0100] INFO  git-policy-archive - Importing technique library archive with id 'HEAD'
[2022-01-05 15:36:22+0100] INFO  git-policy-archive - Importing groups archive with id 'HEAD'
[2022-01-05 15:36:22+0100] INFO  git-policy-archive - Importing Parameters archive with id 'HEAD'
[2022-01-05 15:36:22+0100] INFO  policy.generation - Start policy generation, checking updated rules
[2022-01-05 15:36:22+0100] INFO  policy.generation - [metrics] Xmx:1015 MB nodes:2 (cached:2) rules:5 (enabled:5) techniques:51 (enabled:51) directives:11 (enabled:11) groups:3 (dynamic:3) parameters:2
[2022-01-05 15:36:22+0100] INFO  policy.generation.timing - Policy generation failed after:           
[2022-01-05 15:36:22+0100] ERROR policy.generation.manager - Error when updating policy, reason was: Cannot build Rule vals <- Could not find configuration vals <- Version '1.0' of technique 'abcde' is not available for directive 'abcde' [5f380077-476c-4b11-a694-f1e9259e7dfd]
[2022-01-05 15:36:22+0100] ERROR policy.generation.manager - Policy update error for process '20' at 2022-01-05 15:36:22: Cannot build Rule vals
[2022-01-05 15:36:22+0100] INFO  policy.generation - Start policy generation, checking updated rules
[2022-01-05 15:36:22+0100] INFO  policy.generation - [metrics] Xmx:1015 MB nodes:2 (cached:2) rules:5 (enabled:5) techniques:51 (enabled:51) directives:11 (enabled:11) groups:3 (dynamic:3) parameters:2
[2022-01-05 15:36:22+0100] INFO  policy.generation.timing - Policy generation failed after:           
[2022-01-05 15:36:22+0100] ERROR policy.generation.manager - Error when updating policy, reason was: Cannot build Rule vals <- Could not find configuration vals <- Version '1.0' of technique 'abcde' is not available for directive 'abcde' [5f380077-476c-4b11-a694-f1e9259e7dfd]
[2022-01-05 15:36:22+0100] ERROR policy.generation.manager - Policy update error for process '21' at 2022-01-05 15:36:22: Cannot build Rule vals
[2022-01-05 15:36:22+0100] ERROR com.normation.rudder.services.policies.WriteNodeCertificatesPemImpl - Unexpected: Error when executing reload command '/opt/rudder/bin/rudder relay reload -p' after writing node certificates file. Command output: code: 1
stdout: error: Could not reload relayd configuration
{"result":"error","action":"reloadConfiguration","errorDetails":"Permission denied (os error 13)"}

stderr: 
[2022-01-05 15:39:03+0100] WARN  com.normation.rudder.web.snippet.configuration.DirectiveManagement - Can not display directive edit form: missing information about technique with name='abcde' and version='1.0'
[2022-01-05 15:40:39+0100] INFO  techniques.reader - Reloading technique library, found modified technique(s): ['abcde': updated (1.0: added)]
[2022-01-05 15:40:39+0100] INFO  com.normation.rudder.services.policies.DeployOnTechniqueCallback - Technique library reloaded from REST API
[2022-01-05 15:40:39+0100] INFO  policy.generation - Start policy generation, checking updated rules
[2022-01-05 15:40:39+0100] INFO  policy.generation - [metrics] Xmx:1015 MB nodes:2 (cached:2) rules:5 (enabled:5) techniques:51 (enabled:51) directives:11 (enabled:11) groups:3 (dynamic:3) parameters:2
[2022-01-05 15:40:39+0100] INFO  policy.generation - Configuration of 2 nodes were updated, their policies are going to be written
[2022-01-05 15:40:39+0100] DEBUG explain_compliance - Updated node configuration ids: [root:20220105-153222-db63e4d6->20220105-154039-52f0bc88][149dedb2-9469-4fc8-998f-7c7b2e26d8a2:20220105-153222-3746871a->20220105-154039-c0760bf8]
[2022-01-05 15:40:41+0100] INFO  policy.generation.timing - Timing summary:
[2022-01-05 15:40:41+0100] INFO  policy.generation.timing - Run pre-gen scripts hooks     :          1 ms
[2022-01-05 15:40:41+0100] INFO  policy.generation.timing - Run pre-gen modules hooks     :          0 ms
[2022-01-05 15:40:41+0100] INFO  policy.generation.timing - Fetch all information         :         38 ms
[2022-01-05 15:40:41+0100] INFO  policy.generation.timing - Build current rule values     :          2 ms
[2022-01-05 15:40:41+0100] INFO  policy.generation.timing - Build target configuration    :         26 ms
[2022-01-05 15:40:41+0100] INFO  policy.generation.timing - Write node configurations     :       2016 ms
[2022-01-05 15:40:41+0100] INFO  policy.generation.timing - Save expected reports         :          1 ms
[2022-01-05 15:40:41+0100] INFO  policy.generation.timing - Run post generation hooks     :        146 ms
[2022-01-05 15:40:41+0100] INFO  policy.generation.timing - Number of nodes updated       :          2   
[2022-01-05 15:40:41+0100] INFO  policy.generation.timing - Policy generation succeeded in:        2 s
[2022-01-05 15:40:41+0100] INFO  policy.generation.manager - Successful policy update '22' [started 2022-01-05 15:40:39 - ended 2022-01-05 15:40:41]
[2022-01-05 15:40:51+0100] INFO  techniques.reader - Reloading technique library, no modified techniques found
[2022-01-05 15:40:51+0100] INFO  com.normation.rudder.services.policies.DeployOnTechniqueCallback - Automatic batch update at 20220105T154050.735+0100

Files

Download all files
missing.png (17.8 KB) missing.png Félix DALLIDET, 2022-01-05 15:57
rudder.patch (7.86 KB) rudder.patch Félix DALLIDET, 2022-01-05 16:08

Related issues 6 (2 open — 4 closed)

Related to Rudder - Bug #20401: Error while deleting new / imported TechniquesResolvedActions
Related to Rudder - Bug #17862: error when importing techniques and running reload-techniques in 6.1RejectedActions
Related to Rudder - Bug #15562: Error on importing Global Archive which has just been exportedRejectedActions
Related to Rudder - Bug #11686: Dynamic groups not reloaded after importing archiveRejectedVincent MEMBRÉActions
Related to Rudder - Architecture #7471: Techniques should be reloaded before importing an archiveNewActions
Related to Rudder - Bug #17690: When creating a user technique with restore archive, policy are not correctly regeneratedNewActions
Actions
Copy link
 #2

Updated by Nicolas CHARLES over 2 years ago

15:32: full import
15:35: technique is deleted because of automatic reload of techniques from git every 5 minutes
technique is added back on the FS
15:36: full import - doesn't find/loog for the technique
15:40: reload techniques: fixes the issue

Actions
Copy link
 #3

Updated by Félix DALLIDET over 2 years ago

Here is the git log if needed:

commit 5565da846b405f306924bb883fda8fdf22c36373 (HEAD -> master)
Author: Rudder system account <email not set>
Date:   Wed Jan 5 15:40:39 2022 +0100

    Archive of technique library template for technique name 'abcde'

    Reason provided by user:
    Technique library reloaded from REST API

commit 94aa4f41dd774dde0aba432a306947a6dfa323dc
Author: Rudder system account <email not set>
Date:   Wed Jan 5 15:40:39 2022 +0100

    Archive directive with ID '5f380077-476c-4b11-a694-f1e9259e7dfd'

    Reason provided by user:
    Technique library reloaded from REST API

commit d0864175617361d7caa04078fe7124eea6fb3831
Author: rudder <email not set>
Date:   Wed Jan 5 15:38:58 2022 +0100

    Saving updated generic methods definition

commit 3ec215a0c26efa5042fa4c96c29d9a19bfe57901
Author: rudder <email not set>
Date:   Wed Jan 5 15:38:57 2022 +0100

    Saving updated generic methods definition

commit 9a615afa80de2e80858b9ab83b7d04da1ed13a00
Author: rudder <email not set>
Date:   Wed Jan 5 15:38:57 2022 +0100

    Saving updated generic methods definition

commit 9c20027c1e13f7ed21f6e29d69648cda4a616f02
Author: rudder <email not set>
Date:   Wed Jan 5 15:36:34 2022 +0100

    Saving updated generic methods definition

commit fea7622dc40f4cfe3c440bdd3521627fcc87aa6c
Author: rudder <email not set>
Date:   Wed Jan 5 15:36:34 2022 +0100

    Saving updated generic methods definition

commit e2fceacb639140f4403f711268a15b0d3c2c9fbd
Author: rudder <email not set>
Date:   Wed Jan 5 15:36:33 2022 +0100
...skipping...

commit c2b16fbcc77bd4fa533edb9b59352e59b8cb7921
Author: rudder <email not set>
Date:   Wed Jan 5 10:33:27 2022 +0100

    Archive of technique library template for technique name 'packageManagement'

    Reason provided by user:
    Initialize active templates library

commit 86842f8327620e273b2ad7fc506bedcd5abb7c79
Author: rudder <email not set>
Date:   Wed Jan 5 10:33:27 2022 +0100

    Archive of technique library template for technique name 'snmp'

    Reason provided by user:
    Initialize active templates library

commit 9b8b54f8ba68b80c1497f6074f9d49c40c6b063d
Author: rudder <email not set>
Date:   Wed Jan 5 10:33:27 2022 +0100

    Archive of technique library template for technique name 'repoGpgKeyManagement'

    Reason provided by user:
    Initialize active templates library

commit 30504bcda9b5c62e0a02c555f0e84698af5f954b
Author: rudder <email not set>
Date:   Wed Jan 5 10:33:27 2022 +0100

    Archive of technique library template for technique name 'aptPackageManagerSettings'

    Reason provided by user:
    Initialize active templates library

commit 6d2c96cb78e164256211a1f3c2c16ea262d49a69
Author: rudder <email not set>
Date:   Wed Jan 5 10:33:26 2022 +0100

    Archive of technique library category with ID 'applications'

    Reason provided by user:
    Initialize active templates library

commit 96f10600c12b93401d175f6270534ffc8021de6d
Author: root user (CLI) <root@localhost>
Date:   Wed Jan 5 10:32:56 2022 +0100

    initial commit

Actions
Copy link
 #4

Updated by Vincent MEMBRÉ over 2 years ago

  • Target version changed from 7.0.0~rc3 to 7.0.0
Actions
Copy link
 #5

Updated by Vincent MEMBRÉ about 2 years ago

  • Target version changed from 7.0.0 to 7.0.1
Actions
Copy link
 #6

Updated by François ARMAND about 2 years ago

  • Related to Bug #20401: Error while deleting new / imported Techniques added
Actions
Copy link
 #7

Updated by François ARMAND about 2 years ago

  • Related to Bug #17862: error when importing techniques and running reload-techniques in 6.1 added
Actions
Copy link
 #8

Updated by François ARMAND about 2 years ago

  • Related to Bug #15562: Error on importing Global Archive which has just been exported added
Actions
Copy link
 #9

Updated by François ARMAND about 2 years ago

  • Related to Bug #11686: Dynamic groups not reloaded after importing archive added
Actions
Copy link
 #10

Updated by François ARMAND about 2 years ago

  • Related to Architecture #7471: Techniques should be reloaded before importing an archive added
Actions
Copy link
 #11

Updated by François ARMAND about 2 years ago

This is not 7.0 specific: see #7471 for example :)

Actions
Copy link
 #12

Updated by François ARMAND about 2 years ago

  • Target version changed from 7.0.1 to 6.2.13
Actions
Copy link
 #13

Updated by Vincent MEMBRÉ about 2 years ago

  • Target version changed from 6.2.13 to 6.2.14
Actions
Copy link
 #14

Updated by Vincent MEMBRÉ almost 2 years ago

  • Target version changed from 6.2.14 to 6.2.15
Actions
Copy link
 #15

Updated by Vincent MEMBRÉ almost 2 years ago

  • Target version changed from 6.2.15 to 6.2.16
Actions
Copy link
 #16

Updated by Alexis Mousset over 1 year ago

  • Target version changed from 6.2.16 to 6.2.17
Actions
Copy link
 #17

Updated by Vincent MEMBRÉ over 1 year ago

  • Target version changed from 6.2.17 to 997
Actions
Copy link
 #18

Updated by Vincent MEMBRÉ over 1 year ago

  • Target version changed from 997 to 6.2.18
Actions
Copy link
 #19

Updated by Vincent MEMBRÉ over 1 year ago

  • Target version changed from 6.2.18 to 6.2.19
Actions
Copy link
 #20

Updated by Vincent MEMBRÉ over 1 year ago

  • Target version changed from 6.2.19 to 6.2.20
Actions
Copy link
 #21

Updated by Vincent MEMBRÉ over 1 year ago

  • Target version changed from 6.2.20 to old 6.2 issues to relocate
Actions
Copy link
 #22

Updated by Alexis Mousset 9 months ago

  • Target version changed from old 6.2 issues to relocate to 7.2.11
  • Regression set to No
Actions
Copy link
 #23

Updated by Vincent MEMBRÉ 7 months ago

  • Target version changed from 7.2.11 to 1046
Actions
Copy link
 #24

Updated by Alexis Mousset 7 months ago

  • Target version changed from 1046 to 7.3.8
Actions
Copy link
 #25

Updated by Vincent MEMBRÉ 6 months ago

  • Target version changed from 7.3.8 to 7.3.9
Actions
Copy link
 #26

Updated by Vincent MEMBRÉ 6 months ago

  • Target version changed from 7.3.9 to 7.3.10
Actions
Copy link
 #27

Updated by François ARMAND 6 months ago

  • Related to Bug #17690: When creating a user technique with restore archive, policy are not correctly regenerated added
Actions
Copy link
 #28

Updated by Vincent MEMBRÉ 4 months ago

  • Target version changed from 7.3.10 to 7.3.11
Actions
Copy link
 #29

Updated by Vincent MEMBRÉ 3 months ago

  • Target version changed from 7.3.11 to 7.3.12
Actions
Copy link
 #30

Updated by Vincent MEMBRÉ about 2 months ago

  • Target version changed from 7.3.12 to 7.3.13
Actions
Copy link
 #31

Updated by Vincent MEMBRÉ about 2 months ago

  • Target version changed from 7.3.13 to 7.3.14
Actions
Copy link
 #32

Updated by Vincent MEMBRÉ about 3 hours ago

  • Target version changed from 7.3.14 to 7.3.15
Actions
Copy link

Also available in: Atom PDF