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/201012091434/cudf2msu4user-1.0/rand6d933e.cudf.easy.log.runsolver ./cudf2msu4user-1.0 /home/misc2010/data/2010/easy//rand6d933e.cudf /home/misc2010/tmp/201012091434/cudf2msu4user-1.0/rand6d933e.cudf.easy.result -changed,-removed,-unmet_recommends,-new 

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.21 1.15 1.07 4/40 29683
/proc/meminfo: memFree=374288/1048576 swapFree=2095372/2097144
[pid=29682] ppid=29681 vsize=2572 CPUtime=0
/proc/29682/stat : 29682 (cudf2msu4user-1) S 29681 29682 25521 34816 25544 4202496 380 0 0 0 0 0 0 0 18 0 1 0 900176696 2633728 277 1283457024 134512640 135304128 4293126192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29682/statm: 643 277 237 194 0 29 0
[pid=29683] ppid=29682 vsize=2044 CPUtime=0.01
/proc/29683/stat : 29683 (cudf_msu32) R 29682 29682 25521 34816 25544 4202496 272 0 0 0 1 0 0 0 25 0 1 0 900176696 2093056 211 1283457024 134512640 136120023 4290278816 18446744073709551615 134713255 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/29683/statm: 511 211 140 393 0 116 0

[startup+0.165906 s]
/proc/loadavg: 1.21 1.15 1.07 4/40 29683
/proc/meminfo: memFree=374288/1048576 swapFree=2095372/2097144
[pid=29682] ppid=29681 vsize=2572 CPUtime=0
/proc/29682/stat : 29682 (cudf2msu4user-1) S 29681 29682 25521 34816 25544 4202496 380 0 0 0 0 0 0 0 18 0 1 0 900176696 2633728 277 1283457024 134512640 135304128 4293126192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29682/statm: 643 277 237 194 0 29 0
[pid=29683] ppid=29682 vsize=8724 CPUtime=0.16
/proc/29683/stat : 29683 (cudf_msu32) R 29682 29682 25521 34816 25544 4202496 1937 0 0 0 16 0 0 0 25 0 1 0 900176696 8933376 1876 1283457024 134512640 136120023 4290278816 18446744073709551615 134721247 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/29683/statm: 2181 1876 141 393 0 1786 0
Current children cumulated CPU time (s) 0.16
Current children cumulated vsize (KiB) 11296

[startup+0.205914 s]
/proc/loadavg: 1.21 1.15 1.07 4/40 29683
/proc/meminfo: memFree=374288/1048576 swapFree=2095372/2097144
[pid=29682] ppid=29681 vsize=2572 CPUtime=0
/proc/29682/stat : 29682 (cudf2msu4user-1) S 29681 29682 25521 34816 25544 4202496 380 0 0 0 0 0 0 0 18 0 1 0 900176696 2633728 277 1283457024 134512640 135304128 4293126192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29682/statm: 643 277 237 194 0 29 0
[pid=29683] ppid=29682 vsize=10100 CPUtime=0.21
/proc/29683/stat : 29683 (cudf_msu32) R 29682 29682 25521 34816 25544 4202496 2292 0 0 0 19 2 0 0 25 0 1 0 900176696 10342400 2231 1283457024 134512640 136120023 4290278816 18446744073709551615 135528598 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/29683/statm: 2525 2231 141 393 0 2130 0
Current children cumulated CPU time (s) 0.21
Current children cumulated vsize (KiB) 12672

[startup+0.305938 s]
/proc/loadavg: 1.21 1.15 1.07 4/40 29683
/proc/meminfo: memFree=374288/1048576 swapFree=2095372/2097144
[pid=29682] ppid=29681 vsize=2572 CPUtime=0
/proc/29682/stat : 29682 (cudf2msu4user-1) S 29681 29682 25521 34816 25544 4202496 380 0 0 0 0 0 0 0 18 0 1 0 900176696 2633728 277 1283457024 134512640 135304128 4293126192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29682/statm: 643 277 237 194 0 29 0
[pid=29683] ppid=29682 vsize=13728 CPUtime=0.31
/proc/29683/stat : 29683 (cudf_msu32) R 29682 29682 25521 34816 25544 4202496 3192 0 0 0 29 2 0 0 25 0 1 0 900176696 14057472 3131 1283457024 134512640 136120023 4290278816 18446744073709551615 135534668 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/29683/statm: 3432 3131 142 393 0 3037 0
Current children cumulated CPU time (s) 0.31
Current children cumulated vsize (KiB) 16300

[startup+0.706076 s]
/proc/loadavg: 1.21 1.15 1.07 4/40 29683
/proc/meminfo: memFree=374288/1048576 swapFree=2095372/2097144
[pid=29682] ppid=29681 vsize=2572 CPUtime=0
/proc/29682/stat : 29682 (cudf2msu4user-1) S 29681 29682 25521 34816 25544 4202496 380 0 0 0 0 0 0 0 18 0 1 0 900176696 2633728 277 1283457024 134512640 135304128 4293126192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29682/statm: 643 277 237 194 0 29 0
[pid=29683] ppid=29682 vsize=38836 CPUtime=0.71
/proc/29683/stat : 29683 (cudf_msu32) R 29682 29682 25521 34816 25544 4202496 9520 0 0 0 68 3 0 0 25 0 1 0 900176696 39768064 9458 1283457024 134512640 136120023 4290278816 18446744073709551615 134872833 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/29683/statm: 9709 9458 179 393 0 9314 0
Current children cumulated CPU time (s) 0.71
Current children cumulated vsize (KiB) 41408

[startup+1.50628 s]
/proc/loadavg: 1.20 1.15 1.07 2/41 29684
/proc/meminfo: memFree=337316/1048576 swapFree=2095372/2097144
[pid=29682] ppid=29681 vsize=2572 CPUtime=0
/proc/29682/stat : 29682 (cudf2msu4user-1) S 29681 29682 25521 34816 25544 4202496 380 0 0 0 0 0 0 0 18 0 1 0 900176696 2633728 277 1283457024 134512640 135304128 4293126192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29682/statm: 643 277 237 194 0 29 0
[pid=29683] ppid=29682 vsize=39100 CPUtime=1.51
/proc/29683/stat : 29683 (cudf_msu32) R 29682 29682 25521 34816 25544 4202496 9590 0 0 0 147 4 0 0 25 0 1 0 900176696 40038400 9527 1283457024 134512640 136120023 4290278816 18446744073709551615 134867567 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/29683/statm: 9775 9527 183 393 0 9380 0
Current children cumulated CPU time (s) 1.51
Current children cumulated vsize (KiB) 41672

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

[startup+1.6063 s]
/proc/loadavg: 1.20 1.15 1.07 2/41 29684
/proc/meminfo: memFree=337316/1048576 swapFree=2095372/2097144
[pid=29682] ppid=29681 vsize=2572 CPUtime=0
/proc/29682/stat : 29682 (cudf2msu4user-1) S 29681 29682 25521 34816 25544 4202496 380 0 0 0 0 0 0 0 18 0 1 0 900176696 2633728 277 1283457024 134512640 135304128 4293126192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29682/statm: 643 277 237 194 0 29 0
[pid=29683] ppid=29682 vsize=39100 CPUtime=1.61
/proc/29683/stat : 29683 (cudf_msu32) R 29682 29682 25521 34816 25544 4202496 9590 0 0 0 157 4 0 0 25 0 1 0 900176696 40038400 9527 1283457024 134512640 136120023 4290278816 18446744073709551615 134867751 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/29683/statm: 9775 9527 183 393 0 9380 0
Current children cumulated CPU time (s) 1.61
Current children cumulated vsize (KiB) 41672

[startup+2.40647 s]
/proc/loadavg: 1.20 1.15 1.07 2/41 29684
/proc/meminfo: memFree=336820/1048576 swapFree=2095372/2097144
[pid=29682] ppid=29681 vsize=2572 CPUtime=0
/proc/29682/stat : 29682 (cudf2msu4user-1) S 29681 29682 25521 34816 25544 4202496 380 0 0 0 0 0 0 0 18 0 1 0 900176696 2633728 277 1283457024 134512640 135304128 4293126192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29682/statm: 643 277 237 194 0 29 0
[pid=29683] ppid=29682 vsize=39320 CPUtime=2.41
/proc/29683/stat : 29683 (cudf_msu32) R 29682 29682 25521 34816 25544 4202496 9678 0 0 0 237 4 0 0 25 0 1 0 900176696 40263680 9580 1283457024 134512640 136120023 4290278816 18446744073709551615 134831643 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/29683/statm: 9830 9580 185 393 0 9435 0
Current children cumulated CPU time (s) 2.41
Current children cumulated vsize (KiB) 41892

[startup+2.8066 s]
/proc/loadavg: 1.20 1.15 1.07 2/41 29684
/proc/meminfo: memFree=336820/1048576 swapFree=2095372/2097144
[pid=29682] ppid=29681 vsize=2572 CPUtime=0
/proc/29682/stat : 29682 (cudf2msu4user-1) S 29681 29682 25521 34816 25544 4202496 380 0 0 0 0 0 0 0 18 0 1 0 900176696 2633728 277 1283457024 134512640 135304128 4293126192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29682/statm: 643 277 237 194 0 29 0
[pid=29683] ppid=29682 vsize=39388 CPUtime=2.8
/proc/29683/stat : 29683 (cudf_msu32) R 29682 29682 25521 34816 25544 4202496 9834 0 0 0 276 4 0 0 25 0 1 0 900176696 40333312 9610 1283457024 134512640 136120023 4290278816 18446744073709551615 135511897 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/29683/statm: 9847 9610 185 393 0 9452 0
Current children cumulated CPU time (s) 2.8
Current children cumulated vsize (KiB) 41960

[startup+3.00666 s]
/proc/loadavg: 1.20 1.15 1.07 2/41 29684
/proc/meminfo: memFree=336820/1048576 swapFree=2095372/2097144
[pid=29682] ppid=29681 vsize=2572 CPUtime=0
/proc/29682/stat : 29682 (cudf2msu4user-1) S 29681 29682 25521 34816 25544 4202496 380 0 0 0 0 0 0 0 18 0 1 0 900176696 2633728 277 1283457024 134512640 135304128 4293126192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29682/statm: 643 277 237 194 0 29 0
[pid=29683] ppid=29682 vsize=39192 CPUtime=3.01
/proc/29683/stat : 29683 (cudf_msu32) R 29682 29682 25521 34816 25544 4202496 9849 0 0 0 295 6 0 0 25 0 1 0 900176696 40132608 9576 1283457024 134512640 136120023 4290278816 18446744073709551615 134591823 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/29683/statm: 9798 9576 200 393 0 9403 0
Current children cumulated CPU time (s) 3.01
Current children cumulated vsize (KiB) 41764

Child status: 0
Real time (s): 3.03099
CPU time (s): 3.03219
CPU user time (s): 2.96019
CPU system time (s): 0.072004
CPU usage (%): 100.04
Max. virtual memory (cumulated for all children) (KiB): 41960

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 2.96019
system time used= 0.072004
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 10241
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= 78

runsolver used 0 second user time and 0 second system time

The end