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/4f84e9c6-a79c-11e0-9eb7-00163e1e087d.cudf.log.runsolver /home/competition/p2cudf-basic-1.15/p2cudf-basic-1.15 /home/competition/data/real/4f84e9c6-a79c-11e0-9eb7-00163e1e087d.cudf /tmp/misc2012/2012-09-02-17:21/basic/p2cudf-basic-1.15/embedded/real/4f84e9c6-a79c-11e0-9eb7-00163e1e087d.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.36 1.15 0.98 2/59 24156
/proc/meminfo: memFree=548016/1022884 swapFree=0/0
[pid=24156] ppid=24155 vsize=3152 CPUtime=0
/proc/24156/stat : 24156 (runsolver) R 24155 1733 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 1 0 115984669 3227648 33 18446744073709551615 134512640 134586868 4292671440 4292669488 4151743536 0 0 16781316 24578 0 0 0 17 0 0 0 0 0 0
/proc/24156/statm: 788 33 0 19 0 73 0
Current StackSize limit: 8192 KiB


[startup+0.192842 s]
/proc/loadavg: 1.36 1.15 0.98 2/59 24156
/proc/meminfo: memFree=548016/1022884 swapFree=0/0
[pid=24156] ppid=24155 vsize=9172 CPUtime=0
/proc/24156/stat : 24156 (p2cudf-basic-1.) S 24155 24156 1733 0 -1 4202496 461 290 0 0 0 0 0 0 20 0 1 0 115984669 9392128 332 18446744073709551615 4194304 5129932 140734834770576 140734834768720 139828854174814 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24156/statm: 2293 332 280 229 0 53 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9172

[startup+0.200356 s]
/proc/loadavg: 1.36 1.15 0.98 2/59 24156
/proc/meminfo: memFree=548016/1022884 swapFree=0/0
[pid=24156] ppid=24155 vsize=9172 CPUtime=0
/proc/24156/stat : 24156 (p2cudf-basic-1.) S 24155 24156 1733 0 -1 4202496 461 290 0 0 0 0 0 0 20 0 1 0 115984669 9392128 332 18446744073709551615 4194304 5129932 140734834770576 140734834768720 139828854174814 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24156/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.36 1.15 0.98 2/59 24156
/proc/meminfo: memFree=548016/1022884 swapFree=0/0
[pid=24156] ppid=24155 vsize=9172 CPUtime=0
/proc/24156/stat : 24156 (p2cudf-basic-1.) S 24155 24156 1733 0 -1 4202496 461 290 0 0 0 0 0 0 20 0 1 0 115984669 9392128 332 18446744073709551615 4194304 5129932 140734834770576 140734834768720 139828854174814 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24156/statm: 2293 332 280 229 0 53 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9172

[startup+0.7003 s]
/proc/loadavg: 1.36 1.15 0.98 2/59 24156
/proc/meminfo: memFree=548016/1022884 swapFree=0/0
[pid=24156] ppid=24155 vsize=9172 CPUtime=0
/proc/24156/stat : 24156 (p2cudf-basic-1.) S 24155 24156 1733 0 -1 4202496 461 290 0 0 0 0 0 0 20 0 1 0 115984669 9392128 332 18446744073709551615 4194304 5129932 140734834770576 140734834768720 139828854174814 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24156/statm: 2293 332 280 229 0 53 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9172

[startup+1.50057 s]
/proc/loadavg: 1.33 1.14 0.98 4/70 24168
/proc/meminfo: memFree=469924/1022884 swapFree=0/0
[pid=24156] ppid=24155 vsize=9172 CPUtime=0
/proc/24156/stat : 24156 (p2cudf-basic-1.) S 24155 24156 1733 0 -1 4202496 461 290 0 0 0 0 0 0 20 0 1 0 115984669 9392128 332 18446744073709551615 4194304 5129932 140734834770576 140734834768720 139828854174814 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24156/statm: 2293 332 280 229 0 53 0
[pid=24159] ppid=24156 vsize=1051220 CPUtime=1.46
/proc/24159/stat : 24159 (java) S 24156 24156 1733 0 -1 4202496 37878 0 0 0 132 14 0 0 20 0 10 0 115984669 1076449280 34502 18446744073709551615 4194304 4228012 140735855984736 140735855975760 140375080246901 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24159/statm: 262805 34502 2349 9 0 250155 0
[pid=24159/tid=24160] ppid=24156 vsize=1051220 CPUtime=0.64
/proc/24159/task/24160/stat : 24160 (java) R 24156 24156 1733 0 -1 4202560 17158 0 0 0 56 8 0 0 20 0 10 0 115984670 1076449280 34502 18446744073709551615 4194304 4228012 140735855984736 140375086772896 140375063741877 0 4 0 16800975 0 0 0 -1 0 0 0 2 0 0
[pid=24159/tid=24161] ppid=24156 vsize=1051220 CPUtime=0
/proc/24159/task/24161/stat : 24161 (java) S 24156 24156 1733 0 -1 4202560 3 0 0 0 0 0 0 0 20 0 10 0 115984671 1076449280 34502 18446744073709551615 4194304 4228012 140735855984736 140374979419264 140375080261195 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24162] ppid=24156 vsize=1051220 CPUtime=0
/proc/24159/task/24162/stat : 24162 (java) S 24156 24156 1733 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 10 0 115984672 1076449280 34502 18446744073709551615 4194304 4228012 140735855984736 140374978365456 140375080260308 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24163] ppid=24156 vsize=1051220 CPUtime=0
/proc/24159/task/24163/stat : 24163 (java) S 24156 24156 1733 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 10 0 115984672 1076449280 34502 18446744073709551615 4194304 4228012 140735855984736 140374977312672 140375080260308 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24164] ppid=24156 vsize=1051220 CPUtime=0
/proc/24159/task/24164/stat : 24164 (java) S 24156 24156 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 115984675 1076449280 34502 18446744073709551615 4194304 4228012 140735855984736 140374976261104 140375080268832 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24165] ppid=24156 vsize=1051220 CPUtime=0.41
/proc/24159/task/24165/stat : 24165 (java) R 24156 24156 1733 0 -1 4202560 10542 0 0 0 37 4 0 0 20 0 10 0 115984675 1076449280 34502 18446744073709551615 4194304 4228012 140735855984736 140374975196040 140375064520951 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24166] ppid=24156 vsize=1051220 CPUtime=0.39
/proc/24159/task/24166/stat : 24166 (java) R 24156 24156 1733 0 -1 4202560 8887 0 0 0 37 2 0 0 20 0 10 0 115984675 1076449280 34502 18446744073709551615 4194304 4228012 140735855984736 140374974143320 140375064551074 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24167] ppid=24156 vsize=1051220 CPUtime=0
/proc/24159/task/24167/stat : 24167 (java) S 24156 24156 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115984675 1076449280 34502 18446744073709551615 4194304 4228012 140735855984736 140374973103312 140375080260308 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24168] ppid=24156 vsize=1051220 CPUtime=0
/proc/24159/task/24168/stat : 24168 (java) S 24156 24156 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115984675 1076449280 34502 18446744073709551615 4194304 4228012 140735855984736 140374972050816 140375080261195 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) 1060392

[startup+3.10057 s]
/proc/loadavg: 1.33 1.14 0.98 2/70 24168
/proc/meminfo: memFree=261728/1022884 swapFree=0/0
[pid=24156] ppid=24155 vsize=9172 CPUtime=0
/proc/24156/stat : 24156 (p2cudf-basic-1.) S 24155 24156 1733 0 -1 4202496 461 290 0 0 0 0 0 0 20 0 1 0 115984669 9392128 332 18446744073709551615 4194304 5129932 140734834770576 140734834768720 139828854174814 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24156/statm: 2293 332 280 229 0 53 0
[pid=24159] ppid=24156 vsize=1047992 CPUtime=3.05
/proc/24159/stat : 24159 (java) S 24156 24156 1733 0 -1 4202496 99086 0 0 0 279 26 0 0 20 0 10 0 115984669 1073143808 94625 18446744073709551615 4194304 4228012 140735855984736 140735855975760 140375080246901 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24159/statm: 261998 94625 2370 9 0 249348 0
[pid=24159/tid=24160] ppid=24156 vsize=1047992 CPUtime=1.47
/proc/24159/task/24160/stat : 24160 (java) S 24156 24156 1733 0 -1 4202560 47430 0 0 0 132 15 0 0 20 0 10 0 115984670 1073143808 94625 18446744073709551615 4194304 4228012 140735855984736 140375086780848 140375080260308 0 4 0 16800975 0 0 0 -1 0 0 0 2 0 0
[pid=24159/tid=24161] ppid=24156 vsize=1047992 CPUtime=0.48
/proc/24159/task/24161/stat : 24161 (java) R 24156 24156 1733 0 -1 4202560 30396 0 0 0 44 4 0 0 20 0 10 0 115984671 1073143808 94625 18446744073709551615 4194304 4228012 140735855984736 140374979418640 140375064557490 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24162] ppid=24156 vsize=1047992 CPUtime=0
/proc/24159/task/24162/stat : 24162 (java) S 24156 24156 1733 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 10 0 115984672 1073143808 94625 18446744073709551615 4194304 4228012 140735855984736 140374978365456 140375080260308 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24163] ppid=24156 vsize=1047992 CPUtime=0
/proc/24159/task/24163/stat : 24163 (java) S 24156 24156 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 115984672 1073143808 94625 18446744073709551615 4194304 4228012 140735855984736 140374977312672 140375080260308 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24164] ppid=24156 vsize=1047992 CPUtime=0
/proc/24159/task/24164/stat : 24164 (java) S 24156 24156 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 115984675 1073143808 94625 18446744073709551615 4194304 4228012 140735855984736 140374976261104 140375080268832 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24165] ppid=24156 vsize=1047992 CPUtime=0.52
/proc/24159/task/24165/stat : 24165 (java) S 24156 24156 1733 0 -1 4202560 10738 0 0 0 48 4 0 0 20 0 10 0 115984675 1073143808 94625 18446744073709551615 4194304 4228012 140735855984736 140374975208464 140375080260308 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24166] ppid=24156 vsize=1047992 CPUtime=0.54
/proc/24159/task/24166/stat : 24166 (java) S 24156 24156 1733 0 -1 4202560 9231 0 0 0 52 2 0 0 20 0 10 0 115984675 1073143808 94625 18446744073709551615 4194304 4228012 140735855984736 140374974155792 140375080260308 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24167] ppid=24156 vsize=1047992 CPUtime=0
/proc/24159/task/24167/stat : 24167 (java) S 24156 24156 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115984675 1073143808 94625 18446744073709551615 4194304 4228012 140735855984736 140374973103312 140375080260308 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24168] ppid=24156 vsize=1047992 CPUtime=0
/proc/24159/task/24168/stat : 24168 (java) S 24156 24156 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115984675 1073143808 94625 18446744073709551615 4194304 4228012 140735855984736 140374972050816 140375080261195 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 3.05
Current children cumulated vsize (KiB) 1057164

[startup+6.30059 s]
/proc/loadavg: 1.46 1.18 1.00 4/70 24168
/proc/meminfo: memFree=87880/1022884 swapFree=0/0
[pid=24156] ppid=24155 vsize=9172 CPUtime=0
/proc/24156/stat : 24156 (p2cudf-basic-1.) S 24155 24156 1733 0 -1 4202496 461 290 0 0 0 0 0 0 20 0 1 0 115984669 9392128 332 18446744073709551615 4194304 5129932 140734834770576 140734834768720 139828854174814 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24156/statm: 2293 332 280 229 0 53 0
[pid=24159] ppid=24156 vsize=1047992 CPUtime=6.18
/proc/24159/stat : 24159 (java) S 24156 24156 1733 0 -1 4202496 117085 0 0 0 586 32 0 0 20 0 10 0 115984669 1073143808 111850 18446744073709551615 4194304 4228012 140735855984736 140735855975760 140375080246901 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24159/statm: 261998 111850 2376 9 0 249348 0
[pid=24159/tid=24160] ppid=24156 vsize=1047992 CPUtime=3.03
/proc/24159/task/24160/stat : 24160 (java) R 24156 24156 1733 0 -1 4202560 47732 0 0 0 286 17 0 0 20 0 10 0 115984670 1073143808 111850 18446744073709551615 4194304 4228012 140735855984736 140375086781000 140374985154281 0 4 0 16800975 0 0 0 -1 0 0 0 4 0 0
[pid=24159/tid=24161] ppid=24156 vsize=1047992 CPUtime=0.83
/proc/24159/task/24161/stat : 24161 (java) S 24156 24156 1733 0 -1 4202560 47074 0 0 0 76 7 0 0 20 0 10 0 115984671 1073143808 111850 18446744073709551615 4194304 4228012 140735855984736 140374979419264 140375080261195 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24162] ppid=24156 vsize=1047992 CPUtime=0
/proc/24159/task/24162/stat : 24162 (java) S 24156 24156 1733 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 10 0 115984672 1073143808 111850 18446744073709551615 4194304 4228012 140735855984736 140374978365456 140375080260308 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24163] ppid=24156 vsize=1047992 CPUtime=0
/proc/24159/task/24163/stat : 24163 (java) S 24156 24156 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 115984672 1073143808 111850 18446744073709551615 4194304 4228012 140735855984736 140374977312672 140375080260308 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24164] ppid=24156 vsize=1047992 CPUtime=0
/proc/24159/task/24164/stat : 24164 (java) S 24156 24156 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 115984675 1073143808 111850 18446744073709551615 4194304 4228012 140735855984736 140374976261104 140375080268832 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24165] ppid=24156 vsize=1047992 CPUtime=1.18
/proc/24159/task/24165/stat : 24165 (java) R 24156 24156 1733 0 -1 4202560 11606 0 0 0 113 5 0 0 20 0 10 0 115984675 1073143808 111850 18446744073709551615 4194304 4228012 140735855984736 140374975208208 140375064045481 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24166] ppid=24156 vsize=1047992 CPUtime=1.12
/proc/24159/task/24166/stat : 24166 (java) R 24156 24156 1733 0 -1 4202560 9382 0 0 0 110 2 0 0 20 0 10 0 115984675 1073143808 111850 18446744073709551615 4194304 4228012 140735855984736 140374974155536 140375066761381 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24167] ppid=24156 vsize=1047992 CPUtime=0
/proc/24159/task/24167/stat : 24167 (java) S 24156 24156 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115984675 1073143808 111850 18446744073709551615 4194304 4228012 140735855984736 140374973103312 140375080260308 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24168] ppid=24156 vsize=1047992 CPUtime=0
/proc/24159/task/24168/stat : 24168 (java) S 24156 24156 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115984675 1073143808 111850 18446744073709551615 4194304 4228012 140735855984736 140374972050816 140375080261195 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 6.18
Current children cumulated vsize (KiB) 1057164

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

[startup+6.40075 s]
/proc/loadavg: 1.46 1.18 1.00 4/70 24168
/proc/meminfo: memFree=87880/1022884 swapFree=0/0
[pid=24156] ppid=24155 vsize=9172 CPUtime=0
/proc/24156/stat : 24156 (p2cudf-basic-1.) S 24155 24156 1733 0 -1 4202496 461 290 0 0 0 0 0 0 20 0 1 0 115984669 9392128 332 18446744073709551615 4194304 5129932 140734834770576 140734834768720 139828854174814 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24156/statm: 2293 332 280 229 0 53 0
[pid=24159] ppid=24156 vsize=1047992 CPUtime=6.28
/proc/24159/stat : 24159 (java) S 24156 24156 1733 0 -1 4202496 117092 0 0 0 596 32 0 0 20 0 10 0 115984669 1073143808 111857 18446744073709551615 4194304 4228012 140735855984736 140735855975760 140375080246901 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24159/statm: 261998 111857 2376 9 0 249348 0
[pid=24159/tid=24160] ppid=24156 vsize=1047992 CPUtime=3.07
/proc/24159/task/24160/stat : 24160 (java) R 24156 24156 1733 0 -1 4202560 47732 0 0 0 290 17 0 0 20 0 10 0 115984670 1073143808 111857 18446744073709551615 4194304 4228012 140735855984736 140375086781528 140374984446247 0 4 0 16800975 0 0 0 -1 0 0 0 4 0 0
[pid=24159/tid=24161] ppid=24156 vsize=1047992 CPUtime=0.83
/proc/24159/task/24161/stat : 24161 (java) S 24156 24156 1733 0 -1 4202560 47074 0 0 0 76 7 0 0 20 0 10 0 115984671 1073143808 111857 18446744073709551615 4194304 4228012 140735855984736 140374979419264 140375080261195 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24162] ppid=24156 vsize=1047992 CPUtime=0
/proc/24159/task/24162/stat : 24162 (java) S 24156 24156 1733 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 10 0 115984672 1073143808 111857 18446744073709551615 4194304 4228012 140735855984736 140374978365456 140375080260308 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24163] ppid=24156 vsize=1047992 CPUtime=0
/proc/24159/task/24163/stat : 24163 (java) S 24156 24156 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 115984672 1073143808 111857 18446744073709551615 4194304 4228012 140735855984736 140374977312672 140375080260308 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24164] ppid=24156 vsize=1047992 CPUtime=0
/proc/24159/task/24164/stat : 24164 (java) S 24156 24156 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 115984675 1073143808 111857 18446744073709551615 4194304 4228012 140735855984736 140374976261104 140375080268832 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24165] ppid=24156 vsize=1047992 CPUtime=1.22
/proc/24159/task/24165/stat : 24165 (java) R 24156 24156 1733 0 -1 4202560 11612 0 0 0 117 5 0 0 20 0 10 0 115984675 1073143808 111857 18446744073709551615 4194304 4228012 140735855984736 140374975208208 140375064450497 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24166] ppid=24156 vsize=1047992 CPUtime=1.13
/proc/24159/task/24166/stat : 24166 (java) S 24156 24156 1733 0 -1 4202560 9383 0 0 0 111 2 0 0 20 0 10 0 115984675 1073143808 111857 18446744073709551615 4194304 4228012 140735855984736 140374974155792 140375080260308 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24167] ppid=24156 vsize=1047992 CPUtime=0
/proc/24159/task/24167/stat : 24167 (java) S 24156 24156 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115984675 1073143808 111857 18446744073709551615 4194304 4228012 140735855984736 140374973103312 140375080260308 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24168] ppid=24156 vsize=1047992 CPUtime=0
/proc/24159/task/24168/stat : 24168 (java) S 24156 24156 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115984675 1073143808 111857 18446744073709551615 4194304 4228012 140735855984736 140374972050816 140375080261195 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 6.28
Current children cumulated vsize (KiB) 1057164

[startup+6.80065 s]
/proc/loadavg: 1.46 1.18 1.00 4/70 24168
/proc/meminfo: memFree=87632/1022884 swapFree=0/0
[pid=24156] ppid=24155 vsize=9172 CPUtime=0
/proc/24156/stat : 24156 (p2cudf-basic-1.) S 24155 24156 1733 0 -1 4202496 461 290 0 0 0 0 0 0 20 0 1 0 115984669 9392128 332 18446744073709551615 4194304 5129932 140734834770576 140734834768720 139828854174814 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24156/statm: 2293 332 280 229 0 53 0
[pid=24159] ppid=24156 vsize=1049020 CPUtime=6.58
/proc/24159/stat : 24159 (java) S 24156 24156 1733 0 -1 4202496 117171 0 0 0 626 32 0 0 20 0 11 0 115984669 1074196480 111936 18446744073709551615 4194304 4228012 140735855984736 140735855975760 140375080246901 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24159/statm: 262255 111936 2377 9 0 249605 0
[pid=24159/tid=24160] ppid=24156 vsize=1049020 CPUtime=3.23
/proc/24159/task/24160/stat : 24160 (java) S 24156 24156 1733 0 -1 4202560 47781 0 0 0 306 17 0 0 20 0 11 0 115984670 1074196480 111936 18446744073709551615 4194304 4228012 140735855984736 140375086781360 140375080260308 0 4 0 16800975 0 0 0 -1 0 0 0 4 0 0
[pid=24159/tid=24161] ppid=24156 vsize=1049020 CPUtime=0.83
/proc/24159/task/24161/stat : 24161 (java) S 24156 24156 1733 0 -1 4202560 47074 0 0 0 76 7 0 0 20 0 11 0 115984671 1074196480 111936 18446744073709551615 4194304 4228012 140735855984736 140374979419264 140375080261195 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24162] ppid=24156 vsize=1049020 CPUtime=0
/proc/24159/task/24162/stat : 24162 (java) S 24156 24156 1733 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 11 0 115984672 1074196480 111936 18446744073709551615 4194304 4228012 140735855984736 140374978365456 140375080260308 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24163] ppid=24156 vsize=1049020 CPUtime=0
/proc/24159/task/24163/stat : 24163 (java) S 24156 24156 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 115984672 1074196480 111936 18446744073709551615 4194304 4228012 140735855984736 140374977312672 140375080260308 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24164] ppid=24156 vsize=1049020 CPUtime=0
/proc/24159/task/24164/stat : 24164 (java) S 24156 24156 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 115984675 1074196480 111936 18446744073709551615 4194304 4228012 140735855984736 140374976261104 140375080268832 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24165] ppid=24156 vsize=1049020 CPUtime=1.29
/proc/24159/task/24165/stat : 24165 (java) S 24156 24156 1733 0 -1 4202560 11626 0 0 0 124 5 0 0 20 0 11 0 115984675 1074196480 111936 18446744073709551615 4194304 4228012 140735855984736 140374975208464 140375080260308 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24166] ppid=24156 vsize=1049020 CPUtime=1.2
/proc/24159/task/24166/stat : 24166 (java) S 24156 24156 1733 0 -1 4202560 9393 0 0 0 118 2 0 0 20 0 11 0 115984675 1074196480 111936 18446744073709551615 4194304 4228012 140735855984736 140374974155792 140375080260308 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24167] ppid=24156 vsize=1049020 CPUtime=0
/proc/24159/task/24167/stat : 24167 (java) S 24156 24156 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 115984675 1074196480 111936 18446744073709551615 4194304 4228012 140735855984736 140374973103312 140375080260308 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24159/tid=24168] ppid=24156 vsize=1049020 CPUtime=0
/proc/24159/task/24168/stat : 24168 (java) S 24156 24156 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 115984675 1074196480 111936 18446744073709551615 4194304 4228012 140735855984736 140374972050816 140375080261195 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 6.58
Current children cumulated vsize (KiB) 1058192

[startup+7.20103 s]
/proc/loadavg: 1.46 1.18 1.00 4/70 24168
/proc/meminfo: memFree=87632/1022884 swapFree=0/0
[pid=24156] ppid=24155 vsize=9172 CPUtime=0
/proc/24156/stat : 24156 (p2cudf-basic-1.) S 24155 24156 1733 0 -1 4202496 461 290 0 0 0 0 0 0 20 0 1 0 115984669 9392128 332 18446744073709551615 4194304 5129932 140734834770576 140734834768720 139828854174814 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24156/statm: 2293 332 280 229 0 53 0
[pid=24159] ppid=24156 vsize=0 CPUtime=6.61
/proc/24159/stat : 24159 (java) Z 24156 24156 1733 0 -1 4203532 117183 0 0 0 628 33 0 0 20 0 2 0 115984669 0 0 18446744073709551615 0 0 0 0 0 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24159/statm: 0 0 0 0 0 0 0
[pid=24159/tid=24165] ppid=24156 vsize=0 CPUtime=1.31
/proc/24159/task/24165/stat : 24165 (java) R 24156 24156 1733 0 -1 4203588 11626 0 0 0 125 6 0 0 20 0 2 0 115984675 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) 6.61
Current children cumulated vsize (KiB) 9172

Child status: 0
Real time (s): 7.23373
CPU time (s): 6.65242
CPU user time (s): 6.28439
CPU system time (s): 0.368023
CPU usage (%): 91.9638
Max. virtual memory (cumulated for all children) (KiB): 1060392

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 6.28439
system time used= 0.368023
maximum resident set size= 447828
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 117947
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= 614
involuntary context switches= 1904

runsolver used 0.028001 second user time and 0.036002 second system time

The end