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/upgrade/easy/rand381.cudf.log.runsolver /home/competition/p2cudf-full-1.15/p2cudf-full-1.15 /home/competition/data/upgrade/easy/rand381.cudf /tmp/misc2012/2012-09-02-22:42/full/p2cudf-full-1.15/slowlink/upgrade/easy/rand381.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
Current StackSize limit: 8192 KiB


[startup+0 s]
/proc/loadavg: 1.16 1.25 1.17 2/59 7013
/proc/meminfo: memFree=530928/1022884 swapFree=0/0
[pid=7013] ppid=7012 vsize=9168 CPUtime=0
/proc/7013/stat : 7013 (p2cudf-full-1.1) R 7012 7013 1733 0 -1 4202496 418 0 0 0 0 0 0 0 20 0 1 0 120893168 9388032 325 18446744073709551615 4194304 5129932 140734305781920 140734305779280 140410185390438 0 65538 16781316 65536 0 0 0 17 0 0 0 0 0 0
/proc/7013/statm: 2292 325 275 229 0 52 0

[startup+0.203917 s]
/proc/loadavg: 1.16 1.25 1.17 2/59 7013
/proc/meminfo: memFree=530928/1022884 swapFree=0/0
[pid=7013] ppid=7012 vsize=9168 CPUtime=0
/proc/7013/stat : 7013 (p2cudf-full-1.1) S 7012 7013 1733 0 -1 4202496 457 291 0 0 0 0 0 0 20 0 1 0 120893168 9388032 330 18446744073709551615 4194304 5129932 140734305781920 140734305780064 140410185389150 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/7013/statm: 2292 330 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+0.300311 s]
/proc/loadavg: 1.16 1.25 1.17 2/59 7013
/proc/meminfo: memFree=530928/1022884 swapFree=0/0
[pid=7013] ppid=7012 vsize=9168 CPUtime=0
/proc/7013/stat : 7013 (p2cudf-full-1.1) S 7012 7013 1733 0 -1 4202496 457 291 0 0 0 0 0 0 20 0 1 0 120893168 9388032 330 18446744073709551615 4194304 5129932 140734305781920 140734305780064 140410185389150 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/7013/statm: 2292 330 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+0.400354 s]
/proc/loadavg: 1.16 1.25 1.17 2/59 7013
/proc/meminfo: memFree=530928/1022884 swapFree=0/0
[pid=7013] ppid=7012 vsize=9168 CPUtime=0
/proc/7013/stat : 7013 (p2cudf-full-1.1) S 7012 7013 1733 0 -1 4202496 457 291 0 0 0 0 0 0 20 0 1 0 120893168 9388032 330 18446744073709551615 4194304 5129932 140734305781920 140734305780064 140410185389150 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/7013/statm: 2292 330 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+0.700215 s]
/proc/loadavg: 1.16 1.25 1.17 2/59 7013
/proc/meminfo: memFree=530928/1022884 swapFree=0/0
[pid=7013] ppid=7012 vsize=9168 CPUtime=0
/proc/7013/stat : 7013 (p2cudf-full-1.1) S 7012 7013 1733 0 -1 4202496 457 291 0 0 0 0 0 0 20 0 1 0 120893168 9388032 330 18446744073709551615 4194304 5129932 140734305781920 140734305780064 140410185389150 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/7013/statm: 2292 330 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+1.50075 s]
/proc/loadavg: 1.16 1.25 1.17 4/70 7025
/proc/meminfo: memFree=504304/1022884 swapFree=0/0
[pid=7013] ppid=7012 vsize=9168 CPUtime=0
/proc/7013/stat : 7013 (p2cudf-full-1.1) S 7012 7013 1733 0 -1 4202496 457 291 0 0 0 0 0 0 20 0 1 0 120893168 9388032 330 18446744073709551615 4194304 5129932 140734305781920 140734305780064 140410185389150 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/7013/statm: 2292 330 280 229 0 52 0
[pid=7016] ppid=7013 vsize=961272 CPUtime=0.92
/proc/7016/stat : 7016 (java) S 7013 7013 1733 0 -1 4202496 11743 0 16 0 84 8 0 0 20 0 10 0 120893169 984342528 10432 18446744073709551615 4194304 4228012 140735096411744 140735096402768 140568314285685 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 4 0 0
/proc/7016/statm: 240318 10432 2346 9 0 227668 0
[pid=7016/tid=7017] ppid=7013 vsize=961272 CPUtime=0.48
/proc/7016/task/7017/stat : 7017 (java) R 7013 7013 1733 0 -1 4202560 6433 0 4 0 45 3 0 0 20 0 10 0 120893175 984342528 10432 18446744073709551615 4194304 4228012 140735096411744 140568320811680 140568218621711 0 4 0 16800975 0 0 0 -1 0 0 0 53 0 0
[pid=7016/tid=7018] ppid=7013 vsize=961272 CPUtime=0
/proc/7016/task/7018/stat : 7018 (java) S 7013 7013 1733 0 -1 4202560 4 0 0 0 0 0 0 0 20 0 10 0 120893181 984342528 10432 18446744073709551615 4194304 4228012 140735096411744 140568213458048 140568314299979 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7019] ppid=7013 vsize=961272 CPUtime=0
/proc/7016/task/7019/stat : 7019 (java) S 7013 7013 1733 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 10 0 120893188 984342528 10432 18446744073709551615 4194304 4228012 140735096411744 140568212404240 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7020] ppid=7013 vsize=961272 CPUtime=0
/proc/7016/task/7020/stat : 7020 (java) S 7013 7013 1733 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 10 0 120893188 984342528 10432 18446744073709551615 4194304 4228012 140735096411744 140568211351456 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7021] ppid=7013 vsize=961272 CPUtime=0
/proc/7016/task/7021/stat : 7021 (java) S 7013 7013 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 120893197 984342528 10432 18446744073709551615 4194304 4228012 140735096411744 140568210299888 140568314307616 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7022] ppid=7013 vsize=961272 CPUtime=0.22
/proc/7016/task/7022/stat : 7022 (java) R 7013 7013 1733 0 -1 4202560 2896 0 0 0 20 2 0 0 20 0 10 0 120893197 984342528 10432 18446744073709551615 4194304 4228012 140735096411744 140568209246992 140568295896644 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7023] ppid=7013 vsize=961272 CPUtime=0.19
/proc/7016/task/7023/stat : 7023 (java) R 7013 7013 1733 0 -1 4202560 1132 0 0 0 18 1 0 0 20 0 10 0 120893197 984342528 10432 18446744073709551615 4194304 4228012 140735096411744 140568208194576 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7024] ppid=7013 vsize=961272 CPUtime=0
/proc/7016/task/7024/stat : 7024 (java) S 7013 7013 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 120893197 984342528 10432 18446744073709551615 4194304 4228012 140735096411744 140568207142096 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7025] ppid=7013 vsize=961272 CPUtime=0
/proc/7016/task/7025/stat : 7025 (java) S 7013 7013 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 120893197 984342528 10432 18446744073709551615 4194304 4228012 140735096411744 140568206089600 140568314299979 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 0.92
Current children cumulated vsize (KiB) 970440

[startup+3.10073 s]
/proc/loadavg: 1.16 1.25 1.17 4/70 7025
/proc/meminfo: memFree=404112/1022884 swapFree=0/0
[pid=7013] ppid=7012 vsize=9168 CPUtime=0
/proc/7013/stat : 7013 (p2cudf-full-1.1) S 7012 7013 1733 0 -1 4202496 457 291 0 0 0 0 0 0 20 0 1 0 120893168 9388032 330 18446744073709551615 4194304 5129932 140734305781920 140734305780064 140410185389150 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/7013/statm: 2292 330 280 229 0 52 0
[pid=7016] ppid=7013 vsize=1057688 CPUtime=2.49
/proc/7016/stat : 7016 (java) S 7013 7013 1733 0 -1 4202496 62478 0 16 0 222 27 0 0 20 0 10 0 120893169 1083072512 57193 18446744073709551615 4194304 4228012 140735096411744 140735096402768 140568314285685 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 4 0 0
/proc/7016/statm: 264422 57193 2348 9 0 251772 0
[pid=7016/tid=7017] ppid=7013 vsize=1057688 CPUtime=1.16
/proc/7016/task/7017/stat : 7017 (java) R 7013 7013 1733 0 -1 4202560 41608 0 4 0 100 16 0 0 20 0 10 0 120893175 1083072512 57193 18446744073709551615 4194304 4228012 140735096411744 140568320811712 140568218666601 0 4 0 16800975 0 0 0 -1 0 0 0 53 0 0
[pid=7016/tid=7018] ppid=7013 vsize=1057688 CPUtime=0
/proc/7016/task/7018/stat : 7018 (java) S 7013 7013 1733 0 -1 4202560 4 0 0 0 0 0 0 0 20 0 10 0 120893181 1083072512 57193 18446744073709551615 4194304 4228012 140735096411744 140568213458048 140568314299979 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7019] ppid=7013 vsize=1057688 CPUtime=0
/proc/7016/task/7019/stat : 7019 (java) S 7013 7013 1733 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 10 0 120893188 1083072512 57193 18446744073709551615 4194304 4228012 140735096411744 140568212404240 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7020] ppid=7013 vsize=1057688 CPUtime=0
/proc/7016/task/7020/stat : 7020 (java) S 7013 7013 1733 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 10 0 120893188 1083072512 57193 18446744073709551615 4194304 4228012 140735096411744 140568211351456 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7021] ppid=7013 vsize=1057688 CPUtime=0
/proc/7016/task/7021/stat : 7021 (java) S 7013 7013 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 120893197 1083072512 57193 18446744073709551615 4194304 4228012 140735096411744 140568210299888 140568314307616 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7022] ppid=7013 vsize=1057688 CPUtime=0.69
/proc/7016/task/7022/stat : 7022 (java) S 7013 7013 1733 0 -1 4202560 10405 0 0 0 64 5 0 0 20 0 10 0 120893197 1083072512 57193 18446744073709551615 4194304 4228012 140735096411744 140568209247248 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7023] ppid=7013 vsize=1057688 CPUtime=0.6
/proc/7016/task/7023/stat : 7023 (java) S 7013 7013 1733 0 -1 4202560 9183 0 0 0 56 4 0 0 20 0 10 0 120893197 1083072512 57193 18446744073709551615 4194304 4228012 140735096411744 140568208194576 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7024] ppid=7013 vsize=1057688 CPUtime=0
/proc/7016/task/7024/stat : 7024 (java) S 7013 7013 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 120893197 1083072512 57193 18446744073709551615 4194304 4228012 140735096411744 140568207142096 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7025] ppid=7013 vsize=1057688 CPUtime=0
/proc/7016/task/7025/stat : 7025 (java) S 7013 7013 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 120893197 1083072512 57193 18446744073709551615 4194304 4228012 140735096411744 140568206089600 140568314299979 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 2.49
Current children cumulated vsize (KiB) 1066856

[startup+6.30079 s]
/proc/loadavg: 1.31 1.28 1.18 2/70 7025
/proc/meminfo: memFree=115812/1022884 swapFree=0/0
[pid=7013] ppid=7012 vsize=9168 CPUtime=0
/proc/7013/stat : 7013 (p2cudf-full-1.1) S 7012 7013 1733 0 -1 4202496 457 291 0 0 0 0 0 0 20 0 1 0 120893168 9388032 330 18446744073709551615 4194304 5129932 140734305781920 140734305780064 140410185389150 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/7013/statm: 2292 330 280 229 0 52 0
[pid=7016] ppid=7013 vsize=1057688 CPUtime=5.64
/proc/7016/stat : 7016 (java) S 7013 7013 1733 0 -1 4202496 113507 0 16 0 517 47 0 0 20 0 10 0 120893169 1083072512 108110 18446744073709551615 4194304 4228012 140735096411744 140735096402768 140568314285685 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 4 0 0
/proc/7016/statm: 264422 108110 2370 9 0 251772 0
[pid=7016/tid=7017] ppid=7013 vsize=1057688 CPUtime=3.08
/proc/7016/task/7017/stat : 7017 (java) R 7013 7013 1733 0 -1 4202560 47453 0 4 0 286 22 0 0 20 0 10 0 120893175 1083072512 108110 18446744073709551615 4194304 4228012 140735096411744 140568320819208 140568314310234 0 4 0 16800975 0 0 0 -1 0 0 0 57 0 0
[pid=7016/tid=7018] ppid=7013 vsize=1057688 CPUtime=1.05
/proc/7016/task/7018/stat : 7018 (java) S 7013 7013 1733 0 -1 4202560 45149 0 0 0 91 14 0 0 20 0 10 0 120893181 1083072512 108110 18446744073709551615 4194304 4228012 140735096411744 140568213458048 140568314299979 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7019] ppid=7013 vsize=1057688 CPUtime=0
/proc/7016/task/7019/stat : 7019 (java) S 7013 7013 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 120893188 1083072512 108110 18446744073709551615 4194304 4228012 140735096411744 140568212404240 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7020] ppid=7013 vsize=1057688 CPUtime=0
/proc/7016/task/7020/stat : 7020 (java) S 7013 7013 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 120893188 1083072512 108110 18446744073709551615 4194304 4228012 140735096411744 140568211351456 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7021] ppid=7013 vsize=1057688 CPUtime=0
/proc/7016/task/7021/stat : 7021 (java) S 7013 7013 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 120893197 1083072512 108110 18446744073709551615 4194304 4228012 140735096411744 140568210299888 140568314307616 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7022] ppid=7013 vsize=1057688 CPUtime=0.78
/proc/7016/task/7022/stat : 7022 (java) S 7013 7013 1733 0 -1 4202560 10409 0 0 0 73 5 0 0 20 0 10 0 120893197 1083072512 108110 18446744073709551615 4194304 4228012 140735096411744 140568209247248 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7023] ppid=7013 vsize=1057688 CPUtime=0.7
/proc/7016/task/7023/stat : 7023 (java) S 7013 7013 1733 0 -1 4202560 9214 0 0 0 65 5 0 0 20 0 10 0 120893197 1083072512 108110 18446744073709551615 4194304 4228012 140735096411744 140568208194576 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7024] ppid=7013 vsize=1057688 CPUtime=0
/proc/7016/task/7024/stat : 7024 (java) S 7013 7013 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 120893197 1083072512 108110 18446744073709551615 4194304 4228012 140735096411744 140568207142096 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7025] ppid=7013 vsize=1057688 CPUtime=0
/proc/7016/task/7025/stat : 7025 (java) S 7013 7013 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 120893197 1083072512 108110 18446744073709551615 4194304 4228012 140735096411744 140568206089600 140568314299979 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 5.64
Current children cumulated vsize (KiB) 1066856

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

[startup+6.50075 s]
/proc/loadavg: 1.31 1.28 1.18 2/70 7025
/proc/meminfo: memFree=115812/1022884 swapFree=0/0
[pid=7013] ppid=7012 vsize=9168 CPUtime=0
/proc/7013/stat : 7013 (p2cudf-full-1.1) S 7012 7013 1733 0 -1 4202496 457 291 0 0 0 0 0 0 20 0 1 0 120893168 9388032 330 18446744073709551615 4194304 5129932 140734305781920 140734305780064 140410185389150 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/7013/statm: 2292 330 280 229 0 52 0
[pid=7016] ppid=7013 vsize=1057688 CPUtime=5.83
/proc/7016/stat : 7016 (java) S 7013 7013 1733 0 -1 4202496 113555 0 16 0 536 47 0 0 20 0 10 0 120893169 1083072512 108158 18446744073709551615 4194304 4228012 140735096411744 140735096402768 140568314285685 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 4 0 0
/proc/7016/statm: 264422 108158 2370 9 0 251772 0
[pid=7016/tid=7017] ppid=7013 vsize=1057688 CPUtime=3.15
/proc/7016/task/7017/stat : 7017 (java) R 7013 7013 1733 0 -1 4202560 47454 0 4 0 293 22 0 0 20 0 10 0 120893175 1083072512 108158 18446744073709551615 4194304 4228012 140735096411744 140568320819008 140568218617584 0 4 0 16800975 0 0 0 -1 0 0 0 57 0 0
[pid=7016/tid=7018] ppid=7013 vsize=1057688 CPUtime=1.05
/proc/7016/task/7018/stat : 7018 (java) S 7013 7013 1733 0 -1 4202560 45149 0 0 0 91 14 0 0 20 0 10 0 120893181 1083072512 108158 18446744073709551615 4194304 4228012 140735096411744 140568213458048 140568314299979 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7019] ppid=7013 vsize=1057688 CPUtime=0
/proc/7016/task/7019/stat : 7019 (java) S 7013 7013 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 120893188 1083072512 108158 18446744073709551615 4194304 4228012 140735096411744 140568212404240 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7020] ppid=7013 vsize=1057688 CPUtime=0
/proc/7016/task/7020/stat : 7020 (java) S 7013 7013 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 120893188 1083072512 108158 18446744073709551615 4194304 4228012 140735096411744 140568211351456 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7021] ppid=7013 vsize=1057688 CPUtime=0
/proc/7016/task/7021/stat : 7021 (java) S 7013 7013 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 120893197 1083072512 108158 18446744073709551615 4194304 4228012 140735096411744 140568210299888 140568314307616 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7022] ppid=7013 vsize=1057688 CPUtime=0.83
/proc/7016/task/7022/stat : 7022 (java) R 7013 7013 1733 0 -1 4202560 10448 0 0 0 78 5 0 0 20 0 10 0 120893197 1083072512 108158 18446744073709551615 4194304 4228012 140735096411744 140568209246992 140568298083803 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7023] ppid=7013 vsize=1057688 CPUtime=0.77
/proc/7016/task/7023/stat : 7023 (java) R 7013 7013 1733 0 -1 4202560 9222 0 0 0 72 5 0 0 20 0 10 0 120893197 1083072512 108158 18446744073709551615 4194304 4228012 140735096411744 140568208194320 140568300803038 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7024] ppid=7013 vsize=1057688 CPUtime=0
/proc/7016/task/7024/stat : 7024 (java) S 7013 7013 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 120893197 1083072512 108158 18446744073709551615 4194304 4228012 140735096411744 140568207142096 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7025] ppid=7013 vsize=1057688 CPUtime=0
/proc/7016/task/7025/stat : 7025 (java) S 7013 7013 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 120893197 1083072512 108158 18446744073709551615 4194304 4228012 140735096411744 140568206089600 140568314299979 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 5.83
Current children cumulated vsize (KiB) 1066856

[startup+8.10075 s]
/proc/loadavg: 1.31 1.28 1.18 4/70 7025
/proc/meminfo: memFree=49224/1022884 swapFree=0/0
[pid=7013] ppid=7012 vsize=9168 CPUtime=0
/proc/7013/stat : 7013 (p2cudf-full-1.1) S 7012 7013 1733 0 -1 4202496 457 291 0 0 0 0 0 0 20 0 1 0 120893168 9388032 330 18446744073709551615 4194304 5129932 140734305781920 140734305780064 140410185389150 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/7013/statm: 2292 330 280 229 0 52 0
[pid=7016] ppid=7013 vsize=1057688 CPUtime=7.39
/proc/7016/stat : 7016 (java) S 7013 7013 1733 0 -1 4202496 122138 0 16 0 688 51 0 0 20 0 10 0 120893169 1083072512 116639 18446744073709551615 4194304 4228012 140735096411744 140735096402768 140568314285685 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 4 0 0
/proc/7016/statm: 264422 116639 2373 9 0 251772 0
[pid=7016/tid=7017] ppid=7013 vsize=1057688 CPUtime=3.67
/proc/7016/task/7017/stat : 7017 (java) R 7013 7013 1733 0 -1 4202560 47688 0 4 0 344 23 0 0 20 0 10 0 120893175 1083072512 116639 18446744073709551615 4194304 4228012 140735096411744 140568320819456 140568301719808 0 4 0 16800975 0 0 0 -1 0 0 0 60 0 0
[pid=7016/tid=7018] ppid=7013 vsize=1057688 CPUtime=1.29
/proc/7016/task/7018/stat : 7018 (java) S 7013 7013 1733 0 -1 4202560 52861 0 0 0 111 18 0 0 20 0 10 0 120893181 1083072512 116639 18446744073709551615 4194304 4228012 140735096411744 140568213458048 140568314299979 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7019] ppid=7013 vsize=1057688 CPUtime=0
/proc/7016/task/7019/stat : 7019 (java) S 7013 7013 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 120893188 1083072512 116639 18446744073709551615 4194304 4228012 140735096411744 140568212404240 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7020] ppid=7013 vsize=1057688 CPUtime=0
/proc/7016/task/7020/stat : 7020 (java) S 7013 7013 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 120893188 1083072512 116639 18446744073709551615 4194304 4228012 140735096411744 140568211351456 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7021] ppid=7013 vsize=1057688 CPUtime=0
/proc/7016/task/7021/stat : 7021 (java) S 7013 7013 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 120893197 1083072512 116639 18446744073709551615 4194304 4228012 140735096411744 140568210299888 140568314307616 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7022] ppid=7013 vsize=1057688 CPUtime=1.2
/proc/7016/task/7022/stat : 7022 (java) R 7013 7013 1733 0 -1 4202560 11053 0 0 0 115 5 0 0 20 0 10 0 120893197 1083072512 116639 18446744073709551615 4194304 4228012 140735096411744 140568209232616 140568298562262 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7023] ppid=7013 vsize=1057688 CPUtime=1.21
/proc/7016/task/7023/stat : 7023 (java) R 7013 7013 1733 0 -1 4202560 9254 0 0 0 116 5 0 0 20 0 10 0 120893197 1083072512 116639 18446744073709551615 4194304 4228012 140735096411744 140568208194320 140568298590240 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7024] ppid=7013 vsize=1057688 CPUtime=0
/proc/7016/task/7024/stat : 7024 (java) S 7013 7013 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 120893197 1083072512 116639 18446744073709551615 4194304 4228012 140735096411744 140568207142096 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7025] ppid=7013 vsize=1057688 CPUtime=0
/proc/7016/task/7025/stat : 7025 (java) S 7013 7013 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 120893197 1083072512 116639 18446744073709551615 4194304 4228012 140735096411744 140568206089600 140568314299979 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 7.39
Current children cumulated vsize (KiB) 1066856

[startup+9.70076 s]
/proc/loadavg: 1.31 1.28 1.18 4/70 7025
/proc/meminfo: memFree=47116/1022884 swapFree=0/0
[pid=7013] ppid=7012 vsize=9168 CPUtime=0
/proc/7013/stat : 7013 (p2cudf-full-1.1) S 7012 7013 1733 0 -1 4202496 457 291 0 0 0 0 0 0 20 0 1 0 120893168 9388032 330 18446744073709551615 4194304 5129932 140734305781920 140734305780064 140410185389150 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/7013/statm: 2292 330 280 229 0 52 0
[pid=7016] ppid=7013 vsize=1058716 CPUtime=8.97
/proc/7016/stat : 7016 (java) S 7013 7013 1733 0 -1 4202496 123495 0 16 0 845 52 0 0 20 0 11 0 120893169 1084125184 116739 18446744073709551615 4194304 4228012 140735096411744 140735096402768 140568314285685 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 4 0 0
/proc/7016/statm: 264679 116739 2376 9 0 252029 0
[pid=7016/tid=7017] ppid=7013 vsize=1058716 CPUtime=4.34
/proc/7016/task/7017/stat : 7017 (java) R 7013 7013 1733 0 -1 4202560 47762 0 4 0 411 23 0 0 20 0 11 0 120893175 1084125184 116739 18446744073709551615 4194304 4228012 140735096411744 140568320819816 140568218333028 0 4 0 16800975 0 0 0 -1 0 0 0 61 0 0
[pid=7016/tid=7018] ppid=7013 vsize=1058716 CPUtime=1.3
/proc/7016/task/7018/stat : 7018 (java) S 7013 7013 1733 0 -1 4202560 52861 0 0 0 112 18 0 0 20 0 11 0 120893181 1084125184 116739 18446744073709551615 4194304 4228012 140735096411744 140568213458048 140568314299979 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7019] ppid=7013 vsize=1058716 CPUtime=0
/proc/7016/task/7019/stat : 7019 (java) S 7013 7013 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 120893188 1084125184 116739 18446744073709551615 4194304 4228012 140735096411744 140568212404240 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7020] ppid=7013 vsize=1058716 CPUtime=0
/proc/7016/task/7020/stat : 7020 (java) S 7013 7013 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 120893188 1084125184 116739 18446744073709551615 4194304 4228012 140735096411744 140568211351456 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7021] ppid=7013 vsize=1058716 CPUtime=0
/proc/7016/task/7021/stat : 7021 (java) S 7013 7013 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 120893197 1084125184 116739 18446744073709551615 4194304 4228012 140735096411744 140568210299888 140568314307616 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7022] ppid=7013 vsize=1058716 CPUtime=1.63
/proc/7016/task/7022/stat : 7022 (java) S 7013 7013 1733 0 -1 4202560 12292 0 0 0 158 5 0 0 20 0 11 0 120893197 1084125184 116739 18446744073709551615 4194304 4228012 140735096411744 140568209247248 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7023] ppid=7013 vsize=1058716 CPUtime=1.67
/proc/7016/task/7023/stat : 7023 (java) S 7013 7013 1733 0 -1 4202560 9292 0 0 0 162 5 0 0 20 0 11 0 120893197 1084125184 116739 18446744073709551615 4194304 4228012 140735096411744 140568208194576 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7024] ppid=7013 vsize=1058716 CPUtime=0
/proc/7016/task/7024/stat : 7024 (java) S 7013 7013 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 120893197 1084125184 116739 18446744073709551615 4194304 4228012 140735096411744 140568207142096 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7025] ppid=7013 vsize=1058716 CPUtime=0
/proc/7016/task/7025/stat : 7025 (java) S 7013 7013 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 120893197 1084125184 116739 18446744073709551615 4194304 4228012 140735096411744 140568206089600 140568314299979 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 8.97
Current children cumulated vsize (KiB) 1067884

[startup+10.5008 s]
/proc/loadavg: 1.36 1.29 1.19 4/71 7026
/proc/meminfo: memFree=46612/1022884 swapFree=0/0
[pid=7013] ppid=7012 vsize=9168 CPUtime=0
/proc/7013/stat : 7013 (p2cudf-full-1.1) S 7012 7013 1733 0 -1 4202496 457 291 0 0 0 0 0 0 20 0 1 0 120893168 9388032 330 18446744073709551615 4194304 5129932 140734305781920 140734305780064 140410185389150 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/7013/statm: 2292 330 280 229 0 52 0
[pid=7016] ppid=7013 vsize=1059744 CPUtime=9.42
/proc/7016/stat : 7016 (java) S 7013 7013 1733 0 -1 4202496 124154 0 16 0 890 52 0 0 20 0 11 0 120893169 1085177856 116737 18446744073709551615 4194304 4228012 140735096411744 140735096402768 140568314285685 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 4 0 0
/proc/7016/statm: 264936 116737 2378 9 0 252286 0
[pid=7016/tid=7017] ppid=7013 vsize=1059744 CPUtime=4.51
/proc/7016/task/7017/stat : 7017 (java) S 7013 7013 1733 0 -1 4202560 47777 0 4 0 428 23 0 0 20 0 11 0 120893175 1085177856 116737 18446744073709551615 4194304 4228012 140735096411744 140568320820144 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 61 0 0
[pid=7016/tid=7018] ppid=7013 vsize=1059744 CPUtime=1.3
/proc/7016/task/7018/stat : 7018 (java) S 7013 7013 1733 0 -1 4202560 52862 0 0 0 112 18 0 0 20 0 11 0 120893181 1085177856 116737 18446744073709551615 4194304 4228012 140735096411744 140568213458048 140568314299979 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7019] ppid=7013 vsize=1059744 CPUtime=0
/proc/7016/task/7019/stat : 7019 (java) S 7013 7013 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 120893188 1085177856 116737 18446744073709551615 4194304 4228012 140735096411744 140568212404240 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7020] ppid=7013 vsize=1059744 CPUtime=0
/proc/7016/task/7020/stat : 7020 (java) S 7013 7013 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 120893188 1085177856 116737 18446744073709551615 4194304 4228012 140735096411744 140568211351456 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7021] ppid=7013 vsize=1059744 CPUtime=0
/proc/7016/task/7021/stat : 7021 (java) S 7013 7013 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 120893197 1085177856 116737 18446744073709551615 4194304 4228012 140735096411744 140568210299888 140568314307616 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7022] ppid=7013 vsize=1059744 CPUtime=1.75
/proc/7016/task/7022/stat : 7022 (java) S 7013 7013 1733 0 -1 4202560 12920 0 0 0 170 5 0 0 20 0 11 0 120893197 1085177856 116737 18446744073709551615 4194304 4228012 140735096411744 140568209247248 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7023] ppid=7013 vsize=1059744 CPUtime=1.82
/proc/7016/task/7023/stat : 7023 (java) S 7013 7013 1733 0 -1 4202560 9301 0 0 0 177 5 0 0 20 0 11 0 120893197 1085177856 116737 18446744073709551615 4194304 4228012 140735096411744 140568208194576 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7024] ppid=7013 vsize=1059744 CPUtime=0
/proc/7016/task/7024/stat : 7024 (java) S 7013 7013 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 120893197 1085177856 116737 18446744073709551615 4194304 4228012 140735096411744 140568207142096 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7025] ppid=7013 vsize=1059744 CPUtime=0
/proc/7016/task/7025/stat : 7025 (java) S 7013 7013 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 120893197 1085177856 116737 18446744073709551615 4194304 4228012 140735096411744 140568206089600 140568314299979 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 9.42
Current children cumulated vsize (KiB) 1068912

[startup+10.7031 s]
/proc/loadavg: 1.36 1.29 1.19 4/71 7026
/proc/meminfo: memFree=46612/1022884 swapFree=0/0
[pid=7013] ppid=7012 vsize=9168 CPUtime=0
/proc/7013/stat : 7013 (p2cudf-full-1.1) S 7012 7013 1733 0 -1 4202496 457 291 0 0 0 0 0 0 20 0 1 0 120893168 9388032 330 18446744073709551615 4194304 5129932 140734305781920 140734305780064 140410185389150 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/7013/statm: 2292 330 280 229 0 52 0
[pid=7016] ppid=7013 vsize=1059744 CPUtime=9.48
/proc/7016/stat : 7016 (java) S 7013 7013 1733 0 -1 4202496 124157 0 16 0 894 54 0 0 20 0 11 0 120893169 1085177856 116740 18446744073709551615 4194304 4228012 140735096411744 140735096402768 140568314285685 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 4 0 0
/proc/7016/statm: 264936 116740 2378 9 0 252286 0
[pid=7016/tid=7017] ppid=7013 vsize=1059744 CPUtime=4.51
/proc/7016/task/7017/stat : 7017 (java) S 7013 7013 1733 0 -1 4202560 47777 0 4 0 428 23 0 0 20 0 11 0 120893175 1085177856 116740 18446744073709551615 4194304 4228012 140735096411744 140568320820144 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 61 0 0
[pid=7016/tid=7018] ppid=7013 vsize=1059744 CPUtime=1.3
/proc/7016/task/7018/stat : 7018 (java) S 7013 7013 1733 0 -1 4202560 52862 0 0 0 112 18 0 0 20 0 11 0 120893181 1085177856 116740 18446744073709551615 4194304 4228012 140735096411744 140568213458048 140568314299979 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7019] ppid=7013 vsize=1059744 CPUtime=0
/proc/7016/task/7019/stat : 7019 (java) S 7013 7013 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 120893188 1085177856 116740 18446744073709551615 4194304 4228012 140735096411744 140568212404240 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7020] ppid=7013 vsize=1059744 CPUtime=0
/proc/7016/task/7020/stat : 7020 (java) S 7013 7013 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 120893188 1085177856 116740 18446744073709551615 4194304 4228012 140735096411744 140568211351456 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7021] ppid=7013 vsize=1059744 CPUtime=0
/proc/7016/task/7021/stat : 7021 (java) S 7013 7013 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 120893197 1085177856 116740 18446744073709551615 4194304 4228012 140735096411744 140568210299888 140568314307616 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7022] ppid=7013 vsize=1059744 CPUtime=1.76
/proc/7016/task/7022/stat : 7022 (java) S 7013 7013 1733 0 -1 4202560 12920 0 0 0 171 5 0 0 20 0 11 0 120893197 1085177856 116740 18446744073709551615 4194304 4228012 140735096411744 140568209247248 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7023] ppid=7013 vsize=1059744 CPUtime=1.82
/proc/7016/task/7023/stat : 7023 (java) S 7013 7013 1733 0 -1 4202560 9301 0 0 0 177 5 0 0 20 0 11 0 120893197 1085177856 116740 18446744073709551615 4194304 4228012 140735096411744 140568208194576 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7024] ppid=7013 vsize=1059744 CPUtime=0
/proc/7016/task/7024/stat : 7024 (java) S 7013 7013 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 120893197 1085177856 116740 18446744073709551615 4194304 4228012 140735096411744 140568207142096 140568314299092 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=7016/tid=7025] ppid=7013 vsize=1059744 CPUtime=0
/proc/7016/task/7025/stat : 7025 (java) S 7013 7013 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 120893197 1085177856 116740 18446744073709551615 4194304 4228012 140735096411744 140568206089600 140568314299979 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 9.48
Current children cumulated vsize (KiB) 1068912

[startup+10.8027 s]
/proc/loadavg: 1.36 1.29 1.19 4/71 7026
/proc/meminfo: memFree=46612/1022884 swapFree=0/0
[pid=7013] ppid=7012 vsize=9168 CPUtime=0
/proc/7013/stat : 7013 (p2cudf-full-1.1) S 7012 7013 1733 0 -1 4202496 457 291 0 0 0 0 0 0 20 0 1 0 120893168 9388032 330 18446744073709551615 4194304 5129932 140734305781920 140734305780064 140410185389150 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/7013/statm: 2292 330 280 229 0 52 0
[pid=7016] ppid=7013 vsize=0 CPUtime=9.58
/proc/7016/stat : 7016 (java) Z 7013 7013 1733 0 -1 4203532 124168 0 16 0 901 57 0 0 20 0 2 0 120893169 0 0 18446744073709551615 0 0 0 0 0 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 4 0 0
/proc/7016/statm: 0 0 0 0 0 0 0
Current children cumulated CPU time (s) 9.58
Current children cumulated vsize (KiB) 9168

Child status: 0
Real time (s): 10.8082
CPU time (s): 9.6006
CPU user time (s): 9.02056
CPU system time (s): 0.580036
CPU usage (%): 88.8269
Max. virtual memory (cumulated for all children) (KiB): 1072356

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 9.02056
system time used= 0.580036
maximum resident set size= 467684
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 124928
page faults= 16
swaps= 0
block input operations= 49048
block output operations= 176
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 1194
involuntary context switches= 2747

runsolver used 0.036002 second user time and 0.080005 second system time

The end