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/201103031013/p2cudf-paranoid-1.12/589.cudf.caixa.log.runsolver ./p2cudf-paranoid-1.12 /home/misc2010/data/misc4/caixa//589.cudf /home/misc2010/tmp/201103031013/p2cudf-paranoid-1.12/589.cudf.caixa.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.73 1.74 1.67 5/35 22185
/proc/meminfo: memFree=300232/1048576 swapFree=0/0
[pid=22183] ppid=22182 vsize=2564 CPUtime=0
/proc/22183/stat : 22183 (p2cudf-paranoid) S 22182 22183 29493 34817 29493 4202496 374 0 0 0 0 0 0 0 18 0 1 0 76302444 2625536 270 1283457024 134512640 135304128 4288502784 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22183/statm: 641 270 230 194 0 28 0
[pid=22184] ppid=22183 vsize=2572 CPUtime=0
/proc/22184/stat : 22184 (p2cudf) S 22183 22183 29493 34817 29493 4202496 354 0 0 0 0 0 0 0 25 0 1 0 76302444 2633728 272 1283457024 134512640 135304128 4290000256 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0
/proc/22184/statm: 643 272 231 194 0 30 0
[pid=22185] ppid=22184 vsize=2572 CPUtime=0
/proc/22185/stat : 22185 (p2cudf) R 22184 22183 29493 34817 29493 4202560 94 0 0 0 0 0 0 0 25 0 1 0 76302444 2633728 119 1283457024 134512640 135304128 4290000256 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/22185/statm: 643 119 77 194 0 30 0
[pid=22186] ppid=22185 vsize=2572 CPUtime=0
/proc/22186/stat : 22186 (p2cudf) R 22185 22183 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 1 0 76302444 2633728 42 1283457024 134512640 135304128 4290000256 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/22186/statm: 643 42 0 194 0 30 0

[startup+0.135065 s]
/proc/loadavg: 1.73 1.74 1.67 5/35 22185
/proc/meminfo: memFree=300232/1048576 swapFree=0/0
[pid=22183] ppid=22182 vsize=2564 CPUtime=0
/proc/22183/stat : 22183 (p2cudf-paranoid) S 22182 22183 29493 34817 29493 4202496 374 0 0 0 0 0 0 0 18 0 1 0 76302444 2625536 270 1283457024 134512640 135304128 4288502784 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22183/statm: 641 270 230 194 0 28 0
[pid=22184] ppid=22183 vsize=2580 CPUtime=0.02
/proc/22184/stat : 22184 (p2cudf) S 22183 22183 29493 34817 29493 4202496 395 3013 0 1 0 0 1 1 25 0 1 0 76302444 2641920 282 1283457024 134512640 135304128 4290000256 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22184/statm: 645 282 239 194 0 32 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5144

[startup+0.205067 s]
/proc/loadavg: 1.73 1.74 1.67 5/35 22185
/proc/meminfo: memFree=300232/1048576 swapFree=0/0
[pid=22183] ppid=22182 vsize=2564 CPUtime=0
/proc/22183/stat : 22183 (p2cudf-paranoid) S 22182 22183 29493 34817 29493 4202496 374 0 0 0 0 0 0 0 18 0 1 0 76302444 2625536 270 1283457024 134512640 135304128 4288502784 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22183/statm: 641 270 230 194 0 28 0
[pid=22184] ppid=22183 vsize=2580 CPUtime=0.02
/proc/22184/stat : 22184 (p2cudf) S 22183 22183 29493 34817 29493 4202496 395 3013 0 1 0 0 1 1 25 0 1 0 76302444 2641920 282 1283457024 134512640 135304128 4290000256 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22184/statm: 645 282 239 194 0 32 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5144

[startup+0.305081 s]
/proc/loadavg: 1.73 1.74 1.67 5/35 22185
/proc/meminfo: memFree=300232/1048576 swapFree=0/0
[pid=22183] ppid=22182 vsize=2564 CPUtime=0
/proc/22183/stat : 22183 (p2cudf-paranoid) S 22182 22183 29493 34817 29493 4202496 374 0 0 0 0 0 0 0 18 0 1 0 76302444 2625536 270 1283457024 134512640 135304128 4288502784 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22183/statm: 641 270 230 194 0 28 0
[pid=22184] ppid=22183 vsize=2580 CPUtime=0.02
/proc/22184/stat : 22184 (p2cudf) S 22183 22183 29493 34817 29493 4202496 395 3013 0 1 0 0 1 1 25 0 1 0 76302444 2641920 282 1283457024 134512640 135304128 4290000256 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22184/statm: 645 282 239 194 0 32 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5144

[startup+0.705157 s]
/proc/loadavg: 1.73 1.74 1.67 5/35 22185
/proc/meminfo: memFree=300232/1048576 swapFree=0/0
[pid=22183] ppid=22182 vsize=2564 CPUtime=0
/proc/22183/stat : 22183 (p2cudf-paranoid) S 22182 22183 29493 34817 29493 4202496 374 0 0 0 0 0 0 0 18 0 1 0 76302444 2625536 270 1283457024 134512640 135304128 4288502784 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22183/statm: 641 270 230 194 0 28 0
[pid=22184] ppid=22183 vsize=2580 CPUtime=0.02
/proc/22184/stat : 22184 (p2cudf) S 22183 22183 29493 34817 29493 4202496 395 3013 0 1 0 0 1 1 25 0 1 0 76302444 2641920 282 1283457024 134512640 135304128 4290000256 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22184/statm: 645 282 239 194 0 32 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5144

[startup+1.50531 s]
/proc/loadavg: 1.73 1.74 1.67 5/45 22206
/proc/meminfo: memFree=256308/1048576 swapFree=0/0
[pid=22183] ppid=22182 vsize=2564 CPUtime=0
/proc/22183/stat : 22183 (p2cudf-paranoid) S 22182 22183 29493 34817 29493 4202496 374 0 0 0 0 0 0 0 18 0 1 0 76302444 2625536 270 1283457024 134512640 135304128 4288502784 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22183/statm: 641 270 230 194 0 28 0
[pid=22184] ppid=22183 vsize=2580 CPUtime=0.02
/proc/22184/stat : 22184 (p2cudf) S 22183 22183 29493 34817 29493 4202496 395 3013 0 1 0 0 1 1 25 0 1 0 76302444 2641920 282 1283457024 134512640 135304128 4290000256 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22184/statm: 645 282 239 194 0 32 0
[pid=22197] ppid=22184 vsize=888352 CPUtime=1.47
/proc/22197/stat : 22197 (java) S 22184 22183 29493 34817 29493 4202496 20688 0 1 0 139 8 0 0 25 0 10 0 76302447 909672448 17463 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/22197/statm: 222088 17463 1725 10 0 219179 0
[pid=22197/tid=22198] ppid=22184 vsize=888352 CPUtime=0.79
/proc/22197/task/22198/stat : 22198 (java) R 22184 22183 29493 34817 29493 4202560 8590 0 1 0 73 6 0 0 25 0 10 0 76302448 909672448 17463 1283457024 134512640 134550932 4293084944 18446744073709551615 4095417096 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22197/tid=22199] ppid=22184 vsize=888352 CPUtime=0
/proc/22197/task/22199/stat : 22199 (java) S 22184 22183 29493 34817 29493 4202560 7 0 0 0 0 0 0 0 17 0 10 0 76302450 909672448 17463 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 0 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22200] ppid=22184 vsize=888352 CPUtime=0
/proc/22197/task/22200/stat : 22200 (java) S 22184 22183 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 76302450 909672448 17463 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22201] ppid=22184 vsize=888352 CPUtime=0
/proc/22197/task/22201/stat : 22201 (java) S 22184 22183 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 76302450 909672448 17463 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22202] ppid=22184 vsize=888352 CPUtime=0
/proc/22197/task/22202/stat : 22202 (java) S 22184 22183 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76302453 909672448 17463 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22203] ppid=22184 vsize=888352 CPUtime=0.39
/proc/22197/task/22203/stat : 22203 (java) R 22184 22183 29493 34817 29493 4202560 8012 0 0 0 39 0 0 0 21 0 10 0 76302453 909672448 17463 1283457024 134512640 134550932 4293084944 18446744073709551615 4150298086 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22197/tid=22204] ppid=22184 vsize=888352 CPUtime=0.27
/proc/22197/task/22204/stat : 22204 (java) R 22184 22183 29493 34817 29493 4202560 3006 0 0 0 26 1 0 0 25 0 10 0 76302453 909672448 17463 1283457024 134512640 134550932 4293084944 18446744073709551615 4152657860 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22197/tid=22205] ppid=22184 vsize=888352 CPUtime=0
/proc/22197/task/22205/stat : 22205 (java) S 22184 22183 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76302453 909672448 17463 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22206] ppid=22184 vsize=888352 CPUtime=0
/proc/22197/task/22206/stat : 22206 (java) S 22184 22183 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 76302453 909672448 17463 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 893496

[startup+3.10566 s]
/proc/loadavg: 1.73 1.74 1.67 4/45 22206
/proc/meminfo: memFree=186496/1048576 swapFree=0/0
[pid=22183] ppid=22182 vsize=2564 CPUtime=0
/proc/22183/stat : 22183 (p2cudf-paranoid) S 22182 22183 29493 34817 29493 4202496 374 0 0 0 0 0 0 0 18 0 1 0 76302444 2625536 270 1283457024 134512640 135304128 4288502784 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22183/statm: 641 270 230 194 0 28 0
[pid=22184] ppid=22183 vsize=2580 CPUtime=0.02
/proc/22184/stat : 22184 (p2cudf) S 22183 22183 29493 34817 29493 4202496 395 3013 0 1 0 0 1 1 25 0 1 0 76302444 2641920 282 1283457024 134512640 135304128 4290000256 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22184/statm: 645 282 239 194 0 32 0
[pid=22197] ppid=22184 vsize=884760 CPUtime=3.06
/proc/22197/stat : 22197 (java) S 22184 22183 29493 34817 29493 4202496 57812 0 1 0 289 17 0 0 25 0 10 0 76302447 905994240 52173 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/22197/statm: 221190 52173 1741 10 0 218281 0
[pid=22197/tid=22198] ppid=22184 vsize=884760 CPUtime=1.66
/proc/22197/task/22198/stat : 22198 (java) R 22184 22183 29493 34817 29493 4202560 43621 0 1 0 152 14 0 0 25 0 10 0 76302448 905994240 52173 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22197/tid=22199] ppid=22184 vsize=884760 CPUtime=0
/proc/22197/task/22199/stat : 22199 (java) S 22184 22183 29493 34817 29493 4202560 7 0 0 0 0 0 0 0 15 0 10 0 76302450 905994240 52173 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 0 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22200] ppid=22184 vsize=884760 CPUtime=0
/proc/22197/task/22200/stat : 22200 (java) S 22184 22183 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 76302450 905994240 52173 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22201] ppid=22184 vsize=884760 CPUtime=0
/proc/22197/task/22201/stat : 22201 (java) S 22184 22183 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 76302450 905994240 52173 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22202] ppid=22184 vsize=884760 CPUtime=0
/proc/22197/task/22202/stat : 22202 (java) S 22184 22183 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76302453 905994240 52173 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22203] ppid=22184 vsize=884760 CPUtime=0.72
/proc/22197/task/22203/stat : 22203 (java) S 22184 22183 29493 34817 29493 4202560 8095 0 0 0 72 0 0 0 17 0 10 0 76302453 905994240 52173 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22204] ppid=22184 vsize=884760 CPUtime=0.67
/proc/22197/task/22204/stat : 22204 (java) R 22184 22183 29493 34817 29493 4202560 5016 0 0 0 65 2 0 0 23 0 10 0 76302453 905994240 52173 1283457024 134512640 134550932 4293084944 18446744073709551615 4152820373 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22197/tid=22205] ppid=22184 vsize=884760 CPUtime=0
/proc/22197/task/22205/stat : 22205 (java) S 22184 22183 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76302453 905994240 52173 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22206] ppid=22184 vsize=884760 CPUtime=0
/proc/22197/task/22206/stat : 22206 (java) S 22184 22183 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 76302453 905994240 52173 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.08
Current children cumulated vsize (KiB) 889904

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

[startup+3.2057 s]
/proc/loadavg: 1.73 1.74 1.67 4/45 22206
/proc/meminfo: memFree=186496/1048576 swapFree=0/0
[pid=22183] ppid=22182 vsize=2564 CPUtime=0
/proc/22183/stat : 22183 (p2cudf-paranoid) S 22182 22183 29493 34817 29493 4202496 374 0 0 0 0 0 0 0 18 0 1 0 76302444 2625536 270 1283457024 134512640 135304128 4288502784 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22183/statm: 641 270 230 194 0 28 0
[pid=22184] ppid=22183 vsize=2580 CPUtime=0.02
/proc/22184/stat : 22184 (p2cudf) S 22183 22183 29493 34817 29493 4202496 395 3013 0 1 0 0 1 1 25 0 1 0 76302444 2641920 282 1283457024 134512640 135304128 4290000256 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22184/statm: 645 282 239 194 0 32 0
[pid=22197] ppid=22184 vsize=884760 CPUtime=3.16
/proc/22197/stat : 22197 (java) S 22184 22183 29493 34817 29493 4202496 58284 0 1 0 299 17 0 0 25 0 10 0 76302447 905994240 52645 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/22197/statm: 221190 52645 1741 10 0 218281 0
[pid=22197/tid=22198] ppid=22184 vsize=884760 CPUtime=1.68
/proc/22197/task/22198/stat : 22198 (java) R 22184 22183 29493 34817 29493 4202560 44086 0 1 0 154 14 0 0 25 0 10 0 76302448 905994240 52645 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22197/tid=22199] ppid=22184 vsize=884760 CPUtime=0
/proc/22197/task/22199/stat : 22199 (java) S 22184 22183 29493 34817 29493 4202560 7 0 0 0 0 0 0 0 15 0 10 0 76302450 905994240 52645 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 0 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22200] ppid=22184 vsize=884760 CPUtime=0
/proc/22197/task/22200/stat : 22200 (java) S 22184 22183 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 76302450 905994240 52645 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22201] ppid=22184 vsize=884760 CPUtime=0
/proc/22197/task/22201/stat : 22201 (java) S 22184 22183 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 76302450 905994240 52645 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22202] ppid=22184 vsize=884760 CPUtime=0
/proc/22197/task/22202/stat : 22202 (java) S 22184 22183 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76302453 905994240 52645 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22203] ppid=22184 vsize=884760 CPUtime=0.72
/proc/22197/task/22203/stat : 22203 (java) S 22184 22183 29493 34817 29493 4202560 8095 0 0 0 72 0 0 0 17 0 10 0 76302453 905994240 52645 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22204] ppid=22184 vsize=884760 CPUtime=0.75
/proc/22197/task/22204/stat : 22204 (java) R 22184 22183 29493 34817 29493 4202560 5023 0 0 0 73 2 0 0 24 0 10 0 76302453 905994240 52645 1283457024 134512640 134550932 4293084944 18446744073709551615 4153524549 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22197/tid=22205] ppid=22184 vsize=884760 CPUtime=0
/proc/22197/task/22205/stat : 22205 (java) S 22184 22183 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76302453 905994240 52645 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22206] ppid=22184 vsize=884760 CPUtime=0
/proc/22197/task/22206/stat : 22206 (java) S 22184 22183 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 76302453 905994240 52645 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.18
Current children cumulated vsize (KiB) 889904

[startup+4.00596 s]
/proc/loadavg: 1.75 1.75 1.67 3/45 22206
/proc/meminfo: memFree=73904/1048576 swapFree=0/0
[pid=22183] ppid=22182 vsize=2564 CPUtime=0
/proc/22183/stat : 22183 (p2cudf-paranoid) S 22182 22183 29493 34817 29493 4202496 374 0 0 0 0 0 0 0 18 0 1 0 76302444 2625536 270 1283457024 134512640 135304128 4288502784 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22183/statm: 641 270 230 194 0 28 0
[pid=22184] ppid=22183 vsize=2580 CPUtime=0.02
/proc/22184/stat : 22184 (p2cudf) S 22183 22183 29493 34817 29493 4202496 395 3013 0 1 0 0 1 1 25 0 1 0 76302444 2641920 282 1283457024 134512640 135304128 4290000256 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22184/statm: 645 282 239 194 0 32 0
[pid=22197] ppid=22184 vsize=886872 CPUtime=3.95
/proc/22197/stat : 22197 (java) S 22184 22183 29493 34817 29493 4202496 81781 0 1 0 376 19 0 0 25 0 10 0 76302447 908156928 74952 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/22197/statm: 221718 74952 1746 10 0 218809 0
[pid=22197/tid=22198] ppid=22184 vsize=886872 CPUtime=1.78
/proc/22197/task/22198/stat : 22198 (java) R 22184 22183 29493 34817 29493 4202560 50160 0 1 0 162 16 0 0 25 0 10 0 76302448 908156928 74952 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22197/tid=22199] ppid=22184 vsize=886872 CPUtime=0.33
/proc/22197/task/22199/stat : 22199 (java) S 22184 22183 29493 34817 29493 4202560 15865 0 0 0 33 0 0 0 16 0 10 0 76302450 908156928 74952 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 0 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22200] ppid=22184 vsize=886872 CPUtime=0
/proc/22197/task/22200/stat : 22200 (java) S 22184 22183 29493 34817 29493 4202560 9 0 0 0 0 0 0 0 18 0 10 0 76302450 908156928 74952 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22201] ppid=22184 vsize=886872 CPUtime=0
/proc/22197/task/22201/stat : 22201 (java) S 22184 22183 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 10 0 76302450 908156928 74952 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22202] ppid=22184 vsize=886872 CPUtime=0
/proc/22197/task/22202/stat : 22202 (java) S 22184 22183 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76302453 908156928 74952 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22203] ppid=22184 vsize=886872 CPUtime=1.05
/proc/22197/task/22203/stat : 22203 (java) R 22184 22183 29493 34817 29493 4202560 9655 0 0 0 105 0 0 0 16 0 10 0 76302453 908156928 74952 1283457024 134512640 134550932 4293084944 18446744073709551615 4150290286 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22197/tid=22204] ppid=22184 vsize=886872 CPUtime=0.77
/proc/22197/task/22204/stat : 22204 (java) R 22184 22183 29493 34817 29493 4202560 5025 0 0 0 75 2 0 0 24 0 10 0 76302453 908156928 74952 1283457024 134512640 134550932 4293084944 18446744073709551615 4151927577 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22197/tid=22205] ppid=22184 vsize=886872 CPUtime=0
/proc/22197/task/22205/stat : 22205 (java) S 22184 22183 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76302453 908156928 74952 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22206] ppid=22184 vsize=886872 CPUtime=0
/proc/22197/task/22206/stat : 22206 (java) S 22184 22183 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 76302453 908156928 74952 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.97
Current children cumulated vsize (KiB) 892016

[startup+4.80529 s]
/proc/loadavg: 1.75 1.75 1.67 3/45 22206
/proc/meminfo: memFree=6572/1048576 swapFree=0/0
[pid=22183] ppid=22182 vsize=2564 CPUtime=0
/proc/22183/stat : 22183 (p2cudf-paranoid) S 22182 22183 29493 34817 29493 4202496 374 0 0 0 0 0 0 0 18 0 1 0 76302444 2625536 270 1283457024 134512640 135304128 4288502784 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22183/statm: 641 270 230 194 0 28 0
[pid=22184] ppid=22183 vsize=2580 CPUtime=0.02
/proc/22184/stat : 22184 (p2cudf) S 22183 22183 29493 34817 29493 4202496 395 3013 0 1 0 0 1 1 25 0 1 0 76302444 2641920 282 1283457024 134512640 135304128 4290000256 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22184/statm: 645 282 239 194 0 32 0
[pid=22197] ppid=22184 vsize=885896 CPUtime=4.6
/proc/22197/stat : 22197 (java) S 22184 22183 29493 34817 29493 4202496 81862 0 1 0 441 19 0 0 25 0 11 0 76302447 907157504 74841 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/22197/statm: 221474 74841 1747 10 0 218565 0
[pid=22197/tid=22198] ppid=22184 vsize=885896 CPUtime=2.12
/proc/22197/task/22198/stat : 22198 (java) S 22184 22183 29493 34817 29493 4202560 50184 0 1 0 196 16 0 0 25 0 11 0 76302448 907157504 74841 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22199] ppid=22184 vsize=885896 CPUtime=0.33
/proc/22197/task/22199/stat : 22199 (java) S 22184 22183 29493 34817 29493 4202560 15865 0 0 0 33 0 0 0 15 0 11 0 76302450 907157504 74841 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 0 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22200] ppid=22184 vsize=885896 CPUtime=0
/proc/22197/task/22200/stat : 22200 (java) S 22184 22183 29493 34817 29493 4202560 9 0 0 0 0 0 0 0 18 0 11 0 76302450 907157504 74841 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22201] ppid=22184 vsize=885896 CPUtime=0
/proc/22197/task/22201/stat : 22201 (java) S 22184 22183 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 11 0 76302450 907157504 74841 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22202] ppid=22184 vsize=885896 CPUtime=0
/proc/22197/task/22202/stat : 22202 (java) S 22184 22183 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 76302453 907157504 74841 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22203] ppid=22184 vsize=885896 CPUtime=1.25
/proc/22197/task/22203/stat : 22203 (java) S 22184 22183 29493 34817 29493 4202560 9703 0 0 0 125 0 0 0 15 0 11 0 76302453 907157504 74841 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22204] ppid=22184 vsize=885896 CPUtime=0.88
/proc/22197/task/22204/stat : 22204 (java) S 22184 22183 29493 34817 29493 4202560 5030 0 0 0 86 2 0 0 24 0 11 0 76302453 907157504 74841 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22205] ppid=22184 vsize=885896 CPUtime=0
/proc/22197/task/22205/stat : 22205 (java) S 22184 22183 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 76302453 907157504 74841 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22206] ppid=22184 vsize=885896 CPUtime=0
/proc/22197/task/22206/stat : 22206 (java) S 22184 22183 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 11 0 76302453 907157504 74841 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.62
Current children cumulated vsize (KiB) 891040

[startup+5.20534 s]
/proc/loadavg: 1.75 1.75 1.67 3/45 22206
/proc/meminfo: memFree=6572/1048576 swapFree=0/0
[pid=22183] ppid=22182 vsize=2564 CPUtime=0
/proc/22183/stat : 22183 (p2cudf-paranoid) S 22182 22183 29493 34817 29493 4202496 374 0 0 0 0 0 0 0 18 0 1 0 76302444 2625536 270 1283457024 134512640 135304128 4288502784 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22183/statm: 641 270 230 194 0 28 0
[pid=22184] ppid=22183 vsize=2580 CPUtime=0.02
/proc/22184/stat : 22184 (p2cudf) S 22183 22183 29493 34817 29493 4202496 395 3013 0 1 0 0 1 1 25 0 1 0 76302444 2641920 282 1283457024 134512640 135304128 4290000256 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22184/statm: 645 282 239 194 0 32 0
[pid=22197] ppid=22184 vsize=885896 CPUtime=4.6
/proc/22197/stat : 22197 (java) S 22184 22183 29493 34817 29493 4202496 81864 0 1 0 441 19 0 0 25 0 10 0 76302447 907157504 74843 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/22197/statm: 221474 74843 1749 10 0 218565 0
[pid=22197/tid=22198] ppid=22184 vsize=885896 CPUtime=2.12
/proc/22197/task/22198/stat : 22198 (java) S 22184 22183 29493 34817 29493 4202560 50184 0 1 0 196 16 0 0 20 0 10 0 76302448 907157504 74843 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22199] ppid=22184 vsize=885896 CPUtime=0.33
/proc/22197/task/22199/stat : 22199 (java) S 22184 22183 29493 34817 29493 4202560 15866 0 0 0 33 0 0 0 16 0 10 0 76302450 907157504 74843 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 0 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22200] ppid=22184 vsize=885896 CPUtime=0
/proc/22197/task/22200/stat : 22200 (java) S 22184 22183 29493 34817 29493 4202560 9 0 0 0 0 0 0 0 18 0 10 0 76302450 907157504 74843 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22201] ppid=22184 vsize=885896 CPUtime=0
/proc/22197/task/22201/stat : 22201 (java) S 22184 22183 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 10 0 76302450 907157504 74843 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22202] ppid=22184 vsize=885896 CPUtime=0
/proc/22197/task/22202/stat : 22202 (java) S 22184 22183 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76302453 907157504 74843 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22203] ppid=22184 vsize=885896 CPUtime=1.25
/proc/22197/task/22203/stat : 22203 (java) S 22184 22183 29493 34817 29493 4202560 9703 0 0 0 125 0 0 0 15 0 10 0 76302453 907157504 74843 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22204] ppid=22184 vsize=885896 CPUtime=0.88
/proc/22197/task/22204/stat : 22204 (java) S 22184 22183 29493 34817 29493 4202560 5030 0 0 0 86 2 0 0 24 0 10 0 76302453 907157504 74843 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22205] ppid=22184 vsize=885896 CPUtime=0
/proc/22197/task/22205/stat : 22205 (java) S 22184 22183 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76302453 907157504 74843 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 18446612132758716864 0 0 -1 0 0 0 0
[pid=22197/tid=22206] ppid=22184 vsize=885896 CPUtime=0
/proc/22197/task/22206/stat : 22206 (java) R 22184 22183 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 76302453 907157504 74843 1283457024 134512640 134550932 4293084944 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.62
Current children cumulated vsize (KiB) 891040

Child status: 0
Real time (s): 5.23749
CPU time (s): 4.66829
CPU user time (s): 4.42828
CPU system time (s): 0.240015
CPU usage (%): 89.1322
Max. virtual memory (cumulated for all children) (KiB): 894388

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.42828
system time used= 0.240015
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 85671
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= 342
involuntary context switches= 328

runsolver used 0 second user time and 0.012 second system time

The end