Bug #2863

Error 400 on SERVER: undefined method `each' for nil:NilClass

Added by micah - about 2 years ago. Updated about 2 years ago.

Status:Closed Start date:11/25/2009
Priority:High Due date:
Assignee:Markus Roberts % Done:

0%
Category:-
Target version:0.25.2
Affected Puppet version:0.25.1 Branch:http://github.com/MarkusQ/puppet/tree/ticket/0.25.x/2863
Keywords:
Votes: 2

Description

Upgraded from 0.24.8 to 0.25.1 and some nodes (I have not been able to determine why some nodes, but not others) spit out this error and do not continue:

Nov 25 14:41:39 fulmar puppetd[10243]: Could not retrieve catalog from remote server: Error 400 on SERVER: undefined method `each' for nil:NilClass
Nov 25 14:41:42 fulmar puppetd[10243]: Could not retrieve catalog; skipping run
Nov 25 14:41:42 fulmar puppetd[10243]: Using cached catalog

If I kill the node in the storedconfigs, then things work.

This is the debug output from the client run:

root@fulmar:~# puppetd --masterport 8889 --debug --test
debug: Puppet::Type::User::ProviderUser_role_add: file roleadd does not exist
debug: Puppet::Type::User::ProviderPw: file pw does not exist
debug: Puppet::Type::User::ProviderDirectoryservice: file /usr/bin/dscl does not exist
debug: Puppet::Type::User::ProviderLdap: true value when expecting false
debug: Failed to load library 'ldap' for feature 'ldap'
debug: /File[/var/lib/puppet/ssl/certs/fulmar.riseup.net.pem]: Autorequiring File[/var/lib/puppet/ssl/certs]
debug: /File[/var/lib/puppet/ssl/csr_fulmar.riseup.net.pem]: Autorequiring File[/var/lib/puppet/ssl]
debug: /File[/etc/puppet/puppet.conf]: Autorequiring File[/etc/puppet]
debug: /File[/var/lib/puppet/ssl/private_keys/fulmar.riseup.net.pem]: Autorequiring File[/var/lib/puppet/ssl/private_keys]
debug: /File[/var/lib/puppet/ssl/certs]: Autorequiring File[/var/lib/puppet/ssl]
debug: /File[/var/lib/puppet/ssl/public_keys/fulmar.riseup.net.pem]: Autorequiring File[/var/lib/puppet/ssl/public_keys]
debug: /File[/var/lib/puppet/state/state.yaml]: Autorequiring File[/var/lib/puppet/state]
debug: /File[/var/lib/puppet/ssl/private]: Autorequiring File[/var/lib/puppet/ssl]
debug: /File[/var/lib/puppet/client_yaml]: Autorequiring File[/var/lib/puppet]
debug: /File[/var/lib/puppet/lib]: Autorequiring File[/var/lib/puppet]
debug: /File[/var/lib/puppet/ssl/certs/ca.pem]: Autorequiring File[/var/lib/puppet/ssl/certs]
debug: /File[/var/lib/puppet/facts]: Autorequiring File[/var/lib/puppet]
debug: /File[/var/lib/puppet/ssl]: Autorequiring File[/var/lib/puppet]
debug: /File[/var/lib/puppet/ssl/public_keys]: Autorequiring File[/var/lib/puppet/ssl]
debug: /File[/var/lib/puppet/ssl/certificate_requests]: Autorequiring File[/var/lib/puppet/ssl]
debug: /File[/var/lib/puppet/clientbucket]: Autorequiring File[/var/lib/puppet]
debug: /File[/var/lib/puppet/state]: Autorequiring File[/var/lib/puppet]
debug: /File[/var/lib/puppet/ssl/crl.pem]: Autorequiring File[/var/lib/puppet/ssl]
debug: /File[/var/lib/puppet/state/classes.txt]: Autorequiring File[/var/lib/puppet/state]
debug: /File[/var/lib/puppet/ssl/private_keys]: Autorequiring File[/var/lib/puppet/ssl]
debug: /File[/var/lib/puppet/state/graphs]: Autorequiring File[/var/lib/puppet/state]
debug: Finishing transaction -611703578 with 0 changes
debug: Using cached certificate for ca
debug: Using cached certificate for fulmar.riseup.net
debug: Loaded state in 0.42 seconds
info: Retrieving plugin
debug: Using cached certificate for ca
debug: Using cached certificate for fulmar.riseup.net
debug: Using cached certificate_revocation_list for ca
debug: Format pson not supported for Puppet::FileServing::Metadata; has not implemented method 'from_pson'
debug: Format s not supported for Puppet::FileServing::Metadata; has not implemented method 'from_s'
debug: Finishing transaction -612831068 with 0 changes
info: Loading facts in mysql
info: Loading facts in acpi_available
info: Loading facts in private_ip
info: Loading facts in public_ip
info: Loading facts in munin_interfaces
info: Loading facts in in_colo
info: Loading facts in mysql
info: Loading facts in acpi_available
info: Loading facts in private_ip
info: Loading facts in public_ip
info: Loading facts in munin_interfaces
info: Loading facts in in_colo
debug: Format s not supported for Puppet::Resource::Catalog; has not implemented method 'from_s'
err: Could not retrieve catalog from remote server: Error 400 on SERVER: undefined method `each' for nil:NilClass
warning: Not using cache on failed catalog
err: Could not retrieve catalog; skipping run

and this is the output from the puppetmaster debug output:

root@puppetmaster:/# puppetmasterd --masterport 8889 --debug --no-daemonize
debug: Puppet::Type::User::ProviderPw: file pw does not exist
debug: Puppet::Type::User::ProviderUser_role_add: file rolemod does not exist
debug: Puppet::Type::User::ProviderLdap: true value when expecting false
debug: Puppet::Type::User::ProviderDirectoryservice: file /usr/bin/dscl does not exist
debug: /File[/var/lib/puppet/ssl/certs/ca.pem]: Autorequiring File[/var/lib/puppet/ssl/certs]
debug: /File[/etc/puppet/manifests/site.pp]: Autorequiring File[/etc/puppet/manifests]
debug: /File[/var/lib/puppet/ssl/csr_puppetmaster.riseup.net.pem]: Autorequiring File[/var/lib/puppet/ssl]
debug: /File[/var/lib/puppet/ssl/public_keys/puppetmaster.riseup.net.pem]: Autorequiring File[/var/lib/puppet/ssl/public_keys]
debug: /File[/var/lib/puppet/ssl/certs]: Autorequiring File[/var/lib/puppet/ssl]
debug: /File[/etc/puppet/fileserver.conf]: Autorequiring File[/etc/puppet]
debug: /File[/var/lib/puppet/ssl/certificate_requests]: Autorequiring File[/var/lib/puppet/ssl]
debug: /File[/etc/puppet/auth.conf]: Autorequiring File[/etc/puppet]
debug: /File[/var/lib/puppet/ssl/private_keys]: Autorequiring File[/var/lib/puppet/ssl]
debug: /File[/etc/puppet/manifests]: Autorequiring File[/etc/puppet]
debug: /File[/var/lib/puppet/ssl/private]: Autorequiring File[/var/lib/puppet/ssl]
debug: /File[/var/lib/puppet/state]: Autorequiring File[/var/lib/puppet]
debug: /File[/var/lib/puppet/facts]: Autorequiring File[/var/lib/puppet]
debug: /File[/var/lib/puppet/reports]: Autorequiring File[/var/lib/puppet]
debug: /File[/var/lib/puppet/ssl/public_keys]: Autorequiring File[/var/lib/puppet/ssl]
debug: /File[/etc/puppet/puppet.conf]: Autorequiring File[/etc/puppet]
debug: /File[/var/log/puppet/masterhttp.log]: Autorequiring File[/var/log/puppet]
debug: /File[/var/lib/puppet/ssl/private_keys/puppetmaster.riseup.net.pem]: Autorequiring File[/var/lib/puppet/ssl/private_keys]
debug: /File[/var/lib/puppet/yaml]: Autorequiring File[/var/lib/puppet]
debug: /File[/var/lib/puppet/ssl]: Autorequiring File[/var/lib/puppet]
debug: /File[/var/lib/puppet/ssl/crl.pem]: Autorequiring File[/var/lib/puppet/ssl]
debug: /File[/var/lib/puppet/ssl/certs/puppetmaster.riseup.net.pem]: Autorequiring File[/var/lib/puppet/ssl/certs]
debug: /File[/var/lib/puppet/bucket]: Autorequiring File[/var/lib/puppet]
debug: /File[/var/lib/puppet/lib]: Autorequiring File[/var/lib/puppet]
debug: /File[/var/lib/puppet/rrd]: Autorequiring File[/var/lib/puppet]
debug: Finishing transaction -609929788 with 0 changes
debug: /File[/var/lib/puppet/ssl/ca/requests]: Autorequiring File[/var/lib/puppet/ssl/ca]
debug: /File[/var/lib/puppet/ssl/ca/inventory.txt]: Autorequiring File[/var/lib/puppet/ssl/ca]
debug: /File[/var/lib/puppet/ssl/ca/ca_crl.pem]: Autorequiring File[/var/lib/puppet/ssl/ca]
debug: /File[/var/lib/puppet/ssl/ca/signed]: Autorequiring File[/var/lib/puppet/ssl/ca]
debug: /File[/var/lib/puppet/ssl/ca/serial]: Autorequiring File[/var/lib/puppet/ssl/ca]
debug: /File[/var/lib/puppet/ssl/ca/ca_key.pem]: Autorequiring File[/var/lib/puppet/ssl/ca]
debug: /File[/var/lib/puppet/ssl/ca/private/ca.pass]: Autorequiring File[/var/lib/puppet/ssl/ca/private]
debug: /File[/var/lib/puppet/ssl/ca/private]: Autorequiring File[/var/lib/puppet/ssl/ca]
debug: /File[/var/lib/puppet/ssl/ca/ca_crt.pem]: Autorequiring File[/var/lib/puppet/ssl/ca]
debug: /File[/var/lib/puppet/ssl/ca/ca_pub.pem]: Autorequiring File[/var/lib/puppet/ssl/ca]
debug: Finishing transaction -612595318 with 0 changes
debug: Using cached certificate for ca
debug: Using cached certificate for ca
debug: Using cached certificate for puppetmaster.riseup.net
notice: Starting Puppet server version 0.25.1
info: mount[files]: allowing 10.0.1.0/16 access
info: mount[files]: allowing 127.0.0.1 access
debug: No modules mount given; autocreating with default permissions
debug: No plugins mount given; autocreating with default permissions
debug: Creating interpreter
debug: Finishing transaction -612771598 with 0 changes
debug: Finishing transaction -612773518 with 0 changes
info: access[^/catalog/([^/]+)$]: allowing 'method' find
info: access[^/catalog/([^/]+)$]: allowing $1 access
info: access[/certificate_revocation_list/ca]: allowing 'method' find
info: access[/certificate_revocation_list/ca]: allowing * access
info: access[/report]: allowing 'method' save
info: access[/report]: allowing * access
info: access[/file]: allowing * access
info: access[/certificate/ca]: adding authentication no
info: access[/certificate/ca]: allowing 'method' find
info: access[/certificate/ca]: allowing * access
info: access[/certificate/]: adding authentication no
info: access[/certificate/]: allowing 'method' find
info: access[/certificate/]: allowing * access
info: access[/certificate_request]: adding authentication no
info: access[/certificate_request]: allowing 'method' find
info: access[/certificate_request]: allowing 'method' save
info: access[/certificate_request]: allowing * access
info: access[/]: adding authentication any
info: mount[files]: allowing 10.0.1.0/16 access
info: mount[files]: allowing 127.0.0.1 access
debug: Finishing transaction -613794488 with 0 changes
notice: Migrating
info: Expiring the node cache of fulmar.riseup.net
notice: Migrating
info: Not using expired node for fulmar.riseup.net from cache; expired at Wed Nov 25 16:01:42 -0800 2009
debug: Using cached facts for fulmar.riseup.net
info: Caching node for fulmar.riseup.net
notice: Migrating
debug: importing '/etc/puppet/manifests/common.pp'
debug: importing '/etc/puppet/manifests/modules.pp'
debug: importing '/etc/puppet/modules/common/manifests/init.pp'
debug: importing '/etc/puppet/modules/common/manifests/defines/concatenated_file.pp'
debug: Adding code to main on line 118 in file /etc/puppet/modules/common/manifests/defines/concatenated_file.pp
debug: importing '/etc/puppet/modules/common/manifests/defines/config_file.pp'
debug: importing '/etc/puppet/modules/common/manifests/defines/append_if_no_such_line.pp'
debug: importing '/etc/puppet/modules/common/manifests/defines/line.pp'
debug: importing '/etc/puppet/modules/common/manifests/defines/module_file.pp'
debug: importing '/etc/puppet/modules/common/manifests/defines/replace.pp'
debug: importing '/etc/puppet/modules/common/manifests/defines/module_dir.pp'
debug: Adding code to main on line 43 in file /etc/puppet/modules/common/manifests/defines/module_dir.pp
debug: importing '/etc/puppet/modules/common/manifests/classes/lsb_release.pp'
debug: Adding code to main on line 26 in file /etc/puppet/modules/common/manifests/init.pp

debug: Backupninja::Rdiff[rdiff_fulmar]: Adding default for ssh_dirdebug: Backupninja::Rdiff[rdiff_fulmar]: Adding default for type
debug: Backupninja::Rdiff[rdiff_fulmar]: Adding default for ssh_dir_manage
debug: No true answers and no default
debug: No true answers and no default
debug: Scope(Backupninja::Rdiff[rdiff_fulmar]): Retrieving template backupninja/rdiff.conf.erb
debug: template[/etc/puppet/modules/backupninja/templates/rdiff.conf.erb]: Bound template variables for /etc/puppet/modules/backupninja/templates/rdiff.conf.erb in 0.00 seconds
debug: template[/etc/puppet/modules/backupninja/templates/rdiff.conf.erb]: Interpolated template /etc/puppet/modules/backupninja/templates/rdiff.conf.erb in 0.01 seconds
debug: No true answers and no default
debug: No true answers and no default
debug: No true answers and no default
debug: No true answers and no default
debug: No true answers and no default
debug: Scope(Backupninja::Maildir[maildir_fulmar]): Retrieving template backupninja/maildir.conf.erb
debug: template[/etc/puppet/modules/backupninja/templates/maildir.conf.erb]: Bound template variables for /etc/puppet/modules/backupninja/templates/maildir.conf.erb in 0.00 seconds
debug: template[/etc/puppet/modules/backupninja/templates/maildir.conf.erb]: Interpolated template /etc/puppet/modules/backupninja/templates/maildir.conf.erb in 0.00 seconds
debug: Scope(Nagios2::Service[low_load]): Retrieving template nagios/service.erb
debug: template[/etc/puppet/modules/nagios/templates/service.erb]: Bound template variables for /etc/puppet/modules/nagios/templates/service.erb in 0.00 seconds
debug: template[/etc/puppet/modules/nagios/templates/service.erb]: Interpolated template /etc/puppet/modules/nagios/templates/service.erb in 0.00 seconds
debug: Scope(Nagios2::Service[ekey-egd-linux]): Retrieving template nagios/service.erb
debug: template[/etc/puppet/modules/nagios/templates/service.erb]: Bound template variables for /etc/puppet/modules/nagios/templates/service.erb in 0.00 seconds
debug: template[/etc/puppet/modules/nagios/templates/service.erb]: Interpolated template /etc/puppet/modules/nagios/templates/service.erb in 0.00 seconds
debug: Scope(Class[sshd::client::base]): Collected 0 Sshkey resources in 0.04 seconds
debug: No true answers and no default
debug: Scope(Class[sshd::client::base]): Collected 0 Sshkey resources in 0.04 seconds
debug: Scope(Class[sshd::client::base]): Collected 0 Sshkey resources in 0.04 seconds
debug: File[/var/local]: Adding default for ignore
debug: File[/var/local/puppet]: Adding default for ignore
debug: File[/var/local/puppet/munin-nodes]: Adding default for ignore
debug: File[/usr/local/share/munin-plugins]: Adding default for ignore
debug: File[/var/local/puppet/splice]: Adding default for ignore
debug: Exec[true # assert_lsbdistcodename]: Adding default for path
debug: Exec[true # require_lsbdistcodename]: Adding default for path
debug: File[/etc/apt/apt.conf.d]: Adding default for ignore
debug: Exec[/usr/bin/apt-get update && sleep 1 #on refresh]: Adding default for path
debug: Exec[/usr/bin/apt-get update && /usr/bin/apt-get autoclean #hourly]: Adding default for path
debug: File[/var/lib/puppet/modules/apt/backports.org.key]: Adding default for ignore
debug: Exec[/usr/bin/apt-key add /var/lib/puppet/modules/apt/backports.org.key && apt-get update]: Adding default for path
debug: File[/var/lib/puppet/modules/apt/keys.d]: Adding default for ignore
debug: Exec[find /var/lib/puppet/modules/apt/keys.d -type f -exec apt-key add '{}' \; && apt-get update]: Adding default for path
debug: File[/var/cache]: Adding default for ignore
debug: File[/var/cache/local]: Adding default for ignore
debug: File[/var/cache/local/preseeding]: Adding default for ignore
debug: File[/etc/logcheck]: Adding default for ignore
debug: File[/var/lock/logcheck]: Adding default for ignore
debug: File[/etc/logcheck/logcheck.conf]: Adding default for ignore
debug: File[/etc/logcheck/logcheck.logfiles]: Adding default for ignore
debug: File[/etc/cron.d/logcheck]: Adding default for ignore
debug: File[/etc/puppet/puppetd.conf]: Adding default for ignore
debug: File[/etc/puppet/puppet.conf]: Adding default for ignore
debug: File[/etc/profile]: Adding default for ignore
debug: File[/etc/bash.bashrc]: Adding default for ignore
debug: File[/etc/localtime]: Adding default for ignore
debug: File[/etc/timezone]: Adding default for ignore
debug: File[/etc/default/locale]: Adding default for ignore
debug: File[/etc/passwd]: Adding default for ignore
debug: File[/etc/shadow]: Adding default for ignore
debug: File[/usr/local/bin]: Adding default for ignore
debug: File[/etc/cron.hourly/puppet]: Adding default for ignore
debug: File[/usr/local/share/munin-plugins/process_states]: Adding default for ignore
debug: File[/etc/tmpreaper.conf]: Adding default for ignore
debug: File[/etc/syslog-ng/syslog-ng.conf]: Adding default for ignore
debug: File[/etc/logrotate.d/syslog-ng]: Adding default for ignore
debug: File[/dev/shm/fulmar.gpg]: Adding default for ignore
debug: File[/var/log/lastlog]: Adding default for ignore
debug: File[/var/log/utmp]: Adding default for ignore
debug: File[/var/log/wtmp]: Adding default for ignore
debug: Exec[/etc/init.d/syslog-ng reload]: Adding default for path
debug: File[/etc/apticron/apticron.conf]: Adding default for ignore
debug: File[/etc/apt/listchanges.conf]: Adding default for ignore
debug: File[/etc/default/nagios-statd-server]: Adding default for ignore
debug: File[sudoers]: Adding default for ignore
debug: File[/etc/bind]: Adding default for ignore
debug: File[/etc/bind/rndc.key]: Adding default for ignore
debug: File[/etc/bind/primary]: Adding default for ignore
debug: File[/etc/bind/secondary]: Adding default for ignore
debug: File[/usr/local/sbin/roothints_update.sh]: Adding default for ignore
debug: File[/var/log/bind9]: Adding default for ignore
debug: File[/usr/local/share/munin-plugins/bind9]: Adding default for ignore
debug: File[/usr/local/share/munin-plugins/bind9_rndc]: Adding default for ignore
debug: Exec[reload-bind9]: Adding default for path
debug: Exec[restart-bind9]: Adding default for path
debug: File[/etc/bind/named.conf.options]: Adding default for ignore
debug: File[/etc/default/bind9]: Adding default for ignore
debug: File[/var/lib/puppet/modules/_var_lib_puppet_modules_shorewall_zones.d]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/zones]: Adding default for ignore
debug: Exec[concat_/var/lib/puppet/modules/shorewall/zones]: Adding default for path
debug: File[/var/lib/puppet/modules/_var_lib_puppet_modules_shorewall_interfaces.d]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/interfaces]: Adding default for ignore
debug: Exec[concat_/var/lib/puppet/modules/shorewall/interfaces]: Adding default for path
debug: File[/var/lib/puppet/modules/_var_lib_puppet_modules_shorewall_hosts.d]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/hosts]: Adding default for ignore
debug: Exec[concat_/var/lib/puppet/modules/shorewall/hosts]: Adding default for path
debug: File[/var/lib/puppet/modules/_var_lib_puppet_modules_shorewall_policy.d]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/policy]: Adding default for ignore
debug: Exec[concat_/var/lib/puppet/modules/shorewall/policy]: Adding default for path
debug: File[/var/lib/puppet/modules/_var_lib_puppet_modules_shorewall_rules.d]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/rules]: Adding default for ignore
debug: Exec[concat_/var/lib/puppet/modules/shorewall/rules]: Adding default for path
debug: File[/var/lib/puppet/modules/_var_lib_puppet_modules_shorewall_masq.d]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/masq]: Adding default for ignore
debug: Exec[concat_/var/lib/puppet/modules/shorewall/masq]: Adding default for path
debug: File[/var/lib/puppet/modules/_var_lib_puppet_modules_shorewall_proxyarp.d]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/proxyarp]: Adding default for ignore
debug: Exec[concat_/var/lib/puppet/modules/shorewall/proxyarp]: Adding default for path
debug: File[/var/lib/puppet/modules/_var_lib_puppet_modules_shorewall_nat.d]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/nat]: Adding default for ignore
debug: Exec[concat_/var/lib/puppet/modules/shorewall/nat]: Adding default for path
debug: File[/var/lib/puppet/modules/_var_lib_puppet_modules_shorewall_blacklist.d]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/blacklist]: Adding default for ignore
debug: Exec[concat_/var/lib/puppet/modules/shorewall/blacklist]: Adding default for path
debug: File[/var/lib/puppet/modules/_var_lib_puppet_modules_shorewall_rfc1918.d]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/rfc1918]: Adding default for ignore
debug: Exec[concat_/var/lib/puppet/modules/shorewall/rfc1918]: Adding default for path
debug: File[/var/lib/puppet/modules/_var_lib_puppet_modules_shorewall_routestopped.d]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/routestopped]: Adding default for ignore
debug: Exec[concat_/var/lib/puppet/modules/shorewall/routestopped]: Adding default for path
debug: File[/var/lib/puppet/modules/_var_lib_puppet_modules_shorewall_params.d]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/params]: Adding default for ignore
debug: Exec[concat_/var/lib/puppet/modules/shorewall/params]: Adding default for path
debug: File[/var/lib/puppet/modules/_var_lib_puppet_modules_shorewall_tcdevices.d]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/tcdevices]: Adding default for ignore
debug: Exec[concat_/var/lib/puppet/modules/shorewall/tcdevices]: Adding default for path
debug: File[/var/lib/puppet/modules/_var_lib_puppet_modules_shorewall_tcrules.d]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/tcrules]: Adding default for ignore
debug: Exec[concat_/var/lib/puppet/modules/shorewall/tcrules]: Adding default for path
debug: File[/var/lib/puppet/modules/_var_lib_puppet_modules_shorewall_tcclasses.d]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/tcclasses]: Adding default for ignore
debug: Exec[concat_/var/lib/puppet/modules/shorewall/tcclasses]: Adding default for path
debug: File[/var/lib/puppet/modules/shorewall/interfaces.d/100-eth0]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/interfaces.d/100-eth2]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/interfaces.d/100-tun0]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/routestopped.d/100-fulmar]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/start.d/000-header]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/start.d/999-footer]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/start.d/500-fulmar]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/zones.d/100-net]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/zones.d/200-vpn]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/zones.d/300-priv]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/policy.d/150-fw-to-net]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/policy.d/160-fw-to-vpn]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/policy.d/170-fw-to-priv]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/policy.d/171-priv-to-fw]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/policy.d/180-vpn-to-firewall]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/policy.d/200-net-to-all]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/policy.d/999-all-to-all]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/rules.d/10-NEW]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/rules.d/40020-net-fw-icmp]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/rules.d/40021-fw-net-icmp]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/rules.d/40022-vpn-fw-icmp]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/rules.d/40023-fw-vpn-icmp]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/rules.d/40080-fw-puppetmaster]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/rules.d/40081-nagios-me-ssh]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/rules.d/40082-nagios-me]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/rules.d/40083-munin-me]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/rules.d/40085-services-tcp-vpn-fw]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/rules.d/40086-services-tcp-priv-fw]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/rules.d/40087-obfuscatedssh-tcp-net-fw]: Adding default for ignore
debug: File[/backups/serverbackups/fulmar]: Adding default for ignore
debug: File[/etc/ssh/authorized_keys/backfulmar]: Adding default for ignore
debug: File[/root/.ssh]: Adding default for ignore
debug: File[/root/.ssh/id_rsa]: Adding default for ignore
debug: File[/var/lib/puppet/modules/_var_lib_puppet_modules_shorewall_start.d]: Adding default for ignore
debug: File[/var/lib/puppet/modules/shorewall/start]: Adding default for ignore
debug: Exec[concat_/var/lib/puppet/modules/shorewall/start]: Adding default for path
notice: Compiled catalog for fulmar.riseup.net in 39.94 seconds
info: Caching catalog for fulmar.riseup.net
debug: Searched for resources in 0.31 seconds
debug: Searched for resource params and tags in 1.79 seconds
debug: Resource removal in 0.37 seconds
err: undefined method `each' for nil:NilClass

Related issues

related to Puppet - Bug #2908: Rails resources are sometimes untagged Rejected 12/09/2009

History

#1
Updated by micah - about 2 years ago

On some nodes, even though I killed that node from storedconfigs, this error came back.

#2
Updated by micah - about 2 years ago

I did some debugging today to try and figure out where exactly in the code this is happening, and I’ve narrowed it down to the compare_to_catalog(existing, list) definition in lib/puppet/rails/host.pp, specifically this block:

       # Now for all resources in the catalog but not in the db, we're pretty easy.
        additions = nil        
        debug_benchmark("Resource merger") {
            additions = perform_resource_merger(compiled, resources)
        }

I put a debug line before this and it was printed, and after and it was not printed. The “Resource merger” string is not printed at all. If I put a debug_benchmark(“right before resource merger”) { } I see the string “right before resource merger” printed in my debug output. So obviously there is something going on in the perform_resource_merger call.

#3
Updated by micah - about 2 years ago

micah – wrote:

I did some debugging today to try and figure out where exactly in the code this is happening, and I’ve narrowed it down to the compare_to_catalog(existing, list) definition in lib/puppet/rails/host.pp, specifically this block:

thats host.rb, not host.pp ;)

I dug further and looked at the perform_resource_merger function and found that things got stuck up in:

if db_resource = resources[ref]
                db_resource.merge_parser_resource(resource)
            else
                additions << resource
            end
        end

specifically in the db_resource.merge_parser_resource function. it didn’t seem to hit the else clause and do the additions << resource. I tried to inspect the resource array contents, but that was a HUGE amount of data that wasn’t going to give me anything obvious.

So, I go and look at db_resource.merge_parser_resource…

   # Make sure this resource is equivalent to the provided Parser resource.
    def merge_parser_resource(resource)
        accumulate_benchmark("Individual resource merger", :attributes) { merge_attributes(resource) }
        accumulate_benchmark("Individual resource merger", :parameters) { merge_parameters(resource) }
        accumulate_benchmark("Individual resource merger", :tags) { merge_tags(resource) } 
        save()
    end

Putting in some debugging here narrowed it down to the merge_tags(resource) call, so we head over there:

    # Make sure the tag list is correct.
    def merge_tags(resource)
        in_db = []
        deletions = []
        resource_tags = resource.tags
        debug_benchmark("after the resource.tags"){}
        @tags_hash.each do |tag|
            deletions << tag['id'] and next unless resource_tags.include?(tag['name'])
            in_db << tag['name']
        end
        Puppet::Rails::ResourceTag.delete(deletions) unless deletions.empty?

        (resource_tags - in_db).each do |tag|
            add_resource_tag(tag)
        end
    end

It turns out that at some point for this (and the other nodes) @tags_hash is nil, and thus the “@tags_hash.each do |tag|” call spits out the error I am running into (undefined method ‘each’ for nil:NilClass).

#4
Updated by Markus Roberts about 2 years ago

  • Status changed from Unreviewed to Investigating
  • Assignee set to Markus Roberts

#5
Updated by Markus Roberts about 2 years ago

Looks like this came in with commit:6314745c054ba9482f145b4ec798431ac2f300a3; the code in get_tags_hash explicitly dealt with the possibility that @tags_hash would be nil but the code which replaces it does not.

#6
Updated by Luke Kanies about 2 years ago

Those cases where the tag hash is nil – can you tell if the resource has any tags?

It looks a lot like the tag_hash variable isn’t being initialized unless at least one tag is set, so if there are no tags for a resource then this method will always fail.

I can’t imagine a case where a resource wouldn’t have a tag, but it should pass regardless.

If you can modify that ‘@tags_hash.each’ line so that you print the tag count (

puts Puppet::Rails::ResourceTag.find_all_tags_from_resource(self).length
, I think), that should tell us.

If the tag list isn’t actually nil, then we have a different problem, but if it is, then ‘@tags_hash = []’ in the initialize method is an easy enough fix.

Now, why this isn’t a hash when the variable name implies it is is a whole different wtf.

#7
Updated by micah - about 2 years ago

Luke Kanies wrote:

Those cases where the tag hash is nil – can you tell if the resource has any tags? …

If you can modify that ‘@tags_hash.each’ line so that you print the tag count ([…], I think), that should tell us.

Ok, I added this right before the each call, and I see that it is stepping through a bunch of different resources, as I get 159 different counts of various numbers output, until the very last one, which is a zero.

I’m not sure why this is zero, or which it is…

#8
Updated by Luke Kanies about 2 years ago

  • Status changed from Investigating to Accepted
  • Priority changed from Normal to High

You can get the resource name by using this:

puts self.ref + " " + Puppet::Rails::ResourceTag.find_all_tags_from_resource(self).length

Either way, though, sounds like initialization of that variable is the key here, which should be an easy fix.

#9
Updated by Luke Kanies about 2 years ago

  • Target version set to 0.25.2

#10
Updated by micah - about 2 years ago

Luke Kanies wrote:

You can get the resource name by using this: […]

Actually, that doesn’t work, it says: err: can’t convert Fixnum into String

#11
Updated by Luke Kanies about 2 years ago

micah – wrote:

Luke Kanies wrote:

You can get the resource name by using this: […]

Actually, that doesn’t work, it says: err: can’t convert Fixnum into String

Sorry:

puts self.ref + " " + Puppet::Rails::ResourceTag.find_all_tags_from_resource(self).length.to_s

#12
Updated by Markus Roberts about 2 years ago

After playing around with another instance of this problem I believe it’s simply a simple case of failure to initialize @tags_hash (or account for the possibility that it might be uninitialized) partially obscured by a bad name.

I’ve got a patch in the works but I’m exploring something that may have been done a specific way to work with active record (other possibilities include “it’s just goofy” or “I’m just not seeing something obvious”).

#13
Updated by micah - about 2 years ago

Ok, this isn’t going to be super helpful, but by using the snippet that luk provided:

puts self.ref + " " +
  Puppet::Rails::ResourceTag.find_all_tags_from_resource(self).length.to_s

I was able to track down the specific piece in my manifest that was getting the zero tag. It was a simple exec call. I stared at it forever, and I could not find anything wrong with it. I removed it from my manifest, and then things worked again. Mysteriously, when I added it back in, things still worked again (and it no longer has a tag count of 0).

So I tried running another node that is reporting this issue, and it came up with a different resource that had a tag count of zero, in this case a collected resource (nagios) that was exported from another node, totally no relation to the previous issue at all.

Any ideas how I can track down why these resources don’t have any tags?

#14
Updated by Markus Roberts about 2 years ago

I’ve posted a possible partial fix to the dev list (only addressing the failure when there are no tags, not the question of how they arise), along with a brief explanation of why I’m not entirely satisfied. (Short form: there’s a related piece of code that doesn’t look to me as if it should work, so I’m worried that I might be missing something).

I’ve looked some at the question of how there could be any untagged resources, but am not seeing anything.

#15
Updated by Luke Kanies about 2 years ago

I’m also a bit perplexed as to how there could be untagged resources, but clearly it’s happening somewhere. Given that there’s only one such resource in a given run, it’s likely related to the beginning or end of the loop, so maybe it’s a fencepost problem or something.

It’d obviously be good to fix that, but in the meantime, at least we’re fixing it so that case doesn’t hurt anything.

#16
Updated by Markus Roberts about 2 years ago

Luke (or anyone else) —

Any thought on the “get_params_hash” call (see the commit message to the patch I posted to the dev list)? That’s the other part that has me doubting my sanity on this one.

— Markus

P.S. Also, it appears that we might be seeing only one of them because that kills the compile on the server. It’s similar to the reason you only get one last meal or at most one final skydive attempt.

#17
Updated by Markus Roberts about 2 years ago

  • Status changed from Accepted to In Topic Branch Pending Review
  • Branch set to http://github.com/MarkusQ/puppet/tree/ticket/0.25.x/2863

I’m splitting this into two tickets; the original calling-each-on-nil problem and the mystery of why some resources don’t have tags (#2908).

There’s a branch up for testing that should solve the calling-each-on-nil problem:

http://github.com/MarkusQ/puppet/tree/ticket/0.25.x/2863

#18
Updated by micah - about 2 years ago

Markus Roberts wrote:

I’m splitting this into two tickets; the original calling-each-on-nil problem and the mystery of why some resources don’t have tags (#2908).

There’s a branch up for testing that should solve the calling-each-on-nil problem:

http://github.com/MarkusQ/puppet/tree/ticket/0.25.x/2863

Just tried this branch… and this started to happen right away:

                                                                                                             <pre>

Dec 9 11:28:17 puppetmaster puppetmasterd[24959]: undefined method `<<‘ for nil:NilClass
it seems to be happening on each node. if I run one of the nodes that was experiencing #2863, I then see:

err: Could not retrieve catalog from remote server: Error 400 on SERVER: undefined method `<<' for nil:NilClass


i’ll work on getting some debugging

#19
Updated by Markus Roberts about 2 years ago

Micah —

If you can get a —trace I should be able to run it down in a few minutes.

— Markus

#20
Updated by micah - about 2 years ago

Markus Roberts wrote:

Micah —

If you can get a —trace I should be able to run it down in a few minutes.

— Markus

This is what comes out of the client when I run trace:

/usr/lib/ruby/1.8/puppet/indirector/rest.rb:55:in `deserialize'
/usr/lib/ruby/1.8/puppet/indirector/rest.rb:69:in `find'
/usr/lib/ruby/1.8/puppet/indirector/indirection.rb:198:in `find'
/usr/lib/ruby/1.8/puppet/indirector.rb:51:in `find'
/usr/lib/ruby/1.8/puppet/configurer.rb:94:in `retrieve_catalog'
/usr/lib/ruby/1.8/puppet/util.rb:418:in `thinmark'
/usr/lib/ruby/1.8/benchmark.rb:308:in `realtime'
/usr/lib/ruby/1.8/puppet/util.rb:417:in `thinmark'
/usr/lib/ruby/1.8/puppet/configurer.rb:93:in `retrieve_catalog'
/usr/lib/ruby/1.8/puppet/configurer.rb:146:in `run'
/usr/lib/ruby/1.8/puppet/agent.rb:53:in `run'
/usr/lib/ruby/1.8/puppet/agent/locker.rb:21:in `lock'
/usr/lib/ruby/1.8/puppet/agent.rb:53:in `run'
/usr/lib/ruby/1.8/sync.rb:230:in `synchronize'
/usr/lib/ruby/1.8/puppet/agent.rb:53:in `run'
/usr/lib/ruby/1.8/puppet/agent.rb:130:in `with_client'
/usr/lib/ruby/1.8/puppet/agent.rb:51:in `run'
/usr/lib/ruby/1.8/puppet/application/puppetd.rb:103:in `onetime'
/usr/lib/ruby/1.8/puppet/application.rb:226:in `send'
/usr/lib/ruby/1.8/puppet/application.rb:226:in `run_command'
/usr/lib/ruby/1.8/puppet/application.rb:217:in `run'
/usr/lib/ruby/1.8/puppet/application.rb:306:in `exit_on_fail'
/usr/lib/ruby/1.8/puppet/application.rb:217:in `run'
/usr/sbin/puppetd:159
err: Could not retrieve catalog from remote server: Error 400 on SERVER: undefined method `<<' for nil:NilClass
warning: Not using cache on failed catalog

#21
Updated by Markus Roberts about 2 years ago

Micah —

Sorry, I under specified. It’s the server-side we want the trace from.

— Markus

#22
Updated by micah - about 2 years ago

Oops, I actually considered that, and then forgot :P

Here is the server-side trace:

debug: Searched for resources in 0.26 seconds
/usr/lib/ruby/1.8/puppet/rails/resource.rb:75:in `add_param_to_list'
/usr/lib/ruby/1.8/puppet/rails/host.rb:292:in `find_resources_parameters'
/usr/lib/ruby/1.8/puppet/rails/host.rb:291:in `each'
/usr/lib/ruby/1.8/puppet/rails/host.rb:291:in `find_resources_parameters'
/usr/lib/ruby/1.8/puppet/rails/host.rb:175:in `find_resources_parameters_tags'
/usr/lib/ruby/1.8/puppet/rails/host.rb:157:in `merge_resources'
/usr/lib/ruby/1.8/puppet/rails/benchmark.rb:23:in `debug_benchmark'
/usr/lib/ruby/1.8/puppet/rails/benchmark.rb:11:in `railsmark'
/usr/share/rails/activerecord/lib/../../activesupport/lib/active_support/core_ext/benchmark.rb:8:in `realtime'
/usr/lib/ruby/1.8/puppet/rails/benchmark.rb:11:in `railsmark'
/usr/lib/ruby/1.8/puppet/rails/benchmark.rb:23:in `debug_benchmark'
/usr/lib/ruby/1.8/puppet/rails/host.rb:156:in `merge_resources'
/usr/lib/ruby/1.8/puppet/indirector/catalog/active_record.rb:30:in `save'
/usr/lib/ruby/1.8/puppet/rails/benchmark.rb:11:in `railsmark'
/usr/share/rails/activerecord/lib/../../activesupport/lib/active_support/core_ext/benchmark.rb:8:in `realtime'
/usr/lib/ruby/1.8/puppet/rails/benchmark.rb:11:in `railsmark'
/usr/lib/ruby/1.8/puppet/indirector/catalog/active_record.rb:29:in `save'
/usr/lib/ruby/1.8/puppet/indirector/indirection.rb:202:in `find'
/usr/lib/ruby/1.8/puppet/indirector.rb:51:in `find'
/usr/lib/ruby/1.8/puppet/network/http/handler.rb:99:in `do_find'
/usr/lib/ruby/1.8/puppet/network/http/handler.rb:68:in `send'
/usr/lib/ruby/1.8/puppet/network/http/handler.rb:68:in `process'
/usr/lib/ruby/1.8/puppet/network/http/webrick/rest.rb:23:in `service'
/usr/lib/ruby/1.8/webrick/httpserver.rb:104:in `service'
/usr/lib/ruby/1.8/webrick/httpserver.rb:65:in `run'
/usr/lib/ruby/1.8/puppet/network/http/webrick.rb:45:in `listen'
/usr/lib/ruby/1.8/webrick/server.rb:173:in `call'
/usr/lib/ruby/1.8/webrick/server.rb:173:in `start_thread'
/usr/lib/ruby/1.8/webrick/server.rb:162:in `start'
/usr/lib/ruby/1.8/webrick/server.rb:162:in `start_thread'
/usr/lib/ruby/1.8/webrick/server.rb:95:in `start'
/usr/lib/ruby/1.8/webrick/server.rb:92:in `each'
/usr/lib/ruby/1.8/webrick/server.rb:92:in `start'
/usr/lib/ruby/1.8/webrick/server.rb:23:in `start'
/usr/lib/ruby/1.8/webrick/server.rb:82:in `start'
/usr/lib/ruby/1.8/puppet/network/http/webrick.rb:42:in `listen'
/usr/lib/ruby/1.8/puppet/network/http/webrick.rb:41:in `initialize'
/usr/lib/ruby/1.8/puppet/network/http/webrick.rb:41:in `new'
/usr/lib/ruby/1.8/puppet/network/http/webrick.rb:41:in `listen'
/usr/lib/ruby/1.8/puppet/network/http/webrick.rb:38:in `synchronize'
/usr/lib/ruby/1.8/puppet/network/http/webrick.rb:38:in `listen'
/usr/lib/ruby/1.8/puppet/network/server.rb:131:in `listen'
/usr/lib/ruby/1.8/puppet/network/server.rb:146:in `start'
/usr/lib/ruby/1.8/puppet/daemon.rb:128:in `start'
/usr/lib/ruby/1.8/puppet/application/puppetmasterd.rb:122:in `main'
/usr/lib/ruby/1.8/puppet/application.rb:226:in `send'
/usr/lib/ruby/1.8/puppet/application.rb:226:in `run_command'
/usr/lib/ruby/1.8/puppet/application.rb:217:in `run'
/usr/lib/ruby/1.8/puppet/application.rb:306:in `exit_on_fail'
/usr/lib/ruby/1.8/puppet/application.rb:217:in `run'
/usr/sbin/puppetmasterd:66
err: undefined method `<<' for nil:NilClass

#23
Updated by Markus Roberts about 2 years ago

sigh Mea culpa. It was a stupid typo on my part. I’ve fixed it and updated the branch.

— Markus

#24
Updated by micah - about 2 years ago

That seems to do the trick, the null tags on resource issue is not being reported now.

#25
Updated by Markus Roberts about 2 years ago

  • Status changed from In Topic Branch Pending Review to Ready For Checkin

Great, thanks for helping track this down!

#26
Updated by James Turnbull about 2 years ago

  • Status changed from Ready For Checkin to Closed

Pushed in commit:9ac1ed6d11d0fd272dddbfe7c1455ff56523c6be in branch 0.25.x

Also available in: Atom PDF