On Fri, Mar 1, 2013 at 11:25 AM, Olivier Trempe <oliviertre...@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+unsubscr...@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+unsubscr...@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.
