runsolver Copyright (C) 2010 Olivier ROUSSEL This is runsolver version 3.2.9a (svn: 651) This program is distributed in the hope that it will be useful, but WITHOUT ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License for more details. command line: runsolver -W 300 -M 1124 -w /home/cbse/results/sarge-etch/logs/84.runsolver.cupt cupt -o APT::Architecture=i386 -s -V -y --no-install-recommends install libcrypt-gpg-perl gtoaster cl-ptester libapache-mod-python2.3 opensc Enforcing wall clock limit (soft limit, will send signal-name then SIGKILL): 300 seconds Enforcing VSIZE limit (soft limit, will send signal-name then SIGKILL): 1150976 KiB Enforcing VSIZE limit (hard limit, stack expansion will fail with SIGSEGV, brk() and mmap() will return ENOMEM): 1202176 KiB [startup+0 s] /proc/loadavg: 0.95 0.57 0.23 2/55 23416 /proc/meminfo: memFree=283704/1022884 swapFree=0/0 [pid=23416] ppid=23415 vsize=3152 CPUtime=0 /proc/23416/stat : 23416 (runsolver) R 23415 17872 17872 34816 17872 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28182315 3227648 33 18446744073709551615 134512640 134586868 4291146272 4291144320 4152038448 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/23416/statm: 788 33 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.201122 s] /proc/loadavg: 0.95 0.57 0.23 2/55 23416 /proc/meminfo: memFree=283704/1022884 swapFree=0/0 [pid=23416] ppid=23415 vsize=39712 CPUtime=0.21 /proc/23416/stat : 23416 (cupt) R 23415 23416 17872 34816 17872 4202496 3474 7206 0 0 12 2 5 2 20 0 1 0 28182315 40665088 3284 18446744073709551615 4194304 5184042 140734474822048 140734474818040 140692255002164 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/23416/statm: 9928 3284 792 242 0 2490 0 Current children cumulated CPU time (s) 0.21 Current children cumulated vsize (KiB) 39712 [startup+0.300267 s] /proc/loadavg: 0.95 0.57 0.23 2/55 23416 /proc/meminfo: memFree=283704/1022884 swapFree=0/0 [pid=23416] ppid=23415 vsize=52944 CPUtime=0.32 /proc/23416/stat : 23416 (cupt) R 23415 23416 17872 34816 17872 4202496 6866 7206 0 0 21 4 5 2 20 0 1 0 28182315 54214656 6628 18446744073709551615 4194304 5184042 140734474822048 140734474818872 140692271360916 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/23416/statm: 13236 6628 842 242 0 5798 0 Current children cumulated CPU time (s) 0.32 Current children cumulated vsize (KiB) 52944 [startup+0.400258 s] /proc/loadavg: 0.95 0.57 0.23 2/55 23416 /proc/meminfo: memFree=283704/1022884 swapFree=0/0 [pid=23416] ppid=23415 vsize=53576 CPUtime=0.41 /proc/23416/stat : 23416 (cupt) R 23415 23416 17872 34816 17872 4202496 7120 7206 0 0 30 4 5 2 20 0 1 0 28182315 54861824 6780 18446744073709551615 4194304 5184042 140734474822048 140734474816312 140692254933315 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/23416/statm: 13394 6780 842 242 0 5956 0 Current children cumulated CPU time (s) 0.41 Current children cumulated vsize (KiB) 53576 [startup+0.700203 s] /proc/loadavg: 0.95 0.57 0.23 2/55 23416 /proc/meminfo: memFree=283704/1022884 swapFree=0/0 [pid=23416] ppid=23415 vsize=57956 CPUtime=0.72 /proc/23416/stat : 23416 (cupt) R 23415 23416 17872 34816 17872 4202496 8116 7206 0 0 59 6 5 2 20 0 1 0 28182315 59346944 7776 18446744073709551615 4194304 5184042 140734474822048 140734474819352 140692271309680 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/23416/statm: 14489 7776 842 242 0 7051 0 Current children cumulated CPU time (s) 0.72 Current children cumulated vsize (KiB) 57956 [startup+1.50021 s] /proc/loadavg: 0.95 0.57 0.23 2/56 23436 /proc/meminfo: memFree=254812/1022884 swapFree=0/0 [pid=23416] ppid=23415 vsize=60764 CPUtime=1.51 /proc/23416/stat : 23416 (cupt) R 23415 23416 17872 34816 17872 4202496 9076 7206 0 0 138 6 5 2 20 0 1 0 28182315 62222336 8439 18446744073709551615 4194304 5184042 140734474822048 140734474819352 140692271358835 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/23416/statm: 15191 8439 842 242 0 7753 0 Current children cumulated CPU time (s) 1.51 Current children cumulated vsize (KiB) 60764 Solver just ended. Dumping a history of the last processes samples [startup+1.7002 s] /proc/loadavg: 0.95 0.57 0.23 2/56 23436 /proc/meminfo: memFree=254812/1022884 swapFree=0/0 [pid=23416] ppid=23415 vsize=61216 CPUtime=1.71 /proc/23416/stat : 23416 (cupt) R 23415 23416 17872 34816 17872 4202496 9243 7206 0 0 158 6 5 2 20 0 1 0 28182315 62685184 8606 18446744073709551615 4194304 5184042 140734474822048 140734474819352 140692263424478 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/23416/statm: 15304 8606 842 242 0 7866 0 Current children cumulated CPU time (s) 1.71 Current children cumulated vsize (KiB) 61216 [startup+2.5002 s] /proc/loadavg: 0.96 0.57 0.23 2/56 23436 /proc/meminfo: memFree=246380/1022884 swapFree=0/0 [pid=23416] ppid=23415 vsize=69112 CPUtime=2.5 /proc/23416/stat : 23416 (cupt) R 23415 23416 17872 34816 17872 4202496 11392 7206 0 0 236 7 5 2 20 0 1 0 28182315 70770688 10242 18446744073709551615 4194304 5184042 140734474822048 140734474816344 140692271289373 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/23416/statm: 17278 10242 842 242 0 9840 0 Current children cumulated CPU time (s) 2.5 Current children cumulated vsize (KiB) 69112 [startup+2.90021 s] /proc/loadavg: 0.96 0.57 0.23 2/56 23436 /proc/meminfo: memFree=246380/1022884 swapFree=0/0 [pid=23416] ppid=23415 vsize=69112 CPUtime=2.9 /proc/23416/stat : 23416 (cupt) R 23415 23416 17872 34816 17872 4202496 11474 7206 0 0 276 7 5 2 20 0 1 0 28182315 70770688 10324 18446744073709551615 4194304 5184042 140734474822048 140734474816344 140692271289786 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/23416/statm: 17278 10324 842 242 0 9840 0 Current children cumulated CPU time (s) 2.9 Current children cumulated vsize (KiB) 69112 [startup+3.00021 s] /proc/loadavg: 0.96 0.57 0.23 2/56 23436 /proc/meminfo: memFree=246380/1022884 swapFree=0/0 [pid=23416] ppid=23415 vsize=65012 CPUtime=3 /proc/23416/stat : 23416 (cupt) R 23415 23416 17872 34816 17872 4202496 11495 7206 0 0 286 7 5 2 20 0 1 0 28182315 66572288 9648 18446744073709551615 4194304 5184042 140734474822048 140734474820424 140692271316447 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/23416/statm: 16253 9648 853 242 0 8815 0 Current children cumulated CPU time (s) 3 Current children cumulated vsize (KiB) 65012 Child status: 1 Real time (s): 3.0467 CPU time (s): 3.06419 CPU user time (s): 2.96419 CPU system time (s): 0.100006 CPU usage (%): 100.574 Max. virtual memory (cumulated for all children) (KiB): 69112 getrusage(RUSAGE_CHILDREN,...) data: user time used= 2.96419 system time used= 0.100006 maximum resident set size= 42104 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 18721 page faults= 0 swaps= 0 block input operations= 0 block output operations= 0 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 52 involuntary context switches= 57 runsolver used 0 second user time and 0.016001 second system time The end