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/logs/102.runsolver.cupt cupt -o APT::Architecture=i386 -s -V -y --no-install-recommends remove libglibmm-2.4-1 kuiviewer libgucharmap4 kdict eyesapplet 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.91 2/55 27906 /proc/meminfo: memFree=306292/1022884 swapFree=0/0 [pid=27906] ppid=27905 vsize=3152 CPUtime=0 Current StackSize limit: 8192 KiB /proc/27906/stat : 27906 (runsolver) R 27905 17872 17872 34816 17872 4202560 0 0 0 0 0 0 0 0 20 0 1 0 28488937 3227648 32 18446744073709551615 134512640 134586868 4290988992 4290987040 4151739440 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/27906/statm: 788 32 0 19 0 73 0 [startup+0.124193 s] /proc/loadavg: 1.00 0.99 0.91 2/55 27906 /proc/meminfo: memFree=306292/1022884 swapFree=0/0 [pid=27906] ppid=27905 vsize=33508 CPUtime=0.13 /proc/27906/stat : 27906 (cupt) R 27905 27906 17872 34816 17872 4202496 1841 7200 0 0 5 2 5 1 20 0 1 0 28488937 34312192 1660 18446744073709551615 4194304 5184042 140736651974080 140736651971272 140538616850105 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/27906/statm: 8377 1660 729 242 0 939 0 Current children cumulated CPU time (s) 0.13 Current children cumulated vsize (KiB) 33508 [startup+0.20027 s] /proc/loadavg: 1.00 0.99 0.91 2/55 27906 /proc/meminfo: memFree=306292/1022884 swapFree=0/0 [pid=27906] ppid=27905 vsize=35360 CPUtime=0.21 /proc/27906/stat : 27906 (cupt) R 27905 27906 17872 34816 17872 4202496 2310 7200 0 0 11 4 5 1 20 0 1 0 28488937 36208640 2128 18446744073709551615 4194304 5184042 140736651974080 140736651971272 140538608387824 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/27906/statm: 8840 2128 729 242 0 1402 0 Current children cumulated CPU time (s) 0.21 Current children cumulated vsize (KiB) 35360 [startup+0.300254 s] /proc/loadavg: 1.00 0.99 0.91 2/55 27906 /proc/meminfo: memFree=306292/1022884 swapFree=0/0 [pid=27906] ppid=27905 vsize=46580 CPUtime=0.31 /proc/27906/stat : 27906 (cupt) R 27905 27906 17872 34816 17872 4202496 5234 7200 0 0 19 6 5 1 20 0 1 0 28488937 47697920 5043 18446744073709551615 4194304 5184042 140736651974080 140736651968568 140538624150832 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/27906/statm: 11645 5043 835 242 0 4207 0 Current children cumulated CPU time (s) 0.31 Current children cumulated vsize (KiB) 46580 [startup+0.7002 s] /proc/loadavg: 1.00 0.99 0.91 2/55 27906 /proc/meminfo: memFree=306292/1022884 swapFree=0/0 [pid=27906] ppid=27905 vsize=58708 CPUtime=0.71 /proc/27906/stat : 27906 (cupt) R 27905 27906 17872 34816 17872 4202496 8302 7200 0 0 58 7 5 1 20 0 1 0 28488937 60116992 8013 18446744073709551615 4194304 5184042 140736651974080 140736651971512 140538624394943 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/27906/statm: 14677 8013 842 242 0 7239 0 Current children cumulated CPU time (s) 0.71 Current children cumulated vsize (KiB) 58708 [startup+1.5002 s] /proc/loadavg: 1.00 0.99 0.91 2/56 27926 /proc/meminfo: memFree=275788/1022884 swapFree=0/0 [pid=27906] ppid=27905 vsize=60832 CPUtime=1.51 /proc/27906/stat : 27906 (cupt) R 27905 27906 17872 34816 17872 4202496 8984 7200 0 0 138 7 5 1 20 0 1 0 28488937 62291968 8566 18446744073709551615 4194304 5184042 140736651974080 140736651971384 140538624386656 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/27906/statm: 15208 8566 842 242 0 7770 0 Current children cumulated CPU time (s) 1.51 Current children cumulated vsize (KiB) 60832 [startup+3.10021 s] /proc/loadavg: 1.00 0.99 0.91 2/56 27926 /proc/meminfo: memFree=269464/1022884 swapFree=0/0 [pid=27906] ppid=27905 vsize=69344 CPUtime=3.1 /proc/27906/stat : 27906 (cupt) R 27905 27906 17872 34816 17872 4202496 11423 7200 0 0 297 7 5 1 20 0 1 0 28488937 71008256 10235 18446744073709551615 4194304 5184042 140736651974080 140736651968344 140538624386032 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/27906/statm: 17336 10235 842 242 0 9898 0 Current children cumulated CPU time (s) 3.1 Current children cumulated vsize (KiB) 69344 [startup+6.30021 s] /proc/loadavg: 1.00 0.99 0.91 2/56 27926 /proc/meminfo: memFree=264380/1022884 swapFree=0/0 [pid=27906] ppid=27905 vsize=76336 CPUtime=6.29 /proc/27906/stat : 27906 (cupt) R 27905 27906 17872 34816 17872 4202496 13651 7200 0 0 615 8 5 1 20 0 1 0 28488937 78168064 11438 18446744073709551615 4194304 5184042 140736651974080 140736651971512 140538624360861 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/27906/statm: 19084 11438 842 242 0 11646 0 Current children cumulated CPU time (s) 6.29 Current children cumulated vsize (KiB) 76336 [startup+12.7002 s] /proc/loadavg: 1.00 0.99 0.91 2/56 27926 /proc/meminfo: memFree=259668/1022884 swapFree=0/0 [pid=27906] ppid=27905 vsize=77464 CPUtime=12.66 /proc/27906/stat : 27906 (cupt) R 27905 27906 17872 34816 17872 4202496 14812 7200 0 0 1250 10 5 1 20 0 1 0 28488937 79323136 12599 18446744073709551615 4194304 5184042 140736651974080 140736651971384 140538608042323 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/27906/statm: 19366 12599 842 242 0 11928 0 Current children cumulated CPU time (s) 12.66 Current children cumulated vsize (KiB) 77464 [startup+25.5002 s] /proc/loadavg: 1.00 0.99 0.91 2/56 27926 /proc/meminfo: memFree=250492/1022884 swapFree=0/0 [pid=27906] ppid=27905 vsize=87908 CPUtime=25.4 /proc/27906/stat : 27906 (cupt) R 27905 27906 17872 34816 17872 4202496 19014 7200 0 0 2522 12 5 1 20 0 1 0 28488937 90017792 14752 18446744073709551615 4194304 5184042 140736651974080 140736651971384 140538624367198 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/27906/statm: 21977 14752 842 242 0 14539 0 Current children cumulated CPU time (s) 25.4 Current children cumulated vsize (KiB) 87908 [startup+51.1002 s] /proc/loadavg: 1.00 0.99 0.91 2/56 27926 /proc/meminfo: memFree=237472/1022884 swapFree=0/0 [pid=27906] ppid=27905 vsize=107572 CPUtime=50.9 /proc/27906/stat : 27906 (cupt) R 27905 27906 17872 34816 17872 4202496 26406 7200 0 0 5067 17 5 1 20 0 1 0 28488937 110153728 18047 18446744073709551615 4194304 5184042 140736651974080 140736651971384 140538624386048 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/27906/statm: 26893 18047 842 242 0 19455 0 Current children cumulated CPU time (s) 50.9 Current children cumulated vsize (KiB) 107572 [startup+102.3 s] /proc/loadavg: 1.00 0.99 0.91 2/56 27926 /proc/meminfo: memFree=213416/1022884 swapFree=0/0 [pid=27906] ppid=27905 vsize=144356 CPUtime=101.89 /proc/27906/stat : 27906 (cupt) R 27905 27906 17872 34816 17872 4202496 40526 7200 0 0 10157 26 5 1 20 0 1 0 28488937 147820544 23974 18446744073709551615 4194304 5184042 140736651974080 140736651971384 140538624153856 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/27906/statm: 36089 23974 842 242 0 28651 0 Current children cumulated CPU time (s) 101.89 Current children cumulated vsize (KiB) 144356 Solver just ended. Dumping a history of the last processes samples [startup+102.403 s] /proc/loadavg: 1.00 0.99 0.91 2/56 27926 /proc/meminfo: memFree=213416/1022884 swapFree=0/0 [pid=27906] ppid=27905 vsize=144356 CPUtime=101.99 /proc/27906/stat : 27906 (cupt) R 27905 27906 17872 34816 17872 4202496 40535 7200 0 0 10167 26 5 1 20 0 1 0 28488937 147820544 23983 18446744073709551615 4194304 5184042 140736651974080 140736651971384 140538624386459 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/27906/statm: 36089 23983 842 242 0 28651 0 Current children cumulated CPU time (s) 101.99 Current children cumulated vsize (KiB) 144356 [startup+105.6 s] /proc/loadavg: 1.00 0.99 0.91 2/56 27926 /proc/meminfo: memFree=211556/1022884 swapFree=0/0 [pid=27906] ppid=27905 vsize=145076 CPUtime=105.18 /proc/27906/stat : 27906 (cupt) R 27905 27906 17872 34816 17872 4202496 41006 7200 0 0 10485 27 5 1 20 0 1 0 28488937 148557824 24454 18446744073709551615 4194304 5184042 140736651974080 140736651971384 140538624409707 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/27906/statm: 36269 24454 842 242 0 28831 0 Current children cumulated CPU time (s) 105.18 Current children cumulated vsize (KiB) 145076 [startup+107.2 s] /proc/loadavg: 1.00 0.99 0.91 2/56 27926 /proc/meminfo: memFree=211184/1022884 swapFree=0/0 [pid=27906] ppid=27905 vsize=145076 CPUtime=106.78 /proc/27906/stat : 27906 (cupt) R 27905 27906 17872 34816 17872 4202496 41159 7200 0 0 10645 27 5 1 20 0 1 0 28488937 148557824 24607 18446744073709551615 4194304 5184042 140736651974080 140736651971384 140538624386640 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/27906/statm: 36269 24607 842 242 0 28831 0 Current children cumulated CPU time (s) 106.78 Current children cumulated vsize (KiB) 145076 [startup+108.8 s] /proc/loadavg: 1.00 0.99 0.91 2/56 27926 /proc/meminfo: memFree=210688/1022884 swapFree=0/0 [pid=27906] ppid=27905 vsize=145076 CPUtime=108.37 /proc/27906/stat : 27906 (cupt) R 27905 27906 17872 34816 17872 4202496 41312 7200 0 0 10804 27 5 1 20 0 1 0 28488937 148557824 24760 18446744073709551615 4194304 5184042 140736651974080 140736651971384 140538624386544 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/27906/statm: 36269 24760 842 242 0 28831 0 Current children cumulated CPU time (s) 108.37 Current children cumulated vsize (KiB) 145076 [startup+109.6 s] /proc/loadavg: 1.00 0.99 0.91 2/56 27926 /proc/meminfo: memFree=210192/1022884 swapFree=0/0 [pid=27906] ppid=27905 vsize=145076 CPUtime=109.16 /proc/27906/stat : 27906 (cupt) R 27905 27906 17872 34816 17872 4202496 41376 7200 0 0 10883 27 5 1 20 0 1 0 28488937 148557824 24824 18446744073709551615 4194304 5184042 140736651974080 140736651968328 140538624386035 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/27906/statm: 36269 24824 842 242 0 28831 0 Current children cumulated CPU time (s) 109.16 Current children cumulated vsize (KiB) 145076 [startup+110 s] /proc/loadavg: 1.00 0.99 0.91 2/56 27926 /proc/meminfo: memFree=209820/1022884 swapFree=0/0 [pid=27906] ppid=27905 vsize=145076 CPUtime=109.56 /proc/27906/stat : 27906 (cupt) R 27905 27906 17872 34816 17872 4202496 41408 7200 0 0 10923 27 5 1 20 0 1 0 28488937 148557824 24856 18446744073709551615 4194304 5184042 140736651974080 140736651968296 140538624470528 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/27906/statm: 36269 24856 842 242 0 28831 0 Current children cumulated CPU time (s) 109.56 Current children cumulated vsize (KiB) 145076 [startup+110.103 s] /proc/loadavg: 1.00 0.99 0.91 2/56 27926 /proc/meminfo: memFree=209820/1022884 swapFree=0/0 [pid=27906] ppid=27905 vsize=79276 CPUtime=109.66 /proc/27906/stat : 27906 (cupt) R 27905 27906 17872 34816 17872 4202496 41421 7200 0 0 10932 28 5 1 20 0 1 0 28488937 81178624 13208 18446744073709551615 4194304 5184042 140736651974080 140736651973528 140538608033346 0 0 0 0 0 0 0 17 0 0 0 0 0 0 /proc/27906/statm: 19819 13208 853 242 0 12381 0 Current children cumulated CPU time (s) 109.66 Current children cumulated vsize (KiB) 79276 Child status: 1 Real time (s): 110.124 CPU time (s): 109.707 CPU user time (s): 109.391 CPU system time (s): 0.316019 CPU usage (%): 99.6213 Max. virtual memory (cumulated for all children) (KiB): 145076 getrusage(RUSAGE_CHILDREN,...) data: user time used= 109.391 system time used= 0.316019 maximum resident set size= 116068 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 48641 page faults= 0 swaps= 0 block input operations= 0 block output operations= 136 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 52 involuntary context switches= 1662 runsolver used 0.452028 second user time and 0 second system time The end