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: runsolver -s SIGUSR1 -M 1124 -C 300 -d 10 -w /tmp/misc2012/2012-09-02-22:42/full/p2cudf-full-1.15/dist-upgrade/real/4f84e9c6-a79c-11e0-9eb7-00163e1e087d.cudf.log.runsolver /home/competition/p2cudf-full-1.15/p2cudf-full-1.15 /home/competition/data/real/4f84e9c6-a79c-11e0-9eb7-00163e1e087d.cudf /tmp/misc2012/2012-09-02-22:42/full/p2cudf-full-1.15/dist-upgrade/real/4f84e9c6-a79c-11e0-9eb7-00163e1e087d.cudf.result -notuptodate(solution),-aligned(solution,source,sourceversion),-unsat_recommends(solution),-count(new) 

Enforcing CPUTime limit (soft limit, will send signal-name then SIGKILL): 300 seconds
Enforcing CPUTime limit (hard limit, will send SIGXCPU): 330 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

[startup+0 s]
/proc/loadavg: 1.00 1.05 1.07 2/64 14033
/proc/meminfo: memFree=541808/1022884 swapFree=0/0
[pid=14033] ppid=14032 vsize=3152 CPUtime=0
/proc/14033/stat : 14033 (runsolver) R 14032 1745 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 1 0 118230021 3227648 33 18446744073709551615 134512640 134586868 4293366816 4293364864 4152124464 0 0 16781316 24578 0 0 0 17 0 0 0 0 0 0
/proc/14033/statm: 788 33 0 19 0 73 0
Current StackSize limit: 8192 KiB


[startup+0.115318 s]
/proc/loadavg: 1.00 1.05 1.07 2/64 14033
/proc/meminfo: memFree=541808/1022884 swapFree=0/0
[pid=14033] ppid=14032 vsize=9172 CPUtime=0
/proc/14033/stat : 14033 (p2cudf-full-1.1) S 14032 14033 1745 0 -1 4202496 459 293 0 0 0 0 0 0 20 0 1 0 118230021 9392128 331 18446744073709551615 4194304 5129932 140734568674832 140734568672976 140680660243550 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/14033/statm: 2293 331 280 229 0 53 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9172

[startup+0.20026 s]
/proc/loadavg: 1.00 1.05 1.07 2/64 14033
/proc/meminfo: memFree=541808/1022884 swapFree=0/0
[pid=14033] ppid=14032 vsize=9172 CPUtime=0
/proc/14033/stat : 14033 (p2cudf-full-1.1) S 14032 14033 1745 0 -1 4202496 459 293 0 0 0 0 0 0 20 0 1 0 118230021 9392128 331 18446744073709551615 4194304 5129932 140734568674832 140734568672976 140680660243550 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/14033/statm: 2293 331 280 229 0 53 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9172

[startup+0.300269 s]
/proc/loadavg: 1.00 1.05 1.07 2/64 14033
/proc/meminfo: memFree=541808/1022884 swapFree=0/0
[pid=14033] ppid=14032 vsize=9172 CPUtime=0
/proc/14033/stat : 14033 (p2cudf-full-1.1) S 14032 14033 1745 0 -1 4202496 459 293 0 0 0 0 0 0 20 0 1 0 118230021 9392128 331 18446744073709551615 4194304 5129932 140734568674832 140734568672976 140680660243550 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/14033/statm: 2293 331 280 229 0 53 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9172

[startup+0.700257 s]
/proc/loadavg: 1.00 1.05 1.07 2/64 14033
/proc/meminfo: memFree=541808/1022884 swapFree=0/0
[pid=14033] ppid=14032 vsize=9172 CPUtime=0
/proc/14033/stat : 14033 (p2cudf-full-1.1) S 14032 14033 1745 0 -1 4202496 459 293 0 0 0 0 0 0 20 0 1 0 118230021 9392128 331 18446744073709551615 4194304 5129932 140734568674832 140734568672976 140680660243550 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/14033/statm: 2293 331 280 229 0 53 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9172

[startup+1.50074 s]
/proc/loadavg: 1.00 1.05 1.07 4/75 14045
/proc/meminfo: memFree=451068/1022884 swapFree=0/0
[pid=14033] ppid=14032 vsize=9172 CPUtime=0
/proc/14033/stat : 14033 (p2cudf-full-1.1) S 14032 14033 1745 0 -1 4202496 459 293 0 0 0 0 0 0 20 0 1 0 118230021 9392128 331 18446744073709551615 4194304 5129932 140734568674832 140734568672976 140680660243550 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/14033/statm: 2293 331 280 229 0 53 0
[pid=14036] ppid=14033 vsize=1072924 CPUtime=1.46
/proc/14036/stat : 14036 (java) S 14033 14033 1745 0 -1 4202496 34016 0 0 0 136 10 0 0 20 0 10 0 118230022 1098674176 30994 18446744073709551615 4194304 4228012 140736337219424 140736337210448 140719127326325 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/14036/statm: 268231 30994 2344 9 0 255581 0
[pid=14036/tid=14037] ppid=14033 vsize=1072924 CPUtime=0.63
/proc/14036/task/14037/stat : 14037 (java) R 14033 14033 1745 0 -1 4202560 15325 0 0 0 56 7 0 0 20 0 10 0 118230023 1098674176 30994 18446744073709551615 4194304 4228012 140736337219424 140719133852320 140719031647742 0 4 0 16800975 0 0 0 -1 0 0 0 1 0 0
[pid=14036/tid=14038] ppid=14033 vsize=1072924 CPUtime=0
/proc/14036/task/14038/stat : 14038 (java) S 14033 14033 1745 0 -1 4202560 4 0 0 0 0 0 0 0 20 0 10 0 118230024 1098674176 30994 18446744073709551615 4194304 4228012 140736337219424 140719026498688 140719127340619 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14039] ppid=14033 vsize=1072924 CPUtime=0
/proc/14036/task/14039/stat : 14039 (java) S 14033 14033 1745 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 10 0 118230025 1098674176 30994 18446744073709551615 4194304 4228012 140736337219424 140719025444880 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14040] ppid=14033 vsize=1072924 CPUtime=0
/proc/14036/task/14040/stat : 14040 (java) S 14033 14033 1745 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 10 0 118230025 1098674176 30994 18446744073709551615 4194304 4228012 140736337219424 140719024392096 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14041] ppid=14033 vsize=1072924 CPUtime=0
/proc/14036/task/14041/stat : 14041 (java) S 14033 14033 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 118230028 1098674176 30994 18446744073709551615 4194304 4228012 140736337219424 140719023340528 140719127348256 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14042] ppid=14033 vsize=1072924 CPUtime=0.41
/proc/14036/task/14042/stat : 14042 (java) R 14033 14033 1745 0 -1 4202560 10295 0 0 0 39 2 0 0 20 0 10 0 118230028 1098674176 30994 18446744073709551615 4194304 4228012 140736337219424 140719022275416 140719114016992 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14043] ppid=14033 vsize=1072924 CPUtime=0.4
/proc/14036/task/14043/stat : 14043 (java) R 14033 14033 1745 0 -1 4202560 7105 0 0 0 39 1 0 0 20 0 10 0 118230028 1098674176 30994 18446744073709551615 4194304 4228012 140736337219424 140719021222744 140719113856760 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14044] ppid=14033 vsize=1072924 CPUtime=0
/proc/14036/task/14044/stat : 14044 (java) S 14033 14033 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 118230028 1098674176 30994 18446744073709551615 4194304 4228012 140736337219424 140719020182736 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14045] ppid=14033 vsize=1072924 CPUtime=0
/proc/14036/task/14045/stat : 14045 (java) S 14033 14033 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 118230028 1098674176 30994 18446744073709551615 4194304 4228012 140736337219424 140719019130240 140719127340619 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 1.46
Current children cumulated vsize (KiB) 1082096

[startup+3.10075 s]
/proc/loadavg: 1.00 1.05 1.07 2/75 14045
/proc/meminfo: memFree=335996/1022884 swapFree=0/0
[pid=14033] ppid=14032 vsize=9172 CPUtime=0
/proc/14033/stat : 14033 (p2cudf-full-1.1) S 14032 14033 1745 0 -1 4202496 459 293 0 0 0 0 0 0 20 0 1 0 118230021 9392128 331 18446744073709551615 4194304 5129932 140734568674832 140734568672976 140680660243550 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/14033/statm: 2293 331 280 229 0 53 0
[pid=14036] ppid=14033 vsize=1072924 CPUtime=3.04
/proc/14036/stat : 14036 (java) S 14033 14033 1745 0 -1 4202496 81429 0 0 0 278 26 0 0 20 0 10 0 118230022 1098674176 77060 18446744073709551615 4194304 4228012 140736337219424 140736337210448 140719127326325 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/14036/statm: 268231 77060 2365 9 0 255581 0
[pid=14036/tid=14037] ppid=14033 vsize=1072924 CPUtime=1.58
/proc/14036/task/14037/stat : 14037 (java) S 14033 14033 1745 0 -1 4202560 47422 0 0 0 142 16 0 0 20 0 10 0 118230023 1098674176 77060 18446744073709551615 4194304 4228012 140736337219424 140719133860368 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 2 0 0
[pid=14036/tid=14038] ppid=14033 vsize=1072924 CPUtime=0.29
/proc/14036/task/14038/stat : 14038 (java) R 14033 14033 1745 0 -1 4202560 14192 0 0 0 24 5 0 0 20 0 10 0 118230024 1098674176 77060 18446744073709551615 4194304 4228012 140736337219424 140719026498064 140719111637113 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14039] ppid=14033 vsize=1072924 CPUtime=0
/proc/14036/task/14039/stat : 14039 (java) S 14033 14033 1745 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 118230025 1098674176 77060 18446744073709551615 4194304 4228012 140736337219424 140719025444880 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14040] ppid=14033 vsize=1072924 CPUtime=0
/proc/14036/task/14040/stat : 14040 (java) S 14033 14033 1745 0 -1 4202560 8 0 0 0 0 0 0 0 20 0 10 0 118230025 1098674176 77060 18446744073709551615 4194304 4228012 140736337219424 140719024392096 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14041] ppid=14033 vsize=1072924 CPUtime=0
/proc/14036/task/14041/stat : 14041 (java) S 14033 14033 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 118230028 1098674176 77060 18446744073709551615 4194304 4228012 140736337219424 140719023340528 140719127348256 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14042] ppid=14033 vsize=1072924 CPUtime=0.59
/proc/14036/task/14042/stat : 14042 (java) S 14033 14033 1745 0 -1 4202560 11147 0 0 0 55 4 0 0 20 0 10 0 118230028 1098674176 77060 18446744073709551615 4194304 4228012 140736337219424 140719022287888 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14043] ppid=14033 vsize=1072924 CPUtime=0.56
/proc/14036/task/14043/stat : 14043 (java) S 14033 14033 1745 0 -1 4202560 7378 0 0 0 55 1 0 0 20 0 10 0 118230028 1098674176 77060 18446744073709551615 4194304 4228012 140736337219424 140719021235216 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14044] ppid=14033 vsize=1072924 CPUtime=0
/proc/14036/task/14044/stat : 14044 (java) S 14033 14033 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 118230028 1098674176 77060 18446744073709551615 4194304 4228012 140736337219424 140719020182736 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14045] ppid=14033 vsize=1072924 CPUtime=0
/proc/14036/task/14045/stat : 14045 (java) S 14033 14033 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 118230028 1098674176 77060 18446744073709551615 4194304 4228012 140736337219424 140719019130240 140719127340619 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 3.04
Current children cumulated vsize (KiB) 1082096

[startup+6.30076 s]
/proc/loadavg: 1.00 1.05 1.07 4/75 14045
/proc/meminfo: memFree=118748/1022884 swapFree=0/0
[pid=14033] ppid=14032 vsize=9172 CPUtime=0
/proc/14033/stat : 14033 (p2cudf-full-1.1) S 14032 14033 1745 0 -1 4202496 459 293 0 0 0 0 0 0 20 0 1 0 118230021 9392128 331 18446744073709551615 4194304 5129932 140734568674832 140734568672976 140680660243550 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/14033/statm: 2293 331 280 229 0 53 0
[pid=14036] ppid=14033 vsize=1067728 CPUtime=6.2
/proc/14036/stat : 14036 (java) S 14033 14033 1745 0 -1 4202496 119568 0 0 0 578 42 0 0 20 0 10 0 118230022 1093353472 113902 18446744073709551615 4194304 4228012 140736337219424 140736337210448 140719127326325 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/14036/statm: 266932 113902 2370 9 0 254282 0
[pid=14036/tid=14037] ppid=14033 vsize=1067728 CPUtime=3.24
/proc/14036/task/14037/stat : 14037 (java) R 14033 14033 1745 0 -1 4202560 47492 0 0 0 307 17 0 0 20 0 10 0 118230023 1093353472 113902 18446744073709551615 4194304 4228012 140736337219424 140719133860824 140719032120408 0 4 0 16800975 0 0 0 -1 0 0 0 2 0 0
[pid=14036/tid=14038] ppid=14033 vsize=1067728 CPUtime=1.23
/proc/14036/task/14038/stat : 14038 (java) S 14033 14033 1745 0 -1 4202560 50453 0 0 0 104 19 0 0 20 0 10 0 118230024 1093353472 113902 18446744073709551615 4194304 4228012 140736337219424 140719026498688 140719127340619 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14039] ppid=14033 vsize=1067728 CPUtime=0
/proc/14036/task/14039/stat : 14039 (java) S 14033 14033 1745 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 118230025 1093353472 113902 18446744073709551615 4194304 4228012 140736337219424 140719025444880 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14040] ppid=14033 vsize=1067728 CPUtime=0
/proc/14036/task/14040/stat : 14040 (java) S 14033 14033 1745 0 -1 4202560 8 0 0 0 0 0 0 0 20 0 10 0 118230025 1093353472 113902 18446744073709551615 4194304 4228012 140736337219424 140719024392096 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14041] ppid=14033 vsize=1067728 CPUtime=0
/proc/14036/task/14041/stat : 14041 (java) S 14033 14033 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 118230028 1093353472 113902 18446744073709551615 4194304 4228012 140736337219424 140719023340528 140719127348256 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14042] ppid=14033 vsize=1067728 CPUtime=0.86
/proc/14036/task/14042/stat : 14042 (java) R 14033 14033 1745 0 -1 4202560 12892 0 0 0 82 4 0 0 20 0 10 0 118230028 1093353472 113902 18446744073709551615 4194304 4228012 140736337219424 140719022287632 140719110171915 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14043] ppid=14033 vsize=1067728 CPUtime=0.83
/proc/14036/task/14043/stat : 14043 (java) R 14033 14033 1745 0 -1 4202560 7440 0 0 0 82 1 0 0 20 0 10 0 118230028 1093353472 113902 18446744073709551615 4194304 4228012 140736337219424 140719021234960 140719114014610 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14044] ppid=14033 vsize=1067728 CPUtime=0
/proc/14036/task/14044/stat : 14044 (java) S 14033 14033 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 118230028 1093353472 113902 18446744073709551615 4194304 4228012 140736337219424 140719020182736 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14045] ppid=14033 vsize=1067728 CPUtime=0
/proc/14036/task/14045/stat : 14045 (java) S 14033 14033 1745 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 118230028 1093353472 113902 18446744073709551615 4194304 4228012 140736337219424 140719019130240 140719127340619 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 6.2
Current children cumulated vsize (KiB) 1076900

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

[startup+6.40099 s]
/proc/loadavg: 1.00 1.05 1.07 4/75 14045
/proc/meminfo: memFree=118748/1022884 swapFree=0/0
[pid=14033] ppid=14032 vsize=9172 CPUtime=0
/proc/14033/stat : 14033 (p2cudf-full-1.1) S 14032 14033 1745 0 -1 4202496 459 293 0 0 0 0 0 0 20 0 1 0 118230021 9392128 331 18446744073709551615 4194304 5129932 140734568674832 140734568672976 140680660243550 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/14033/statm: 2293 331 280 229 0 53 0
[pid=14036] ppid=14033 vsize=1067728 CPUtime=6.3
/proc/14036/stat : 14036 (java) S 14033 14033 1745 0 -1 4202496 119569 0 0 0 588 42 0 0 20 0 10 0 118230022 1093353472 113903 18446744073709551615 4194304 4228012 140736337219424 140736337210448 140719127326325 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/14036/statm: 266932 113903 2370 9 0 254282 0
[pid=14036/tid=14037] ppid=14033 vsize=1067728 CPUtime=3.31
/proc/14036/task/14037/stat : 14037 (java) R 14033 14033 1745 0 -1 4202560 47493 0 0 0 314 17 0 0 20 0 10 0 118230023 1093353472 113903 18446744073709551615 4194304 4228012 140736337219424 140719133860856 140719032056655 0 4 0 16800975 0 0 0 -1 0 0 0 2 0 0
[pid=14036/tid=14038] ppid=14033 vsize=1067728 CPUtime=1.23
/proc/14036/task/14038/stat : 14038 (java) S 14033 14033 1745 0 -1 4202560 50453 0 0 0 104 19 0 0 20 0 10 0 118230024 1093353472 113903 18446744073709551615 4194304 4228012 140736337219424 140719026498688 140719127340619 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14039] ppid=14033 vsize=1067728 CPUtime=0
/proc/14036/task/14039/stat : 14039 (java) S 14033 14033 1745 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 118230025 1093353472 113903 18446744073709551615 4194304 4228012 140736337219424 140719025444880 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14040] ppid=14033 vsize=1067728 CPUtime=0
/proc/14036/task/14040/stat : 14040 (java) S 14033 14033 1745 0 -1 4202560 8 0 0 0 0 0 0 0 20 0 10 0 118230025 1093353472 113903 18446744073709551615 4194304 4228012 140736337219424 140719024392096 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14041] ppid=14033 vsize=1067728 CPUtime=0
/proc/14036/task/14041/stat : 14041 (java) S 14033 14033 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 118230028 1093353472 113903 18446744073709551615 4194304 4228012 140736337219424 140719023340528 140719127348256 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14042] ppid=14033 vsize=1067728 CPUtime=0.87
/proc/14036/task/14042/stat : 14042 (java) S 14033 14033 1745 0 -1 4202560 12892 0 0 0 83 4 0 0 20 0 10 0 118230028 1093353472 113903 18446744073709551615 4194304 4228012 140736337219424 140719022287888 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14043] ppid=14033 vsize=1067728 CPUtime=0.84
/proc/14036/task/14043/stat : 14043 (java) S 14033 14033 1745 0 -1 4202560 7440 0 0 0 83 1 0 0 20 0 10 0 118230028 1093353472 113903 18446744073709551615 4194304 4228012 140736337219424 140719021235216 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14044] ppid=14033 vsize=1067728 CPUtime=0
/proc/14036/task/14044/stat : 14044 (java) S 14033 14033 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 118230028 1093353472 113903 18446744073709551615 4194304 4228012 140736337219424 140719020182736 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14045] ppid=14033 vsize=1067728 CPUtime=0
/proc/14036/task/14045/stat : 14045 (java) S 14033 14033 1745 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 118230028 1093353472 113903 18446744073709551615 4194304 4228012 140736337219424 140719019130240 140719127340619 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 6.3
Current children cumulated vsize (KiB) 1076900

[startup+8.00077 s]
/proc/loadavg: 1.00 1.05 1.07 4/75 14045
/proc/meminfo: memFree=64064/1022884 swapFree=0/0
[pid=14033] ppid=14032 vsize=9172 CPUtime=0
/proc/14033/stat : 14033 (p2cudf-full-1.1) S 14032 14033 1745 0 -1 4202496 459 293 0 0 0 0 0 0 20 0 1 0 118230021 9392128 331 18446744073709551615 4194304 5129932 140734568674832 140734568672976 140680660243550 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/14033/statm: 2293 331 280 229 0 53 0
[pid=14036] ppid=14033 vsize=1067728 CPUtime=7.87
/proc/14036/stat : 14036 (java) S 14033 14033 1745 0 -1 4202496 124410 0 0 0 741 46 0 0 20 0 10 0 118230022 1093353472 116664 18446744073709551615 4194304 4228012 140736337219424 140736337210448 140719127326325 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/14036/statm: 266932 116664 2375 9 0 254282 0
[pid=14036/tid=14037] ppid=14033 vsize=1067728 CPUtime=3.9
/proc/14036/task/14037/stat : 14037 (java) R 14033 14033 1745 0 -1 4202560 47728 0 0 0 373 17 0 0 20 0 10 0 118230023 1093353472 116664 18446744073709551615 4194304 4228012 140736337219424 140719133858824 140719114109688 0 4 0 16800975 0 0 0 -1 0 0 0 2 0 0
[pid=14036/tid=14038] ppid=14033 vsize=1067728 CPUtime=1.24
/proc/14036/task/14038/stat : 14038 (java) S 14033 14033 1745 0 -1 4202560 50453 0 0 0 105 19 0 0 20 0 10 0 118230024 1093353472 116664 18446744073709551615 4194304 4228012 140736337219424 140719026498688 140719127340619 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14039] ppid=14033 vsize=1067728 CPUtime=0
/proc/14036/task/14039/stat : 14039 (java) S 14033 14033 1745 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 118230025 1093353472 116664 18446744073709551615 4194304 4228012 140736337219424 140719025444880 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14040] ppid=14033 vsize=1067728 CPUtime=0
/proc/14036/task/14040/stat : 14040 (java) S 14033 14033 1745 0 -1 4202560 8 0 0 0 0 0 0 0 20 0 10 0 118230025 1093353472 116664 18446744073709551615 4194304 4228012 140736337219424 140719024392096 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14041] ppid=14033 vsize=1067728 CPUtime=0
/proc/14036/task/14041/stat : 14041 (java) S 14033 14033 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 118230028 1093353472 116664 18446744073709551615 4194304 4228012 140736337219424 140719023340528 140719127348256 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14042] ppid=14033 vsize=1067728 CPUtime=1.39
/proc/14036/task/14042/stat : 14042 (java) R 14033 14033 1745 0 -1 4202560 17344 0 0 0 132 7 0 0 20 0 10 0 118230028 1093353472 116664 18446744073709551615 4194304 4228012 140736337219424 140719022275496 140719110558387 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14043] ppid=14033 vsize=1067728 CPUtime=1.29
/proc/14036/task/14043/stat : 14043 (java) R 14033 14033 1745 0 -1 4202560 7594 0 0 0 128 1 0 0 20 0 10 0 118230028 1093353472 116664 18446744073709551615 4194304 4228012 140736337219424 140719021218952 140719110112480 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14044] ppid=14033 vsize=1067728 CPUtime=0
/proc/14036/task/14044/stat : 14044 (java) S 14033 14033 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 118230028 1093353472 116664 18446744073709551615 4194304 4228012 140736337219424 140719020182736 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14045] ppid=14033 vsize=1067728 CPUtime=0
/proc/14036/task/14045/stat : 14045 (java) S 14033 14033 1745 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 118230028 1093353472 116664 18446744073709551615 4194304 4228012 140736337219424 140719019130240 140719127340619 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 7.87
Current children cumulated vsize (KiB) 1076900

[startup+9.60081 s]
/proc/loadavg: 1.00 1.05 1.07 4/75 14045
/proc/meminfo: memFree=60592/1022884 swapFree=0/0
[pid=14033] ppid=14032 vsize=9172 CPUtime=0
/proc/14033/stat : 14033 (p2cudf-full-1.1) S 14032 14033 1745 0 -1 4202496 459 293 0 0 0 0 0 0 20 0 1 0 118230021 9392128 331 18446744073709551615 4194304 5129932 140734568674832 140734568672976 140680660243550 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/14033/statm: 2293 331 280 229 0 53 0
[pid=14036] ppid=14033 vsize=1067728 CPUtime=9.44
/proc/14036/stat : 14036 (java) S 14033 14033 1745 0 -1 4202496 125149 0 0 0 898 46 0 0 20 0 10 0 118230022 1093353472 117056 18446744073709551615 4194304 4228012 140736337219424 140736337210448 140719127326325 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/14036/statm: 266932 117056 2376 9 0 254282 0
[pid=14036/tid=14037] ppid=14033 vsize=1067728 CPUtime=4.6
/proc/14036/task/14037/stat : 14037 (java) R 14033 14033 1745 0 -1 4202560 47772 0 0 0 442 18 0 0 20 0 10 0 118230023 1093353472 117056 18446744073709551615 4194304 4228012 140736337219424 140719133861040 140719031490016 0 4 0 16800975 0 0 0 -1 0 0 0 2 0 0
[pid=14036/tid=14038] ppid=14033 vsize=1067728 CPUtime=1.24
/proc/14036/task/14038/stat : 14038 (java) S 14033 14033 1745 0 -1 4202560 50453 0 0 0 105 19 0 0 20 0 10 0 118230024 1093353472 117056 18446744073709551615 4194304 4228012 140736337219424 140719026498688 140719127340619 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14039] ppid=14033 vsize=1067728 CPUtime=0
/proc/14036/task/14039/stat : 14039 (java) S 14033 14033 1745 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 118230025 1093353472 117056 18446744073709551615 4194304 4228012 140736337219424 140719025444880 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14040] ppid=14033 vsize=1067728 CPUtime=0
/proc/14036/task/14040/stat : 14040 (java) S 14033 14033 1745 0 -1 4202560 8 0 0 0 0 0 0 0 20 0 10 0 118230025 1093353472 117056 18446744073709551615 4194304 4228012 140736337219424 140719024392096 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14041] ppid=14033 vsize=1067728 CPUtime=0
/proc/14036/task/14041/stat : 14041 (java) S 14033 14033 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 118230028 1093353472 117056 18446744073709551615 4194304 4228012 140736337219424 140719023340528 140719127348256 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14042] ppid=14033 vsize=1067728 CPUtime=1.83
/proc/14036/task/14042/stat : 14042 (java) S 14033 14033 1745 0 -1 4202560 17980 0 0 0 176 7 0 0 20 0 10 0 118230028 1093353472 117056 18446744073709551615 4194304 4228012 140736337219424 140719022287888 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14043] ppid=14033 vsize=1067728 CPUtime=1.74
/proc/14036/task/14043/stat : 14043 (java) S 14033 14033 1745 0 -1 4202560 7653 0 0 0 172 2 0 0 20 0 10 0 118230028 1093353472 117056 18446744073709551615 4194304 4228012 140736337219424 140719021235216 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14044] ppid=14033 vsize=1067728 CPUtime=0
/proc/14036/task/14044/stat : 14044 (java) S 14033 14033 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 118230028 1093353472 117056 18446744073709551615 4194304 4228012 140736337219424 140719020182736 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14045] ppid=14033 vsize=1067728 CPUtime=0
/proc/14036/task/14045/stat : 14045 (java) S 14033 14033 1745 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 118230028 1093353472 117056 18446744073709551615 4194304 4228012 140736337219424 140719019130240 140719127340619 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 9.44
Current children cumulated vsize (KiB) 1076900

[startup+10.0057 s]
/proc/loadavg: 1.00 1.05 1.07 1/76 14046
/proc/meminfo: memFree=60592/1022884 swapFree=0/0
[pid=14033] ppid=14032 vsize=9172 CPUtime=0
/proc/14033/stat : 14033 (p2cudf-full-1.1) S 14032 14033 1745 0 -1 4202496 459 293 0 0 0 0 0 0 20 0 1 0 118230021 9392128 331 18446744073709551615 4194304 5129932 140734568674832 140734568672976 140680660243550 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/14033/statm: 2293 331 280 229 0 53 0
[pid=14036] ppid=14033 vsize=1068756 CPUtime=9.55
/proc/14036/stat : 14036 (java) S 14033 14033 1745 0 -1 4202496 125172 0 0 0 908 47 0 0 20 0 11 0 118230022 1094406144 117079 18446744073709551615 4194304 4228012 140736337219424 140736337210448 140719127326325 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/14036/statm: 267189 117079 2377 9 0 254539 0
[pid=14036/tid=14037] ppid=14033 vsize=1068756 CPUtime=4.62
/proc/14036/task/14037/stat : 14037 (java) S 14033 14033 1745 0 -1 4202560 47784 0 0 0 444 18 0 0 20 0 11 0 118230023 1094406144 117079 18446744073709551615 4194304 4228012 140736337219424 140719133860784 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 2 0 0
[pid=14036/tid=14038] ppid=14033 vsize=1068756 CPUtime=1.24
/proc/14036/task/14038/stat : 14038 (java) S 14033 14033 1745 0 -1 4202560 50453 0 0 0 105 19 0 0 20 0 11 0 118230024 1094406144 117079 18446744073709551615 4194304 4228012 140736337219424 140719026498688 140719127340619 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14039] ppid=14033 vsize=1068756 CPUtime=0
/proc/14036/task/14039/stat : 14039 (java) S 14033 14033 1745 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 118230025 1094406144 117079 18446744073709551615 4194304 4228012 140736337219424 140719025444880 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14040] ppid=14033 vsize=1068756 CPUtime=0
/proc/14036/task/14040/stat : 14040 (java) S 14033 14033 1745 0 -1 4202560 8 0 0 0 0 0 0 0 20 0 11 0 118230025 1094406144 117079 18446744073709551615 4194304 4228012 140736337219424 140719024392096 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14041] ppid=14033 vsize=1068756 CPUtime=0
/proc/14036/task/14041/stat : 14041 (java) S 14033 14033 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 118230028 1094406144 117079 18446744073709551615 4194304 4228012 140736337219424 140719023340528 140719127348256 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14042] ppid=14033 vsize=1068756 CPUtime=1.88
/proc/14036/task/14042/stat : 14042 (java) S 14033 14033 1745 0 -1 4202560 17983 0 0 0 180 8 0 0 20 0 11 0 118230028 1094406144 117079 18446744073709551615 4194304 4228012 140736337219424 140719022287888 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14043] ppid=14033 vsize=1068756 CPUtime=1.78
/proc/14036/task/14043/stat : 14043 (java) S 14033 14033 1745 0 -1 4202560 7655 0 0 0 176 2 0 0 20 0 11 0 118230028 1094406144 117079 18446744073709551615 4194304 4228012 140736337219424 140719021235216 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14044] ppid=14033 vsize=1068756 CPUtime=0
/proc/14036/task/14044/stat : 14044 (java) S 14033 14033 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 118230028 1094406144 117079 18446744073709551615 4194304 4228012 140736337219424 140719020182736 140719127339732 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14045] ppid=14033 vsize=1068756 CPUtime=0
/proc/14036/task/14045/stat : 14045 (java) S 14033 14033 1745 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 118230028 1094406144 117079 18446744073709551615 4194304 4228012 140736337219424 140719019130240 140719127340619 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=14036/tid=14046] ppid=14033 vsize=1068756 CPUtime=0
/proc/14036/task/14046/stat : 14046 (java) S 14033 14033 1745 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 11 0 118230991 1094406144 117079 18446744073709551615 4194304 4228012 140736337219424 140719017937072 140719127340619 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 9.55
Current children cumulated vsize (KiB) 1077928

[startup+10.2122 s]
/proc/loadavg: 1.00 1.05 1.07 1/76 14046
/proc/meminfo: memFree=60592/1022884 swapFree=0/0
[pid=14033] ppid=14032 vsize=9172 CPUtime=0
/proc/14033/stat : 14033 (p2cudf-full-1.1) S 14032 14033 1745 0 -1 4202496 459 293 0 0 0 0 0 0 20 0 1 0 118230021 9392128 331 18446744073709551615 4194304 5129932 140734568674832 140734568672976 140680660243550 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/14033/statm: 2293 331 280 229 0 53 0
[pid=14036] ppid=14033 vsize=0 CPUtime=9.56
/proc/14036/stat : 14036 (java) Z 14033 14033 1745 0 -1 4203532 125184 0 0 0 909 47 0 0 20 0 2 0 118230022 0 0 18446744073709551615 0 0 0 0 0 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/14036/statm: 0 0 0 0 0 0 0
[pid=14036/tid=14045] ppid=14033 vsize=0 CPUtime=0.02
/proc/14036/task/14045/stat : 14045 (java) R 14033 14033 1745 0 -1 4203588 1 0 0 0 1 1 0 0 20 0 2 0 118230028 0 0 18446744073709551615 0 0 0 0 0 0 4 0 16800975 18446744073709551615 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 9.56
Current children cumulated vsize (KiB) 9172

Child status: 0
Real time (s): 10.2582
CPU time (s): 9.6246
CPU user time (s): 9.10457
CPU system time (s): 0.520032
CPU usage (%): 93.8237
Max. virtual memory (cumulated for all children) (KiB): 1082096

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 9.10457
system time used= 0.520032
maximum resident set size= 468788
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 125948
page faults= 0
swaps= 0
block input operations= 41408
block output operations= 80
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 702
involuntary context switches= 2652

runsolver used 0.044002 second user time and 0.076004 second system time

The end