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-trendy-1.12/4009.cudf.caixa.log.runsolver ./p2cudf-trendy-1.12 /home/misc2010/data/misc4/caixa//4009.cudf /home/misc2010/tmp/201103031013/p2cudf-trendy-1.12/4009.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.90 1.84 1.70 5/37 22875
/proc/meminfo: memFree=283028/1048576 swapFree=0/0
[pid=22871] ppid=22870 vsize=2572 CPUtime=0
/proc/22871/stat : 22871 (p2cudf-trendy-1) S 22870 22871 29493 34817 29493 4202496 376 0 0 0 0 0 0 0 25 0 1 0 76061792 2633728 271 1283457024 134512640 135304128 4291282608 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22871/statm: 643 271 230 194 0 30 0
[pid=22872] ppid=22871 vsize=2568 CPUtime=0
/proc/22872/stat : 22872 (p2cudf) S 22871 22871 29493 34817 29493 4202496 353 0 0 0 0 0 0 0 25 0 1 0 76061792 2629632 271 1283457024 134512640 135304128 4287986560 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0
/proc/22872/statm: 642 271 231 194 0 29 0
[pid=22873] ppid=22872 vsize=2568 CPUtime=0
/proc/22873/stat : 22873 (p2cudf) R 22872 22871 29493 34817 29493 4202560 117 0 0 0 0 0 0 0 25 0 1 0 76061792 2629632 125 1283457024 134512640 135304128 4287986560 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/22873/statm: 642 125 84 194 0 29 0
[pid=22874] ppid=22873 vsize=192 CPUtime=0
/proc/22874/stat : 22874 (java) R 22873 22871 29493 34817 29493 4194304 300 0 0 0 0 0 0 0 25 0 1 0 76061792 196608 35 1283457024 134512640 134550932 4287009392 18446744073709551615 4160387806 0 0 0 0 0 0 0 17 0 0 0 0
/proc/22874/statm: 48 35 26 10 0 8 0
[pid=22875] ppid=22873 vsize=2568 CPUtime=0
/proc/22875/stat : 22875 (p2cudf) R 22873 22871 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 1 0 76061792 2629632 41 1283457024 134512640 135304128 4287986560 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/22875/statm: 642 41 0 194 0 29 0

[startup+0.155668 s]
/proc/loadavg: 1.90 1.84 1.70 5/37 22875
/proc/meminfo: memFree=283028/1048576 swapFree=0/0
[pid=22871] ppid=22870 vsize=2572 CPUtime=0
/proc/22871/stat : 22871 (p2cudf-trendy-1) S 22870 22871 29493 34817 29493 4202496 376 0 0 0 0 0 0 0 25 0 1 0 76061792 2633728 271 1283457024 134512640 135304128 4291282608 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22871/statm: 643 271 230 194 0 30 0
[pid=22872] ppid=22871 vsize=2572 CPUtime=0.02
/proc/22872/stat : 22872 (p2cudf) S 22871 22871 29493 34817 29493 4202496 392 3017 0 1 0 0 0 2 25 0 1 0 76061792 2633728 280 1283457024 134512640 135304128 4287986560 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22872/statm: 643 280 239 194 0 30 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5144

[startup+0.205666 s]
/proc/loadavg: 1.90 1.84 1.70 5/37 22875
/proc/meminfo: memFree=283028/1048576 swapFree=0/0
[pid=22871] ppid=22870 vsize=2572 CPUtime=0
/proc/22871/stat : 22871 (p2cudf-trendy-1) S 22870 22871 29493 34817 29493 4202496 376 0 0 0 0 0 0 0 25 0 1 0 76061792 2633728 271 1283457024 134512640 135304128 4291282608 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22871/statm: 643 271 230 194 0 30 0
[pid=22872] ppid=22871 vsize=2572 CPUtime=0.02
/proc/22872/stat : 22872 (p2cudf) S 22871 22871 29493 34817 29493 4202496 392 3017 0 1 0 0 0 2 25 0 1 0 76061792 2633728 280 1283457024 134512640 135304128 4287986560 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22872/statm: 643 280 239 194 0 30 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5144

[startup+0.305683 s]
/proc/loadavg: 1.90 1.84 1.70 5/37 22875
/proc/meminfo: memFree=283028/1048576 swapFree=0/0
[pid=22871] ppid=22870 vsize=2572 CPUtime=0
/proc/22871/stat : 22871 (p2cudf-trendy-1) S 22870 22871 29493 34817 29493 4202496 376 0 0 0 0 0 0 0 25 0 1 0 76061792 2633728 271 1283457024 134512640 135304128 4291282608 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22871/statm: 643 271 230 194 0 30 0
[pid=22872] ppid=22871 vsize=2572 CPUtime=0.02
/proc/22872/stat : 22872 (p2cudf) S 22871 22871 29493 34817 29493 4202496 392 3017 0 1 0 0 0 2 25 0 1 0 76061792 2633728 280 1283457024 134512640 135304128 4287986560 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22872/statm: 643 280 239 194 0 30 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5144

[startup+0.705768 s]
/proc/loadavg: 1.90 1.84 1.70 5/37 22875
/proc/meminfo: memFree=283028/1048576 swapFree=0/0
[pid=22871] ppid=22870 vsize=2572 CPUtime=0
/proc/22871/stat : 22871 (p2cudf-trendy-1) S 22870 22871 29493 34817 29493 4202496 376 0 0 0 0 0 0 0 25 0 1 0 76061792 2633728 271 1283457024 134512640 135304128 4291282608 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22871/statm: 643 271 230 194 0 30 0
[pid=22872] ppid=22871 vsize=2572 CPUtime=0.02
/proc/22872/stat : 22872 (p2cudf) S 22871 22871 29493 34817 29493 4202496 392 3017 0 1 0 0 0 2 25 0 1 0 76061792 2633728 280 1283457024 134512640 135304128 4287986560 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22872/statm: 643 280 239 194 0 30 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5144

[startup+1.5059 s]
/proc/loadavg: 1.90 1.84 1.70 5/45 22894
/proc/meminfo: memFree=240440/1048576 swapFree=0/0
[pid=22871] ppid=22870 vsize=2572 CPUtime=0
/proc/22871/stat : 22871 (p2cudf-trendy-1) S 22870 22871 29493 34817 29493 4202496 376 0 0 0 0 0 0 0 25 0 1 0 76061792 2633728 271 1283457024 134512640 135304128 4291282608 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22871/statm: 643 271 230 194 0 30 0
[pid=22872] ppid=22871 vsize=2572 CPUtime=0.02
/proc/22872/stat : 22872 (p2cudf) S 22871 22871 29493 34817 29493 4202496 392 3017 0 1 0 0 0 2 25 0 1 0 76061792 2633728 280 1283457024 134512640 135304128 4287986560 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22872/statm: 643 280 239 194 0 30 0
[pid=22885] ppid=22872 vsize=880244 CPUtime=1.46
/proc/22885/stat : 22885 (java) S 22872 22871 29493 34817 29493 4202496 18729 0 1 0 139 7 0 0 25 0 10 0 76061795 901369856 14346 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/22885/statm: 220061 14346 1730 10 0 217152 0
[pid=22885/tid=22886] ppid=22872 vsize=880244 CPUtime=0.7
/proc/22885/task/22886/stat : 22886 (java) R 22872 22871 29493 34817 29493 4202560 6944 0 1 0 68 2 0 0 25 0 10 0 76061796 901369856 14346 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22885/tid=22887] ppid=22872 vsize=880244 CPUtime=0
/proc/22885/task/22887/stat : 22887 (java) S 22872 22871 29493 34817 29493 4202560 7 0 0 0 0 0 0 0 16 0 10 0 76061798 901369856 14346 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 0 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22888] ppid=22872 vsize=880244 CPUtime=0
/proc/22885/task/22888/stat : 22888 (java) S 22872 22871 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 76061798 901369856 14346 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22889] ppid=22872 vsize=880244 CPUtime=0
/proc/22885/task/22889/stat : 22889 (java) S 22872 22871 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 76061798 901369856 14346 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22890] ppid=22872 vsize=880244 CPUtime=0
/proc/22885/task/22890/stat : 22890 (java) S 22872 22871 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76061801 901369856 14346 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22891] ppid=22872 vsize=880244 CPUtime=0.55
/proc/22885/task/22891/stat : 22891 (java) R 22872 22871 29493 34817 29493 4202560 9150 0 0 0 50 5 0 0 22 0 10 0 76061801 901369856 14346 1283457024 134512640 134550932 4289586080 18446744073709551615 4149113042 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22885/tid=22892] ppid=22872 vsize=880244 CPUtime=0.2
/proc/22885/task/22892/stat : 22892 (java) R 22872 22871 29493 34817 29493 4202560 1554 0 0 0 20 0 0 0 24 0 10 0 76061801 901369856 14346 1283457024 134512640 134550932 4289586080 18446744073709551615 4151837399 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22885/tid=22893] ppid=22872 vsize=880244 CPUtime=0
/proc/22885/task/22893/stat : 22893 (java) S 22872 22871 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76061801 901369856 14346 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22894] ppid=22872 vsize=880244 CPUtime=0
/proc/22885/task/22894/stat : 22894 (java) S 22872 22871 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 76061801 901369856 14346 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.48
Current children cumulated vsize (KiB) 885388

[startup+3.10614 s]
/proc/loadavg: 1.90 1.84 1.70 4/45 22894
/proc/meminfo: memFree=185756/1048576 swapFree=0/0
[pid=22871] ppid=22870 vsize=2572 CPUtime=0
/proc/22871/stat : 22871 (p2cudf-trendy-1) S 22870 22871 29493 34817 29493 4202496 376 0 0 0 0 0 0 0 25 0 1 0 76061792 2633728 271 1283457024 134512640 135304128 4291282608 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22871/statm: 643 271 230 194 0 30 0
[pid=22872] ppid=22871 vsize=2572 CPUtime=0.02
/proc/22872/stat : 22872 (p2cudf) S 22871 22871 29493 34817 29493 4202496 392 3017 0 1 0 0 0 2 25 0 1 0 76061792 2633728 280 1283457024 134512640 135304128 4287986560 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22872/statm: 643 280 239 194 0 30 0
[pid=22885] ppid=22872 vsize=879264 CPUtime=3.06
/proc/22885/stat : 22885 (java) S 22872 22871 29493 34817 29493 4202496 55954 0 1 0 290 16 0 0 25 0 10 0 76061795 900366336 50306 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/22885/statm: 219816 50306 1743 10 0 216907 0
[pid=22885/tid=22886] ppid=22872 vsize=879264 CPUtime=1.52
/proc/22885/task/22886/stat : 22886 (java) R 22872 22871 29493 34817 29493 4202560 43003 0 1 0 142 10 0 0 25 0 10 0 76061796 900366336 50306 1283457024 134512640 134550932 4289586080 18446744073709551615 4095354216 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22885/tid=22887] ppid=22872 vsize=879264 CPUtime=0
/proc/22885/task/22887/stat : 22887 (java) S 22872 22871 29493 34817 29493 4202560 7 0 0 0 0 0 0 0 15 0 10 0 76061798 900366336 50306 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 0 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22888] ppid=22872 vsize=879264 CPUtime=0
/proc/22885/task/22888/stat : 22888 (java) S 22872 22871 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 76061798 900366336 50306 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22889] ppid=22872 vsize=879264 CPUtime=0
/proc/22885/task/22889/stat : 22889 (java) S 22872 22871 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 76061798 900366336 50306 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22890] ppid=22872 vsize=879264 CPUtime=0
/proc/22885/task/22890/stat : 22890 (java) S 22872 22871 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76061801 900366336 50306 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22891] ppid=22872 vsize=879264 CPUtime=1.05
/proc/22885/task/22891/stat : 22891 (java) R 22872 22871 29493 34817 29493 4202560 10291 0 0 0 99 6 0 0 19 0 10 0 76061801 900366336 50306 1283457024 134512640 134550932 4289586080 18446744073709551615 4153404304 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22885/tid=22892] ppid=22872 vsize=879264 CPUtime=0.48
/proc/22885/task/22892/stat : 22892 (java) S 22872 22871 29493 34817 29493 4202560 1579 0 0 0 48 0 0 0 16 0 10 0 76061801 900366336 50306 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22893] ppid=22872 vsize=879264 CPUtime=0
/proc/22885/task/22893/stat : 22893 (java) S 22872 22871 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76061801 900366336 50306 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22894] ppid=22872 vsize=879264 CPUtime=0
/proc/22885/task/22894/stat : 22894 (java) S 22872 22871 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 76061801 900366336 50306 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.08
Current children cumulated vsize (KiB) 884408

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

[startup+3.20617 s]
/proc/loadavg: 1.90 1.84 1.70 4/45 22894
/proc/meminfo: memFree=185756/1048576 swapFree=0/0
[pid=22871] ppid=22870 vsize=2572 CPUtime=0
/proc/22871/stat : 22871 (p2cudf-trendy-1) S 22870 22871 29493 34817 29493 4202496 376 0 0 0 0 0 0 0 25 0 1 0 76061792 2633728 271 1283457024 134512640 135304128 4291282608 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22871/statm: 643 271 230 194 0 30 0
[pid=22872] ppid=22871 vsize=2572 CPUtime=0.02
/proc/22872/stat : 22872 (p2cudf) S 22871 22871 29493 34817 29493 4202496 392 3017 0 1 0 0 0 2 25 0 1 0 76061792 2633728 280 1283457024 134512640 135304128 4287986560 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22872/statm: 643 280 239 194 0 30 0
[pid=22885] ppid=22872 vsize=879264 CPUtime=3.16
/proc/22885/stat : 22885 (java) S 22872 22871 29493 34817 29493 4202496 60752 0 1 0 300 16 0 0 25 0 10 0 76061795 900366336 55104 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/22885/statm: 219816 55104 1743 10 0 216907 0
[pid=22885/tid=22886] ppid=22872 vsize=879264 CPUtime=1.57
/proc/22885/task/22886/stat : 22886 (java) R 22872 22871 29493 34817 29493 4202560 47797 0 1 0 147 10 0 0 25 0 10 0 76061796 900366336 55104 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22885/tid=22887] ppid=22872 vsize=879264 CPUtime=0
/proc/22885/task/22887/stat : 22887 (java) S 22872 22871 29493 34817 29493 4202560 7 0 0 0 0 0 0 0 15 0 10 0 76061798 900366336 55104 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 0 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22888] ppid=22872 vsize=879264 CPUtime=0
/proc/22885/task/22888/stat : 22888 (java) S 22872 22871 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 76061798 900366336 55104 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22889] ppid=22872 vsize=879264 CPUtime=0
/proc/22885/task/22889/stat : 22889 (java) S 22872 22871 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 76061798 900366336 55104 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22890] ppid=22872 vsize=879264 CPUtime=0
/proc/22885/task/22890/stat : 22890 (java) S 22872 22871 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76061801 900366336 55104 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22891] ppid=22872 vsize=879264 CPUtime=1.06
/proc/22885/task/22891/stat : 22891 (java) R 22872 22871 29493 34817 29493 4202560 10291 0 0 0 100 6 0 0 19 0 10 0 76061801 900366336 55104 1283457024 134512640 134550932 4289586080 18446744073709551615 4151837566 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22885/tid=22892] ppid=22872 vsize=879264 CPUtime=0.52
/proc/22885/task/22892/stat : 22892 (java) S 22872 22871 29493 34817 29493 4202560 1583 0 0 0 52 0 0 0 16 0 10 0 76061801 900366336 55104 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22893] ppid=22872 vsize=879264 CPUtime=0
/proc/22885/task/22893/stat : 22893 (java) S 22872 22871 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76061801 900366336 55104 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22894] ppid=22872 vsize=879264 CPUtime=0
/proc/22885/task/22894/stat : 22894 (java) S 22872 22871 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 76061801 900366336 55104 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.18
Current children cumulated vsize (KiB) 884408

[startup+4.00626 s]
/proc/loadavg: 1.90 1.84 1.70 3/45 22894
/proc/meminfo: memFree=67468/1048576 swapFree=0/0
[pid=22871] ppid=22870 vsize=2572 CPUtime=0
/proc/22871/stat : 22871 (p2cudf-trendy-1) S 22870 22871 29493 34817 29493 4202496 376 0 0 0 0 0 0 0 25 0 1 0 76061792 2633728 271 1283457024 134512640 135304128 4291282608 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22871/statm: 643 271 230 194 0 30 0
[pid=22872] ppid=22871 vsize=2572 CPUtime=0.02
/proc/22872/stat : 22872 (p2cudf) S 22871 22871 29493 34817 29493 4202496 392 3017 0 1 0 0 0 2 25 0 1 0 76061792 2633728 280 1283457024 134512640 135304128 4287986560 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22872/statm: 643 280 239 194 0 30 0
[pid=22885] ppid=22872 vsize=880932 CPUtime=3.95
/proc/22885/stat : 22885 (java) S 22872 22871 29493 34817 29493 4202496 79605 0 1 0 372 23 0 0 25 0 10 0 76061795 902074368 73628 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/22885/statm: 220233 73628 1748 10 0 217324 0
[pid=22885/tid=22886] ppid=22872 vsize=880932 CPUtime=1.71
/proc/22885/task/22886/stat : 22886 (java) R 22872 22871 29493 34817 29493 4202560 50192 0 1 0 159 12 0 0 25 0 10 0 76061796 902074368 73628 1283457024 134512640 134550932 4289586080 18446744073709551615 4096120790 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22885/tid=22887] ppid=22872 vsize=880932 CPUtime=0.36
/proc/22885/task/22887/stat : 22887 (java) S 22872 22871 29493 34817 29493 4202560 15799 0 0 0 32 4 0 0 16 0 10 0 76061798 902074368 73628 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 0 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22888] ppid=22872 vsize=880932 CPUtime=0
/proc/22885/task/22888/stat : 22888 (java) S 22872 22871 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 18 0 10 0 76061798 902074368 73628 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22889] ppid=22872 vsize=880932 CPUtime=0
/proc/22885/task/22889/stat : 22889 (java) S 22872 22871 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 10 0 76061798 902074368 73628 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22890] ppid=22872 vsize=880932 CPUtime=0
/proc/22885/task/22890/stat : 22890 (java) S 22872 22871 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76061801 902074368 73628 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22891] ppid=22872 vsize=880932 CPUtime=1.31
/proc/22885/task/22891/stat : 22891 (java) R 22872 22871 29493 34817 29493 4202560 10949 0 0 0 124 7 0 0 19 0 10 0 76061801 902074368 73628 1283457024 134512640 134550932 4289586080 18446744073709551615 4150227773 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22885/tid=22892] ppid=22872 vsize=880932 CPUtime=0.55
/proc/22885/task/22892/stat : 22892 (java) S 22872 22871 29493 34817 29493 4202560 1589 0 0 0 55 0 0 0 16 0 10 0 76061801 902074368 73628 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22893] ppid=22872 vsize=880932 CPUtime=0
/proc/22885/task/22893/stat : 22893 (java) S 22872 22871 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76061801 902074368 73628 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22894] ppid=22872 vsize=880932 CPUtime=0
/proc/22885/task/22894/stat : 22894 (java) S 22872 22871 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 76061801 902074368 73628 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.97
Current children cumulated vsize (KiB) 886076

[startup+4.40632 s]
/proc/loadavg: 1.90 1.84 1.70 3/45 22894
/proc/meminfo: memFree=6640/1048576 swapFree=0/0
[pid=22871] ppid=22870 vsize=2572 CPUtime=0
/proc/22871/stat : 22871 (p2cudf-trendy-1) S 22870 22871 29493 34817 29493 4202496 376 0 0 0 0 0 0 0 25 0 1 0 76061792 2633728 271 1283457024 134512640 135304128 4291282608 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22871/statm: 643 271 230 194 0 30 0
[pid=22872] ppid=22871 vsize=2572 CPUtime=0.02
/proc/22872/stat : 22872 (p2cudf) S 22871 22871 29493 34817 29493 4202496 392 3017 0 1 0 0 0 2 25 0 1 0 76061792 2633728 280 1283457024 134512640 135304128 4287986560 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22872/statm: 643 280 239 194 0 30 0
[pid=22885] ppid=22872 vsize=879440 CPUtime=4.34
/proc/22885/stat : 22885 (java) S 22872 22871 29493 34817 29493 4202496 80092 0 1 0 410 24 0 0 25 0 10 0 76061795 900546560 73369 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/22885/statm: 219860 73369 1761 10 0 216951 0
[pid=22885/tid=22886] ppid=22872 vsize=879440 CPUtime=1.86
/proc/22885/task/22886/stat : 22886 (java) R 22872 22871 29493 34817 29493 4202560 50199 0 1 0 174 12 0 0 25 0 10 0 76061796 900546560 73369 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22885/tid=22887] ppid=22872 vsize=879440 CPUtime=0.36
/proc/22885/task/22887/stat : 22887 (java) S 22872 22871 29493 34817 29493 4202560 15799 0 0 0 32 4 0 0 16 0 10 0 76061798 900546560 73369 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 0 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22888] ppid=22872 vsize=879440 CPUtime=0
/proc/22885/task/22888/stat : 22888 (java) S 22872 22871 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 18 0 10 0 76061798 900546560 73369 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22889] ppid=22872 vsize=879440 CPUtime=0
/proc/22885/task/22889/stat : 22889 (java) S 22872 22871 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 10 0 76061798 900546560 73369 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22890] ppid=22872 vsize=879440 CPUtime=0
/proc/22885/task/22890/stat : 22890 (java) S 22872 22871 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76061801 900546560 73369 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22891] ppid=22872 vsize=879440 CPUtime=1.43
/proc/22885/task/22891/stat : 22891 (java) R 22872 22871 29493 34817 29493 4202560 11403 0 0 0 135 8 0 0 19 0 10 0 76061801 900546560 73369 1283457024 134512640 134550932 4289586080 18446744073709551615 4148819650 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22885/tid=22892] ppid=22872 vsize=879440 CPUtime=0.68
/proc/22885/task/22892/stat : 22892 (java) S 22872 22871 29493 34817 29493 4202560 1615 0 0 0 68 0 0 0 15 0 10 0 76061801 900546560 73369 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22893] ppid=22872 vsize=879440 CPUtime=0
/proc/22885/task/22893/stat : 22893 (java) S 22872 22871 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 76061801 900546560 73369 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22894] ppid=22872 vsize=879440 CPUtime=0
/proc/22885/task/22894/stat : 22894 (java) S 22872 22871 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 10 0 76061801 900546560 73369 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.36
Current children cumulated vsize (KiB) 884584

[startup+4.806 s]
/proc/loadavg: 1.90 1.84 1.70 3/45 22894
/proc/meminfo: memFree=6640/1048576 swapFree=0/0
[pid=22871] ppid=22870 vsize=2572 CPUtime=0
/proc/22871/stat : 22871 (p2cudf-trendy-1) S 22870 22871 29493 34817 29493 4202496 376 0 0 0 0 0 0 0 25 0 1 0 76061792 2633728 271 1283457024 134512640 135304128 4291282608 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22871/statm: 643 271 230 194 0 30 0
[pid=22872] ppid=22871 vsize=2572 CPUtime=0.02
/proc/22872/stat : 22872 (p2cudf) S 22871 22871 29493 34817 29493 4202496 392 3017 0 1 0 0 0 2 25 0 1 0 76061792 2633728 280 1283457024 134512640 135304128 4287986560 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22872/statm: 643 280 239 194 0 30 0
[pid=22885] ppid=22872 vsize=879764 CPUtime=4.38
/proc/22885/stat : 22885 (java) S 22872 22871 29493 34817 29493 4202496 80100 0 1 0 414 24 0 0 25 0 11 0 76061795 900878336 73377 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/22885/statm: 219941 73377 1761 10 0 217032 0
[pid=22885/tid=22886] ppid=22872 vsize=879764 CPUtime=1.88
/proc/22885/task/22886/stat : 22886 (java) S 22872 22871 29493 34817 29493 4202560 50203 0 1 0 176 12 0 0 25 0 11 0 76061796 900878336 73377 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22887] ppid=22872 vsize=879764 CPUtime=0.36
/proc/22885/task/22887/stat : 22887 (java) S 22872 22871 29493 34817 29493 4202560 15799 0 0 0 32 4 0 0 16 0 11 0 76061798 900878336 73377 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 0 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22888] ppid=22872 vsize=879764 CPUtime=0
/proc/22885/task/22888/stat : 22888 (java) S 22872 22871 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 18 0 11 0 76061798 900878336 73377 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22889] ppid=22872 vsize=879764 CPUtime=0
/proc/22885/task/22889/stat : 22889 (java) S 22872 22871 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 11 0 76061798 900878336 73377 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22890] ppid=22872 vsize=879764 CPUtime=0
/proc/22885/task/22890/stat : 22890 (java) S 22872 22871 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 76061801 900878336 73377 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22891] ppid=22872 vsize=879764 CPUtime=1.44
/proc/22885/task/22891/stat : 22891 (java) S 22872 22871 29493 34817 29493 4202560 11403 0 0 0 136 8 0 0 19 0 11 0 76061801 900878336 73377 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22892] ppid=22872 vsize=879764 CPUtime=0.68
/proc/22885/task/22892/stat : 22892 (java) S 22872 22871 29493 34817 29493 4202560 1615 0 0 0 68 0 0 0 15 0 11 0 76061801 900878336 73377 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22893] ppid=22872 vsize=879764 CPUtime=0
/proc/22885/task/22893/stat : 22893 (java) S 22872 22871 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 76061801 900878336 73377 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22894] ppid=22872 vsize=879764 CPUtime=0
/proc/22885/task/22894/stat : 22894 (java) R 22872 22871 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 11 0 76061801 900878336 73377 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.4
Current children cumulated vsize (KiB) 884908

[startup+4.90599 s]
/proc/loadavg: 1.90 1.84 1.70 3/45 22894
/proc/meminfo: memFree=6640/1048576 swapFree=0/0
[pid=22871] ppid=22870 vsize=2572 CPUtime=0
/proc/22871/stat : 22871 (p2cudf-trendy-1) S 22870 22871 29493 34817 29493 4202496 376 0 0 0 0 0 0 0 25 0 1 0 76061792 2633728 271 1283457024 134512640 135304128 4291282608 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22871/statm: 643 271 230 194 0 30 0
[pid=22872] ppid=22871 vsize=2572 CPUtime=0.02
/proc/22872/stat : 22872 (p2cudf) S 22871 22871 29493 34817 29493 4202496 392 3017 0 1 0 0 0 2 25 0 1 0 76061792 2633728 280 1283457024 134512640 135304128 4287986560 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22872/statm: 643 280 239 194 0 30 0
[pid=22885] ppid=22872 vsize=879764 CPUtime=4.38
/proc/22885/stat : 22885 (java) S 22872 22871 29493 34817 29493 4202496 80100 0 1 0 414 24 0 0 25 0 11 0 76061795 900878336 73377 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/22885/statm: 219941 73377 1761 10 0 217032 0
[pid=22885/tid=22886] ppid=22872 vsize=879764 CPUtime=1.88
/proc/22885/task/22886/stat : 22886 (java) S 22872 22871 29493 34817 29493 4202560 50203 0 1 0 176 12 0 0 25 0 11 0 76061796 900878336 73377 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22887] ppid=22872 vsize=879764 CPUtime=0.36
/proc/22885/task/22887/stat : 22887 (java) S 22872 22871 29493 34817 29493 4202560 15799 0 0 0 32 4 0 0 16 0 11 0 76061798 900878336 73377 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 0 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22888] ppid=22872 vsize=879764 CPUtime=0
/proc/22885/task/22888/stat : 22888 (java) S 22872 22871 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 18 0 11 0 76061798 900878336 73377 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22889] ppid=22872 vsize=879764 CPUtime=0
/proc/22885/task/22889/stat : 22889 (java) S 22872 22871 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 11 0 76061798 900878336 73377 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22890] ppid=22872 vsize=879764 CPUtime=0
/proc/22885/task/22890/stat : 22890 (java) S 22872 22871 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 76061801 900878336 73377 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22891] ppid=22872 vsize=879764 CPUtime=1.44
/proc/22885/task/22891/stat : 22891 (java) S 22872 22871 29493 34817 29493 4202560 11403 0 0 0 136 8 0 0 19 0 11 0 76061801 900878336 73377 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22892] ppid=22872 vsize=879764 CPUtime=0.68
/proc/22885/task/22892/stat : 22892 (java) S 22872 22871 29493 34817 29493 4202560 1615 0 0 0 68 0 0 0 15 0 11 0 76061801 900878336 73377 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22893] ppid=22872 vsize=879764 CPUtime=0
/proc/22885/task/22893/stat : 22893 (java) S 22872 22871 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 76061801 900878336 73377 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
[pid=22885/tid=22894] ppid=22872 vsize=879764 CPUtime=0
/proc/22885/task/22894/stat : 22894 (java) S 22872 22871 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 15 0 11 0 76061801 900878336 73377 1283457024 134512640 134550932 4289586080 18446744073709551615 4294960130 0 4 0 16800975 18446612133395009856 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.4
Current children cumulated vsize (KiB) 884908

Child status: 0
Real time (s): 5.00514
CPU time (s): 4.45628
CPU user time (s): 4.16026
CPU system time (s): 0.296018
CPU usage (%): 89.034
Max. virtual memory (cumulated for all children) (KiB): 887120

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.16026
system time used= 0.296018
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 83912
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= 444
involuntary context switches= 438

runsolver used 0 second user time and 0 second system time

The end