Glenn Poston
2013-Nov-28 05:17 UTC
[Puppet Users] external facts cause puppet apply to take inordinately longer to run
My external fact script takes 5s to run. With external fact... puppet takes 2.5m to run facter takes 33s to run Without external fact... puppet takes 27s to run facter takes 0.68s Bottom line... there''s no significant change in facter runtime when parsing the external fact, but the puppet runtime quadruples. From watching the logs in real time I can see that the extra time is taken before puppet outputs its first response line (compilation time). Also note that the compilation time that puppet reports is ~2s even though (when watching the output realtime) it takes 2 minutes for that line to return when puppet is parsing the external fact script. Note: This script generates 36 custom facts Should I submit a bug for this? #Time of external fact script [root@fisheye-10-0-2-15 manifests]# time /etc/facter/facts.d/service_discovery.sh environment=test ... service_discovery_script=ran real 0m5.478s user 0m0.053s sys 0m0.111s # Time of puppet run with external fact [root@fisheye-10-0-2-15 manifests]# time FACTER_environment=''vagrant'' FACTER_role=''fisheye'' puppet apply --modulepath ''/etc/puppet/modules:/tmp/vagrant-puppet/modules-0'' site.ppNotice: Compiled catalog for fisheye-10-0-2-15.inin.com in environment production in 2.22 seconds Notice: Finished catalog run in 30.76 seconds real 2m25.856s user 0m5.124s sys 0m3.830s #Time of facter with external fact [root@fisheye-10-0-2-15 manifests]# time facter analyticsapisegmentindexconsusmerwaittimeseconds => 1 architecture => x86_64 ... uptime_hours => 0 uptime_seconds => 2529 real 0m33.587s user 0m0.658s sys 0m0.849s #Removing external fact script [root@fisheye-10-0-2-15 manifests]# rm /etc/facter/facts.d/service_discovery.sh rm: remove regular file `/etc/facter/facts.d/service_discovery.sh''? y [root@fisheye-10-0-2-15 manifests]# ls /etc/facter/facts.d/ #Time of puppet run without external fact script [root@fisheye-10-0-2-15 manifests]# time FACTER_environment=''vagrant'' FACTER_role=''fisheye'' puppet apply --modulepath ''/etc/puppet/modules:/tmp/vagrant-puppet/modules-0'' site.pp Notice: Compiled catalog for fisheye-10-0-2-15.inin.com in environment production in 2.06 seconds Notice: /Stage[main]/System::Facts/Facter::Fact[service_discovery]/File[/etc/facter/facts.d/service_discovery.sh]/ensure: created Notice: Finished catalog run in 23.22 seconds real 0m27.550s user 0m4.408s sys 0m2.292s # Removing script again (cuz puppet run put it back) [root@fisheye-10-0-2-15 manifests]# rm /etc/facter/facts.d/service_discovery.sh rm: remove regular file `/etc/facter/facts.d/service_discovery.sh''? y [root@fisheye-10-0-2-15 manifests]# ls /etc/facter/facts.d/ #Time of facter run without external script [root@fisheye-10-0-2-15 manifests]# time facter architecture => x86_64 augeasversion => 0.9.0 ... virtual => virtualbox real 0m0.687s user 0m0.324s sys 0m0.287s -- 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 view this discussion on the web visit https://groups.google.com/d/msgid/puppet-users/264663b8-a346-4b02-8373-3f822b57c882%40googlegroups.com. For more options, visit https://groups.google.com/groups/opt_out.
Glenn Poston
2013-Dec-03 03:15 UTC
[Puppet Users] Re: external facts cause puppet apply to take inordinately longer to run
Any ideas anyone? [vagrant@fisheye-10-0-2-15 ~]$ facter --version 1.7.3 [vagrant@fisheye-10-0-2-15 ~]$ puppet --version 3.3.2 On Thursday, November 28, 2013 12:17:44 AM UTC-5, Glenn Poston wrote:> > My external fact script takes 5s to run. > > With external fact... > puppet takes 2.5m to run > facter takes 33s to run > > Without external fact... > puppet takes 27s to run > facter takes 0.68s > > Bottom line... there''s no significant change in facter runtime when > parsing the external fact, but the puppet runtime quadruples. > > From watching the logs in real time I can see that the extra time is taken > before puppet outputs its first response line (compilation time). Also > note that the compilation time that puppet reports is ~2s even though (when > watching the output realtime) it takes 2 minutes for that line to return > when puppet is parsing the external fact script. > > Note: This script generates 36 custom facts > > Should I submit a bug for this? > > #Time of external fact script > [root@fisheye-10-0-2-15 manifests]# time > /etc/facter/facts.d/service_discovery.sh > environment=test > ... > service_discovery_script=ran > > real 0m5.478s > user 0m0.053s > sys 0m0.111s > > # Time of puppet run with external fact > [root@fisheye-10-0-2-15 manifests]# time FACTER_environment=''vagrant'' > FACTER_role=''fisheye'' puppet apply --modulepath > ''/etc/puppet/modules:/tmp/vagrant-puppet/modules-0'' site.ppNotice: Compiled > catalog for fisheye-10-0-2-15.inin.com in environment production in 2.22 > seconds > Notice: Finished catalog run in 30.76 seconds > > real 2m25.856s > user 0m5.124s > sys 0m3.830s > > #Time of facter with external fact > [root@fisheye-10-0-2-15 manifests]# time facter > analyticsapisegmentindexconsusmerwaittimeseconds => 1 > architecture => x86_64 > ... > uptime_hours => 0 > uptime_seconds => 2529 > > real 0m33.587s > user 0m0.658s > sys 0m0.849s > > #Removing external fact script > [root@fisheye-10-0-2-15 manifests]# rm > /etc/facter/facts.d/service_discovery.sh > rm: remove regular file `/etc/facter/facts.d/service_discovery.sh''? y > [root@fisheye-10-0-2-15 manifests]# ls /etc/facter/facts.d/ > > #Time of puppet run without external fact script > [root@fisheye-10-0-2-15 manifests]# time FACTER_environment=''vagrant'' > FACTER_role=''fisheye'' puppet apply --modulepath > ''/etc/puppet/modules:/tmp/vagrant-puppet/modules-0'' site.pp > Notice: Compiled catalog for fisheye-10-0-2-15.inin.com in environment > production in 2.06 seconds > Notice: > /Stage[main]/System::Facts/Facter::Fact[service_discovery]/File[/etc/facter/facts.d/service_discovery.sh]/ensure: > created > Notice: Finished catalog run in 23.22 seconds > > real 0m27.550s > user 0m4.408s > sys 0m2.292s > > # Removing script again (cuz puppet run put it back) > [root@fisheye-10-0-2-15 manifests]# rm > /etc/facter/facts.d/service_discovery.sh > rm: remove regular file `/etc/facter/facts.d/service_discovery.sh''? y > [root@fisheye-10-0-2-15 manifests]# ls /etc/facter/facts.d/ > > #Time of facter run without external script > [root@fisheye-10-0-2-15 manifests]# time facter > architecture => x86_64 > augeasversion => 0.9.0 > ... > virtual => virtualbox > > real 0m0.687s > user 0m0.324s > sys 0m0.287s >-- 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 view this discussion on the web visit https://groups.google.com/d/msgid/puppet-users/76d164e0-5826-4b2e-89b7-bbd00f12c6e2%40googlegroups.com. For more options, visit https://groups.google.com/groups/opt_out.
jcbollinger
2013-Dec-03 16:08 UTC
[Puppet Users] Re: external facts cause puppet apply to take inordinately longer to run
On Wednesday, November 27, 2013 11:17:44 PM UTC-6, Glenn Poston wrote:> > My external fact script takes 5s to run. > > With external fact... > puppet takes 2.5m to run > facter takes 33s to run > > Without external fact... > puppet takes 27s to run > facter takes 0.68s > > Bottom line... there''s no significant change in facter runtime when > parsing the external fact, but the puppet runtime quadruples. >Well, no significant change in facter''s runtime give or take a factor of x50. What''s two orders of magnitude between friends? Really, a five-second runtime for a fact is pretty extreme, but even that seems not to match the timings you report -- it looks more like your external fact takes 32 seconds to run. In the past, Puppet has sometimes had issues with unnecessarily evaluating facts more than once, so perhaps such an issue is magnifying the effect of your slow fact. Or perhaps the fact value is extremely large. Or maybe evaluating the fact leaves the node in a state that slows or delays communication with the master. It is probably worth your while to run the agent with the "--test --evaltrace" options to get a more detailed breakdown of how the time is being consumed. Please post the whole timing report. Also, it might be helpful to know what your external fact script is actually doing. Are you at liberty to post that?> > From watching the logs in real time I can see that the extra time is taken > before puppet outputs its first response line (compilation time). Also > note that the compilation time that puppet reports is ~2s even though (when > watching the output realtime) it takes 2 minutes for that line to return > when puppet is parsing the external fact script. > > Note: This script generates 36 custom facts > > Should I submit a bug for this? > >I think that would be premature at this time. The issue is likely to be tied to details of your external fact script, so although there may indeed be a bug to report, I don''t think we know yet what it might be. John -- 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 view this discussion on the web visit https://groups.google.com/d/msgid/puppet-users/fe6a462d-77d9-4058-ad37-58d6a7dd667b%40googlegroups.com. For more options, visit https://groups.google.com/groups/opt_out.
Glenn Poston
2013-Dec-03 17:30 UTC
[Puppet Users] Re: external facts cause puppet apply to take inordinately longer to run
On Tuesday, December 3, 2013 11:08:33 AM UTC-5, jcbollinger wrote:> > > > On Wednesday, November 27, 2013 11:17:44 PM UTC-6, Glenn Poston wrote: >> >> My external fact script takes 5s to run. >> >> With external fact... >> puppet takes 2.5m to run >> facter takes 33s to run >> >> Without external fact... >> puppet takes 27s to run >> facter takes 0.68s >> >> Bottom line... there''s no significant change in facter runtime when >> parsing the external fact, but the puppet runtime quadruples. >> > > > Well, no significant change in facter''s runtime give or take a factor of > x50. What''s two orders of magnitude between friends? > > Really, a five-second runtime for a fact is pretty extreme, but even that > seems not to match the timings you report -- it looks more like your > external fact takes 32 seconds to run. >When I run the external fact script by itself it takes 5s to run. Facter takes 32 seconds longer to run. Here''s the timing data for the run of the script outside of facter: #Time of external fact script [root@fisheye-10-0-2-15 manifests]# time /etc/facter/facts.d/service_discovery.sh environment=test ... service_discovery_script=ran real 0m5.478s user 0m0.053s sys 0m0.111s> > In the past, Puppet has sometimes had issues with unnecessarily evaluating > facts more than once, so perhaps such an issue is magnifying the effect of > your slow fact. Or perhaps the fact value is extremely large. Or maybe > evaluating the fact leaves the node in a state that slows or delays > communication with the master. >I would agree that a good theory is that puppet is unnecessarily evaluating facts more than once. Also, these puppet runs are in standalone mode, so the master is not an issue. The script will resolve 32 facts. Each fact has a key that is less than 20 characters and a value that is less than 100 characters.> > It is probably worth your while to run the agent with the "--test > --evaltrace" options to get a more detailed breakdown of how the time is > being consumed. Please post the whole timing report. >Since we''re running puppet in standalone mode, --test and --evaltrace aren''t available. I ran in --debug mode, but there''s nothing being output about facter resolution so that wasn''t very helpful.> > Also, it might be helpful to know what your external fact script is > actually doing. Are you at liberty to post that? >The fact is making a curl request to a static file in AWS S3 that contains the key/value pairs. Here is the external fact script (URL''s have been changed) #!/bin/bash curl -s https://s3.amazonaws.com/blah/blah/blah | while read line; do key=`echo $line | cut -d = -f 1 | sed ''s/\./_/g''` val=`echo $line | cut -d = -f 2` echo $key=$val done echo "service_discovery_script=ran"> > >> >> From watching the logs in real time I can see that the extra time is >> taken before puppet outputs its first response line (compilation time). >> Also note that the compilation time that puppet reports is ~2s even though >> (when watching the output realtime) it takes 2 minutes for that line to >> return when puppet is parsing the external fact script. >> >> Note: This script generates 36 custom facts >> >> Should I submit a bug for this? >> >> > > I think that would be premature at this time. The issue is likely to be > tied to details of your external fact script, so although there may indeed > be a bug to report, I don''t think we know yet what it might be. > > > John > >-- 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 view this discussion on the web visit https://groups.google.com/d/msgid/puppet-users/38190418-6036-494b-840d-ac4d07dc4bde%40googlegroups.com. For more options, visit https://groups.google.com/groups/opt_out.
R.I.Pienaar
2013-Dec-03 17:33 UTC
Re: [Puppet Users] Re: external facts cause puppet apply to take inordinately longer to run
----- Original Message -----> From: "Glenn Poston" <gposton1040@gmail.com> > To: puppet-users@googlegroups.com > Sent: Tuesday, December 3, 2013 5:30:30 PM > Subject: [Puppet Users] Re: external facts cause puppet apply to take inordinately longer to run > > > > On Tuesday, December 3, 2013 11:08:33 AM UTC-5, jcbollinger wrote: > > > > > > > > On Wednesday, November 27, 2013 11:17:44 PM UTC-6, Glenn Poston wrote: > >> > >> My external fact script takes 5s to run. > >> > >> With external fact... > >> puppet takes 2.5m to run > >> facter takes 33s to run > >> > >> Without external fact... > >> puppet takes 27s to run > >> facter takes 0.68s > >> > >> Bottom line... there''s no significant change in facter runtime when > >> parsing the external fact, but the puppet runtime quadruples. > >> > > > > > > Well, no significant change in facter''s runtime give or take a factor of > > x50. What''s two orders of magnitude between friends? > > > > Really, a five-second runtime for a fact is pretty extreme, but even that > > seems not to match the timings you report -- it looks more like your > > external fact takes 32 seconds to run. > > > > When I run the external fact script by itself it takes 5s to run. Facter > takes 32 seconds longer to run. > > Here''s the timing data for the run of the script outside of facter: > > #Time of external fact script > [root@fisheye-10-0-2-15 manifests]# time > /etc/facter/facts.d/service_discovery.sh > environment=test > ... > service_discovery_script=ran > > real 0m5.478s > user 0m0.053s > sys 0m0.111s >there was either a thread here or a ticket files that puppet will run external facts as much as 5 times over for a single run, might be worth adding some debug logging to a file or something you in your fact to see if this is the case? -- 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 view this discussion on the web visit https://groups.google.com/d/msgid/puppet-users/2115610401.1064.1386092015565.JavaMail.zimbra%40devco.net. For more options, visit https://groups.google.com/groups/opt_out.
Stuart Cracraft
2013-Dec-03 17:55 UTC
[Puppet Users] Re: external facts cause puppet apply to take inordinately longer to run
Scary. On Wednesday, November 27, 2013 9:17:44 PM UTC-8, Glenn Poston wrote:> > My external fact script takes 5s to run. > > With external fact... > puppet takes 2.5m to run > facter takes 33s to run > > Without external fact... > puppet takes 27s to run > facter takes 0.68s > > Bottom line... there''s no significant change in facter runtime when > parsing the external fact, but the puppet runtime quadruples. > > From watching the logs in real time I can see that the extra time is taken > before puppet outputs its first response line (compilation time). Also > note that the compilation time that puppet reports is ~2s even though (when > watching the output realtime) it takes 2 minutes for that line to return > when puppet is parsing the external fact script. > > Note: This script generates 36 custom facts > > Should I submit a bug for this? > > #Time of external fact script > [root@fisheye-10-0-2-15 manifests]# time > /etc/facter/facts.d/service_discovery.sh > environment=test > ... > service_discovery_script=ran > > real 0m5.478s > user 0m0.053s > sys 0m0.111s > > # Time of puppet run with external fact > [root@fisheye-10-0-2-15 manifests]# time FACTER_environment=''vagrant'' > FACTER_role=''fisheye'' puppet apply --modulepath > ''/etc/puppet/modules:/tmp/vagrant-puppet/modules-0'' site.ppNotice: Compiled > catalog for fisheye-10-0-2-15.inin.com in environment production in 2.22 > seconds > Notice: Finished catalog run in 30.76 seconds > > real 2m25.856s > user 0m5.124s > sys 0m3.830s > > #Time of facter with external fact > [root@fisheye-10-0-2-15 manifests]# time facter > analyticsapisegmentindexconsusmerwaittimeseconds => 1 > architecture => x86_64 > ... > uptime_hours => 0 > uptime_seconds => 2529 > > real 0m33.587s > user 0m0.658s > sys 0m0.849s > > #Removing external fact script > [root@fisheye-10-0-2-15 manifests]# rm > /etc/facter/facts.d/service_discovery.sh > rm: remove regular file `/etc/facter/facts.d/service_discovery.sh''? y > [root@fisheye-10-0-2-15 manifests]# ls /etc/facter/facts.d/ > > #Time of puppet run without external fact script > [root@fisheye-10-0-2-15 manifests]# time FACTER_environment=''vagrant'' > FACTER_role=''fisheye'' puppet apply --modulepath > ''/etc/puppet/modules:/tmp/vagrant-puppet/modules-0'' site.pp > Notice: Compiled catalog for fisheye-10-0-2-15.inin.com in environment > production in 2.06 seconds > Notice: > /Stage[main]/System::Facts/Facter::Fact[service_discovery]/File[/etc/facter/facts.d/service_discovery.sh]/ensure: > created > Notice: Finished catalog run in 23.22 seconds > > real 0m27.550s > user 0m4.408s > sys 0m2.292s > > # Removing script again (cuz puppet run put it back) > [root@fisheye-10-0-2-15 manifests]# rm > /etc/facter/facts.d/service_discovery.sh > rm: remove regular file `/etc/facter/facts.d/service_discovery.sh''? y > [root@fisheye-10-0-2-15 manifests]# ls /etc/facter/facts.d/ > > #Time of facter run without external script > [root@fisheye-10-0-2-15 manifests]# time facter > architecture => x86_64 > augeasversion => 0.9.0 > ... > virtual => virtualbox > > real 0m0.687s > user 0m0.324s > sys 0m0.287s >-- 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 view this discussion on the web visit https://groups.google.com/d/msgid/puppet-users/84604e29-a050-4fbd-aad8-72c555452193%40googlegroups.com. For more options, visit https://groups.google.com/groups/opt_out.
Glenn Poston
2013-Dec-03 18:01 UTC
[Puppet Users] Re: external facts cause puppet apply to take inordinately longer to run
I was curious how much of an effect the long running external fact was effecting the timing, so I updated the external fact script to simply echo the content (instead of fetching it from s3). The facts it produced were the same as if it had fetched the facts from S3. I then introduced a ''sleep x'' before the echo statement in the script. Now we see some compounding delays. I think this adds a bit of support to the theory that puppet is unnecessarily re-evaluating facts, but it appears that facter may have some compounding delays as well. Bottom Line: When the script resolves instantaneously (echo statment only) script takes .004s facter takes .754s puppet takes 1m When the script takes 1s (sleep 1, then echo) script takes 1s facter takes 6s puppet takes 1m12s When the script takes 5s (sleep 5, then echo) script takes 5s facter takes 30s puppet takes 2m38s -- 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 view this discussion on the web visit https://groups.google.com/d/msgid/puppet-users/15127c27-91d5-452a-b322-af2b783d42fa%40googlegroups.com. For more options, visit https://groups.google.com/groups/opt_out.
Josh Cooper
2013-Dec-03 18:15 UTC
Re: [Puppet Users] Re: external facts cause puppet apply to take inordinately longer to run
On Tue, Dec 3, 2013 at 10:01 AM, Glenn Poston <gposton1040@gmail.com> wrote:> I was curious how much of an effect the long running external fact was > effecting the timing, so I updated the external fact script to simply echo > the content (instead of fetching it from s3). The facts it produced were > the same as if it had fetched the facts from S3. > > I then introduced a ''sleep x'' before the echo statement in the script. > Now we see some compounding delays. I think this adds a bit of support to > the theory that puppet is unnecessarily re-evaluating facts, but it appears > that facter may have some compounding delays as well. > > Bottom Line: > > When the script resolves instantaneously (echo statment only) > script takes .004s > facter takes .754s > puppet takes 1m > > When the script takes 1s (sleep 1, then echo) > script takes 1s > facter takes 6s > puppet takes 1m12s > > When the script takes 5s (sleep 5, then echo) > script takes 5s > facter takes 30s > puppet takes 2m38s > > -- > 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 view this discussion on the web visit > https://groups.google.com/d/msgid/puppet-users/15127c27-91d5-452a-b322-af2b783d42fa%40googlegroups.com > . > > For more options, visit https://groups.google.com/groups/opt_out. >This is https://projects.puppetlabs.com/issues/22944. Facter will execute external facts multiple times. I''ve seen it as little as 6 on Mac and 19 on Windows. We are working on a fix for this to be released in 1.7.4. 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 view this discussion on the web visit https://groups.google.com/d/msgid/puppet-users/CA%2Bu97u%3DC0OSukwjabDBUegG%2BaYyFFGJY2qd%2BFBPYAsBf9YG%2BFg%40mail.gmail.com. For more options, visit https://groups.google.com/groups/opt_out.
Glenn Poston
2013-Dec-03 18:18 UTC
[Puppet Users] Re: external facts cause puppet apply to take inordinately longer to run
This bug has been reported, but I think it''s severity is understated. Please vote for these bugs. https://projects.puppetlabs.com/issues/22944 -> original https://projects.puppetlabs.com/issues/23335 -> mine (duplicate) -- 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 view this discussion on the web visit https://groups.google.com/d/msgid/puppet-users/e7ffbceb-32ca-4fe7-b90a-f75aaccf2f43%40googlegroups.com. For more options, visit https://groups.google.com/groups/opt_out.
Glenn Poston
2013-Dec-03 18:22 UTC
Re: [Puppet Users] Re: external facts cause puppet apply to take inordinately longer to run
I hope no one takes this personally, but I''ve got to ask. I''ve been using external facts for 3 years. I started with facts-dot-d (which I''m sure you''re familiar with :). This issue did not exist when I was using that beautiful little gem. Why the re-write/integration when it worked perfectly fine? On Tuesday, December 3, 2013 12:33:35 PM UTC-5, R.I. Pienaar wrote:> > > > ----- Original Message ----- > > From: "Glenn Poston" <gpost...@gmail.com <javascript:>> > > To: puppet...@googlegroups.com <javascript:> > > Sent: Tuesday, December 3, 2013 5:30:30 PM > > Subject: [Puppet Users] Re: external facts cause puppet apply to take > inordinately longer to run > > > > > > > > On Tuesday, December 3, 2013 11:08:33 AM UTC-5, jcbollinger wrote: > > > > > > > > > > > > On Wednesday, November 27, 2013 11:17:44 PM UTC-6, Glenn Poston wrote: > > >> > > >> My external fact script takes 5s to run. > > >> > > >> With external fact... > > >> puppet takes 2.5m to run > > >> facter takes 33s to run > > >> > > >> Without external fact... > > >> puppet takes 27s to run > > >> facter takes 0.68s > > >> > > >> Bottom line... there''s no significant change in facter runtime when > > >> parsing the external fact, but the puppet runtime quadruples. > > >> > > > > > > > > > Well, no significant change in facter''s runtime give or take a factor > of > > > x50. What''s two orders of magnitude between friends? > > > > > > Really, a five-second runtime for a fact is pretty extreme, but even > that > > > seems not to match the timings you report -- it looks more like your > > > external fact takes 32 seconds to run. > > > > > > > When I run the external fact script by itself it takes 5s to run. > Facter > > takes 32 seconds longer to run. > > > > Here''s the timing data for the run of the script outside of facter: > > > > #Time of external fact script > > [root@fisheye-10-0-2-15 manifests]# time > > /etc/facter/facts.d/service_discovery.sh > > environment=test > > ... > > service_discovery_script=ran > > > > real 0m5.478s > > user 0m0.053s > > sys 0m0.111s > > > > there was either a thread here or a ticket files that puppet will run > external facts > as much as 5 times over for a single run, might be worth adding some debug > logging > to a file or something you in your fact to see if this is the case? >-- 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 view this discussion on the web visit https://groups.google.com/d/msgid/puppet-users/4a9aa501-8e26-49c7-b7c0-801d44227156%40googlegroups.com. For more options, visit https://groups.google.com/groups/opt_out.
Glenn Poston
2013-Dec-03 18:24 UTC
Re: [Puppet Users] Re: external facts cause puppet apply to take inordinately longer to run
Thanks Josh... I made some comments on that ticket and added a vote. On Tuesday, December 3, 2013 1:15:49 PM UTC-5, Josh Cooper wrote:> > > > > On Tue, Dec 3, 2013 at 10:01 AM, Glenn Poston <gpost...@gmail.com<javascript:> > > wrote: > >> I was curious how much of an effect the long running external fact was >> effecting the timing, so I updated the external fact script to simply echo >> the content (instead of fetching it from s3). The facts it produced were >> the same as if it had fetched the facts from S3. >> >> I then introduced a ''sleep x'' before the echo statement in the script. >> Now we see some compounding delays. I think this adds a bit of support to >> the theory that puppet is unnecessarily re-evaluating facts, but it appears >> that facter may have some compounding delays as well. >> >> Bottom Line: >> >> When the script resolves instantaneously (echo statment only) >> script takes .004s >> facter takes .754s >> puppet takes 1m >> >> When the script takes 1s (sleep 1, then echo) >> script takes 1s >> facter takes 6s >> puppet takes 1m12s >> >> When the script takes 5s (sleep 5, then echo) >> script takes 5s >> facter takes 30s >> puppet takes 2m38s >> >> -- >> 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 view this discussion on the web visit >> https://groups.google.com/d/msgid/puppet-users/15127c27-91d5-452a-b322-af2b783d42fa%40googlegroups.com >> . >> >> For more options, visit https://groups.google.com/groups/opt_out. >> > > This is https://projects.puppetlabs.com/issues/22944. Facter will execute > external facts multiple times. I''ve seen it as little as 6 on Mac and 19 on > Windows. We are working on a fix for this to be released in 1.7.4. > > 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 view this discussion on the web visit https://groups.google.com/d/msgid/puppet-users/83f71c91-20ea-466b-b034-988b14814666%40googlegroups.com. For more options, visit https://groups.google.com/groups/opt_out.