Changeset 7954


Ignore:
Timestamp:
Dec 26, 2007, 8:03:26 AM (12 years ago)
Author:
gb
Message:

Time-reporting changes.

File:
1 edited

Legend:

Unmodified
Added
Removed
  • branches/working-0711/ccl/lib/misc.lisp

    r7652 r7954  
    373373   :FORM              the form that was executed
    374374   :RESULTS           a list of all values returned by the execution of FORM
    375    :ELAPSED-TIME      total elapsed (real) time, in milliseconds
    376    :USER-TIME         elapsed user time, in milliseconds
    377    :SYSTEM-TIME       elapsed system time, in milliseconds
    378    :GC-TIME           total real time spent in the GC, in milliseconds
     375   :ELAPSED-TIME      total elapsed (real) time, in internal-time-units-per-second
     376   :USER-TIME         elapsed user time, in internal-time-units-per-second
     377   :SYSTEM-TIME       elapsed system time, in internal-time-units-per-second
     378   :GC-TIME           total real time spent in the GC, in internal-time-units-per-second
    379379   :BYTES-ALLOCATED   total bytes allocated
    380380   :MINOR-PAGE-FAULTS minor page faults
     
    388388                                  swaps)
    389389  (let* ((s *trace-output*)
     390         (units
     391          (ecase internal-time-units-per-second
     392            (1000000 "microseconds")
     393            (1000  "milliseconds")))
     394         (width
     395          (ecase internal-time-units-per-second
     396            (1000000 6)
     397            (100  3)))
    390398         (cpu-count (cpu-count)))
    391     (format s "~&~S took ~:D milliseconds (~,3F seconds) to run ~%~20twith ~D available CPU core~P."
    392             form elapsed-time (/ elapsed-time internal-time-units-per-second) cpu-count cpu-count)
    393     (format s "~&During that period, ~:D milliseconds (~,3F seconds) were spent in user mode" user-time (/ user-time internal-time-units-per-second))
    394     (format s "~&                    ~:D milliseconds (~,3F seconds) were spent in system mode" system-time (/ system-time internal-time-units-per-second))
     399    (format s "~&~S took ~:D ~a (~,vF seconds) to run ~%~20twith ~D available CPU core~P."
     400            form elapsed-time units width (/ elapsed-time internal-time-units-per-second) cpu-count cpu-count)
     401    (format s "~&During that period, ~:D ~a (~,vF seconds) were spent in user mode" user-time units width (/ user-time internal-time-units-per-second))
     402    (format s "~&                    ~:D ~a (~,vF seconds) were spent in system mode" system-time units width(/ system-time internal-time-units-per-second))
    395403    (unless (eql gc-time 0)
    396404      (format s
    397               "~%~:D milliseconds (~,3F seconds) was spent in GC."
    398               gc-time (/ gc-time internal-time-units-per-second)))
     405              "~%~:D ~a (~,vF seconds) was spent in GC."
     406              gc-time units width (/ gc-time internal-time-units-per-second)))
    399407    (unless (eql 0 bytes-allocated)
    400408      (format s "~% ~:D bytes of memory allocated." bytes-allocated))
     
    435443                                   (pref stop :rusage.ru_utime)
    436444                                   (pref start :rusage.ru_utime))
    437                     (timeval->milliseconds timediff)))
     445                    (ecase internal-time-units-per-second
     446                      (1000000 (timeval->microseconds timediff))
     447                      (1000 (timeval->milliseconds timediff)))))
    438448                 (elapsed-system-time
    439449                  (progn
     
    441451                                   (pref stop :rusage.ru_stime)
    442452                                   (pref start :rusage.ru_stime))
    443                     (timeval->milliseconds timediff)))
     453                    (ecase internal-time-units-per-second
     454                      (1000000 (timeval->microseconds timediff))
     455                      (1000 (timeval->milliseconds timediff)))))
    444456                 (elapsed-minor (- (pref stop :rusage.ru_minflt)
    445457                                   (pref start :rusage.ru_minflt)))
Note: See TracChangeset for help on using the changeset viewer.