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/trendy-size/upgrade/difficult/rand293.cudf.log.runsolver /home/competition/p2cudf-full-1.15/p2cudf-full-1.15 /home/competition/data/upgrade/difficult/rand293.cudf /tmp/misc2012/2012-09-02-22:42/full/p2cudf-full-1.15/trendy-size/upgrade/difficult/rand293.cudf.result -count(removed),-sum(solution,installedsize),-notuptodate(solution),-unsat_recommends(solution),-count(new) 

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.30 1.14 1.03 2/60 24961
/proc/meminfo: memFree=591596/1022884 swapFree=0/0
[pid=24961] ppid=24960 vsize=1068 CPUtime=0
/proc/24961/stat : 24961 (p2cudf-full-1.1) D 24960 24961 32685 0 -1 4194304 76 0 0 0 0 0 0 0 20 0 1 0 41680240 1093632 1 18446744073709551615 0 0 140733676481434 4286735856 4152001584 0 0 16781316 0 0 0 0 17 0 0 0 0 0 0
/proc/24961/statm: 267 1 0 0 0 28 0

[startup+0.113399 s]
/proc/loadavg: 1.30 1.14 1.03 2/60 24961
/proc/meminfo: memFree=591596/1022884 swapFree=0/0
[pid=24961] ppid=24960 vsize=9168 CPUtime=0
/proc/24961/stat : 24961 (p2cudf-full-1.1) S 24960 24961 32685 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 41680240 9388032 330 18446744073709551615 4194304 5129932 140733676477392 140733676475536 139681663095902 0 65536 16781316 65538 0 0 0 17 0 0 0 1 0 0
/proc/24961/statm: 2292 330 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+0.200344 s]
/proc/loadavg: 1.30 1.14 1.03 2/60 24961
/proc/meminfo: memFree=591596/1022884 swapFree=0/0
[pid=24961] ppid=24960 vsize=9168 CPUtime=0
/proc/24961/stat : 24961 (p2cudf-full-1.1) S 24960 24961 32685 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 41680240 9388032 330 18446744073709551615 4194304 5129932 140733676477392 140733676475536 139681663095902 0 65536 16781316 65538 0 0 0 17 0 0 0 1 0 0
/proc/24961/statm: 2292 330 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+0.300305 s]
/proc/loadavg: 1.30 1.14 1.03 2/60 24961
/proc/meminfo: memFree=591596/1022884 swapFree=0/0
[pid=24961] ppid=24960 vsize=9168 CPUtime=0
/proc/24961/stat : 24961 (p2cudf-full-1.1) S 24960 24961 32685 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 41680240 9388032 330 18446744073709551615 4194304 5129932 140733676477392 140733676475536 139681663095902 0 65536 16781316 65538 0 0 0 17 0 0 0 1 0 0
/proc/24961/statm: 2292 330 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+0.700236 s]
/proc/loadavg: 1.30 1.14 1.03 2/60 24961
/proc/meminfo: memFree=591596/1022884 swapFree=0/0
[pid=24961] ppid=24960 vsize=9168 CPUtime=0
/proc/24961/stat : 24961 (p2cudf-full-1.1) S 24960 24961 32685 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 41680240 9388032 330 18446744073709551615 4194304 5129932 140733676477392 140733676475536 139681663095902 0 65536 16781316 65538 0 0 0 17 0 0 0 1 0 0
/proc/24961/statm: 2292 330 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+1.50074 s]
/proc/loadavg: 1.44 1.17 1.04 4/71 24973
/proc/meminfo: memFree=547852/1022884 swapFree=0/0
[pid=24961] ppid=24960 vsize=9168 CPUtime=0
/proc/24961/stat : 24961 (p2cudf-full-1.1) S 24960 24961 32685 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 41680240 9388032 330 18446744073709551615 4194304 5129932 140733676477392 140733676475536 139681663095902 0 65536 16781316 65538 0 0 0 17 0 0 0 1 0 0
/proc/24961/statm: 2292 330 280 229 0 52 0
[pid=24964] ppid=24961 vsize=1058548 CPUtime=1.39
/proc/24964/stat : 24964 (java) S 24961 24961 32685 0 -1 4202496 31755 0 14 0 127 12 0 0 20 0 10 0 41680243 1083953152 28536 18446744073709551615 4194304 4228012 140735584560464 140735584551488 140054176456309 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 3 0 0
/proc/24964/statm: 264637 28536 2345 9 0 251987 0
[pid=24964/tid=24965] ppid=24961 vsize=1058548 CPUtime=0.66
/proc/24964/task/24965/stat : 24965 (java) R 24961 24961 32685 0 -1 4202560 13520 0 3 0 60 6 0 0 20 0 10 0 41680248 1083953152 28536 18446744073709551615 4194304 4228012 140735584560464 140054182982304 140054080469120 0 4 0 16800975 0 0 0 -1 0 0 0 3 0 0
[pid=24964/tid=24966] ppid=24961 vsize=1058548 CPUtime=0
/proc/24964/task/24966/stat : 24966 (java) S 24961 24961 32685 0 -1 4202560 4 0 0 0 0 0 0 0 20 0 10 0 41680251 1083953152 28536 18446744073709551615 4194304 4228012 140735584560464 140054075628672 140054176470603 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24967] ppid=24961 vsize=1058548 CPUtime=0
/proc/24964/task/24967/stat : 24967 (java) S 24961 24961 32685 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 10 0 41680252 1083953152 28536 18446744073709551615 4194304 4228012 140735584560464 140054074574864 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24968] ppid=24961 vsize=1058548 CPUtime=0
/proc/24964/task/24968/stat : 24968 (java) S 24961 24961 32685 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 10 0 41680252 1083953152 28536 18446744073709551615 4194304 4228012 140735584560464 140054073522080 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24969] ppid=24961 vsize=1058548 CPUtime=0
/proc/24964/task/24969/stat : 24969 (java) S 24961 24961 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 41680256 1083953152 28536 18446744073709551615 4194304 4228012 140735584560464 140054072470512 140054176478240 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24970] ppid=24961 vsize=1058548 CPUtime=0.35
/proc/24964/task/24970/stat : 24970 (java) R 24961 24961 32685 0 -1 4202560 9280 0 0 0 31 4 0 0 20 0 10 0 41680256 1083953152 28536 18446744073709551615 4194304 4228012 140735584560464 140054071403064 140054162129309 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24971] ppid=24961 vsize=1058548 CPUtime=0.36
/proc/24964/task/24971/stat : 24971 (java) R 24961 24961 32685 0 -1 4202560 7672 0 0 0 34 2 0 0 20 0 10 0 41680256 1083953152 28536 18446744073709551615 4194304 4228012 140735584560464 140054070350456 140054162147952 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24972] ppid=24961 vsize=1058548 CPUtime=0
/proc/24964/task/24972/stat : 24972 (java) S 24961 24961 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 41680256 1083953152 28536 18446744073709551615 4194304 4228012 140735584560464 140054069312720 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24973] ppid=24961 vsize=1058548 CPUtime=0
/proc/24964/task/24973/stat : 24973 (java) S 24961 24961 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 41680256 1083953152 28536 18446744073709551615 4194304 4228012 140735584560464 140054068260224 140054176470603 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 1.39
Current children cumulated vsize (KiB) 1067716

[startup+3.10076 s]
/proc/loadavg: 1.44 1.17 1.04 4/71 24973
/proc/meminfo: memFree=445304/1022884 swapFree=0/0
[pid=24961] ppid=24960 vsize=9168 CPUtime=0
/proc/24961/stat : 24961 (p2cudf-full-1.1) S 24960 24961 32685 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 41680240 9388032 330 18446744073709551615 4194304 5129932 140733676477392 140733676475536 139681663095902 0 65536 16781316 65538 0 0 0 17 0 0 0 1 0 0
/proc/24961/statm: 2292 330 280 229 0 52 0
[pid=24964] ppid=24961 vsize=1058612 CPUtime=2.97
/proc/24964/stat : 24964 (java) S 24961 24961 32685 0 -1 4202496 75919 0 14 0 268 29 0 0 20 0 10 0 41680243 1084018688 71106 18446744073709551615 4194304 4228012 140735584560464 140735584551488 140054176456309 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 3 0 0
/proc/24964/statm: 264653 71106 2365 9 0 252003 0
[pid=24964/tid=24965] ppid=24961 vsize=1058612 CPUtime=1.49
/proc/24964/task/24965/stat : 24965 (java) R 24961 24961 32685 0 -1 4202560 47399 0 3 0 130 19 0 0 20 0 10 0 41680248 1084018688 71106 18446744073709551615 4194304 4228012 140735584560464 140054182982336 140054080928041 0 4 0 16800975 0 0 0 -1 0 0 0 3 0 0
[pid=24964/tid=24966] ppid=24961 vsize=1058612 CPUtime=0.16
/proc/24964/task/24966/stat : 24966 (java) S 24961 24961 32685 0 -1 4202560 7974 0 0 0 13 3 0 0 20 0 10 0 41680251 1084018688 71106 18446744073709551615 4194304 4228012 140735584560464 140054075628672 140054176470603 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24967] ppid=24961 vsize=1058612 CPUtime=0
/proc/24964/task/24967/stat : 24967 (java) S 24961 24961 32685 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 41680252 1084018688 71106 18446744073709551615 4194304 4228012 140735584560464 140054074574864 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24968] ppid=24961 vsize=1058612 CPUtime=0
/proc/24964/task/24968/stat : 24968 (java) S 24961 24961 32685 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 41680252 1084018688 71106 18446744073709551615 4194304 4228012 140735584560464 140054073522080 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24969] ppid=24961 vsize=1058612 CPUtime=0
/proc/24964/task/24969/stat : 24969 (java) S 24961 24961 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 41680256 1084018688 71106 18446744073709551615 4194304 4228012 140735584560464 140054072470512 140054176478240 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24970] ppid=24961 vsize=1058612 CPUtime=0.61
/proc/24964/task/24970/stat : 24970 (java) S 24961 24961 32685 0 -1 4202560 10710 0 0 0 57 4 0 0 20 0 10 0 41680256 1084018688 71106 18446744073709551615 4194304 4228012 140735584560464 140054071417872 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24971] ppid=24961 vsize=1058612 CPUtime=0.68
/proc/24964/task/24971/stat : 24971 (java) S 24961 24961 32685 0 -1 4202560 8553 0 0 0 66 2 0 0 20 0 10 0 41680256 1084018688 71106 18446744073709551615 4194304 4228012 140735584560464 140054070365200 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24972] ppid=24961 vsize=1058612 CPUtime=0
/proc/24964/task/24972/stat : 24972 (java) S 24961 24961 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 41680256 1084018688 71106 18446744073709551615 4194304 4228012 140735584560464 140054069312720 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24973] ppid=24961 vsize=1058612 CPUtime=0
/proc/24964/task/24973/stat : 24973 (java) S 24961 24961 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 41680256 1084018688 71106 18446744073709551615 4194304 4228012 140735584560464 140054068260224 140054176470603 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 2.97
Current children cumulated vsize (KiB) 1067780

[startup+6.30059 s]
/proc/loadavg: 1.44 1.17 1.04 2/71 24973
/proc/meminfo: memFree=144356/1022884 swapFree=0/0
[pid=24961] ppid=24960 vsize=9168 CPUtime=0
/proc/24961/stat : 24961 (p2cudf-full-1.1) S 24960 24961 32685 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 41680240 9388032 330 18446744073709551615 4194304 5129932 140733676477392 140733676475536 139681663095902 0 65536 16781316 65538 0 0 0 17 0 0 0 1 0 0
/proc/24961/statm: 2292 330 280 229 0 52 0
[pid=24964] ppid=24961 vsize=1058612 CPUtime=6.11
/proc/24964/stat : 24964 (java) S 24961 24961 32685 0 -1 4202496 129443 0 14 0 564 47 0 0 20 0 10 0 41680243 1084018688 124269 18446744073709551615 4194304 4228012 140735584560464 140735584551488 140054176456309 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 3 0 0
/proc/24964/statm: 264653 124269 2367 9 0 252003 0
[pid=24964/tid=24965] ppid=24961 vsize=1058612 CPUtime=3.31
/proc/24964/task/24965/stat : 24965 (java) R 24961 24961 32685 0 -1 4202560 47403 0 3 0 309 22 0 0 20 0 10 0 41680248 1084018688 124269 18446744073709551615 4194304 4228012 140735584560464 140054182982336 140054080901068 0 4 0 16800975 0 0 0 -1 0 0 0 7 0 0
[pid=24964/tid=24966] ppid=24961 vsize=1058612 CPUtime=1.39
/proc/24964/task/24966/stat : 24966 (java) S 24961 24961 32685 0 -1 4202560 61460 0 0 0 121 18 0 0 20 0 10 0 41680251 1084018688 124269 18446744073709551615 4194304 4228012 140735584560464 140054075628672 140054176470603 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24967] ppid=24961 vsize=1058612 CPUtime=0
/proc/24964/task/24967/stat : 24967 (java) S 24961 24961 32685 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 41680252 1084018688 124269 18446744073709551615 4194304 4228012 140735584560464 140054074574864 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24968] ppid=24961 vsize=1058612 CPUtime=0
/proc/24964/task/24968/stat : 24968 (java) S 24961 24961 32685 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 41680252 1084018688 124269 18446744073709551615 4194304 4228012 140735584560464 140054073522080 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24969] ppid=24961 vsize=1058612 CPUtime=0
/proc/24964/task/24969/stat : 24969 (java) S 24961 24961 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 41680256 1084018688 124269 18446744073709551615 4194304 4228012 140735584560464 140054072470512 140054176478240 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24970] ppid=24961 vsize=1058612 CPUtime=0.65
/proc/24964/task/24970/stat : 24970 (java) S 24961 24961 32685 0 -1 4202560 10741 0 0 0 61 4 0 0 20 0 10 0 41680256 1084018688 124269 18446744073709551615 4194304 4228012 140735584560464 140054071417872 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24971] ppid=24961 vsize=1058612 CPUtime=0.71
/proc/24964/task/24971/stat : 24971 (java) S 24961 24961 32685 0 -1 4202560 8555 0 0 0 69 2 0 0 20 0 10 0 41680256 1084018688 124269 18446744073709551615 4194304 4228012 140735584560464 140054070365200 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24972] ppid=24961 vsize=1058612 CPUtime=0
/proc/24964/task/24972/stat : 24972 (java) S 24961 24961 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 41680256 1084018688 124269 18446744073709551615 4194304 4228012 140735584560464 140054069312720 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24973] ppid=24961 vsize=1058612 CPUtime=0
/proc/24964/task/24973/stat : 24973 (java) S 24961 24961 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 41680256 1084018688 124269 18446744073709551615 4194304 4228012 140735584560464 140054068260224 140054176470603 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 6.11
Current children cumulated vsize (KiB) 1067780

[startup+12.7006 s]
/proc/loadavg: 1.53 1.19 1.05 3/72 24974
/proc/meminfo: memFree=10748/1022884 swapFree=0/0
[pid=24961] ppid=24960 vsize=9168 CPUtime=0
/proc/24961/stat : 24961 (p2cudf-full-1.1) S 24960 24961 32685 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 41680240 9388032 330 18446744073709551615 4194304 5129932 140733676477392 140733676475536 139681663095902 0 65536 16781316 65538 0 0 0 17 0 0 0 1 0 0
/proc/24961/statm: 2292 330 280 229 0 52 0
[pid=24964] ppid=24961 vsize=1059640 CPUtime=12.35
/proc/24964/stat : 24964 (java) S 24961 24961 32685 0 -1 4202496 154899 0 14 0 1181 54 0 0 20 0 11 0 41680243 1085071360 148347 18446744073709551615 4194304 4228012 140735584560464 140735584551488 140054176456309 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 3 0 0
/proc/24964/statm: 264910 148347 2380 9 0 252260 0
[pid=24964/tid=24965] ppid=24961 vsize=1059640 CPUtime=6.57
/proc/24964/task/24965/stat : 24965 (java) R 24961 24961 32685 0 -1 4202560 47786 0 3 0 634 23 0 0 20 0 11 0 41680248 1085071360 148347 18446744073709551615 4194304 4228012 140735584560464 140054182981536 140054081627820 0 4 0 16800975 0 0 0 -1 0 0 0 7 0 0
[pid=24964/tid=24966] ppid=24961 vsize=1059640 CPUtime=1.88
/proc/24964/task/24966/stat : 24966 (java) S 24961 24961 32685 0 -1 4202560 83700 0 0 0 164 24 0 0 20 0 11 0 41680251 1085071360 148347 18446744073709551615 4194304 4228012 140735584560464 140054075628672 140054176470603 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24967] ppid=24961 vsize=1059640 CPUtime=0
/proc/24964/task/24967/stat : 24967 (java) S 24961 24961 32685 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 41680252 1085071360 148347 18446744073709551615 4194304 4228012 140735584560464 140054074574864 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24968] ppid=24961 vsize=1059640 CPUtime=0
/proc/24964/task/24968/stat : 24968 (java) S 24961 24961 32685 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 41680252 1085071360 148347 18446744073709551615 4194304 4228012 140735584560464 140054073522080 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24969] ppid=24961 vsize=1059640 CPUtime=0
/proc/24964/task/24969/stat : 24969 (java) S 24961 24961 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 41680256 1085071360 148347 18446744073709551615 4194304 4228012 140735584560464 140054072470512 140054176478240 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24970] ppid=24961 vsize=1059640 CPUtime=1.93
/proc/24964/task/24970/stat : 24970 (java) S 24961 24961 32685 0 -1 4202560 10933 0 0 0 188 5 0 0 20 0 11 0 41680256 1085071360 148347 18446744073709551615 4194304 4228012 140735584560464 140054071417872 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24971] ppid=24961 vsize=1059640 CPUtime=1.94
/proc/24964/task/24971/stat : 24971 (java) S 24961 24961 32685 0 -1 4202560 11190 0 0 0 192 2 0 0 20 0 11 0 41680256 1085071360 148347 18446744073709551615 4194304 4228012 140735584560464 140054070365200 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24972] ppid=24961 vsize=1059640 CPUtime=0
/proc/24964/task/24972/stat : 24972 (java) S 24961 24961 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 41680256 1085071360 148347 18446744073709551615 4194304 4228012 140735584560464 140054069312720 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24973] ppid=24961 vsize=1059640 CPUtime=0
/proc/24964/task/24973/stat : 24973 (java) S 24961 24961 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 41680256 1085071360 148347 18446744073709551615 4194304 4228012 140735584560464 140054068260224 140054176470603 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24974] ppid=24961 vsize=1059640 CPUtime=0
/proc/24964/task/24974/stat : 24974 (java) S 24961 24961 32685 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 11 0 41681328 1085071360 148347 18446744073709551615 4194304 4228012 140735584560464 140054067058528 140054176470603 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 12.35
Current children cumulated vsize (KiB) 1068808

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

[startup+12.8008 s]
/proc/loadavg: 1.53 1.19 1.05 3/72 24974
/proc/meminfo: memFree=10748/1022884 swapFree=0/0
[pid=24961] ppid=24960 vsize=9168 CPUtime=0
/proc/24961/stat : 24961 (p2cudf-full-1.1) S 24960 24961 32685 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 41680240 9388032 330 18446744073709551615 4194304 5129932 140733676477392 140733676475536 139681663095902 0 65536 16781316 65538 0 0 0 17 0 0 0 1 0 0
/proc/24961/statm: 2292 330 280 229 0 52 0
[pid=24964] ppid=24961 vsize=1059640 CPUtime=12.45
/proc/24964/stat : 24964 (java) S 24961 24961 32685 0 -1 4202496 154899 0 14 0 1191 54 0 0 20 0 11 0 41680243 1085071360 148347 18446744073709551615 4194304 4228012 140735584560464 140735584551488 140054176456309 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 3 0 0
/proc/24964/statm: 264910 148347 2380 9 0 252260 0
[pid=24964/tid=24965] ppid=24961 vsize=1059640 CPUtime=6.67
/proc/24964/task/24965/stat : 24965 (java) R 24961 24961 32685 0 -1 4202560 47786 0 3 0 644 23 0 0 20 0 11 0 41680248 1085071360 148347 18446744073709551615 4194304 4228012 140735584560464 140054182990184 140054081184784 0 4 0 16800975 0 0 0 -1 0 0 0 7 0 0
[pid=24964/tid=24966] ppid=24961 vsize=1059640 CPUtime=1.88
/proc/24964/task/24966/stat : 24966 (java) S 24961 24961 32685 0 -1 4202560 83700 0 0 0 164 24 0 0 20 0 11 0 41680251 1085071360 148347 18446744073709551615 4194304 4228012 140735584560464 140054075628672 140054176470603 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24967] ppid=24961 vsize=1059640 CPUtime=0
/proc/24964/task/24967/stat : 24967 (java) S 24961 24961 32685 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 41680252 1085071360 148347 18446744073709551615 4194304 4228012 140735584560464 140054074574864 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24968] ppid=24961 vsize=1059640 CPUtime=0
/proc/24964/task/24968/stat : 24968 (java) S 24961 24961 32685 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 41680252 1085071360 148347 18446744073709551615 4194304 4228012 140735584560464 140054073522080 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24969] ppid=24961 vsize=1059640 CPUtime=0
/proc/24964/task/24969/stat : 24969 (java) S 24961 24961 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 41680256 1085071360 148347 18446744073709551615 4194304 4228012 140735584560464 140054072470512 140054176478240 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24970] ppid=24961 vsize=1059640 CPUtime=1.93
/proc/24964/task/24970/stat : 24970 (java) S 24961 24961 32685 0 -1 4202560 10933 0 0 0 188 5 0 0 20 0 11 0 41680256 1085071360 148347 18446744073709551615 4194304 4228012 140735584560464 140054071417872 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24971] ppid=24961 vsize=1059640 CPUtime=1.94
/proc/24964/task/24971/stat : 24971 (java) S 24961 24961 32685 0 -1 4202560 11190 0 0 0 192 2 0 0 20 0 11 0 41680256 1085071360 148347 18446744073709551615 4194304 4228012 140735584560464 140054070365200 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24972] ppid=24961 vsize=1059640 CPUtime=0
/proc/24964/task/24972/stat : 24972 (java) S 24961 24961 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 41680256 1085071360 148347 18446744073709551615 4194304 4228012 140735584560464 140054069312720 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24973] ppid=24961 vsize=1059640 CPUtime=0
/proc/24964/task/24973/stat : 24973 (java) S 24961 24961 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 41680256 1085071360 148347 18446744073709551615 4194304 4228012 140735584560464 140054068260224 140054176470603 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24974] ppid=24961 vsize=1059640 CPUtime=0
/proc/24964/task/24974/stat : 24974 (java) S 24961 24961 32685 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 11 0 41681328 1085071360 148347 18446744073709551615 4194304 4228012 140735584560464 140054067058528 140054176470603 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 12.45
Current children cumulated vsize (KiB) 1068808

[startup+13.6006 s]
/proc/loadavg: 1.53 1.19 1.05 2/72 24974
/proc/meminfo: memFree=10748/1022884 swapFree=0/0
[pid=24961] ppid=24960 vsize=9168 CPUtime=0
/proc/24961/stat : 24961 (p2cudf-full-1.1) S 24960 24961 32685 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 41680240 9388032 330 18446744073709551615 4194304 5129932 140733676477392 140733676475536 139681663095902 0 65536 16781316 65538 0 0 0 17 0 0 0 1 0 0
/proc/24961/statm: 2292 330 280 229 0 52 0
[pid=24964] ppid=24961 vsize=1059640 CPUtime=13.24
/proc/24964/stat : 24964 (java) S 24961 24961 32685 0 -1 4202496 154907 0 14 0 1270 54 0 0 20 0 11 0 41680243 1085071360 148355 18446744073709551615 4194304 4228012 140735584560464 140735584551488 140054176456309 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 3 0 0
/proc/24964/statm: 264910 148355 2381 9 0 252260 0
[pid=24964/tid=24965] ppid=24961 vsize=1059640 CPUtime=7.41
/proc/24964/task/24965/stat : 24965 (java) R 24961 24961 32685 0 -1 4202560 47788 0 3 0 718 23 0 0 20 0 11 0 41680248 1085071360 148355 18446744073709551615 4194304 4228012 140735584560464 140054182989624 140054081184870 0 4 0 16800975 0 0 0 -1 0 0 0 7 0 0
[pid=24964/tid=24966] ppid=24961 vsize=1059640 CPUtime=1.88
/proc/24964/task/24966/stat : 24966 (java) S 24961 24961 32685 0 -1 4202560 83700 0 0 0 164 24 0 0 20 0 11 0 41680251 1085071360 148355 18446744073709551615 4194304 4228012 140735584560464 140054075628672 140054176470603 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24967] ppid=24961 vsize=1059640 CPUtime=0
/proc/24964/task/24967/stat : 24967 (java) S 24961 24961 32685 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 41680252 1085071360 148355 18446744073709551615 4194304 4228012 140735584560464 140054074574864 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24968] ppid=24961 vsize=1059640 CPUtime=0
/proc/24964/task/24968/stat : 24968 (java) S 24961 24961 32685 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 41680252 1085071360 148355 18446744073709551615 4194304 4228012 140735584560464 140054073522080 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24969] ppid=24961 vsize=1059640 CPUtime=0
/proc/24964/task/24969/stat : 24969 (java) S 24961 24961 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 41680256 1085071360 148355 18446744073709551615 4194304 4228012 140735584560464 140054072470512 140054176478240 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24970] ppid=24961 vsize=1059640 CPUtime=1.96
/proc/24964/task/24970/stat : 24970 (java) S 24961 24961 32685 0 -1 4202560 10938 0 0 0 191 5 0 0 20 0 11 0 41680256 1085071360 148355 18446744073709551615 4194304 4228012 140735584560464 140054071417872 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24971] ppid=24961 vsize=1059640 CPUtime=1.95
/proc/24964/task/24971/stat : 24971 (java) S 24961 24961 32685 0 -1 4202560 11191 0 0 0 193 2 0 0 20 0 11 0 41680256 1085071360 148355 18446744073709551615 4194304 4228012 140735584560464 140054070365200 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24972] ppid=24961 vsize=1059640 CPUtime=0
/proc/24964/task/24972/stat : 24972 (java) S 24961 24961 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 41680256 1085071360 148355 18446744073709551615 4194304 4228012 140735584560464 140054069312720 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24973] ppid=24961 vsize=1059640 CPUtime=0
/proc/24964/task/24973/stat : 24973 (java) S 24961 24961 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 41680256 1085071360 148355 18446744073709551615 4194304 4228012 140735584560464 140054068260224 140054176470603 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24974] ppid=24961 vsize=1059640 CPUtime=0
/proc/24964/task/24974/stat : 24974 (java) S 24961 24961 32685 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 11 0 41681328 1085071360 148355 18446744073709551615 4194304 4228012 140735584560464 140054067058528 140054176470603 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 13.24
Current children cumulated vsize (KiB) 1068808

[startup+14.0008 s]
/proc/loadavg: 1.53 1.19 1.05 2/72 24974
/proc/meminfo: memFree=10748/1022884 swapFree=0/0
[pid=24961] ppid=24960 vsize=9168 CPUtime=0
/proc/24961/stat : 24961 (p2cudf-full-1.1) S 24960 24961 32685 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 41680240 9388032 330 18446744073709551615 4194304 5129932 140733676477392 140733676475536 139681663095902 0 65536 16781316 65538 0 0 0 17 0 0 0 1 0 0
/proc/24961/statm: 2292 330 280 229 0 52 0
[pid=24964] ppid=24961 vsize=1060668 CPUtime=13.45
/proc/24964/stat : 24964 (java) S 24961 24961 32685 0 -1 4202496 154933 0 14 0 1291 54 0 0 20 0 11 0 41680243 1086124032 148379 18446744073709551615 4194304 4228012 140735584560464 140735584551488 140054176456309 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 3 0 0
/proc/24964/statm: 265167 148379 2381 9 0 252517 0
[pid=24964/tid=24965] ppid=24961 vsize=1060668 CPUtime=7.54
/proc/24964/task/24965/stat : 24965 (java) S 24961 24961 32685 0 -1 4202560 47797 0 3 0 731 23 0 0 20 0 11 0 41680248 1086124032 148379 18446744073709551615 4194304 4228012 140735584560464 140054182990768 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 7 0 0
[pid=24964/tid=24966] ppid=24961 vsize=1060668 CPUtime=1.88
/proc/24964/task/24966/stat : 24966 (java) S 24961 24961 32685 0 -1 4202560 83700 0 0 0 164 24 0 0 20 0 11 0 41680251 1086124032 148379 18446744073709551615 4194304 4228012 140735584560464 140054075628672 140054176470603 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24967] ppid=24961 vsize=1060668 CPUtime=0
/proc/24964/task/24967/stat : 24967 (java) S 24961 24961 32685 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 41680252 1086124032 148379 18446744073709551615 4194304 4228012 140735584560464 140054074574864 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24968] ppid=24961 vsize=1060668 CPUtime=0
/proc/24964/task/24968/stat : 24968 (java) S 24961 24961 32685 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 41680252 1086124032 148379 18446744073709551615 4194304 4228012 140735584560464 140054073522080 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24969] ppid=24961 vsize=1060668 CPUtime=0
/proc/24964/task/24969/stat : 24969 (java) S 24961 24961 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 41680256 1086124032 148379 18446744073709551615 4194304 4228012 140735584560464 140054072470512 140054176478240 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24970] ppid=24961 vsize=1060668 CPUtime=1.99
/proc/24964/task/24970/stat : 24970 (java) S 24961 24961 32685 0 -1 4202560 10941 0 0 0 194 5 0 0 20 0 11 0 41680256 1086124032 148379 18446744073709551615 4194304 4228012 140735584560464 140054071417872 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24971] ppid=24961 vsize=1060668 CPUtime=2.01
/proc/24964/task/24971/stat : 24971 (java) S 24961 24961 32685 0 -1 4202560 11199 0 0 0 199 2 0 0 20 0 11 0 41680256 1086124032 148379 18446744073709551615 4194304 4228012 140735584560464 140054070365200 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24972] ppid=24961 vsize=1060668 CPUtime=0
/proc/24964/task/24972/stat : 24972 (java) S 24961 24961 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 41680256 1086124032 148379 18446744073709551615 4194304 4228012 140735584560464 140054069312720 140054176469716 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24964/tid=24973] ppid=24961 vsize=1060668 CPUtime=0
/proc/24964/task/24973/stat : 24973 (java) S 24961 24961 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 41680256 1086124032 148379 18446744073709551615 4194304 4228012 140735584560464 140054068260224 140054176470603 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 13.45
Current children cumulated vsize (KiB) 1069836

[startup+14.4154 s]
/proc/loadavg: 1.53 1.19 1.05 2/72 24975
/proc/meminfo: memFree=10624/1022884 swapFree=0/0
[pid=24961] ppid=24960 vsize=9168 CPUtime=0
/proc/24961/stat : 24961 (p2cudf-full-1.1) S 24960 24961 32685 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 41680240 9388032 330 18446744073709551615 4194304 5129932 140733676477392 140733676475536 139681663095902 0 65536 16781316 65538 0 0 0 17 0 0 0 1 0 0
/proc/24961/statm: 2292 330 280 229 0 52 0
[pid=24964] ppid=24961 vsize=0 CPUtime=13.57
/proc/24964/stat : 24964 (java) Z 24961 24961 32685 0 -1 4203532 154946 0 14 0 1298 59 0 0 20 0 2 0 41680243 0 0 18446744073709551615 0 0 0 0 0 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 3 0 0
/proc/24964/statm: 0 0 0 0 0 0 0
[pid=24964/tid=24975] ppid=24961 vsize=0 CPUtime=0.1
/proc/24964/task/24975/stat : 24975 (java) R 24961 24961 32685 0 -1 4203588 8 0 0 0 4 6 0 0 20 0 2 0 41681618 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) 13.57
Current children cumulated vsize (KiB) 9168

Child status: 0
Real time (s): 14.4783
CPU time (s): 13.6449
CPU user time (s): 12.9888
CPU system time (s): 0.656041
CPU usage (%): 94.2435
Max. virtual memory (cumulated for all children) (KiB): 1072892

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 12.9888
system time used= 0.656041
maximum resident set size= 594308
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 155704
page faults= 17
swaps= 0
block input operations= 70392
block output operations= 184
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 1224
involuntary context switches= 2471

runsolver used 0.016001 second user time and 0.124007 second system time

The end