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/201108291842/p2cudf-user-1.13/rand56.cudf.user-upgrades.log.runsolver ./p2cudf-user-1.13 /home/misc2010/data/2011/user-upgrades/rand56.cudf /home/misc2010/tmp/201108291842/p2cudf-user-1.13/rand56.cudf.user-upgrades.result -notuptodate,-removed,-changed 

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.27 1.20 1.17 3/34 23812
/proc/meminfo: memFree=305524/1048576 swapFree=0/0
[pid=23811] ppid=23810 vsize=2564 CPUtime=0
/proc/23811/stat : 23811 (p2cudf-user-1.1) R 23810 23811 17511 34816 17511 4202496 357 0 0 0 0 0 0 0 25 0 1 0 46294019 2625536 270 1283457024 134512640 135304128 4294224192 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/23811/statm: 641 270 230 194 0 28 0
[pid=23812] ppid=23811 vsize=2564 CPUtime=0
/proc/23812/stat : 23812 (p2cudf-user-1.1) R 23811 23811 17511 34816 17511 4202560 0 0 0 0 0 0 0 0 25 0 1 0 46294019 2625536 40 1283457024 134512640 135304128 4294224192 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/23812/statm: 641 40 0 194 0 28 0

[startup+0.145437 s]
/proc/loadavg: 1.27 1.20 1.17 3/34 23812
/proc/meminfo: memFree=305524/1048576 swapFree=0/0
[pid=23811] ppid=23810 vsize=2564 CPUtime=0
/proc/23811/stat : 23811 (p2cudf-user-1.1) S 23810 23811 17511 34816 17511 4202496 375 0 0 0 0 0 0 0 25 0 1 0 46294019 2625536 270 1283457024 134512640 135304128 4294224192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23811/statm: 641 270 230 194 0 28 0
[pid=23812] ppid=23811 vsize=2572 CPUtime=0.02
/proc/23812/stat : 23812 (p2cudf) S 23811 23811 17511 34816 17511 4202496 389 3012 0 1 0 0 0 2 25 0 1 0 46294019 2633728 279 1283457024 134512640 135304128 4291329712 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23812/statm: 643 279 239 194 0 30 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5136

[startup+0.205434 s]
/proc/loadavg: 1.27 1.20 1.17 3/34 23812
/proc/meminfo: memFree=305524/1048576 swapFree=0/0
[pid=23811] ppid=23810 vsize=2564 CPUtime=0
/proc/23811/stat : 23811 (p2cudf-user-1.1) S 23810 23811 17511 34816 17511 4202496 375 0 0 0 0 0 0 0 25 0 1 0 46294019 2625536 270 1283457024 134512640 135304128 4294224192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23811/statm: 641 270 230 194 0 28 0
[pid=23812] ppid=23811 vsize=2572 CPUtime=0.02
/proc/23812/stat : 23812 (p2cudf) S 23811 23811 17511 34816 17511 4202496 389 3012 0 1 0 0 0 2 25 0 1 0 46294019 2633728 279 1283457024 134512640 135304128 4291329712 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23812/statm: 643 279 239 194 0 30 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5136

[startup+0.30545 s]
/proc/loadavg: 1.27 1.20 1.17 3/34 23812
/proc/meminfo: memFree=305524/1048576 swapFree=0/0
[pid=23811] ppid=23810 vsize=2564 CPUtime=0
/proc/23811/stat : 23811 (p2cudf-user-1.1) S 23810 23811 17511 34816 17511 4202496 375 0 0 0 0 0 0 0 25 0 1 0 46294019 2625536 270 1283457024 134512640 135304128 4294224192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23811/statm: 641 270 230 194 0 28 0
[pid=23812] ppid=23811 vsize=2572 CPUtime=0.02
/proc/23812/stat : 23812 (p2cudf) S 23811 23811 17511 34816 17511 4202496 389 3012 0 1 0 0 0 2 25 0 1 0 46294019 2633728 279 1283457024 134512640 135304128 4291329712 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23812/statm: 643 279 239 194 0 30 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5136

[startup+0.705544 s]
/proc/loadavg: 1.27 1.20 1.17 3/34 23812
/proc/meminfo: memFree=305524/1048576 swapFree=0/0
[pid=23811] ppid=23810 vsize=2564 CPUtime=0
/proc/23811/stat : 23811 (p2cudf-user-1.1) S 23810 23811 17511 34816 17511 4202496 375 0 0 0 0 0 0 0 25 0 1 0 46294019 2625536 270 1283457024 134512640 135304128 4294224192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23811/statm: 641 270 230 194 0 28 0
[pid=23812] ppid=23811 vsize=2572 CPUtime=0.02
/proc/23812/stat : 23812 (p2cudf) S 23811 23811 17511 34816 17511 4202496 389 3012 0 1 0 0 0 2 25 0 1 0 46294019 2633728 279 1283457024 134512640 135304128 4291329712 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23812/statm: 643 279 239 194 0 30 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5136

[startup+1.50574 s]
/proc/loadavg: 1.27 1.20 1.17 5/45 23834
/proc/meminfo: memFree=256436/1048576 swapFree=0/0
[pid=23811] ppid=23810 vsize=2564 CPUtime=0
/proc/23811/stat : 23811 (p2cudf-user-1.1) S 23810 23811 17511 34816 17511 4202496 375 0 0 0 0 0 0 0 25 0 1 0 46294019 2625536 270 1283457024 134512640 135304128 4294224192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23811/statm: 641 270 230 194 0 28 0
[pid=23812] ppid=23811 vsize=2572 CPUtime=0.02
/proc/23812/stat : 23812 (p2cudf) S 23811 23811 17511 34816 17511 4202496 389 3012 0 1 0 0 0 2 25 0 1 0 46294019 2633728 279 1283457024 134512640 135304128 4291329712 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23812/statm: 643 279 239 194 0 30 0
[pid=23825] ppid=23812 vsize=893692 CPUtime=1.46
/proc/23825/stat : 23825 (java) S 23812 23811 17511 34816 17511 4202496 21742 0 1 0 138 8 0 0 25 0 10 0 46294022 915140608 18629 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/23825/statm: 223423 18629 1724 10 0 220514 0
[pid=23825/tid=23826] ppid=23812 vsize=893692 CPUtime=0.79
/proc/23825/task/23826/stat : 23826 (java) R 23812 23811 17511 34816 17511 4202560 8399 0 1 0 74 5 0 0 25 0 10 0 46294023 915140608 18629 1283457024 134512640 134550932 4288043568 18446744073709551615 4095687668 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23825/tid=23827] ppid=23812 vsize=893692 CPUtime=0
/proc/23825/task/23827/stat : 23827 (java) S 23812 23811 17511 34816 17511 4202560 7 0 0 0 0 0 0 0 16 0 10 0 46294024 915140608 18629 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 0 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23828] ppid=23812 vsize=893692 CPUtime=0
/proc/23825/task/23828/stat : 23828 (java) S 23812 23811 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 25 0 10 0 46294025 915140608 18629 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23829] ppid=23812 vsize=893692 CPUtime=0
/proc/23825/task/23829/stat : 23829 (java) S 23812 23811 17511 34816 17511 4202560 4 0 0 0 0 0 0 0 25 0 10 0 46294025 915140608 18629 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23830] ppid=23812 vsize=893692 CPUtime=0
/proc/23825/task/23830/stat : 23830 (java) S 23812 23811 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46294027 915140608 18629 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23831] ppid=23812 vsize=893692 CPUtime=0.39
/proc/23825/task/23831/stat : 23831 (java) R 23812 23811 17511 34816 17511 4202560 5848 0 0 0 38 1 0 0 21 0 10 0 46294027 915140608 18629 1283457024 134512640 134550932 4288043568 18446744073709551615 4151933024 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23825/tid=23832] ppid=23812 vsize=893692 CPUtime=0.27
/proc/23825/task/23832/stat : 23832 (java) R 23812 23811 17511 34816 17511 4202560 6415 0 0 0 25 2 0 0 25 0 10 0 46294027 915140608 18629 1283457024 134512640 134550932 4288043568 18446744073709551615 4152907073 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23825/tid=23833] ppid=23812 vsize=893692 CPUtime=0
/proc/23825/task/23833/stat : 23833 (java) S 23812 23811 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46294027 915140608 18629 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23834] ppid=23812 vsize=893692 CPUtime=0
/proc/23825/task/23834/stat : 23834 (java) S 23812 23811 17511 34816 17511 4202560 2 0 0 0 0 0 0 0 15 0 10 0 46294027 915140608 18629 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.48
Current children cumulated vsize (KiB) 898828

[startup+3.10644 s]
/proc/loadavg: 1.27 1.20 1.17 2/45 23834
/proc/meminfo: memFree=157732/1048576 swapFree=0/0
[pid=23811] ppid=23810 vsize=2564 CPUtime=0
/proc/23811/stat : 23811 (p2cudf-user-1.1) S 23810 23811 17511 34816 17511 4202496 375 0 0 0 0 0 0 0 25 0 1 0 46294019 2625536 270 1283457024 134512640 135304128 4294224192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23811/statm: 641 270 230 194 0 28 0
[pid=23812] ppid=23811 vsize=2572 CPUtime=0.02
/proc/23812/stat : 23812 (p2cudf) S 23811 23811 17511 34816 17511 4202496 389 3012 0 1 0 0 0 2 25 0 1 0 46294019 2633728 279 1283457024 134512640 135304128 4291329712 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23812/statm: 643 279 239 194 0 30 0
[pid=23825] ppid=23812 vsize=891592 CPUtime=3.07
/proc/23825/stat : 23825 (java) S 23812 23811 17511 34816 17511 4202496 74506 0 1 0 279 28 0 0 25 0 10 0 46294022 912990208 70998 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/23825/statm: 222898 70998 1732 10 0 219989 0
[pid=23825/tid=23826] ppid=23812 vsize=891592 CPUtime=1.82
/proc/23825/task/23826/stat : 23826 (java) R 23812 23811 17511 34816 17511 4202560 50039 0 1 0 158 24 0 0 25 0 10 0 46294023 912990208 70998 1283457024 134512640 134550932 4288043568 18446744073709551615 4095810681 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23825/tid=23827] ppid=23812 vsize=891592 CPUtime=0.22
/proc/23825/task/23827/stat : 23827 (java) S 23812 23811 17511 34816 17511 4202560 10771 0 0 0 22 0 0 0 16 0 10 0 46294024 912990208 70998 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 0 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23828] ppid=23812 vsize=891592 CPUtime=0
/proc/23825/task/23828/stat : 23828 (java) S 23812 23811 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 18 0 10 0 46294025 912990208 70998 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23829] ppid=23812 vsize=891592 CPUtime=0
/proc/23825/task/23829/stat : 23829 (java) S 23812 23811 17511 34816 17511 4202560 6 0 0 0 0 0 0 0 18 0 10 0 46294025 912990208 70998 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23830] ppid=23812 vsize=891592 CPUtime=0
/proc/23825/task/23830/stat : 23830 (java) S 23812 23811 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46294027 912990208 70998 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23831] ppid=23812 vsize=891592 CPUtime=0.65
/proc/23825/task/23831/stat : 23831 (java) S 23812 23811 17511 34816 17511 4202560 6018 0 0 0 64 1 0 0 15 0 10 0 46294027 912990208 70998 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23832] ppid=23812 vsize=891592 CPUtime=0.35
/proc/23825/task/23832/stat : 23832 (java) S 23812 23811 17511 34816 17511 4202560 6603 0 0 0 33 2 0 0 25 0 10 0 46294027 912990208 70998 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23833] ppid=23812 vsize=891592 CPUtime=0
/proc/23825/task/23833/stat : 23833 (java) S 23812 23811 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46294027 912990208 70998 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23834] ppid=23812 vsize=891592 CPUtime=0
/proc/23825/task/23834/stat : 23834 (java) S 23812 23811 17511 34816 17511 4202560 2 0 0 0 0 0 0 0 15 0 10 0 46294027 912990208 70998 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.09
Current children cumulated vsize (KiB) 896728

[startup+6.30982 s]
/proc/loadavg: 1.33 1.21 1.17 2/46 23835
/proc/meminfo: memFree=25540/1048576 swapFree=0/0
[pid=23811] ppid=23810 vsize=2564 CPUtime=0
/proc/23811/stat : 23811 (p2cudf-user-1.1) S 23810 23811 17511 34816 17511 4202496 375 0 0 0 0 0 0 0 25 0 1 0 46294019 2625536 270 1283457024 134512640 135304128 4294224192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23811/statm: 641 270 230 194 0 28 0
[pid=23812] ppid=23811 vsize=2572 CPUtime=0.02
/proc/23812/stat : 23812 (p2cudf) S 23811 23811 17511 34816 17511 4202496 389 3012 0 1 0 0 0 2 25 0 1 0 46294019 2633728 279 1283457024 134512640 135304128 4291329712 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23812/statm: 643 279 239 194 0 30 0
[pid=23825] ppid=23812 vsize=892316 CPUtime=6.26
/proc/23825/stat : 23825 (java) S 23812 23811 17511 34816 17511 4202496 76492 0 1 0 594 32 0 0 25 0 11 0 46294022 913731584 71548 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/23825/statm: 223079 71548 1776 10 0 220170 0
[pid=23825/tid=23826] ppid=23812 vsize=892316 CPUtime=3.16
/proc/23825/task/23826/stat : 23826 (java) R 23812 23811 17511 34816 17511 4202560 50277 0 1 0 290 26 0 0 25 0 11 0 46294023 913731584 71548 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23825/tid=23827] ppid=23812 vsize=892316 CPUtime=0.22
/proc/23825/task/23827/stat : 23827 (java) S 23812 23811 17511 34816 17511 4202560 10771 0 0 0 22 0 0 0 15 0 11 0 46294024 913731584 71548 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 0 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23828] ppid=23812 vsize=892316 CPUtime=0
/proc/23825/task/23828/stat : 23828 (java) S 23812 23811 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 18 0 11 0 46294025 913731584 71548 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23829] ppid=23812 vsize=892316 CPUtime=0
/proc/23825/task/23829/stat : 23829 (java) S 23812 23811 17511 34816 17511 4202560 6 0 0 0 0 0 0 0 18 0 11 0 46294025 913731584 71548 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23830] ppid=23812 vsize=892316 CPUtime=0
/proc/23825/task/23830/stat : 23830 (java) S 23812 23811 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 11 0 46294027 913731584 71548 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23831] ppid=23812 vsize=892316 CPUtime=2.5
/proc/23825/task/23831/stat : 23831 (java) S 23812 23811 17511 34816 17511 4202560 7762 0 0 0 248 2 0 0 15 0 11 0 46294027 913731584 71548 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23832] ppid=23812 vsize=892316 CPUtime=0.35
/proc/23825/task/23832/stat : 23832 (java) S 23812 23811 17511 34816 17511 4202560 6603 0 0 0 33 2 0 0 25 0 11 0 46294027 913731584 71548 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23833] ppid=23812 vsize=892316 CPUtime=0
/proc/23825/task/23833/stat : 23833 (java) S 23812 23811 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 11 0 46294027 913731584 71548 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23834] ppid=23812 vsize=892316 CPUtime=0
/proc/23825/task/23834/stat : 23834 (java) R 23812 23811 17511 34816 17511 4202560 2 0 0 0 0 0 0 0 15 0 11 0 46294027 913731584 71548 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23825/tid=23835] ppid=23812 vsize=892316 CPUtime=0
/proc/23825/task/23835/stat : 23835 (java) S 23812 23811 17511 34816 17511 4202560 4 0 0 0 0 0 0 0 25 0 11 0 46294476 913731584 71548 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.28
Current children cumulated vsize (KiB) 897452

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

[startup+6.70734 s]
/proc/loadavg: 1.33 1.21 1.17 2/46 23835
/proc/meminfo: memFree=25424/1048576 swapFree=0/0
[pid=23811] ppid=23810 vsize=2564 CPUtime=0
/proc/23811/stat : 23811 (p2cudf-user-1.1) S 23810 23811 17511 34816 17511 4202496 375 0 0 0 0 0 0 0 25 0 1 0 46294019 2625536 270 1283457024 134512640 135304128 4294224192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23811/statm: 641 270 230 194 0 28 0
[pid=23812] ppid=23811 vsize=2572 CPUtime=0.02
/proc/23812/stat : 23812 (p2cudf) S 23811 23811 17511 34816 17511 4202496 389 3012 0 1 0 0 0 2 25 0 1 0 46294019 2633728 279 1283457024 134512640 135304128 4291329712 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23812/statm: 643 279 239 194 0 30 0
[pid=23825] ppid=23812 vsize=889264 CPUtime=6.66
/proc/23825/stat : 23825 (java) S 23812 23811 17511 34816 17511 4202496 76498 0 1 0 634 32 0 0 25 0 11 0 46294022 910606336 70844 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/23825/statm: 222316 70844 1777 10 0 219407 0
[pid=23825/tid=23826] ppid=23812 vsize=889264 CPUtime=3.5
/proc/23825/task/23826/stat : 23826 (java) R 23812 23811 17511 34816 17511 4202560 50278 0 1 0 324 26 0 0 25 0 11 0 46294023 910606336 70844 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23825/tid=23827] ppid=23812 vsize=889264 CPUtime=0.22
/proc/23825/task/23827/stat : 23827 (java) S 23812 23811 17511 34816 17511 4202560 10771 0 0 0 22 0 0 0 15 0 11 0 46294024 910606336 70844 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 0 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23828] ppid=23812 vsize=889264 CPUtime=0
/proc/23825/task/23828/stat : 23828 (java) S 23812 23811 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 18 0 11 0 46294025 910606336 70844 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23829] ppid=23812 vsize=889264 CPUtime=0
/proc/23825/task/23829/stat : 23829 (java) S 23812 23811 17511 34816 17511 4202560 6 0 0 0 0 0 0 0 18 0 11 0 46294025 910606336 70844 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23830] ppid=23812 vsize=889264 CPUtime=0
/proc/23825/task/23830/stat : 23830 (java) S 23812 23811 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 11 0 46294027 910606336 70844 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23831] ppid=23812 vsize=889264 CPUtime=2.56
/proc/23825/task/23831/stat : 23831 (java) R 23812 23811 17511 34816 17511 4202560 7767 0 0 0 254 2 0 0 16 0 11 0 46294027 910606336 70844 1283457024 134512640 134550932 4288043568 18446744073709551615 4148308871 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23825/tid=23832] ppid=23812 vsize=889264 CPUtime=0.35
/proc/23825/task/23832/stat : 23832 (java) S 23812 23811 17511 34816 17511 4202560 6603 0 0 0 33 2 0 0 25 0 11 0 46294027 910606336 70844 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23833] ppid=23812 vsize=889264 CPUtime=0
/proc/23825/task/23833/stat : 23833 (java) S 23812 23811 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 11 0 46294027 910606336 70844 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23834] ppid=23812 vsize=889264 CPUtime=0
/proc/23825/task/23834/stat : 23834 (java) S 23812 23811 17511 34816 17511 4202560 2 0 0 0 0 0 0 0 15 0 11 0 46294027 910606336 70844 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23835] ppid=23812 vsize=889264 CPUtime=0
/proc/23825/task/23835/stat : 23835 (java) S 23812 23811 17511 34816 17511 4202560 4 0 0 0 0 0 0 0 25 0 11 0 46294476 910606336 70844 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.68
Current children cumulated vsize (KiB) 894400

[startup+7.10584 s]
/proc/loadavg: 1.33 1.21 1.17 2/46 23835
/proc/meminfo: memFree=25424/1048576 swapFree=0/0
[pid=23811] ppid=23810 vsize=2564 CPUtime=0
/proc/23811/stat : 23811 (p2cudf-user-1.1) S 23810 23811 17511 34816 17511 4202496 375 0 0 0 0 0 0 0 25 0 1 0 46294019 2625536 270 1283457024 134512640 135304128 4294224192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23811/statm: 641 270 230 194 0 28 0
[pid=23812] ppid=23811 vsize=2572 CPUtime=0.02
/proc/23812/stat : 23812 (p2cudf) S 23811 23811 17511 34816 17511 4202496 389 3012 0 1 0 0 0 2 25 0 1 0 46294019 2633728 279 1283457024 134512640 135304128 4291329712 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23812/statm: 643 279 239 194 0 30 0
[pid=23825] ppid=23812 vsize=889588 CPUtime=6.66
/proc/23825/stat : 23825 (java) S 23812 23811 17511 34816 17511 4202496 76512 0 1 0 634 32 0 0 25 0 11 0 46294022 910938112 70858 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/23825/statm: 222397 70858 1778 10 0 219488 0
[pid=23825/tid=23826] ppid=23812 vsize=889588 CPUtime=3.5
/proc/23825/task/23826/stat : 23826 (java) S 23812 23811 17511 34816 17511 4202560 50285 0 1 0 324 26 0 0 25 0 11 0 46294023 910938112 70858 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23827] ppid=23812 vsize=889588 CPUtime=0.22
/proc/23825/task/23827/stat : 23827 (java) S 23812 23811 17511 34816 17511 4202560 10771 0 0 0 22 0 0 0 16 0 11 0 46294024 910938112 70858 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 0 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23828] ppid=23812 vsize=889588 CPUtime=0
/proc/23825/task/23828/stat : 23828 (java) S 23812 23811 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 18 0 11 0 46294025 910938112 70858 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23829] ppid=23812 vsize=889588 CPUtime=0
/proc/23825/task/23829/stat : 23829 (java) S 23812 23811 17511 34816 17511 4202560 6 0 0 0 0 0 0 0 18 0 11 0 46294025 910938112 70858 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23830] ppid=23812 vsize=889588 CPUtime=0
/proc/23825/task/23830/stat : 23830 (java) S 23812 23811 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 11 0 46294027 910938112 70858 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23831] ppid=23812 vsize=889588 CPUtime=2.56
/proc/23825/task/23831/stat : 23831 (java) S 23812 23811 17511 34816 17511 4202560 7769 0 0 0 254 2 0 0 16 0 11 0 46294027 910938112 70858 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23832] ppid=23812 vsize=889588 CPUtime=0.35
/proc/23825/task/23832/stat : 23832 (java) S 23812 23811 17511 34816 17511 4202560 6603 0 0 0 33 2 0 0 25 0 11 0 46294027 910938112 70858 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23833] ppid=23812 vsize=889588 CPUtime=0
/proc/23825/task/23833/stat : 23833 (java) S 23812 23811 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 11 0 46294027 910938112 70858 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23834] ppid=23812 vsize=889588 CPUtime=0
/proc/23825/task/23834/stat : 23834 (java) S 23812 23811 17511 34816 17511 4202560 2 0 0 0 0 0 0 0 15 0 11 0 46294027 910938112 70858 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.68
Current children cumulated vsize (KiB) 894724

[startup+7.20582 s]
/proc/loadavg: 1.33 1.21 1.17 2/46 23835
/proc/meminfo: memFree=25424/1048576 swapFree=0/0
[pid=23811] ppid=23810 vsize=2564 CPUtime=0
/proc/23811/stat : 23811 (p2cudf-user-1.1) S 23810 23811 17511 34816 17511 4202496 375 0 0 0 0 0 0 0 25 0 1 0 46294019 2625536 270 1283457024 134512640 135304128 4294224192 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23811/statm: 641 270 230 194 0 28 0
[pid=23812] ppid=23811 vsize=2572 CPUtime=0.02
/proc/23812/stat : 23812 (p2cudf) S 23811 23811 17511 34816 17511 4202496 389 3012 0 1 0 0 0 2 25 0 1 0 46294019 2633728 279 1283457024 134512640 135304128 4291329712 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23812/statm: 643 279 239 194 0 30 0
[pid=23825] ppid=23812 vsize=889588 CPUtime=6.66
/proc/23825/stat : 23825 (java) S 23812 23811 17511 34816 17511 4202496 76512 0 1 0 634 32 0 0 25 0 11 0 46294022 910938112 70858 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/23825/statm: 222397 70858 1778 10 0 219488 0
[pid=23825/tid=23826] ppid=23812 vsize=889588 CPUtime=3.5
/proc/23825/task/23826/stat : 23826 (java) S 23812 23811 17511 34816 17511 4202560 50285 0 1 0 324 26 0 0 25 0 11 0 46294023 910938112 70858 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23827] ppid=23812 vsize=889588 CPUtime=0.22
/proc/23825/task/23827/stat : 23827 (java) S 23812 23811 17511 34816 17511 4202560 10771 0 0 0 22 0 0 0 16 0 11 0 46294024 910938112 70858 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 0 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23828] ppid=23812 vsize=889588 CPUtime=0
/proc/23825/task/23828/stat : 23828 (java) S 23812 23811 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 18 0 11 0 46294025 910938112 70858 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23829] ppid=23812 vsize=889588 CPUtime=0
/proc/23825/task/23829/stat : 23829 (java) S 23812 23811 17511 34816 17511 4202560 6 0 0 0 0 0 0 0 18 0 11 0 46294025 910938112 70858 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23830] ppid=23812 vsize=889588 CPUtime=0
/proc/23825/task/23830/stat : 23830 (java) S 23812 23811 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 11 0 46294027 910938112 70858 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23831] ppid=23812 vsize=889588 CPUtime=2.56
/proc/23825/task/23831/stat : 23831 (java) S 23812 23811 17511 34816 17511 4202560 7769 0 0 0 254 2 0 0 16 0 11 0 46294027 910938112 70858 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23832] ppid=23812 vsize=889588 CPUtime=0.35
/proc/23825/task/23832/stat : 23832 (java) S 23812 23811 17511 34816 17511 4202560 6603 0 0 0 33 2 0 0 25 0 11 0 46294027 910938112 70858 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23833] ppid=23812 vsize=889588 CPUtime=0
/proc/23825/task/23833/stat : 23833 (java) S 23812 23811 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 11 0 46294027 910938112 70858 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
[pid=23825/tid=23834] ppid=23812 vsize=889588 CPUtime=0
/proc/23825/task/23834/stat : 23834 (java) S 23812 23811 17511 34816 17511 4202560 2 0 0 0 0 0 0 0 15 0 11 0 46294027 910938112 70858 1283457024 134512640 134550932 4288043568 18446744073709551615 4294960130 0 4 0 16800975 18446612133395358784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.68
Current children cumulated vsize (KiB) 894724

Child status: 0
Real time (s): 7.30386
CPU time (s): 6.78442
CPU user time (s): 6.4084
CPU system time (s): 0.376023
CPU usage (%): 92.8882
Max. virtual memory (cumulated for all children) (KiB): 899672

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 6.4084
system time used= 0.376023
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 80313
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= 757
involuntary context switches= 739

runsolver used 0 second user time and 0 second system time

The end