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/rand796.cudf.user-upgrades.log.runsolver ./p2cudf-user-1.13 /home/misc2010/data/2011/user-upgrades/rand796.cudf /home/misc2010/tmp/201108291842/p2cudf-user-1.13/rand796.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.29 1.22 1.19 5/35 25617
/proc/meminfo: memFree=305800/1048576 swapFree=0/0
[pid=25616] ppid=25615 vsize=2568 CPUtime=0
/proc/25616/stat : 25616 (p2cudf-user-1.1) R 25615 25616 17511 34816 17511 4202496 358 0 0 0 0 0 0 0 25 0 1 0 46359738 2629632 271 1283457024 134512640 135304128 4290078032 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/25616/statm: 642 271 230 194 0 29 0
[pid=25617] ppid=25616 vsize=2568 CPUtime=0
/proc/25617/stat : 25617 (p2cudf-user-1.1) R 25616 25616 17511 34816 17511 4202560 0 0 0 0 0 0 0 0 25 0 1 0 46359738 2629632 41 1283457024 134512640 135304128 4290078032 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/25617/statm: 642 41 0 194 0 29 0

[startup+0.195566 s]
/proc/loadavg: 1.29 1.22 1.19 5/35 25617
/proc/meminfo: memFree=305800/1048576 swapFree=0/0
[pid=25616] ppid=25615 vsize=2568 CPUtime=0
/proc/25616/stat : 25616 (p2cudf-user-1.1) S 25615 25616 17511 34816 17511 4202496 377 0 0 0 0 0 0 0 25 0 1 0 46359738 2629632 271 1283457024 134512640 135304128 4290078032 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25616/statm: 642 271 230 194 0 29 0
[pid=25617] ppid=25616 vsize=2572 CPUtime=0.03
/proc/25617/stat : 25617 (p2cudf) S 25616 25616 17511 34816 17511 4202496 392 3014 0 1 0 1 2 0 25 0 1 0 46359738 2633728 280 1283457024 134512640 135304128 4287425264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25617/statm: 643 280 239 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5140

[startup+0.205558 s]
/proc/loadavg: 1.29 1.22 1.19 5/35 25617
/proc/meminfo: memFree=305800/1048576 swapFree=0/0
[pid=25616] ppid=25615 vsize=2568 CPUtime=0
/proc/25616/stat : 25616 (p2cudf-user-1.1) S 25615 25616 17511 34816 17511 4202496 377 0 0 0 0 0 0 0 25 0 1 0 46359738 2629632 271 1283457024 134512640 135304128 4290078032 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25616/statm: 642 271 230 194 0 29 0
[pid=25617] ppid=25616 vsize=2572 CPUtime=0.03
/proc/25617/stat : 25617 (p2cudf) S 25616 25616 17511 34816 17511 4202496 392 3014 0 1 0 1 2 0 25 0 1 0 46359738 2633728 280 1283457024 134512640 135304128 4287425264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25617/statm: 643 280 239 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5140

[startup+0.305573 s]
/proc/loadavg: 1.29 1.22 1.19 5/35 25617
/proc/meminfo: memFree=305800/1048576 swapFree=0/0
[pid=25616] ppid=25615 vsize=2568 CPUtime=0
/proc/25616/stat : 25616 (p2cudf-user-1.1) S 25615 25616 17511 34816 17511 4202496 377 0 0 0 0 0 0 0 25 0 1 0 46359738 2629632 271 1283457024 134512640 135304128 4290078032 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25616/statm: 642 271 230 194 0 29 0
[pid=25617] ppid=25616 vsize=2572 CPUtime=0.03
/proc/25617/stat : 25617 (p2cudf) S 25616 25616 17511 34816 17511 4202496 392 3014 0 1 0 1 2 0 25 0 1 0 46359738 2633728 280 1283457024 134512640 135304128 4287425264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25617/statm: 643 280 239 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5140

[startup+0.705631 s]
/proc/loadavg: 1.29 1.22 1.19 5/35 25617
/proc/meminfo: memFree=305800/1048576 swapFree=0/0
[pid=25616] ppid=25615 vsize=2568 CPUtime=0
/proc/25616/stat : 25616 (p2cudf-user-1.1) S 25615 25616 17511 34816 17511 4202496 377 0 0 0 0 0 0 0 25 0 1 0 46359738 2629632 271 1283457024 134512640 135304128 4290078032 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25616/statm: 642 271 230 194 0 29 0
[pid=25617] ppid=25616 vsize=2572 CPUtime=0.03
/proc/25617/stat : 25617 (p2cudf) S 25616 25616 17511 34816 17511 4202496 392 3014 0 1 0 1 2 0 25 0 1 0 46359738 2633728 280 1283457024 134512640 135304128 4287425264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25617/statm: 643 280 239 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5140

[startup+1.50576 s]
/proc/loadavg: 1.29 1.22 1.19 5/46 25639
/proc/meminfo: memFree=256588/1048576 swapFree=0/0
[pid=25616] ppid=25615 vsize=2568 CPUtime=0
/proc/25616/stat : 25616 (p2cudf-user-1.1) S 25615 25616 17511 34816 17511 4202496 377 0 0 0 0 0 0 0 25 0 1 0 46359738 2629632 271 1283457024 134512640 135304128 4290078032 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25616/statm: 642 271 230 194 0 29 0
[pid=25617] ppid=25616 vsize=2572 CPUtime=0.03
/proc/25617/stat : 25617 (p2cudf) S 25616 25616 17511 34816 17511 4202496 392 3014 0 1 0 1 2 0 25 0 1 0 46359738 2633728 280 1283457024 134512640 135304128 4287425264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25617/statm: 643 280 239 194 0 30 0
[pid=25630] ppid=25617 vsize=893752 CPUtime=1.46
/proc/25630/stat : 25630 (java) S 25617 25616 17511 34816 17511 4202496 21813 0 1 0 140 6 0 0 25 0 10 0 46359742 915202048 18700 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25630/statm: 223438 18700 1724 10 0 220529 0
[pid=25630/tid=25631] ppid=25617 vsize=893752 CPUtime=0.79
/proc/25630/task/25631/stat : 25631 (java) R 25617 25616 17511 34816 17511 4202560 8469 0 1 0 76 3 0 0 25 0 10 0 46359742 915202048 18700 1283457024 134512640 134550932 4291698080 18446744073709551615 4095119847 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25630/tid=25632] ppid=25617 vsize=893752 CPUtime=0
/proc/25630/task/25632/stat : 25632 (java) S 25617 25616 17511 34816 17511 4202560 7 0 0 0 0 0 0 0 16 0 10 0 46359744 915202048 18700 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 0 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25633] ppid=25617 vsize=893752 CPUtime=0
/proc/25630/task/25633/stat : 25633 (java) S 25617 25616 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 25 0 10 0 46359744 915202048 18700 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25634] ppid=25617 vsize=893752 CPUtime=0
/proc/25630/task/25634/stat : 25634 (java) S 25617 25616 17511 34816 17511 4202560 4 0 0 0 0 0 0 0 25 0 10 0 46359744 915202048 18700 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25635] ppid=25617 vsize=893752 CPUtime=0
/proc/25630/task/25635/stat : 25635 (java) S 25617 25616 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46359747 915202048 18700 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25636] ppid=25617 vsize=893752 CPUtime=0.38
/proc/25630/task/25636/stat : 25636 (java) R 25617 25616 17511 34816 17511 4202560 5842 0 0 0 38 0 0 0 21 0 10 0 46359747 915202048 18700 1283457024 134512640 134550932 4291698080 18446744073709551615 4151532003 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25630/tid=25637] ppid=25617 vsize=893752 CPUtime=0.28
/proc/25630/task/25637/stat : 25637 (java) R 25617 25616 17511 34816 17511 4202560 6424 0 0 0 26 2 0 0 25 0 10 0 46359747 915202048 18700 1283457024 134512640 134550932 4291698080 18446744073709551615 4152518627 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25630/tid=25638] ppid=25617 vsize=893752 CPUtime=0
/proc/25630/task/25638/stat : 25638 (java) S 25617 25616 17511 34816 17511 4202560 0 0 0 0 0 0 0 0 25 0 10 0 46359747 915202048 18700 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25639] ppid=25617 vsize=893752 CPUtime=0
/proc/25630/task/25639/stat : 25639 (java) S 25617 25616 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 10 0 46359747 915202048 18700 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 898892

[startup+3.10604 s]
/proc/loadavg: 1.43 1.25 1.20 2/46 25639
/proc/meminfo: memFree=157016/1048576 swapFree=0/0
[pid=25616] ppid=25615 vsize=2568 CPUtime=0
/proc/25616/stat : 25616 (p2cudf-user-1.1) S 25615 25616 17511 34816 17511 4202496 377 0 0 0 0 0 0 0 25 0 1 0 46359738 2629632 271 1283457024 134512640 135304128 4290078032 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25616/statm: 642 271 230 194 0 29 0
[pid=25617] ppid=25616 vsize=2572 CPUtime=0.03
/proc/25617/stat : 25617 (p2cudf) S 25616 25616 17511 34816 17511 4202496 392 3014 0 1 0 1 2 0 25 0 1 0 46359738 2633728 280 1283457024 134512640 135304128 4287425264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25617/statm: 643 280 239 194 0 30 0
[pid=25630] ppid=25617 vsize=891652 CPUtime=3.06
/proc/25630/stat : 25630 (java) S 25617 25616 17511 34816 17511 4202496 74508 0 1 0 278 28 0 0 25 0 10 0 46359742 913051648 71000 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25630/statm: 222913 71000 1732 10 0 220004 0
[pid=25630/tid=25631] ppid=25617 vsize=891652 CPUtime=1.83
/proc/25630/task/25631/stat : 25631 (java) R 25617 25616 17511 34816 17511 4202560 50039 0 1 0 161 22 0 0 25 0 10 0 46359742 913051648 71000 1283457024 134512640 134550932 4291698080 18446744073709551615 4095383652 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25630/tid=25632] ppid=25617 vsize=891652 CPUtime=0.22
/proc/25630/task/25632/stat : 25632 (java) S 25617 25616 17511 34816 17511 4202560 10772 0 0 0 20 2 0 0 16 0 10 0 46359744 913051648 71000 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 0 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25633] ppid=25617 vsize=891652 CPUtime=0
/proc/25630/task/25633/stat : 25633 (java) S 25617 25616 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 18 0 10 0 46359744 913051648 71000 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25634] ppid=25617 vsize=891652 CPUtime=0
/proc/25630/task/25634/stat : 25634 (java) S 25617 25616 17511 34816 17511 4202560 6 0 0 0 0 0 0 0 18 0 10 0 46359744 913051648 71000 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25635] ppid=25617 vsize=891652 CPUtime=0
/proc/25630/task/25635/stat : 25635 (java) S 25617 25616 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46359747 913051648 71000 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25636] ppid=25617 vsize=891652 CPUtime=0.63
/proc/25630/task/25636/stat : 25636 (java) S 25617 25616 17511 34816 17511 4202560 6012 0 0 0 62 1 0 0 15 0 10 0 46359747 913051648 71000 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25637] ppid=25617 vsize=891652 CPUtime=0.36
/proc/25630/task/25637/stat : 25637 (java) S 25617 25616 17511 34816 17511 4202560 6612 0 0 0 34 2 0 0 25 0 10 0 46359747 913051648 71000 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25638] ppid=25617 vsize=891652 CPUtime=0
/proc/25630/task/25638/stat : 25638 (java) S 25617 25616 17511 34816 17511 4202560 0 0 0 0 0 0 0 0 25 0 10 0 46359747 913051648 71000 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25639] ppid=25617 vsize=891652 CPUtime=0
/proc/25630/task/25639/stat : 25639 (java) S 25617 25616 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 10 0 46359747 913051648 71000 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.09
Current children cumulated vsize (KiB) 896792

[startup+6.30704 s]
/proc/loadavg: 1.43 1.25 1.20 2/47 25640
/proc/meminfo: memFree=25700/1048576 swapFree=0/0
[pid=25616] ppid=25615 vsize=2568 CPUtime=0
/proc/25616/stat : 25616 (p2cudf-user-1.1) S 25615 25616 17511 34816 17511 4202496 377 0 0 0 0 0 0 0 25 0 1 0 46359738 2629632 271 1283457024 134512640 135304128 4290078032 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25616/statm: 642 271 230 194 0 29 0
[pid=25617] ppid=25616 vsize=2572 CPUtime=0.03
/proc/25617/stat : 25617 (p2cudf) S 25616 25616 17511 34816 17511 4202496 392 3014 0 1 0 1 2 0 25 0 1 0 46359738 2633728 280 1283457024 134512640 135304128 4287425264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25617/statm: 643 280 239 194 0 30 0
[pid=25630] ppid=25617 vsize=892376 CPUtime=6.26
/proc/25630/stat : 25630 (java) S 25617 25616 17511 34816 17511 4202496 76493 0 1 0 596 30 0 0 25 0 11 0 46359742 913793024 71549 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25630/statm: 223094 71549 1777 10 0 220185 0
[pid=25630/tid=25631] ppid=25617 vsize=892376 CPUtime=3.24
/proc/25630/task/25631/stat : 25631 (java) R 25617 25616 17511 34816 17511 4202560 50277 0 1 0 301 23 0 0 25 0 11 0 46359742 913793024 71549 1283457024 134512640 134550932 4291698080 18446744073709551615 4096123116 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25630/tid=25632] ppid=25617 vsize=892376 CPUtime=0.22
/proc/25630/task/25632/stat : 25632 (java) S 25617 25616 17511 34816 17511 4202560 10772 0 0 0 20 2 0 0 15 0 11 0 46359744 913793024 71549 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 0 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25633] ppid=25617 vsize=892376 CPUtime=0
/proc/25630/task/25633/stat : 25633 (java) S 25617 25616 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 18 0 11 0 46359744 913793024 71549 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25634] ppid=25617 vsize=892376 CPUtime=0
/proc/25630/task/25634/stat : 25634 (java) S 25617 25616 17511 34816 17511 4202560 6 0 0 0 0 0 0 0 18 0 11 0 46359744 913793024 71549 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25635] ppid=25617 vsize=892376 CPUtime=0
/proc/25630/task/25635/stat : 25635 (java) S 25617 25616 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 11 0 46359747 913793024 71549 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25636] ppid=25617 vsize=892376 CPUtime=2.42
/proc/25630/task/25636/stat : 25636 (java) S 25617 25616 17511 34816 17511 4202560 7755 0 0 0 240 2 0 0 15 0 11 0 46359747 913793024 71549 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25637] ppid=25617 vsize=892376 CPUtime=0.36
/proc/25630/task/25637/stat : 25637 (java) S 25617 25616 17511 34816 17511 4202560 6612 0 0 0 34 2 0 0 25 0 11 0 46359747 913793024 71549 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25638] ppid=25617 vsize=892376 CPUtime=0
/proc/25630/task/25638/stat : 25638 (java) S 25617 25616 17511 34816 17511 4202560 0 0 0 0 0 0 0 0 25 0 11 0 46359747 913793024 71549 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25639] ppid=25617 vsize=892376 CPUtime=0
/proc/25630/task/25639/stat : 25639 (java) S 25617 25616 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 11 0 46359747 913793024 71549 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25640] ppid=25617 vsize=892376 CPUtime=0
/proc/25630/task/25640/stat : 25640 (java) S 25617 25616 17511 34816 17511 4202560 4 0 0 0 0 0 0 0 25 0 11 0 46360194 913793024 71549 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.29
Current children cumulated vsize (KiB) 897516

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

[startup+6.40706 s]
/proc/loadavg: 1.43 1.25 1.20 2/47 25640
/proc/meminfo: memFree=25700/1048576 swapFree=0/0
[pid=25616] ppid=25615 vsize=2568 CPUtime=0
/proc/25616/stat : 25616 (p2cudf-user-1.1) S 25615 25616 17511 34816 17511 4202496 377 0 0 0 0 0 0 0 25 0 1 0 46359738 2629632 271 1283457024 134512640 135304128 4290078032 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25616/statm: 642 271 230 194 0 29 0
[pid=25617] ppid=25616 vsize=2572 CPUtime=0.03
/proc/25617/stat : 25617 (p2cudf) S 25616 25616 17511 34816 17511 4202496 392 3014 0 1 0 1 2 0 25 0 1 0 46359738 2633728 280 1283457024 134512640 135304128 4287425264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25617/statm: 643 280 239 194 0 30 0
[pid=25630] ppid=25617 vsize=892376 CPUtime=6.36
/proc/25630/stat : 25630 (java) S 25617 25616 17511 34816 17511 4202496 76495 0 1 0 606 30 0 0 25 0 11 0 46359742 913793024 71551 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25630/statm: 223094 71551 1777 10 0 220185 0
[pid=25630/tid=25631] ppid=25617 vsize=892376 CPUtime=3.31
/proc/25630/task/25631/stat : 25631 (java) R 25617 25616 17511 34816 17511 4202560 50277 0 1 0 308 23 0 0 25 0 11 0 46359742 913793024 71551 1283457024 134512640 134550932 4291698080 18446744073709551615 4096116611 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=25630/tid=25632] ppid=25617 vsize=892376 CPUtime=0.22
/proc/25630/task/25632/stat : 25632 (java) S 25617 25616 17511 34816 17511 4202560 10772 0 0 0 20 2 0 0 15 0 11 0 46359744 913793024 71551 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 0 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25633] ppid=25617 vsize=892376 CPUtime=0
/proc/25630/task/25633/stat : 25633 (java) S 25617 25616 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 18 0 11 0 46359744 913793024 71551 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25634] ppid=25617 vsize=892376 CPUtime=0
/proc/25630/task/25634/stat : 25634 (java) S 25617 25616 17511 34816 17511 4202560 6 0 0 0 0 0 0 0 18 0 11 0 46359744 913793024 71551 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25635] ppid=25617 vsize=892376 CPUtime=0
/proc/25630/task/25635/stat : 25635 (java) S 25617 25616 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 11 0 46359747 913793024 71551 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25636] ppid=25617 vsize=892376 CPUtime=2.45
/proc/25630/task/25636/stat : 25636 (java) S 25617 25616 17511 34816 17511 4202560 7757 0 0 0 243 2 0 0 15 0 11 0 46359747 913793024 71551 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25637] ppid=25617 vsize=892376 CPUtime=0.36
/proc/25630/task/25637/stat : 25637 (java) S 25617 25616 17511 34816 17511 4202560 6612 0 0 0 34 2 0 0 25 0 11 0 46359747 913793024 71551 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25638] ppid=25617 vsize=892376 CPUtime=0
/proc/25630/task/25638/stat : 25638 (java) S 25617 25616 17511 34816 17511 4202560 0 0 0 0 0 0 0 0 25 0 11 0 46359747 913793024 71551 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25639] ppid=25617 vsize=892376 CPUtime=0
/proc/25630/task/25639/stat : 25639 (java) S 25617 25616 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 11 0 46359747 913793024 71551 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25640] ppid=25617 vsize=892376 CPUtime=0
/proc/25630/task/25640/stat : 25640 (java) S 25617 25616 17511 34816 17511 4202560 4 0 0 0 0 0 0 0 25 0 11 0 46360194 913793024 71551 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.39
Current children cumulated vsize (KiB) 897516

[startup+6.80598 s]
/proc/loadavg: 1.39 1.25 1.20 2/47 25640
/proc/meminfo: memFree=25700/1048576 swapFree=0/0
[pid=25616] ppid=25615 vsize=2568 CPUtime=0
/proc/25616/stat : 25616 (p2cudf-user-1.1) S 25615 25616 17511 34816 17511 4202496 377 0 0 0 0 0 0 0 25 0 1 0 46359738 2629632 271 1283457024 134512640 135304128 4290078032 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25616/statm: 642 271 230 194 0 29 0
[pid=25617] ppid=25616 vsize=2572 CPUtime=0.03
/proc/25617/stat : 25617 (p2cudf) S 25616 25616 17511 34816 17511 4202496 392 3014 0 1 0 1 2 0 25 0 1 0 46359738 2633728 280 1283457024 134512640 135304128 4287425264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25617/statm: 643 280 239 194 0 30 0
[pid=25630] ppid=25617 vsize=892700 CPUtime=6.67
/proc/25630/stat : 25630 (java) S 25617 25616 17511 34816 17511 4202496 76513 0 1 0 637 30 0 0 25 0 11 0 46359742 914124800 71569 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25630/statm: 223175 71569 1779 10 0 220266 0
[pid=25630/tid=25631] ppid=25617 vsize=892700 CPUtime=3.58
/proc/25630/task/25631/stat : 25631 (java) S 25617 25616 17511 34816 17511 4202560 50285 0 1 0 335 23 0 0 25 0 11 0 46359742 914124800 71569 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25632] ppid=25617 vsize=892700 CPUtime=0.22
/proc/25630/task/25632/stat : 25632 (java) S 25617 25616 17511 34816 17511 4202560 10772 0 0 0 20 2 0 0 16 0 11 0 46359744 914124800 71569 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 0 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25633] ppid=25617 vsize=892700 CPUtime=0
/proc/25630/task/25633/stat : 25633 (java) S 25617 25616 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 18 0 11 0 46359744 914124800 71569 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25634] ppid=25617 vsize=892700 CPUtime=0
/proc/25630/task/25634/stat : 25634 (java) S 25617 25616 17511 34816 17511 4202560 6 0 0 0 0 0 0 0 18 0 11 0 46359744 914124800 71569 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25635] ppid=25617 vsize=892700 CPUtime=0
/proc/25630/task/25635/stat : 25635 (java) S 25617 25616 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 11 0 46359747 914124800 71569 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25636] ppid=25617 vsize=892700 CPUtime=2.49
/proc/25630/task/25636/stat : 25636 (java) S 25617 25616 17511 34816 17511 4202560 7762 0 0 0 247 2 0 0 16 0 11 0 46359747 914124800 71569 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25637] ppid=25617 vsize=892700 CPUtime=0.36
/proc/25630/task/25637/stat : 25637 (java) S 25617 25616 17511 34816 17511 4202560 6612 0 0 0 34 2 0 0 25 0 11 0 46359747 914124800 71569 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25638] ppid=25617 vsize=892700 CPUtime=0
/proc/25630/task/25638/stat : 25638 (java) S 25617 25616 17511 34816 17511 4202560 0 0 0 0 0 0 0 0 25 0 11 0 46359747 914124800 71569 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25639] ppid=25617 vsize=892700 CPUtime=0
/proc/25630/task/25639/stat : 25639 (java) S 25617 25616 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 11 0 46359747 914124800 71569 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.7
Current children cumulated vsize (KiB) 897840

[startup+7.20602 s]
/proc/loadavg: 1.39 1.25 1.20 2/47 25640
/proc/meminfo: memFree=25700/1048576 swapFree=0/0
[pid=25616] ppid=25615 vsize=2568 CPUtime=0
/proc/25616/stat : 25616 (p2cudf-user-1.1) S 25615 25616 17511 34816 17511 4202496 377 0 0 0 0 0 0 0 25 0 1 0 46359738 2629632 271 1283457024 134512640 135304128 4290078032 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25616/statm: 642 271 230 194 0 29 0
[pid=25617] ppid=25616 vsize=2572 CPUtime=0.03
/proc/25617/stat : 25617 (p2cudf) S 25616 25616 17511 34816 17511 4202496 392 3014 0 1 0 1 2 0 25 0 1 0 46359738 2633728 280 1283457024 134512640 135304128 4287425264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25617/statm: 643 280 239 194 0 30 0
[pid=25630] ppid=25617 vsize=892700 CPUtime=6.67
/proc/25630/stat : 25630 (java) S 25617 25616 17511 34816 17511 4202496 76513 0 1 0 637 30 0 0 25 0 11 0 46359742 914124800 71569 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25630/statm: 223175 71569 1779 10 0 220266 0
[pid=25630/tid=25631] ppid=25617 vsize=892700 CPUtime=3.58
/proc/25630/task/25631/stat : 25631 (java) S 25617 25616 17511 34816 17511 4202560 50285 0 1 0 335 23 0 0 25 0 11 0 46359742 914124800 71569 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25632] ppid=25617 vsize=892700 CPUtime=0.22
/proc/25630/task/25632/stat : 25632 (java) S 25617 25616 17511 34816 17511 4202560 10772 0 0 0 20 2 0 0 16 0 11 0 46359744 914124800 71569 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 0 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25633] ppid=25617 vsize=892700 CPUtime=0
/proc/25630/task/25633/stat : 25633 (java) S 25617 25616 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 18 0 11 0 46359744 914124800 71569 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25634] ppid=25617 vsize=892700 CPUtime=0
/proc/25630/task/25634/stat : 25634 (java) S 25617 25616 17511 34816 17511 4202560 6 0 0 0 0 0 0 0 18 0 11 0 46359744 914124800 71569 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25635] ppid=25617 vsize=892700 CPUtime=0
/proc/25630/task/25635/stat : 25635 (java) S 25617 25616 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 11 0 46359747 914124800 71569 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25636] ppid=25617 vsize=892700 CPUtime=2.49
/proc/25630/task/25636/stat : 25636 (java) S 25617 25616 17511 34816 17511 4202560 7762 0 0 0 247 2 0 0 16 0 11 0 46359747 914124800 71569 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25637] ppid=25617 vsize=892700 CPUtime=0.36
/proc/25630/task/25637/stat : 25637 (java) S 25617 25616 17511 34816 17511 4202560 6612 0 0 0 34 2 0 0 25 0 11 0 46359747 914124800 71569 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25638] ppid=25617 vsize=892700 CPUtime=0
/proc/25630/task/25638/stat : 25638 (java) S 25617 25616 17511 34816 17511 4202560 0 0 0 0 0 0 0 0 25 0 11 0 46359747 914124800 71569 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25639] ppid=25617 vsize=892700 CPUtime=0
/proc/25630/task/25639/stat : 25639 (java) R 25617 25616 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 11 0 46359747 914124800 71569 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.7
Current children cumulated vsize (KiB) 897840

[startup+7.306 s]
/proc/loadavg: 1.39 1.25 1.20 2/47 25640
/proc/meminfo: memFree=25700/1048576 swapFree=0/0
[pid=25616] ppid=25615 vsize=2568 CPUtime=0
/proc/25616/stat : 25616 (p2cudf-user-1.1) S 25615 25616 17511 34816 17511 4202496 377 0 0 0 0 0 0 0 25 0 1 0 46359738 2629632 271 1283457024 134512640 135304128 4290078032 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25616/statm: 642 271 230 194 0 29 0
[pid=25617] ppid=25616 vsize=2572 CPUtime=0.03
/proc/25617/stat : 25617 (p2cudf) S 25616 25616 17511 34816 17511 4202496 392 3014 0 1 0 1 2 0 25 0 1 0 46359738 2633728 280 1283457024 134512640 135304128 4287425264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/25617/statm: 643 280 239 194 0 30 0
[pid=25630] ppid=25617 vsize=892700 CPUtime=6.74
/proc/25630/stat : 25630 (java) S 25617 25616 17511 34816 17511 4202496 76515 0 1 0 644 30 0 0 25 0 10 0 46359742 914124800 71571 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/25630/statm: 223175 71571 1779 10 0 220266 0
[pid=25630/tid=25631] ppid=25617 vsize=892700 CPUtime=3.58
/proc/25630/task/25631/stat : 25631 (java) S 25617 25616 17511 34816 17511 4202560 50285 0 1 0 335 23 0 0 20 0 10 0 46359742 914124800 71571 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25632] ppid=25617 vsize=892700 CPUtime=0.22
/proc/25630/task/25632/stat : 25632 (java) S 25617 25616 17511 34816 17511 4202560 10772 0 0 0 20 2 0 0 16 0 10 0 46359744 914124800 71571 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 0 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25633] ppid=25617 vsize=892700 CPUtime=0
/proc/25630/task/25633/stat : 25633 (java) S 25617 25616 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 18 0 10 0 46359744 914124800 71571 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25634] ppid=25617 vsize=892700 CPUtime=0
/proc/25630/task/25634/stat : 25634 (java) S 25617 25616 17511 34816 17511 4202560 6 0 0 0 0 0 0 0 18 0 10 0 46359744 914124800 71571 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25635] ppid=25617 vsize=892700 CPUtime=0
/proc/25630/task/25635/stat : 25635 (java) S 25617 25616 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46359747 914124800 71571 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25636] ppid=25617 vsize=892700 CPUtime=2.49
/proc/25630/task/25636/stat : 25636 (java) S 25617 25616 17511 34816 17511 4202560 7763 0 0 0 247 2 0 0 15 0 10 0 46359747 914124800 71571 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25637] ppid=25617 vsize=892700 CPUtime=0.36
/proc/25630/task/25637/stat : 25637 (java) S 25617 25616 17511 34816 17511 4202560 6612 0 0 0 34 2 0 0 25 0 10 0 46359747 914124800 71571 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25638] ppid=25617 vsize=892700 CPUtime=0
/proc/25630/task/25638/stat : 25638 (java) S 25617 25616 17511 34816 17511 4202560 0 0 0 0 0 0 0 0 25 0 10 0 46359747 914124800 71571 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
[pid=25630/tid=25639] ppid=25617 vsize=892700 CPUtime=0
/proc/25630/task/25639/stat : 25639 (java) S 25617 25616 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 10 0 46359747 914124800 71571 1283457024 134512640 134550932 4291698080 18446744073709551615 4294960130 0 4 0 16800975 18446612133393238784 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.77
Current children cumulated vsize (KiB) 897840

Child status: 0
Real time (s): 7.34707
CPU time (s): 6.80042
CPU user time (s): 6.4684
CPU system time (s): 0.33202
CPU usage (%): 92.5596
Max. virtual memory (cumulated for all children) (KiB): 899736

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 6.4684
system time used= 0.33202
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 80322
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= 777
involuntary context switches= 759

runsolver used 0 second user time and 0 second system time

The end