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: /home/misc2010/bin/runsolver -s SIGUSR1 -M 1124 -C 290 -d 10 -w /home/misc2010/tmp/201012061533/cudf2msu4paranoid-1.0/rand165.sarge-etch.cudf.sarge-etch.log.runsolver ./cudf2msu4paranoid-1.0 /home/misc2010/data/icse/sarge-etch/rand165.sarge-etch.cudf /home/misc2010/tmp/201012061533/cudf2msu4paranoid-1.0/rand165.sarge-etch.cudf.sarge-etch.result 

Enforcing CPUTime limit (soft limit, will send signal-name then SIGKILL): 290 seconds
Enforcing CPUTime limit (hard limit, will send SIGXCPU): 320 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: 1.29 1.13 1.08 4/46 7080
/proc/meminfo: memFree=811496/1048576 swapFree=2078740/2097144
[pid=7079] ppid=7078 vsize=2568 CPUtime=0
/proc/7079/stat : 7079 (cudf2msu4parano) S 7078 7079 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 22 0 1 0 874850356 2629632 271 1283457024 134512640 135304128 4287482592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7079/statm: 642 271 231 194 0 28 0
[pid=7080] ppid=7079 vsize=2048 CPUtime=0.01
/proc/7080/stat : 7080 (cudf_msu32) R 7079 7079 2059 34821 2220 4202496 269 0 0 0 1 0 0 0 25 0 1 0 874850357 2097152 209 1283457024 134512640 136120023 4288564240 18446744073709551615 134596914 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/7080/statm: 512 209 137 393 0 117 0

[startup+0.165789 s]
/proc/loadavg: 1.29 1.13 1.08 4/46 7080
/proc/meminfo: memFree=811496/1048576 swapFree=2078740/2097144
[pid=7079] ppid=7078 vsize=2568 CPUtime=0
/proc/7079/stat : 7079 (cudf2msu4parano) S 7078 7079 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 22 0 1 0 874850356 2629632 271 1283457024 134512640 135304128 4287482592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7079/statm: 642 271 231 194 0 28 0
[pid=7080] ppid=7079 vsize=8388 CPUtime=0.17
/proc/7080/stat : 7080 (cudf_msu32) R 7079 7079 2059 34821 2220 4202496 1844 0 0 0 17 0 0 0 25 0 1 0 874850357 8589312 1784 1283457024 134512640 136120023 4288564240 18446744073709551615 134711990 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/7080/statm: 2097 1784 138 393 0 1702 0
Current children cumulated CPU time (s) 0.17
Current children cumulated vsize (KiB) 10956

[startup+0.205796 s]
/proc/loadavg: 1.29 1.13 1.08 4/46 7080
/proc/meminfo: memFree=811496/1048576 swapFree=2078740/2097144
[pid=7079] ppid=7078 vsize=2568 CPUtime=0
/proc/7079/stat : 7079 (cudf2msu4parano) S 7078 7079 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 22 0 1 0 874850356 2629632 271 1283457024 134512640 135304128 4287482592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7079/statm: 642 271 231 194 0 28 0
[pid=7080] ppid=7079 vsize=9708 CPUtime=0.21
/proc/7080/stat : 7080 (cudf_msu32) R 7079 7079 2059 34821 2220 4202496 2184 0 0 0 21 0 0 0 25 0 1 0 874850357 9940992 2124 1283457024 134512640 136120023 4288564240 18446744073709551615 134707364 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/7080/statm: 2427 2124 138 393 0 2032 0
Current children cumulated CPU time (s) 0.21
Current children cumulated vsize (KiB) 12276

[startup+0.30582 s]
/proc/loadavg: 1.29 1.13 1.08 4/46 7080
/proc/meminfo: memFree=811496/1048576 swapFree=2078740/2097144
[pid=7079] ppid=7078 vsize=2568 CPUtime=0
/proc/7079/stat : 7079 (cudf2msu4parano) S 7078 7079 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 22 0 1 0 874850356 2629632 271 1283457024 134512640 135304128 4287482592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7079/statm: 642 271 231 194 0 28 0
[pid=7080] ppid=7079 vsize=13028 CPUtime=0.31
/proc/7080/stat : 7080 (cudf_msu32) R 7079 7079 2059 34821 2220 4202496 3000 0 0 0 31 0 0 0 25 0 1 0 874850357 13340672 2940 1283457024 134512640 136120023 4288564240 18446744073709551615 134580447 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/7080/statm: 3257 2940 138 393 0 2862 0
Current children cumulated CPU time (s) 0.31
Current children cumulated vsize (KiB) 15596

[startup+0.705921 s]
/proc/loadavg: 1.29 1.13 1.08 4/46 7080
/proc/meminfo: memFree=811496/1048576 swapFree=2078740/2097144
[pid=7079] ppid=7078 vsize=2568 CPUtime=0
/proc/7079/stat : 7079 (cudf2msu4parano) S 7078 7079 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 22 0 1 0 874850356 2629632 271 1283457024 134512640 135304128 4287482592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7079/statm: 642 271 231 194 0 28 0
[pid=7080] ppid=7079 vsize=32812 CPUtime=0.71
/proc/7080/stat : 7080 (cudf_msu32) R 7079 7079 2059 34821 2220 4202496 8127 0 0 0 70 1 0 0 25 0 1 0 874850357 33599488 7955 1283457024 134512640 136120023 4288564240 18446744073709551615 134870864 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/7080/statm: 8203 7955 176 393 0 7808 0
Current children cumulated CPU time (s) 0.71
Current children cumulated vsize (KiB) 35380

[startup+1.50612 s]
/proc/loadavg: 1.29 1.13 1.08 2/47 7081
/proc/meminfo: memFree=780476/1048576 swapFree=2078740/2097144
[pid=7079] ppid=7078 vsize=2568 CPUtime=0
/proc/7079/stat : 7079 (cudf2msu4parano) S 7078 7079 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 22 0 1 0 874850356 2629632 271 1283457024 134512640 135304128 4287482592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7079/statm: 642 271 231 194 0 28 0
[pid=7080] ppid=7079 vsize=32812 CPUtime=1.51
/proc/7080/stat : 7080 (cudf_msu32) R 7079 7079 2059 34821 2220 4202496 8129 0 0 0 150 1 0 0 25 0 1 0 874850357 33599488 7957 1283457024 134512640 136120023 4288564240 18446744073709551615 134867660 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/7080/statm: 8203 7957 178 393 0 7808 0
Current children cumulated CPU time (s) 1.51
Current children cumulated vsize (KiB) 35380

[startup+3.10651 s]
/proc/loadavg: 1.29 1.13 1.08 2/47 7081
/proc/meminfo: memFree=780476/1048576 swapFree=2078740/2097144
[pid=7079] ppid=7078 vsize=2568 CPUtime=0
/proc/7079/stat : 7079 (cudf2msu4parano) S 7078 7079 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 22 0 1 0 874850356 2629632 271 1283457024 134512640 135304128 4287482592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7079/statm: 642 271 231 194 0 28 0
[pid=7080] ppid=7079 vsize=33604 CPUtime=3.11
/proc/7080/stat : 7080 (cudf_msu32) R 7079 7079 2059 34821 2220 4202496 8302 0 0 0 309 2 0 0 25 0 1 0 874850357 34410496 8130 1283457024 134512640 136120023 4288564240 18446744073709551615 134867658 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/7080/statm: 8401 8130 182 393 0 8006 0
Current children cumulated CPU time (s) 3.11
Current children cumulated vsize (KiB) 36172

[startup+6.30727 s]
/proc/loadavg: 1.27 1.13 1.08 2/47 7081
/proc/meminfo: memFree=779732/1048576 swapFree=2078740/2097144
[pid=7079] ppid=7078 vsize=2568 CPUtime=0
/proc/7079/stat : 7079 (cudf2msu4parano) S 7078 7079 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 22 0 1 0 874850356 2629632 271 1283457024 134512640 135304128 4287482592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7079/statm: 642 271 231 194 0 28 0
[pid=7080] ppid=7079 vsize=33604 CPUtime=6.31
/proc/7080/stat : 7080 (cudf_msu32) R 7079 7079 2059 34821 2220 4202496 8302 0 0 0 629 2 0 0 25 0 1 0 874850357 34410496 8130 1283457024 134512640 136120023 4288564240 18446744073709551615 134862891 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/7080/statm: 8401 8130 182 393 0 8006 0
Current children cumulated CPU time (s) 6.31
Current children cumulated vsize (KiB) 36172

Solver just ended. Dumping a history of the last processes samples

[startup+6.4073 s]
/proc/loadavg: 1.27 1.13 1.08 2/47 7081
/proc/meminfo: memFree=779732/1048576 swapFree=2078740/2097144
[pid=7079] ppid=7078 vsize=2568 CPUtime=0
/proc/7079/stat : 7079 (cudf2msu4parano) S 7078 7079 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 22 0 1 0 874850356 2629632 271 1283457024 134512640 135304128 4287482592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7079/statm: 642 271 231 194 0 28 0
[pid=7080] ppid=7079 vsize=33604 CPUtime=6.41
/proc/7080/stat : 7080 (cudf_msu32) R 7079 7079 2059 34821 2220 4202496 8302 0 0 0 639 2 0 0 25 0 1 0 874850357 34410496 8130 1283457024 134512640 136120023 4288564240 18446744073709551615 134837904 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/7080/statm: 8401 8130 182 393 0 8006 0
Current children cumulated CPU time (s) 6.41
Current children cumulated vsize (KiB) 36172

[startup+6.80735 s]
/proc/loadavg: 1.27 1.13 1.08 2/47 7081
/proc/meminfo: memFree=779732/1048576 swapFree=2078740/2097144
[pid=7079] ppid=7078 vsize=2568 CPUtime=0
/proc/7079/stat : 7079 (cudf2msu4parano) S 7078 7079 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 22 0 1 0 874850356 2629632 271 1283457024 134512640 135304128 4287482592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7079/statm: 642 271 231 194 0 28 0
[pid=7080] ppid=7079 vsize=33604 CPUtime=6.81
/proc/7080/stat : 7080 (cudf_msu32) R 7079 7079 2059 34821 2220 4202496 8317 0 0 0 678 3 0 0 25 0 1 0 874850357 34410496 8145 1283457024 134512640 136120023 4288564240 18446744073709551615 135511805 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/7080/statm: 8401 8145 197 393 0 8006 0
Current children cumulated CPU time (s) 6.81
Current children cumulated vsize (KiB) 36172

Child status: 0
Real time (s): 6.82343
CPU time (s): 6.82443
CPU user time (s): 6.79242
CPU system time (s): 0.032002
CPU usage (%): 100.015
Max. virtual memory (cumulated for all children) (KiB): 36172

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 6.79242
system time used= 0.032002
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 8703
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= 3
involuntary context switches= 125

runsolver used 0 second user time and 0 second system time

The end