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/rand180.sarge-etch-lenny-squeeze.cudf.sarge-etch-lenny-squeeze.log.runsolver ./cudf2pbo4paranoid-1.0 /home/misc2010/data/icse/sarge-etch-lenny-squeeze/rand180.sarge-etch-lenny-squeeze.cudf /home/misc2010/tmp/201012081719/cudf2pbo4paranoid-1.0/rand180.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.94 0.90 5/39 10201
/proc/meminfo: memFree=88876/1048576 swapFree=2095372/2097144
[pid=10200] ppid=10199 vsize=2572 CPUtime=0
/proc/10200/stat : 10200 (cudf2pbo4parano) R 10199 10200 9023 34817 9081 4202496 366 0 0 0 0 0 0 0 25 0 1 0 892846913 2633728 279 1283457024 134512640 135304128 4293142544 18446744073709551615 4294960130 0 65538 4 82432 0 0 0 17 0 0 0 0
/proc/10200/statm: 643 279 238 194 0 29 0
[pid=10201] ppid=10200 vsize=2572 CPUtime=0
/proc/10201/stat : 10201 (cudf2pbo4parano) R 10200 10200 9023 34817 9081 4202560 0 0 0 0 0 0 0 0 25 0 1 0 892846913 2633728 41 1283457024 134512640 135304128 4293142544 18446744073709551615 4294960130 0 65538 4 82432 0 0 0 17 0 0 0 0
/proc/10201/statm: 643 41 0 194 0 29 0

[startup+0.116432 s]
/proc/loadavg: 0.85 0.94 0.90 5/39 10201
/proc/meminfo: memFree=88876/1048576 swapFree=2095372/2097144
[pid=10200] ppid=10199 vsize=2572 CPUtime=0
/proc/10200/stat : 10200 (cudf2pbo4parano) S 10199 10200 9023 34817 9081 4202496 383 0 0 0 0 0 0 0 25 0 1 0 892846913 2633728 279 1283457024 134512640 135304128 4293142544 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/10200/statm: 643 279 238 194 0 29 0
[pid=10201] ppid=10200 vsize=6340 CPUtime=0.1
/proc/10201/stat : 10201 (cudf_msu32) R 10200 10200 9023 34817 9081 4202496 1390 0 0 0 9 1 0 0 25 0 1 0 892846913 6492160 1282 1283457024 134512640 136125367 4291512096 18446744073709551615 134717668 0 0 0 25121 0 0 0 17 0 0 0 0
/proc/10201/statm: 1585 1282 143 394 0 1189 0
Current children cumulated CPU time (s) 0.1
Current children cumulated vsize (KiB) 8912

[startup+0.204454 s]
/proc/loadavg: 0.85 0.94 0.90 5/39 10201
/proc/meminfo: memFree=88876/1048576 swapFree=2095372/2097144
[pid=10200] ppid=10199 vsize=2572 CPUtime=0
/proc/10200/stat : 10200 (cudf2pbo4parano) S 10199 10200 9023 34817 9081 4202496 383 0 0 0 0 0 0 0 25 0 1 0 892846913 2633728 279 1283457024 134512640 135304128 4293142544 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/10200/statm: 643 279 238 194 0 29 0
[pid=10201] ppid=10200 vsize=9772 CPUtime=0.17
/proc/10201/stat : 10201 (cudf_msu32) R 10200 10200 9023 34817 9081 4202496 2257 0 0 0 16 1 0 0 25 0 1 0 892846913 10006528 2149 1283457024 134512640 136125367 4291512096 18446744073709551615 134738431 0 0 0 25121 0 0 0 17 0 0 0 0
/proc/10201/statm: 2443 2149 143 394 0 2047 0
Current children cumulated CPU time (s) 0.17
Current children cumulated vsize (KiB) 12344

[startup+0.304467 s]
/proc/loadavg: 0.85 0.94 0.90 5/39 10201
/proc/meminfo: memFree=88876/1048576 swapFree=2095372/2097144
[pid=10200] ppid=10199 vsize=2572 CPUtime=0
/proc/10200/stat : 10200 (cudf2pbo4parano) S 10199 10200 9023 34817 9081 4202496 383 0 0 0 0 0 0 0 25 0 1 0 892846913 2633728 279 1283457024 134512640 135304128 4293142544 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/10200/statm: 643 279 238 194 0 29 0
[pid=10201] ppid=10200 vsize=13220 CPUtime=0.26
/proc/10201/stat : 10201 (cudf_msu32) R 10200 10200 9023 34817 9081 4202496 3112 0 0 0 25 1 0 0 25 0 1 0 892846913 13537280 3004 1283457024 134512640 136125367 4291512096 18446744073709551615 134717672 0 0 0 25121 0 0 0 17 0 0 0 0
/proc/10201/statm: 3305 3004 144 394 0 2909 0
Current children cumulated CPU time (s) 0.26
Current children cumulated vsize (KiB) 15792

[startup+0.704487 s]
/proc/loadavg: 0.85 0.94 0.90 5/39 10201
/proc/meminfo: memFree=88876/1048576 swapFree=2095372/2097144
[pid=10200] ppid=10199 vsize=2572 CPUtime=0
/proc/10200/stat : 10200 (cudf2pbo4parano) S 10199 10200 9023 34817 9081 4202496 383 0 0 0 0 0 0 0 25 0 1 0 892846913 2633728 279 1283457024 134512640 135304128 4293142544 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/10200/statm: 643 279 238 194 0 29 0
[pid=10201] ppid=10200 vsize=25428 CPUtime=0.61
/proc/10201/stat : 10201 (cudf_msu32) R 10200 10200 9023 34817 9081 4202496 6154 0 0 0 60 1 0 0 25 0 1 0 892846913 26038272 6046 1283457024 134512640 136125367 4291512096 18446744073709551615 134718040 0 0 0 25121 0 0 0 17 0 0 0 0
/proc/10201/statm: 6357 6046 144 394 0 5961 0
Current children cumulated CPU time (s) 0.61
Current children cumulated vsize (KiB) 28000

[startup+1.50656 s]
/proc/loadavg: 0.85 0.94 0.90 2/40 10202
/proc/meminfo: memFree=35980/1048576 swapFree=2095372/2097144
[pid=10200] ppid=10199 vsize=2572 CPUtime=0
/proc/10200/stat : 10200 (cudf2pbo4parano) S 10199 10200 9023 34817 9081 4202496 383 0 0 0 0 0 0 0 25 0 1 0 892846913 2633728 279 1283457024 134512640 135304128 4293142544 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/10200/statm: 643 279 238 194 0 29 0
[pid=10201] ppid=10200 vsize=47356 CPUtime=1.38
/proc/10201/stat : 10201 (cudf_msu32) R 10200 10200 9023 34817 9081 4202496 11737 0 0 0 125 13 0 0 25 0 1 0 892846913 48492544 11580 1283457024 134512640 136125367 4291512096 18446744073709551615 135594622 0 0 0 25121 0 0 0 17 0 0 0 0
/proc/10201/statm: 11839 11580 165 394 0 11443 0
Current children cumulated CPU time (s) 1.38
Current children cumulated vsize (KiB) 49928

[startup+3.107 s]
/proc/loadavg: 0.85 0.94 0.90 2/40 10203
/proc/meminfo: memFree=54332/1048576 swapFree=2095372/2097144
[pid=10200] ppid=10199 vsize=2572 CPUtime=1.64
/proc/10200/stat : 10200 (cudf2pbo4parano) S 10199 10200 9023 34817 9081 4202496 403 11739 0 0 0 0 140 24 18 0 1 0 892846913 2633728 282 1283457024 134512640 135304128 4293142544 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/10200/statm: 643 282 241 194 0 29 0
[pid=10203] ppid=10200 vsize=20236 CPUtime=1.33
/proc/10203/stat : 10203 (bmo-pblex32) R 10200 10200 9023 34817 9081 4202496 6056 0 0 0 110 23 0 0 25 0 1 0 892847090 20721664 4754 1283457024 134512640 135887319 4293665072 18446744073709551615 135324846 0 0 0 16899 0 0 0 17 0 0 0 0
/proc/10203/statm: 5059 4754 143 336 0 4721 0
Current children cumulated CPU time (s) 2.97
Current children cumulated vsize (KiB) 22808

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

[startup+3.20704 s]
/proc/loadavg: 0.85 0.94 0.90 2/40 10203
/proc/meminfo: memFree=54332/1048576 swapFree=2095372/2097144
[pid=10200] ppid=10199 vsize=2572 CPUtime=1.64
/proc/10200/stat : 10200 (cudf2pbo4parano) S 10199 10200 9023 34817 9081 4202496 403 11739 0 0 0 0 140 24 18 0 1 0 892846913 2633728 282 1283457024 134512640 135304128 4293142544 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/10200/statm: 643 282 241 194 0 29 0
[pid=10203] ppid=10200 vsize=20372 CPUtime=1.43
/proc/10203/stat : 10203 (bmo-pblex32) R 10200 10200 9023 34817 9081 4202496 6093 0 0 0 120 23 0 0 25 0 1 0 892847090 20860928 4791 1283457024 134512640 135887319 4293665072 18446744073709551615 134617654 0 0 0 16899 0 0 0 17 0 0 0 0
/proc/10203/statm: 5093 4791 143 336 0 4755 0
Current children cumulated CPU time (s) 3.07
Current children cumulated vsize (KiB) 22944

[startup+3.4071 s]
/proc/loadavg: 0.85 0.94 0.90 2/40 10203
/proc/meminfo: memFree=49124/1048576 swapFree=2095372/2097144
[pid=10200] ppid=10199 vsize=2572 CPUtime=3.25
/proc/10200/stat : 10200 (cudf2pbo4parano) R 10199 10200 9023 34817 9081 4202496 422 17901 0 0 0 0 276 49 18 0 1 0 892846913 2633728 282 1283457024 134512640 135304128 4293142544 18446744073709551615 4294960130 0 65538 4 82432 0 0 0 17 0 0 0 0
/proc/10200/statm: 643 282 241 194 0 29 0
Current children cumulated CPU time (s) 3.25
Current children cumulated vsize (KiB) 2572

Child status: 0
Real time (s): 3.43852
CPU time (s): 3.32021
CPU user time (s): 2.80418
CPU system time (s): 0.516032
CPU usage (%): 96.5592
Max. virtual memory (cumulated for all children) (KiB): 49928

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 2.80417
system time used= 0.516032
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 20194
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= 54
involuntary context switches= 884

runsolver used 0 second user time and 0 second system time

The end