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/rand753.sarge-etch.cudf.sarge-etch.log.runsolver ./cudf2pbo4paranoid-1.0 /home/misc2010/data/icse/sarge-etch/rand753.sarge-etch.cudf /home/misc2010/tmp/201012081719/cudf2pbo4paranoid-1.0/rand753.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: 0.84 0.94 0.90 5/35 11908
/proc/meminfo: memFree=54404/1048576 swapFree=2095372/2097144
[pid=11907] ppid=11906 vsize=2572 CPUtime=0
/proc/11907/stat : 11907 (cudf2pbo4parano) R 11906 11907 9023 34817 9081 4202496 366 0 0 0 0 0 0 0 25 0 1 0 893817645 2633728 279 1283457024 134512640 135304128 4288275360 18446744073709551615 4294960130 0 65538 4 82432 0 0 0 17 0 0 0 0
/proc/11907/statm: 643 279 238 194 0 29 0
[pid=11908] ppid=11907 vsize=2572 CPUtime=0
/proc/11908/stat : 11908 (cudf2pbo4parano) R 11907 11907 9023 34817 9081 4202560 0 0 0 0 0 0 0 0 25 0 1 0 893817645 2633728 41 1283457024 134512640 135304128 4288275360 18446744073709551615 4294960130 0 65538 4 82432 0 0 0 17 0 0 0 0
/proc/11908/statm: 643 41 0 194 0 29 0

[startup+0.136504 s]
/proc/loadavg: 0.84 0.94 0.90 5/35 11908
/proc/meminfo: memFree=54404/1048576 swapFree=2095372/2097144
[pid=11907] ppid=11906 vsize=2572 CPUtime=0
/proc/11907/stat : 11907 (cudf2pbo4parano) S 11906 11907 9023 34817 9081 4202496 384 0 0 0 0 0 0 0 25 0 1 0 893817645 2633728 279 1283457024 134512640 135304128 4288275360 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/11907/statm: 643 279 238 194 0 29 0
[pid=11908] ppid=11907 vsize=6548 CPUtime=0.1
/proc/11908/stat : 11908 (cudf_msu32) R 11907 11907 9023 34817 9081 4202496 1435 0 0 0 10 0 0 0 25 0 1 0 893817645 6705152 1327 1283457024 134512640 136125367 4294865504 18446744073709551615 134727019 0 0 0 25121 0 0 0 17 0 0 0 0
/proc/11908/statm: 1637 1327 143 394 0 1241 0
Current children cumulated CPU time (s) 0.1
Current children cumulated vsize (KiB) 9120

[startup+0.204504 s]
/proc/loadavg: 0.84 0.94 0.90 5/35 11908
/proc/meminfo: memFree=54404/1048576 swapFree=2095372/2097144
[pid=11907] ppid=11906 vsize=2572 CPUtime=0
/proc/11907/stat : 11907 (cudf2pbo4parano) S 11906 11907 9023 34817 9081 4202496 384 0 0 0 0 0 0 0 25 0 1 0 893817645 2633728 279 1283457024 134512640 135304128 4288275360 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/11907/statm: 643 279 238 194 0 29 0
[pid=11908] ppid=11907 vsize=8924 CPUtime=0.16
/proc/11908/stat : 11908 (cudf_msu32) R 11907 11907 9023 34817 9081 4202496 2041 0 0 0 16 0 0 0 25 0 1 0 893817645 9138176 1933 1283457024 134512640 136125367 4294865504 18446744073709551615 134717885 0 0 0 25121 0 0 0 17 0 0 0 0
/proc/11908/statm: 2231 1933 143 394 0 1835 0
Current children cumulated CPU time (s) 0.16
Current children cumulated vsize (KiB) 11496

[startup+0.304509 s]
/proc/loadavg: 0.84 0.94 0.90 5/35 11908
/proc/meminfo: memFree=54404/1048576 swapFree=2095372/2097144
[pid=11907] ppid=11906 vsize=2572 CPUtime=0
/proc/11907/stat : 11907 (cudf2pbo4parano) S 11906 11907 9023 34817 9081 4202496 384 0 0 0 0 0 0 0 25 0 1 0 893817645 2633728 279 1283457024 134512640 135304128 4288275360 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/11907/statm: 643 279 238 194 0 29 0
[pid=11908] ppid=11907 vsize=12112 CPUtime=0.24
/proc/11908/stat : 11908 (cudf_msu32) R 11907 11907 9023 34817 9081 4202496 2855 0 0 0 24 0 0 0 25 0 1 0 893817645 12402688 2747 1283457024 134512640 136125367 4294865504 18446744073709551615 135684553 0 0 0 25121 0 0 0 17 0 0 0 0
/proc/11908/statm: 3028 2747 143 394 0 2632 0
Current children cumulated CPU time (s) 0.24
Current children cumulated vsize (KiB) 14684

[startup+0.70603 s]
/proc/loadavg: 0.84 0.94 0.90 5/35 11908
/proc/meminfo: memFree=54404/1048576 swapFree=2095372/2097144
[pid=11907] ppid=11906 vsize=2572 CPUtime=0
/proc/11907/stat : 11907 (cudf2pbo4parano) S 11906 11907 9023 34817 9081 4202496 384 0 0 0 0 0 0 0 25 0 1 0 893817645 2633728 279 1283457024 134512640 135304128 4288275360 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/11907/statm: 643 279 238 194 0 29 0
[pid=11908] ppid=11907 vsize=21476 CPUtime=0.64
/proc/11908/stat : 11908 (cudf_msu32) R 11907 11907 9023 34817 9081 4202496 5201 0 0 0 56 8 0 0 25 0 1 0 893817645 21991424 5093 1283457024 134512640 136125367 4294865504 18446744073709551615 135530993 0 0 0 25121 0 0 0 17 0 0 0 0
/proc/11908/statm: 5369 5093 165 394 0 4973 0
Current children cumulated CPU time (s) 0.64
Current children cumulated vsize (KiB) 24048

[startup+1.50619 s]
/proc/loadavg: 0.84 0.94 0.90 2/36 11910
/proc/meminfo: memFree=37220/1048576 swapFree=2095372/2097144
[pid=11907] ppid=11906 vsize=2572 CPUtime=0.66
/proc/11907/stat : 11907 (cudf2pbo4parano) S 11906 11907 9023 34817 9081 4202496 404 5203 0 0 0 0 58 8 18 0 1 0 893817645 2633728 282 1283457024 134512640 135304128 4288275360 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/11907/statm: 643 282 241 194 0 29 0
[pid=11910] ppid=11907 vsize=11424 CPUtime=0.73
/proc/11910/stat : 11910 (bmo-pblex32) R 11907 11907 9023 34817 9081 4202496 3344 0 0 0 58 15 0 0 25 0 1 0 893817718 11698176 2533 1283457024 134512640 135887319 4287480672 18446744073709551615 134525304 0 0 0 16899 0 0 0 17 0 0 0 0
/proc/11910/statm: 2856 2533 143 336 0 2518 0
Current children cumulated CPU time (s) 1.39
Current children cumulated vsize (KiB) 13996

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

[startup+1.60621 s]
/proc/loadavg: 0.84 0.94 0.90 2/36 11910
/proc/meminfo: memFree=37220/1048576 swapFree=2095372/2097144
[pid=11907] ppid=11906 vsize=2572 CPUtime=0.66
/proc/11907/stat : 11907 (cudf2pbo4parano) S 11906 11907 9023 34817 9081 4202496 404 5203 0 0 0 0 58 8 18 0 1 0 893817645 2633728 282 1283457024 134512640 135304128 4288275360 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/11907/statm: 643 282 241 194 0 29 0
[pid=11910] ppid=11907 vsize=11688 CPUtime=0.83
/proc/11910/stat : 11910 (bmo-pblex32) R 11907 11907 9023 34817 9081 4202496 3406 0 0 0 63 20 0 0 25 0 1 0 893817718 11968512 2595 1283457024 134512640 135887319 4287480672 18446744073709551615 135381649 0 0 0 16899 0 0 0 17 0 0 0 0
/proc/11910/statm: 2922 2595 143 336 0 2584 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 14260

[startup+1.70624 s]
/proc/loadavg: 0.84 0.94 0.90 2/36 11910
/proc/meminfo: memFree=37220/1048576 swapFree=2095372/2097144
[pid=11907] ppid=11906 vsize=2572 CPUtime=0.66
/proc/11907/stat : 11907 (cudf2pbo4parano) S 11906 11907 9023 34817 9081 4202496 404 5203 0 0 0 0 58 8 18 0 1 0 893817645 2633728 282 1283457024 134512640 135304128 4288275360 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/11907/statm: 643 282 241 194 0 29 0
[pid=11910] ppid=11907 vsize=11952 CPUtime=0.93
/proc/11910/stat : 11910 (bmo-pblex32) R 11907 11907 9023 34817 9081 4202496 3471 0 0 0 71 22 0 0 25 0 1 0 893817718 12238848 2660 1283457024 134512640 135887319 4287480672 18446744073709551615 134598581 0 0 0 16899 0 0 0 17 0 0 0 0
/proc/11910/statm: 2988 2660 143 336 0 2650 0
Current children cumulated CPU time (s) 1.59
Current children cumulated vsize (KiB) 14524

Child status: 0
Real time (s): 1.75931
CPU time (s): 1.6521
CPU user time (s): 1.33208
CPU system time (s): 0.32002
CPU usage (%): 93.9062
Max. virtual memory (cumulated for all children) (KiB): 24048

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 1.33208
system time used= 0.32002
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 10658
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= 29
involuntary context switches= 2113

runsolver used 0 second user time and 0 second system time

The end