On Fri, Mar 1, 2013 at 11:25 AM, Olivier Trempe <[email protected]>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 [email protected].
>> > 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 [email protected].
> To post to this group, send email to [email protected].
> 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 [email protected].
To post to this group, send email to [email protected].
Visit this group at http://groups.google.com/group/puppet-users?hl=en.
For more options, visit https://groups.google.com/groups/opt_out.
