D 2013-04-30T04:12:12.315 L v1.5418\sprofile U matt W 25030 matt@xena:/opt/testing/megatest/tests$ chicken-profile /tmp/megatest.profile reading `/tmp/megatest.profile' ... procedure calls seconds average percent ----------------------------------------------------------------------------- launch:execute 1 0.072 0.072 100.000 cdb:client-call 26 0.040 0.001 55.555 http-transport:client-send-receive 26 0.036 0.001 50.000 read-config 10 0.036 0.003 50.000 configf:process-line 249 0.024 0.000 33.333 setup-for-run 2 0.024 0.012 33.333 find-and-read-config 2 0.024 0.012 33.333 cdb:get-test-info-by-id 6 0.020 0.003 27.777 tests:test-set-status! 4 0.020 0.004 27.777 tests:set-meta-info 2 0.020 0.010 27.777 open-run-close-no-exception-handling 2 0.016 0.008 22.222 client:setup 1 0.016 0.016 22.222 set-run-config-vars 1 0.016 0.016 22.222 client:launch 1 0.016 0.016 22.222 cmd-run->list 43 0.012 0.000 16.666 tests:update-central-meta-info 2 0.012 0.006 16.666 setup-env-defaults 1 0.012 0.012 16.666 cdb:tests-update-run-duration 2 0.008 0.004 11.111 port->list 43 0.004 0.000 5.555 config:eval-string-in-environment 31 0.004 0.000 5.555 db:obj->string 26 0.004 0.000 5.555 cdb:remote-run 9 0.004 0.000 5.555 db:open-test-db-by-test-id 4 0.004 0.000 5.555 open-test-db 4 0.004 0.000 5.555 cdb:test-set-status-state 4 0.004 0.000 5.555 set-megatest-env-vars 2 0.004 0.002 5.555 cdb:tests-update-cpuload-diskfree 2 0.004 0.002 5.555 get-cpu-load 2 0.004 0.002 5.555 db:testdb-initialize 1 0.004 0.004 5.555 save-environment-as-files 1 0.004 0.004 5.555 client:login 1 0.004 0.004 5.555 test-get-kill-request 1 0.004 0.004 5.555 http-transport:client-connect 1 0.004 0.004 5.555 cdb:login 1 0.004 0.004 5.555 db:get-key-vals 1 0.004 0.004 5.555 db:get-target 1 0.004 0.004 5.555 debug:debug-mode 585 0.000 0.000 0.000 debug:print-info 545 0.000 0.000 0.000 config:assoc-safe-add 77 0.000 0.000 0.000 conservative-read 69 0.000 0.000 0.000 debug:print 39 0.000 0.000 0.000 client:get-signature 27 0.000 0.000 0.000 db:string->obj 26 0.000 0.000 0.000 http-transport:make-server-url 26 0.000 0.000 0.000 assoc/default 18 0.000 0.000 0.000 config-lookup 8 0.000 0.000 0.000 nice-path 7 0.000 0.000 0.000 items:check-valid-items 4 0.000 0.000 0.000 alist->env-vars 3 0.000 0.000 0.000 get-uname 2 0.000 0.000 0.000 cdb:tests-update-uname-host 2 0.000 0.000 0.000 find-config 2 0.000 0.000 0.000 db:teststep-set-status! 2 0.000 0.000 0.000 test:tdb-get-rundat-count 2 0.000 0.000 0.000 get-df 2 0.000 0.000 0.000 runconfigs-get 2 0.000 0.000 0.000 cmd-run-proc-each-line-alt 1 0.000 0.000 0.000 tasks:hostinfo-get-transport 1 0.000 0.000 0.000 debug:calc-verbosity 1 0.000 0.000 0.000 tasks:hostinfo-get-port 1 0.000 0.000 0.000 args-defined? 1 0.000 0.000 0.000 tasks:hostinfo-get-interface 1 0.000 0.000 0.000 steprun-good? 1 0.000 0.000 0.000 tasks:get-best-server 1 0.000 0.000 0.000 debug:check-verbosity 1 0.000 0.000 0.000 set-item-env-vars 1 0.000 0.000 0.000 get-keys 1 0.000 0.000 0.000 db:set-sync 1 0.000 0.000 0.000 shell 1 0.000 0.000 0.000 open-db 1 0.000 0.000 0.000 debug:setup 1 0.000 0.000 0.000 tasks:open-db 1 0.000 0.000 0.000 make-tasks:task 0 0.000 0.000 0.000 db:delete-old-deleted-test-records 0 0.000 0.000 0.000 common:get-color-for-state-status 0 0.000 0.000 0.000 db:extract-ods-file 0 0.000 0.000 0.000 server:mk-signature 0 0.000 0.000 0.000 db:get-count-tests-running-in-jobgroup 0 0.000 0.000 0.000 keys->keystr 0 0.000 0.000 0.000 db:get-steps-table 0 0.000 0.000 0.000 args:usage 0 0.000 0.000 0.000 server:make-server-url 0 0.000 0.000 0.000 tasks:add-from-params 0 0.000 0.000 0.000 db:update-run-event_time 0 0.000 0.000 0.000 get-with-default 0 0.000 0.000 0.000 client:signal-handler 0 0.000 0.000 0.000 open-run-close-measure 0 0.000 0.000 0.000 tasks:get-tasks 0 0.000 0.000 0.000 db:log-local-event 0 0.000 0.000 0.000 any->number 0 0.000 0.000 0.000 patch-db 0 0.000 0.000 0.000 make-tests:testqueue 0 0.000 0.000 0.000 run-n-wait 0 0.000 0.000 0.000 db:set-tests-state-status 0 0.000 0.000 0.000 tasks:server-deregister-self 0 0.000 0.000 0.000 tasks:hostinfo-get-hostname 0 0.000 0.000 0.000 cdb:tests-register-test 0 0.000 0.000 0.000 args:get-arg-from 0 0.000 0.000 0.000 cdb:get-test-info 0 0.000 0.000 0.000 tasks:process-queue 0 0.000 0.000 0.000 make-db:testmeta 0 0.000 0.000 0.000 db:testmeta-get-record 0 0.000 0.000 0.000 db:test-set-state-status-by-run-id-testname 0 0.000 0.000 0.000 runs:update-test_meta 0 0.000 0.000 0.000 args:print-args 0 0.000 0.000 0.000 db:delete-test-step-records 0 0.000 0.000 0.000 db:get-tests-for-run 0 0.000 0.000 0.000 tests:match->sqlqry 0 0.000 0.000 0.000 process-itemlist 0 0.000 0.000 0.000 seconds->hr-min-sec 0 0.000 0.000 0.000 ods:column 0 0.000 0.000 0.000 db:test-get-records-for-index-file 0 0.000 0.000 0.000 tasks:remove-server-records 0 0.000 0.000 0.000 tasks:rollup-runs 0 0.000 0.000 0.000 run:test 0 0.000 0.000 0.000 db:test-set-state-status-by-id 0 0.000 0.000 0.000 get-dir-up-n 0 0.000 0.000 0.000 cdb:roll-up-pass-fail-counts 0 0.000 0.000 0.000 launch-test 0 0.000 0.000 0.000 cdb:pass-fail-counts 0 0.000 0.000 0.000 patt-list-match 0 0.000 0.000 0.000 db:get-prev-tol-for-test 0 0.000 0.000 0.000 synchash:get-delta 0 0.000 0.000 0.000 db:test-get-paths-matching-keynames-target 0 0.000 0.000 0.000 megatest:step 0 0.000 0.000 0.000 tasks:client-logout 0 0.000 0.000 0.000 db:get-keys 0 0.000 0.000 0.000 runs:handle-locking 0 0.000 0.000 0.000 common:name->iup-color 0 0.000 0.000 0.000 tasks:reset-stuck-tasks 0 0.000 0.000 0.000 db:test-get-rundir-from-test-id 0 0.000 0.000 0.000 db:test-get-logfile-info 0 0.000 0.000 0.000 ods:construct-dir 0 0.000 0.000 0.000 tests:test-set-toplog! 0 0.000 0.000 0.000 db:delete-run 0 0.000 0.000 0.000 tasks:server-update-heartbeat 0 0.000 0.000 0.000 launch:get-cmdinfo-assoc-list 0 0.000 0.000 0.000 db:get-key-val-pairs 0 0.000 0.000 0.000 db:del-var 0 0.000 0.000 0.000 common:get-disks 0 0.000 0.000 0.000 cdb:set-verbosity 0 0.000 0.000 0.000 cdb:kill-server 0 0.000 0.000 0.000 daemon:ize 0 0.000 0.000 0.000 item-table->item-list 0 0.000 0.000 0.000 tasks:client-register 0 0.000 0.000 0.000 runs:calc-fails 0 0.000 0.000 0.000 test:archive-tests 0 0.000 0.000 0.000 cdb:use-non-blocking-mode 0 0.000 0.000 0.000 cdb:delete-tests-in-state 0 0.000 0.000 0.000 tests:glob-like-match 0 0.000 0.000 0.000 tasks:server-alive? 0 0.000 0.000 0.000 cdb:flush-queue 0 0.000 0.000 0.000 db:get-steps-table-list 0 0.000 0.000 0.000 db:get-var 0 0.000 0.000 0.000 ods:make-thumbnail 0 0.000 0.000 0.000 tests:summarize-items 0 0.000 0.000 0.000 runs:get-std-run-fields 0 0.000 0.000 0.000 keys:target->keyval 0 0.000 0.000 0.000 db:test-data-rollup 0 0.000 0.000 0.000 tasks:server-delete 0 0.000 0.000 0.000 http-transport:server-signal-handler 0 0.000 0.000 0.000 tests:check-waiver-eligibility 0 0.000 0.000 0.000 items:get-items-from-config 0 0.000 0.000 0.000 db:process-queue-item 0 0.000 0.000 0.000 tests:sort-by-priority-and-waiton 0 0.000 0.000 0.000 test:archive 0 0.000 0.000 0.000 cmd-run-with-stderr->list 0 0.000 0.000 0.000 cmd-run-proc-each-line 0 0.000 0.000 0.000 tests:filter-non-runnable 0 0.000 0.000 0.000 db:testmeta-add-record 0 0.000 0.000 0.000 tasks:monitors-update 0 0.000 0.000 0.000 http-transport:launch 0 0.000 0.000 0.000 db:get-tests-for-runs 0 0.000 0.000 0.000 db:get-compressed-steps 0 0.000 0.000 0.000 tasks:start-run 0 0.000 0.000 0.000 db:estimated-tests-remaining 0 0.000 0.000 0.000 db:log-event 0 0.000 0.000 0.000 config-get-fields 0 0.000 0.000 0.000 test:get-matching-previous-test-run-records 0 0.000 0.000 0.000 runs:can-run-more-tests 0 0.000 0.000 0.000 test:get-previous-test-run-record 0 0.000 0.000 0.000 ods:add-non-content-files 0 0.000 0.000 0.000 tasks:snag-a-task 0 0.000 0.000 0.000 db:initialize 0 0.000 0.000 0.000 db:testmeta-update-field 0 0.000 0.000 0.000 make-tasks:monitor 0 0.000 0.000 0.000 db:clean-all-caches 0 0.000 0.000 0.000 db:read-test-data 0 0.000 0.000 0.000 common:get-color-from-status 0 0.000 0.000 0.000 db:csv->test-data 0 0.000 0.000 0.000 tasks:mark-server 0 0.000 0.000 0.000 http-transport:run 0 0.000 0.000 0.000 tasks:add 0 0.000 0.000 0.000 db:get-runs 0 0.000 0.000 0.000 tasks:set-state 0 0.000 0.000 0.000 open-logging-db 0 0.000 0.000 0.000 tasks:start-monitor 0 0.000 0.000 0.000 runs:operate-on 0 0.000 0.000 0.000 db:step-get-time-as-string 0 0.000 0.000 0.000 http-transport:try-start-server 0 0.000 0.000 0.000 open-run-close-exception-handling 0 0.000 0.000 0.000 db:register-run 0 0.000 0.000 0.000 db:lock/unlock-run 0 0.000 0.000 0.000 cdb:test-set-rundir! 0 0.000 0.000 0.000 make-db:test 0 0.000 0.000 0.000 operate-on 0 0.000 0.000 0.000 setup 0 0.000 0.000 0.000 common:get-runconfig-targets 0 0.000 0.000 0.000 db:get-value-by-header 0 0.000 0.000 0.000 db:get-num-runs 0 0.000 0.000 0.000 runs:get-runs-by-patt 0 0.000 0.000 0.000 db:get-run-key-val 0 0.000 0.000 0.000 runs:calc-not-completed 0 0.000 0.000 0.000 any->number-if-possible 0 0.000 0.000 0.000 configf:expand-multi-lines 0 0.000 0.000 0.000 db:test-get-paths-matching 0 0.000 0.000 0.000 tasks:hostinfo-get-id 0 0.000 0.000 0.000 db:patt->like 0 0.000 0.000 0.000 runs:run-tests 0 0.000 0.000 0.000 keys:key-vals-hash->target 0 0.000 0.000 0.000 make-db:test-data 0 0.000 0.000 0.000 configf:write-config 0 0.000 0.000 0.000 server:launch 0 0.000 0.000 0.000 runs:pretty-string 0 0.000 0.000 0.000 db:delete-tests-for-run 0 0.000 0.000 0.000 db:patch-tdb-data-into-test-info 0 0.000 0.000 0.000 db:get-test-id-not-cached 0 0.000 0.000 0.000 tasks:have-clients? 0 0.000 0.000 0.000 tasks:monitors->text-table 0 0.000 0.000 0.000 tasks:register-monitor 0 0.000 0.000 0.000 cdb:num-clients 0 0.000 0.000 0.000 db:set-var 0 0.000 0.000 0.000 configf:get-section 0 0.000 0.000 0.000 db:queue-write-and-wait 0 0.000 0.000 0.000 make-db:steps-table 0 0.000 0.000 0.000 server:reply 0 0.000 0.000 0.000 db:get-test-info-by-ids 0 0.000 0.000 0.000 db:get-steps-for-test 0 0.000 0.000 0.000 ods:sheet 0 0.000 0.000 0.000 tasks:get-all-servers 0 0.000 0.000 0.000 configf:compress-multi-lines 0 0.000 0.000 0.000 db:get-test-info-by-id 0 0.000 0.000 0.000 tasks:remove-monitor-record 0 0.000 0.000 0.000 configf:section-vars 0 0.000 0.000 0.000 tests:get-testconfig 0 0.000 0.000 0.000 keys->alist 0 0.000 0.000 0.000 tasks:tasks->text 0 0.000 0.000 0.000 server:get-best-guess-address 0 0.000 0.000 0.000 make-db:mintest 0 0.000 0.000 0.000 db:get-run-name-from-id 0 0.000 0.000 0.000 fs:process-queue-item 0 0.000 0.000 0.000 item-assoc->item-list 0 0.000 0.000 0.000 keys->vallist 0 0.000 0.000 0.000 tasks:server-register 0 0.000 0.000 0.000 genexample:mk-megatest-test 0 0.000 0.000 0.000 tests:match 0 0.000 0.000 0.000 tasks:get-num-alive-monitors 0 0.000 0.000 0.000 ods:row 0 0.000 0.000 0.000 general-run-call 0 0.000 0.000 0.000 common:clear-caches 0 0.000 0.000 0.000 configf:file->list 0 0.000 0.000 0.000 cdb:test-rollup-test_data-pass-fail 0 0.000 0.000 0.000 runs:rollup-run 0 0.000 0.000 0.000 db:get-tests-for-runs-mindata 0 0.000 0.000 0.000 tests:get-valid-tests 0 0.000 0.000 0.000 db:test-get-first-path-matching 0 0.000 0.000 0.000 synchash:server-get 0 0.000 0.000 0.000 get-all-legal-tests 0 0.000 0.000 0.000 runs:test-get-full-path 0 0.000 0.000 0.000 create-work-area 0 0.000 0.000 0.000 keys:target-set-args 0 0.000 0.000 0.000 runs:shrink-can-run-more-tests-delay 0 0.000 0.000 0.000 client:logout 0 0.000 0.000 0.000 ods:cell 0 0.000 0.000 0.000 cdb:test-set-rundir-by-test-id 0 0.000 0.000 0.000 http-transport:keep-running 0 0.000 0.000 0.000 tasks:get-monitors 0 0.000 0.000 0.000 args:get-arg 0 0.000 0.000 0.000 genexample:mk-megatest.config 0 0.000 0.000 0.000 get-best-disk 0 0.000 0.000 0.000 db:process-cached-writes 0 0.000 0.000 0.000 tasks:kill-server 0 0.000 0.000 0.000 runs:make-full-test-name 0 0.000 0.000 0.000 db:get-run-info 0 0.000 0.000 0.000 make-cdb:packet 0 0.000 0.000 0.000 ods:list->ods 0 0.000 0.000 0.000 port-proc->list 0 0.000 0.000 0.000 synchash:client-get 0 0.000 0.000 0.000 seconds->time-string 0 0.000 0.000 0.000 db:delete-test-records 0 0.000 0.000 0.000 tasks:hostinfo-get-pubport 0 0.000 0.000 0.000 tasks:server-deregister 0 0.000 0.000 0.000 cdb:test-set-log! 0 0.000 0.000 0.000 server:write-queue-handler 0 0.000 0.000 0.000 keystring->keys 0 0.000 0.000 0.000 db:load-test-data 0 0.000 0.000 0.000 db:roll-up-pass-fail-counts 0 0.000 0.000 0.000 tasks:hostinfo-get-pid 0 0.000 0.000 0.000 make-db:step 0 0.000 0.000 0.000 cdb:logout 0 0.000 0.000 0.000 runs:run-tests-queue 0 0.000 0.000 0.000 runs:update-all-test_meta 0 0.000 0.000 0.000 db:get-test-info 0 0.000 0.000 0.000 tasks:remove-queue-entries 0 0.000 0.000 0.000 tasks:server-get-server-id 0 0.000 0.000 0.000 tasks:get-logged-in-clients 0 0.000 0.000 0.000 db:get-test-id-cached 0 0.000 0.000 0.000 args:get-args 0 0.000 0.000 0.000 db:get-prereqs-not-met 0 0.000 0.000 0.000 synchash:make 0 0.000 0.000 0.000 db:test-set-comment 0 0.000 0.000 0.000 db:get-count-tests-running 0 0.000 0.000 0.000 db:set-comment-for-run 0 0.000 0.000 0.000 Z 5147708a49b9cd1a8d30453984849749