troubleshooting looong cfengine run times

[Aleksey Tsalolikhin]

OK, so how do we troubleshoot loooong cf-agent run times?

I have a report of a VM where CFEngine is sucking up CPU, and included in the report is a screenshot from "top" showing five cf-agent processes.

I look in promise-summary.log and see that policy runs usually take < 20 seconds but sometimes take as long as 5 minutes.

Nothing out of the ordinary in the outputs/ directory.

How do I turn on "timings" ?

For example, strace has:

       -t          Prefix each line of the trace with the time of day.

       -tt         If given twice, the time printed will include the microseconds.

       -ttt        If given thrice, the time printed will include the microseconds  and

                   the  leading  portion will be printed as the number of seconds since

                   the epoch.

       -T          Show the time spent in system calls. This records the  time  differ-

                   ence between the beginning and the end of each system call.

Is there a way to show time spent in each bundle?  I'm running 3.6.6 but we can update to 3.7 if it has per-bundle timing. (However I don't see anything about it in the ChangeLog.)

I've played around with https://github.com/lpefferkorn/cfe-profiler and am watching https://dev.cfengine.com/issues/3607 but I don't want to switch away from vendor packages to ones I build myself...  I can jury-right cf-execd to call cfe-profiler if I have to, but I'd rather get a clean build from the vendor that does this out of the box, right?

Yours,

--

Aleksey Tsalolikhin

CFEngine Training & Consulting

Vertical Sysadmin, Inc.

+1-323-393-0779

[Neil Watson]

There is timing in 3.7:

cf-agent -Kvtf ./tap.cf|grep 'T:'

verbose: T: time measurement for stated object (promise or bundle)
verbose: T: This measurement event, alias 'default:efl_test_simple', measured at time Tue Sep 1 21:59:53 2015
verbose: T: Last measured 35.000000 seconds ago
verbose: T: This execution measured 0.009754 seconds
verbose: T: Average execution time 0.009551 +/- 0.009773 seconds
verbose: T: .........................................................
verbose: T: Promise timing summary for any
verbose: T: No measurement_class attribute set in action body
verbose: T: This execution measured 0.058587 seconds (use measurement_class to track)
verbose: T: .........................................................
verbose: T: This measurement event, alias 'default:main', measured at time Tue Sep 1 21:59:53 2015
verbose: T: Last measured 35.000000 seconds ago
verbose: T: This execution measured 0.059266 seconds
verbose: T: Average execution time 0.075145 +/- 0.040511 seconds


--
Neil H Watson
Sr. Partner, Architecture and Infrastructure
CFEngine reporting: https://github.com/evolvethinking/delta_reporting
CFEngine policy: https://github.com/evolvethinking/evolve_cfengine_freelib
CFEngine and vim: https://github.com/neilhwatson/vim_cf3
CFEngine support: http://evolvethinking.com

[Brian Bennett]

I would want to know what it's children are. Run `ps fax` to see the process hierarchy. There's almost certainly a child process that's hanging the parent.

-- 
Brian Bennett
Looking for CFEngine training?
http://www.verticalsysadmin.com/

--
You received this message because you are subscribed to the Google Groups "help-cfengine" group.
To unsubscribe from this group and stop receiving emails from it, send an email to help-cfengin...@googlegroups.com.
To post to this group, send email to help-c...@googlegroups.com.
Visit this group at http://groups.google.com/group/help-cfengine.
For more options, visit https://groups.google.com/d/optout.

[Aleksey Tsalolikhin]

Thanks Neil and Brian!  Yeah, I've requested pstree output to get the process hierarchy.  I may put 3.7 on that one host to get the timing information...