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/145.runsolver.cupt cupt -o APT::Architecture=i386 -s -V -y --no-install-recommends remove libatk1.0-0 libopenexr2 cpp dia-libs libmad0-dev 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 Current StackSize limit: 8192 KiB [startup+0 s] /proc/loadavg: 0.99 0.84 0.44 2/56 24767 /proc/meminfo: memFree=281940/1022884 swapFree=0/0 [pid=24767] ppid=24766 vsize=3152 CPUtime=0 /proc/24767/stat : 24767 (runsolver) R 24766 17872 17872 34816 17872 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28214322 3227648 33 18446744073709551615 134512640 134586868 4289309024 4289307072 4151456816 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/24767/statm: 788 33 0 19 0 73 0 [startup+0.150874 s] /proc/loadavg: 0.99 0.84 0.44 2/56 24767 /proc/meminfo: memFree=281940/1022884 swapFree=0/0 [pid=24767] ppid=24766 vsize=34168 CPUtime=0.16 /proc/24767/stat : 24767 (cupt) R 24766 24767 17872 34816 17872 4202496 1993 7205 0 0 9 1 4 2 20 0 1 0 28214322 34988032 1812 18446744073709551615 4194304 5184042 140736383387264 140736383384456 140335883612374 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/24767/statm: 8542 1812 729 242 0 1104 0 Current children cumulated CPU time (s) 0.16 Current children cumulated vsize (KiB) 34168 [startup+0.200274 s] /proc/loadavg: 0.99 0.84 0.44 2/56 24767 /proc/meminfo: memFree=281940/1022884 swapFree=0/0 [pid=24767] ppid=24766 vsize=39448 CPUtime=0.2 /proc/24767/stat : 24767 (cupt) R 24766 24767 17872 34816 17872 4202496 3407 7205 0 0 12 2 4 2 20 0 1 0 28214322 40394752 3218 18446744073709551615 4194304 5184042 140736383387264 140736383383256 140335883681332 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/24767/statm: 9862 3218 792 242 0 2424 0 Current children cumulated CPU time (s) 0.2 Current children cumulated vsize (KiB) 39448 [startup+0.300259 s] /proc/loadavg: 0.99 0.84 0.44 2/56 24767 /proc/meminfo: memFree=281940/1022884 swapFree=0/0 [pid=24767] ppid=24766 vsize=49776 CPUtime=0.31 /proc/24767/stat : 24767 (cupt) R 24766 24767 17872 34816 17872 4202496 6016 7205 0 0 21 4 4 2 20 0 1 0 28214322 50970624 5826 18446744073709551615 4194304 5184042 140736383387264 140736383384760 140335883673724 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/24767/statm: 12444 5826 842 242 0 5006 0 Current children cumulated CPU time (s) 0.31 Current children cumulated vsize (KiB) 49776 [startup+0.700195 s] /proc/loadavg: 0.99 0.84 0.44 2/56 24767 /proc/meminfo: memFree=281940/1022884 swapFree=0/0 [pid=24767] ppid=24766 vsize=57100 CPUtime=0.7 /proc/24767/stat : 24767 (cupt) R 24766 24767 17872 34816 17872 4202496 7964 7205 0 0 60 4 4 2 20 0 1 0 28214322 58470400 7547 18446744073709551615 4194304 5184042 140736383387264 140736383381560 140335883678153 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/24767/statm: 14275 7547 842 242 0 6837 0 Current children cumulated CPU time (s) 0.7 Current children cumulated vsize (KiB) 57100 [startup+1.5002 s] /proc/loadavg: 0.99 0.84 0.44 2/57 24787 /proc/meminfo: memFree=252924/1022884 swapFree=0/0 [pid=24767] ppid=24766 vsize=60008 CPUtime=1.5 /proc/24767/stat : 24767 (cupt) R 24766 24767 17872 34816 17872 4202496 8870 7205 0 0 139 5 4 2 20 0 1 0 28214322 61448192 8196 18446744073709551615 4194304 5184042 140736383387264 140736383384568 140335900022312 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/24767/statm: 15002 8196 842 242 0 7564 0 Current children cumulated CPU time (s) 1.5 Current children cumulated vsize (KiB) 60008 [startup+3.10128 s] /proc/loadavg: 0.99 0.84 0.44 3/59 24799 /proc/meminfo: memFree=246328/1022884 swapFree=0/0 [pid=24767] ppid=24766 vsize=60008 CPUtime=2.47 /proc/24767/stat : 24767 (cupt) R 24766 24767 17872 34816 17872 4202496 9011 7205 0 0 235 6 4 2 20 0 1 0 28214322 61448192 8337 18446744073709551615 4194304 5184042 140736383387264 140736383384568 140335900021747 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/24767/statm: 15002 8337 842 242 0 7564 0 Current children cumulated CPU time (s) 2.47 Current children cumulated vsize (KiB) 60008 heavy processes: Solver just ended. Dumping a history of the last processes samples [startup+3.2038 s] /proc/loadavg: 1.07 0.86 0.45 4/57 24841 /proc/meminfo: memFree=251544/1022884 swapFree=0/0 [pid=24767] ppid=24766 vsize=60008 CPUtime=2.52 /proc/24767/stat : 24767 (cupt) R 24766 24767 17872 34816 17872 4202496 9020 7205 0 0 240 6 4 2 20 0 1 0 28214322 61448192 8346 18446744073709551615 4194304 5184042 140736383387264 140736383384568 140335900021856 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/24767/statm: 15002 8346 842 242 0 7564 0 Current children cumulated CPU time (s) 2.52 Current children cumulated vsize (KiB) 60008 [startup+4.00343 s] /proc/loadavg: 1.07 0.86 0.45 3/56 24849 /proc/meminfo: memFree=251436/1022884 swapFree=0/0 [pid=24767] ppid=24766 vsize=62056 CPUtime=2.86 /proc/24767/stat : 24767 (cupt) R 24766 24767 17872 34816 17872 4202496 9586 7205 0 0 274 6 4 2 20 0 1 0 28214322 63545344 8399 18446744073709551615 4194304 5184042 140736383387264 140736383384696 140335900022524 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/24767/statm: 15514 8399 842 242 0 8076 0 Current children cumulated CPU time (s) 2.86 Current children cumulated vsize (KiB) 62056 [startup+4.80019 s] /proc/loadavg: 1.07 0.86 0.45 3/56 24903 /proc/meminfo: memFree=251180/1022884 swapFree=0/0 [pid=24767] ppid=24766 vsize=62056 CPUtime=3.22 /proc/24767/stat : 24767 (cupt) R 24766 24767 17872 34816 17872 4202496 9627 7205 0 0 310 6 4 2 20 0 1 0 28214322 63545344 8440 18446744073709551615 4194304 5184042 140736383387264 140736383384696 140335899996568 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/24767/statm: 15514 8440 842 242 0 8076 0 Current children cumulated CPU time (s) 3.22 Current children cumulated vsize (KiB) 62056 [startup+5.00021 s] /proc/loadavg: 1.07 0.86 0.45 3/56 24903 /proc/meminfo: memFree=251180/1022884 swapFree=0/0 [pid=24767] ppid=24766 vsize=62056 CPUtime=3.39 /proc/24767/stat : 24767 (cupt) R 24766 24767 17872 34816 17872 4202496 9646 7205 0 0 327 6 4 2 20 0 1 0 28214322 63545344 8459 18446744073709551615 4194304 5184042 140736383387264 140736383384696 140335899996661 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/24767/statm: 15514 8459 842 242 0 8076 0 Current children cumulated CPU time (s) 3.39 Current children cumulated vsize (KiB) 62056 [startup+5.10021 s] /proc/loadavg: 1.07 0.86 0.45 3/56 24903 /proc/meminfo: memFree=251180/1022884 swapFree=0/0 [pid=24767] ppid=24766 vsize=57700 CPUtime=3.49 /proc/24767/stat : 24767 (cupt) R 24766 24767 17872 34816 17872 4202496 9664 7205 0 0 336 7 4 2 20 0 1 0 28214322 59084800 7819 18446744073709551615 4194304 5184042 140736383387264 140736383386712 140335883669096 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/24767/statm: 14425 7819 853 242 0 6987 0 Current children cumulated CPU time (s) 3.49 Current children cumulated vsize (KiB) 57700 Child status: 1 Real time (s): 5.13489 CPU time (s): 3.54022 CPU user time (s): 3.43621 CPU system time (s): 0.104006 CPU usage (%): 68.9444 Max. virtual memory (cumulated for all children) (KiB): 62056 getrusage(RUSAGE_CHILDREN,...) data: user time used= 3.43621 system time used= 0.104006 maximum resident set size= 35592 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 16889 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= 55 involuntary context switches= 590 runsolver used 0.008 second user time and 0.020001 second system time The end