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/201012070034/p2cudf-trendy-1.9/randc192b7.cudf.easy.log.runsolver ./p2cudf-trendy-1.9 /home/misc2010/data/2010/easy//randc192b7.cudf /home/misc2010/tmp/201012070034/p2cudf-trendy-1.9/randc192b7.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.00 1.03 1.00 3/43 6035
/proc/meminfo: memFree=715076/1048576 swapFree=2077620/2097144
[pid=6032] ppid=6031 vsize=2576 CPUtime=0
/proc/6032/stat : 6032 (p2cudf-trendy-1) S 6031 6032 4159 34819 4229 4202496 378 0 0 0 0 0 0 0 25 0 1 0 885481637 2637824 274 1283457024 134512640 135304128 4289533184 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6032/statm: 644 274 233 194 0 30 0
[pid=6033] ppid=6032 vsize=2572 CPUtime=0
/proc/6033/stat : 6033 (p2cudf) S 6032 6032 4159 34819 4229 4202496 356 0 0 0 0 0 0 0 25 0 1 0 885481637 2633728 274 1283457024 134512640 135304128 4286628400 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0
/proc/6033/statm: 643 274 234 194 0 29 0
[pid=6034] ppid=6033 vsize=2572 CPUtime=0
/proc/6034/stat : 6034 (p2cudf) R 6033 6032 4159 34819 4229 4202560 91 0 0 0 0 0 0 0 25 0 1 0 885481638 2633728 116 1283457024 134512640 135304128 4286628400 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/6034/statm: 643 116 75 194 0 29 0
[pid=6035] ppid=6034 vsize=2572 CPUtime=0
/proc/6035/stat : 6035 (p2cudf) R 6034 6032 4159 34819 4229 4202560 0 0 0 0 0 0 0 0 25 0 1 0 885481638 2633728 41 1283457024 134512640 135304128 4286628400 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/6035/statm: 643 41 0 194 0 29 0

[startup+0.149905 s]
/proc/loadavg: 1.00 1.03 1.00 3/43 6035
/proc/meminfo: memFree=715076/1048576 swapFree=2077620/2097144
[pid=6032] ppid=6031 vsize=2576 CPUtime=0
/proc/6032/stat : 6032 (p2cudf-trendy-1) S 6031 6032 4159 34819 4229 4202496 378 0 0 0 0 0 0 0 25 0 1 0 885481637 2637824 274 1283457024 134512640 135304128 4289533184 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6032/statm: 644 274 233 194 0 30 0
[pid=6033] ppid=6032 vsize=2576 CPUtime=0.02
/proc/6033/stat : 6033 (p2cudf) S 6032 6032 4159 34819 4229 4202496 395 2995 0 1 0 0 2 0 25 0 1 0 885481637 2637824 282 1283457024 134512640 135304128 4286628400 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6033/statm: 644 282 241 194 0 30 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5152

[startup+0.209921 s]
/proc/loadavg: 1.00 1.03 1.00 3/43 6035
/proc/meminfo: memFree=715076/1048576 swapFree=2077620/2097144
[pid=6032] ppid=6031 vsize=2576 CPUtime=0
/proc/6032/stat : 6032 (p2cudf-trendy-1) S 6031 6032 4159 34819 4229 4202496 378 0 0 0 0 0 0 0 25 0 1 0 885481637 2637824 274 1283457024 134512640 135304128 4289533184 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6032/statm: 644 274 233 194 0 30 0
[pid=6033] ppid=6032 vsize=2576 CPUtime=0.02
/proc/6033/stat : 6033 (p2cudf) S 6032 6032 4159 34819 4229 4202496 395 2995 0 1 0 0 2 0 25 0 1 0 885481637 2637824 282 1283457024 134512640 135304128 4286628400 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6033/statm: 644 282 241 194 0 30 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5152

[startup+0.309944 s]
/proc/loadavg: 1.00 1.03 1.00 3/43 6035
/proc/meminfo: memFree=715076/1048576 swapFree=2077620/2097144
[pid=6032] ppid=6031 vsize=2576 CPUtime=0
/proc/6032/stat : 6032 (p2cudf-trendy-1) S 6031 6032 4159 34819 4229 4202496 378 0 0 0 0 0 0 0 25 0 1 0 885481637 2637824 274 1283457024 134512640 135304128 4289533184 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6032/statm: 644 274 233 194 0 30 0
[pid=6033] ppid=6032 vsize=2576 CPUtime=0.02
/proc/6033/stat : 6033 (p2cudf) S 6032 6032 4159 34819 4229 4202496 395 2995 0 1 0 0 2 0 25 0 1 0 885481637 2637824 282 1283457024 134512640 135304128 4286628400 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6033/statm: 644 282 241 194 0 30 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5152

[startup+0.710031 s]
/proc/loadavg: 1.00 1.03 1.00 3/43 6035
/proc/meminfo: memFree=715076/1048576 swapFree=2077620/2097144
[pid=6032] ppid=6031 vsize=2576 CPUtime=0
/proc/6032/stat : 6032 (p2cudf-trendy-1) S 6031 6032 4159 34819 4229 4202496 378 0 0 0 0 0 0 0 25 0 1 0 885481637 2637824 274 1283457024 134512640 135304128 4289533184 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6032/statm: 644 274 233 194 0 30 0
[pid=6033] ppid=6032 vsize=2576 CPUtime=0.02
/proc/6033/stat : 6033 (p2cudf) S 6032 6032 4159 34819 4229 4202496 395 2995 0 1 0 0 2 0 25 0 1 0 885481637 2637824 282 1283457024 134512640 135304128 4286628400 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6033/statm: 644 282 241 194 0 30 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5152

[startup+1.51025 s]
/proc/loadavg: 1.00 1.03 1.00 5/52 6055
/proc/meminfo: memFree=677008/1048576 swapFree=2077620/2097144
[pid=6032] ppid=6031 vsize=2576 CPUtime=0
/proc/6032/stat : 6032 (p2cudf-trendy-1) S 6031 6032 4159 34819 4229 4202496 378 0 0 0 0 0 0 0 25 0 1 0 885481637 2637824 274 1283457024 134512640 135304128 4289533184 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6032/statm: 644 274 233 194 0 30 0
[pid=6033] ppid=6032 vsize=2576 CPUtime=0.02
/proc/6033/stat : 6033 (p2cudf) S 6032 6032 4159 34819 4229 4202496 395 2995 0 1 0 0 2 0 25 0 1 0 885481637 2637824 282 1283457024 134512640 135304128 4286628400 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6033/statm: 644 282 241 194 0 30 0
[pid=6046] ppid=6033 vsize=883168 CPUtime=1.47
/proc/6046/stat : 6046 (java) S 6033 6032 4159 34819 4229 4202496 17824 0 1 0 141 6 0 0 25 0 10 0 885481641 904364032 13845 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/6046/statm: 220792 13845 1732 10 0 217882 0
[pid=6046/tid=6047] ppid=6033 vsize=883168 CPUtime=0.66
/proc/6046/task/6047/stat : 6047 (java) R 6033 6032 4159 34819 4229 4202560 6122 0 1 0 63 3 0 0 25 0 10 0 885481642 904364032 13845 1283457024 134512640 134550932 4290454640 18446744073709551615 4095557441 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=6046/tid=6048] ppid=6033 vsize=883168 CPUtime=0
/proc/6046/task/6048/stat : 6048 (java) S 6033 6032 4159 34819 4229 4202560 5 0 0 0 0 0 0 0 18 0 10 0 885481643 904364032 13845 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 0 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6049] ppid=6033 vsize=883168 CPUtime=0
/proc/6046/task/6049/stat : 6049 (java) S 6033 6032 4159 34819 4229 4202560 9 0 0 0 0 0 0 0 25 0 10 0 885481644 904364032 13845 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6050] ppid=6033 vsize=883168 CPUtime=0
/proc/6046/task/6050/stat : 6050 (java) S 6033 6032 4159 34819 4229 4202560 4 0 0 0 0 0 0 0 25 0 10 0 885481644 904364032 13845 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6051] ppid=6033 vsize=883168 CPUtime=0
/proc/6046/task/6051/stat : 6051 (java) S 6033 6032 4159 34819 4229 4202560 1 0 0 0 0 0 0 0 25 0 10 0 885481646 904364032 13845 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6052] ppid=6033 vsize=883168 CPUtime=0.51
/proc/6046/task/6052/stat : 6052 (java) R 6033 6032 4159 34819 4229 4202560 7420 0 0 0 49 2 0 0 20 0 10 0 885481646 904364032 13845 1283457024 134512640 134550932 4290454640 18446744073709551615 4150194382 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=6046/tid=6053] ppid=6033 vsize=883168 CPUtime=0.28
/proc/6046/task/6053/stat : 6053 (java) R 6033 6032 4159 34819 4229 4202560 3169 0 0 0 28 0 0 0 25 0 10 0 885481646 904364032 13845 1283457024 134512640 134550932 4290454640 18446744073709551615 4148355467 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=6046/tid=6054] ppid=6033 vsize=883168 CPUtime=0
/proc/6046/task/6054/stat : 6054 (java) S 6033 6032 4159 34819 4229 4202560 1 0 0 0 0 0 0 0 25 0 10 0 885481646 904364032 13845 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6055] ppid=6033 vsize=883168 CPUtime=0
/proc/6046/task/6055/stat : 6055 (java) S 6033 6032 4159 34819 4229 4202560 1 0 0 0 0 0 0 0 15 0 10 0 885481646 904364032 13845 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 888320

[startup+3.11063 s]
/proc/loadavg: 1.16 1.06 1.01 3/52 6055
/proc/meminfo: memFree=624432/1048576 swapFree=2077620/2097144
[pid=6032] ppid=6031 vsize=2576 CPUtime=0
/proc/6032/stat : 6032 (p2cudf-trendy-1) S 6031 6032 4159 34819 4229 4202496 378 0 0 0 0 0 0 0 25 0 1 0 885481637 2637824 274 1283457024 134512640 135304128 4289533184 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6032/statm: 644 274 233 194 0 30 0
[pid=6033] ppid=6032 vsize=2576 CPUtime=0.02
/proc/6033/stat : 6033 (p2cudf) S 6032 6032 4159 34819 4229 4202496 395 2995 0 1 0 0 2 0 25 0 1 0 885481637 2637824 282 1283457024 134512640 135304128 4286628400 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6033/statm: 644 282 241 194 0 30 0
[pid=6046] ppid=6033 vsize=882328 CPUtime=3.07
/proc/6046/stat : 6046 (java) S 6033 6032 4159 34819 4229 4202496 46214 0 1 0 287 20 0 0 25 0 10 0 885481641 903503872 40243 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/6046/statm: 220582 40243 1759 10 0 217672 0
[pid=6046/tid=6047] ppid=6033 vsize=882328 CPUtime=1.44
/proc/6046/task/6047/stat : 6047 (java) R 6033 6032 4159 34819 4229 4202560 32190 0 1 0 129 15 0 0 25 0 10 0 885481642 903503872 40243 1283457024 134512640 134550932 4290454640 18446744073709551615 4095583364 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=6046/tid=6048] ppid=6033 vsize=882328 CPUtime=0
/proc/6046/task/6048/stat : 6048 (java) S 6033 6032 4159 34819 4229 4202560 5 0 0 0 0 0 0 0 18 0 10 0 885481643 903503872 40243 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 0 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6049] ppid=6033 vsize=882328 CPUtime=0
/proc/6046/task/6049/stat : 6049 (java) S 6033 6032 4159 34819 4229 4202560 9 0 0 0 0 0 0 0 25 0 10 0 885481644 903503872 40243 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6050] ppid=6033 vsize=882328 CPUtime=0
/proc/6046/task/6050/stat : 6050 (java) S 6033 6032 4159 34819 4229 4202560 4 0 0 0 0 0 0 0 25 0 10 0 885481644 903503872 40243 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6051] ppid=6033 vsize=882328 CPUtime=0
/proc/6046/task/6051/stat : 6051 (java) S 6033 6032 4159 34819 4229 4202560 1 0 0 0 0 0 0 0 25 0 10 0 885481646 903503872 40243 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6052] ppid=6033 vsize=882328 CPUtime=0.9
/proc/6046/task/6052/stat : 6052 (java) S 6033 6032 4159 34819 4229 4202560 7477 0 0 0 88 2 0 0 16 0 10 0 885481646 903503872 40243 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6053] ppid=6033 vsize=882328 CPUtime=0.68
/proc/6046/task/6053/stat : 6053 (java) R 6033 6032 4159 34819 4229 4202560 5434 0 0 0 68 0 0 0 25 0 10 0 885481646 903503872 40243 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=6046/tid=6054] ppid=6033 vsize=882328 CPUtime=0
/proc/6046/task/6054/stat : 6054 (java) S 6033 6032 4159 34819 4229 4202560 1 0 0 0 0 0 0 0 25 0 10 0 885481646 903503872 40243 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6055] ppid=6033 vsize=882328 CPUtime=0
/proc/6046/task/6055/stat : 6055 (java) S 6033 6032 4159 34819 4229 4202560 1 0 0 0 0 0 0 0 15 0 10 0 885481646 903503872 40243 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.09
Current children cumulated vsize (KiB) 887480

[startup+6.31107 s]
/proc/loadavg: 1.16 1.06 1.01 3/55 6059
/proc/meminfo: memFree=457628/1048576 swapFree=2077620/2097144
[pid=6032] ppid=6031 vsize=2576 CPUtime=0
/proc/6032/stat : 6032 (p2cudf-trendy-1) S 6031 6032 4159 34819 4229 4202496 378 0 0 0 0 0 0 0 25 0 1 0 885481637 2637824 274 1283457024 134512640 135304128 4289533184 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6032/statm: 644 274 233 194 0 30 0
[pid=6033] ppid=6032 vsize=2576 CPUtime=0.02
/proc/6033/stat : 6033 (p2cudf) S 6032 6032 4159 34819 4229 4202496 395 2995 0 1 0 0 2 0 25 0 1 0 885481637 2637824 282 1283457024 134512640 135304128 4286628400 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6033/statm: 644 282 241 194 0 30 0
[pid=6046] ppid=6033 vsize=883300 CPUtime=5.75
/proc/6046/stat : 6046 (java) S 6033 6032 4159 34819 4229 4202496 76942 0 1 0 544 31 0 0 25 0 10 0 885481641 904499200 69525 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/6046/statm: 220825 69525 1794 10 0 217915 0
[pid=6046/tid=6047] ppid=6033 vsize=883300 CPUtime=2.29
/proc/6046/task/6047/stat : 6047 (java) S 6033 6032 4159 34819 4229 4202560 50451 0 1 0 210 19 0 0 19 0 10 0 885481642 904499200 69525 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6048] ppid=6033 vsize=883300 CPUtime=0.25
/proc/6046/task/6048/stat : 6048 (java) S 6033 6032 4159 34819 4229 4202560 10832 0 0 0 22 3 0 0 15 0 10 0 885481643 904499200 69525 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 0 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6049] ppid=6033 vsize=883300 CPUtime=0
/proc/6046/task/6049/stat : 6049 (java) S 6033 6032 4159 34819 4229 4202560 10 0 0 0 0 0 0 0 18 0 10 0 885481644 904499200 69525 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6050] ppid=6033 vsize=883300 CPUtime=0
/proc/6046/task/6050/stat : 6050 (java) S 6033 6032 4159 34819 4229 4202560 6 0 0 0 0 0 0 0 18 0 10 0 885481644 904499200 69525 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6051] ppid=6033 vsize=883300 CPUtime=0
/proc/6046/task/6051/stat : 6051 (java) S 6033 6032 4159 34819 4229 4202560 1 0 0 0 0 0 0 0 25 0 10 0 885481646 904499200 69525 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6052] ppid=6033 vsize=883300 CPUtime=1.63
/proc/6046/task/6052/stat : 6052 (java) S 6033 6032 4159 34819 4229 4202560 8999 0 0 0 160 3 0 0 15 0 10 0 885481646 904499200 69525 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6053] ppid=6033 vsize=883300 CPUtime=1.47
/proc/6046/task/6053/stat : 6053 (java) S 6033 6032 4159 34819 4229 4202560 5535 0 0 0 147 0 0 0 16 0 10 0 885481646 904499200 69525 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6054] ppid=6033 vsize=883300 CPUtime=0
/proc/6046/task/6054/stat : 6054 (java) S 6033 6032 4159 34819 4229 4202560 1 0 0 0 0 0 0 0 25 0 10 0 885481646 904499200 69525 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6055] ppid=6033 vsize=883300 CPUtime=0
/proc/6046/task/6055/stat : 6055 (java) S 6033 6032 4159 34819 4229 4202560 1 0 0 0 0 0 0 0 15 0 10 0 885481646 904499200 69525 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 5.77
Current children cumulated vsize (KiB) 888452

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

[startup+6.31107 s]
/proc/loadavg: 1.16 1.06 1.01 3/55 6059
/proc/meminfo: memFree=457628/1048576 swapFree=2077620/2097144
[pid=6032] ppid=6031 vsize=2576 CPUtime=0
/proc/6032/stat : 6032 (p2cudf-trendy-1) S 6031 6032 4159 34819 4229 4202496 378 0 0 0 0 0 0 0 25 0 1 0 885481637 2637824 274 1283457024 134512640 135304128 4289533184 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6032/statm: 644 274 233 194 0 30 0
[pid=6033] ppid=6032 vsize=2576 CPUtime=0.02
/proc/6033/stat : 6033 (p2cudf) S 6032 6032 4159 34819 4229 4202496 395 2995 0 1 0 0 2 0 25 0 1 0 885481637 2637824 282 1283457024 134512640 135304128 4286628400 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6033/statm: 644 282 241 194 0 30 0
[pid=6046] ppid=6033 vsize=883300 CPUtime=5.75
/proc/6046/stat : 6046 (java) S 6033 6032 4159 34819 4229 4202496 76942 0 1 0 544 31 0 0 25 0 10 0 885481641 904499200 69525 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/6046/statm: 220825 69525 1794 10 0 217915 0
[pid=6046/tid=6047] ppid=6033 vsize=883300 CPUtime=2.29
/proc/6046/task/6047/stat : 6047 (java) S 6033 6032 4159 34819 4229 4202560 50451 0 1 0 210 19 0 0 19 0 10 0 885481642 904499200 69525 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6048] ppid=6033 vsize=883300 CPUtime=0.25
/proc/6046/task/6048/stat : 6048 (java) S 6033 6032 4159 34819 4229 4202560 10832 0 0 0 22 3 0 0 15 0 10 0 885481643 904499200 69525 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 0 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6049] ppid=6033 vsize=883300 CPUtime=0
/proc/6046/task/6049/stat : 6049 (java) S 6033 6032 4159 34819 4229 4202560 10 0 0 0 0 0 0 0 18 0 10 0 885481644 904499200 69525 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6050] ppid=6033 vsize=883300 CPUtime=0
/proc/6046/task/6050/stat : 6050 (java) S 6033 6032 4159 34819 4229 4202560 6 0 0 0 0 0 0 0 18 0 10 0 885481644 904499200 69525 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6051] ppid=6033 vsize=883300 CPUtime=0
/proc/6046/task/6051/stat : 6051 (java) S 6033 6032 4159 34819 4229 4202560 1 0 0 0 0 0 0 0 25 0 10 0 885481646 904499200 69525 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6052] ppid=6033 vsize=883300 CPUtime=1.63
/proc/6046/task/6052/stat : 6052 (java) S 6033 6032 4159 34819 4229 4202560 8999 0 0 0 160 3 0 0 15 0 10 0 885481646 904499200 69525 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6053] ppid=6033 vsize=883300 CPUtime=1.47
/proc/6046/task/6053/stat : 6053 (java) S 6033 6032 4159 34819 4229 4202560 5535 0 0 0 147 0 0 0 16 0 10 0 885481646 904499200 69525 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6054] ppid=6033 vsize=883300 CPUtime=0
/proc/6046/task/6054/stat : 6054 (java) S 6033 6032 4159 34819 4229 4202560 1 0 0 0 0 0 0 0 25 0 10 0 885481646 904499200 69525 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
[pid=6046/tid=6055] ppid=6033 vsize=883300 CPUtime=0
/proc/6046/task/6055/stat : 6055 (java) S 6033 6032 4159 34819 4229 4202560 1 0 0 0 0 0 0 0 15 0 10 0 885481646 904499200 69525 1283457024 134512640 134550932 4290454640 18446744073709551615 4294960130 0 4 0 16800975 18446612133359098816 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 5.77
Current children cumulated vsize (KiB) 888452

Child status: 0
Real time (s): 6.36617
CPU time (s): 5.80436
CPU user time (s): 5.46034
CPU system time (s): 0.344021
CPU usage (%): 91.1752
Max. virtual memory (cumulated for all children) (KiB): 890908

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 5.46034
system time used= 0.344021
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 80733
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= 788
involuntary context switches= 760

runsolver used 0 second user time and 0 second system time

The end