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/201012061533/p2cudf-paranoid-1.9/randea6106.cudf.easy.log.runsolver ./p2cudf-paranoid-1.9 /home/misc2010/data/2010/easy//randea6106.cudf /home/misc2010/tmp/201012061533/p2cudf-paranoid-1.9/randea6106.cudf.easy.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: 1.41 1.43 1.31 6/42 2602
/proc/meminfo: memFree=598048/1048576 swapFree=2084004/2097144
[pid=2599] ppid=2598 vsize=2576 CPUtime=0
/proc/2599/stat : 2599 (p2cudf-paranoid) S 2598 2599 2059 34821 2220 4202496 378 0 0 0 0 0 0 0 23 0 1 0 876728242 2637824 273 1283457024 134512640 135304128 4287050400 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2599/statm: 644 273 233 194 0 30 0
[pid=2600] ppid=2599 vsize=2576 CPUtime=0
/proc/2600/stat : 2600 (p2cudf) S 2599 2599 2059 34821 2220 4202496 357 0 0 0 0 0 0 0 23 0 1 0 876728243 2637824 275 1283457024 134512640 135304128 4290467312 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0
/proc/2600/statm: 644 275 234 194 0 30 0
[pid=2601] ppid=2600 vsize=2576 CPUtime=0
/proc/2601/stat : 2601 (p2cudf) R 2600 2599 2059 34821 2220 4202560 92 0 0 0 0 0 0 0 25 0 1 0 876728243 2637824 117 1283457024 134512640 135304128 4290467312 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/2601/statm: 644 117 75 194 0 30 0
[pid=2602] ppid=2601 vsize=2576 CPUtime=0
/proc/2602/stat : 2602 (p2cudf) R 2601 2599 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 1 0 876728243 2637824 42 1283457024 134512640 135304128 4290467312 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/2602/statm: 644 42 0 194 0 30 0

[startup+0.154387 s]
/proc/loadavg: 1.41 1.43 1.31 6/42 2602
/proc/meminfo: memFree=598048/1048576 swapFree=2084004/2097144
[pid=2599] ppid=2598 vsize=2576 CPUtime=0
/proc/2599/stat : 2599 (p2cudf-paranoid) S 2598 2599 2059 34821 2220 4202496 378 0 0 0 0 0 0 0 23 0 1 0 876728242 2637824 273 1283457024 134512640 135304128 4287050400 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2599/statm: 644 273 233 194 0 30 0
[pid=2600] ppid=2599 vsize=2580 CPUtime=0.03
/proc/2600/stat : 2600 (p2cudf) S 2599 2599 2059 34821 2220 4202496 394 2996 0 1 0 0 2 1 25 0 1 0 876728243 2641920 283 1283457024 134512640 135304128 4290467312 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2600/statm: 645 283 241 194 0 31 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5156

[startup+0.204401 s]
/proc/loadavg: 1.41 1.43 1.31 6/42 2602
/proc/meminfo: memFree=598048/1048576 swapFree=2084004/2097144
[pid=2599] ppid=2598 vsize=2576 CPUtime=0
/proc/2599/stat : 2599 (p2cudf-paranoid) S 2598 2599 2059 34821 2220 4202496 378 0 0 0 0 0 0 0 23 0 1 0 876728242 2637824 273 1283457024 134512640 135304128 4287050400 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2599/statm: 644 273 233 194 0 30 0
[pid=2600] ppid=2599 vsize=2580 CPUtime=0.03
/proc/2600/stat : 2600 (p2cudf) S 2599 2599 2059 34821 2220 4202496 394 2996 0 1 0 0 2 1 25 0 1 0 876728243 2641920 283 1283457024 134512640 135304128 4290467312 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2600/statm: 645 283 241 194 0 31 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5156

[startup+0.304418 s]
/proc/loadavg: 1.41 1.43 1.31 6/42 2602
/proc/meminfo: memFree=598048/1048576 swapFree=2084004/2097144
[pid=2599] ppid=2598 vsize=2576 CPUtime=0
/proc/2599/stat : 2599 (p2cudf-paranoid) S 2598 2599 2059 34821 2220 4202496 378 0 0 0 0 0 0 0 23 0 1 0 876728242 2637824 273 1283457024 134512640 135304128 4287050400 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2599/statm: 644 273 233 194 0 30 0
[pid=2600] ppid=2599 vsize=2580 CPUtime=0.03
/proc/2600/stat : 2600 (p2cudf) S 2599 2599 2059 34821 2220 4202496 394 2996 0 1 0 0 2 1 25 0 1 0 876728243 2641920 283 1283457024 134512640 135304128 4290467312 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2600/statm: 645 283 241 194 0 31 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5156

[startup+0.704468 s]
/proc/loadavg: 1.41 1.43 1.31 6/42 2602
/proc/meminfo: memFree=598048/1048576 swapFree=2084004/2097144
[pid=2599] ppid=2598 vsize=2576 CPUtime=0
/proc/2599/stat : 2599 (p2cudf-paranoid) S 2598 2599 2059 34821 2220 4202496 378 0 0 0 0 0 0 0 23 0 1 0 876728242 2637824 273 1283457024 134512640 135304128 4287050400 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2599/statm: 644 273 233 194 0 30 0
[pid=2600] ppid=2599 vsize=2580 CPUtime=0.03
/proc/2600/stat : 2600 (p2cudf) S 2599 2599 2059 34821 2220 4202496 394 2996 0 1 0 0 2 1 25 0 1 0 876728243 2641920 283 1283457024 134512640 135304128 4290467312 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2600/statm: 645 283 241 194 0 31 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5156

[startup+1.50461 s]
/proc/loadavg: 1.46 1.44 1.31 5/51 2622
/proc/meminfo: memFree=554900/1048576 swapFree=2084004/2097144
[pid=2599] ppid=2598 vsize=2576 CPUtime=0
/proc/2599/stat : 2599 (p2cudf-paranoid) S 2598 2599 2059 34821 2220 4202496 378 0 0 0 0 0 0 0 23 0 1 0 876728242 2637824 273 1283457024 134512640 135304128 4287050400 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2599/statm: 644 273 233 194 0 30 0
[pid=2600] ppid=2599 vsize=2580 CPUtime=0.03
/proc/2600/stat : 2600 (p2cudf) S 2599 2599 2059 34821 2220 4202496 394 2996 0 1 0 0 2 1 25 0 1 0 876728243 2641920 283 1283457024 134512640 135304128 4290467312 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2600/statm: 645 283 241 194 0 31 0
[pid=2613] ppid=2600 vsize=883372 CPUtime=1.46
/proc/2613/stat : 2613 (java) S 2600 2599 2059 34821 2220 4202496 21615 0 1 0 142 4 0 0 25 0 10 0 876728246 904572928 17819 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/2613/statm: 220843 17819 1729 10 0 217933 0
[pid=2613/tid=2614] ppid=2600 vsize=883372 CPUtime=0.79
/proc/2613/task/2614/stat : 2614 (java) R 2600 2599 2059 34821 2220 4202560 10656 0 1 0 76 3 0 0 25 0 10 0 876728247 904572928 17819 1283457024 134512640 134550932 4294559856 18446744073709551615 4095672574 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=2613/tid=2615] ppid=2600 vsize=883372 CPUtime=0
/proc/2613/task/2615/stat : 2615 (java) S 2600 2599 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 18 0 10 0 876728248 904572928 17819 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 0 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2616] ppid=2600 vsize=883372 CPUtime=0
/proc/2613/task/2616/stat : 2616 (java) S 2600 2599 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 25 0 10 0 876728249 904572928 17819 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2617] ppid=2600 vsize=883372 CPUtime=0
/proc/2613/task/2617/stat : 2617 (java) S 2600 2599 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 10 0 876728249 904572928 17819 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2618] ppid=2600 vsize=883372 CPUtime=0
/proc/2613/task/2618/stat : 2618 (java) S 2600 2599 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 876728251 904572928 17819 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2619] ppid=2600 vsize=883372 CPUtime=0.38
/proc/2613/task/2619/stat : 2619 (java) R 2600 2599 2059 34821 2220 4202560 6882 0 0 0 38 0 0 0 22 0 10 0 876728251 904572928 17819 1283457024 134512640 134550932 4294559856 18446744073709551615 4149422536 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=2613/tid=2620] ppid=2600 vsize=883372 CPUtime=0.28
/proc/2613/task/2620/stat : 2620 (java) R 2600 2599 2059 34821 2220 4202560 2962 0 0 0 28 0 0 0 25 0 10 0 876728251 904572928 17819 1283457024 134512640 134550932 4294559856 18446744073709551615 4150512531 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=2613/tid=2621] ppid=2600 vsize=883372 CPUtime=0
/proc/2613/task/2621/stat : 2621 (java) S 2600 2599 2059 34821 2220 4202560 2 0 0 0 0 0 0 0 25 0 10 0 876728251 904572928 17819 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2622] ppid=2600 vsize=883372 CPUtime=0
/proc/2613/task/2622/stat : 2622 (java) S 2600 2599 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 10 0 876728251 904572928 17819 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 888528

[startup+3.1049 s]
/proc/loadavg: 1.46 1.44 1.31 4/51 2622
/proc/meminfo: memFree=493184/1048576 swapFree=2084004/2097144
[pid=2599] ppid=2598 vsize=2576 CPUtime=0
/proc/2599/stat : 2599 (p2cudf-paranoid) S 2598 2599 2059 34821 2220 4202496 378 0 0 0 0 0 0 0 23 0 1 0 876728242 2637824 273 1283457024 134512640 135304128 4287050400 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2599/statm: 644 273 233 194 0 30 0
[pid=2600] ppid=2599 vsize=2580 CPUtime=0.03
/proc/2600/stat : 2600 (p2cudf) S 2599 2599 2059 34821 2220 4202496 394 2996 0 1 0 0 2 1 25 0 1 0 876728243 2641920 283 1283457024 134512640 135304128 4290467312 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2600/statm: 645 283 241 194 0 31 0
[pid=2613] ppid=2600 vsize=918348 CPUtime=3.07
/proc/2613/stat : 2613 (java) S 2600 2599 2059 34821 2220 4202496 42803 0 1 0 292 15 0 0 25 0 10 0 876728246 940388352 32067 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/2613/statm: 229587 32067 1732 10 0 226677 0
[pid=2613/tid=2614] ppid=2600 vsize=918348 CPUtime=1.02
/proc/2613/task/2614/stat : 2614 (java) R 2600 2599 2059 34821 2220 4202560 15860 0 1 0 95 7 0 0 25 0 10 0 876728247 940388352 32067 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=2613/tid=2615] ppid=2600 vsize=918348 CPUtime=0
/proc/2613/task/2615/stat : 2615 (java) S 2600 2599 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 18 0 10 0 876728248 940388352 32067 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 0 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2616] ppid=2600 vsize=918348 CPUtime=0
/proc/2613/task/2616/stat : 2616 (java) S 2600 2599 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 25 0 10 0 876728249 940388352 32067 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2617] ppid=2600 vsize=918348 CPUtime=0
/proc/2613/task/2617/stat : 2617 (java) S 2600 2599 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 10 0 876728249 940388352 32067 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2618] ppid=2600 vsize=918348 CPUtime=0
/proc/2613/task/2618/stat : 2618 (java) S 2600 2599 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 876728251 940388352 32067 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2619] ppid=2600 vsize=918348 CPUtime=1.06
/proc/2613/task/2619/stat : 2619 (java) R 2600 2599 2059 34821 2220 4202560 14580 0 0 0 101 5 0 0 25 0 10 0 876728251 940388352 32067 1283457024 134512640 134550932 4294559856 18446744073709551615 4147636052 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=2613/tid=2620] ppid=2600 vsize=918348 CPUtime=0.97
/proc/2613/task/2620/stat : 2620 (java) R 2600 2599 2059 34821 2220 4202560 11248 0 0 0 95 2 0 0 25 0 10 0 876728251 940388352 32067 1283457024 134512640 134550932 4294559856 18446744073709551615 4159495094 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=2613/tid=2621] ppid=2600 vsize=918348 CPUtime=0
/proc/2613/task/2621/stat : 2621 (java) S 2600 2599 2059 34821 2220 4202560 2 0 0 0 0 0 0 0 25 0 10 0 876728251 940388352 32067 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2622] ppid=2600 vsize=918348 CPUtime=0
/proc/2613/task/2622/stat : 2622 (java) S 2600 2599 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 10 0 876728251 940388352 32067 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.1
Current children cumulated vsize (KiB) 923504

[startup+6.30546 s]
/proc/loadavg: 1.58 1.46 1.32 4/52 2623
/proc/meminfo: memFree=356172/1048576 swapFree=2084004/2097144
[pid=2599] ppid=2598 vsize=2576 CPUtime=0
/proc/2599/stat : 2599 (p2cudf-paranoid) S 2598 2599 2059 34821 2220 4202496 378 0 0 0 0 0 0 0 23 0 1 0 876728242 2637824 273 1283457024 134512640 135304128 4287050400 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2599/statm: 644 273 233 194 0 30 0
[pid=2600] ppid=2599 vsize=2580 CPUtime=0.03
/proc/2600/stat : 2600 (p2cudf) S 2599 2599 2059 34821 2220 4202496 394 2996 0 1 0 0 2 1 25 0 1 0 876728243 2641920 283 1283457024 134512640 135304128 4290467312 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2600/statm: 645 283 241 194 0 31 0
[pid=2613] ppid=2600 vsize=914868 CPUtime=6.27
/proc/2613/stat : 2613 (java) S 2600 2599 2059 34821 2220 4202496 72530 0 1 0 600 27 0 0 25 0 12 0 876728246 936824832 60261 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/2613/statm: 228717 60261 1783 10 0 225807 0
[pid=2613/tid=2614] ppid=2600 vsize=914868 CPUtime=2.37
/proc/2613/task/2614/stat : 2614 (java) S 2600 2599 2059 34821 2220 4202560 44177 0 1 0 218 19 0 0 24 0 12 0 876728247 936824832 60261 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2615] ppid=2600 vsize=914868 CPUtime=0
/proc/2613/task/2615/stat : 2615 (java) S 2600 2599 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 15 0 12 0 876728248 936824832 60261 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 0 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2616] ppid=2600 vsize=914868 CPUtime=0
/proc/2613/task/2616/stat : 2616 (java) S 2600 2599 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 25 0 12 0 876728249 936824832 60261 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2617] ppid=2600 vsize=914868 CPUtime=0
/proc/2613/task/2617/stat : 2617 (java) S 2600 2599 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 12 0 876728249 936824832 60261 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2618] ppid=2600 vsize=914868 CPUtime=0
/proc/2613/task/2618/stat : 2618 (java) S 2600 2599 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 12 0 876728251 936824832 60261 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2619] ppid=2600 vsize=914868 CPUtime=2.11
/proc/2613/task/2619/stat : 2619 (java) R 2600 2599 2059 34821 2220 4202560 15442 0 0 0 206 5 0 0 17 0 12 0 876728251 936824832 60261 1283457024 134512640 134550932 4294559856 18446744073709551615 4150277699 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=2613/tid=2620] ppid=2600 vsize=914868 CPUtime=1.76
/proc/2613/task/2620/stat : 2620 (java) R 2600 2599 2059 34821 2220 4202560 11792 0 0 0 174 2 0 0 24 0 12 0 876728251 936824832 60261 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=2613/tid=2621] ppid=2600 vsize=914868 CPUtime=0
/proc/2613/task/2621/stat : 2621 (java) S 2600 2599 2059 34821 2220 4202560 2 0 0 0 0 0 0 0 25 0 12 0 876728251 936824832 60261 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2622] ppid=2600 vsize=914868 CPUtime=0
/proc/2613/task/2622/stat : 2622 (java) S 2600 2599 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 12 0 876728251 936824832 60261 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2623] ppid=2600 vsize=914868 CPUtime=0
/proc/2613/task/2623/stat : 2623 (java) S 2600 2599 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 24 0 12 0 876728783 936824832 60261 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.3
Current children cumulated vsize (KiB) 920024

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

[startup+6.40548 s]
/proc/loadavg: 1.58 1.46 1.32 4/52 2623
/proc/meminfo: memFree=356172/1048576 swapFree=2084004/2097144
[pid=2599] ppid=2598 vsize=2576 CPUtime=0
/proc/2599/stat : 2599 (p2cudf-paranoid) S 2598 2599 2059 34821 2220 4202496 378 0 0 0 0 0 0 0 23 0 1 0 876728242 2637824 273 1283457024 134512640 135304128 4287050400 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2599/statm: 644 273 233 194 0 30 0
[pid=2600] ppid=2599 vsize=2580 CPUtime=0.03
/proc/2600/stat : 2600 (p2cudf) S 2599 2599 2059 34821 2220 4202496 394 2996 0 1 0 0 2 1 25 0 1 0 876728243 2641920 283 1283457024 134512640 135304128 4290467312 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2600/statm: 645 283 241 194 0 31 0
[pid=2613] ppid=2600 vsize=914868 CPUtime=6.37
/proc/2613/stat : 2613 (java) S 2600 2599 2059 34821 2220 4202496 72540 0 1 0 610 27 0 0 25 0 11 0 876728246 936824832 60271 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/2613/statm: 228717 60271 1784 10 0 225807 0
[pid=2613/tid=2614] ppid=2600 vsize=914868 CPUtime=2.41
/proc/2613/task/2614/stat : 2614 (java) R 2600 2599 2059 34821 2220 4202560 44177 0 1 0 222 19 0 0 23 0 11 0 876728247 936824832 60271 1283457024 134512640 134550932 4294559856 18446744073709551615 4095696760 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=2613/tid=2615] ppid=2600 vsize=914868 CPUtime=0
/proc/2613/task/2615/stat : 2615 (java) S 2600 2599 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 15 0 11 0 876728248 936824832 60271 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 0 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2616] ppid=2600 vsize=914868 CPUtime=0
/proc/2613/task/2616/stat : 2616 (java) S 2600 2599 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 25 0 11 0 876728249 936824832 60271 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2617] ppid=2600 vsize=914868 CPUtime=0
/proc/2613/task/2617/stat : 2617 (java) S 2600 2599 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 11 0 876728249 936824832 60271 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2618] ppid=2600 vsize=914868 CPUtime=0
/proc/2613/task/2618/stat : 2618 (java) S 2600 2599 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 876728251 936824832 60271 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2619] ppid=2600 vsize=914868 CPUtime=2.18
/proc/2613/task/2619/stat : 2619 (java) S 2600 2599 2059 34821 2220 4202560 15451 0 0 0 213 5 0 0 17 0 11 0 876728251 936824832 60271 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2620] ppid=2600 vsize=914868 CPUtime=1.76
/proc/2613/task/2620/stat : 2620 (java) R 2600 2599 2059 34821 2220 4202560 11792 0 0 0 174 2 0 0 24 0 11 0 876728251 936824832 60271 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=2613/tid=2621] ppid=2600 vsize=914868 CPUtime=0
/proc/2613/task/2621/stat : 2621 (java) S 2600 2599 2059 34821 2220 4202560 2 0 0 0 0 0 0 0 25 0 11 0 876728251 936824832 60271 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2622] ppid=2600 vsize=914868 CPUtime=0
/proc/2613/task/2622/stat : 2622 (java) S 2600 2599 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 11 0 876728251 936824832 60271 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.4
Current children cumulated vsize (KiB) 920024

[startup+6.80481 s]
/proc/loadavg: 1.58 1.46 1.32 1/52 2625
/proc/meminfo: memFree=353196/1048576 swapFree=2084004/2097144
[pid=2599] ppid=2598 vsize=2576 CPUtime=0
/proc/2599/stat : 2599 (p2cudf-paranoid) S 2598 2599 2059 34821 2220 4202496 378 0 0 0 0 0 0 0 23 0 1 0 876728242 2637824 273 1283457024 134512640 135304128 4287050400 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2599/statm: 644 273 233 194 0 30 0
[pid=2600] ppid=2599 vsize=2580 CPUtime=0.03
/proc/2600/stat : 2600 (p2cudf) S 2599 2599 2059 34821 2220 4202496 394 2996 0 1 0 0 2 1 25 0 1 0 876728243 2641920 283 1283457024 134512640 135304128 4290467312 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2600/statm: 645 283 241 194 0 31 0
[pid=2613] ppid=2600 vsize=914868 CPUtime=6.53
/proc/2613/stat : 2613 (java) S 2600 2599 2059 34821 2220 4202496 72897 0 1 0 626 27 0 0 25 0 11 0 876728246 936824832 60628 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/2613/statm: 228717 60628 1787 10 0 225807 0
[pid=2613/tid=2614] ppid=2600 vsize=914868 CPUtime=2.49
/proc/2613/task/2614/stat : 2614 (java) S 2600 2599 2059 34821 2220 4202560 44515 0 1 0 230 19 0 0 24 0 11 0 876728247 936824832 60628 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2615] ppid=2600 vsize=914868 CPUtime=0
/proc/2613/task/2615/stat : 2615 (java) S 2600 2599 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 15 0 11 0 876728248 936824832 60628 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 0 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2616] ppid=2600 vsize=914868 CPUtime=0
/proc/2613/task/2616/stat : 2616 (java) S 2600 2599 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 25 0 11 0 876728249 936824832 60628 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2617] ppid=2600 vsize=914868 CPUtime=0
/proc/2613/task/2617/stat : 2617 (java) S 2600 2599 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 11 0 876728249 936824832 60628 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2618] ppid=2600 vsize=914868 CPUtime=0
/proc/2613/task/2618/stat : 2618 (java) S 2600 2599 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 876728251 936824832 60628 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2619] ppid=2600 vsize=914868 CPUtime=2.25
/proc/2613/task/2619/stat : 2619 (java) S 2600 2599 2059 34821 2220 4202560 15465 0 0 0 220 5 0 0 16 0 11 0 876728251 936824832 60628 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2620] ppid=2600 vsize=914868 CPUtime=1.78
/proc/2613/task/2620/stat : 2620 (java) S 2600 2599 2059 34821 2220 4202560 11794 0 0 0 176 2 0 0 24 0 11 0 876728251 936824832 60628 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2621] ppid=2600 vsize=914868 CPUtime=0
/proc/2613/task/2621/stat : 2621 (java) S 2600 2599 2059 34821 2220 4202560 2 0 0 0 0 0 0 0 25 0 11 0 876728251 936824832 60628 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2622] ppid=2600 vsize=914868 CPUtime=0
/proc/2613/task/2622/stat : 2622 (java) S 2600 2599 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 11 0 876728251 936824832 60628 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2625] ppid=2600 vsize=914868 CPUtime=0
/proc/2613/task/2625/stat : 2625 (java) S 2600 2599 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 11 0 876728896 936824832 60628 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.56
Current children cumulated vsize (KiB) 920024

[startup+7.20484 s]
/proc/loadavg: 1.58 1.46 1.32 1/52 2625
/proc/meminfo: memFree=353196/1048576 swapFree=2084004/2097144
[pid=2599] ppid=2598 vsize=2576 CPUtime=0
/proc/2599/stat : 2599 (p2cudf-paranoid) S 2598 2599 2059 34821 2220 4202496 378 0 0 0 0 0 0 0 23 0 1 0 876728242 2637824 273 1283457024 134512640 135304128 4287050400 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2599/statm: 644 273 233 194 0 30 0
[pid=2600] ppid=2599 vsize=2580 CPUtime=0.03
/proc/2600/stat : 2600 (p2cudf) S 2599 2599 2059 34821 2220 4202496 394 2996 0 1 0 0 2 1 25 0 1 0 876728243 2641920 283 1283457024 134512640 135304128 4290467312 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2600/statm: 645 283 241 194 0 31 0
[pid=2613] ppid=2600 vsize=914868 CPUtime=6.66
/proc/2613/stat : 2613 (java) S 2600 2599 2059 34821 2220 4202496 73131 0 1 0 638 28 0 0 25 0 11 0 876728246 936824832 60862 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/2613/statm: 228717 60862 1787 10 0 225807 0
[pid=2613/tid=2614] ppid=2600 vsize=914868 CPUtime=2.49
/proc/2613/task/2614/stat : 2614 (java) S 2600 2599 2059 34821 2220 4202560 44515 0 1 0 230 19 0 0 24 0 11 0 876728247 936824832 60862 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2615] ppid=2600 vsize=914868 CPUtime=0
/proc/2613/task/2615/stat : 2615 (java) S 2600 2599 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 15 0 11 0 876728248 936824832 60862 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 0 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2616] ppid=2600 vsize=914868 CPUtime=0
/proc/2613/task/2616/stat : 2616 (java) S 2600 2599 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 25 0 11 0 876728249 936824832 60862 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2617] ppid=2600 vsize=914868 CPUtime=0
/proc/2613/task/2617/stat : 2617 (java) S 2600 2599 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 11 0 876728249 936824832 60862 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2618] ppid=2600 vsize=914868 CPUtime=0
/proc/2613/task/2618/stat : 2618 (java) S 2600 2599 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 876728251 936824832 60862 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2619] ppid=2600 vsize=914868 CPUtime=2.25
/proc/2613/task/2619/stat : 2619 (java) S 2600 2599 2059 34821 2220 4202560 15465 0 0 0 220 5 0 0 16 0 11 0 876728251 936824832 60862 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2620] ppid=2600 vsize=914868 CPUtime=1.82
/proc/2613/task/2620/stat : 2620 (java) R 2600 2599 2059 34821 2220 4202560 11798 0 0 0 180 2 0 0 18 0 11 0 876728251 936824832 60862 1283457024 134512640 134550932 4294559856 18446744073709551615 4152949956 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=2613/tid=2621] ppid=2600 vsize=914868 CPUtime=0
/proc/2613/task/2621/stat : 2621 (java) S 2600 2599 2059 34821 2220 4202560 2 0 0 0 0 0 0 0 25 0 11 0 876728251 936824832 60862 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2622] ppid=2600 vsize=914868 CPUtime=0
/proc/2613/task/2622/stat : 2622 (java) S 2600 2599 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 11 0 876728251 936824832 60862 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=2613/tid=2625] ppid=2600 vsize=914868 CPUtime=0.07
/proc/2613/task/2625/stat : 2625 (java) R 2600 2599 2059 34821 2220 4202560 230 0 0 0 7 0 0 0 20 0 11 0 876728896 936824832 60862 1283457024 134512640 134550932 4294559856 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.69
Current children cumulated vsize (KiB) 920024

Child status: 0
Real time (s): 7.26018
CPU time (s): 6.73242
CPU user time (s): 6.4204
CPU system time (s): 0.312019
CPU usage (%): 92.7307
Max. virtual memory (cumulated for all children) (KiB): 927920

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 6.4204
system time used= 0.312019
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 76952
page faults= 2
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 444
involuntary context switches= 475

runsolver used 0 second user time and 0.008 second system time

The end