Trouble running puppet from cron

[Martin Englund]

Folks,

I've got a problem when I run puppetd (--no-daemonize --ontime)
through cron:
it fails to find the providers; "could not find a default provider for
cron"

At first I thought it was bug# 1631 so I added an explicit PATH to the
script that cron runs, but it still fails with the above error.

Looking at the debug output from puppetd I see that it says:
debug: file crontab does not exist
which isn't true - as it is in /usr/bin (which is in the PATH).

Clues and hints to what is wrong are most welcome :)

cheers,
/Martin
--
Martin Englund, Security Engineer, .Sun Engineering, Sun Microsystems
Inc.
Email: martin....@sun.com Time Zone: GMT+1 PGP: 1024D/AA514677
"The question is not if you are paranoid, it is if you are paranoid
enough."

[James Turnbull]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Martin Englund wrote:
> Folks,
>
> I've got a problem when I run puppetd (--no-daemonize --ontime)
> through cron:
> it fails to find the providers; "could not find a default provider for
> cron"
>
> At first I thought it was bug# 1631 so I added an explicit PATH to the
> script that cron runs, but it still fails with the above error.
>
> Looking at the debug output from puppetd I see that it says:
> debug: file crontab does not exist
> which isn't true - as it is in /usr/bin (which is in the PATH).
>
> Clues and hints to what is wrong are most welcome :)

Version? Platform? Logs?

Regards

James Turnbull

- --
Author of:
* Pulling Strings with Puppet
(http://www.amazon.com/gp/product/1590599780/)
* Pro Nagios 2.0
(http://www.amazon.com/gp/product/1590596099/)
* Hardening Linux
(http://www.amazon.com/gp/product/1590594444/)

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.7 (Darwin)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org

iD8DBQFJGCFZ9hTGvAxC30ARAnhfAJ4gmMQqaP0b0M49UkleRjqFwxErhACg0O3o
flWyR3VONUnrgdIDQ7/BbVQ=
=vB7D
-----END PGP SIGNATURE-----

[martin]

Solaris 10 update 5 on x86

Ruby 1.8.7 p72, Facter 1.5.2 & Puppet 0.24.6

Here's the script that is run through cron:
#!/bin/sh
#

PATH=/usr/bin:/usr/sbin:/sbin:/usr/sfw/bin:/opt/sfw/bin:/usr/ops/bin
export PATH

CONF=/etc/puppet/puppet.conf

PUPPETD=/usr/ops/bin/puppetd

LAST=/var/puppet/log/last
LOG=/var/puppet/log/cron.`date '+%Y%m%d%H%M'`

if [ ! -f $CONF ]; then
echo "Error: $CONF is missing"
exit 1
fi

if [ ! -f $PUPPETD ]; then
echo "Error: $PUPPETD is missing"
exit 1
fi

$PUPPETD --onetime --verbose --no-daemonize --trace --debug > $LOG

rm -f $LAST
ln -s $LOG $LAST

And here is the script output:
info: Loading fact zonename
info: Loading fact zpool
info: Loading fact location
debug: Creating default schedules
debug: Failed to load library 'ldap' for feature 'ldap'
debug: Failed to load library 'shadow' for feature 'libshadow'
debug: /Settings[/etc/puppet/puppet.conf]/Settings[main]/File[/var/
puppet/log]: Autorequiring File[/var/puppet]
debug: /Settings[/etc/puppet/puppet.conf]/Settings[main]/File[/var/
puppet/run]: Autorequiring File[/var/puppet]
debug: /Settings[/etc/puppet/puppet.conf]/Settings[ssl]/File[/etc/
puppet/ssl/certs/xxx.sun.com.pem]: Autorequiring File[/etc/puppet/ssl/
certs]
debug: /Settings[/etc/puppet/puppet.conf]/Settings[ssl]/File[/etc/
puppet/ssl/certs]: Autorequiring File[/etc/puppet/ssl]
debug: /Settings[/etc/puppet/puppet.conf]/Settings[main]/File[/etc/
puppet/ssl]: Autorequiring File[/etc/puppet]
debug: /Settings[/etc/puppet/puppet.conf]/Settings[ssl]/File[/etc/
puppet/ssl/csr_dns-prod1.java.sun.com.pem]: Autorequiring File[/etc/
puppet/ssl]
debug: /Settings[/etc/puppet/puppet.conf]/Settings[ssl]/File[/etc/
puppet/ssl/private_keys/xxx.sun.com.pem]: Autorequiring File[/etc/
puppet/ssl/private_keys]
debug: /Settings[/etc/puppet/puppet.conf]/Settings[puppetd]/File[/var/
puppet/state/state.yaml]: Autorequiring File[/var/puppet/state]
debug: /Settings[/etc/puppet/puppet.conf]/Settings[ssl]/File[/etc/
puppet/ssl/certs/ca.pem]: Autorequiring File[/etc/puppet/ssl/certs]
debug: /Settings[/etc/puppet/puppet.conf]/Settings[main]/File[/var/
puppet/facts]: Autorequiring File[/var/puppet]
debug: /Settings[/etc/puppet/puppet.conf]/Settings[main]/File[/var/
puppet/lib]: Autorequiring File[/var/puppet]
debug: /Settings[/etc/puppet/puppet.conf]/Settings[ssl]/File[/etc/
puppet/ssl/private]: Autorequiring File[/etc/puppet/ssl]
debug: /Settings[/etc/puppet/puppet.conf]/Settings[ssl]/File[/etc/
puppet/ssl/public_keys]: Autorequiring File[/etc/puppet/ssl]
debug: /Settings[/etc/puppet/puppet.conf]/Settings[puppetd]/File[/var/
puppet/state/classes.txt]: Autorequiring File[/var/puppet/state]
debug: /Settings[/etc/puppet/puppet.conf]/Settings[puppetd]/File[/etc/
puppet/puppet.conf]: Autorequiring File[/etc/puppet]
debug: /Settings[/etc/puppet/puppet.conf]/Settings[main]/File[/var/
puppet/state]: Autorequiring File[/var/puppet]
debug: /Settings[/etc/puppet/puppet.conf]/Settings[ssl]/File[/etc/
puppet/ssl/private_keys]: Autorequiring File[/etc/puppet/ssl]
debug: /Settings[/etc/puppet/puppet.conf]/Settings[ssl]/File[/etc/
puppet/ssl/public_keys/xxx.sun.com.pem]: Autorequiring File[/etc/
puppet/ssl/public_keys]
debug: Finishing transaction 69300300 with 0 changes
debug: Loaded state in 0.00 seconds
debug: Puppet::Network::Client::File: defining fileserver.describe
debug: Puppet::Network::Client::File: defining fileserver.list
debug: Puppet::Network::Client::File: defining fileserver.retrieve
info: Retrieving facts
debug: Calling fileserver.list
debug: Calling fileserver.describe
debug: Calling fileserver.list
debug: Calling fileserver.describe
debug: Calling fileserver.list
debug: Calling fileserver.describe
debug: Calling fileserver.list
debug: Calling fileserver.describe
debug: Finishing transaction 70297360 with 0 changes
info: Loading fact zonename
info: Loading fact zpool
info: Loading fact location
debug: Retrieved facts in 1.76 seconds
debug: Retrieving catalog
debug: Calling puppetmaster.getconfig
debug: Retrieved catalog in 1.71 seconds
debug: false value when expecting true
debug: file /usr/bin/dscl does not exist
debug: file /usr/sbin/pw does not exist
debug: file nireport does not exist
debug: file groupmod does not exist
err: Could not create ipfilter: Could not find a default provider for
group
/usr/ops/lib/ruby/site_ruby/1.8/puppet/type.rb:1737:in
`defaultprovider'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/type.rb:1880:in `default'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/type.rb:651:in `setdefaults'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/type.rb:140:in `eachattr'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/type.rb:135:in `each'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/type.rb:135:in `eachattr'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/type.rb:641:in `setdefaults'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/type.rb:2342:in `initialize'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/type.rb:1131:in `new'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/type.rb:1131:in `create'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:90:in
`to_type'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:197:in
`to_catalog'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:125:in `each'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:125:in `each'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:194:in
`to_catalog'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:203:in `call'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:203:in
`to_catalog'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:125:in `each'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:125:in `each'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:194:in
`to_catalog'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:203:in `call'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:203:in
`to_catalog'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:125:in `each'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:125:in `each'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:194:in
`to_catalog'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:203:in `call'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:203:in
`to_catalog'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:125:in `each'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:125:in `each'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:194:in
`to_catalog'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:209:in `call'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:209:in
`to_catalog'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/network/client/master.rb:172:in
`getconfig'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/network/client/master.rb:245:in
`run'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/util.rb:445:in `thinmark'
/usr/ops/lib/ruby/1.8/benchmark.rb:308:in `realtime'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/util.rb:444:in `thinmark'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/network/client/master.rb:244:in
`run'
/usr/ops/lib/ruby/1.8/sync.rb:229:in `synchronize'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/network/client/master.rb:237:in
`run'
/usr/ops/bin/puppetd:417

debug: file crontab does not exist

err: Could not create puppet: Could not find a default provider for
cron
/usr/ops/lib/ruby/site_ruby/1.8/puppet/type.rb:1737:in
`defaultprovider'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/type.rb:1880:in `default'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/type.rb:651:in `setdefaults'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/type.rb:140:in `eachattr'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/type.rb:135:in `each'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/type.rb:135:in `eachattr'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/type.rb:641:in `setdefaults'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/type.rb:2342:in `initialize'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/type.rb:1131:in `new'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/type.rb:1131:in `create'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:90:in
`to_type'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:197:in
`to_catalog'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:125:in `each'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:125:in `each'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:194:in
`to_catalog'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:203:in `call'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:203:in
`to_catalog'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:125:in `each'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:125:in `each'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:194:in
`to_catalog'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:203:in `call'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:203:in
`to_catalog'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:125:in `each'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:125:in `each'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:194:in
`to_catalog'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:209:in `call'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/transportable.rb:209:in
`to_catalog'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/network/client/master.rb:513:in
`use_cached_config'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/network/client/master.rb:177:in
`getconfig'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/network/client/master.rb:245:in
`run'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/util.rb:445:in `thinmark'
/usr/ops/lib/ruby/1.8/benchmark.rb:308:in `realtime'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/util.rb:444:in `thinmark'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/network/client/master.rb:244:in
`run'
/usr/ops/lib/ruby/1.8/sync.rb:229:in `synchronize'
/usr/ops/lib/ruby/site_ruby/1.8/puppet/network/client/master.rb:237:in
`run'
/usr/ops/bin/puppetd:417
warning: Could not load cached catalog: Could not find a default
provider for cron
warning: Configuration could not be instantiated: Could not find a
default provider for group

cheers,
/Martin

[martin]

One thing I forgot to mention: if I run the script by hand (as root)
it works as expected.

cheers,
/Martin

[martin]

After debugging this some more, I noticed that I get the same error
when I run it as a daemon (puppetd). Where and how does puppetd pick
up the PATH it is using?

cheers,
/Martin

[Luke Kanies]

On Nov 11, 2008, at 7:21 AM, martin wrote:

> After debugging this some more, I noticed that I get the same error
> when I run it as a daemon (puppetd). Where and how does puppetd pick
> up the PATH it is using?

It just uses the path from the environment.

Should we look at having a default path? If so, how should it change
per-platform, if at all?

I've always figured people had their own customized paths, given how
much it changes at different environments.

--
The great aim of education is not knowledge but action.
-- Herbert Spencer
---------------------------------------------------------------------
Luke Kanies | http://reductivelabs.com | http://madstop.com

[martin]

On Nov 13, 1:31 am, Luke Kanies <l...@madstop.com> wrote:

> It just uses the path from the environment.
>

But that doesn't explain that the below script fails to find
crontab :)
---8<---

#!/bin/sh
#

PATH=/usr/bin:/usr/sbin:/sbin:/usr/sfw/bin:/opt/sfw/bin:/usr/ops/bin
export PATH

CONF=/etc/puppet/puppet.conf

PUPPETD=/usr/ops/bin/puppetd

LAST=/var/puppet/log/last
LOG=/var/puppet/log/cron.`date '+%Y%m%d%H%M'`

if [ ! -f $CONF ]; then
echo "Error: $CONF is missing"
exit 1
fi

if [ ! -f $PUPPETD ]; then
echo "Error: $PUPPETD is missing"
exit 1
fi

$PUPPETD --onetime --verbose --no-daemonize --trace --debug > $LOG

rm -f $LAST
ln -s $LOG $LAST

---8<---

> Should we look at having a default path?  If so, how should it change  
> per-platform, if at all?
>

What about allowing the user to set the path in puppet.conf?

[puppetd]
path /usr/bin:/usr/sbin:/usr/foo:/usr/bar

cheers,
/Martin

[Andrew Shafer]

I don't see how puppet changes the env.

Try printing the ENV from puppetd on one of the systems that are failing.

ENV is a global hash, you should be able call each with a block to print to the logs.

If we verify that the runtime has the appropriate user and path, that will be confusing, but if it isn't that explains the behavior and gives a bit more focus to the problem.

[martin]

I'm one step closer now :)

It turns out that facter fiddles with the PATH - I've filed bug #1745.
It sets the PATH to
/bin:/sbin:/usr/bin:/usr/sbin:/usr/local/sbin:/usr/local/bin

But it still doesn't explain why I get the "Could not find default
provider for ...". I've found out that suitableprovider returns the
full list of providers, but this statement in type.rb
# Find which providers are a default for this system.
defaults = suitable.find_all { |provider|
provider.default? }
returns an empty list when run from cron.

cheers,
/Martin

[martin]

Minor correction:
it is suitableprovider() which returns an empty list, while it
successfully loads all providers, but provider.suitable? always
evaluates to false.

cheers,
/Martin

[Andrew Shafer]

The suitable logic is trying to find those underlying commands and failing.

If it can find the commands, suitable? will be true.

[Luke Kanies]

As Andrew says, the providers must be considered unsuitable because
they're missing executables.

You *can* set the path in puppet.conf; try that.

--
Ours is the age that is proud of machines that think and suspicious of
men who try to. -- H. Mumford Jones

[martin]

On Nov 13, 9:07 pm, Luke Kanies <l...@madstop.com> wrote:

> As Andrew says, the providers must be considered unsuitable because  
> they're missing executables.
>

But the executables are in the PATH, even in the incorrect one.

> You *can* set the path in puppet.conf; try that.
>

I fixed the virtual fact, and got the correct PATH.

But it still fails when run through cron (even though the PATH contain
all commands the providers are looking for).

Another thing which could be wrong are the facts. What is the best way
to dump them from within puppet?

cheers,
/Martin

[Andrew Shafer]

Hmm, what does the ENV say the user is?  Does that user have appropriate permissions on the files in the PATH?

The errors mean for some reason the Ruby runtime environment can't access those executables.  Not sure why...

[martin]

On Nov 13, 9:38 pm, "Andrew Shafer" <and...@reductivelabs.com> wrote:
> Hmm, what does the ENV say the user is?  Does that user have appropriate
> permissions on the files in the PATH?
>

Here's the ENV dumped from within puppetd running from cron:
warning: LANG = C
warning: HOME = /root
warning: LOGNAME = root
warning: PATH = /usr/bin:/usr/sbin:/sbin:/usr/ops/bin
warning: SHELL = /usr/bin/sh
warning: TZ = US/Pacific

and here is when I run it at the commend line:
warning: DEBIAN_FRONTEND = noninteractive
warning: EDITOR = vi
warning: HOME = /root
warning: HZ =
warning: LANG = C
warning: LC_MESSAGES = en_US.UTF-8
warning: LOGNAME = root
warning: MAIL = /var/mail/root
warning: OLDPWD = /root
warning: PAGER = /usr/bin/cat
warning: PATH = /usr/bin:/usr/sbin:/sbin:/usr/ops/bin
warning: PS1 = \u@\h \$
warning: PWD = /usr/ops/lib/ruby/site_ruby/1.8/puppet
warning: SHELL = /bin/bash
warning: SHLVL = 1
warning: TERM = xterm
warning: TZ = US/Pacific
warning: _ = /usr/ops/bin/puppet.sh

So it is root in both cases (as expected).

> The errors mean for some reason the Ruby runtime environment can't access
> those executables.  Not sure why...
>

Can't it be the confines which evaluates to false?

cheers,
/Martin

[martin]

One more tidbit of information:
debug: PATH = /usr/bin:/usr/sbin:/sbin:/usr/ops/bin
debug: suitableproviders = ldap, directoryservice, pw, netinfo,
groupadd

debug: false value when expecting true
debug: file /usr/bin/dscl does not exist
debug: file /usr/sbin/pw does not exist
debug: file nireport does not exist
debug: file groupmod does not exist

err: Could not create ipfilter: Could not find a default provider for
group

And groupmod is in /usr/sbin with mode 755

cheers,
/Martin - baffled and ready for bed