Bug #20520: Error while importing ncf techniques using the restore from latest commit feature - Rudder - Issue Tracker

Actions

Copy link

Bug #20520

open

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

Added by Félix DALLIDET almost 3 years ago. Updated 5 months ago.

Status:

New

Priority:

N/A

Assignee:

Category:

Server components

Target version:

7.3.17

Pull Request:

Severity:

UX impact:

User visibility:

Effort required:

Priority:

Name check:

To do

Fix check:

To do

Regression:

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 7 (3 open — 4 closed)

Related to Rudder - Bug #20401: Error while deleting new / imported Techniques	Resolved		Actions
Related to Rudder - Bug #17862: error when importing techniques and running reload-techniques in 6.1	Rejected		Actions
Related to Rudder - Bug #15562: Error on importing Global Archive which has just been exported	Rejected		Actions
Related to Rudder - Bug #11686: Dynamic groups not reloaded after importing archive	Rejected	Vincent MEMBRÉ	Actions
Related to Rudder - Architecture #7471: Techniques should be reloaded before importing an archive	New		Actions
Related to Rudder - Bug #17690: When creating a user technique with restore archive, policy are not correctly regenerated	New		Actions
Related to Rudder - Bug #24294: API Import does not reload imported techniques before importing elements that rely on them	New	François ARMAND	Actions

Actions

Copy link

Also available in: Atom PDF

Project

General

Profile

Rudder

Custom queries

Bug #20520

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

Updated by Félix DALLIDET almost 3 years ago

Updated by Nicolas CHARLES almost 3 years ago

Updated by Félix DALLIDET almost 3 years ago

Updated by Vincent MEMBRÉ almost 3 years ago

Updated by Vincent MEMBRÉ almost 3 years ago

Updated by François ARMAND almost 3 years ago

Updated by François ARMAND almost 3 years ago

Updated by François ARMAND almost 3 years ago

Updated by François ARMAND almost 3 years ago

Updated by François ARMAND almost 3 years ago

Updated by François ARMAND almost 3 years ago

Updated by François ARMAND almost 3 years ago

Updated by Vincent MEMBRÉ over 2 years ago

Updated by Vincent MEMBRÉ over 2 years ago

Updated by Vincent MEMBRÉ over 2 years ago

Updated by Alexis Mousset over 2 years ago

Updated by Vincent MEMBRÉ about 2 years ago

Updated by Vincent MEMBRÉ about 2 years ago

Updated by Vincent MEMBRÉ about 2 years ago

Updated by Vincent MEMBRÉ about 2 years ago

Updated by Vincent MEMBRÉ about 2 years ago

Updated by Alexis Mousset over 1 year ago

Updated by Vincent MEMBRÉ about 1 year ago

Updated by Alexis Mousset about 1 year ago

Updated by Vincent MEMBRÉ about 1 year ago

Updated by Vincent MEMBRÉ about 1 year ago

Updated by François ARMAND about 1 year ago

Updated by Vincent MEMBRÉ 12 months ago

Updated by Vincent MEMBRÉ 10 months ago

Updated by Vincent MEMBRÉ 9 months ago

Updated by Vincent MEMBRÉ 9 months ago

Updated by Vincent MEMBRÉ 7 months ago

Updated by Vincent MEMBRÉ 6 months ago

Updated by Vincent MEMBRÉ 5 months ago

Updated by Nicolas CHARLES 4 months ago