Issue #20919 has been updated by Charlie Sharpsteen.

Status changed from Unreviewed to Duplicate
Assignee set to Charlie Sharpsteen

Thanks for reporting this Andreas.

The change of behavior resulted from a patch that tried to ensure messages 
weren't lost during daemon start-up by sending them to the console if no other 
logger was specified. Unfortunately, the patch had unintended side-effects and 
now all agents end up with a console logger attached even if `--logdest` is in 
used. Marking as a duplicate of #20263.

----------------------------------------
Bug #20919: Logging behaviour issues in 3.2.1
https://projects.puppetlabs.com/issues/20919#change-91637

* Author: Andreas Ntaflos
* Status: Duplicate
* Priority: Normal
* Assignee: Charlie Sharpsteen
* Category: 
* Target version: 
* Affected Puppet version: 
* Keywords: 
* Branch: 
----------------------------------------
As reported [1,2,3] on the puppet-users list it seems some undocumented changes 
(regressions?) made it into Puppet 3.2.1 regarding logging behaviour.
Using Puppet 3.2.1 on Ubuntu 12.04 and 10.04.

We run Puppet from Cron, and up to 3.1.1 this `cron` resource did the job just 
fine:

<pre>
cron { 'puppet_agent':
  ensure  => 'present',
  command => '/usr/bin/puppet agent -o --no-daemonize --logdest syslog',
  user    => 'root',
  minute  => [ $min1, $min2, $min3, $min4 ],
}
</pre>

This sent log messages to syslog (and nowhere else!) looking like this:

<pre>
May 21 09:30:01 node01 CRON[14018]: (root) CMD (/usr/bin/puppet agent --onetime 
--no-daemonize --logdest syslog)
May 21 09:30:38 node01 crontab[15379]: (root) LIST (root)
May 21 09:30:38 node01 puppet-agent[14019]: Finished catalog run in 17.33 
seconds 
</pre>

The same `cron` resource in Puppet 3.2.1 produces syslog messages like this:

<pre>
May 24 07:15:01 node01 CRON[23182]: (root) CMD (/usr/bin/puppet agent --onetime 
--no-daemonize --logdest syslog > /dev/null 2>&1)
May 24 07:15:02 node01 puppet-agent[23183]: Retrieving plugin
May 24 07:15:03 node01 puppet-agent[23183]: Loading facts in 
/var/lib/puppet/lib/facter/postgres_default_version.rb
May 24 07:15:03 node01 puppet-agent[23183]: Loading facts in 
/var/lib/puppet/lib/facter/corosync_mcastaddr.rb
May 24 07:15:03 node01 puppet-agent[23183]: Loading facts in 
/var/lib/puppet/lib/facter/pe_version.rb
May 24 07:15:03 node01 puppet-agent[23183]: Loading facts in 
/var/lib/puppet/lib/facter/concat_basedir.rb
May 24 07:15:03 node01 puppet-agent[23183]: Loading facts in 
/var/lib/puppet/lib/facter/root_home.rb
May 24 07:15:03 node01 puppet-agent[23183]: Loading facts in 
/var/lib/puppet/lib/facter/lvm_disk_usage.rb
May 24 07:15:03 node01 puppet-agent[23183]: Loading facts in 
/var/lib/puppet/lib/facter/corosync_mcastport.rb
May 24 07:15:03 node01 puppet-agent[23183]: Loading facts in 
/var/lib/puppet/lib/facter/libvirt_guests.rb
May 24 07:15:03 node01 puppet-agent[23183]: Loading facts in 
/var/lib/puppet/lib/facter/libvirt_used_memory.rb
May 24 07:15:03 node01 puppet-agent[23183]: Loading facts in 
/var/lib/puppet/lib/facter/puppet_vardir.rb
May 24 07:15:03 node01 puppet-agent[23183]: Loading facts in 
/var/lib/puppet/lib/facter/has_libvirtd.rb
May 24 07:15:03 node01 puppet-agent[23183]: Loading facts in 
/var/lib/puppet/lib/facter/has_group_libvirtd.rb
May 24 07:15:22 node01 puppet-agent[23183]: Caching catalog for 
node01.example.com
May 24 07:15:24 node01 puppet-agent[23183]: Applying configuration version 
'1369362429'
May 24 07:15:43 node01 crontab[24545]: (root) LIST (root)
May 24 07:15:43 node01 puppet-agent[23183]: Finished catalog run in 20.11 
seconds 
</pre>

Apparently the default log level changed from "notice" to "verbose"?

Also, much more disturbing, these messages now also seem to go to STDOUT. This 
means Cron produces mail messages for every Puppet run! With hundreds of nodes 
and four Puppet runs every hour this results in thousands of mail messages per 
day. None of these messages contain anything interesting, just output like 
above, but with the colour control characters still included:

<pre>
 [0;32mInfo: Retrieving plugin [0m
 [0;32mInfo: Loading facts in
/var/lib/puppet/lib/facter/lvm_disk_usage.rb [0m
 [0;32mInfo: Loading facts in /var/lib/puppet/lib/facter/pe_version.rb [0m
 [0;32mInfo: Loading facts in
/var/lib/puppet/lib/facter/puppet_vardir.rb [0m
 [0;32mInfo: Loading facts in
/var/lib/puppet/lib/facter/corosync_mcastport.rb [0m
 [0;32mInfo: Loading facts in
/var/lib/puppet/lib/facter/libvirt_guests.rb [0m
 [0;32mInfo: Loading facts in
/var/lib/puppet/lib/facter/concat_basedir.rb [0m
 [0;32mInfo: Loading facts in /var/lib/puppet/lib/facter/has_libvirtd.rb [0m
 [0;32mInfo: Loading facts in /var/lib/puppet/lib/facter/root_home.rb [0m
 [0;32mInfo: Loading facts in
/var/lib/puppet/lib/facter/postgres_default_version.rb [0m
 [0;32mInfo: Loading facts in
/var/lib/puppet/lib/facter/corosync_mcastaddr.rb [0m
 [0;32mInfo: Loading facts in
/var/lib/puppet/lib/facter/has_group_libvirtd.rb [0m
 [0;32mInfo: Loading facts in
/var/lib/puppet/lib/facter/libvirt_used_memory.rb [0m
 [0;32mInfo: Caching catalog for node01.example.com[0m
 [0;32mInfo: Applying configuration version '1369264386' [0m
 [mNotice: Finished catalog run in 17.63 seconds [0m
</pre>

We had to change the `cron` resource definition to the following to make Cron 
shut up:

<pre>
cron { 'puppet_agent':
  ensure  => 'present',
  command => '/usr/bin/puppet agent -o --no-daemonize --logdest syslog > 
/dev/null',
  user    => 'root',
  minute  => [ $min1, $min2, $min3, $min4 ],
}
</pre>

All of this doesn't seem like deliberate changes to the logging behaviour, 
especially since I cannot find any of it documented in the release notes.

[1] https://groups.google.com/d/msg/puppet-users/7eK2Qs3XALU/3Sns247k8bEJ
[2] https://groups.google.com/d/msg/puppet-users/7eK2Qs3XALU/_nt6GEixMsoJ
[3] https://groups.google.com/d/msg/puppet-users/NZky_BW89pc/66GH3pvbHLwJ


-- 
You have received this notification because you have either subscribed to it, 
or are involved in it.
To change your notification preferences, please click here: 
http://projects.puppetlabs.com/my/account

-- 
You received this message because you are subscribed to the Google Groups 
"Puppet Bugs" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to [email protected].
To post to this group, send email to [email protected].
Visit this group at http://groups.google.com/group/puppet-bugs?hl=en.
For more options, visit https://groups.google.com/groups/opt_out.


Reply via email to