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/install/rand290.cudf.log.runsolver /home/competition/p2cudf-basic-1.15/p2cudf-basic-1.15 /home/competition/data/install/rand290.cudf /tmp/misc2012/2012-09-02-17:21/basic/p2cudf-basic-1.15/embedded/install/rand290.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
Current StackSize limit: 8192 KiB


[startup+0 s]
/proc/loadavg: 1.17 1.03 0.93 2/56 10706
/proc/meminfo: memFree=572972/1022884 swapFree=0/0
[pid=10706] ppid=10705 vsize=1068 CPUtime=0
/proc/10706/stat : 10706 (p2cudf-basic-1.) D 10705 10706 32685 0 -1 4194304 76 0 0 0 0 0 0 0 20 0 1 0 37745431 1093632 1 18446744073709551615 0 0 140735739784170 4294075392 4152132656 0 0 16781316 0 0 0 0 17 0 0 0 0 0 0
/proc/10706/statm: 267 1 0 0 0 28 0

[startup+0.196441 s]
/proc/loadavg: 1.17 1.03 0.93 2/56 10706
/proc/meminfo: memFree=572972/1022884 swapFree=0/0
[pid=10706] ppid=10705 vsize=9168 CPUtime=0
/proc/10706/stat : 10706 (p2cudf-basic-1.) S 10705 10706 32685 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 37745431 9388032 331 18446744073709551615 4194304 5129932 140735739776768 140735739774912 139912303322206 0 65536 16781316 65538 0 0 0 17 0 0 0 3 0 0
/proc/10706/statm: 2292 331 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+0.200261 s]
/proc/loadavg: 1.17 1.03 0.93 2/56 10706
/proc/meminfo: memFree=572972/1022884 swapFree=0/0
[pid=10706] ppid=10705 vsize=9168 CPUtime=0
/proc/10706/stat : 10706 (p2cudf-basic-1.) S 10705 10706 32685 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 37745431 9388032 331 18446744073709551615 4194304 5129932 140735739776768 140735739774912 139912303322206 0 65536 16781316 65538 0 0 0 17 0 0 0 3 0 0
/proc/10706/statm: 2292 331 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+0.300334 s]
/proc/loadavg: 1.17 1.03 0.93 2/56 10706
/proc/meminfo: memFree=572972/1022884 swapFree=0/0
[pid=10706] ppid=10705 vsize=9168 CPUtime=0
/proc/10706/stat : 10706 (p2cudf-basic-1.) S 10705 10706 32685 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 37745431 9388032 331 18446744073709551615 4194304 5129932 140735739776768 140735739774912 139912303322206 0 65536 16781316 65538 0 0 0 17 0 0 0 3 0 0
/proc/10706/statm: 2292 331 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+0.700194 s]
/proc/loadavg: 1.17 1.03 0.93 2/56 10706
/proc/meminfo: memFree=572972/1022884 swapFree=0/0
[pid=10706] ppid=10705 vsize=9168 CPUtime=0
/proc/10706/stat : 10706 (p2cudf-basic-1.) S 10705 10706 32685 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 37745431 9388032 331 18446744073709551615 4194304 5129932 140735739776768 140735739774912 139912303322206 0 65536 16781316 65538 0 0 0 17 0 0 0 3 0 0
/proc/10706/statm: 2292 331 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+1.50055 s]
/proc/loadavg: 1.17 1.03 0.93 4/67 10718
/proc/meminfo: memFree=512860/1022884 swapFree=0/0
[pid=10706] ppid=10705 vsize=9168 CPUtime=0
/proc/10706/stat : 10706 (p2cudf-basic-1.) S 10705 10706 32685 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 37745431 9388032 331 18446744073709551615 4194304 5129932 140735739776768 140735739774912 139912303322206 0 65536 16781316 65538 0 0 0 17 0 0 0 3 0 0
/proc/10706/statm: 2292 331 280 229 0 52 0
[pid=10709] ppid=10706 vsize=1060372 CPUtime=1.18
/proc/10709/stat : 10709 (java) S 10706 10706 32685 0 -1 4202496 37695 0 21 0 102 16 0 0 20 0 10 0 37745436 1085820928 33856 18446744073709551615 4194304 4228012 140734679478240 140734679469264 140570839932533 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 5 0 0
/proc/10709/statm: 265093 33856 2349 9 0 252443 0
[pid=10709/tid=10710] ppid=10706 vsize=1060372 CPUtime=0.52
/proc/10709/task/10710/stat : 10710 (java) R 10706 10706 32685 0 -1 4202560 17610 0 9 0 44 8 0 0 20 0 10 0 37745442 1085820928 33856 18446744073709551615 4194304 4228012 140734679478240 140570846458528 140570743956519 0 4 0 16800975 0 0 0 -1 0 0 0 23 0 0
[pid=10709/tid=10711] ppid=10706 vsize=1060372 CPUtime=0.01
/proc/10709/task/10711/stat : 10711 (java) S 10706 10706 32685 0 -1 4202560 4 0 0 0 0 1 0 0 20 0 10 0 37745451 1085820928 33856 18446744073709551615 4194304 4228012 140734679478240 140570739104896 140570839946827 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10712] ppid=10706 vsize=1060372 CPUtime=0
/proc/10709/task/10712/stat : 10712 (java) S 10706 10706 32685 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 10 0 37745451 1085820928 33856 18446744073709551615 4194304 4228012 140734679478240 140570738051088 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10713] ppid=10706 vsize=1060372 CPUtime=0
/proc/10709/task/10713/stat : 10713 (java) S 10706 10706 32685 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 10 0 37745451 1085820928 33856 18446744073709551615 4194304 4228012 140734679478240 140570736998304 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10714] ppid=10706 vsize=1060372 CPUtime=0
/proc/10709/task/10714/stat : 10714 (java) S 10706 10706 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 37745458 1085820928 33856 18446744073709551615 4194304 4228012 140734679478240 140570735946736 140570839954464 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10715] ppid=10706 vsize=1060372 CPUtime=0.32
/proc/10709/task/10715/stat : 10715 (java) R 10706 10706 32685 0 -1 4202560 8463 0 0 0 30 2 0 0 20 0 10 0 37745458 1085820928 33856 18446744073709551615 4194304 4228012 140734679478240 140570734881624 140570826630184 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10716] ppid=10706 vsize=1060372 CPUtime=0.31
/proc/10709/task/10716/stat : 10716 (java) R 10706 10706 32685 0 -1 4202560 10344 0 0 0 26 5 0 0 20 0 10 0 37745458 1085820928 33856 18446744073709551615 4194304 4228012 140734679478240 140570733829272 140570832510397 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10717] ppid=10706 vsize=1060372 CPUtime=0
/proc/10709/task/10717/stat : 10717 (java) S 10706 10706 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 37745458 1085820928 33856 18446744073709551615 4194304 4228012 140734679478240 140570732788944 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10718] ppid=10706 vsize=1060372 CPUtime=0
/proc/10709/task/10718/stat : 10718 (java) S 10706 10706 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 37745458 1085820928 33856 18446744073709551615 4194304 4228012 140734679478240 140570731736448 140570839946827 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 1.18
Current children cumulated vsize (KiB) 1069540

[startup+3.10073 s]
/proc/loadavg: 1.17 1.03 0.93 1/67 10718
/proc/meminfo: memFree=292884/1022884 swapFree=0/0
[pid=10706] ppid=10705 vsize=9168 CPUtime=0
/proc/10706/stat : 10706 (p2cudf-basic-1.) S 10705 10706 32685 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 37745431 9388032 331 18446744073709551615 4194304 5129932 140735739776768 140735739774912 139912303322206 0 65536 16781316 65538 0 0 0 17 0 0 0 3 0 0
/proc/10706/statm: 2292 331 280 229 0 52 0
[pid=10709] ppid=10706 vsize=1059900 CPUtime=2.69
/proc/10709/stat : 10709 (java) S 10706 10706 32685 0 -1 4202496 97340 0 21 0 243 26 0 0 20 0 10 0 37745436 1085337600 92209 18446744073709551615 4194304 4228012 140734679478240 140734679469264 140570839932533 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 5 0 0
/proc/10709/statm: 264975 92209 2370 9 0 252325 0
[pid=10709/tid=10710] ppid=10706 vsize=1059900 CPUtime=1.3
/proc/10709/task/10710/stat : 10710 (java) D 10706 10706 32685 0 -1 4202560 47382 0 9 0 115 15 0 0 20 0 10 0 37745442 1085337600 92209 18446744073709551615 4194304 4228012 140734679478240 140570846458560 140570839957901 0 4 0 16800975 0 0 0 -1 0 0 0 31 0 0
[pid=10709/tid=10711] ppid=10706 vsize=1059900 CPUtime=0.47
/proc/10709/task/10711/stat : 10711 (java) S 10706 10706 32685 0 -1 4202560 29292 0 0 0 42 5 0 0 20 0 10 0 37745451 1085337600 92209 18446744073709551615 4194304 4228012 140734679478240 140570739104896 140570839946827 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10712] ppid=10706 vsize=1059900 CPUtime=0
/proc/10709/task/10712/stat : 10712 (java) S 10706 10706 32685 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 37745451 1085337600 92209 18446744073709551615 4194304 4228012 140734679478240 140570738051088 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10713] ppid=10706 vsize=1059900 CPUtime=0
/proc/10709/task/10713/stat : 10713 (java) S 10706 10706 32685 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 37745451 1085337600 92209 18446744073709551615 4194304 4228012 140734679478240 140570736998304 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10714] ppid=10706 vsize=1059900 CPUtime=0
/proc/10709/task/10714/stat : 10714 (java) S 10706 10706 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 37745458 1085337600 92209 18446744073709551615 4194304 4228012 140734679478240 140570735946736 140570839954464 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10715] ppid=10706 vsize=1059900 CPUtime=0.46
/proc/10709/task/10715/stat : 10715 (java) S 10706 10706 32685 0 -1 4202560 8599 0 0 0 44 2 0 0 20 0 10 0 37745458 1085337600 92209 18446744073709551615 4194304 4228012 140734679478240 140570734894096 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10716] ppid=10706 vsize=1059900 CPUtime=0.44
/proc/10709/task/10716/stat : 10716 (java) S 10706 10706 32685 0 -1 4202560 10789 0 0 0 39 5 0 0 20 0 10 0 37745458 1085337600 92209 18446744073709551615 4194304 4228012 140734679478240 140570733841424 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10717] ppid=10706 vsize=1059900 CPUtime=0
/proc/10709/task/10717/stat : 10717 (java) S 10706 10706 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 37745458 1085337600 92209 18446744073709551615 4194304 4228012 140734679478240 140570732788944 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10718] ppid=10706 vsize=1059900 CPUtime=0
/proc/10709/task/10718/stat : 10718 (java) S 10706 10706 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 37745458 1085337600 92209 18446744073709551615 4194304 4228012 140734679478240 140570731736448 140570839946827 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 2.69
Current children cumulated vsize (KiB) 1069068

[startup+6.30058 s]
/proc/loadavg: 1.16 1.03 0.93 2/67 10718
/proc/meminfo: memFree=78240/1022884 swapFree=0/0
[pid=10706] ppid=10705 vsize=9168 CPUtime=0
/proc/10706/stat : 10706 (p2cudf-basic-1.) S 10705 10706 32685 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 37745431 9388032 331 18446744073709551615 4194304 5129932 140735739776768 140735739774912 139912303322206 0 65536 16781316 65538 0 0 0 17 0 0 0 3 0 0
/proc/10706/statm: 2292 331 280 229 0 52 0
[pid=10709] ppid=10706 vsize=1049356 CPUtime=5.63
/proc/10709/stat : 10709 (java) S 10706 10706 32685 0 -1 4202496 137306 0 21 0 521 42 0 0 20 0 10 0 37745436 1074540544 129878 18446744073709551615 4194304 4228012 140734679478240 140734679469264 140570839932533 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 5 0 0
/proc/10709/statm: 262339 129878 2370 9 0 249689 0
[pid=10709/tid=10710] ppid=10706 vsize=1049356 CPUtime=3.09
/proc/10709/task/10710/stat : 10710 (java) R 10706 10706 32685 0 -1 4202560 47385 0 9 0 293 16 0 0 20 0 10 0 37745442 1074540544 129878 18446744073709551615 4194304 4228012 140734679478240 140570846458560 140570744328958 0 4 0 16800975 0 0 0 -1 0 0 0 55 0 0
[pid=10709/tid=10711] ppid=10706 vsize=1049356 CPUtime=1.54
/proc/10709/task/10711/stat : 10711 (java) S 10706 10706 32685 0 -1 4202560 69249 0 0 0 136 18 0 0 20 0 10 0 37745451 1074540544 129878 18446744073709551615 4194304 4228012 140734679478240 140570739104896 140570839946827 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10712] ppid=10706 vsize=1049356 CPUtime=0
/proc/10709/task/10712/stat : 10712 (java) S 10706 10706 32685 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 37745451 1074540544 129878 18446744073709551615 4194304 4228012 140734679478240 140570738051088 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10713] ppid=10706 vsize=1049356 CPUtime=0
/proc/10709/task/10713/stat : 10713 (java) S 10706 10706 32685 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 37745451 1074540544 129878 18446744073709551615 4194304 4228012 140734679478240 140570736998304 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10714] ppid=10706 vsize=1049356 CPUtime=0
/proc/10709/task/10714/stat : 10714 (java) S 10706 10706 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 37745458 1074540544 129878 18446744073709551615 4194304 4228012 140734679478240 140570735946736 140570839954464 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10715] ppid=10706 vsize=1049356 CPUtime=0.5
/proc/10709/task/10715/stat : 10715 (java) S 10706 10706 32685 0 -1 4202560 8605 0 0 0 48 2 0 0 20 0 10 0 37745458 1074540544 129878 18446744073709551615 4194304 4228012 140734679478240 140570734894096 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10716] ppid=10706 vsize=1049356 CPUtime=0.47
/proc/10709/task/10716/stat : 10716 (java) S 10706 10706 32685 0 -1 4202560 10789 0 0 0 42 5 0 0 20 0 10 0 37745458 1074540544 129878 18446744073709551615 4194304 4228012 140734679478240 140570733841424 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10717] ppid=10706 vsize=1049356 CPUtime=0
/proc/10709/task/10717/stat : 10717 (java) S 10706 10706 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 37745458 1074540544 129878 18446744073709551615 4194304 4228012 140734679478240 140570732788944 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10718] ppid=10706 vsize=1049356 CPUtime=0
/proc/10709/task/10718/stat : 10718 (java) S 10706 10706 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 37745458 1074540544 129878 18446744073709551615 4194304 4228012 140734679478240 140570731736448 140570839946827 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 5.63
Current children cumulated vsize (KiB) 1058524

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

[startup+6.40082 s]
/proc/loadavg: 1.16 1.03 0.93 2/67 10718
/proc/meminfo: memFree=78240/1022884 swapFree=0/0
[pid=10706] ppid=10705 vsize=9168 CPUtime=0
/proc/10706/stat : 10706 (p2cudf-basic-1.) S 10705 10706 32685 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 37745431 9388032 331 18446744073709551615 4194304 5129932 140735739776768 140735739774912 139912303322206 0 65536 16781316 65538 0 0 0 17 0 0 0 3 0 0
/proc/10706/statm: 2292 331 280 229 0 52 0
[pid=10709] ppid=10706 vsize=1049356 CPUtime=5.69
/proc/10709/stat : 10709 (java) S 10706 10706 32685 0 -1 4202496 137306 0 21 0 527 42 0 0 20 0 10 0 37745436 1074540544 129878 18446744073709551615 4194304 4228012 140734679478240 140734679469264 140570839932533 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 5 0 0
/proc/10709/statm: 262339 129878 2370 9 0 249689 0
[pid=10709/tid=10710] ppid=10706 vsize=1049356 CPUtime=3.15
/proc/10709/task/10710/stat : 10710 (java) R 10706 10706 32685 0 -1 4202560 47385 0 9 0 299 16 0 0 20 0 10 0 37745442 1074540544 129878 18446744073709551615 4194304 4228012 140734679478240 140570846458560 140570744268416 0 4 0 16800975 0 0 0 -1 0 0 0 59 0 0
[pid=10709/tid=10711] ppid=10706 vsize=1049356 CPUtime=1.54
/proc/10709/task/10711/stat : 10711 (java) S 10706 10706 32685 0 -1 4202560 69249 0 0 0 136 18 0 0 20 0 10 0 37745451 1074540544 129878 18446744073709551615 4194304 4228012 140734679478240 140570739104896 140570839946827 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10712] ppid=10706 vsize=1049356 CPUtime=0
/proc/10709/task/10712/stat : 10712 (java) S 10706 10706 32685 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 37745451 1074540544 129878 18446744073709551615 4194304 4228012 140734679478240 140570738051088 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10713] ppid=10706 vsize=1049356 CPUtime=0
/proc/10709/task/10713/stat : 10713 (java) S 10706 10706 32685 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 37745451 1074540544 129878 18446744073709551615 4194304 4228012 140734679478240 140570736998304 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10714] ppid=10706 vsize=1049356 CPUtime=0
/proc/10709/task/10714/stat : 10714 (java) S 10706 10706 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 37745458 1074540544 129878 18446744073709551615 4194304 4228012 140734679478240 140570735946736 140570839954464 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10715] ppid=10706 vsize=1049356 CPUtime=0.5
/proc/10709/task/10715/stat : 10715 (java) S 10706 10706 32685 0 -1 4202560 8605 0 0 0 48 2 0 0 20 0 10 0 37745458 1074540544 129878 18446744073709551615 4194304 4228012 140734679478240 140570734894096 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10716] ppid=10706 vsize=1049356 CPUtime=0.47
/proc/10709/task/10716/stat : 10716 (java) S 10706 10706 32685 0 -1 4202560 10789 0 0 0 42 5 0 0 20 0 10 0 37745458 1074540544 129878 18446744073709551615 4194304 4228012 140734679478240 140570733841424 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10717] ppid=10706 vsize=1049356 CPUtime=0
/proc/10709/task/10717/stat : 10717 (java) S 10706 10706 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 37745458 1074540544 129878 18446744073709551615 4194304 4228012 140734679478240 140570732788944 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10718] ppid=10706 vsize=1049356 CPUtime=0
/proc/10709/task/10718/stat : 10718 (java) S 10706 10706 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 37745458 1074540544 129878 18446744073709551615 4194304 4228012 140734679478240 140570731736448 140570839946827 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 5.69
Current children cumulated vsize (KiB) 1058524

[startup+9.60075 s]
/proc/loadavg: 1.15 1.03 0.93 3/67 10718
/proc/meminfo: memFree=10164/1022884 swapFree=0/0
[pid=10706] ppid=10705 vsize=9168 CPUtime=0
/proc/10706/stat : 10706 (p2cudf-basic-1.) S 10705 10706 32685 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 37745431 9388032 331 18446744073709551615 4194304 5129932 140735739776768 140735739774912 139912303322206 0 65536 16781316 65538 0 0 0 17 0 0 0 3 0 0
/proc/10706/statm: 2292 331 280 229 0 52 0
[pid=10709] ppid=10706 vsize=1049356 CPUtime=8.77
/proc/10709/stat : 10709 (java) S 10706 10706 32685 0 -1 4202496 154662 0 21 0 827 50 0 0 20 0 10 0 37745436 1074540544 145089 18446744073709551615 4194304 4228012 140734679478240 140734679469264 140570839932533 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 5 0 0
/proc/10709/statm: 262339 145089 2376 9 0 249689 0
[pid=10709/tid=10710] ppid=10706 vsize=1049356 CPUtime=4.33
/proc/10709/task/10710/stat : 10710 (java) R 10706 10706 32685 0 -1 4202560 47715 0 9 0 416 17 0 0 20 0 10 0 37745442 1074540544 145089 18446744073709551615 4194304 4228012 140734679478240 140570846466824 140570743977824 0 4 0 16800975 0 0 0 -1 0 0 0 59 0 0
[pid=10709/tid=10711] ppid=10706 vsize=1049356 CPUtime=1.96
/proc/10709/task/10711/stat : 10711 (java) S 10706 10706 32685 0 -1 4202560 83867 0 0 0 173 23 0 0 20 0 10 0 37745451 1074540544 145089 18446744073709551615 4194304 4228012 140734679478240 140570739104896 140570839946827 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10712] ppid=10706 vsize=1049356 CPUtime=0
/proc/10709/task/10712/stat : 10712 (java) S 10706 10706 32685 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 37745451 1074540544 145089 18446744073709551615 4194304 4228012 140734679478240 140570738051088 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10713] ppid=10706 vsize=1049356 CPUtime=0
/proc/10709/task/10713/stat : 10713 (java) S 10706 10706 32685 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 37745451 1074540544 145089 18446744073709551615 4194304 4228012 140734679478240 140570736998304 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10714] ppid=10706 vsize=1049356 CPUtime=0
/proc/10709/task/10714/stat : 10714 (java) S 10706 10706 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 37745458 1074540544 145089 18446744073709551615 4194304 4228012 140734679478240 140570735946736 140570839954464 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10715] ppid=10706 vsize=1049356 CPUtime=1.26
/proc/10709/task/10715/stat : 10715 (java) R 10706 10706 32685 0 -1 4202560 8717 0 0 0 124 2 0 0 20 0 10 0 37745458 1074540544 145089 18446744073709551615 4194304 4228012 140734679478240 140570734894096 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10716] ppid=10706 vsize=1049356 CPUtime=1.19
/proc/10709/task/10716/stat : 10716 (java) S 10706 10706 32685 0 -1 4202560 13085 0 0 0 112 7 0 0 20 0 10 0 37745458 1074540544 145089 18446744073709551615 4194304 4228012 140734679478240 140570733841424 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10717] ppid=10706 vsize=1049356 CPUtime=0
/proc/10709/task/10717/stat : 10717 (java) S 10706 10706 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 37745458 1074540544 145089 18446744073709551615 4194304 4228012 140734679478240 140570732788944 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10718] ppid=10706 vsize=1049356 CPUtime=0
/proc/10709/task/10718/stat : 10718 (java) S 10706 10706 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 37745458 1074540544 145089 18446744073709551615 4194304 4228012 140734679478240 140570731736448 140570839946827 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 8.77
Current children cumulated vsize (KiB) 1058524

[startup+10.4006 s]
/proc/loadavg: 1.15 1.03 0.93 3/68 10719
/proc/meminfo: memFree=10048/1022884 swapFree=0/0
[pid=10706] ppid=10705 vsize=9168 CPUtime=0
/proc/10706/stat : 10706 (p2cudf-basic-1.) S 10705 10706 32685 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 37745431 9388032 331 18446744073709551615 4194304 5129932 140735739776768 140735739774912 139912303322206 0 65536 16781316 65538 0 0 0 17 0 0 0 3 0 0
/proc/10706/statm: 2292 331 280 229 0 52 0
[pid=10709] ppid=10706 vsize=1043024 CPUtime=9.56
/proc/10709/stat : 10709 (java) S 10706 10706 32685 0 -1 4202496 155068 0 21 0 905 51 0 0 20 0 11 0 37745436 1068056576 143453 18446744073709551615 4194304 4228012 140734679478240 140734679469264 140570839932533 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 5 0 0
/proc/10709/statm: 260756 143453 2379 9 0 248106 0
[pid=10709/tid=10710] ppid=10706 vsize=1043024 CPUtime=4.73
/proc/10709/task/10710/stat : 10710 (java) R 10706 10706 32685 0 -1 4202560 47760 0 9 0 455 18 0 0 20 0 11 0 37745442 1068056576 143453 18446744073709551615 4194304 4228012 140734679478240 140570846466264 140570745276460 0 4 0 16800975 0 0 0 -1 0 0 0 59 0 0
[pid=10709/tid=10711] ppid=10706 vsize=1043024 CPUtime=1.96
/proc/10709/task/10711/stat : 10711 (java) S 10706 10706 32685 0 -1 4202560 83868 0 0 0 173 23 0 0 20 0 11 0 37745451 1068056576 143453 18446744073709551615 4194304 4228012 140734679478240 140570739104896 140570839946827 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10712] ppid=10706 vsize=1043024 CPUtime=0
/proc/10709/task/10712/stat : 10712 (java) S 10706 10706 32685 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 37745451 1068056576 143453 18446744073709551615 4194304 4228012 140734679478240 140570738051088 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10713] ppid=10706 vsize=1043024 CPUtime=0
/proc/10709/task/10713/stat : 10713 (java) S 10706 10706 32685 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 37745451 1068056576 143453 18446744073709551615 4194304 4228012 140734679478240 140570736998304 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10714] ppid=10706 vsize=1043024 CPUtime=0
/proc/10709/task/10714/stat : 10714 (java) S 10706 10706 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 37745458 1068056576 143453 18446744073709551615 4194304 4228012 140734679478240 140570735946736 140570839954464 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10715] ppid=10706 vsize=1043024 CPUtime=1.43
/proc/10709/task/10715/stat : 10715 (java) S 10706 10706 32685 0 -1 4202560 8731 0 0 0 141 2 0 0 20 0 11 0 37745458 1068056576 143453 18446744073709551615 4194304 4228012 140734679478240 140570734894096 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10716] ppid=10706 vsize=1043024 CPUtime=1.41
/proc/10709/task/10716/stat : 10716 (java) S 10706 10706 32685 0 -1 4202560 13425 0 0 0 133 8 0 0 20 0 11 0 37745458 1068056576 143453 18446744073709551615 4194304 4228012 140734679478240 140570733841424 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10717] ppid=10706 vsize=1043024 CPUtime=0
/proc/10709/task/10717/stat : 10717 (java) S 10706 10706 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 37745458 1068056576 143453 18446744073709551615 4194304 4228012 140734679478240 140570732788944 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10718] ppid=10706 vsize=1043024 CPUtime=0
/proc/10709/task/10718/stat : 10718 (java) S 10706 10706 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 37745458 1068056576 143453 18446744073709551615 4194304 4228012 140734679478240 140570731736448 140570839946827 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10719] ppid=10706 vsize=1043024 CPUtime=0
/proc/10709/task/10719/stat : 10719 (java) S 10706 10706 32685 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 11 0 37746395 1068056576 143453 18446744073709551615 4194304 4228012 140734679478240 140570730534752 140570839946827 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 9.56
Current children cumulated vsize (KiB) 1052192

[startup+11.2007 s]
/proc/loadavg: 1.15 1.03 0.93 1/68 10720
/proc/meminfo: memFree=16240/1022884 swapFree=0/0
[pid=10706] ppid=10705 vsize=9168 CPUtime=0
/proc/10706/stat : 10706 (p2cudf-basic-1.) S 10705 10706 32685 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 37745431 9388032 331 18446744073709551615 4194304 5129932 140735739776768 140735739774912 139912303322206 0 65536 16781316 65538 0 0 0 17 0 0 0 3 0 0
/proc/10706/statm: 2292 331 280 229 0 52 0
[pid=10709] ppid=10706 vsize=1044052 CPUtime=9.98
/proc/10709/stat : 10709 (java) S 10706 10706 32685 0 -1 4202496 155100 0 21 0 947 51 0 0 20 0 11 0 37745436 1069109248 143483 18446744073709551615 4194304 4228012 140734679478240 140734679469264 140570839932533 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 5 0 0
/proc/10709/statm: 261013 143483 2381 9 0 248363 0
[pid=10709/tid=10710] ppid=10706 vsize=1044052 CPUtime=5.02
/proc/10709/task/10710/stat : 10710 (java) S 10706 10706 32685 0 -1 4202560 47770 0 9 0 484 18 0 0 20 0 11 0 37745442 1069109248 143483 18446744073709551615 4194304 4228012 140734679478240 140570846466992 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 59 0 0
[pid=10709/tid=10711] ppid=10706 vsize=1044052 CPUtime=1.96
/proc/10709/task/10711/stat : 10711 (java) S 10706 10706 32685 0 -1 4202560 83868 0 0 0 173 23 0 0 20 0 11 0 37745451 1069109248 143483 18446744073709551615 4194304 4228012 140734679478240 140570739104896 140570839946827 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10712] ppid=10706 vsize=1044052 CPUtime=0
/proc/10709/task/10712/stat : 10712 (java) S 10706 10706 32685 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 37745451 1069109248 143483 18446744073709551615 4194304 4228012 140734679478240 140570738051088 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10713] ppid=10706 vsize=1044052 CPUtime=0
/proc/10709/task/10713/stat : 10713 (java) S 10706 10706 32685 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 37745451 1069109248 143483 18446744073709551615 4194304 4228012 140734679478240 140570736998304 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10714] ppid=10706 vsize=1044052 CPUtime=0
/proc/10709/task/10714/stat : 10714 (java) S 10706 10706 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 37745458 1069109248 143483 18446744073709551615 4194304 4228012 140734679478240 140570735946736 140570839954464 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10715] ppid=10706 vsize=1044052 CPUtime=1.5
/proc/10709/task/10715/stat : 10715 (java) S 10706 10706 32685 0 -1 4202560 8738 0 0 0 148 2 0 0 20 0 11 0 37745458 1069109248 143483 18446744073709551615 4194304 4228012 140734679478240 140570734894096 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10716] ppid=10706 vsize=1044052 CPUtime=1.48
/proc/10709/task/10716/stat : 10716 (java) S 10706 10706 32685 0 -1 4202560 13434 0 0 0 140 8 0 0 20 0 11 0 37745458 1069109248 143483 18446744073709551615 4194304 4228012 140734679478240 140570733841424 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10717] ppid=10706 vsize=1044052 CPUtime=0
/proc/10709/task/10717/stat : 10717 (java) S 10706 10706 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 37745458 1069109248 143483 18446744073709551615 4194304 4228012 140734679478240 140570732788944 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10718] ppid=10706 vsize=1044052 CPUtime=0
/proc/10709/task/10718/stat : 10718 (java) S 10706 10706 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 37745458 1069109248 143483 18446744073709551615 4194304 4228012 140734679478240 140570731736448 140570839946827 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10720] ppid=10706 vsize=1044052 CPUtime=0
/proc/10709/task/10720/stat : 10720 (java) S 10706 10706 32685 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 11 0 37746512 1069109248 143483 18446744073709551615 4194304 4228012 140734679478240 140570729482416 140570839946827 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 9.98
Current children cumulated vsize (KiB) 1053220

[startup+11.4008 s]
/proc/loadavg: 1.15 1.03 0.93 1/68 10720
/proc/meminfo: memFree=16240/1022884 swapFree=0/0
[pid=10706] ppid=10705 vsize=9168 CPUtime=0
/proc/10706/stat : 10706 (p2cudf-basic-1.) S 10705 10706 32685 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 37745431 9388032 331 18446744073709551615 4194304 5129932 140735739776768 140735739774912 139912303322206 0 65536 16781316 65538 0 0 0 17 0 0 0 3 0 0
/proc/10706/statm: 2292 331 280 229 0 52 0
[pid=10709] ppid=10706 vsize=1044052 CPUtime=10.05
/proc/10709/stat : 10709 (java) S 10706 10706 32685 0 -1 4202496 155102 0 21 0 952 53 0 0 20 0 11 0 37745436 1069109248 143485 18446744073709551615 4194304 4228012 140734679478240 140734679469264 140570839932533 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 5 0 0
/proc/10709/statm: 261013 143485 2381 9 0 248363 0
[pid=10709/tid=10710] ppid=10706 vsize=1044052 CPUtime=5.02
/proc/10709/task/10710/stat : 10710 (java) S 10706 10706 32685 0 -1 4202560 47770 0 9 0 484 18 0 0 20 0 11 0 37745442 1069109248 143485 18446744073709551615 4194304 4228012 140734679478240 140570846466992 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 59 0 0
[pid=10709/tid=10711] ppid=10706 vsize=1044052 CPUtime=1.96
/proc/10709/task/10711/stat : 10711 (java) S 10706 10706 32685 0 -1 4202560 83868 0 0 0 173 23 0 0 20 0 11 0 37745451 1069109248 143485 18446744073709551615 4194304 4228012 140734679478240 140570739104896 140570839946827 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10712] ppid=10706 vsize=1044052 CPUtime=0
/proc/10709/task/10712/stat : 10712 (java) S 10706 10706 32685 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 37745451 1069109248 143485 18446744073709551615 4194304 4228012 140734679478240 140570738051088 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10713] ppid=10706 vsize=1044052 CPUtime=0
/proc/10709/task/10713/stat : 10713 (java) S 10706 10706 32685 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 37745451 1069109248 143485 18446744073709551615 4194304 4228012 140734679478240 140570736998304 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10714] ppid=10706 vsize=1044052 CPUtime=0
/proc/10709/task/10714/stat : 10714 (java) S 10706 10706 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 37745458 1069109248 143485 18446744073709551615 4194304 4228012 140734679478240 140570735946736 140570839954464 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10715] ppid=10706 vsize=1044052 CPUtime=1.5
/proc/10709/task/10715/stat : 10715 (java) S 10706 10706 32685 0 -1 4202560 8738 0 0 0 148 2 0 0 20 0 11 0 37745458 1069109248 143485 18446744073709551615 4194304 4228012 140734679478240 140570734894096 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10716] ppid=10706 vsize=1044052 CPUtime=1.48
/proc/10709/task/10716/stat : 10716 (java) S 10706 10706 32685 0 -1 4202560 13434 0 0 0 140 8 0 0 20 0 11 0 37745458 1069109248 143485 18446744073709551615 4194304 4228012 140734679478240 140570733841424 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10717] ppid=10706 vsize=1044052 CPUtime=0
/proc/10709/task/10717/stat : 10717 (java) S 10706 10706 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 37745458 1069109248 143485 18446744073709551615 4194304 4228012 140734679478240 140570732788944 140570839945940 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10718] ppid=10706 vsize=1044052 CPUtime=0
/proc/10709/task/10718/stat : 10718 (java) S 10706 10706 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 37745458 1069109248 143485 18446744073709551615 4194304 4228012 140734679478240 140570731736448 140570839946827 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=10709/tid=10720] ppid=10706 vsize=1044052 CPUtime=0.05
/proc/10709/task/10720/stat : 10720 (java) R 10706 10706 32685 0 -1 4202560 8 0 0 0 3 2 0 0 20 0 11 0 37746512 1069109248 143485 18446744073709551615 4194304 4228012 140734679478240 140570729473216 140570744869189 0 4 0 16800975 0 0 0 -1 0 0 0 1 0 0
Current children cumulated CPU time (s) 10.05
Current children cumulated vsize (KiB) 1053220

Child status: 0
Real time (s): 11.5
CPU time (s): 10.1606
CPU user time (s): 9.5686
CPU system time (s): 0.592037
CPU usage (%): 88.3534
Max. virtual memory (cumulated for all children) (KiB): 1069540

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 9.5686
system time used= 0.592037
maximum resident set size= 580708
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 155871
page faults= 24
swaps= 0
block input operations= 70512
block output operations= 200
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 1209
involuntary context switches= 1976

runsolver used 0.028001 second user time and 0.080005 second system time

The end