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-lenny-squeeze-sid/logs/121.runsolver.cupt cupt -o APT::Architecture=i386 -s -V -y --no-install-recommends remove libguile-ltdl-1 libjpeg62-dev libxrender1 kopete libxft2 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: 1.00 0.99 0.99 2/55 7169 /proc/meminfo: memFree=575080/1022884 swapFree=0/0 [pid=7169] ppid=7168 vsize=3152 CPUtime=0 /proc/7169/stat : 7169 (runsolver) R 7168 17872 17872 34816 17872 4202560 0 0 0 0 0 0 0 0 20 0 1 0 31502979 3227648 32 18446744073709551615 134512640 134586868 4289948352 4289946400 4151968816 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/7169/statm: 788 32 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.114717 s] /proc/loadavg: 1.00 0.99 0.99 2/55 7169 /proc/meminfo: memFree=575080/1022884 swapFree=0/0 [pid=7169] ppid=7168 vsize=33244 CPUtime=0.12 /proc/7169/stat : 7169 (cupt) R 7168 7169 17872 34816 17872 4202496 1788 7190 0 0 4 2 5 1 20 0 1 0 31502979 34041856 1607 18446744073709551615 4194304 5184042 140736561290480 140736561287672 140548166488373 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/7169/statm: 8311 1607 729 242 0 873 0 Current children cumulated CPU time (s) 0.12 Current children cumulated vsize (KiB) 33244 [startup+0.200269 s] /proc/loadavg: 1.00 0.99 0.99 2/55 7169 /proc/meminfo: memFree=575080/1022884 swapFree=0/0 [pid=7169] ppid=7168 vsize=35492 CPUtime=0.21 /proc/7169/stat : 7169 (cupt) R 7168 7169 17872 34816 17872 4202496 2341 7190 0 0 10 5 5 1 20 0 1 0 31502979 36343808 2159 18446744073709551615 4194304 5184042 140736561290480 140736561287672 140548167252842 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/7169/statm: 8873 2159 729 242 0 1435 0 Current children cumulated CPU time (s) 0.21 Current children cumulated vsize (KiB) 35492 [startup+0.30026 s] /proc/loadavg: 1.00 0.99 0.99 2/55 7169 /proc/meminfo: memFree=575080/1022884 swapFree=0/0 [pid=7169] ppid=7168 vsize=37984 CPUtime=0.31 /proc/7169/stat : 7169 (cupt) R 7168 7169 17872 34816 17872 4202496 3045 7190 0 0 19 6 5 1 20 0 1 0 31502979 38895616 2800 18446744073709551615 4194304 5184042 140736561290480 140736561287672 140548183018548 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/7169/statm: 9496 2800 739 242 0 2058 0 Current children cumulated CPU time (s) 0.31 Current children cumulated vsize (KiB) 37984 [startup+0.700203 s] /proc/loadavg: 1.00 0.99 0.99 2/55 7169 /proc/meminfo: memFree=575080/1022884 swapFree=0/0 [pid=7169] ppid=7168 vsize=63516 CPUtime=0.71 /proc/7169/stat : 7169 (cupt) R 7168 7169 17872 34816 17872 4202496 9514 7190 0 0 51 14 5 1 20 0 1 0 31502979 65040384 9260 18446744073709551615 4194304 5184042 140736561290480 140736561287720 140548182832562 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/7169/statm: 15879 9260 851 242 0 8441 0 Current children cumulated CPU time (s) 0.71 Current children cumulated vsize (KiB) 63516 [startup+1.5002 s] /proc/loadavg: 1.00 0.99 0.99 2/56 7189 /proc/meminfo: memFree=537508/1022884 swapFree=0/0 [pid=7169] ppid=7168 vsize=68240 CPUtime=1.51 /proc/7169/stat : 7169 (cupt) R 7168 7169 17872 34816 17872 4202496 10863 7190 0 0 130 15 5 1 20 0 1 0 31502979 69877760 10415 18446744073709551615 4194304 5184042 140736561290480 140736561287784 140548182832547 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/7169/statm: 17060 10415 851 242 0 9622 0 Current children cumulated CPU time (s) 1.51 Current children cumulated vsize (KiB) 68240 [startup+3.1002 s] /proc/loadavg: 1.00 0.99 0.99 2/56 7189 /proc/meminfo: memFree=535896/1022884 swapFree=0/0 [pid=7169] ppid=7168 vsize=70072 CPUtime=3.1 /proc/7169/stat : 7169 (cupt) R 7168 7169 17872 34816 17872 4202496 11551 7190 0 0 289 15 5 1 20 0 1 0 31502979 71753728 10846 18446744073709551615 4194304 5184042 140736561290480 140736561287784 140548182832738 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/7169/statm: 17518 10846 851 242 0 10080 0 Current children cumulated CPU time (s) 3.1 Current children cumulated vsize (KiB) 70072 Solver just ended. Dumping a history of the last processes samples [startup+3.20027 s] /proc/loadavg: 1.00 0.99 0.99 2/56 7189 /proc/meminfo: memFree=535896/1022884 swapFree=0/0 [pid=7169] ppid=7168 vsize=70072 CPUtime=3.2 /proc/7169/stat : 7169 (cupt) R 7168 7169 17872 34816 17872 4202496 11575 7190 0 0 299 15 5 1 20 0 1 0 31502979 71753728 10870 18446744073709551615 4194304 5184042 140736561290480 140736561287784 140548166488985 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/7169/statm: 17518 10870 851 242 0 10080 0 Current children cumulated CPU time (s) 3.2 Current children cumulated vsize (KiB) 70072 [startup+4.0002 s] /proc/loadavg: 1.00 0.99 0.99 2/56 7189 /proc/meminfo: memFree=534904/1022884 swapFree=0/0 [pid=7169] ppid=7168 vsize=72384 CPUtime=4 /proc/7169/stat : 7169 (cupt) R 7168 7169 17872 34816 17872 4202496 12266 7190 0 0 378 16 5 1 20 0 1 0 31502979 74121216 11048 18446744073709551615 4194304 5184042 140736561290480 140736561287784 140548166483833 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/7169/statm: 18096 11048 851 242 0 10658 0 Current children cumulated CPU time (s) 4 Current children cumulated vsize (KiB) 72384 [startup+4.8002 s] /proc/loadavg: 1.00 0.99 0.99 2/56 7189 /proc/meminfo: memFree=533912/1022884 swapFree=0/0 [pid=7169] ppid=7168 vsize=72524 CPUtime=4.79 /proc/7169/stat : 7169 (cupt) R 7168 7169 17872 34816 17872 4202496 12403 7190 0 0 457 16 5 1 20 0 1 0 31502979 74264576 11185 18446744073709551615 4194304 5184042 140736561290480 140736561287784 140548182817525 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/7169/statm: 18131 11185 851 242 0 10693 0 Current children cumulated CPU time (s) 4.79 Current children cumulated vsize (KiB) 72524 [startup+5.0002 s] /proc/loadavg: 1.00 0.99 0.99 2/56 7189 /proc/meminfo: memFree=533912/1022884 swapFree=0/0 [pid=7169] ppid=7168 vsize=72524 CPUtime=4.99 /proc/7169/stat : 7169 (cupt) R 7168 7169 17872 34816 17872 4202496 12429 7190 0 0 477 16 5 1 20 0 1 0 31502979 74264576 11211 18446744073709551615 4194304 5184042 140736561290480 140736561287784 140548182832288 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/7169/statm: 18131 11211 851 242 0 10693 0 Current children cumulated CPU time (s) 4.99 Current children cumulated vsize (KiB) 72524 [startup+5.10021 s] /proc/loadavg: 1.00 0.99 0.99 2/56 7189 /proc/meminfo: memFree=533912/1022884 swapFree=0/0 [pid=7169] ppid=7168 vsize=67912 CPUtime=5.09 /proc/7169/stat : 7169 (cupt) R 7168 7169 17872 34816 17872 4202496 12446 7190 0 0 487 16 5 1 20 0 1 0 31502979 69541888 10377 18446744073709551615 4194304 5184042 140736561290480 140736561289928 140548166479488 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/7169/statm: 16978 10377 862 242 0 9540 0 Current children cumulated CPU time (s) 5.09 Current children cumulated vsize (KiB) 67912 Child status: 1 Real time (s): 5.11545 CPU time (s): 5.12832 CPU user time (s): 4.93631 CPU system time (s): 0.192012 CPU usage (%): 100.252 Max. virtual memory (cumulated for all children) (KiB): 72524 getrusage(RUSAGE_CHILDREN,...) data: user time used= 4.93631 system time used= 0.192012 maximum resident set size= 45852 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 19656 page faults= 0 swaps= 0 block input operations= 0 block output operations= 24 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 52 involuntary context switches= 90 runsolver used 0.016001 second user time and 0.008 second system time The end