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/randadea40.cudf.easy.log.runsolver ./cudf2msu4user-1.0 /home/misc2010/data/2010/easy//randadea40.cudf /home/misc2010/tmp/201012091434/cudf2msu4user-1.0/randadea40.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.08 1.05 1.03 4/39 32548
/proc/meminfo: memFree=404544/1048576 swapFree=2095372/2097144
[pid=32547] ppid=32546 vsize=2572 CPUtime=0
/proc/32547/stat : 32547 (cudf2msu4user-1) S 32546 32547 25521 34816 25544 4202496 381 0 0 0 0 0 0 0 18 0 1 0 900564974 2633728 278 1283457024 134512640 135304128 4292446096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/32547/statm: 643 278 237 194 0 29 0
[pid=32548] ppid=32547 vsize=2044 CPUtime=0.01
/proc/32548/stat : 32548 (cudf_msu32) R 32547 32547 25521 34816 25544 4202496 271 0 0 0 0 1 0 0 25 0 1 0 900564974 2093056 210 1283457024 134512640 136120023 4294052160 18446744073709551615 135528598 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/32548/statm: 511 210 140 393 0 116 0

[startup+0.205859 s]
/proc/loadavg: 1.08 1.05 1.03 4/39 32548
/proc/meminfo: memFree=404544/1048576 swapFree=2095372/2097144
[pid=32547] ppid=32546 vsize=2572 CPUtime=0
/proc/32547/stat : 32547 (cudf2msu4user-1) S 32546 32547 25521 34816 25544 4202496 381 0 0 0 0 0 0 0 18 0 1 0 900564974 2633728 278 1283457024 134512640 135304128 4292446096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/32547/statm: 643 278 237 194 0 29 0
[pid=32548] ppid=32547 vsize=10100 CPUtime=0.2
/proc/32548/stat : 32548 (cudf_msu32) R 32547 32547 25521 34816 25544 4202496 2297 0 0 0 18 2 0 0 25 0 1 0 900564974 10342400 2236 1283457024 134512640 136120023 4294052160 18446744073709551615 134722710 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/32548/statm: 2525 2236 141 393 0 2130 0
Current children cumulated CPU time (s) 0.2
Current children cumulated vsize (KiB) 12672

[startup+0.305871 s]
/proc/loadavg: 1.08 1.05 1.03 4/39 32548
/proc/meminfo: memFree=404544/1048576 swapFree=2095372/2097144
[pid=32547] ppid=32546 vsize=2572 CPUtime=0
/proc/32547/stat : 32547 (cudf2msu4user-1) S 32546 32547 25521 34816 25544 4202496 381 0 0 0 0 0 0 0 18 0 1 0 900564974 2633728 278 1283457024 134512640 135304128 4292446096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/32547/statm: 643 278 237 194 0 29 0
[pid=32548] ppid=32547 vsize=13728 CPUtime=0.3
/proc/32548/stat : 32548 (cudf_msu32) R 32547 32547 25521 34816 25544 4202496 3212 0 0 0 27 3 0 0 25 0 1 0 900564974 14057472 3151 1283457024 134512640 136120023 4294052160 18446744073709551615 135528598 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/32548/statm: 3432 3151 142 393 0 3037 0
Current children cumulated CPU time (s) 0.3
Current children cumulated vsize (KiB) 16300

[startup+0.405887 s]
/proc/loadavg: 1.08 1.05 1.03 4/39 32548
/proc/meminfo: memFree=404544/1048576 swapFree=2095372/2097144
[pid=32547] ppid=32546 vsize=2572 CPUtime=0
/proc/32547/stat : 32547 (cudf2msu4user-1) S 32546 32547 25521 34816 25544 4202496 381 0 0 0 0 0 0 0 18 0 1 0 900564974 2633728 278 1283457024 134512640 135304128 4292446096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/32547/statm: 643 278 237 194 0 29 0
[pid=32548] ppid=32547 vsize=17224 CPUtime=0.4
/proc/32548/stat : 32548 (cudf_msu32) R 32547 32547 25521 34816 25544 4202496 4056 0 0 0 37 3 0 0 25 0 1 0 900564974 17637376 3995 1283457024 134512640 136120023 4294052160 18446744073709551615 134721232 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/32548/statm: 4306 3995 142 393 0 3911 0
Current children cumulated CPU time (s) 0.4
Current children cumulated vsize (KiB) 19796

[startup+0.705968 s]
/proc/loadavg: 1.08 1.05 1.03 4/39 32548
/proc/meminfo: memFree=404544/1048576 swapFree=2095372/2097144
[pid=32547] ppid=32546 vsize=2572 CPUtime=0
/proc/32547/stat : 32547 (cudf2msu4user-1) S 32546 32547 25521 34816 25544 4202496 381 0 0 0 0 0 0 0 18 0 1 0 900564974 2633728 278 1283457024 134512640 135304128 4292446096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/32547/statm: 643 278 237 194 0 29 0
[pid=32548] ppid=32547 vsize=38704 CPUtime=0.7
/proc/32548/stat : 32548 (cudf_msu32) R 32547 32547 25521 34816 25544 4202496 9477 0 0 0 64 6 0 0 25 0 1 0 900564974 39632896 9415 1283457024 134512640 136120023 4294052160 18446744073709551615 134872503 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/32548/statm: 9676 9415 179 393 0 9281 0
Current children cumulated CPU time (s) 0.7
Current children cumulated vsize (KiB) 41276

[startup+1.50613 s]
/proc/loadavg: 1.08 1.05 1.03 2/40 32549
/proc/meminfo: memFree=367820/1048576 swapFree=2095372/2097144
[pid=32547] ppid=32546 vsize=2572 CPUtime=0
/proc/32547/stat : 32547 (cudf2msu4user-1) S 32546 32547 25521 34816 25544 4202496 381 0 0 0 0 0 0 0 18 0 1 0 900564974 2633728 278 1283457024 134512640 135304128 4292446096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/32547/statm: 643 278 237 194 0 29 0
[pid=32548] ppid=32547 vsize=38704 CPUtime=1.5
/proc/32548/stat : 32548 (cudf_msu32) R 32547 32547 25521 34816 25544 4202496 9477 0 0 0 144 6 0 0 25 0 1 0 900564974 39632896 9415 1283457024 134512640 136120023 4294052160 18446744073709551615 134869763 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/32548/statm: 9676 9415 179 393 0 9281 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 41276

[startup+3.10664 s]
/proc/loadavg: 1.08 1.05 1.03 2/40 32549
/proc/meminfo: memFree=367332/1048576 swapFree=2095372/2097144
[pid=32547] ppid=32546 vsize=2572 CPUtime=0
/proc/32547/stat : 32547 (cudf2msu4user-1) S 32546 32547 25521 34816 25544 4202496 381 0 0 0 0 0 0 0 18 0 1 0 900564974 2633728 278 1283457024 134512640 135304128 4292446096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/32547/statm: 643 278 237 194 0 29 0
[pid=32548] ppid=32547 vsize=39396 CPUtime=3.1
/proc/32548/stat : 32548 (cudf_msu32) R 32547 32547 25521 34816 25544 4202496 9720 0 0 0 303 7 0 0 25 0 1 0 900564974 40341504 9586 1283457024 134512640 136120023 4294052160 18446744073709551615 134869125 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/32548/statm: 9849 9586 185 393 0 9454 0
Current children cumulated CPU time (s) 3.1
Current children cumulated vsize (KiB) 41968

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

[startup+3.30671 s]
/proc/loadavg: 1.08 1.05 1.03 2/40 32549
/proc/meminfo: memFree=367332/1048576 swapFree=2095372/2097144
[pid=32547] ppid=32546 vsize=2572 CPUtime=0
/proc/32547/stat : 32547 (cudf2msu4user-1) S 32546 32547 25521 34816 25544 4202496 381 0 0 0 0 0 0 0 18 0 1 0 900564974 2633728 278 1283457024 134512640 135304128 4292446096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/32547/statm: 643 278 237 194 0 29 0
[pid=32548] ppid=32547 vsize=39396 CPUtime=3.3
/proc/32548/stat : 32548 (cudf_msu32) R 32547 32547 25521 34816 25544 4202496 9720 0 0 0 323 7 0 0 25 0 1 0 900564974 40341504 9586 1283457024 134512640 136120023 4294052160 18446744073709551615 134863525 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/32548/statm: 9849 9586 185 393 0 9454 0
Current children cumulated CPU time (s) 3.3
Current children cumulated vsize (KiB) 41968

[startup+3.50678 s]
/proc/loadavg: 1.07 1.05 1.03 2/40 32549
/proc/meminfo: memFree=366340/1048576 swapFree=2095372/2097144
[pid=32547] ppid=32546 vsize=2572 CPUtime=0
/proc/32547/stat : 32547 (cudf2msu4user-1) S 32546 32547 25521 34816 25544 4202496 381 0 0 0 0 0 0 0 18 0 1 0 900564974 2633728 278 1283457024 134512640 135304128 4292446096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/32547/statm: 643 278 237 194 0 29 0
[pid=32548] ppid=32547 vsize=40064 CPUtime=3.49
/proc/32548/stat : 32548 (cudf_msu32) R 32547 32547 25521 34816 25544 4202496 10042 0 0 0 342 7 0 0 25 0 1 0 900564974 41025536 9769 1283457024 134512640 136120023 4294052160 18446744073709551615 134831648 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/32548/statm: 10016 9769 185 393 0 9621 0
Current children cumulated CPU time (s) 3.49
Current children cumulated vsize (KiB) 42636

[startup+3.60682 s]
/proc/loadavg: 1.07 1.05 1.03 2/40 32549
/proc/meminfo: memFree=366340/1048576 swapFree=2095372/2097144
[pid=32547] ppid=32546 vsize=2572 CPUtime=0
/proc/32547/stat : 32547 (cudf2msu4user-1) S 32546 32547 25521 34816 25544 4202496 381 0 0 0 0 0 0 0 18 0 1 0 900564974 2633728 278 1283457024 134512640 135304128 4292446096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/32547/statm: 643 278 237 194 0 29 0
[pid=32548] ppid=32547 vsize=38736 CPUtime=3.59
/proc/32548/stat : 32548 (cudf_msu32) R 32547 32547 25521 34816 25544 4202496 10056 0 0 0 351 8 0 0 25 0 1 0 900564974 39665664 9461 1283457024 134512640 136120023 4294052160 18446744073709551615 135589886 0 0 0 16929 0 0 0 17 0 0 0 0
/proc/32548/statm: 9684 9461 199 393 0 9289 0
Current children cumulated CPU time (s) 3.59
Current children cumulated vsize (KiB) 41308

Child status: 0
Real time (s): 3.65375
CPU time (s): 3.63623
CPU user time (s): 3.53222
CPU system time (s): 0.104006
CPU usage (%): 99.5203
Max. virtual memory (cumulated for all children) (KiB): 42636

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

runsolver used 0 second user time and 0 second system time

The end