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/paranoid-size/real/deb285a6-db9e-11df-8f4f-00163e3d3b7c.cudf.log.runsolver /home/competition/p2cudf-basic-1.15/p2cudf-basic-1.15 /home/competition/data/real/deb285a6-db9e-11df-8f4f-00163e3d3b7c.cudf /tmp/misc2012/2012-09-02-17:21/basic/p2cudf-basic-1.15/paranoid-size/real/deb285a6-db9e-11df-8f4f-00163e3d3b7c.cudf.result -count(removed),-sum(solution,installedsize),-count(changed) 

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.07 1.11 1.01 2/60 22249
/proc/meminfo: memFree=592664/1022884 swapFree=0/0
[pid=22249] ppid=22248 vsize=3152 CPUtime=0
/proc/22249/stat : 22249 (runsolver) R 22248 1733 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 1 0 115475276 3227648 32 18446744073709551615 134512640 134586868 4292814320 4292812368 4152054832 0 0 16781316 24578 0 0 0 17 0 0 0 0 0 0
/proc/22249/statm: 788 32 0 19 0 73 0
Current StackSize limit: 8192 KiB


[startup+0.159195 s]
/proc/loadavg: 1.07 1.11 1.01 2/60 22249
/proc/meminfo: memFree=592664/1022884 swapFree=0/0
[pid=22249] ppid=22248 vsize=9172 CPUtime=0
/proc/22249/stat : 22249 (p2cudf-basic-1.) S 22248 22249 1733 0 -1 4202496 461 293 0 0 0 0 0 0 20 0 1 0 115475276 9392128 332 18446744073709551615 4194304 5129932 140737411025552 140737411023696 140539319370846 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/22249/statm: 2293 332 280 229 0 53 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9172

[startup+0.200372 s]
/proc/loadavg: 1.07 1.11 1.01 2/60 22249
/proc/meminfo: memFree=592664/1022884 swapFree=0/0
[pid=22249] ppid=22248 vsize=9172 CPUtime=0
/proc/22249/stat : 22249 (p2cudf-basic-1.) S 22248 22249 1733 0 -1 4202496 461 293 0 0 0 0 0 0 20 0 1 0 115475276 9392128 332 18446744073709551615 4194304 5129932 140737411025552 140737411023696 140539319370846 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/22249/statm: 2293 332 280 229 0 53 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9172

[startup+0.30037 s]
/proc/loadavg: 1.07 1.11 1.01 2/60 22249
/proc/meminfo: memFree=592664/1022884 swapFree=0/0
[pid=22249] ppid=22248 vsize=9172 CPUtime=0
/proc/22249/stat : 22249 (p2cudf-basic-1.) S 22248 22249 1733 0 -1 4202496 461 293 0 0 0 0 0 0 20 0 1 0 115475276 9392128 332 18446744073709551615 4194304 5129932 140737411025552 140737411023696 140539319370846 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/22249/statm: 2293 332 280 229 0 53 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9172

[startup+0.700229 s]
/proc/loadavg: 1.07 1.11 1.01 2/60 22249
/proc/meminfo: memFree=592664/1022884 swapFree=0/0
[pid=22249] ppid=22248 vsize=9172 CPUtime=0
/proc/22249/stat : 22249 (p2cudf-basic-1.) S 22248 22249 1733 0 -1 4202496 461 293 0 0 0 0 0 0 20 0 1 0 115475276 9392128 332 18446744073709551615 4194304 5129932 140737411025552 140737411023696 140539319370846 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/22249/statm: 2293 332 280 229 0 53 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9172

[startup+1.50082 s]
/proc/loadavg: 1.07 1.11 1.01 1/71 22261
/proc/meminfo: memFree=581044/1022884 swapFree=0/0
[pid=22249] ppid=22248 vsize=9172 CPUtime=0
/proc/22249/stat : 22249 (p2cudf-basic-1.) S 22248 22249 1733 0 -1 4202496 461 293 0 0 0 0 0 0 20 0 1 0 115475276 9392128 332 18446744073709551615 4194304 5129932 140737411025552 140737411023696 140539319370846 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/22249/statm: 2293 332 280 229 0 53 0
[pid=22252] ppid=22249 vsize=950348 CPUtime=0.11
/proc/22252/stat : 22252 (java) S 22249 22249 1733 0 -1 4202496 4117 0 23 0 9 2 0 0 20 0 10 0 115475277 973156352 3808 18446744073709551615 4194304 4228012 140733472833248 140733472824272 140090339372661 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 10 0 0
/proc/22252/statm: 237587 3808 1860 9 0 224944 0
[pid=22252/tid=22253] ppid=22249 vsize=950348 CPUtime=0.1
/proc/22252/task/22253/stat : 22253 (java) D 22249 22249 1733 0 -1 4202560 2815 0 11 0 8 2 0 0 20 0 10 0 115475289 973156352 3808 18446744073709551615 4194304 4228012 140733472833248 140090345901712 140090339398029 0 4 0 16800975 0 0 0 -1 0 0 0 125 0 0
[pid=22252/tid=22254] ppid=22249 vsize=950348 CPUtime=0
/proc/22252/task/22254/stat : 22254 (java) S 22249 22249 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 115475325 973156352 3808 18446744073709551615 4194304 4228012 140733472833248 140090238545024 140090339386955 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22255] ppid=22249 vsize=950348 CPUtime=0
/proc/22252/task/22255/stat : 22255 (java) S 22249 22249 1733 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 10 0 115475342 973156352 3808 18446744073709551615 4194304 4228012 140733472833248 140090237491216 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22256] ppid=22249 vsize=950348 CPUtime=0
/proc/22252/task/22256/stat : 22256 (java) S 22249 22249 1733 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 10 0 115475342 973156352 3808 18446744073709551615 4194304 4228012 140733472833248 140090236438432 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22257] ppid=22249 vsize=950348 CPUtime=0
/proc/22252/task/22257/stat : 22257 (java) S 22249 22249 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 115475357 973156352 3808 18446744073709551615 4194304 4228012 140733472833248 140090235386864 140090339394592 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22258] ppid=22249 vsize=950348 CPUtime=0
/proc/22252/task/22258/stat : 22258 (java) S 22249 22249 1733 0 -1 4202560 25 0 0 0 0 0 0 0 20 0 10 0 115475357 973156352 3808 18446744073709551615 4194304 4228012 140733472833248 140090234334224 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22259] ppid=22249 vsize=950348 CPUtime=0
/proc/22252/task/22259/stat : 22259 (java) S 22249 22249 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115475357 973156352 3808 18446744073709551615 4194304 4228012 140733472833248 140090233281552 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22260] ppid=22249 vsize=950348 CPUtime=0
/proc/22252/task/22260/stat : 22260 (java) S 22249 22249 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115475357 973156352 3808 18446744073709551615 4194304 4228012 140733472833248 140090232229072 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22261] ppid=22249 vsize=950348 CPUtime=0
/proc/22252/task/22261/stat : 22261 (java) S 22249 22249 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115475357 973156352 3808 18446744073709551615 4194304 4228012 140733472833248 140090231176576 140090339386955 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 0.11
Current children cumulated vsize (KiB) 959520

[startup+3.10055 s]
/proc/loadavg: 1.07 1.11 1.01 3/71 22261
/proc/meminfo: memFree=567528/1022884 swapFree=0/0
[pid=22249] ppid=22248 vsize=9172 CPUtime=0
/proc/22249/stat : 22249 (p2cudf-basic-1.) S 22248 22249 1733 0 -1 4202496 461 293 0 0 0 0 0 0 20 0 1 0 115475276 9392128 332 18446744073709551615 4194304 5129932 140737411025552 140737411023696 140539319370846 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/22249/statm: 2293 332 280 229 0 53 0
[pid=22252] ppid=22249 vsize=1069500 CPUtime=1.45
/proc/22252/stat : 22252 (java) S 22249 22249 1733 0 -1 4202496 38189 0 24 0 131 14 0 0 20 0 10 0 115475277 1095168000 34877 18446744073709551615 4194304 4228012 140733472833248 140733472824272 140090339372661 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 10 0 0
/proc/22252/statm: 267375 34877 2348 9 0 254725 0
[pid=22252/tid=22253] ppid=22249 vsize=1069500 CPUtime=0.67
/proc/22252/task/22253/stat : 22253 (java) R 22249 22249 1733 0 -1 4202560 18361 0 12 0 61 6 0 0 20 0 10 0 115475289 1095168000 34877 18446744073709551615 4194304 4228012 140733472833248 140090345898656 140090243408084 0 4 0 16800975 0 0 0 -1 0 0 0 154 0 0
[pid=22252/tid=22254] ppid=22249 vsize=1069500 CPUtime=0
/proc/22252/task/22254/stat : 22254 (java) S 22249 22249 1733 0 -1 4202560 3 0 0 0 0 0 0 0 20 0 10 0 115475325 1095168000 34877 18446744073709551615 4194304 4228012 140733472833248 140090238545024 140090339386955 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22255] ppid=22249 vsize=1069500 CPUtime=0
/proc/22252/task/22255/stat : 22255 (java) S 22249 22249 1733 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 10 0 115475342 1095168000 34877 18446744073709551615 4194304 4228012 140733472833248 140090237491216 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22256] ppid=22249 vsize=1069500 CPUtime=0
/proc/22252/task/22256/stat : 22256 (java) S 22249 22249 1733 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 10 0 115475342 1095168000 34877 18446744073709551615 4194304 4228012 140733472833248 140090236438432 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22257] ppid=22249 vsize=1069500 CPUtime=0
/proc/22252/task/22257/stat : 22257 (java) S 22249 22249 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 115475357 1095168000 34877 18446744073709551615 4194304 4228012 140733472833248 140090235386864 140090339394592 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22258] ppid=22249 vsize=1069500 CPUtime=0.37
/proc/22252/task/22258/stat : 22258 (java) R 22249 22249 1733 0 -1 4202560 10497 0 0 0 34 3 0 0 20 0 10 0 115475357 1095168000 34877 18446744073709551615 4194304 4228012 140733472833248 140090234321752 140090323677164 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22259] ppid=22249 vsize=1069500 CPUtime=0.38
/proc/22252/task/22259/stat : 22259 (java) R 22249 22249 1733 0 -1 4202560 8052 0 0 0 34 4 0 0 20 0 10 0 115475357 1095168000 34877 18446744073709551615 4194304 4228012 140733472833248 140090233269272 140090325906526 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22260] ppid=22249 vsize=1069500 CPUtime=0
/proc/22252/task/22260/stat : 22260 (java) S 22249 22249 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115475357 1095168000 34877 18446744073709551615 4194304 4228012 140733472833248 140090232229072 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22261] ppid=22249 vsize=1069500 CPUtime=0
/proc/22252/task/22261/stat : 22261 (java) S 22249 22249 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115475357 1095168000 34877 18446744073709551615 4194304 4228012 140733472833248 140090231176576 140090339386955 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 1.45
Current children cumulated vsize (KiB) 1078672
heavy processes:

[startup+6.30056 s]
/proc/loadavg: 1.06 1.10 1.01 4/71 22261
/proc/meminfo: memFree=206068/1022884 swapFree=0/0
[pid=22249] ppid=22248 vsize=9172 CPUtime=0
/proc/22249/stat : 22249 (p2cudf-basic-1.) S 22248 22249 1733 0 -1 4202496 461 293 0 0 0 0 0 0 20 0 1 0 115475276 9392128 332 18446744073709551615 4194304 5129932 140737411025552 140737411023696 140539319370846 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/22249/statm: 2293 332 280 229 0 53 0
[pid=22252] ppid=22249 vsize=1065104 CPUtime=4.34
/proc/22252/stat : 22252 (java) S 22249 22249 1733 0 -1 4202496 98502 0 24 0 406 28 0 0 20 0 10 0 115475277 1090666496 93987 18446744073709551615 4194304 4228012 140733472833248 140733472824272 140090339372661 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 10 0 0
/proc/22252/statm: 266276 93987 2374 9 0 253626 0
[pid=22252/tid=22253] ppid=22249 vsize=1065104 CPUtime=2.19
/proc/22252/task/22253/stat : 22253 (java) R 22249 22249 1733 0 -1 4202560 47681 0 12 0 205 14 0 0 20 0 10 0 115475289 1090666496 93987 18446744073709551615 4194304 4228012 140733472833248 140090345906168 140090325579224 0 4 0 16800975 0 0 0 -1 0 0 0 184 0 0
[pid=22252/tid=22254] ppid=22249 vsize=1065104 CPUtime=0.56
/proc/22252/task/22254/stat : 22254 (java) S 22249 22249 1733 0 -1 4202560 30210 0 0 0 50 6 0 0 20 0 10 0 115475325 1090666496 93987 18446744073709551615 4194304 4228012 140733472833248 140090238545024 140090339386955 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22255] ppid=22249 vsize=1065104 CPUtime=0
/proc/22252/task/22255/stat : 22255 (java) S 22249 22249 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 115475342 1090666496 93987 18446744073709551615 4194304 4228012 140733472833248 140090237491216 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22256] ppid=22249 vsize=1065104 CPUtime=0
/proc/22252/task/22256/stat : 22256 (java) S 22249 22249 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 115475342 1090666496 93987 18446744073709551615 4194304 4228012 140733472833248 140090236438432 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 1 0 0
[pid=22252/tid=22257] ppid=22249 vsize=1065104 CPUtime=0
/proc/22252/task/22257/stat : 22257 (java) S 22249 22249 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 115475357 1090666496 93987 18446744073709551615 4194304 4228012 140733472833248 140090235386864 140090339394592 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22258] ppid=22249 vsize=1065104 CPUtime=0.74
/proc/22252/task/22258/stat : 22258 (java) S 22249 22249 1733 0 -1 4202560 10608 0 0 0 71 3 0 0 20 0 10 0 115475357 1090666496 93987 18446744073709551615 4194304 4228012 140733472833248 140090234334224 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22259] ppid=22249 vsize=1065104 CPUtime=0.81
/proc/22252/task/22259/stat : 22259 (java) R 22249 22249 1733 0 -1 4202560 8723 0 0 0 76 5 0 0 20 0 10 0 115475357 1090666496 93987 18446744073709551615 4194304 4228012 140733472833248 140090233281296 140090325212128 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22260] ppid=22249 vsize=1065104 CPUtime=0
/proc/22252/task/22260/stat : 22260 (java) S 22249 22249 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115475357 1090666496 93987 18446744073709551615 4194304 4228012 140733472833248 140090232229072 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22261] ppid=22249 vsize=1065104 CPUtime=0
/proc/22252/task/22261/stat : 22261 (java) S 22249 22249 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115475357 1090666496 93987 18446744073709551615 4194304 4228012 140733472833248 140090231176576 140090339386955 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 4.34
Current children cumulated vsize (KiB) 1074276
heavy processes:

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

[startup+6.41219 s]
/proc/loadavg: 1.06 1.10 1.01 3/71 22261
/proc/meminfo: memFree=204704/1022884 swapFree=0/0
[pid=22249] ppid=22248 vsize=9172 CPUtime=0
/proc/22249/stat : 22249 (p2cudf-basic-1.) S 22248 22249 1733 0 -1 4202496 461 293 0 0 0 0 0 0 20 0 1 0 115475276 9392128 332 18446744073709551615 4194304 5129932 140737411025552 140737411023696 140539319370846 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/22249/statm: 2293 332 280 229 0 53 0
[pid=22252] ppid=22249 vsize=1065104 CPUtime=4.45
/proc/22252/stat : 22252 (java) S 22249 22249 1733 0 -1 4202496 99077 0 24 0 417 28 0 0 20 0 10 0 115475277 1090666496 94562 18446744073709551615 4194304 4228012 140733472833248 140733472824272 140090339372661 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 10 0 0
/proc/22252/statm: 266276 94562 2374 9 0 253626 0
[pid=22252/tid=22253] ppid=22249 vsize=1065104 CPUtime=2.24
/proc/22252/task/22253/stat : 22253 (java) R 22249 22249 1733 0 -1 4202560 47683 0 12 0 210 14 0 0 20 0 10 0 115475289 1090666496 94562 18446744073709551615 4194304 4228012 140733472833248 140090345906728 140090243370944 0 4 0 16800975 0 0 0 -1 0 0 0 184 0 0
[pid=22252/tid=22254] ppid=22249 vsize=1065104 CPUtime=0.56
/proc/22252/task/22254/stat : 22254 (java) S 22249 22249 1733 0 -1 4202560 30210 0 0 0 50 6 0 0 20 0 10 0 115475325 1090666496 94562 18446744073709551615 4194304 4228012 140733472833248 140090238545024 140090339386955 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22255] ppid=22249 vsize=1065104 CPUtime=0
/proc/22252/task/22255/stat : 22255 (java) S 22249 22249 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 115475342 1090666496 94562 18446744073709551615 4194304 4228012 140733472833248 140090237491216 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22256] ppid=22249 vsize=1065104 CPUtime=0
/proc/22252/task/22256/stat : 22256 (java) S 22249 22249 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 115475342 1090666496 94562 18446744073709551615 4194304 4228012 140733472833248 140090236438432 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 1 0 0
[pid=22252/tid=22257] ppid=22249 vsize=1065104 CPUtime=0
/proc/22252/task/22257/stat : 22257 (java) S 22249 22249 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 115475357 1090666496 94562 18446744073709551615 4194304 4228012 140733472833248 140090235386864 140090339394592 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22258] ppid=22249 vsize=1065104 CPUtime=0.77
/proc/22252/task/22258/stat : 22258 (java) R 22249 22249 1733 0 -1 4202560 10609 0 0 0 74 3 0 0 20 0 10 0 115475357 1090666496 94562 18446744073709551615 4194304 4228012 140733472833248 140090234333968 140090322191605 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22259] ppid=22249 vsize=1065104 CPUtime=0.86
/proc/22252/task/22259/stat : 22259 (java) R 22249 22249 1733 0 -1 4202560 9295 0 0 0 81 5 0 0 20 0 10 0 115475357 1090666496 94562 18446744073709551615 4194304 4228012 140733472833248 140090233281296 140090322218248 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22260] ppid=22249 vsize=1065104 CPUtime=0
/proc/22252/task/22260/stat : 22260 (java) S 22249 22249 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115475357 1090666496 94562 18446744073709551615 4194304 4228012 140733472833248 140090232229072 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22261] ppid=22249 vsize=1065104 CPUtime=0
/proc/22252/task/22261/stat : 22261 (java) S 22249 22249 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115475357 1090666496 94562 18446744073709551615 4194304 4228012 140733472833248 140090231176576 140090339386955 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 4.45
Current children cumulated vsize (KiB) 1074276

[startup+8.00075 s]
/proc/loadavg: 1.06 1.10 1.01 4/71 22261
/proc/meminfo: memFree=196768/1022884 swapFree=0/0
[pid=22249] ppid=22248 vsize=9172 CPUtime=0
/proc/22249/stat : 22249 (p2cudf-basic-1.) S 22248 22249 1733 0 -1 4202496 461 293 0 0 0 0 0 0 20 0 1 0 115475276 9392128 332 18446744073709551615 4194304 5129932 140737411025552 140737411023696 140539319370846 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/22249/statm: 2293 332 280 229 0 53 0
[pid=22252] ppid=22249 vsize=1066132 CPUtime=6.02
/proc/22252/stat : 22252 (java) S 22249 22249 1733 0 -1 4202496 102632 0 24 0 572 30 0 0 20 0 11 0 115475277 1091719168 95893 18446744073709551615 4194304 4228012 140733472833248 140733472824272 140090339372661 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 10 0 0
/proc/22252/statm: 266533 95893 2378 9 0 253883 0
[pid=22252/tid=22253] ppid=22249 vsize=1066132 CPUtime=2.82
/proc/22252/task/22253/stat : 22253 (java) R 22249 22249 1733 0 -1 4202560 47747 0 12 0 268 14 0 0 20 0 11 0 115475289 1091719168 95893 18446744073709551615 4194304 4228012 140733472833248 140090345906520 140090243329677 0 4 0 16800975 0 0 0 -1 0 0 0 191 0 0
[pid=22252/tid=22254] ppid=22249 vsize=1066132 CPUtime=0.56
/proc/22252/task/22254/stat : 22254 (java) S 22249 22249 1733 0 -1 4202560 30211 0 0 0 50 6 0 0 20 0 11 0 115475325 1091719168 95893 18446744073709551615 4194304 4228012 140733472833248 140090238545024 140090339386955 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22255] ppid=22249 vsize=1066132 CPUtime=0
/proc/22252/task/22255/stat : 22255 (java) S 22249 22249 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 115475342 1091719168 95893 18446744073709551615 4194304 4228012 140733472833248 140090237491216 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22256] ppid=22249 vsize=1066132 CPUtime=0
/proc/22252/task/22256/stat : 22256 (java) S 22249 22249 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 115475342 1091719168 95893 18446744073709551615 4194304 4228012 140733472833248 140090236438432 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 1 0 0
[pid=22252/tid=22257] ppid=22249 vsize=1066132 CPUtime=0
/proc/22252/task/22257/stat : 22257 (java) S 22249 22249 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 115475357 1091719168 95893 18446744073709551615 4194304 4228012 140733472833248 140090235386864 140090339394592 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22258] ppid=22249 vsize=1066132 CPUtime=1.25
/proc/22252/task/22258/stat : 22258 (java) S 22249 22249 1733 0 -1 4202560 10678 0 0 0 121 4 0 0 20 0 11 0 115475357 1091719168 95893 18446744073709551615 4194304 4228012 140733472833248 140090234334224 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22259] ppid=22249 vsize=1066132 CPUtime=1.37
/proc/22252/task/22259/stat : 22259 (java) R 22249 22249 1733 0 -1 4202560 12710 0 0 0 131 6 0 0 20 0 11 0 115475357 1091719168 95893 18446744073709551615 4194304 4228012 140733472833248 140090233281296 140090325039346 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22260] ppid=22249 vsize=1066132 CPUtime=0
/proc/22252/task/22260/stat : 22260 (java) S 22249 22249 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 115475357 1091719168 95893 18446744073709551615 4194304 4228012 140733472833248 140090232229072 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22261] ppid=22249 vsize=1066132 CPUtime=0
/proc/22252/task/22261/stat : 22261 (java) S 22249 22249 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 115475357 1091719168 95893 18446744073709551615 4194304 4228012 140733472833248 140090231176576 140090339386955 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 6.02
Current children cumulated vsize (KiB) 1075304

[startup+8.80081 s]
/proc/loadavg: 1.06 1.10 1.01 1/72 22263
/proc/meminfo: memFree=196388/1022884 swapFree=0/0
[pid=22249] ppid=22248 vsize=9172 CPUtime=0
/proc/22249/stat : 22249 (p2cudf-basic-1.) S 22248 22249 1733 0 -1 4202496 461 293 0 0 0 0 0 0 20 0 1 0 115475276 9392128 332 18446744073709551615 4194304 5129932 140737411025552 140737411023696 140539319370846 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/22249/statm: 2293 332 280 229 0 53 0
[pid=22252] ppid=22249 vsize=1067160 CPUtime=6.42
/proc/22252/stat : 22252 (java) S 22249 22249 1733 0 -1 4202496 102677 0 24 0 612 30 0 0 20 0 11 0 115475277 1092771840 95936 18446744073709551615 4194304 4228012 140733472833248 140733472824272 140090339372661 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 10 0 0
/proc/22252/statm: 266790 95936 2379 9 0 254140 0
[pid=22252/tid=22253] ppid=22249 vsize=1067160 CPUtime=2.94
/proc/22252/task/22253/stat : 22253 (java) S 22249 22249 1733 0 -1 4202560 47781 0 12 0 280 14 0 0 20 0 11 0 115475289 1092771840 95936 18446744073709551615 4194304 4228012 140733472833248 140090345907120 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 193 0 0
[pid=22252/tid=22254] ppid=22249 vsize=1067160 CPUtime=0.56
/proc/22252/task/22254/stat : 22254 (java) S 22249 22249 1733 0 -1 4202560 30211 0 0 0 50 6 0 0 20 0 11 0 115475325 1092771840 95936 18446744073709551615 4194304 4228012 140733472833248 140090238545024 140090339386955 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22255] ppid=22249 vsize=1067160 CPUtime=0
/proc/22252/task/22255/stat : 22255 (java) S 22249 22249 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 115475342 1092771840 95936 18446744073709551615 4194304 4228012 140733472833248 140090237491216 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22256] ppid=22249 vsize=1067160 CPUtime=0
/proc/22252/task/22256/stat : 22256 (java) S 22249 22249 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 115475342 1092771840 95936 18446744073709551615 4194304 4228012 140733472833248 140090236438432 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 1 0 0
[pid=22252/tid=22257] ppid=22249 vsize=1067160 CPUtime=0
/proc/22252/task/22257/stat : 22257 (java) S 22249 22249 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 115475357 1092771840 95936 18446744073709551615 4194304 4228012 140733472833248 140090235386864 140090339394592 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22258] ppid=22249 vsize=1067160 CPUtime=1.39
/proc/22252/task/22258/stat : 22258 (java) S 22249 22249 1733 0 -1 4202560 10679 0 0 0 135 4 0 0 20 0 11 0 115475357 1092771840 95936 18446744073709551615 4194304 4228012 140733472833248 140090234334224 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22259] ppid=22249 vsize=1067160 CPUtime=1.5
/proc/22252/task/22259/stat : 22259 (java) S 22249 22249 1733 0 -1 4202560 12714 0 0 0 144 6 0 0 20 0 11 0 115475357 1092771840 95936 18446744073709551615 4194304 4228012 140733472833248 140090233281552 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22260] ppid=22249 vsize=1067160 CPUtime=0
/proc/22252/task/22260/stat : 22260 (java) S 22249 22249 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 115475357 1092771840 95936 18446744073709551615 4194304 4228012 140733472833248 140090232229072 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22261] ppid=22249 vsize=1067160 CPUtime=0
/proc/22252/task/22261/stat : 22261 (java) S 22249 22249 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 115475357 1092771840 95936 18446744073709551615 4194304 4228012 140733472833248 140090231176576 140090339386955 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22263] ppid=22249 vsize=1067160 CPUtime=0
/proc/22252/task/22263/stat : 22263 (java) S 22249 22249 1733 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 11 0 115476114 1092771840 95936 18446744073709551615 4194304 4228012 140733472833248 140090228918448 140090339386955 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 6.42
Current children cumulated vsize (KiB) 1076332

[startup+9.00078 s]
/proc/loadavg: 1.06 1.10 1.01 1/72 22263
/proc/meminfo: memFree=196388/1022884 swapFree=0/0
[pid=22249] ppid=22248 vsize=9172 CPUtime=0
/proc/22249/stat : 22249 (p2cudf-basic-1.) S 22248 22249 1733 0 -1 4202496 461 293 0 0 0 0 0 0 20 0 1 0 115475276 9392128 332 18446744073709551615 4194304 5129932 140737411025552 140737411023696 140539319370846 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/22249/statm: 2293 332 280 229 0 53 0
[pid=22252] ppid=22249 vsize=1067160 CPUtime=6.54
/proc/22252/stat : 22252 (java) S 22249 22249 1733 0 -1 4202496 102679 0 24 0 620 34 0 0 20 0 11 0 115475277 1092771840 95938 18446744073709551615 4194304 4228012 140733472833248 140733472824272 140090339372661 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 10 0 0
/proc/22252/statm: 266790 95938 2379 9 0 254140 0
[pid=22252/tid=22253] ppid=22249 vsize=1067160 CPUtime=2.94
/proc/22252/task/22253/stat : 22253 (java) S 22249 22249 1733 0 -1 4202560 47781 0 12 0 280 14 0 0 20 0 11 0 115475289 1092771840 95938 18446744073709551615 4194304 4228012 140733472833248 140090345907120 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 193 0 0
[pid=22252/tid=22254] ppid=22249 vsize=1067160 CPUtime=0.56
/proc/22252/task/22254/stat : 22254 (java) S 22249 22249 1733 0 -1 4202560 30211 0 0 0 50 6 0 0 20 0 11 0 115475325 1092771840 95938 18446744073709551615 4194304 4228012 140733472833248 140090238545024 140090339386955 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22255] ppid=22249 vsize=1067160 CPUtime=0
/proc/22252/task/22255/stat : 22255 (java) S 22249 22249 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 115475342 1092771840 95938 18446744073709551615 4194304 4228012 140733472833248 140090237491216 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22256] ppid=22249 vsize=1067160 CPUtime=0
/proc/22252/task/22256/stat : 22256 (java) S 22249 22249 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 115475342 1092771840 95938 18446744073709551615 4194304 4228012 140733472833248 140090236438432 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 1 0 0
[pid=22252/tid=22257] ppid=22249 vsize=1067160 CPUtime=0
/proc/22252/task/22257/stat : 22257 (java) S 22249 22249 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 115475357 1092771840 95938 18446744073709551615 4194304 4228012 140733472833248 140090235386864 140090339394592 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22258] ppid=22249 vsize=1067160 CPUtime=1.4
/proc/22252/task/22258/stat : 22258 (java) R 22249 22249 1733 0 -1 4202560 10679 0 0 0 136 4 0 0 20 0 11 0 115475357 1092771840 95938 18446744073709551615 4194304 4228012 140733472833248 140090234333968 140090320987969 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22259] ppid=22249 vsize=1067160 CPUtime=1.53
/proc/22252/task/22259/stat : 22259 (java) S 22249 22249 1733 0 -1 4202560 12714 0 0 0 147 6 0 0 20 0 11 0 115475357 1092771840 95938 18446744073709551615 4194304 4228012 140733472833248 140090233281552 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22260] ppid=22249 vsize=1067160 CPUtime=0
/proc/22252/task/22260/stat : 22260 (java) S 22249 22249 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 115475357 1092771840 95938 18446744073709551615 4194304 4228012 140733472833248 140090232229072 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22261] ppid=22249 vsize=1067160 CPUtime=0
/proc/22252/task/22261/stat : 22261 (java) S 22249 22249 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 115475357 1092771840 95938 18446744073709551615 4194304 4228012 140733472833248 140090231176576 140090339386955 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22263] ppid=22249 vsize=1067160 CPUtime=0.08
/proc/22252/task/22263/stat : 22263 (java) R 22249 22249 1733 0 -1 4202560 8 0 0 0 4 4 0 0 20 0 11 0 115476114 1092771840 95938 18446744073709551615 4194304 4228012 140733472833248 140090228909360 140090243396676 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 6.54
Current children cumulated vsize (KiB) 1076332

[startup+9.1008 s]
/proc/loadavg: 1.06 1.10 1.01 1/72 22263
/proc/meminfo: memFree=196388/1022884 swapFree=0/0
[pid=22249] ppid=22248 vsize=9172 CPUtime=0
/proc/22249/stat : 22249 (p2cudf-basic-1.) S 22248 22249 1733 0 -1 4202496 461 293 0 0 0 0 0 0 20 0 1 0 115475276 9392128 332 18446744073709551615 4194304 5129932 140737411025552 140737411023696 140539319370846 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/22249/statm: 2293 332 280 229 0 53 0
[pid=22252] ppid=22249 vsize=1067160 CPUtime=6.63
/proc/22252/stat : 22252 (java) S 22249 22249 1733 0 -1 4202496 102681 0 24 0 627 36 0 0 20 0 11 0 115475277 1092771840 95940 18446744073709551615 4194304 4228012 140733472833248 140733472824272 140090339372661 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 10 0 0
/proc/22252/statm: 266790 95940 2380 9 0 254140 0
[pid=22252/tid=22253] ppid=22249 vsize=1067160 CPUtime=2.94
/proc/22252/task/22253/stat : 22253 (java) S 22249 22249 1733 0 -1 4202560 47781 0 12 0 280 14 0 0 20 0 11 0 115475289 1092771840 95940 18446744073709551615 4194304 4228012 140733472833248 140090345907120 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 193 0 0
[pid=22252/tid=22254] ppid=22249 vsize=1067160 CPUtime=0.56
/proc/22252/task/22254/stat : 22254 (java) S 22249 22249 1733 0 -1 4202560 30211 0 0 0 50 6 0 0 20 0 11 0 115475325 1092771840 95940 18446744073709551615 4194304 4228012 140733472833248 140090238545024 140090339386955 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22255] ppid=22249 vsize=1067160 CPUtime=0
/proc/22252/task/22255/stat : 22255 (java) S 22249 22249 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 115475342 1092771840 95940 18446744073709551615 4194304 4228012 140733472833248 140090237491216 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22256] ppid=22249 vsize=1067160 CPUtime=0
/proc/22252/task/22256/stat : 22256 (java) S 22249 22249 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 115475342 1092771840 95940 18446744073709551615 4194304 4228012 140733472833248 140090236438432 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 1 0 0
[pid=22252/tid=22257] ppid=22249 vsize=1067160 CPUtime=0
/proc/22252/task/22257/stat : 22257 (java) S 22249 22249 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 115475357 1092771840 95940 18446744073709551615 4194304 4228012 140733472833248 140090235386864 140090339394592 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22258] ppid=22249 vsize=1067160 CPUtime=1.42
/proc/22252/task/22258/stat : 22258 (java) R 22249 22249 1733 0 -1 4202560 10680 0 0 0 138 4 0 0 20 0 11 0 115475357 1092771840 95940 18446744073709551615 4194304 4228012 140733472833248 140090234333968 140090325524340 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22259] ppid=22249 vsize=1067160 CPUtime=1.54
/proc/22252/task/22259/stat : 22259 (java) R 22249 22249 1733 0 -1 4202560 12714 0 0 0 148 6 0 0 20 0 11 0 115475357 1092771840 95940 18446744073709551615 4194304 4228012 140733472833248 140090233281296 140090325465065 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22260] ppid=22249 vsize=1067160 CPUtime=0
/proc/22252/task/22260/stat : 22260 (java) S 22249 22249 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 115475357 1092771840 95940 18446744073709551615 4194304 4228012 140733472833248 140090232229072 140090339386068 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22261] ppid=22249 vsize=1067160 CPUtime=0
/proc/22252/task/22261/stat : 22261 (java) S 22249 22249 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 115475357 1092771840 95940 18446744073709551615 4194304 4228012 140733472833248 140090231176576 140090339386955 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=22252/tid=22263] ppid=22249 vsize=1067160 CPUtime=0.14
/proc/22252/task/22263/stat : 22263 (java) R 22249 22249 1733 0 -1 4202560 9 0 0 0 8 6 0 0 20 0 11 0 115476114 1092771840 95940 18446744073709551615 4194304 4228012 140733472833248 140090228909296 140090324215093 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 6.63
Current children cumulated vsize (KiB) 1076332

Child status: 0
Real time (s): 9.19862
CPU time (s): 6.74442
CPU user time (s): 6.3364
CPU system time (s): 0.408025
CPU usage (%): 73.3199
Max. virtual memory (cumulated for all children) (KiB): 1078672

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 6.3364
system time used= 0.408025
maximum resident set size= 385556
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 103461
page faults= 24
swaps= 0
block input operations= 40864
block output operations= 288
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 1275
involuntary context switches= 2087

runsolver used 0.024001 second user time and 0.068004 second system time

The end