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/65.cudf.caixa.log.runsolver ./p2cudf-paranoid-1.12 /home/misc2010/data/misc4/caixa//65.cudf /home/misc2010/tmp/201103031013/p2cudf-paranoid-1.12/65.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.93 1.87 1.73 5/35 25385
/proc/meminfo: memFree=297324/1048576 swapFree=0/0
[pid=25383] ppid=25382 vsize=2568 CPUtime=0
/proc/25383/stat : 25383 (p2cudf-paranoid) S 25382 25383 29493 34817 29493 4202496 372 0 0 0 0 0 0 0 18 0 1 0 76321685 2629632 269 1283457024 134512640 135304128 4291419856 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25383/statm: 642 269 230 194 0 29 0
[pid=25384] ppid=25383 vsize=2568 CPUtime=0
/proc/25384/stat : 25384 (p2cudf) R 25383 25383 29493 34817 29493 4202496 345 0 0 0 0 0 0 0 25 0 1 0 76321685 2629632 271 1283457024 134512640 135304128 4294937152 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/25384/statm: 642 271 231 194 0 29 0
[pid=25385] ppid=25384 vsize=2568 CPUtime=0
/proc/25385/stat : 25385 (p2cudf) R 25384 25383 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 1 0 76321685 2629632 40 1283457024 134512640 135304128 4294937152 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/25385/statm: 642 40 0 194 0 29 0

[startup+0.155669 s]
/proc/loadavg: 1.93 1.87 1.73 5/35 25385
/proc/meminfo: memFree=297324/1048576 swapFree=0/0
[pid=25383] ppid=25382 vsize=2568 CPUtime=0
/proc/25383/stat : 25383 (p2cudf-paranoid) S 25382 25383 29493 34817 29493 4202496 372 0 0 0 0 0 0 0 18 0 1 0 76321685 2629632 269 1283457024 134512640 135304128 4291419856 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25383/statm: 642 269 230 194 0 29 0
[pid=25384] ppid=25383 vsize=2576 CPUtime=0.04
/proc/25384/stat : 25384 (p2cudf) S 25383 25383 29493 34817 29493 4202496 393 3017 0 1 0 0 2 2 25 0 1 0 76321685 2637824 281 1283457024 134512640 135304128 4294937152 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25384/statm: 644 281 239 194 0 31 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 5144

[startup+0.205671 s]
/proc/loadavg: 1.93 1.87 1.73 5/35 25385
/proc/meminfo: memFree=297324/1048576 swapFree=0/0
[pid=25383] ppid=25382 vsize=2568 CPUtime=0
/proc/25383/stat : 25383 (p2cudf-paranoid) S 25382 25383 29493 34817 29493 4202496 372 0 0 0 0 0 0 0 18 0 1 0 76321685 2629632 269 1283457024 134512640 135304128 4291419856 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25383/statm: 642 269 230 194 0 29 0
[pid=25384] ppid=25383 vsize=2576 CPUtime=0.04
/proc/25384/stat : 25384 (p2cudf) S 25383 25383 29493 34817 29493 4202496 393 3017 0 1 0 0 2 2 25 0 1 0 76321685 2637824 281 1283457024 134512640 135304128 4294937152 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25384/statm: 644 281 239 194 0 31 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 5144

[startup+0.305698 s]
/proc/loadavg: 1.93 1.87 1.73 5/35 25385
/proc/meminfo: memFree=297324/1048576 swapFree=0/0
[pid=25383] ppid=25382 vsize=2568 CPUtime=0
/proc/25383/stat : 25383 (p2cudf-paranoid) S 25382 25383 29493 34817 29493 4202496 372 0 0 0 0 0 0 0 18 0 1 0 76321685 2629632 269 1283457024 134512640 135304128 4291419856 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25383/statm: 642 269 230 194 0 29 0
[pid=25384] ppid=25383 vsize=2576 CPUtime=0.04
/proc/25384/stat : 25384 (p2cudf) S 25383 25383 29493 34817 29493 4202496 393 3017 0 1 0 0 2 2 25 0 1 0 76321685 2637824 281 1283457024 134512640 135304128 4294937152 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25384/statm: 644 281 239 194 0 31 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 5144

[startup+0.705814 s]
/proc/loadavg: 1.93 1.87 1.73 5/35 25385
/proc/meminfo: memFree=297324/1048576 swapFree=0/0
[pid=25383] ppid=25382 vsize=2568 CPUtime=0
/proc/25383/stat : 25383 (p2cudf-paranoid) S 25382 25383 29493 34817 29493 4202496 372 0 0 0 0 0 0 0 18 0 1 0 76321685 2629632 269 1283457024 134512640 135304128 4291419856 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25383/statm: 642 269 230 194 0 29 0
[pid=25384] ppid=25383 vsize=2576 CPUtime=0.04
/proc/25384/stat : 25384 (p2cudf) S 25383 25383 29493 34817 29493 4202496 393 3017 0 1 0 0 2 2 25 0 1 0 76321685 2637824 281 1283457024 134512640 135304128 4294937152 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25384/statm: 644 281 239 194 0 31 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 5144

[startup+1.50599 s]
/proc/loadavg: 2.01 1.89 1.74 4/45 25406
/proc/meminfo: memFree=244472/1048576 swapFree=0/0
[pid=25383] ppid=25382 vsize=2568 CPUtime=0
/proc/25383/stat : 25383 (p2cudf-paranoid) S 25382 25383 29493 34817 29493 4202496 372 0 0 0 0 0 0 0 18 0 1 0 76321685 2629632 269 1283457024 134512640 135304128 4291419856 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25383/statm: 642 269 230 194 0 29 0
[pid=25384] ppid=25383 vsize=2576 CPUtime=0.04
/proc/25384/stat : 25384 (p2cudf) S 25383 25383 29493 34817 29493 4202496 393 3017 0 1 0 0 2 2 25 0 1 0 76321685 2637824 281 1283457024 134512640 135304128 4294937152 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25384/statm: 644 281 239 194 0 31 0
[pid=25397] ppid=25384 vsize=885720 CPUtime=1.46
/proc/25397/stat : 25397 (java) S 25384 25383 29493 34817 29493 4202496 24123 0 1 0 136 10 0 0 25 0 10 0 76321689 906977280 20154 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25397/statm: 221430 20154 1730 10 0 218521 0
[pid=25397/tid=25398] ppid=25384 vsize=885720 CPUtime=0.79
/proc/25397/task/25398/stat : 25398 (java) R 25384 25383 29493 34817 29493 4202560 11836 0 1 0 71 8 0 0 25 0 10 0 76321689 906977280 20154 1283457024 134512640 134550932 4290460816 18446744073709551615 4095782146 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25397/tid=25399] ppid=25384 vsize=885720 CPUtime=0
/proc/25397/task/25399/stat : 25399 (java) S 25384 25383 29493 34817 29493 4202560 7 0 0 0 0 0 0 0 18 0 10 0 76321691 906977280 20154 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 0 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25400] ppid=25384 vsize=885720 CPUtime=0
/proc/25397/task/25400/stat : 25400 (java) S 25384 25383 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 76321691 906977280 20154 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25401] ppid=25384 vsize=885720 CPUtime=0
/proc/25397/task/25401/stat : 25401 (java) S 25384 25383 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 76321691 906977280 20154 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25402] ppid=25384 vsize=885720 CPUtime=0
/proc/25397/task/25402/stat : 25402 (java) S 25384 25383 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76321694 906977280 20154 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25403] ppid=25384 vsize=885720 CPUtime=0.46
/proc/25397/task/25403/stat : 25403 (java) R 25384 25383 29493 34817 29493 4202560 9290 0 0 0 44 2 0 0 25 0 10 0 76321694 906977280 20154 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25397/tid=25404] ppid=25384 vsize=885720 CPUtime=0.2
/proc/25397/task/25404/stat : 25404 (java) R 25384 25383 29493 34817 29493 4202560 1918 0 0 0 20 0 0 0 17 0 10 0 76321694 906977280 20154 1283457024 134512640 134550932 4290460816 18446744073709551615 4152918251 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25397/tid=25405] ppid=25384 vsize=885720 CPUtime=0
/proc/25397/task/25405/stat : 25405 (java) S 25384 25383 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76321694 906977280 20154 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25406] ppid=25384 vsize=885720 CPUtime=0
/proc/25397/task/25406/stat : 25406 (java) S 25384 25383 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 76321694 906977280 20154 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 890864

[startup+3.11634 s]
/proc/loadavg: 2.01 1.89 1.74 4/45 25406
/proc/meminfo: memFree=210992/1048576 swapFree=0/0
[pid=25383] ppid=25382 vsize=2568 CPUtime=0
/proc/25383/stat : 25383 (p2cudf-paranoid) S 25382 25383 29493 34817 29493 4202496 372 0 0 0 0 0 0 0 18 0 1 0 76321685 2629632 269 1283457024 134512640 135304128 4291419856 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25383/statm: 642 269 230 194 0 29 0
[pid=25384] ppid=25383 vsize=2576 CPUtime=0.04
/proc/25384/stat : 25384 (p2cudf) S 25383 25383 29493 34817 29493 4202496 393 3017 0 1 0 0 2 2 25 0 1 0 76321685 2637824 281 1283457024 134512640 135304128 4294937152 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25384/statm: 644 281 239 194 0 31 0
[pid=25397] ppid=25384 vsize=895864 CPUtime=3.06
/proc/25397/stat : 25397 (java) S 25384 25383 29493 34817 29493 4202496 61886 0 1 0 283 23 0 0 25 0 10 0 76321689 917364736 54053 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25397/statm: 223966 54053 1741 10 0 221057 0
[pid=25397/tid=25398] ppid=25384 vsize=895864 CPUtime=1.47
/proc/25397/task/25398/stat : 25398 (java) R 25384 25383 29493 34817 29493 4202560 42838 0 1 0 128 19 0 0 25 0 10 0 76321689 917364736 54053 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25397/tid=25399] ppid=25384 vsize=895864 CPUtime=0
/proc/25397/task/25399/stat : 25399 (java) S 25384 25383 29493 34817 29493 4202560 7 0 0 0 0 0 0 0 18 0 10 0 76321691 917364736 54053 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 0 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25400] ppid=25384 vsize=895864 CPUtime=0
/proc/25397/task/25400/stat : 25400 (java) S 25384 25383 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 76321691 917364736 54053 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25401] ppid=25384 vsize=895864 CPUtime=0
/proc/25397/task/25401/stat : 25401 (java) S 25384 25383 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 76321691 917364736 54053 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25402] ppid=25384 vsize=895864 CPUtime=0
/proc/25397/task/25402/stat : 25402 (java) S 25384 25383 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76321694 917364736 54053 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25403] ppid=25384 vsize=895864 CPUtime=0.56
/proc/25397/task/25403/stat : 25403 (java) R 25384 25383 29493 34817 29493 4202560 9332 0 0 0 54 2 0 0 21 0 10 0 76321694 917364736 54053 1283457024 134512640 134550932 4290460816 18446744073709551615 4152771692 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25397/tid=25404] ppid=25384 vsize=895864 CPUtime=1.02
/proc/25397/task/25404/stat : 25404 (java) R 25384 25383 29493 34817 29493 4202560 8637 0 0 0 101 1 0 0 15 0 10 0 76321694 917364736 54053 1283457024 134512640 134550932 4290460816 18446744073709551615 4152032785 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25397/tid=25405] ppid=25384 vsize=895864 CPUtime=0
/proc/25397/task/25405/stat : 25405 (java) S 25384 25383 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76321694 917364736 54053 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25406] ppid=25384 vsize=895864 CPUtime=0
/proc/25397/task/25406/stat : 25406 (java) S 25384 25383 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 76321694 917364736 54053 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.1
Current children cumulated vsize (KiB) 901008

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

[startup+3.20632 s]
/proc/loadavg: 2.01 1.89 1.74 4/45 25406
/proc/meminfo: memFree=210992/1048576 swapFree=0/0
[pid=25383] ppid=25382 vsize=2568 CPUtime=0
/proc/25383/stat : 25383 (p2cudf-paranoid) S 25382 25383 29493 34817 29493 4202496 372 0 0 0 0 0 0 0 18 0 1 0 76321685 2629632 269 1283457024 134512640 135304128 4291419856 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25383/statm: 642 269 230 194 0 29 0
[pid=25384] ppid=25383 vsize=2576 CPUtime=0.04
/proc/25384/stat : 25384 (p2cudf) S 25383 25383 29493 34817 29493 4202496 393 3017 0 1 0 0 2 2 25 0 1 0 76321685 2637824 281 1283457024 134512640 135304128 4294937152 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25384/statm: 644 281 239 194 0 31 0
[pid=25397] ppid=25384 vsize=895864 CPUtime=3.15
/proc/25397/stat : 25397 (java) S 25384 25383 29493 34817 29493 4202496 62259 0 1 0 292 23 0 0 25 0 10 0 76321689 917364736 54426 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25397/statm: 223966 54426 1741 10 0 221057 0
[pid=25397/tid=25398] ppid=25384 vsize=895864 CPUtime=1.49
/proc/25397/task/25398/stat : 25398 (java) R 25384 25383 29493 34817 29493 4202560 43208 0 1 0 130 19 0 0 25 0 10 0 76321689 917364736 54426 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25397/tid=25399] ppid=25384 vsize=895864 CPUtime=0
/proc/25397/task/25399/stat : 25399 (java) S 25384 25383 29493 34817 29493 4202560 7 0 0 0 0 0 0 0 18 0 10 0 76321691 917364736 54426 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 0 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25400] ppid=25384 vsize=895864 CPUtime=0
/proc/25397/task/25400/stat : 25400 (java) S 25384 25383 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 76321691 917364736 54426 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25401] ppid=25384 vsize=895864 CPUtime=0
/proc/25397/task/25401/stat : 25401 (java) S 25384 25383 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 76321691 917364736 54426 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25402] ppid=25384 vsize=895864 CPUtime=0
/proc/25397/task/25402/stat : 25402 (java) S 25384 25383 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76321694 917364736 54426 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25403] ppid=25384 vsize=895864 CPUtime=0.56
/proc/25397/task/25403/stat : 25403 (java) R 25384 25383 29493 34817 29493 4202560 9332 0 0 0 54 2 0 0 21 0 10 0 76321694 917364736 54426 1283457024 134512640 134550932 4290460816 18446744073709551615 4152771692 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25397/tid=25404] ppid=25384 vsize=895864 CPUtime=1.09
/proc/25397/task/25404/stat : 25404 (java) R 25384 25383 29493 34817 29493 4202560 8640 0 0 0 108 1 0 0 16 0 10 0 76321694 917364736 54426 1283457024 134512640 134550932 4290460816 18446744073709551615 4151933667 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25397/tid=25405] ppid=25384 vsize=895864 CPUtime=0
/proc/25397/task/25405/stat : 25405 (java) S 25384 25383 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76321694 917364736 54426 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25406] ppid=25384 vsize=895864 CPUtime=0
/proc/25397/task/25406/stat : 25406 (java) S 25384 25383 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 76321694 917364736 54426 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.19
Current children cumulated vsize (KiB) 901008

[startup+4.00661 s]
/proc/loadavg: 2.01 1.89 1.74 3/45 25406
/proc/meminfo: memFree=76576/1048576 swapFree=0/0
[pid=25383] ppid=25382 vsize=2568 CPUtime=0
/proc/25383/stat : 25383 (p2cudf-paranoid) S 25382 25383 29493 34817 29493 4202496 372 0 0 0 0 0 0 0 18 0 1 0 76321685 2629632 269 1283457024 134512640 135304128 4291419856 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25383/statm: 642 269 230 194 0 29 0
[pid=25384] ppid=25383 vsize=2576 CPUtime=0.04
/proc/25384/stat : 25384 (p2cudf) S 25383 25383 29493 34817 29493 4202496 393 3017 0 1 0 0 2 2 25 0 1 0 76321685 2637824 281 1283457024 134512640 135304128 4294937152 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25384/statm: 644 281 239 194 0 31 0
[pid=25397] ppid=25384 vsize=895864 CPUtime=3.93
/proc/25397/stat : 25397 (java) S 25384 25383 29493 34817 29493 4202496 84927 0 1 0 367 26 0 0 25 0 10 0 76321689 917364736 77094 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25397/statm: 223966 77094 1746 10 0 221057 0
[pid=25397/tid=25398] ppid=25384 vsize=895864 CPUtime=1.62
/proc/25397/task/25398/stat : 25398 (java) R 25384 25383 29493 34817 29493 4202560 50169 0 1 0 140 22 0 0 25 0 10 0 76321689 917364736 77094 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25397/tid=25399] ppid=25384 vsize=895864 CPUtime=0.31
/proc/25397/task/25399/stat : 25399 (java) S 25384 25383 29493 34817 29493 4202560 15598 0 0 0 31 0 0 0 16 0 10 0 76321691 917364736 77094 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 0 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25400] ppid=25384 vsize=895864 CPUtime=0
/proc/25397/task/25400/stat : 25400 (java) S 25384 25383 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 18 0 10 0 76321691 917364736 77094 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25401] ppid=25384 vsize=895864 CPUtime=0
/proc/25397/task/25401/stat : 25401 (java) S 25384 25383 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 10 0 76321691 917364736 77094 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25402] ppid=25384 vsize=895864 CPUtime=0
/proc/25397/task/25402/stat : 25402 (java) S 25384 25383 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76321694 917364736 77094 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25403] ppid=25384 vsize=895864 CPUtime=0.81
/proc/25397/task/25403/stat : 25403 (java) R 25384 25383 29493 34817 29493 4202560 9437 0 0 0 79 2 0 0 17 0 10 0 76321694 917364736 77094 1283457024 134512640 134550932 4290460816 18446744073709551615 4150421130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25397/tid=25404] ppid=25384 vsize=895864 CPUtime=1.17
/proc/25397/task/25404/stat : 25404 (java) S 25384 25383 29493 34817 29493 4202560 8649 0 0 0 116 1 0 0 15 0 10 0 76321694 917364736 77094 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25405] ppid=25384 vsize=895864 CPUtime=0
/proc/25397/task/25405/stat : 25405 (java) S 25384 25383 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76321694 917364736 77094 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25406] ppid=25384 vsize=895864 CPUtime=0
/proc/25397/task/25406/stat : 25406 (java) S 25384 25383 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 76321694 917364736 77094 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.97
Current children cumulated vsize (KiB) 901008

[startup+4.80588 s]
/proc/loadavg: 2.01 1.89 1.74 3/45 25406
/proc/meminfo: memFree=5296/1048576 swapFree=0/0
[pid=25383] ppid=25382 vsize=2568 CPUtime=0
/proc/25383/stat : 25383 (p2cudf-paranoid) S 25382 25383 29493 34817 29493 4202496 372 0 0 0 0 0 0 0 18 0 1 0 76321685 2629632 269 1283457024 134512640 135304128 4291419856 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25383/statm: 642 269 230 194 0 29 0
[pid=25384] ppid=25383 vsize=2576 CPUtime=0.04
/proc/25384/stat : 25384 (p2cudf) S 25383 25383 29493 34817 29493 4202496 393 3017 0 1 0 0 2 2 25 0 1 0 76321685 2637824 281 1283457024 134512640 135304128 4294937152 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25384/statm: 644 281 239 194 0 31 0
[pid=25397] ppid=25384 vsize=896188 CPUtime=4.44
/proc/25397/stat : 25397 (java) S 25384 25383 29493 34817 29493 4202496 85006 0 1 0 418 26 0 0 25 0 11 0 76321689 917696512 77173 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25397/statm: 224047 77173 1752 10 0 221138 0
[pid=25397/tid=25398] ppid=25384 vsize=896188 CPUtime=1.86
/proc/25397/task/25398/stat : 25398 (java) S 25384 25383 29493 34817 29493 4202560 50193 0 1 0 164 22 0 0 25 0 11 0 76321689 917696512 77173 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25399] ppid=25384 vsize=896188 CPUtime=0.31
/proc/25397/task/25399/stat : 25399 (java) S 25384 25383 29493 34817 29493 4202560 15598 0 0 0 31 0 0 0 15 0 11 0 76321691 917696512 77173 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 0 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25400] ppid=25384 vsize=896188 CPUtime=0
/proc/25397/task/25400/stat : 25400 (java) S 25384 25383 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 18 0 11 0 76321691 917696512 77173 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25401] ppid=25384 vsize=896188 CPUtime=0
/proc/25397/task/25401/stat : 25401 (java) S 25384 25383 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 11 0 76321691 917696512 77173 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25402] ppid=25384 vsize=896188 CPUtime=0
/proc/25397/task/25402/stat : 25402 (java) S 25384 25383 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 76321694 917696512 77173 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25403] ppid=25384 vsize=896188 CPUtime=1.08
/proc/25397/task/25403/stat : 25403 (java) S 25384 25383 29493 34817 29493 4202560 9488 0 0 0 106 2 0 0 15 0 11 0 76321694 917696512 77173 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25404] ppid=25384 vsize=896188 CPUtime=1.17
/proc/25397/task/25404/stat : 25404 (java) S 25384 25383 29493 34817 29493 4202560 8649 0 0 0 116 1 0 0 15 0 11 0 76321694 917696512 77173 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25405] ppid=25384 vsize=896188 CPUtime=0
/proc/25397/task/25405/stat : 25405 (java) S 25384 25383 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 76321694 917696512 77173 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25406] ppid=25384 vsize=896188 CPUtime=0
/proc/25397/task/25406/stat : 25406 (java) S 25384 25383 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 11 0 76321694 917696512 77173 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.48
Current children cumulated vsize (KiB) 901332

[startup+5.00597 s]
/proc/loadavg: 2.01 1.89 1.74 3/45 25406
/proc/meminfo: memFree=5296/1048576 swapFree=0/0
[pid=25383] ppid=25382 vsize=2568 CPUtime=0
/proc/25383/stat : 25383 (p2cudf-paranoid) S 25382 25383 29493 34817 29493 4202496 372 0 0 0 0 0 0 0 18 0 1 0 76321685 2629632 269 1283457024 134512640 135304128 4291419856 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25383/statm: 642 269 230 194 0 29 0
[pid=25384] ppid=25383 vsize=2576 CPUtime=0.04
/proc/25384/stat : 25384 (p2cudf) S 25383 25383 29493 34817 29493 4202496 393 3017 0 1 0 0 2 2 25 0 1 0 76321685 2637824 281 1283457024 134512640 135304128 4294937152 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25384/statm: 644 281 239 194 0 31 0
[pid=25397] ppid=25384 vsize=896188 CPUtime=4.44
/proc/25397/stat : 25397 (java) S 25384 25383 29493 34817 29493 4202496 85006 0 1 0 418 26 0 0 25 0 11 0 76321689 917696512 77173 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25397/statm: 224047 77173 1752 10 0 221138 0
[pid=25397/tid=25398] ppid=25384 vsize=896188 CPUtime=1.86
/proc/25397/task/25398/stat : 25398 (java) S 25384 25383 29493 34817 29493 4202560 50193 0 1 0 164 22 0 0 25 0 11 0 76321689 917696512 77173 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25399] ppid=25384 vsize=896188 CPUtime=0.31
/proc/25397/task/25399/stat : 25399 (java) S 25384 25383 29493 34817 29493 4202560 15598 0 0 0 31 0 0 0 15 0 11 0 76321691 917696512 77173 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 0 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25400] ppid=25384 vsize=896188 CPUtime=0
/proc/25397/task/25400/stat : 25400 (java) S 25384 25383 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 18 0 11 0 76321691 917696512 77173 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25401] ppid=25384 vsize=896188 CPUtime=0
/proc/25397/task/25401/stat : 25401 (java) S 25384 25383 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 11 0 76321691 917696512 77173 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25402] ppid=25384 vsize=896188 CPUtime=0
/proc/25397/task/25402/stat : 25402 (java) S 25384 25383 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 76321694 917696512 77173 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25403] ppid=25384 vsize=896188 CPUtime=1.08
/proc/25397/task/25403/stat : 25403 (java) S 25384 25383 29493 34817 29493 4202560 9488 0 0 0 106 2 0 0 15 0 11 0 76321694 917696512 77173 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25404] ppid=25384 vsize=896188 CPUtime=1.17
/proc/25397/task/25404/stat : 25404 (java) S 25384 25383 29493 34817 29493 4202560 8649 0 0 0 116 1 0 0 15 0 11 0 76321694 917696512 77173 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25405] ppid=25384 vsize=896188 CPUtime=0
/proc/25397/task/25405/stat : 25405 (java) S 25384 25383 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 76321694 917696512 77173 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
[pid=25397/tid=25406] ppid=25384 vsize=896188 CPUtime=0
/proc/25397/task/25406/stat : 25406 (java) S 25384 25383 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 11 0 76321694 917696512 77173 1283457024 134512640 134550932 4290460816 18446744073709551615 4294960130 0 4 0 16800975 18446612132758717760 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.48
Current children cumulated vsize (KiB) 901332

Child status: 0
Real time (s): 5.10734
CPU time (s): 4.52428
CPU user time (s): 4.20426
CPU system time (s): 0.32002
CPU usage (%): 88.584
Max. virtual memory (cumulated for all children) (KiB): 904588

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.20426
system time used= 0.32002
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 88815
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= 425
involuntary context switches= 419

runsolver used 0 second user time and 0 second system time

The end