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/201012081719/cudf2pbo4paranoid-1.0/rand108.sarge-etch-lenny-squeeze.cudf.sarge-etch-lenny-squeeze.log.runsolver ./cudf2pbo4paranoid-1.0 /home/misc2010/data/icse/sarge-etch-lenny-squeeze/rand108.sarge-etch-lenny-squeeze.cudf /home/misc2010/tmp/201012081719/cudf2pbo4paranoid-1.0/rand108.sarge-etch-lenny-squeeze.cudf.sarge-etch-lenny-squeeze.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: 0.85 0.93 0.64 3/39 9400
/proc/meminfo: memFree=74988/1048576 swapFree=2095372/2097144
[pid=9399] ppid=9398 vsize=2568 CPUtime=0
/proc/9399/stat : 9399 (cudf2pbo4parano) S 9398 9399 9023 34817 9081 4202496 380 0 0 0 0 0 0 0 18 0 1 0 892274464 2629632 277 1283457024 134512640 135304128 4294357312 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/9399/statm: 642 277 238 194 0 28 0
[pid=9400] ppid=9399 vsize=1920 CPUtime=0
/proc/9400/stat : 9400 (cudf_msu32) D 9399 9399 9023 34817 9081 4202496 264 0 0 0 0 0 0 0 18 0 1 0 892274464 1966080 157 1283457024 134512640 136125367 4286767760 18446744073709551615 135594526 0 0 0 25121 18446744071564332000 0 0 17 0 0 0 0
/proc/9400/statm: 480 157 133 394 0 84 0

[startup+0.140314 s]
/proc/loadavg: 0.85 0.93 0.64 3/39 9400
/proc/meminfo: memFree=74988/1048576 swapFree=2095372/2097144
[pid=9399] ppid=9398 vsize=2568 CPUtime=0
/proc/9399/stat : 9399 (cudf2pbo4parano) S 9398 9399 9023 34817 9081 4202496 380 0 0 0 0 0 0 0 18 0 1 0 892274464 2629632 277 1283457024 134512640 135304128 4294357312 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/9399/statm: 642 277 238 194 0 28 0
[pid=9400] ppid=9399 vsize=7004 CPUtime=0.1
/proc/9400/stat : 9400 (cudf_msu32) R 9399 9399 9023 34817 9081 4202496 1550 0 0 0 10 0 0 0 25 0 1 0 892274464 7172096 1443 1283457024 134512640 136125367 4286767760 18446744073709551615 134717792 0 0 0 25121 0 0 0 17 0 0 0 0
/proc/9400/statm: 1751 1443 143 394 0 1355 0
Current children cumulated CPU time (s) 0.1
Current children cumulated vsize (KiB) 9572

[startup+0.204334 s]
/proc/loadavg: 0.85 0.93 0.64 3/39 9400
/proc/meminfo: memFree=74988/1048576 swapFree=2095372/2097144
[pid=9399] ppid=9398 vsize=2568 CPUtime=0
/proc/9399/stat : 9399 (cudf2pbo4parano) S 9398 9399 9023 34817 9081 4202496 380 0 0 0 0 0 0 0 18 0 1 0 892274464 2629632 277 1283457024 134512640 135304128 4294357312 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/9399/statm: 642 277 238 194 0 28 0
[pid=9400] ppid=9399 vsize=9512 CPUtime=0.15
/proc/9400/stat : 9400 (cudf_msu32) R 9399 9399 9023 34817 9081 4202496 2178 0 0 0 14 1 0 0 25 0 1 0 892274464 9740288 2071 1283457024 134512640 136125367 4286767760 18446744073709551615 134718254 0 0 0 25121 0 0 0 17 0 0 0 0
/proc/9400/statm: 2378 2071 143 394 0 1982 0
Current children cumulated CPU time (s) 0.15
Current children cumulated vsize (KiB) 12080

[startup+0.304641 s]
/proc/loadavg: 0.85 0.93 0.64 3/39 9400
/proc/meminfo: memFree=74988/1048576 swapFree=2095372/2097144
[pid=9399] ppid=9398 vsize=2568 CPUtime=0
/proc/9399/stat : 9399 (cudf2pbo4parano) S 9398 9399 9023 34817 9081 4202496 380 0 0 0 0 0 0 0 18 0 1 0 892274464 2629632 277 1283457024 134512640 135304128 4294357312 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/9399/statm: 642 277 238 194 0 28 0
[pid=9400] ppid=9399 vsize=12828 CPUtime=0.24
/proc/9400/stat : 9400 (cudf_msu32) R 9399 9399 9023 34817 9081 4202496 3028 0 0 0 21 3 0 0 25 0 1 0 892274464 13135872 2921 1283457024 134512640 136125367 4286767760 18446744073709551615 135533302 0 0 0 25121 0 0 0 17 0 0 0 0
/proc/9400/statm: 3207 2921 144 394 0 2811 0
Current children cumulated CPU time (s) 0.24
Current children cumulated vsize (KiB) 15396

[startup+0.704366 s]
/proc/loadavg: 0.85 0.93 0.64 3/39 9400
/proc/meminfo: memFree=74988/1048576 swapFree=2095372/2097144
[pid=9399] ppid=9398 vsize=2568 CPUtime=0
/proc/9399/stat : 9399 (cudf2pbo4parano) S 9398 9399 9023 34817 9081 4202496 380 0 0 0 0 0 0 0 18 0 1 0 892274464 2629632 277 1283457024 134512640 135304128 4294357312 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/9399/statm: 642 277 238 194 0 28 0
[pid=9400] ppid=9399 vsize=24904 CPUtime=0.58
/proc/9400/stat : 9400 (cudf_msu32) R 9399 9399 9023 34817 9081 4202496 6021 0 0 0 55 3 0 0 25 0 1 0 892274464 25501696 5914 1283457024 134512640 136125367 4286767760 18446744073709551615 134710475 0 0 0 25121 0 0 0 17 0 0 0 0
/proc/9400/statm: 6226 5914 144 394 0 5830 0
Current children cumulated CPU time (s) 0.58
Current children cumulated vsize (KiB) 27472

[startup+1.50582 s]
/proc/loadavg: 0.85 0.93 0.64 2/40 9401
/proc/meminfo: memFree=23076/1048576 swapFree=2095372/2097144
[pid=9399] ppid=9398 vsize=2568 CPUtime=0
/proc/9399/stat : 9399 (cudf2pbo4parano) S 9398 9399 9023 34817 9081 4202496 380 0 0 0 0 0 0 0 18 0 1 0 892274464 2629632 277 1283457024 134512640 135304128 4294357312 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/9399/statm: 642 277 238 194 0 28 0
[pid=9400] ppid=9399 vsize=47356 CPUtime=1.31
/proc/9400/stat : 9400 (cudf_msu32) R 9399 9399 9023 34817 9081 4202496 11735 0 0 0 113 18 0 0 25 0 1 0 892274464 48492544 11579 1283457024 134512640 136125367 4286767760 18446744073709551615 135535283 0 0 0 25121 0 0 0 17 0 0 0 0
/proc/9400/statm: 11839 11579 165 394 0 11443 0
Current children cumulated CPU time (s) 1.31
Current children cumulated vsize (KiB) 49924

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

[startup+1.60584 s]
/proc/loadavg: 0.85 0.93 0.64 2/40 9401
/proc/meminfo: memFree=23076/1048576 swapFree=2095372/2097144
[pid=9399] ppid=9398 vsize=2568 CPUtime=0
/proc/9399/stat : 9399 (cudf2pbo4parano) S 9398 9399 9023 34817 9081 4202496 380 0 0 0 0 0 0 0 18 0 1 0 892274464 2629632 277 1283457024 134512640 135304128 4294357312 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/9399/statm: 642 277 238 194 0 28 0
[pid=9400] ppid=9399 vsize=47356 CPUtime=1.41
/proc/9400/stat : 9400 (cudf_msu32) R 9399 9399 9023 34817 9081 4202496 11735 0 0 0 117 24 0 0 25 0 1 0 892274464 48492544 11579 1283457024 134512640 136125367 4286767760 18446744073709551615 135168480 0 0 0 25121 0 0 0 17 0 0 0 0
/proc/9400/statm: 11839 11579 165 394 0 11443 0
Current children cumulated CPU time (s) 1.41
Current children cumulated vsize (KiB) 49924

[startup+2.00594 s]
/proc/loadavg: 0.85 0.93 0.64 2/40 9401
/proc/meminfo: memFree=23076/1048576 swapFree=2095372/2097144
[pid=9399] ppid=9398 vsize=2568 CPUtime=1.62
/proc/9399/stat : 9399 (cudf2pbo4parano) S 9398 9399 9023 34817 9081 4202496 400 11737 0 0 0 0 128 34 20 0 1 0 892274464 2629632 280 1283457024 134512640 135304128 4294357312 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/9399/statm: 642 280 241 194 0 28 0
Current children cumulated CPU time (s) 1.62
Current children cumulated vsize (KiB) 2568

[startup+2.40606 s]
/proc/loadavg: 0.85 0.93 0.64 2/40 9402
/proc/meminfo: memFree=40808/1048576 swapFree=2095372/2097144
[pid=9399] ppid=9398 vsize=2568 CPUtime=1.62
/proc/9399/stat : 9399 (cudf2pbo4parano) S 9398 9399 9023 34817 9081 4202496 400 11737 0 0 0 0 128 34 20 0 1 0 892274464 2629632 280 1283457024 134512640 135304128 4294357312 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/9399/statm: 642 280 241 194 0 28 0
[pid=9402] ppid=9399 vsize=19964 CPUtime=0.58
/proc/9402/stat : 9402 (bmo-pblex32) R 9399 9399 9023 34817 9081 4202496 5964 0 0 0 46 12 0 0 23 0 1 0 892274645 20443136 4680 1283457024 134512640 135887319 4291624768 18446744073709551615 134525040 0 0 0 16899 0 0 0 17 0 0 0 0
/proc/9402/statm: 4991 4680 143 336 0 4653 0
Current children cumulated CPU time (s) 2.2
Current children cumulated vsize (KiB) 22532

[startup+2.50608 s]
/proc/loadavg: 0.85 0.93 0.64 2/40 9402
/proc/meminfo: memFree=40808/1048576 swapFree=2095372/2097144
[pid=9399] ppid=9398 vsize=2568 CPUtime=1.62
/proc/9399/stat : 9399 (cudf2pbo4parano) S 9398 9399 9023 34817 9081 4202496 400 11737 0 0 0 0 128 34 20 0 1 0 892274464 2629632 280 1283457024 134512640 135304128 4294357312 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/9399/statm: 642 280 241 194 0 28 0
[pid=9402] ppid=9399 vsize=19964 CPUtime=0.68
/proc/9402/stat : 9402 (bmo-pblex32) R 9399 9399 9023 34817 9081 4202496 5978 0 0 0 55 13 0 0 23 0 1 0 892274645 20443136 4694 1283457024 134512640 135887319 4291624768 18446744073709551615 134600851 0 0 0 16899 0 0 0 17 0 0 0 0
/proc/9402/statm: 4991 4694 143 336 0 4653 0
Current children cumulated CPU time (s) 2.3
Current children cumulated vsize (KiB) 22532

Child status: 0
Real time (s): 2.58015
CPU time (s): 2.38015
CPU user time (s): 1.89212
CPU system time (s): 0.48803
CPU usage (%): 92.2485
Max. virtual memory (cumulated for all children) (KiB): 49924

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 1.89212
system time used= 0.48803
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 20009
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= 56
involuntary context switches= 377

runsolver used 0 second user time and 0.012 second system time

The end