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 150 -d 10 -w /tmp/misc2012/2012-09-02-17:21/basic/p2cudf-basic-1.15/embedded/real/56ae4afa-0b33-11df-8a2b-00163e1d94dc.cudf.log.runsolver /home/competition/p2cudf-basic-1.15/p2cudf-basic-1.15 /home/competition/data/real/56ae4afa-0b33-11df-8a2b-00163e1d94dc.cudf /tmp/misc2012/2012-09-02-17:21/basic/p2cudf-basic-1.15/embedded/real/56ae4afa-0b33-11df-8a2b-00163e1d94dc.cudf.result -sum(solution,installedsize),-count(removed) 

Enforcing CPUTime limit (soft limit, will send signal-name then SIGKILL): 150 seconds
Enforcing CPUTime limit (hard limit, will send SIGXCPU): 180 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.55 1.21 1.01 2/64 6855
/proc/meminfo: memFree=552508/1022884 swapFree=0/0
[pid=6855] ppid=6854 vsize=3152 CPUtime=0
/proc/6855/stat : 6855 (runsolver) R 6854 1745 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 1 0 115981968 3227648 32 18446744073709551615 134512640 134586868 4289155952 4289154000 4151432240 0 0 16781316 24578 0 0 0 17 0 0 0 0 0 0
/proc/6855/statm: 788 32 0 19 0 73 0
Current StackSize limit: 8192 KiB


[startup+0.170121 s]
/proc/loadavg: 1.55 1.21 1.01 2/64 6855
/proc/meminfo: memFree=552508/1022884 swapFree=0/0
[pid=6855] ppid=6854 vsize=9172 CPUtime=0
/proc/6855/stat : 6855 (p2cudf-basic-1.) S 6854 6855 1745 0 -1 4202496 463 290 0 0 0 0 0 0 20 0 1 0 115981968 9392128 332 18446744073709551615 4194304 5129932 140736669153504 140736669151648 139820741108830 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/6855/statm: 2293 332 280 229 0 53 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9172

[startup+0.200345 s]
/proc/loadavg: 1.55 1.21 1.01 2/64 6855
/proc/meminfo: memFree=552508/1022884 swapFree=0/0
[pid=6855] ppid=6854 vsize=9172 CPUtime=0
/proc/6855/stat : 6855 (p2cudf-basic-1.) S 6854 6855 1745 0 -1 4202496 463 290 0 0 0 0 0 0 20 0 1 0 115981968 9392128 332 18446744073709551615 4194304 5129932 140736669153504 140736669151648 139820741108830 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/6855/statm: 2293 332 280 229 0 53 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9172

[startup+0.300333 s]
/proc/loadavg: 1.55 1.21 1.01 2/64 6855
/proc/meminfo: memFree=552508/1022884 swapFree=0/0
[pid=6855] ppid=6854 vsize=9172 CPUtime=0
/proc/6855/stat : 6855 (p2cudf-basic-1.) S 6854 6855 1745 0 -1 4202496 463 290 0 0 0 0 0 0 20 0 1 0 115981968 9392128 332 18446744073709551615 4194304 5129932 140736669153504 140736669151648 139820741108830 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/6855/statm: 2293 332 280 229 0 53 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9172

[startup+0.700237 s]
/proc/loadavg: 1.55 1.21 1.01 2/64 6855
/proc/meminfo: memFree=552508/1022884 swapFree=0/0
[pid=6855] ppid=6854 vsize=9172 CPUtime=0
/proc/6855/stat : 6855 (p2cudf-basic-1.) S 6854 6855 1745 0 -1 4202496 463 290 0 0 0 0 0 0 20 0 1 0 115981968 9392128 332 18446744073709551615 4194304 5129932 140736669153504 140736669151648 139820741108830 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/6855/statm: 2293 332 280 229 0 53 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9172

[startup+1.50056 s]
/proc/loadavg: 1.55 1.21 1.01 4/75 6867
/proc/meminfo: memFree=469456/1022884 swapFree=0/0
[pid=6855] ppid=6854 vsize=9172 CPUtime=0
/proc/6855/stat : 6855 (p2cudf-basic-1.) S 6854 6855 1745 0 -1 4202496 463 290 0 0 0 0 0 0 20 0 1 0 115981968 9392128 332 18446744073709551615 4194304 5129932 140736669153504 140736669151648 139820741108830 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/6855/statm: 2293 332 280 229 0 53 0
[pid=6858] ppid=6855 vsize=1059260 CPUtime=1.46
/proc/6858/stat : 6858 (java) S 6855 6855 1745 0 -1 4202496 37984 0 0 0 132 14 0 0 20 0 10 0 115981968 1084682240 34472 18446744073709551615 4194304 4228012 140735826348112 140735826339136 140483538075253 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/6858/statm: 264815 34472 2343 9 0 252165 0
[pid=6858/tid=6859] ppid=6855 vsize=1059260 CPUtime=0.63
/proc/6858/task/6859/stat : 6859 (java) R 6855 6855 1745 0 -1 4202560 17088 0 0 0 56 7 0 0 20 0 10 0 115981969 1084682240 34472 18446744073709551615 4194304 4228012 140735826348112 140483544601248 140483442559450 0 4 0 16800975 0 0 0 -1 0 0 0 2 0 0
[pid=6858/tid=6860] ppid=6855 vsize=1059260 CPUtime=0
/proc/6858/task/6860/stat : 6860 (java) S 6855 6855 1745 0 -1 4202560 4 0 0 0 0 0 0 0 20 0 10 0 115981971 1084682240 34472 18446744073709551615 4194304 4228012 140735826348112 140483437247616 140483538089547 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6861] ppid=6855 vsize=1059260 CPUtime=0
/proc/6858/task/6861/stat : 6861 (java) S 6855 6855 1745 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 10 0 115981971 1084682240 34472 18446744073709551615 4194304 4228012 140735826348112 140483436193808 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6862] ppid=6855 vsize=1059260 CPUtime=0
/proc/6858/task/6862/stat : 6862 (java) S 6855 6855 1745 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 10 0 115981971 1084682240 34472 18446744073709551615 4194304 4228012 140735826348112 140483435141024 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6863] ppid=6855 vsize=1059260 CPUtime=0
/proc/6858/task/6863/stat : 6863 (java) S 6855 6855 1745 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 115981974 1084682240 34472 18446744073709551615 4194304 4228012 140735826348112 140483434089456 140483538097184 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6864] ppid=6855 vsize=1059260 CPUtime=0.4
/proc/6858/task/6864/stat : 6864 (java) R 6855 6855 1745 0 -1 4202560 10116 0 0 0 37 3 0 0 20 0 10 0 115981974 1084682240 34472 18446744073709551615 4194304 4228012 140735826348112 140483433024344 140483524775364 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6865] ppid=6855 vsize=1059260 CPUtime=0.4
/proc/6858/task/6865/stat : 6865 (java) R 6855 6855 1745 0 -1 4202560 9486 0 0 0 37 3 0 0 20 0 10 0 115981974 1084682240 34472 18446744073709551615 4194304 4228012 140735826348112 140483431971864 140483522378936 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6866] ppid=6855 vsize=1059260 CPUtime=0
/proc/6858/task/6866/stat : 6866 (java) S 6855 6855 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115981974 1084682240 34472 18446744073709551615 4194304 4228012 140735826348112 140483430931664 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6867] ppid=6855 vsize=1059260 CPUtime=0
/proc/6858/task/6867/stat : 6867 (java) S 6855 6855 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115981974 1084682240 34472 18446744073709551615 4194304 4228012 140735826348112 140483429879168 140483538089547 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) 1068432

[startup+3.10083 s]
/proc/loadavg: 1.55 1.21 1.01 2/75 6867
/proc/meminfo: memFree=267212/1022884 swapFree=0/0
[pid=6855] ppid=6854 vsize=9172 CPUtime=0
/proc/6855/stat : 6855 (p2cudf-basic-1.) S 6854 6855 1745 0 -1 4202496 463 290 0 0 0 0 0 0 20 0 1 0 115981968 9392128 332 18446744073709551615 4194304 5129932 140736669153504 140736669151648 139820741108830 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/6855/statm: 2293 332 280 229 0 53 0
[pid=6858] ppid=6855 vsize=1056008 CPUtime=3.02
/proc/6858/stat : 6858 (java) S 6855 6855 1745 0 -1 4202496 91186 0 0 0 268 34 0 0 20 0 10 0 115981968 1081352192 85873 18446744073709551615 4194304 4228012 140735826348112 140735826339136 140483538075253 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/6858/statm: 264002 85873 2369 9 0 251352 0
[pid=6858/tid=6859] ppid=6855 vsize=1056008 CPUtime=1.54
/proc/6858/task/6859/stat : 6859 (java) R 6855 6855 1745 0 -1 4202560 47441 0 0 0 136 18 0 0 20 0 10 0 115981969 1081352192 85873 18446744073709551615 4194304 4228012 140735826348112 140483544601280 140483442414210 0 4 0 16800975 0 0 0 -1 0 0 0 4 0 0
[pid=6858/tid=6860] ppid=6855 vsize=1056008 CPUtime=0.37
/proc/6858/task/6860/stat : 6860 (java) S 6855 6855 1745 0 -1 4202560 21883 0 0 0 29 8 0 0 20 0 10 0 115981971 1081352192 85873 18446744073709551615 4194304 4228012 140735826348112 140483437247616 140483538089547 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6861] ppid=6855 vsize=1056008 CPUtime=0
/proc/6858/task/6861/stat : 6861 (java) S 6855 6855 1745 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 115981971 1081352192 85873 18446744073709551615 4194304 4228012 140735826348112 140483436193808 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6862] ppid=6855 vsize=1056008 CPUtime=0
/proc/6858/task/6862/stat : 6862 (java) S 6855 6855 1745 0 -1 4202560 8 0 0 0 0 0 0 0 20 0 10 0 115981971 1081352192 85873 18446744073709551615 4194304 4228012 140735826348112 140483435141024 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6863] ppid=6855 vsize=1056008 CPUtime=0
/proc/6858/task/6863/stat : 6863 (java) S 6855 6855 1745 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 115981974 1081352192 85873 18446744073709551615 4194304 4228012 140735826348112 140483434089456 140483538097184 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6864] ppid=6855 vsize=1056008 CPUtime=0.53
/proc/6858/task/6864/stat : 6864 (java) S 6855 6855 1745 0 -1 4202560 10152 0 0 0 50 3 0 0 20 0 10 0 115981974 1081352192 85873 18446744073709551615 4194304 4228012 140735826348112 140483433036816 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6865] ppid=6855 vsize=1056008 CPUtime=0.56
/proc/6858/task/6865/stat : 6865 (java) S 6855 6855 1745 0 -1 4202560 10417 0 0 0 52 4 0 0 20 0 10 0 115981974 1081352192 85873 18446744073709551615 4194304 4228012 140735826348112 140483431984144 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6866] ppid=6855 vsize=1056008 CPUtime=0
/proc/6858/task/6866/stat : 6866 (java) S 6855 6855 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115981974 1081352192 85873 18446744073709551615 4194304 4228012 140735826348112 140483430931664 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6867] ppid=6855 vsize=1056008 CPUtime=0
/proc/6858/task/6867/stat : 6867 (java) S 6855 6855 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115981974 1081352192 85873 18446744073709551615 4194304 4228012 140735826348112 140483429879168 140483538089547 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 3.02
Current children cumulated vsize (KiB) 1065180

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

[startup+3.20105 s]
/proc/loadavg: 1.55 1.21 1.01 2/75 6867
/proc/meminfo: memFree=267212/1022884 swapFree=0/0
[pid=6855] ppid=6854 vsize=9172 CPUtime=0
/proc/6855/stat : 6855 (p2cudf-basic-1.) S 6854 6855 1745 0 -1 4202496 463 290 0 0 0 0 0 0 20 0 1 0 115981968 9392128 332 18446744073709551615 4194304 5129932 140736669153504 140736669151648 139820741108830 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/6855/statm: 2293 332 280 229 0 53 0
[pid=6858] ppid=6855 vsize=1056008 CPUtime=3.12
/proc/6858/stat : 6858 (java) S 6855 6855 1745 0 -1 4202496 91186 0 0 0 278 34 0 0 20 0 10 0 115981968 1081352192 85873 18446744073709551615 4194304 4228012 140735826348112 140735826339136 140483538075253 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/6858/statm: 264002 85873 2369 9 0 251352 0
[pid=6858/tid=6859] ppid=6855 vsize=1056008 CPUtime=1.64
/proc/6858/task/6859/stat : 6859 (java) R 6855 6855 1745 0 -1 4202560 47441 0 0 0 146 18 0 0 20 0 10 0 115981969 1081352192 85873 18446744073709551615 4194304 4228012 140735826348112 140483544601280 140483442465572 0 4 0 16800975 0 0 0 -1 0 0 0 4 0 0
[pid=6858/tid=6860] ppid=6855 vsize=1056008 CPUtime=0.37
/proc/6858/task/6860/stat : 6860 (java) S 6855 6855 1745 0 -1 4202560 21883 0 0 0 29 8 0 0 20 0 10 0 115981971 1081352192 85873 18446744073709551615 4194304 4228012 140735826348112 140483437247616 140483538089547 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6861] ppid=6855 vsize=1056008 CPUtime=0
/proc/6858/task/6861/stat : 6861 (java) S 6855 6855 1745 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 115981971 1081352192 85873 18446744073709551615 4194304 4228012 140735826348112 140483436193808 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6862] ppid=6855 vsize=1056008 CPUtime=0
/proc/6858/task/6862/stat : 6862 (java) S 6855 6855 1745 0 -1 4202560 8 0 0 0 0 0 0 0 20 0 10 0 115981971 1081352192 85873 18446744073709551615 4194304 4228012 140735826348112 140483435141024 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6863] ppid=6855 vsize=1056008 CPUtime=0
/proc/6858/task/6863/stat : 6863 (java) S 6855 6855 1745 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 115981974 1081352192 85873 18446744073709551615 4194304 4228012 140735826348112 140483434089456 140483538097184 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6864] ppid=6855 vsize=1056008 CPUtime=0.53
/proc/6858/task/6864/stat : 6864 (java) S 6855 6855 1745 0 -1 4202560 10152 0 0 0 50 3 0 0 20 0 10 0 115981974 1081352192 85873 18446744073709551615 4194304 4228012 140735826348112 140483433036816 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6865] ppid=6855 vsize=1056008 CPUtime=0.56
/proc/6858/task/6865/stat : 6865 (java) S 6855 6855 1745 0 -1 4202560 10417 0 0 0 52 4 0 0 20 0 10 0 115981974 1081352192 85873 18446744073709551615 4194304 4228012 140735826348112 140483431984144 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6866] ppid=6855 vsize=1056008 CPUtime=0
/proc/6858/task/6866/stat : 6866 (java) S 6855 6855 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115981974 1081352192 85873 18446744073709551615 4194304 4228012 140735826348112 140483430931664 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6867] ppid=6855 vsize=1056008 CPUtime=0
/proc/6858/task/6867/stat : 6867 (java) S 6855 6855 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115981974 1081352192 85873 18446744073709551615 4194304 4228012 140735826348112 140483429879168 140483538089547 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 3.12
Current children cumulated vsize (KiB) 1065180

[startup+4.80057 s]
/proc/loadavg: 1.50 1.21 1.01 2/75 6867
/proc/meminfo: memFree=120396/1022884 swapFree=0/0
[pid=6855] ppid=6854 vsize=9172 CPUtime=0
/proc/6855/stat : 6855 (p2cudf-basic-1.) S 6854 6855 1745 0 -1 4202496 463 290 0 0 0 0 0 0 20 0 1 0 115981968 9392128 332 18446744073709551615 4194304 5129932 140736669153504 140736669151648 139820741108830 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/6855/statm: 2293 332 280 229 0 53 0
[pid=6858] ppid=6855 vsize=1056008 CPUtime=4.66
/proc/6858/stat : 6858 (java) S 6855 6855 1745 0 -1 4202496 115974 0 0 0 424 42 0 0 20 0 10 0 115981968 1081352192 110661 18446744073709551615 4194304 4228012 140735826348112 140735826339136 140483538075253 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/6858/statm: 264002 110661 2369 9 0 251352 0
[pid=6858/tid=6859] ppid=6855 vsize=1056008 CPUtime=2.55
/proc/6858/task/6859/stat : 6859 (java) R 6855 6855 1745 0 -1 4202560 47479 0 0 0 235 20 0 0 20 0 10 0 115981969 1081352192 110661 18446744073709551615 4194304 4228012 140735826348112 140483544598512 140735827409213 0 4 0 16800975 0 0 0 -1 0 0 0 8 0 0
[pid=6858/tid=6860] ppid=6855 vsize=1056008 CPUtime=0.99
/proc/6858/task/6860/stat : 6860 (java) S 6855 6855 1745 0 -1 4202560 46633 0 0 0 84 15 0 0 20 0 10 0 115981971 1081352192 110661 18446744073709551615 4194304 4228012 140735826348112 140483437247616 140483538089547 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6861] ppid=6855 vsize=1056008 CPUtime=0
/proc/6858/task/6861/stat : 6861 (java) S 6855 6855 1745 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 115981971 1081352192 110661 18446744073709551615 4194304 4228012 140735826348112 140483436193808 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6862] ppid=6855 vsize=1056008 CPUtime=0
/proc/6858/task/6862/stat : 6862 (java) S 6855 6855 1745 0 -1 4202560 8 0 0 0 0 0 0 0 20 0 10 0 115981971 1081352192 110661 18446744073709551615 4194304 4228012 140735826348112 140483435141024 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6863] ppid=6855 vsize=1056008 CPUtime=0
/proc/6858/task/6863/stat : 6863 (java) S 6855 6855 1745 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 115981974 1081352192 110661 18446744073709551615 4194304 4228012 140735826348112 140483434089456 140483538097184 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6864] ppid=6855 vsize=1056008 CPUtime=0.53
/proc/6858/task/6864/stat : 6864 (java) S 6855 6855 1745 0 -1 4202560 10152 0 0 0 50 3 0 0 20 0 10 0 115981974 1081352192 110661 18446744073709551615 4194304 4228012 140735826348112 140483433036816 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6865] ppid=6855 vsize=1056008 CPUtime=0.56
/proc/6858/task/6865/stat : 6865 (java) S 6855 6855 1745 0 -1 4202560 10417 0 0 0 52 4 0 0 20 0 10 0 115981974 1081352192 110661 18446744073709551615 4194304 4228012 140735826348112 140483431984144 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6866] ppid=6855 vsize=1056008 CPUtime=0
/proc/6858/task/6866/stat : 6866 (java) S 6855 6855 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115981974 1081352192 110661 18446744073709551615 4194304 4228012 140735826348112 140483430931664 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6867] ppid=6855 vsize=1056008 CPUtime=0
/proc/6858/task/6867/stat : 6867 (java) S 6855 6855 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115981974 1081352192 110661 18446744073709551615 4194304 4228012 140735826348112 140483429879168 140483538089547 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 4.66
Current children cumulated vsize (KiB) 1065180

[startup+5.60389 s]
/proc/loadavg: 1.50 1.21 1.01 2/76 6868
/proc/meminfo: memFree=93728/1022884 swapFree=0/0
[pid=6855] ppid=6854 vsize=9172 CPUtime=0
/proc/6855/stat : 6855 (p2cudf-basic-1.) S 6854 6855 1745 0 -1 4202496 463 290 0 0 0 0 0 0 20 0 1 0 115981968 9392128 332 18446744073709551615 4194304 5129932 140736669153504 140736669151648 139820741108830 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/6855/statm: 2293 332 280 229 0 53 0
[pid=6858] ppid=6855 vsize=1058064 CPUtime=5.37
/proc/6858/stat : 6858 (java) S 6855 6855 1745 0 -1 4202496 116462 0 0 0 494 43 0 0 20 0 11 0 115981968 1083457536 111147 18446744073709551615 4194304 4228012 140735826348112 140735826339136 140483538075253 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/6858/statm: 264516 111147 2375 9 0 251866 0
[pid=6858/tid=6859] ppid=6855 vsize=1058064 CPUtime=2.87
/proc/6858/task/6859/stat : 6859 (java) S 6855 6855 1745 0 -1 4202560 47800 0 0 0 267 20 0 0 20 0 11 0 115981969 1083457536 111147 18446744073709551615 4194304 4228012 140735826348112 140483544609712 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 10 0 0
[pid=6858/tid=6860] ppid=6855 vsize=1058064 CPUtime=0.99
/proc/6858/task/6860/stat : 6860 (java) S 6855 6855 1745 0 -1 4202560 46634 0 0 0 84 15 0 0 20 0 11 0 115981971 1083457536 111147 18446744073709551615 4194304 4228012 140735826348112 140483437247616 140483538089547 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6861] ppid=6855 vsize=1058064 CPUtime=0
/proc/6858/task/6861/stat : 6861 (java) S 6855 6855 1745 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 115981971 1083457536 111147 18446744073709551615 4194304 4228012 140735826348112 140483436193808 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6862] ppid=6855 vsize=1058064 CPUtime=0
/proc/6858/task/6862/stat : 6862 (java) S 6855 6855 1745 0 -1 4202560 8 0 0 0 0 0 0 0 20 0 11 0 115981971 1083457536 111147 18446744073709551615 4194304 4228012 140735826348112 140483435141024 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6863] ppid=6855 vsize=1058064 CPUtime=0
/proc/6858/task/6863/stat : 6863 (java) S 6855 6855 1745 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 115981974 1083457536 111147 18446744073709551615 4194304 4228012 140735826348112 140483434089456 140483538097184 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6864] ppid=6855 vsize=1058064 CPUtime=0.71
/proc/6858/task/6864/stat : 6864 (java) S 6855 6855 1745 0 -1 4202560 10179 0 0 0 68 3 0 0 20 0 11 0 115981974 1083457536 111147 18446744073709551615 4194304 4228012 140735826348112 140483433036816 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6865] ppid=6855 vsize=1058064 CPUtime=0.76
/proc/6858/task/6865/stat : 6865 (java) S 6855 6855 1745 0 -1 4202560 10544 0 0 0 72 4 0 0 20 0 11 0 115981974 1083457536 111147 18446744073709551615 4194304 4228012 140735826348112 140483431984144 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6866] ppid=6855 vsize=1058064 CPUtime=0
/proc/6858/task/6866/stat : 6866 (java) S 6855 6855 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 115981974 1083457536 111147 18446744073709551615 4194304 4228012 140735826348112 140483430931664 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6867] ppid=6855 vsize=1058064 CPUtime=0
/proc/6858/task/6867/stat : 6867 (java) S 6855 6855 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 115981974 1083457536 111147 18446744073709551615 4194304 4228012 140735826348112 140483429879168 140483538089547 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 5.37
Current children cumulated vsize (KiB) 1067236

[startup+6.00085 s]
/proc/loadavg: 1.50 1.21 1.01 2/76 6868
/proc/meminfo: memFree=93728/1022884 swapFree=0/0
[pid=6855] ppid=6854 vsize=9172 CPUtime=0
/proc/6855/stat : 6855 (p2cudf-basic-1.) S 6854 6855 1745 0 -1 4202496 463 290 0 0 0 0 0 0 20 0 1 0 115981968 9392128 332 18446744073709551615 4194304 5129932 140736669153504 140736669151648 139820741108830 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/6855/statm: 2293 332 280 229 0 53 0
[pid=6858] ppid=6855 vsize=1058064 CPUtime=5.37
/proc/6858/stat : 6858 (java) S 6855 6855 1745 0 -1 4202496 116462 0 0 0 494 43 0 0 20 0 11 0 115981968 1083457536 111147 18446744073709551615 4194304 4228012 140735826348112 140735826339136 140483538075253 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/6858/statm: 264516 111147 2375 9 0 251866 0
[pid=6858/tid=6859] ppid=6855 vsize=1058064 CPUtime=2.87
/proc/6858/task/6859/stat : 6859 (java) S 6855 6855 1745 0 -1 4202560 47800 0 0 0 267 20 0 0 20 0 11 0 115981969 1083457536 111147 18446744073709551615 4194304 4228012 140735826348112 140483544609712 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 10 0 0
[pid=6858/tid=6860] ppid=6855 vsize=1058064 CPUtime=0.99
/proc/6858/task/6860/stat : 6860 (java) S 6855 6855 1745 0 -1 4202560 46634 0 0 0 84 15 0 0 20 0 11 0 115981971 1083457536 111147 18446744073709551615 4194304 4228012 140735826348112 140483437247616 140483538089547 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6861] ppid=6855 vsize=1058064 CPUtime=0
/proc/6858/task/6861/stat : 6861 (java) S 6855 6855 1745 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 115981971 1083457536 111147 18446744073709551615 4194304 4228012 140735826348112 140483436193808 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6862] ppid=6855 vsize=1058064 CPUtime=0
/proc/6858/task/6862/stat : 6862 (java) S 6855 6855 1745 0 -1 4202560 8 0 0 0 0 0 0 0 20 0 11 0 115981971 1083457536 111147 18446744073709551615 4194304 4228012 140735826348112 140483435141024 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6863] ppid=6855 vsize=1058064 CPUtime=0
/proc/6858/task/6863/stat : 6863 (java) S 6855 6855 1745 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 115981974 1083457536 111147 18446744073709551615 4194304 4228012 140735826348112 140483434089456 140483538097184 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6864] ppid=6855 vsize=1058064 CPUtime=0.71
/proc/6858/task/6864/stat : 6864 (java) S 6855 6855 1745 0 -1 4202560 10179 0 0 0 68 3 0 0 20 0 11 0 115981974 1083457536 111147 18446744073709551615 4194304 4228012 140735826348112 140483433036816 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6865] ppid=6855 vsize=1058064 CPUtime=0.76
/proc/6858/task/6865/stat : 6865 (java) S 6855 6855 1745 0 -1 4202560 10544 0 0 0 72 4 0 0 20 0 11 0 115981974 1083457536 111147 18446744073709551615 4194304 4228012 140735826348112 140483431984144 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6866] ppid=6855 vsize=1058064 CPUtime=0
/proc/6858/task/6866/stat : 6866 (java) S 6855 6855 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 115981974 1083457536 111147 18446744073709551615 4194304 4228012 140735826348112 140483430931664 140483538088660 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6858/tid=6867] ppid=6855 vsize=1058064 CPUtime=0
/proc/6858/task/6867/stat : 6867 (java) S 6855 6855 1745 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 115981974 1083457536 111147 18446744073709551615 4194304 4228012 140735826348112 140483429879168 140483538089547 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 5.37
Current children cumulated vsize (KiB) 1067236

[startup+6.10117 s]
/proc/loadavg: 1.50 1.21 1.01 2/76 6868
/proc/meminfo: memFree=93728/1022884 swapFree=0/0
[pid=6855] ppid=6854 vsize=9172 CPUtime=0
/proc/6855/stat : 6855 (p2cudf-basic-1.) S 6854 6855 1745 0 -1 4202496 463 290 0 0 0 0 0 0 20 0 1 0 115981968 9392128 332 18446744073709551615 4194304 5129932 140736669153504 140736669151648 139820741108830 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/6855/statm: 2293 332 280 229 0 53 0
[pid=6858] ppid=6855 vsize=0 CPUtime=5.43
/proc/6858/stat : 6858 (java) Z 6855 6855 1745 0 -1 4203532 116473 0 0 0 498 45 0 0 20 0 2 0 115981968 0 0 18446744073709551615 0 0 0 0 0 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/6858/statm: 0 0 0 0 0 0 0
[pid=6858/tid=6865] ppid=6855 vsize=0 CPUtime=0.82
/proc/6858/task/6865/stat : 6865 (java) R 6855 6855 1745 0 -1 4203588 10544 0 0 0 76 6 0 0 20 0 2 0 115981974 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) 5.43
Current children cumulated vsize (KiB) 9172

Child status: 0
Real time (s): 6.11614
CPU time (s): 5.46434
CPU user time (s): 4.99231
CPU system time (s): 0.472029
CPU usage (%): 89.3429
Max. virtual memory (cumulated for all children) (KiB): 1068432

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.99231
system time used= 0.472029
maximum resident set size= 444624
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 117237
page faults= 0
swaps= 0
block input operations= 44272
block output operations= 88
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 641
involuntary context switches= 1407

runsolver used 0.020001 second user time and 0.040002 second system time

The end