Olivier Trempe
2013-Feb-25 20:16 UTC
[Puppet Users] Puppet execution hangs for long periods of time
Hi,
I wrote a little "hello world" script and I am a little concerned by
execution that hangs for long periods of time.
*computer:*
Windows XP Professional Service Pack 3
Intel(R) Xeon(R) CPU
W3550 @ 3.07GHz
3.07GHz, 3.50 GB of RAM
*init.pp:*
class hello
{
notice(''Hello world!'')
}
*command line:*
puppet apply --debug -e ''include hello''
*output:*
*Execution hangs ~12 seconds before printing first debug log line*
Debug: importing
''K:/Code/puppet/modules/hello/manifests/init.pp'' in
environment production
Debug: Automatically imported hello from hello into production
Notice: Scope(Class[Hello]): Hello world!
Debug: Creating default schedules
Debug: Failed to load library ''selinux'' for feature
''selinux''
Debug: Using settings: adding file resource ''requestdir'':
''File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl/certificate_requests]{:loglevel=>:debug,
:ensure=>:directory, :links=>:follow, :backup=>false,
:path=>"C:/Documents
and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl/certificate_requests"}''
Debug: Using settings: adding file resource ''client_datadir'':
''File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/var/client_data]{:loglevel=>:debug,
:ensure=>:directory, :links=>:follow, :mode=>"750",
:backup=>false,
:path=>"C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/var/client_data"}''
Debug: Using settings: adding file resource ''hostprivkey'':
''File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl/private_keys/###########.############.net.pem]{:loglevel=>:debug,
:ensure=>:file, :links=>:follow, :mode=>"600",
:backup=>false,
:path=>"C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl/private_keys/###########.############.net.pem"}''
Debug: Using settings: adding file resource ''vardir'':
''File[C:/Documents
and Settings/All Users/Application
Data/PuppetLabs/puppet/var]{:loglevel=>:debug, :ensure=>:directory,
:links=>:follow, :backup=>false, :path=>"C:/Documents and
Settings/All
Users/Application Data/PuppetLabs/puppet/var"}''
Debug: Using settings: adding file resource ''statedir'':
''File[C:/Documents
and Settings/All Users/Application
Data/PuppetLabs/puppet/var/state]{:loglevel=>:debug, :ensure=>:directory,
:links=>:follow, :mode=>"1755", :backup=>false,
:path=>"C:/Documents and
Settings/All Users/Application Data/PuppetLabs/puppet/var/state"}''
Debug: Using settings: adding file resource ''rundir'':
''File[C:/Documents
and Settings/All Users/Application
Data/PuppetLabs/puppet/var/run]{:loglevel=>:debug, :ensure=>:directory,
:links=>:follow, :mode=>"1777", :backup=>false,
:path=>"C:/Documents and
Settings/All Users/Application Data/PuppetLabs/puppet/var/run"}''
Debug: Using settings: adding file resource ''ssldir'':
''File[C:/Documents
and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl]{:loglevel=>:debug, :ensure=>:directory,
:links=>:follow, :mode=>"771", :backup=>false,
:path=>"C:/Documents and
Settings/All Users/Application Data/PuppetLabs/puppet/etc/ssl"}''
Debug: Using settings: adding file resource ''privatekeydir'':
''File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl/private_keys]{:loglevel=>:debug,
:ensure=>:directory, :links=>:follow, :mode=>"750",
:backup=>false,
:path=>"C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl/private_keys"}''
Debug: Using settings: adding file resource ''plugindest'':
''File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/var/lib]{:loglevel=>:debug, :ensure=>:directory,
:links=>:follow, :backup=>false, :path=>"C:/Documents and
Settings/All
Users/Application Data/PuppetLabs/puppet/var/lib"}''
Debug: Using settings: adding file resource ''statefile'':
''File[C:/Documents
and Settings/All Users/Application
Data/PuppetLabs/puppet/var/state/state.yaml]{:loglevel=>:debug,
:ensure=>:file, :links=>:follow, :mode=>"660",
:backup=>false,
:path=>"C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/var/state/state.yaml"}''
Debug: Using settings: adding file resource ''clientbucketdir'':
''File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/var/clientbucket]{:loglevel=>:debug,
:ensure=>:directory, :links=>:follow, :mode=>"750",
:backup=>false,
:path=>"C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/var/clientbucket"}''
Debug: Using settings: adding file resource ''hostpubkey'':
''File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl/public_keys/###########.############.net.pem]{:loglevel=>:debug,
:ensure=>:file, :links=>:follow, :mode=>"644",
:backup=>false,
:path=>"C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl/public_keys/###########.############.net.pem"}''
Debug: Using settings: adding file resource ''logdir'':
''File[C:/Documents
and Settings/All Users/Application
Data/PuppetLabs/puppet/var/log]{:loglevel=>:debug, :ensure=>:directory,
:links=>:follow, :mode=>"750", :backup=>false,
:path=>"C:/Documents and
Settings/All Users/Application Data/PuppetLabs/puppet/var/log"}''
Debug: Using settings: adding file resource ''lastrunfile'':
''File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/var/state/last_run_summary.yaml]{:loglevel=>:debug,
:ensure=>:file, :links=>:follow, :mode=>"644",
:backup=>false,
:path=>"C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/var/state/last_run_summary.yaml"}''
Debug: Using settings: adding file resource ''graphdir'':
''File[C:/Documents
and Settings/All Users/Application
Data/PuppetLabs/puppet/var/state/graphs]{:loglevel=>:debug,
:ensure=>:directory, :links=>:follow, :backup=>false,
:path=>"C:/Documents
and Settings/All Users/Application
Data/PuppetLabs/puppet/var/state/graphs"}''
Debug: Using settings: adding file resource ''publickeydir'':
''File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl/public_keys]{:loglevel=>:debug,
:ensure=>:directory, :links=>:follow, :backup=>false,
:path=>"C:/Documents
and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl/public_keys"}''
Debug: Using settings: adding file resource ''privatedir'':
''File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl/private]{:loglevel=>:debug,
:ensure=>:directory, :links=>:follow, :mode=>"750",
:backup=>false,
:path=>"C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl/private"}''
Debug: Using settings: adding file resource ''clientyamldir'':
''File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/var/client_yaml]{:loglevel=>:debug,
:ensure=>:directory, :links=>:follow, :mode=>"750",
:backup=>false,
:path=>"C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/var/client_yaml"}''
Debug: Using settings: adding file resource ''confdir'':
''File[C:/Documents
and Settings/All Users/Application
Data/PuppetLabs/puppet/etc]{:loglevel=>:debug, :ensure=>:directory,
:links=>:follow, :backup=>false, :path=>"C:/Documents and
Settings/All
Users/Application Data/PuppetLabs/puppet/etc"}''
Debug: Using settings: adding file resource ''lastrunreport'':
''File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/var/state/last_run_report.yaml]{:loglevel=>:debug,
:ensure=>:file, :links=>:follow, :mode=>"640",
:backup=>false,
:path=>"C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/var/state/last_run_report.yaml"}''
Debug: Using settings: adding file resource ''certdir'':
''File[C:/Documents
and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl/certs]{:loglevel=>:debug,
:ensure=>:directory, :links=>:follow, :backup=>false,
:path=>"C:/Documents
and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl/certs"}''
Debug: Puppet::Type::File::ProviderPosix: feature posix is missing
Debug: Failed to load library ''shadow'' for feature
''libshadow''
Debug: /File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl]: Autorequiring File[C:/Documents and
Settings/All Users/Application Data/PuppetLabs/puppet/etc]
Debug: /File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/var/state]: Autorequiring File[C:/Documents and
Settings/All Users/Application Data/PuppetLabs/puppet/var]
Debug: /File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/var/state/last_run_summary.yaml]: Autorequiring
File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/var/state]
Debug: /File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl/private_keys]: Autorequiring
File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl]
Debug: /File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/var/state/last_run_report.yaml]: Autorequiring
File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/var/state]
Debug: /File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/var/lib]: Autorequiring File[C:/Documents and
Settings/All Users/Application Data/PuppetLabs/puppet/var]
Debug: /File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl/public_keys/###########.############.net.pem]:
Autorequiring File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl/public_keys]
Debug: /File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/var/log]: Autorequiring File[C:/Documents and
Settings/All Users/Application Data/PuppetLabs/puppet/var]
Debug: /File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/var/clientbucket]: Autorequiring File[C:/Documents
and Settings/All Users/Application Data/PuppetLabs/puppet/var]
Debug: /File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/var/state/state.yaml]: Autorequiring
File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/var/state]
Debug: /File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl/certs]: Autorequiring File[C:/Documents and
Settings/All Users/Application Data/PuppetLabs/puppet/etc/ssl]
Debug: /File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/var/client_data]: Autorequiring File[C:/Documents
and Settings/All Users/Application Data/PuppetLabs/puppet/var]
Debug: /File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/var/state/graphs]: Autorequiring File[C:/Documents
and Settings/All Users/Application Data/PuppetLabs/puppet/var/state]
Debug: /File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl/private]: Autorequiring File[C:/Documents
and Settings/All Users/Application Data/PuppetLabs/puppet/etc/ssl]
Debug: /File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl/private_keys/###########.############.net.pem]:
Autorequiring File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl/private_keys]
Debug: /File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/var/run]: Autorequiring File[C:/Documents and
Settings/All Users/Application Data/PuppetLabs/puppet/var]
Debug: /File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl/certificate_requests]: Autorequiring
File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl]
Debug: /File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/var/client_yaml]: Autorequiring File[C:/Documents
and Settings/All Users/Application Data/PuppetLabs/puppet/var]
Debug: /File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl/public_keys]: Autorequiring
File[C:/Documents and Settings/All Users/Application
Data/PuppetLabs/puppet/etc/ssl]
Debug: Finishing transaction 86414160
Debug: Loaded state in 0.00 seconds
*Execution hangs another ~12 seconds here*
Debug: Loaded state in 0.00 seconds
Info: Applying configuration version ''1361821561''
Debug: /Schedule[daily]: Skipping device resources because running on a host
Debug: /Schedule[monthly]: Skipping device resources because running on a
host
Debug: /Schedule[hourly]: Skipping device resources because running on a
host
Debug: /Schedule[never]: Skipping device resources because running on a host
Debug: /Schedule[weekly]: Skipping device resources because running on a
host
Debug: /Schedule[puppet]: Skipping device resources because running on a
host
Debug: Finishing transaction 98314548
Debug: Storing state
Debug: Stored state in 0.02 seconds
Notice: Finished catalog run in 0.11 seconds
Debug: Using settings: adding file resource ''rrddir'':
''File[C:/Documents
and Settings/All Users/Application
Data/PuppetLabs/puppet/var/rrd]{:loglevel=>:debug, :ensure=>:directory,
:links=>:follow, :mode=>"750", :backup=>false,
:path=>"C:/Documents and
Settings/All Users/Application Data/PuppetLabs/puppet/var/rrd"}''
Debug: Finishing transaction 98020872
Debug: Received report to process from ###########.############.net
Debug: Processing report from ###########.############.net with processor
Puppet::Reports::Store
*total execution time:*
25 seconds... just to print hello world?!?
Is this a normal behavior?
(It takes the same time without the --debug switch)
Thanks!
Olivier Trempe
--
You received this message because you are subscribed to the Google Groups
"Puppet Users" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to puppet-users+unsubscribe@googlegroups.com.
To post to this group, send email to puppet-users@googlegroups.com.
Visit this group at http://groups.google.com/group/puppet-users?hl=en.
For more options, visit https://groups.google.com/groups/opt_out.
Felix Frank
2013-Feb-27 09:32 UTC
Re: [Puppet Users] Puppet execution hangs for long periods of time
Huh. Is there an strace for windows? It would be good to know exactly what''s going on during those breaks. On 02/25/2013 09:16 PM, Olivier Trempe wrote:> Hi, > > I wrote a little "hello world" script and I am a little concerned by > execution that hangs for long periods of time. > > *computer:* > Windows XP Professional Service Pack 3 > Intel(R) Xeon(R) CPU > W3550 @ 3.07GHz > 3.07GHz, 3.50 GB of RAM > > *init.pp:* > class hello > { > notice(''Hello world!'') > } > > *command line:* > puppet apply --debug -e ''include hello'' > > *output:* > */Execution hangs ~12 seconds before printing first debug log line/* > Debug: importing ''K:/Code/puppet/modules/hello/manifests/init.pp'' in > environment production > Debug: Automatically imported hello from hello into production > Notice: Scope(Class[Hello]): Hello world! > Debug: Creating default schedules > Debug: Failed to load library ''selinux'' for feature ''selinux'' > Debug: Using settings: adding file resource ''requestdir'': > ''File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl/certificate_requests]{:loglevel=>:debug, > :ensure=>:directory, :links=>:follow, :backup=>false, > :path=>"C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl/certificate_requests"}'' > Debug: Using settings: adding file resource ''client_datadir'': > ''File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/client_data]{:loglevel=>:debug, > :ensure=>:directory, :links=>:follow, :mode=>"750", :backup=>false, > :path=>"C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/client_data"}'' > Debug: Using settings: adding file resource ''hostprivkey'': > ''File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl/private_keys/###########.############.net.pem]{:loglevel=>:debug, > :ensure=>:file, :links=>:follow, :mode=>"600", :backup=>false, > :path=>"C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl/private_keys/###########.############.net.pem"}'' > Debug: Using settings: adding file resource ''vardir'': ''File[C:/Documents > and Settings/All Users/Application > Data/PuppetLabs/puppet/var]{:loglevel=>:debug, :ensure=>:directory, > :links=>:follow, :backup=>false, :path=>"C:/Documents and Settings/All > Users/Application Data/PuppetLabs/puppet/var"}'' > Debug: Using settings: adding file resource ''statedir'': > ''File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/state]{:loglevel=>:debug, > :ensure=>:directory, :links=>:follow, :mode=>"1755", :backup=>false, > :path=>"C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/state"}'' > Debug: Using settings: adding file resource ''rundir'': ''File[C:/Documents > and Settings/All Users/Application > Data/PuppetLabs/puppet/var/run]{:loglevel=>:debug, :ensure=>:directory, > :links=>:follow, :mode=>"1777", :backup=>false, :path=>"C:/Documents and > Settings/All Users/Application Data/PuppetLabs/puppet/var/run"}'' > Debug: Using settings: adding file resource ''ssldir'': ''File[C:/Documents > and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl]{:loglevel=>:debug, :ensure=>:directory, > :links=>:follow, :mode=>"771", :backup=>false, :path=>"C:/Documents and > Settings/All Users/Application Data/PuppetLabs/puppet/etc/ssl"}'' > Debug: Using settings: adding file resource ''privatekeydir'': > ''File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl/private_keys]{:loglevel=>:debug, > :ensure=>:directory, :links=>:follow, :mode=>"750", :backup=>false, > :path=>"C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl/private_keys"}'' > Debug: Using settings: adding file resource ''plugindest'': > ''File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/lib]{:loglevel=>:debug, :ensure=>:directory, > :links=>:follow, :backup=>false, :path=>"C:/Documents and Settings/All > Users/Application Data/PuppetLabs/puppet/var/lib"}'' > Debug: Using settings: adding file resource ''statefile'': > ''File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/state/state.yaml]{:loglevel=>:debug, > :ensure=>:file, :links=>:follow, :mode=>"660", :backup=>false, > :path=>"C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/state/state.yaml"}'' > Debug: Using settings: adding file resource ''clientbucketdir'': > ''File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/clientbucket]{:loglevel=>:debug, > :ensure=>:directory, :links=>:follow, :mode=>"750", :backup=>false, > :path=>"C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/clientbucket"}'' > Debug: Using settings: adding file resource ''hostpubkey'': > ''File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl/public_keys/###########.############.net.pem]{:loglevel=>:debug, > :ensure=>:file, :links=>:follow, :mode=>"644", :backup=>false, > :path=>"C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl/public_keys/###########.############.net.pem"}'' > Debug: Using settings: adding file resource ''logdir'': ''File[C:/Documents > and Settings/All Users/Application > Data/PuppetLabs/puppet/var/log]{:loglevel=>:debug, :ensure=>:directory, > :links=>:follow, :mode=>"750", :backup=>false, :path=>"C:/Documents and > Settings/All Users/Application Data/PuppetLabs/puppet/var/log"}'' > Debug: Using settings: adding file resource ''lastrunfile'': > ''File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/state/last_run_summary.yaml]{:loglevel=>:debug, > :ensure=>:file, :links=>:follow, :mode=>"644", :backup=>false, > :path=>"C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/state/last_run_summary.yaml"}'' > Debug: Using settings: adding file resource ''graphdir'': > ''File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/state/graphs]{:loglevel=>:debug, > :ensure=>:directory, :links=>:follow, :backup=>false, > :path=>"C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/state/graphs"}'' > Debug: Using settings: adding file resource ''publickeydir'': > ''File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl/public_keys]{:loglevel=>:debug, > :ensure=>:directory, :links=>:follow, :backup=>false, > :path=>"C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl/public_keys"}'' > Debug: Using settings: adding file resource ''privatedir'': > ''File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl/private]{:loglevel=>:debug, > :ensure=>:directory, :links=>:follow, :mode=>"750", :backup=>false, > :path=>"C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl/private"}'' > Debug: Using settings: adding file resource ''clientyamldir'': > ''File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/client_yaml]{:loglevel=>:debug, > :ensure=>:directory, :links=>:follow, :mode=>"750", :backup=>false, > :path=>"C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/client_yaml"}'' > Debug: Using settings: adding file resource ''confdir'': > ''File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc]{:loglevel=>:debug, :ensure=>:directory, > :links=>:follow, :backup=>false, :path=>"C:/Documents and Settings/All > Users/Application Data/PuppetLabs/puppet/etc"}'' > Debug: Using settings: adding file resource ''lastrunreport'': > ''File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/state/last_run_report.yaml]{:loglevel=>:debug, :ensure=>:file, > :links=>:follow, :mode=>"640", :backup=>false, :path=>"C:/Documents and > Settings/All Users/Application > Data/PuppetLabs/puppet/var/state/last_run_report.yaml"}'' > Debug: Using settings: adding file resource ''certdir'': > ''File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl/certs]{:loglevel=>:debug, > :ensure=>:directory, :links=>:follow, :backup=>false, > :path=>"C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl/certs"}'' > Debug: Puppet::Type::File::ProviderPosix: feature posix is missing > Debug: Failed to load library ''shadow'' for feature ''libshadow'' > Debug: /File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl]: Autorequiring File[C:/Documents and > Settings/All Users/Application Data/PuppetLabs/puppet/etc] > Debug: /File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/state]: Autorequiring File[C:/Documents and > Settings/All Users/Application Data/PuppetLabs/puppet/var] > Debug: /File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/state/last_run_summary.yaml]: Autorequiring > File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/state] > Debug: /File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl/private_keys]: Autorequiring > File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl] > Debug: /File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/state/last_run_report.yaml]: Autorequiring > File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/state] > Debug: /File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/lib]: Autorequiring File[C:/Documents and > Settings/All Users/Application Data/PuppetLabs/puppet/var] > Debug: /File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl/public_keys/###########.############.net.pem]: > Autorequiring File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl/public_keys] > Debug: /File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/log]: Autorequiring File[C:/Documents and > Settings/All Users/Application Data/PuppetLabs/puppet/var] > Debug: /File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/clientbucket]: Autorequiring > File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var] > Debug: /File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/state/state.yaml]: Autorequiring > File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/state] > Debug: /File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl/certs]: Autorequiring File[C:/Documents > and Settings/All Users/Application Data/PuppetLabs/puppet/etc/ssl] > Debug: /File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/client_data]: Autorequiring File[C:/Documents > and Settings/All Users/Application Data/PuppetLabs/puppet/var] > Debug: /File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/state/graphs]: Autorequiring > File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/state] > Debug: /File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl/private]: Autorequiring File[C:/Documents > and Settings/All Users/Application Data/PuppetLabs/puppet/etc/ssl] > Debug: /File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl/private_keys/###########.############.net.pem]: > Autorequiring File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl/private_keys] > Debug: /File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/run]: Autorequiring File[C:/Documents and > Settings/All Users/Application Data/PuppetLabs/puppet/var] > Debug: /File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl/certificate_requests]: Autorequiring > File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl] > Debug: /File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/var/client_yaml]: Autorequiring File[C:/Documents > and Settings/All Users/Application Data/PuppetLabs/puppet/var] > Debug: /File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl/public_keys]: Autorequiring > File[C:/Documents and Settings/All Users/Application > Data/PuppetLabs/puppet/etc/ssl] > Debug: Finishing transaction 86414160 > Debug: Loaded state in 0.00 seconds > */Execution hangs another ~12 seconds here/* > Debug: Loaded state in 0.00 seconds > Info: Applying configuration version ''1361821561'' > Debug: /Schedule[daily]: Skipping device resources because running on a host > Debug: /Schedule[monthly]: Skipping device resources because running on > a host > Debug: /Schedule[hourly]: Skipping device resources because running on a > host > Debug: /Schedule[never]: Skipping device resources because running on a host > Debug: /Schedule[weekly]: Skipping device resources because running on a > host > Debug: /Schedule[puppet]: Skipping device resources because running on a > host > Debug: Finishing transaction 98314548 > Debug: Storing state > Debug: Stored state in 0.02 seconds > Notice: Finished catalog run in 0.11 seconds > Debug: Using settings: adding file resource ''rrddir'': ''File[C:/Documents > and Settings/All Users/Application > Data/PuppetLabs/puppet/var/rrd]{:loglevel=>:debug, :ensure=>:directory, > :links=>:follow, :mode=>"750", :backup=>false, :path=>"C:/Documents and > Settings/All Users/Application Data/PuppetLabs/puppet/var/rrd"}'' > Debug: Finishing transaction 98020872 > Debug: Received report to process from ###########.############.net > Debug: Processing report from ###########.############.net with > processor Puppet::Reports::Store > > > *total execution time:* > 25 seconds... just to print hello world?!? > > Is this a normal behavior? > (It takes the same time without the --debug switch) > > Thanks! > > Olivier Trempe > > > -- > You received this message because you are subscribed to the Google > Groups "Puppet Users" group. > To unsubscribe from this group and stop receiving emails from it, send > an email to puppet-users+unsubscribe@googlegroups.com. > To post to this group, send email to puppet-users@googlegroups.com. > Visit this group at http://groups.google.com/group/puppet-users?hl=en. > For more options, visit https://groups.google.com/groups/opt_out. > >-- You received this message because you are subscribed to the Google Groups "Puppet Users" group. To unsubscribe from this group and stop receiving emails from it, send an email to puppet-users+unsubscribe@googlegroups.com. To post to this group, send email to puppet-users@googlegroups.com. Visit this group at http://groups.google.com/group/puppet-users?hl=en. For more options, visit https://groups.google.com/groups/opt_out.
Olivier Trempe
2013-Mar-01 19:25 UTC
Re: [Puppet Users] Puppet execution hangs for long periods of time
Ok, I used this tool: StraceNT So when it first hangs, I got loads of: [T4168] WahReferenceContextByHandle(45718, 5f8, 2416954, 71ab4762, ...) [T4168] InterlockedExchangeAdd(45840, 2, 2416088, 24166ec, ...) = 46 [T4168] InterlockedExchangeAdd(45844, 2, 2416088, 24166ec, ...) = 47 = 0 [T4168] GetHandleInformation(5f8, 2416698, 2416fec, 241703c, ...) = 1 [T4168] WaitForSingleObject(7bc, 0, 2416690, 71ab26c8, ...) = 102 [T4168] EnterCriticalSection(391ef0, 0, 5f8, ffff, ...) = 0 [T4168] InterlockedIncrement(391f18, 0, 5f8, ffff, ...) = 2 [T4168] LeaveCriticalSection(391ef0, 0, 5f8, ffff, ...) = 0 and [T4168] ReadProcessMemory(5c4, 142150, 241433c, 50, ...) = 1 and [T4168] EnterCriticalSection(66c46db0, 2418110, 2417e98, 66b9715b, ...) = 0 [T4168] HeapAlloc(230000, 0, 10, 24184d4, ...) = 399ae78 [T4168] LeaveCriticalSection(66c46db0, 10, 2417e48, 77c2c42e, ...) = 0 Those are the most repeated patterns. I don''t know much about Windows'' core... I hope this help you identify the problem On Wednesday, February 27, 2013 4:32:41 AM UTC-5, Felix.Frank wrote:> > Huh. > > Is there an strace for windows? It would be good to know exactly what''s > going on during those breaks. > > On 02/25/2013 09:16 PM, Olivier Trempe wrote: > > Hi, > > > > I wrote a little "hello world" script and I am a little concerned by > > execution that hangs for long periods of time. > > > > *computer:* > > Windows XP Professional Service Pack 3 > > Intel(R) Xeon(R) CPU > > W3550 @ 3.07GHz > > 3.07GHz, 3.50 GB of RAM > > > > *init.pp:* > > class hello > > { > > notice(''Hello world!'') > > } > > > > *command line:* > > puppet apply --debug -e ''include hello'' > > > > *output:* > > */Execution hangs ~12 seconds before printing first debug log line/* > > Debug: importing ''K:/Code/puppet/modules/hello/manifests/init.pp'' in > > environment production > > Debug: Automatically imported hello from hello into production > > Notice: Scope(Class[Hello]): Hello world! > > Debug: Creating default schedules > > Debug: Failed to load library ''selinux'' for feature ''selinux'' > > Debug: Using settings: adding file resource ''requestdir'': > > ''File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/etc/ssl/certificate_requests]{:loglevel=>:debug, > > :ensure=>:directory, :links=>:follow, :backup=>false, > > :path=>"C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/etc/ssl/certificate_requests"}'' > > Debug: Using settings: adding file resource ''client_datadir'': > > ''File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/client_data]{:loglevel=>:debug, > > :ensure=>:directory, :links=>:follow, :mode=>"750", :backup=>false, > > :path=>"C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/client_data"}'' > > Debug: Using settings: adding file resource ''hostprivkey'': > > ''File[C:/Documents and Settings/All Users/Application > > > Data/PuppetLabs/puppet/etc/ssl/private_keys/###########.############.net.pem]{:loglevel=>:debug, > > > :ensure=>:file, :links=>:follow, :mode=>"600", :backup=>false, > > :path=>"C:/Documents and Settings/All Users/Application > > > Data/PuppetLabs/puppet/etc/ssl/private_keys/###########.############.net.pem"}'' > > > Debug: Using settings: adding file resource ''vardir'': ''File[C:/Documents > > and Settings/All Users/Application > > Data/PuppetLabs/puppet/var]{:loglevel=>:debug, :ensure=>:directory, > > :links=>:follow, :backup=>false, :path=>"C:/Documents and Settings/All > > Users/Application Data/PuppetLabs/puppet/var"}'' > > Debug: Using settings: adding file resource ''statedir'': > > ''File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/state]{:loglevel=>:debug, > > :ensure=>:directory, :links=>:follow, :mode=>"1755", :backup=>false, > > :path=>"C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/state"}'' > > Debug: Using settings: adding file resource ''rundir'': ''File[C:/Documents > > and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/run]{:loglevel=>:debug, :ensure=>:directory, > > :links=>:follow, :mode=>"1777", :backup=>false, :path=>"C:/Documents and > > Settings/All Users/Application Data/PuppetLabs/puppet/var/run"}'' > > Debug: Using settings: adding file resource ''ssldir'': ''File[C:/Documents > > and Settings/All Users/Application > > Data/PuppetLabs/puppet/etc/ssl]{:loglevel=>:debug, :ensure=>:directory, > > :links=>:follow, :mode=>"771", :backup=>false, :path=>"C:/Documents and > > Settings/All Users/Application Data/PuppetLabs/puppet/etc/ssl"}'' > > Debug: Using settings: adding file resource ''privatekeydir'': > > ''File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/etc/ssl/private_keys]{:loglevel=>:debug, > > :ensure=>:directory, :links=>:follow, :mode=>"750", :backup=>false, > > :path=>"C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/etc/ssl/private_keys"}'' > > Debug: Using settings: adding file resource ''plugindest'': > > ''File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/lib]{:loglevel=>:debug, :ensure=>:directory, > > :links=>:follow, :backup=>false, :path=>"C:/Documents and Settings/All > > Users/Application Data/PuppetLabs/puppet/var/lib"}'' > > Debug: Using settings: adding file resource ''statefile'': > > ''File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/state/state.yaml]{:loglevel=>:debug, > > :ensure=>:file, :links=>:follow, :mode=>"660", :backup=>false, > > :path=>"C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/state/state.yaml"}'' > > Debug: Using settings: adding file resource ''clientbucketdir'': > > ''File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/clientbucket]{:loglevel=>:debug, > > :ensure=>:directory, :links=>:follow, :mode=>"750", :backup=>false, > > :path=>"C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/clientbucket"}'' > > Debug: Using settings: adding file resource ''hostpubkey'': > > ''File[C:/Documents and Settings/All Users/Application > > > Data/PuppetLabs/puppet/etc/ssl/public_keys/###########.############.net.pem]{:loglevel=>:debug, > > > :ensure=>:file, :links=>:follow, :mode=>"644", :backup=>false, > > :path=>"C:/Documents and Settings/All Users/Application > > > Data/PuppetLabs/puppet/etc/ssl/public_keys/###########.############.net.pem"}'' > > > Debug: Using settings: adding file resource ''logdir'': ''File[C:/Documents > > and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/log]{:loglevel=>:debug, :ensure=>:directory, > > :links=>:follow, :mode=>"750", :backup=>false, :path=>"C:/Documents and > > Settings/All Users/Application Data/PuppetLabs/puppet/var/log"}'' > > Debug: Using settings: adding file resource ''lastrunfile'': > > ''File[C:/Documents and Settings/All Users/Application > > > Data/PuppetLabs/puppet/var/state/last_run_summary.yaml]{:loglevel=>:debug, > > :ensure=>:file, :links=>:follow, :mode=>"644", :backup=>false, > > :path=>"C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/state/last_run_summary.yaml"}'' > > Debug: Using settings: adding file resource ''graphdir'': > > ''File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/state/graphs]{:loglevel=>:debug, > > :ensure=>:directory, :links=>:follow, :backup=>false, > > :path=>"C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/state/graphs"}'' > > Debug: Using settings: adding file resource ''publickeydir'': > > ''File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/etc/ssl/public_keys]{:loglevel=>:debug, > > :ensure=>:directory, :links=>:follow, :backup=>false, > > :path=>"C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/etc/ssl/public_keys"}'' > > Debug: Using settings: adding file resource ''privatedir'': > > ''File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/etc/ssl/private]{:loglevel=>:debug, > > :ensure=>:directory, :links=>:follow, :mode=>"750", :backup=>false, > > :path=>"C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/etc/ssl/private"}'' > > Debug: Using settings: adding file resource ''clientyamldir'': > > ''File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/client_yaml]{:loglevel=>:debug, > > :ensure=>:directory, :links=>:follow, :mode=>"750", :backup=>false, > > :path=>"C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/client_yaml"}'' > > Debug: Using settings: adding file resource ''confdir'': > > ''File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/etc]{:loglevel=>:debug, :ensure=>:directory, > > :links=>:follow, :backup=>false, :path=>"C:/Documents and Settings/All > > Users/Application Data/PuppetLabs/puppet/etc"}'' > > Debug: Using settings: adding file resource ''lastrunreport'': > > ''File[C:/Documents and Settings/All Users/Application > > > Data/PuppetLabs/puppet/var/state/last_run_report.yaml]{:loglevel=>:debug, > :ensure=>:file, > > :links=>:follow, :mode=>"640", :backup=>false, :path=>"C:/Documents and > > Settings/All Users/Application > > Data/PuppetLabs/puppet/var/state/last_run_report.yaml"}'' > > Debug: Using settings: adding file resource ''certdir'': > > ''File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/etc/ssl/certs]{:loglevel=>:debug, > > :ensure=>:directory, :links=>:follow, :backup=>false, > > :path=>"C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/etc/ssl/certs"}'' > > Debug: Puppet::Type::File::ProviderPosix: feature posix is missing > > Debug: Failed to load library ''shadow'' for feature ''libshadow'' > > Debug: /File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/etc/ssl]: Autorequiring File[C:/Documents and > > Settings/All Users/Application Data/PuppetLabs/puppet/etc] > > Debug: /File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/state]: Autorequiring File[C:/Documents and > > Settings/All Users/Application Data/PuppetLabs/puppet/var] > > Debug: /File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/state/last_run_summary.yaml]: Autorequiring > > File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/state] > > Debug: /File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/etc/ssl/private_keys]: Autorequiring > > File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/etc/ssl] > > Debug: /File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/state/last_run_report.yaml]: Autorequiring > > File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/state] > > Debug: /File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/lib]: Autorequiring File[C:/Documents and > > Settings/All Users/Application Data/PuppetLabs/puppet/var] > > Debug: /File[C:/Documents and Settings/All Users/Application > > > Data/PuppetLabs/puppet/etc/ssl/public_keys/###########.############.net.pem]: > > > Autorequiring File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/etc/ssl/public_keys] > > Debug: /File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/log]: Autorequiring File[C:/Documents and > > Settings/All Users/Application Data/PuppetLabs/puppet/var] > > Debug: /File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/clientbucket]: Autorequiring > > File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var] > > Debug: /File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/state/state.yaml]: Autorequiring > > File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/state] > > Debug: /File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/etc/ssl/certs]: Autorequiring File[C:/Documents > > and Settings/All Users/Application Data/PuppetLabs/puppet/etc/ssl] > > Debug: /File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/client_data]: Autorequiring File[C:/Documents > > and Settings/All Users/Application Data/PuppetLabs/puppet/var] > > Debug: /File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/state/graphs]: Autorequiring > > File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/state] > > Debug: /File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/etc/ssl/private]: Autorequiring File[C:/Documents > > and Settings/All Users/Application Data/PuppetLabs/puppet/etc/ssl] > > Debug: /File[C:/Documents and Settings/All Users/Application > > > Data/PuppetLabs/puppet/etc/ssl/private_keys/###########.############.net.pem]: > > > Autorequiring File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/etc/ssl/private_keys] > > Debug: /File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/run]: Autorequiring File[C:/Documents and > > Settings/All Users/Application Data/PuppetLabs/puppet/var] > > Debug: /File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/etc/ssl/certificate_requests]: Autorequiring > > File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/etc/ssl] > > Debug: /File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/client_yaml]: Autorequiring File[C:/Documents > > and Settings/All Users/Application Data/PuppetLabs/puppet/var] > > Debug: /File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/etc/ssl/public_keys]: Autorequiring > > File[C:/Documents and Settings/All Users/Application > > Data/PuppetLabs/puppet/etc/ssl] > > Debug: Finishing transaction 86414160 > > Debug: Loaded state in 0.00 seconds > > */Execution hangs another ~12 seconds here/* > > Debug: Loaded state in 0.00 seconds > > Info: Applying configuration version ''1361821561'' > > Debug: /Schedule[daily]: Skipping device resources because running on a > host > > Debug: /Schedule[monthly]: Skipping device resources because running on > > a host > > Debug: /Schedule[hourly]: Skipping device resources because running on a > > host > > Debug: /Schedule[never]: Skipping device resources because running on a > host > > Debug: /Schedule[weekly]: Skipping device resources because running on a > > host > > Debug: /Schedule[puppet]: Skipping device resources because running on a > > host > > Debug: Finishing transaction 98314548 > > Debug: Storing state > > Debug: Stored state in 0.02 seconds > > Notice: Finished catalog run in 0.11 seconds > > Debug: Using settings: adding file resource ''rrddir'': ''File[C:/Documents > > and Settings/All Users/Application > > Data/PuppetLabs/puppet/var/rrd]{:loglevel=>:debug, :ensure=>:directory, > > :links=>:follow, :mode=>"750", :backup=>false, :path=>"C:/Documents and > > Settings/All Users/Application Data/PuppetLabs/puppet/var/rrd"}'' > > Debug: Finishing transaction 98020872 > > Debug: Received report to process from ###########.############.net > > Debug: Processing report from ###########.############.net with > > processor Puppet::Reports::Store > > > > > > *total execution time:* > > 25 seconds... just to print hello world?!? > > > > Is this a normal behavior? > > (It takes the same time without the --debug switch) > > > > Thanks! > > > > Olivier Trempe > > > > > > -- > > You received this message because you are subscribed to the Google > > Groups "Puppet Users" group. > > To unsubscribe from this group and stop receiving emails from it, send > > an email to puppet-users...@googlegroups.com <javascript:>. > > To post to this group, send email to puppet...@googlegroups.com<javascript:>. > > > Visit this group at http://groups.google.com/group/puppet-users?hl=en. > > For more options, visit https://groups.google.com/groups/opt_out. > > > > >-- You received this message because you are subscribed to the Google Groups "Puppet Users" group. To unsubscribe from this group and stop receiving emails from it, send an email to puppet-users+unsubscribe@googlegroups.com. To post to this group, send email to puppet-users@googlegroups.com. Visit this group at http://groups.google.com/group/puppet-users?hl=en. For more options, visit https://groups.google.com/groups/opt_out.
Josh Cooper
2013-Mar-01 20:32 UTC
Re: [Puppet Users] Puppet execution hangs for long periods of time
On Fri, Mar 1, 2013 at 11:25 AM, Olivier Trempe <oliviertrempe@gmail.com>wrote:> Ok, > > I used this tool: StraceNT > > So when it first hangs, I got loads of: > > [T4168] WahReferenceContextByHandle(45718, 5f8, 2416954, 71ab4762, ...) > [T4168] InterlockedExchangeAdd(45840, 2, 2416088, 24166ec, ...) = 46 > [T4168] InterlockedExchangeAdd(45844, 2, 2416088, 24166ec, ...) = 47 > = 0 > [T4168] GetHandleInformation(5f8, 2416698, 2416fec, 241703c, ...) = 1 > [T4168] WaitForSingleObject(7bc, 0, 2416690, 71ab26c8, ...) = 102 > [T4168] EnterCriticalSection(391ef0, 0, 5f8, ffff, ...) = 0 > [T4168] InterlockedIncrement(391f18, 0, 5f8, ffff, ...) = 2 > [T4168] LeaveCriticalSection(391ef0, 0, 5f8, ffff, ...) = 0 > > and > > [T4168] ReadProcessMemory(5c4, 142150, 241433c, 50, ...) = 1 > > and > > [T4168] EnterCriticalSection(66c46db0, 2418110, 2417e98, 66b9715b, ...) = 0 > [T4168] HeapAlloc(230000, 0, 10, 24184d4, ...) = 399ae78 > [T4168] LeaveCriticalSection(66c46db0, 10, 2417e48, 77c2c42e, ...) = 0 > > Those are the most repeated patterns. > I don''t know much about Windows'' core... I hope this help you identify the > problem > > > On Wednesday, February 27, 2013 4:32:41 AM UTC-5, Felix.Frank wrote: > >> Huh. >> >> Is there an strace for windows? It would be good to know exactly what''s >> going on during those breaks. >> >> On 02/25/2013 09:16 PM, Olivier Trempe wrote: >> > Hi, >> > >> > I wrote a little "hello world" script and I am a little concerned by >> > execution that hangs for long periods of time. >> > >> > *computer:* >> > Windows XP Professional Service Pack 3 >> > Intel(R) Xeon(R) CPU >> > W3550 @ 3.07GHz >> > 3.07GHz, 3.50 GB of RAM >> > >> > *init.pp:* >> > class hello >> > { >> > notice(''Hello world!'') >> > } >> > >> > *command line:* >> > puppet apply --debug -e ''include hello'' >> > >> > *output:* >> > */Execution hangs ~12 seconds before printing first debug log line/* >> > Debug: importing ''K:/Code/puppet/modules/hello/**manifests/init.pp'' in >> > environment production >> > Debug: Automatically imported hello from hello into production >> > Notice: Scope(Class[Hello]): Hello world! >> > Debug: Creating default schedules >> > Debug: Failed to load library ''selinux'' for feature ''selinux'' >> > Debug: Using settings: adding file resource ''requestdir'': >> > ''File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl/certificate_requests]{:**loglevel=>:debug, >> >> > :ensure=>:directory, :links=>:follow, :backup=>false, >> > :path=>"C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl/certificate_requests"}'' >> > Debug: Using settings: adding file resource ''client_datadir'': >> > ''File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**client_data]{:loglevel=>:**debug, >> > :ensure=>:directory, :links=>:follow, :mode=>"750", :backup=>false, >> > :path=>"C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**client_data"}'' >> > Debug: Using settings: adding file resource ''hostprivkey'': >> > ''File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl/private_keys/###########.#** >> ###########.net.pem]{:**loglevel=>:debug, >> > :ensure=>:file, :links=>:follow, :mode=>"600", :backup=>false, >> > :path=>"C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl/private_keys/###########.#**###########.net.pem"}'' >> >> > Debug: Using settings: adding file resource ''vardir'': >> ''File[C:/Documents >> > and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var]{:**loglevel=>:debug, :ensure=>:directory, >> > :links=>:follow, :backup=>false, :path=>"C:/Documents and Settings/All >> > Users/Application Data/PuppetLabs/puppet/var"}'' >> > Debug: Using settings: adding file resource ''statedir'': >> > ''File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**state]{:loglevel=>:debug, >> > :ensure=>:directory, :links=>:follow, :mode=>"1755", :backup=>false, >> > :path=>"C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**state"}'' >> > Debug: Using settings: adding file resource ''rundir'': >> ''File[C:/Documents >> > and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**run]{:loglevel=>:debug, >> :ensure=>:directory, >> > :links=>:follow, :mode=>"1777", :backup=>false, :path=>"C:/Documents >> and >> > Settings/All Users/Application Data/PuppetLabs/puppet/var/**run"}'' >> > Debug: Using settings: adding file resource ''ssldir'': >> ''File[C:/Documents >> > and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl]{:loglevel=>:debug, >> :ensure=>:directory, >> > :links=>:follow, :mode=>"771", :backup=>false, :path=>"C:/Documents and >> > Settings/All Users/Application Data/PuppetLabs/puppet/etc/**ssl"}'' >> > Debug: Using settings: adding file resource ''privatekeydir'': >> > ''File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl/private_keys]{:loglevel=>:**debug, >> > :ensure=>:directory, :links=>:follow, :mode=>"750", :backup=>false, >> > :path=>"C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl/private_keys"}'' >> > Debug: Using settings: adding file resource ''plugindest'': >> > ''File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**lib]{:loglevel=>:debug, >> :ensure=>:directory, >> > :links=>:follow, :backup=>false, :path=>"C:/Documents and Settings/All >> > Users/Application Data/PuppetLabs/puppet/var/**lib"}'' >> > Debug: Using settings: adding file resource ''statefile'': >> > ''File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**state/state.yaml]{:loglevel=>:**debug, >> > :ensure=>:file, :links=>:follow, :mode=>"660", :backup=>false, >> > :path=>"C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**state/state.yaml"}'' >> > Debug: Using settings: adding file resource ''clientbucketdir'': >> > ''File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**clientbucket]{:loglevel=>:**debug, >> > :ensure=>:directory, :links=>:follow, :mode=>"750", :backup=>false, >> > :path=>"C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**clientbucket"}'' >> > Debug: Using settings: adding file resource ''hostpubkey'': >> > ''File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl/public_keys/###########.##** >> ##########.net.pem]{:loglevel=**>:debug, >> > :ensure=>:file, :links=>:follow, :mode=>"644", :backup=>false, >> > :path=>"C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl/public_keys/###########.##**##########.net.pem"}'' >> >> > Debug: Using settings: adding file resource ''logdir'': >> ''File[C:/Documents >> > and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**log]{:loglevel=>:debug, >> :ensure=>:directory, >> > :links=>:follow, :mode=>"750", :backup=>false, :path=>"C:/Documents and >> > Settings/All Users/Application Data/PuppetLabs/puppet/var/**log"}'' >> > Debug: Using settings: adding file resource ''lastrunfile'': >> > ''File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**state/last_run_summary.yaml]{:**loglevel=>:debug, >> >> > :ensure=>:file, :links=>:follow, :mode=>"644", :backup=>false, >> > :path=>"C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**state/last_run_summary.yaml"}'' >> > Debug: Using settings: adding file resource ''graphdir'': >> > ''File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**state/graphs]{:loglevel=>:**debug, >> > :ensure=>:directory, :links=>:follow, :backup=>false, >> > :path=>"C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**state/graphs"}'' >> > Debug: Using settings: adding file resource ''publickeydir'': >> > ''File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl/public_keys]{:loglevel=>:**debug, >> > :ensure=>:directory, :links=>:follow, :backup=>false, >> > :path=>"C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl/public_keys"}'' >> > Debug: Using settings: adding file resource ''privatedir'': >> > ''File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl/private]{:loglevel=>:**debug, >> > :ensure=>:directory, :links=>:follow, :mode=>"750", :backup=>false, >> > :path=>"C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl/private"}'' >> > Debug: Using settings: adding file resource ''clientyamldir'': >> > ''File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**client_yaml]{:loglevel=>:**debug, >> > :ensure=>:directory, :links=>:follow, :mode=>"750", :backup=>false, >> > :path=>"C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**client_yaml"}'' >> > Debug: Using settings: adding file resource ''confdir'': >> > ''File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc]{:**loglevel=>:debug, :ensure=>:directory, >> > :links=>:follow, :backup=>false, :path=>"C:/Documents and Settings/All >> > Users/Application Data/PuppetLabs/puppet/etc"}'' >> > Debug: Using settings: adding file resource ''lastrunreport'': >> > ''File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**state/last_run_report.yaml]{:**loglevel=>:debug, >> :ensure=>:file, >> > :links=>:follow, :mode=>"640", :backup=>false, :path=>"C:/Documents and >> > Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**state/last_run_report.yaml"}'' >> > Debug: Using settings: adding file resource ''certdir'': >> > ''File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl/certs]{:loglevel=>:debug, >> > :ensure=>:directory, :links=>:follow, :backup=>false, >> > :path=>"C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl/certs"}'' >> > Debug: Puppet::Type::File::**ProviderPosix: feature posix is missing >> > Debug: Failed to load library ''shadow'' for feature ''libshadow'' >> > Debug: /File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl]: Autorequiring File[C:/Documents and >> > Settings/All Users/Application Data/PuppetLabs/puppet/etc] >> > Debug: /File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**state]: Autorequiring File[C:/Documents >> and >> > Settings/All Users/Application Data/PuppetLabs/puppet/var] >> > Debug: /File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**state/last_run_summary.yaml]: >> Autorequiring >> > File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**state] >> > Debug: /File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl/private_keys]: Autorequiring >> > File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl] >> > Debug: /File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**state/last_run_report.yaml]: >> Autorequiring >> > File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**state] >> > Debug: /File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**lib]: Autorequiring File[C:/Documents and >> > Settings/All Users/Application Data/PuppetLabs/puppet/var] >> > Debug: /File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl/public_keys/###########.##**##########.net.pem]: >> >> > Autorequiring File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl/public_keys] >> > Debug: /File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**log]: Autorequiring File[C:/Documents and >> > Settings/All Users/Application Data/PuppetLabs/puppet/var] >> > Debug: /File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**clientbucket]: Autorequiring >> > File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var] >> > Debug: /File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**state/state.yaml]: Autorequiring >> > File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**state] >> > Debug: /File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl/certs]: Autorequiring >> File[C:/Documents >> > and Settings/All Users/Application Data/PuppetLabs/puppet/etc/**ssl] >> > Debug: /File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**client_data]: Autorequiring >> File[C:/Documents >> > and Settings/All Users/Application Data/PuppetLabs/puppet/var] >> > Debug: /File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**state/graphs]: Autorequiring >> > File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**state] >> > Debug: /File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl/private]: Autorequiring >> File[C:/Documents >> > and Settings/All Users/Application Data/PuppetLabs/puppet/etc/**ssl] >> > Debug: /File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl/private_keys/###########.#**###########.net.pem]: >> >> > Autorequiring File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl/private_keys] >> > Debug: /File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**run]: Autorequiring File[C:/Documents and >> > Settings/All Users/Application Data/PuppetLabs/puppet/var] >> > Debug: /File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl/certificate_requests]: Autorequiring >> > File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl] >> > Debug: /File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**client_yaml]: Autorequiring >> File[C:/Documents >> > and Settings/All Users/Application Data/PuppetLabs/puppet/var] >> > Debug: /File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl/public_keys]: Autorequiring >> > File[C:/Documents and Settings/All Users/Application >> > Data/PuppetLabs/puppet/etc/**ssl] >> > Debug: Finishing transaction 86414160 >> > Debug: Loaded state in 0.00 seconds >> > */Execution hangs another ~12 seconds here/* >> > Debug: Loaded state in 0.00 seconds >> > Info: Applying configuration version ''1361821561'' >> > Debug: /Schedule[daily]: Skipping device resources because running on a >> host >> > Debug: /Schedule[monthly]: Skipping device resources because running on >> > a host >> > Debug: /Schedule[hourly]: Skipping device resources because running on >> a >> > host >> > Debug: /Schedule[never]: Skipping device resources because running on a >> host >> > Debug: /Schedule[weekly]: Skipping device resources because running on >> a >> > host >> > Debug: /Schedule[puppet]: Skipping device resources because running on >> a >> > host >> > Debug: Finishing transaction 98314548 >> > Debug: Storing state >> > Debug: Stored state in 0.02 seconds >> > Notice: Finished catalog run in 0.11 seconds >> > Debug: Using settings: adding file resource ''rrddir'': >> ''File[C:/Documents >> > and Settings/All Users/Application >> > Data/PuppetLabs/puppet/var/**rrd]{:loglevel=>:debug, >> :ensure=>:directory, >> > :links=>:follow, :mode=>"750", :backup=>false, :path=>"C:/Documents and >> > Settings/All Users/Application Data/PuppetLabs/puppet/var/**rrd"}'' >> > Debug: Finishing transaction 98020872 >> > Debug: Received report to process from ###########.############.net >> > Debug: Processing report from ###########.############.net with >> > processor Puppet::Reports::Store >> > >> > >> > *total execution time:* >> > 25 seconds... just to print hello world?!? >> > >> > Is this a normal behavior? >> > (It takes the same time without the --debug switch) >> > >> > Thanks! >> > >> > Olivier Trempe >> > >> > >> > -- >> > You received this message because you are subscribed to the Google >> > Groups "Puppet Users" group. >> > To unsubscribe from this group and stop receiving emails from it, send >> > an email to puppet-users...@**googlegroups.com. >> > To post to this group, send email to puppet...@googlegroups.com. >> > Visit this group at http://groups.google.com/**group/puppet-users?hl=en<http://groups.google.com/group/puppet-users?hl=en>. >> >> > For more options, visit https://groups.google.com/**groups/opt_out<https://groups.google.com/groups/opt_out>. >> >> > >> > >> > -- > You received this message because you are subscribed to the Google Groups > "Puppet Users" group. > To unsubscribe from this group and stop receiving emails from it, send an > email to puppet-users+unsubscribe@googlegroups.com. > To post to this group, send email to puppet-users@googlegroups.com. > Visit this group at http://groups.google.com/group/puppet-users?hl=en. > For more options, visit https://groups.google.com/groups/opt_out. > > >Make sure you''re using the latest 2.7.x and 3.0.x (or 3.1.x) as there was a performance issue when resolving usernames into SIDs. Also to debug further, try using procmon from sysinternals, now part of MS, configure it to filter on the ruby.exe process. Josh -- Josh Cooper Developer, Puppet Labs -- You received this message because you are subscribed to the Google Groups "Puppet Users" group. To unsubscribe from this group and stop receiving emails from it, send an email to puppet-users+unsubscribe@googlegroups.com. To post to this group, send email to puppet-users@googlegroups.com. Visit this group at http://groups.google.com/group/puppet-users?hl=en. For more options, visit https://groups.google.com/groups/opt_out.
Felix Frank
2013-Mar-04 12:32 UTC
Re: [Puppet Users] Puppet execution hangs for long periods of time
On 03/01/2013 09:32 PM, Josh Cooper wrote:> > Those are the most repeated patterns. > I don''t know much about Windows'' core... I hope this help you identify > the problemNo, sorry, I''m pretty much a novice with Windows as well. HeapAlloc sounds like memory allocation issues. Which can be a performance criteria. So basically - what Josh said, also probably some kind of ruby profiling tool? I don''t really know what''s out there though. -- You received this message because you are subscribed to the Google Groups "Puppet Users" group. To unsubscribe from this group and stop receiving emails from it, send an email to puppet-users+unsubscribe@googlegroups.com. To post to this group, send email to puppet-users@googlegroups.com. Visit this group at http://groups.google.com/group/puppet-users?hl=en. For more options, visit https://groups.google.com/groups/opt_out.
Olivier Trempe
2013-Mar-04 22:09 UTC
Re: [Puppet Users] Puppet execution hangs for long periods of time
Ok, I just tried on Windows 7 and I don''t observe the performance issue. Thanks to all of you. I will not push this investigation further as I hope to have my linux master soon! On Monday, March 4, 2013 7:32:11 AM UTC-5, Felix.Frank wrote:> > On 03/01/2013 09:32 PM, Josh Cooper wrote: > > > > Those are the most repeated patterns. > > I don''t know much about Windows'' core... I hope this help you identify > > the problem > > No, sorry, I''m pretty much a novice with Windows as well. > > HeapAlloc sounds like memory allocation issues. Which can be a > performance criteria. > > So basically - what Josh said, also probably some kind of ruby profiling > tool? I don''t really know what''s out there though. >-- You received this message because you are subscribed to the Google Groups "Puppet Users" group. To unsubscribe from this group and stop receiving emails from it, send an email to puppet-users+unsubscribe@googlegroups.com. To post to this group, send email to puppet-users@googlegroups.com. Visit this group at http://groups.google.com/group/puppet-users?hl=en. For more options, visit https://groups.google.com/groups/opt_out.