runsolver Copyright (C) 2010 Olivier ROUSSEL

This is runsolver version 3.2.9a (svn: 651)

This program is distributed in the hope that it will be useful,
but WITHOUT ANY WARRANTY; without even the implied warranty of
MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
GNU General Public License for more details.

command line: runsolver -s SIGUSR1 -M 1124 -C 300 -d 10 -w /tmp/misc2012/2012-09-02-22:42/full/p2cudf-full-1.15/slowlink/real/301cbe92-a79c-11e0-9181-00163e1e087d.cudf.log.runsolver /home/competition/p2cudf-full-1.15/p2cudf-full-1.15 /home/competition/data/real/301cbe92-a79c-11e0-9181-00163e1e087d.cudf /tmp/misc2012/2012-09-02-22:42/full/p2cudf-full-1.15/slowlink/real/301cbe92-a79c-11e0-9181-00163e1e087d.cudf.result -sum(changed,installedsize),-count(removed),-notuptodate(solution),-count(changed) 

Enforcing CPUTime limit (soft limit, will send signal-name then SIGKILL): 300 seconds
Enforcing CPUTime limit (hard limit, will send SIGXCPU): 330 seconds
Enforcing VSIZE limit (soft limit, will send signal-name then SIGKILL): 1150976 KiB
Enforcing VSIZE limit (hard limit, stack expansion will fail with SIGSEGV, brk() and mmap() will return ENOMEM): 1202176 KiB

[startup+0 s]
/proc/loadavg: 1.56 1.39 1.17 2/59 6686
/proc/meminfo: memFree=446864/1022884 swapFree=0/0
[pid=6686] ppid=6685 vsize=3152 CPUtime=0
/proc/6686/stat : 6686 (runsolver) R 6685 1733 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 1 0 120859985 3227648 32 18446744073709551615 134512640 134586868 4289936912 4289934960 4151624752 0 0 16781316 24578 0 0 0 17 0 0 0 0 0 0
/proc/6686/statm: 788 32 0 19 0 73 0
Current StackSize limit: 8192 KiB


[startup+0.181737 s]
/proc/loadavg: 1.56 1.39 1.17 2/59 6686
/proc/meminfo: memFree=446864/1022884 swapFree=0/0
[pid=6686] ppid=6685 vsize=9172 CPUtime=0
/proc/6686/stat : 6686 (p2cudf-full-1.1) S 6685 6686 1733 0 -1 4202496 457 292 0 0 0 0 0 0 20 0 1 0 120859985 9392128 331 18446744073709551615 4194304 5129932 140734010475216 140734010473360 140114724373598 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/6686/statm: 2293 331 280 229 0 53 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9172

[startup+0.200278 s]
/proc/loadavg: 1.56 1.39 1.17 2/59 6686
/proc/meminfo: memFree=446864/1022884 swapFree=0/0
[pid=6686] ppid=6685 vsize=9172 CPUtime=0
/proc/6686/stat : 6686 (p2cudf-full-1.1) S 6685 6686 1733 0 -1 4202496 457 292 0 0 0 0 0 0 20 0 1 0 120859985 9392128 331 18446744073709551615 4194304 5129932 140734010475216 140734010473360 140114724373598 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/6686/statm: 2293 331 280 229 0 53 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9172

[startup+0.300267 s]
/proc/loadavg: 1.56 1.39 1.17 2/59 6686
/proc/meminfo: memFree=446864/1022884 swapFree=0/0
[pid=6686] ppid=6685 vsize=9172 CPUtime=0
/proc/6686/stat : 6686 (p2cudf-full-1.1) S 6685 6686 1733 0 -1 4202496 457 292 0 0 0 0 0 0 20 0 1 0 120859985 9392128 331 18446744073709551615 4194304 5129932 140734010475216 140734010473360 140114724373598 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/6686/statm: 2293 331 280 229 0 53 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9172

[startup+0.700243 s]
/proc/loadavg: 1.56 1.39 1.17 2/59 6686
/proc/meminfo: memFree=446864/1022884 swapFree=0/0
[pid=6686] ppid=6685 vsize=9172 CPUtime=0
/proc/6686/stat : 6686 (p2cudf-full-1.1) S 6685 6686 1733 0 -1 4202496 457 292 0 0 0 0 0 0 20 0 1 0 120859985 9392128 331 18446744073709551615 4194304 5129932 140734010475216 140734010473360 140114724373598 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/6686/statm: 2293 331 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.56 1.39 1.17 4/70 6698
/proc/meminfo: memFree=343476/1022884 swapFree=0/0
[pid=6686] ppid=6685 vsize=9172 CPUtime=0
/proc/6686/stat : 6686 (p2cudf-full-1.1) S 6685 6686 1733 0 -1 4202496 457 292 0 0 0 0 0 0 20 0 1 0 120859985 9392128 331 18446744073709551615 4194304 5129932 140734010475216 140734010473360 140114724373598 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/6686/statm: 2293 331 280 229 0 53 0
[pid=6689] ppid=6686 vsize=1071972 CPUtime=1.47
/proc/6689/stat : 6689 (java) S 6686 6686 1733 0 -1 4202496 39844 0 0 0 135 12 0 0 20 0 10 0 120859986 1097699328 35590 18446744073709551615 4194304 4228012 140734464163168 140734464154192 139882899754613 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/6689/statm: 267993 35590 2348 9 0 255343 0
[pid=6689/tid=6690] ppid=6686 vsize=1071972 CPUtime=0.63
/proc/6689/task/6690/stat : 6690 (java) R 6686 6686 1733 0 -1 4202560 18694 0 0 0 54 9 0 0 20 0 10 0 120859987 1097699328 35590 18446744073709551615 4194304 4228012 140734464163168 139882906280608 139882803800168 0 4 0 16800975 0 0 0 -1 0 0 0 1 0 0
[pid=6689/tid=6691] ppid=6686 vsize=1071972 CPUtime=0
/proc/6689/task/6691/stat : 6691 (java) S 6686 6686 1733 0 -1 4202560 4 0 0 0 0 0 0 0 20 0 10 0 120859990 1097699328 35590 18446744073709551615 4194304 4228012 140734464163168 139882798926976 139882899768907 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6692] ppid=6686 vsize=1071972 CPUtime=0
/proc/6689/task/6692/stat : 6692 (java) S 6686 6686 1733 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 10 0 120859991 1097699328 35590 18446744073709551615 4194304 4228012 140734464163168 139882797873168 139882899768020 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6693] ppid=6686 vsize=1071972 CPUtime=0
/proc/6689/task/6693/stat : 6693 (java) S 6686 6686 1733 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 10 0 120859991 1097699328 35590 18446744073709551615 4194304 4228012 140734464163168 139882796820384 139882899768020 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6694] ppid=6686 vsize=1071972 CPUtime=0
/proc/6689/task/6694/stat : 6694 (java) S 6686 6686 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 120859994 1097699328 35590 18446744073709551615 4194304 4228012 140734464163168 139882795768816 139882899776544 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6695] ppid=6686 vsize=1071972 CPUtime=0.42
/proc/6689/task/6695/stat : 6695 (java) R 6686 6686 1733 0 -1 4202560 10470 0 0 0 41 1 0 0 20 0 10 0 120859994 1097699328 35590 18446744073709551615 4194304 4228012 140734464163168 139882794703896 139882886080203 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6696] ppid=6686 vsize=1071972 CPUtime=0.4
/proc/6689/task/6696/stat : 6696 (java) R 6686 6686 1733 0 -1 4202560 9387 0 0 0 38 2 0 0 20 0 10 0 120859994 1097699328 35590 18446744073709551615 4194304 4228012 140734464163168 139882793663248 139882885480339 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6697] ppid=6686 vsize=1071972 CPUtime=0
/proc/6689/task/6697/stat : 6697 (java) S 6686 6686 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 120859994 1097699328 35590 18446744073709551615 4194304 4228012 140734464163168 139882792611024 139882899768020 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6698] ppid=6686 vsize=1071972 CPUtime=0
/proc/6689/task/6698/stat : 6698 (java) S 6686 6686 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 120859994 1097699328 35590 18446744073709551615 4194304 4228012 140734464163168 139882791558528 139882899768907 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 1.47
Current children cumulated vsize (KiB) 1081144

[startup+3.10075 s]
/proc/loadavg: 1.67 1.42 1.18 2/70 6698
/proc/meminfo: memFree=160948/1022884 swapFree=0/0
[pid=6686] ppid=6685 vsize=9172 CPUtime=0
/proc/6686/stat : 6686 (p2cudf-full-1.1) S 6685 6686 1733 0 -1 4202496 457 292 0 0 0 0 0 0 20 0 1 0 120859985 9392128 331 18446744073709551615 4194304 5129932 140734010475216 140734010473360 140114724373598 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/6686/statm: 2293 331 280 229 0 53 0
[pid=6689] ppid=6686 vsize=1071972 CPUtime=2.98
/proc/6689/stat : 6689 (java) S 6686 6686 1733 0 -1 4202496 92234 0 0 0 269 29 0 0 20 0 10 0 120859986 1097699328 86280 18446744073709551615 4194304 4228012 140734464163168 140734464154192 139882899754613 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/6689/statm: 267993 86280 2369 9 0 255343 0
[pid=6689/tid=6690] ppid=6686 vsize=1071972 CPUtime=1.53
/proc/6689/task/6690/stat : 6690 (java) R 6686 6686 1733 0 -1 4202560 47406 0 0 0 135 18 0 0 20 0 10 0 120859987 1097699328 86280 18446744073709551615 4194304 4228012 140734464163168 139882906280640 139882804154969 0 4 0 16800975 0 0 0 -1 0 0 0 8 0 0
[pid=6689/tid=6691] ppid=6686 vsize=1071972 CPUtime=0.42
/proc/6689/task/6691/stat : 6691 (java) S 6686 6686 1733 0 -1 4202560 22051 0 0 0 36 6 0 0 20 0 10 0 120859990 1097699328 86280 18446744073709551615 4194304 4228012 140734464163168 139882798926976 139882899768907 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6692] ppid=6686 vsize=1071972 CPUtime=0
/proc/6689/task/6692/stat : 6692 (java) S 6686 6686 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 120859991 1097699328 86280 18446744073709551615 4194304 4228012 140734464163168 139882797873168 139882899768020 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6693] ppid=6686 vsize=1071972 CPUtime=0
/proc/6689/task/6693/stat : 6693 (java) S 6686 6686 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 120859991 1097699328 86280 18446744073709551615 4194304 4228012 140734464163168 139882796820384 139882899768020 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6694] ppid=6686 vsize=1071972 CPUtime=0
/proc/6689/task/6694/stat : 6694 (java) S 6686 6686 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 120859994 1097699328 86280 18446744073709551615 4194304 4228012 140734464163168 139882795768816 139882899776544 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6695] ppid=6686 vsize=1071972 CPUtime=0.53
/proc/6689/task/6695/stat : 6695 (java) R 6686 6686 1733 0 -1 4202560 12029 0 0 0 51 2 0 0 20 0 10 0 120859994 1097699328 86280 18446744073709551615 4194304 4228012 140734464163168 139882794715920 139882886476711 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6696] ppid=6686 vsize=1071972 CPUtime=0.46
/proc/6689/task/6696/stat : 6696 (java) R 6686 6686 1733 0 -1 4202560 9455 0 0 0 44 2 0 0 20 0 10 0 120859994 1097699328 86280 18446744073709551615 4194304 4228012 140734464163168 139882793663248 139882886218023 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6697] ppid=6686 vsize=1071972 CPUtime=0
/proc/6689/task/6697/stat : 6697 (java) S 6686 6686 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 120859994 1097699328 86280 18446744073709551615 4194304 4228012 140734464163168 139882792611024 139882899768020 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6698] ppid=6686 vsize=1071972 CPUtime=0
/proc/6689/task/6698/stat : 6698 (java) S 6686 6686 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 120859994 1097699328 86280 18446744073709551615 4194304 4228012 140734464163168 139882791558528 139882899768907 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 2.98
Current children cumulated vsize (KiB) 1081144

[startup+6.30058 s]
/proc/loadavg: 1.67 1.42 1.18 4/70 6698
/proc/meminfo: memFree=9992/1022884 swapFree=0/0
[pid=6686] ppid=6685 vsize=9172 CPUtime=0
/proc/6686/stat : 6686 (p2cudf-full-1.1) S 6685 6686 1733 0 -1 4202496 457 292 0 0 0 0 0 0 20 0 1 0 120859985 9392128 331 18446744073709551615 4194304 5129932 140734010475216 140734010473360 140114724373598 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/6686/statm: 2293 331 280 229 0 53 0
[pid=6689] ppid=6686 vsize=1071972 CPUtime=6.04
/proc/6689/stat : 6689 (java) S 6686 6686 1733 0 -1 4202496 117773 0 0 0 565 39 0 0 20 0 10 0 120859986 1097699328 111777 18446744073709551615 4194304 4228012 140734464163168 140734464154192 139882899754613 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/6689/statm: 267993 111777 2373 9 0 255343 0
[pid=6689/tid=6690] ppid=6686 vsize=1071972 CPUtime=3.13
/proc/6689/task/6690/stat : 6690 (java) R 6686 6686 1733 0 -1 4202560 47705 0 0 0 293 20 0 0 20 0 10 0 120859987 1097699328 111777 18446744073709551615 4194304 4228012 140734464163168 139882906288384 139882804645170 0 4 0 16800975 0 0 0 -1 0 0 0 13 0 0
[pid=6689/tid=6691] ppid=6686 vsize=1071972 CPUtime=1.04
/proc/6689/task/6691/stat : 6691 (java) S 6686 6686 1733 0 -1 4202560 47074 0 0 0 90 14 0 0 20 0 10 0 120859990 1097699328 111777 18446744073709551615 4194304 4228012 140734464163168 139882798926976 139882899768907 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6692] ppid=6686 vsize=1071972 CPUtime=0
/proc/6689/task/6692/stat : 6692 (java) S 6686 6686 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 120859991 1097699328 111777 18446744073709551615 4194304 4228012 140734464163168 139882797873168 139882899768020 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6693] ppid=6686 vsize=1071972 CPUtime=0
/proc/6689/task/6693/stat : 6693 (java) S 6686 6686 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 120859991 1097699328 111777 18446744073709551615 4194304 4228012 140734464163168 139882796820384 139882899768020 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6694] ppid=6686 vsize=1071972 CPUtime=0
/proc/6689/task/6694/stat : 6694 (java) S 6686 6686 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 120859994 1097699328 111777 18446744073709551615 4194304 4228012 140734464163168 139882795768816 139882899776544 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6695] ppid=6686 vsize=1071972 CPUtime=0.91
/proc/6689/task/6695/stat : 6695 (java) R 6686 6686 1733 0 -1 4202560 12158 0 0 0 89 2 0 0 20 0 10 0 120859994 1097699328 111777 18446744073709551615 4194304 4228012 140734464163168 139882794715920 139882884088478 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6696] ppid=6686 vsize=1071972 CPUtime=0.92
/proc/6689/task/6696/stat : 6696 (java) R 6686 6686 1733 0 -1 4202560 9543 0 0 0 90 2 0 0 20 0 10 0 120859994 1097699328 111777 18446744073709551615 4194304 4228012 140734464163168 139882793663248 139882882602858 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6697] ppid=6686 vsize=1071972 CPUtime=0
/proc/6689/task/6697/stat : 6697 (java) S 6686 6686 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 120859994 1097699328 111777 18446744073709551615 4194304 4228012 140734464163168 139882792611024 139882899768020 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6698] ppid=6686 vsize=1071972 CPUtime=0
/proc/6689/task/6698/stat : 6698 (java) S 6686 6686 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 120859994 1097699328 111777 18446744073709551615 4194304 4228012 140734464163168 139882791558528 139882899768907 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 6.04
Current children cumulated vsize (KiB) 1081144

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

[startup+6.40076 s]
/proc/loadavg: 1.67 1.42 1.18 4/70 6698
/proc/meminfo: memFree=9992/1022884 swapFree=0/0
[pid=6686] ppid=6685 vsize=9172 CPUtime=0
/proc/6686/stat : 6686 (p2cudf-full-1.1) S 6685 6686 1733 0 -1 4202496 457 292 0 0 0 0 0 0 20 0 1 0 120859985 9392128 331 18446744073709551615 4194304 5129932 140734010475216 140734010473360 140114724373598 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/6686/statm: 2293 331 280 229 0 53 0
[pid=6689] ppid=6686 vsize=1071972 CPUtime=6.14
/proc/6689/stat : 6689 (java) S 6686 6686 1733 0 -1 4202496 118830 0 0 0 574 40 0 0 20 0 10 0 120859986 1097699328 112834 18446744073709551615 4194304 4228012 140734464163168 140734464154192 139882899754613 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/6689/statm: 267993 112834 2373 9 0 255343 0
[pid=6689/tid=6690] ppid=6686 vsize=1071972 CPUtime=3.16
/proc/6689/task/6690/stat : 6690 (java) R 6686 6686 1733 0 -1 4202560 47706 0 0 0 296 20 0 0 20 0 10 0 120859987 1097699328 112834 18446744073709551615 4194304 4228012 140734464163168 139882906288384 139882803800168 0 4 0 16800975 0 0 0 -1 0 0 0 13 0 0
[pid=6689/tid=6691] ppid=6686 vsize=1071972 CPUtime=1.04
/proc/6689/task/6691/stat : 6691 (java) S 6686 6686 1733 0 -1 4202560 47074 0 0 0 90 14 0 0 20 0 10 0 120859990 1097699328 112834 18446744073709551615 4194304 4228012 140734464163168 139882798926976 139882899768907 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6692] ppid=6686 vsize=1071972 CPUtime=0
/proc/6689/task/6692/stat : 6692 (java) S 6686 6686 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 120859991 1097699328 112834 18446744073709551615 4194304 4228012 140734464163168 139882797873168 139882899768020 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6693] ppid=6686 vsize=1071972 CPUtime=0
/proc/6689/task/6693/stat : 6693 (java) S 6686 6686 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 120859991 1097699328 112834 18446744073709551615 4194304 4228012 140734464163168 139882796820384 139882899768020 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6694] ppid=6686 vsize=1071972 CPUtime=0
/proc/6689/task/6694/stat : 6694 (java) S 6686 6686 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 120859994 1097699328 112834 18446744073709551615 4194304 4228012 140734464163168 139882795768816 139882899776544 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6695] ppid=6686 vsize=1071972 CPUtime=0.94
/proc/6689/task/6695/stat : 6695 (java) R 6686 6686 1733 0 -1 4202560 13206 0 0 0 91 3 0 0 20 0 10 0 120859994 1097699328 112834 18446744073709551615 4194304 4228012 140734464163168 139882794701560 139882883582689 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6696] ppid=6686 vsize=1071972 CPUtime=0.96
/proc/6689/task/6696/stat : 6696 (java) R 6686 6686 1733 0 -1 4202560 9551 0 0 0 94 2 0 0 20 0 10 0 120859994 1097699328 112834 18446744073709551615 4194304 4228012 140734464163168 139882793663248 139882882607226 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6697] ppid=6686 vsize=1071972 CPUtime=0
/proc/6689/task/6697/stat : 6697 (java) S 6686 6686 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 120859994 1097699328 112834 18446744073709551615 4194304 4228012 140734464163168 139882792611024 139882899768020 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6698] ppid=6686 vsize=1071972 CPUtime=0
/proc/6689/task/6698/stat : 6698 (java) S 6686 6686 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 120859994 1097699328 112834 18446744073709551615 4194304 4228012 140734464163168 139882791558528 139882899768907 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 6.14
Current children cumulated vsize (KiB) 1081144

[startup+8.00058 s]
/proc/loadavg: 1.78 1.44 1.19 2/70 6698
/proc/meminfo: memFree=9496/1022884 swapFree=0/0
[pid=6686] ppid=6685 vsize=9172 CPUtime=0
/proc/6686/stat : 6686 (p2cudf-full-1.1) S 6685 6686 1733 0 -1 4202496 457 292 0 0 0 0 0 0 20 0 1 0 120859985 9392128 331 18446744073709551615 4194304 5129932 140734010475216 140734010473360 140114724373598 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/6686/statm: 2293 331 280 229 0 53 0
[pid=6689] ppid=6686 vsize=1071972 CPUtime=7.69
/proc/6689/stat : 6689 (java) S 6686 6686 1733 0 -1 4202496 122173 0 0 0 728 41 0 0 20 0 10 0 120859986 1097699328 115649 18446744073709551615 4194304 4228012 140734464163168 140734464154192 139882899754613 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/6689/statm: 267993 115649 2375 9 0 255343 0
[pid=6689/tid=6690] ppid=6686 vsize=1071972 CPUtime=3.78
/proc/6689/task/6690/stat : 6690 (java) R 6686 6686 1733 0 -1 4202560 47747 0 0 0 358 20 0 0 20 0 10 0 120859987 1097699328 115649 18446744073709551615 4194304 4228012 140734464163168 139882906290064 139882803752951 0 4 0 16800975 0 0 0 -1 0 0 0 13 0 0
[pid=6689/tid=6691] ppid=6686 vsize=1071972 CPUtime=1.04
/proc/6689/task/6691/stat : 6691 (java) S 6686 6686 1733 0 -1 4202560 47074 0 0 0 90 14 0 0 20 0 10 0 120859990 1097699328 115649 18446744073709551615 4194304 4228012 140734464163168 139882798926976 139882899768907 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6692] ppid=6686 vsize=1071972 CPUtime=0
/proc/6689/task/6692/stat : 6692 (java) S 6686 6686 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 120859991 1097699328 115649 18446744073709551615 4194304 4228012 140734464163168 139882797873168 139882899768020 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6693] ppid=6686 vsize=1071972 CPUtime=0
/proc/6689/task/6693/stat : 6693 (java) S 6686 6686 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 120859991 1097699328 115649 18446744073709551615 4194304 4228012 140734464163168 139882796820384 139882899768020 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6694] ppid=6686 vsize=1071972 CPUtime=0
/proc/6689/task/6694/stat : 6694 (java) S 6686 6686 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 120859994 1097699328 115649 18446744073709551615 4194304 4228012 140734464163168 139882795768816 139882899776544 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6695] ppid=6686 vsize=1071972 CPUtime=1.41
/proc/6689/task/6695/stat : 6695 (java) R 6686 6686 1733 0 -1 4202560 16374 0 0 0 137 4 0 0 20 0 10 0 120859994 1097699328 115649 18446744073709551615 4194304 4228012 140734464163168 139882794715920 139882882004594 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6696] ppid=6686 vsize=1071972 CPUtime=1.43
/proc/6689/task/6696/stat : 6696 (java) R 6686 6686 1733 0 -1 4202560 9685 0 0 0 141 2 0 0 20 0 10 0 120859994 1097699328 115649 18446744073709551615 4194304 4228012 140734464163168 139882793663248 139882884058786 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6697] ppid=6686 vsize=1071972 CPUtime=0
/proc/6689/task/6697/stat : 6697 (java) S 6686 6686 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 120859994 1097699328 115649 18446744073709551615 4194304 4228012 140734464163168 139882792611024 139882899768020 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6698] ppid=6686 vsize=1071972 CPUtime=0
/proc/6689/task/6698/stat : 6698 (java) S 6686 6686 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 120859994 1097699328 115649 18446744073709551615 4194304 4228012 140734464163168 139882791558528 139882899768907 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 7.69
Current children cumulated vsize (KiB) 1081144

[startup+8.40086 s]
/proc/loadavg: 1.78 1.44 1.19 2/70 6698
/proc/meminfo: memFree=9496/1022884 swapFree=0/0
[pid=6686] ppid=6685 vsize=9172 CPUtime=0
/proc/6686/stat : 6686 (p2cudf-full-1.1) S 6685 6686 1733 0 -1 4202496 457 292 0 0 0 0 0 0 20 0 1 0 120859985 9392128 331 18446744073709551615 4194304 5129932 140734010475216 140734010473360 140114724373598 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/6686/statm: 2293 331 280 229 0 53 0
[pid=6689] ppid=6686 vsize=1073000 CPUtime=7.74
/proc/6689/stat : 6689 (java) S 6686 6686 1733 0 -1 4202496 122205 0 0 0 733 41 0 0 20 0 11 0 120859986 1098752000 115681 18446744073709551615 4194304 4228012 140734464163168 140734464154192 139882899754613 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/6689/statm: 268250 115681 2376 9 0 255600 0
[pid=6689/tid=6690] ppid=6686 vsize=1073000 CPUtime=3.8
/proc/6689/task/6690/stat : 6690 (java) S 6686 6686 1733 0 -1 4202560 47759 0 0 0 360 20 0 0 20 0 11 0 120859987 1098752000 115681 18446744073709551615 4194304 4228012 140734464163168 139882906289072 139882899768020 0 4 0 16800975 0 0 0 -1 0 0 0 13 0 0
[pid=6689/tid=6691] ppid=6686 vsize=1073000 CPUtime=1.04
/proc/6689/task/6691/stat : 6691 (java) S 6686 6686 1733 0 -1 4202560 47074 0 0 0 90 14 0 0 20 0 11 0 120859990 1098752000 115681 18446744073709551615 4194304 4228012 140734464163168 139882798926976 139882899768907 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6692] ppid=6686 vsize=1073000 CPUtime=0
/proc/6689/task/6692/stat : 6692 (java) S 6686 6686 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 120859991 1098752000 115681 18446744073709551615 4194304 4228012 140734464163168 139882797873168 139882899768020 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6693] ppid=6686 vsize=1073000 CPUtime=0
/proc/6689/task/6693/stat : 6693 (java) S 6686 6686 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 120859991 1098752000 115681 18446744073709551615 4194304 4228012 140734464163168 139882796820384 139882899768020 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6694] ppid=6686 vsize=1073000 CPUtime=0
/proc/6689/task/6694/stat : 6694 (java) S 6686 6686 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 120859994 1098752000 115681 18446744073709551615 4194304 4228012 140734464163168 139882795768816 139882899776544 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6695] ppid=6686 vsize=1073000 CPUtime=1.42
/proc/6689/task/6695/stat : 6695 (java) S 6686 6686 1733 0 -1 4202560 16377 0 0 0 138 4 0 0 20 0 11 0 120859994 1098752000 115681 18446744073709551615 4194304 4228012 140734464163168 139882794716176 139882899768020 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6696] ppid=6686 vsize=1073000 CPUtime=1.44
/proc/6689/task/6696/stat : 6696 (java) S 6686 6686 1733 0 -1 4202560 9696 0 0 0 142 2 0 0 20 0 11 0 120859994 1098752000 115681 18446744073709551615 4194304 4228012 140734464163168 139882793663504 139882899768020 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6697] ppid=6686 vsize=1073000 CPUtime=0
/proc/6689/task/6697/stat : 6697 (java) S 6686 6686 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 120859994 1098752000 115681 18446744073709551615 4194304 4228012 140734464163168 139882792611024 139882899768020 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=6689/tid=6698] ppid=6686 vsize=1073000 CPUtime=0
/proc/6689/task/6698/stat : 6698 (java) S 6686 6686 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 120859994 1098752000 115681 18446744073709551615 4194304 4228012 140734464163168 139882791558528 139882899768907 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 7.74
Current children cumulated vsize (KiB) 1082172

[startup+8.60079 s]
/proc/loadavg: 1.78 1.44 1.19 2/70 6698
/proc/meminfo: memFree=9496/1022884 swapFree=0/0
[pid=6686] ppid=6685 vsize=9172 CPUtime=0
/proc/6686/stat : 6686 (p2cudf-full-1.1) S 6685 6686 1733 0 -1 4202496 457 292 0 0 0 0 0 0 20 0 1 0 120859985 9392128 331 18446744073709551615 4194304 5129932 140734010475216 140734010473360 140114724373598 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/6686/statm: 2293 331 280 229 0 53 0
[pid=6689] ppid=6686 vsize=0 CPUtime=7.79
/proc/6689/stat : 6689 (java) Z 6686 6686 1733 0 -1 4203532 122217 0 0 0 734 45 0 0 20 0 2 0 120859986 0 0 18446744073709551615 0 0 0 0 0 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/6689/statm: 0 0 0 0 0 0 0
[pid=6689/tid=6696] ppid=6686 vsize=0 CPUtime=1.49
/proc/6689/task/6696/stat : 6696 (java) R 6686 6686 1733 0 -1 4203588 9696 0 0 0 143 6 0 0 20 0 2 0 120859994 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) 7.79
Current children cumulated vsize (KiB) 9172

Child status: 0
Real time (s): 8.60458
CPU time (s): 7.80849
CPU user time (s): 7.34846
CPU system time (s): 0.460028
CPU usage (%): 90.7481
Max. virtual memory (cumulated for all children) (KiB): 1084668

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 7.34846
system time used= 0.460028
maximum resident set size= 462756
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 122980
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= 676
involuntary context switches= 2150

runsolver used 0.008 second user time and 0.084005 second system time

The end