Project

General

Profile

Actions
Copy link

Bug #9512

closed

Bad log level during generation

Added by François ARMAND over 7 years ago. Updated over 5 years ago.

Status:
Released
Priority:
N/A
Assignee:
François ARMAND
Category:
System integration
Target version:
4.3.7
Pull Request:
https://github.com/Normation/rudder/p...
Severity:
Trivial - no functional impact | cosmetic
UX impact:
User visibility:
Operational - other Techniques | Technique editor | Rudder settings
Effort required:
Small
Priority:
0
Name check:
Fix check:
Regression:

Description

The log level during a generation are strange for a default installation:


[2016-10-24 14:21:31] INFO  com.normation.rudder.repository.xml.GitParameterArchiverImpl - Create a new archive: GitPath(archives/parameters/2016-10-24_14-21-31.722)
[2016-10-24 14:21:31] INFO  com.normation.rudder.repository.xml.ItemArchiveManagerImpl - Create a new archive: GitPath(archives/full/2016-10-24_14-21-31.936)
[2016-10-24 14:22:11] INFO  com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Start policy generation, checking updated rules
[2016-10-24 14:22:11] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - All relevant information fetched in 233 ms, start names historization.
[2016-10-24 14:22:11] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Node contexts built in 169 ms, start to build new node configurations.
[2016-10-24 14:22:11] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Historization of names done in 151 ms, start to build rule values.
[2016-10-24 14:22:11] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - RuleVals built in 13 ms, start to expand their values.
[2016-10-24 14:22:11] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Node's target configuration built in 99 ms, start to update rule values.
[2016-10-24 14:22:11] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - RuleVals updated in 18 ms, start to detect changes in node configuration.
[2016-10-24 14:22:11] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Checked node configuration updates leading to rules serial number updates and serial number updated in 24 ms
[2016-10-24 14:22:11] INFO  com.normation.rudder.services.policies.nodeconfig.NodeConfigurationServiceImpl - Configuration of following nodes were updated, their promises are going to be written: [root]
[2016-10-24 14:22:14] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Node configuration written on filesystem in 2515 ms
[2016-10-24 14:22:14] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Node configuration cached in LDAP in 58 ms
[2016-10-24 14:22:14] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Node configuration written in 2584 ms, start to update expected reports.
[2016-10-24 14:22:14] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Reports updated in 246 ms
[2016-10-24 14:22:14] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Timing summary:
[2016-10-24 14:22:14] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Fetch all information     :        233 ms
[2016-10-24 14:22:14] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Historize names           :        151 ms
[2016-10-24 14:22:14] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Build current rule values :         13 ms
[2016-10-24 14:22:14] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Build target configuration:         99 ms
[2016-10-24 14:22:14] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Update rule vals          :         18 ms
[2016-10-24 14:22:14] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Increment rule serials    :         24 ms
[2016-10-24 14:22:14] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Write node configurations :       2584 ms
[2016-10-24 14:22:14] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Save expected reports     :        246 ms
[2016-10-24 14:22:14] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Policy generation completed in 3569 ms
[2016-10-24 14:22:14] INFO  com.normation.rudder.batch.AsyncDeploymentAgent - Successful policy update '3' [started 2016-10-24 14:22:11 - ended 2016-10-24 14:22:14]
Actions
Copy link
 #1

Updated by Alexis Mousset over 7 years ago

  • Target version changed from 321 to 4.0.1
Actions
Copy link
 #2

Updated by Vincent MEMBRÉ over 7 years ago

  • Target version changed from 4.0.1 to 4.0.2
Actions
Copy link
 #3

Updated by Vincent MEMBRÉ over 7 years ago

  • Target version changed from 4.0.2 to 4.0.3
Actions
Copy link
 #4

Updated by Vincent MEMBRÉ about 7 years ago

  • Target version changed from 4.0.3 to 4.0.4
Actions
Copy link
 #5

Updated by Benoît PECCATTE about 7 years ago

  • Severity set to Trivial - no functional impact | cosmetic
  • User visibility set to Operational - other Techniques | Technique editor | Rudder settings
  • Effort required set to Small
  • Priority set to 20
Actions
Copy link
 #6

Updated by Vincent MEMBRÉ about 7 years ago

  • Target version changed from 4.0.4 to 4.0.5
Actions
Copy link
 #7

Updated by Vincent MEMBRÉ almost 7 years ago

  • Target version changed from 4.0.5 to 4.0.6
Actions
Copy link
 #8

Updated by Vincent MEMBRÉ almost 7 years ago

  • Target version changed from 4.0.6 to 4.0.7
Actions
Copy link
 #9

Updated by Vincent MEMBRÉ almost 7 years ago

  • Target version changed from 4.0.7 to 357
  • Priority changed from 20 to 19
Actions
Copy link
 #10

Updated by Benoît PECCATTE almost 7 years ago

  • Priority changed from 19 to 29
Actions
Copy link
 #11

Updated by Alexis Mousset almost 7 years ago

  • Target version changed from 357 to 4.1.6
Actions
Copy link
 #12

Updated by Vincent MEMBRÉ over 6 years ago

  • Target version changed from 4.1.6 to 4.1.7
  • Priority changed from 29 to 28
Actions
Copy link
 #13

Updated by Vincent MEMBRÉ over 6 years ago

  • Target version changed from 4.1.7 to 4.1.8
Actions
Copy link
 #14

Updated by Vincent MEMBRÉ over 6 years ago

  • Target version changed from 4.1.8 to 4.1.9
  • Priority changed from 28 to 27
Actions
Copy link
 #15

Updated by Benoît PECCATTE over 6 years ago

  • Priority changed from 27 to 37
Actions
Copy link
 #16

Updated by Vincent MEMBRÉ over 6 years ago

  • Target version changed from 4.1.9 to 4.1.10
Actions
Copy link
 #17

Updated by Vincent MEMBRÉ about 6 years ago

  • Target version changed from 4.1.10 to 4.1.11
Actions
Copy link
 #18

Updated by Vincent MEMBRÉ about 6 years ago

  • Target version changed from 4.1.11 to 4.1.12
Actions
Copy link
 #19

Updated by Vincent MEMBRÉ almost 6 years ago

  • Target version changed from 4.1.12 to 4.1.13
Actions
Copy link
 #20

Updated by Vincent MEMBRÉ almost 6 years ago

  • Target version changed from 4.1.13 to 4.1.14
Actions
Copy link
 #21

Updated by Benoît PECCATTE over 5 years ago

  • Target version changed from 4.1.14 to 4.1.15
Actions
Copy link
 #22

Updated by Vincent MEMBRÉ over 5 years ago

  • Target version changed from 4.1.15 to 4.1.16
Actions
Copy link
 #23

Updated by Vincent MEMBRÉ over 5 years ago

  • Target version changed from 4.1.16 to 4.1.17
Actions
Copy link
 #24

Updated by Nicolas CHARLES over 5 years ago

  • Target version changed from 4.1.17 to 4.3.7
  • Priority changed from 37 to 0
Actions
Copy link
 #25

Updated by Nicolas CHARLES over 5 years ago

  • Status changed from New to In progress
  • Assignee set to Nicolas CHARLES
Actions
Copy link
 #26

Updated by Nicolas CHARLES over 5 years ago

Logs are now
[2018-11-07 17:07:40] INFO  policy.generation - Successful policy update '3' [started 2018-11-07 17:07:36 - ended 2018-11-07 17:07:40]
[2018-11-07 17:07:54] INFO  com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Start policy generation, checking updated rules
[2018-11-07 17:07:54] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Pre-policy-generation scripts hooks ran in 3 ms
[2018-11-07 17:07:54] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Pre-policy-generation modules hooks in 0 ms, start getting all generation related data.
[2018-11-07 17:07:54] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - All relevant information fetched in 55 ms, start names historization.
[2018-11-07 17:07:54] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Historization of names done in 57 ms, start to build rule values.
[2018-11-07 17:07:54] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - RuleVals built in 1 ms, start to expand their values.
[2018-11-07 17:07:54] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Node contexts built in 27 ms, start to build new node configurations.
[2018-11-07 17:07:54] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Node's target configuration built in 39 ms, start to update rule values.
[2018-11-07 17:07:54] INFO  com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Configuration of following nodes were updated, their promises are going to be written: [root]
[2018-11-07 17:07:54] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Reports updated in 1 ms
[2018-11-07 17:07:56] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Node configuration written on filesystem in 2306 ms
[2018-11-07 17:07:56] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Node configuration cached in LDAP in 12 ms
[2018-11-07 17:07:56] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Node configuration written in 2318 ms, start to update expected reports.
[2018-11-07 17:07:56] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Node expected reports saved in base in 2318 ms.
[2018-11-07 17:07:56] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Post-policy-generation hooks ran in 20 ms
[2018-11-07 17:07:56] INFO  policy.generation - Timing summary:
[2018-11-07 17:07:56] INFO  policy.generation - Run pre-gen scripts hooks :          3 ms
[2018-11-07 17:07:56] INFO  policy.generation - Run pre-gen modules hooks :          0 ms
[2018-11-07 17:07:56] INFO  policy.generation - Fetch all information     :         55 ms
[2018-11-07 17:07:56] INFO  policy.generation - Historize names           :         57 ms
[2018-11-07 17:07:56] INFO  policy.generation - Build current rule values :          1 ms
[2018-11-07 17:07:56] INFO  policy.generation - Build target configuration:         39 ms
[2018-11-07 17:07:56] INFO  policy.generation - Write node configurations :       2318 ms
[2018-11-07 17:07:56] INFO  policy.generation - Save expected reports     :          1 ms
[2018-11-07 17:07:56] INFO  policy.generation - Run post generation hooks :         20 ms
[2018-11-07 17:07:56] INFO  policy.generation - Number of nodes updated   :          1   
[2018-11-07 17:07:56] DEBUG com.normation.rudder.services.policies.PromiseGenerationServiceImpl - Policy generation completed in 2570 ms
[2018-11-07 17:07:56] INFO  policy.generation - Successful policy update '4' [started 2018-11-07 17:07:54 - ended 2018-11-07 17:07:56]

Solution us:
  • hide the DEBUG
  • change the INFO com.normation.rudder.services.policies.PromiseGenerationServiceImpl to INFO policy.generation
  • add the total time in the INFO policy.generation
Actions
Copy link
 #27

Updated by Nicolas CHARLES over 5 years ago

  • Status changed from In progress to Pending technical review
  • Assignee changed from Nicolas CHARLES to François ARMAND
  • Pull Request set to https://github.com/Normation/rudder/pull/2079
Actions
Copy link
 #28

Updated by Nicolas CHARLES over 5 years ago

  • Status changed from Pending technical review to Pending release
Actions
Copy link
 #29

Updated by Vincent MEMBRÉ over 5 years ago

  • Status changed from Pending release to Released
This bug has been fixed in Rudder 4.3.7 and 5.0.3 which were released today. 
Changelog
 Changelog
Actions
Copy link

Also available in: Atom PDF