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/easy/rand653.cudf.log.runsolver /home/competition/p2cudf-full-1.15/p2cudf-full-1.15 /home/competition/data/upgrade/easy/rand653.cudf /tmp/misc2012/2012-09-02-22:42/full/p2cudf-full-1.15/trendy-size/upgrade/easy/rand653.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: 0.96 1.37 1.32 2/59 19376
/proc/meminfo: memFree=511644/1022884 swapFree=0/0
[pid=19376] ppid=19375 vsize=9168 CPUtime=0
/proc/19376/stat : 19376 (p2cudf-full-1.1) S 19375 19376 1750 0 -1 4202496 425 0 0 0 0 0 0 0 20 0 1 0 119889993 9388032 325 18446744073709551615 4194304 5129932 140733405299424 140733405297096 140700561098528 0 0 16781316 65536 0 0 0 17 0 0 0 0 0 0
/proc/19376/statm: 2292 325 275 229 0 52 0

[startup+0.178271 s]
/proc/loadavg: 0.96 1.37 1.32 2/59 19376
/proc/meminfo: memFree=511644/1022884 swapFree=0/0
[pid=19376] ppid=19375 vsize=9168 CPUtime=0
/proc/19376/stat : 19376 (p2cudf-full-1.1) S 19375 19376 1750 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 119889993 9388032 330 18446744073709551615 4194304 5129932 140733405299424 140733405297568 140700560954462 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/19376/statm: 2292 330 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+0.200314 s]
/proc/loadavg: 0.96 1.37 1.32 2/59 19376
/proc/meminfo: memFree=511644/1022884 swapFree=0/0
[pid=19376] ppid=19375 vsize=9168 CPUtime=0
/proc/19376/stat : 19376 (p2cudf-full-1.1) S 19375 19376 1750 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 119889993 9388032 330 18446744073709551615 4194304 5129932 140733405299424 140733405297568 140700560954462 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/19376/statm: 2292 330 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+0.300301 s]
/proc/loadavg: 0.96 1.37 1.32 2/59 19376
/proc/meminfo: memFree=511644/1022884 swapFree=0/0
[pid=19376] ppid=19375 vsize=9168 CPUtime=0
/proc/19376/stat : 19376 (p2cudf-full-1.1) S 19375 19376 1750 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 119889993 9388032 330 18446744073709551615 4194304 5129932 140733405299424 140733405297568 140700560954462 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/19376/statm: 2292 330 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+0.700284 s]
/proc/loadavg: 0.96 1.37 1.32 2/59 19376
/proc/meminfo: memFree=511644/1022884 swapFree=0/0
[pid=19376] ppid=19375 vsize=9168 CPUtime=0
/proc/19376/stat : 19376 (p2cudf-full-1.1) S 19375 19376 1750 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 119889993 9388032 330 18446744073709551615 4194304 5129932 140733405299424 140733405297568 140700560954462 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/19376/statm: 2292 330 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+1.50071 s]
/proc/loadavg: 0.96 1.37 1.32 4/70 19388
/proc/meminfo: memFree=458972/1022884 swapFree=0/0
[pid=19376] ppid=19375 vsize=9168 CPUtime=0
/proc/19376/stat : 19376 (p2cudf-full-1.1) S 19375 19376 1750 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 119889993 9388032 330 18446744073709551615 4194304 5129932 140733405299424 140733405297568 140700560954462 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/19376/statm: 2292 330 280 229 0 52 0
[pid=19379] ppid=19376 vsize=1050996 CPUtime=1.46
/proc/19379/stat : 19379 (java) S 19376 19376 1750 0 -1 4202496 34269 0 0 0 131 15 0 0 20 0 10 0 119889994 1076219904 30384 18446744073709551615 4194304 4228012 140734226831488 140734226822512 140646894075509 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/19379/statm: 262749 30384 2345 9 0 250099 0
[pid=19379/tid=19380] ppid=19376 vsize=1050996 CPUtime=0.67
/proc/19379/task/19380/stat : 19380 (java) R 19376 19376 1750 0 -1 4202560 14772 0 0 0 59 8 0 0 20 0 10 0 119889995 1076219904 30384 18446744073709551615 4194304 4228012 140734226831488 140646900601504 140646798238316 0 4 0 16800975 0 0 0 -1 0 0 0 1 0 0
[pid=19379/tid=19381] ppid=19376 vsize=1050996 CPUtime=0
/proc/19379/task/19381/stat : 19381 (java) S 19376 19376 1750 0 -1 4202560 3 0 0 0 0 0 0 0 20 0 10 0 119889997 1076219904 30384 18446744073709551615 4194304 4228012 140734226831488 140646793247872 140646894089803 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19382] ppid=19376 vsize=1050996 CPUtime=0
/proc/19379/task/19382/stat : 19382 (java) S 19376 19376 1750 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 10 0 119889998 1076219904 30384 18446744073709551615 4194304 4228012 140734226831488 140646792194064 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19383] ppid=19376 vsize=1050996 CPUtime=0
/proc/19379/task/19383/stat : 19383 (java) S 19376 19376 1750 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 10 0 119889998 1076219904 30384 18446744073709551615 4194304 4228012 140734226831488 140646791141280 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19384] ppid=19376 vsize=1050996 CPUtime=0
/proc/19379/task/19384/stat : 19384 (java) S 19376 19376 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 119890002 1076219904 30384 18446744073709551615 4194304 4228012 140734226831488 140646790089712 140646894097440 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19385] ppid=19376 vsize=1050996 CPUtime=0.38
/proc/19379/task/19385/stat : 19385 (java) R 19376 19376 1750 0 -1 4202560 10013 0 0 0 34 4 0 0 20 0 10 0 119890002 1076219904 30384 18446744073709551615 4194304 4228012 140734226831488 140646789023288 140646879907992 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19386] ppid=19376 vsize=1050996 CPUtime=0.37
/proc/19379/task/19386/stat : 19386 (java) R 19376 19376 1750 0 -1 4202560 8195 0 0 0 36 1 0 0 20 0 10 0 119890002 1076219904 30384 18446744073709551615 4194304 4228012 140734226831488 140646787972200 140646879532474 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19387] ppid=19376 vsize=1050996 CPUtime=0
/proc/19379/task/19387/stat : 19387 (java) S 19376 19376 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119890002 1076219904 30384 18446744073709551615 4194304 4228012 140734226831488 140646786931920 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19388] ppid=19376 vsize=1050996 CPUtime=0
/proc/19379/task/19388/stat : 19388 (java) S 19376 19376 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119890002 1076219904 30384 18446744073709551615 4194304 4228012 140734226831488 140646785879424 140646894089803 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 1.46
Current children cumulated vsize (KiB) 1060164

[startup+3.10074 s]
/proc/loadavg: 0.96 1.37 1.32 4/70 19388
/proc/meminfo: memFree=357044/1022884 swapFree=0/0
[pid=19376] ppid=19375 vsize=9168 CPUtime=0
/proc/19376/stat : 19376 (p2cudf-full-1.1) S 19375 19376 1750 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 119889993 9388032 330 18446744073709551615 4194304 5129932 140733405299424 140733405297568 140700560954462 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/19376/statm: 2292 330 280 229 0 52 0
[pid=19379] ppid=19376 vsize=1051200 CPUtime=3.03
/proc/19379/stat : 19379 (java) S 19376 19376 1750 0 -1 4202496 76716 0 0 0 275 28 0 0 20 0 10 0 119889994 1076428800 71519 18446744073709551615 4194304 4228012 140734226831488 140734226822512 140646894075509 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/19379/statm: 262800 71519 2367 9 0 250150 0
[pid=19379/tid=19380] ppid=19376 vsize=1051200 CPUtime=1.54
/proc/19379/task/19380/stat : 19380 (java) S 19376 19376 1750 0 -1 4202560 47420 0 0 0 134 20 0 0 20 0 10 0 119889995 1076428800 71519 18446744073709551615 4194304 4228012 140734226831488 140646900609552 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 1 0 0
[pid=19379/tid=19381] ppid=19376 vsize=1051200 CPUtime=0.17
/proc/19379/task/19381/stat : 19381 (java) R 19376 19376 1750 0 -1 4202560 8298 0 0 0 16 1 0 0 20 0 10 0 119889997 1076428800 71519 18446744073709551615 4194304 4228012 140734226831488 140646793247248 140646878199063 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19382] ppid=19376 vsize=1051200 CPUtime=0
/proc/19379/task/19382/stat : 19382 (java) S 19376 19376 1750 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 119889998 1076428800 71519 18446744073709551615 4194304 4228012 140734226831488 140646792194064 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19383] ppid=19376 vsize=1051200 CPUtime=0
/proc/19379/task/19383/stat : 19383 (java) S 19376 19376 1750 0 -1 4202560 8 0 0 0 0 0 0 0 20 0 10 0 119889998 1076428800 71519 18446744073709551615 4194304 4228012 140734226831488 140646791141280 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19384] ppid=19376 vsize=1051200 CPUtime=0
/proc/19379/task/19384/stat : 19384 (java) S 19376 19376 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 119890002 1076428800 71519 18446744073709551615 4194304 4228012 140734226831488 140646790089712 140646894097440 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19385] ppid=19376 vsize=1051200 CPUtime=0.63
/proc/19379/task/19385/stat : 19385 (java) S 19376 19376 1750 0 -1 4202560 11056 0 0 0 58 5 0 0 20 0 10 0 119890002 1076428800 71519 18446744073709551615 4194304 4228012 140734226831488 140646789037072 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19386] ppid=19376 vsize=1051200 CPUtime=0.68
/proc/19379/task/19386/stat : 19386 (java) S 19376 19376 1750 0 -1 4202560 8653 0 0 0 66 2 0 0 20 0 10 0 119890002 1076428800 71519 18446744073709551615 4194304 4228012 140734226831488 140646787984400 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19387] ppid=19376 vsize=1051200 CPUtime=0
/proc/19379/task/19387/stat : 19387 (java) S 19376 19376 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119890002 1076428800 71519 18446744073709551615 4194304 4228012 140734226831488 140646786931920 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19388] ppid=19376 vsize=1051200 CPUtime=0
/proc/19379/task/19388/stat : 19388 (java) S 19376 19376 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119890002 1076428800 71519 18446744073709551615 4194304 4228012 140734226831488 140646785879424 140646894089803 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 3.03
Current children cumulated vsize (KiB) 1060368

[startup+6.30075 s]
/proc/loadavg: 0.96 1.36 1.32 3/70 19388
/proc/meminfo: memFree=67380/1022884 swapFree=0/0
[pid=19376] ppid=19375 vsize=9168 CPUtime=0
/proc/19376/stat : 19376 (p2cudf-full-1.1) S 19375 19376 1750 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 119889993 9388032 330 18446744073709551615 4194304 5129932 140733405299424 140733405297568 140700560954462 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/19376/statm: 2292 330 280 229 0 52 0
[pid=19379] ppid=19376 vsize=1048352 CPUtime=6.19
/proc/19379/stat : 19379 (java) S 19376 19376 1750 0 -1 4202496 114174 0 0 0 576 43 0 0 20 0 10 0 119889994 1073512448 108217 18446744073709551615 4194304 4228012 140734226831488 140734226822512 140646894075509 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/19379/statm: 262088 108217 2371 9 0 249438 0
[pid=19379/tid=19380] ppid=19376 vsize=1048352 CPUtime=3.24
/proc/19379/task/19380/stat : 19380 (java) S 19376 19376 1750 0 -1 4202560 47490 0 0 0 300 24 0 0 20 0 10 0 119889995 1073512448 108217 18446744073709551615 4194304 4228012 140734226831488 140646900609264 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 2 0 0
[pid=19379/tid=19381] ppid=19376 vsize=1048352 CPUtime=1.11
/proc/19379/task/19381/stat : 19381 (java) R 19376 19376 1750 0 -1 4202560 45565 0 0 0 99 12 0 0 20 0 10 0 119889997 1073512448 108217 18446744073709551615 4194304 4228012 140734226831488 140646793247248 140646878386297 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19382] ppid=19376 vsize=1048352 CPUtime=0
/proc/19379/task/19382/stat : 19382 (java) S 19376 19376 1750 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 119889998 1073512448 108217 18446744073709551615 4194304 4228012 140734226831488 140646792194064 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19383] ppid=19376 vsize=1048352 CPUtime=0
/proc/19379/task/19383/stat : 19383 (java) S 19376 19376 1750 0 -1 4202560 8 0 0 0 0 0 0 0 20 0 10 0 119889998 1073512448 108217 18446744073709551615 4194304 4228012 140734226831488 140646791141280 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19384] ppid=19376 vsize=1048352 CPUtime=0
/proc/19379/task/19384/stat : 19384 (java) S 19376 19376 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 119890002 1073512448 108217 18446744073709551615 4194304 4228012 140734226831488 140646790089712 140646894097440 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19385] ppid=19376 vsize=1048352 CPUtime=0.89
/proc/19379/task/19385/stat : 19385 (java) S 19376 19376 1750 0 -1 4202560 11155 0 0 0 84 5 0 0 20 0 10 0 119890002 1073512448 108217 18446744073709551615 4194304 4228012 140734226831488 140646789037072 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19386] ppid=19376 vsize=1048352 CPUtime=0.93
/proc/19379/task/19386/stat : 19386 (java) S 19376 19376 1750 0 -1 4202560 8674 0 0 0 91 2 0 0 20 0 10 0 119890002 1073512448 108217 18446744073709551615 4194304 4228012 140734226831488 140646787984400 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19387] ppid=19376 vsize=1048352 CPUtime=0
/proc/19379/task/19387/stat : 19387 (java) S 19376 19376 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119890002 1073512448 108217 18446744073709551615 4194304 4228012 140734226831488 140646786931920 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19388] ppid=19376 vsize=1048352 CPUtime=0
/proc/19379/task/19388/stat : 19388 (java) S 19376 19376 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 119890002 1073512448 108217 18446744073709551615 4194304 4228012 140734226831488 140646785879424 140646894089803 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 6.19
Current children cumulated vsize (KiB) 1057520

[startup+12.7008 s]
/proc/loadavg: 1.13 1.39 1.33 2/71 19389
/proc/meminfo: memFree=32652/1022884 swapFree=0/0
[pid=19376] ppid=19375 vsize=9168 CPUtime=0
/proc/19376/stat : 19376 (p2cudf-full-1.1) S 19375 19376 1750 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 119889993 9388032 330 18446744073709551615 4194304 5129932 140733405299424 140733405297568 140700560954462 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/19376/statm: 2292 330 280 229 0 52 0
[pid=19379] ppid=19376 vsize=1049380 CPUtime=12.49
/proc/19379/stat : 19379 (java) S 19376 19376 1750 0 -1 4202496 122366 0 0 0 1203 46 0 0 20 0 11 0 119889994 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140734226822512 140646894075509 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/19379/statm: 262345 116409 2381 9 0 249695 0
[pid=19379/tid=19380] ppid=19376 vsize=1049380 CPUtime=6.79
/proc/19379/task/19380/stat : 19380 (java) R 19376 19376 1750 0 -1 4202560 47805 0 0 0 654 25 0 0 20 0 11 0 119889995 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646900609112 140646799433273 0 4 0 16800975 0 0 0 -1 0 0 0 2 0 0
[pid=19379/tid=19381] ppid=19376 vsize=1049380 CPUtime=1.31
/proc/19379/task/19381/stat : 19381 (java) S 19376 19376 1750 0 -1 4202560 53197 0 0 0 117 14 0 0 20 0 11 0 119889997 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646793247872 140646894089803 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19382] ppid=19376 vsize=1049380 CPUtime=0
/proc/19379/task/19382/stat : 19382 (java) S 19376 19376 1750 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 119889998 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646792194064 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19383] ppid=19376 vsize=1049380 CPUtime=0
/proc/19379/task/19383/stat : 19383 (java) S 19376 19376 1750 0 -1 4202560 8 0 0 0 0 0 0 0 20 0 11 0 119889998 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646791141280 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19384] ppid=19376 vsize=1049380 CPUtime=0
/proc/19379/task/19384/stat : 19384 (java) S 19376 19376 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 119890002 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646790089712 140646894097440 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19385] ppid=19376 vsize=1049380 CPUtime=2.21
/proc/19379/task/19385/stat : 19385 (java) S 19376 19376 1750 0 -1 4202560 11222 0 0 0 216 5 0 0 20 0 11 0 119890002 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646789037072 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19386] ppid=19376 vsize=1049380 CPUtime=2.16
/proc/19379/task/19386/stat : 19386 (java) S 19376 19376 1750 0 -1 4202560 8846 0 0 0 214 2 0 0 20 0 11 0 119890002 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646787984400 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19387] ppid=19376 vsize=1049380 CPUtime=0
/proc/19379/task/19387/stat : 19387 (java) S 19376 19376 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 119890002 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646786931920 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19388] ppid=19376 vsize=1049380 CPUtime=0
/proc/19379/task/19388/stat : 19388 (java) S 19376 19376 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 119890002 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646785879424 140646894089803 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19389] ppid=19376 vsize=1049380 CPUtime=0
/proc/19379/task/19389/stat : 19389 (java) S 19376 19376 1750 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 11 0 119890960 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646784681824 140646894089803 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 12.49
Current children cumulated vsize (KiB) 1058548

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

[startup+12.801 s]
/proc/loadavg: 1.13 1.39 1.33 2/71 19389
/proc/meminfo: memFree=32652/1022884 swapFree=0/0
[pid=19376] ppid=19375 vsize=9168 CPUtime=0
/proc/19376/stat : 19376 (p2cudf-full-1.1) S 19375 19376 1750 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 119889993 9388032 330 18446744073709551615 4194304 5129932 140733405299424 140733405297568 140700560954462 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/19376/statm: 2292 330 280 229 0 52 0
[pid=19379] ppid=19376 vsize=1049380 CPUtime=12.6
/proc/19379/stat : 19379 (java) S 19376 19376 1750 0 -1 4202496 122366 0 0 0 1213 47 0 0 20 0 11 0 119889994 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140734226822512 140646894075509 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/19379/statm: 262345 116409 2381 9 0 249695 0
[pid=19379/tid=19380] ppid=19376 vsize=1049380 CPUtime=6.89
/proc/19379/task/19380/stat : 19380 (java) R 19376 19376 1750 0 -1 4202560 47805 0 0 0 664 25 0 0 20 0 11 0 119889995 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646900608808 140646799433388 0 4 0 16800975 0 0 0 -1 0 0 0 2 0 0
[pid=19379/tid=19381] ppid=19376 vsize=1049380 CPUtime=1.31
/proc/19379/task/19381/stat : 19381 (java) R 19376 19376 1750 0 -1 4202560 53197 0 0 0 117 14 0 0 20 0 11 0 119889997 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646793248072 140646886851831 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19382] ppid=19376 vsize=1049380 CPUtime=0
/proc/19379/task/19382/stat : 19382 (java) S 19376 19376 1750 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 119889998 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646792194064 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19383] ppid=19376 vsize=1049380 CPUtime=0
/proc/19379/task/19383/stat : 19383 (java) S 19376 19376 1750 0 -1 4202560 8 0 0 0 0 0 0 0 20 0 11 0 119889998 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646791141280 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19384] ppid=19376 vsize=1049380 CPUtime=0
/proc/19379/task/19384/stat : 19384 (java) S 19376 19376 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 119890002 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646790089712 140646894097440 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19385] ppid=19376 vsize=1049380 CPUtime=2.21
/proc/19379/task/19385/stat : 19385 (java) S 19376 19376 1750 0 -1 4202560 11222 0 0 0 216 5 0 0 20 0 11 0 119890002 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646789037072 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19386] ppid=19376 vsize=1049380 CPUtime=2.16
/proc/19379/task/19386/stat : 19386 (java) S 19376 19376 1750 0 -1 4202560 8846 0 0 0 214 2 0 0 20 0 11 0 119890002 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646787984400 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19387] ppid=19376 vsize=1049380 CPUtime=0
/proc/19379/task/19387/stat : 19387 (java) S 19376 19376 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 119890002 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646786931920 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19388] ppid=19376 vsize=1049380 CPUtime=0
/proc/19379/task/19388/stat : 19388 (java) S 19376 19376 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 119890002 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646785879424 140646894089803 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19389] ppid=19376 vsize=1049380 CPUtime=0
/proc/19379/task/19389/stat : 19389 (java) S 19376 19376 1750 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 11 0 119890960 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646784681824 140646894089803 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 12.6
Current children cumulated vsize (KiB) 1058548

[startup+14.409 s]
/proc/loadavg: 1.12 1.38 1.33 2/71 19389
/proc/meminfo: memFree=32652/1022884 swapFree=0/0
[pid=19376] ppid=19375 vsize=9168 CPUtime=0
/proc/19376/stat : 19376 (p2cudf-full-1.1) S 19375 19376 1750 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 119889993 9388032 330 18446744073709551615 4194304 5129932 140733405299424 140733405297568 140700560954462 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/19376/statm: 2292 330 280 229 0 52 0
[pid=19379] ppid=19376 vsize=1049380 CPUtime=14.18
/proc/19379/stat : 19379 (java) S 19376 19376 1750 0 -1 4202496 122366 0 0 0 1371 47 0 0 20 0 11 0 119889994 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140734226822512 140646894075509 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/19379/statm: 262345 116409 2381 9 0 249695 0
[pid=19379/tid=19380] ppid=19376 vsize=1049380 CPUtime=8.46
/proc/19379/task/19380/stat : 19380 (java) R 19376 19376 1750 0 -1 4202560 47805 0 0 0 821 25 0 0 20 0 11 0 119889995 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646900608792 140646798907093 0 4 0 16800975 0 0 0 -1 0 0 0 2 0 0
[pid=19379/tid=19381] ppid=19376 vsize=1049380 CPUtime=1.31
/proc/19379/task/19381/stat : 19381 (java) S 19376 19376 1750 0 -1 4202560 53197 0 0 0 117 14 0 0 20 0 11 0 119889997 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646793247872 140646894089803 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19382] ppid=19376 vsize=1049380 CPUtime=0
/proc/19379/task/19382/stat : 19382 (java) S 19376 19376 1750 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 119889998 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646792194064 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19383] ppid=19376 vsize=1049380 CPUtime=0
/proc/19379/task/19383/stat : 19383 (java) S 19376 19376 1750 0 -1 4202560 8 0 0 0 0 0 0 0 20 0 11 0 119889998 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646791141280 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19384] ppid=19376 vsize=1049380 CPUtime=0
/proc/19379/task/19384/stat : 19384 (java) S 19376 19376 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 119890002 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646790089712 140646894097440 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19385] ppid=19376 vsize=1049380 CPUtime=2.22
/proc/19379/task/19385/stat : 19385 (java) S 19376 19376 1750 0 -1 4202560 11222 0 0 0 217 5 0 0 20 0 11 0 119890002 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646789037072 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19386] ppid=19376 vsize=1049380 CPUtime=2.16
/proc/19379/task/19386/stat : 19386 (java) S 19376 19376 1750 0 -1 4202560 8846 0 0 0 214 2 0 0 20 0 11 0 119890002 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646787984400 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19387] ppid=19376 vsize=1049380 CPUtime=0
/proc/19379/task/19387/stat : 19387 (java) S 19376 19376 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 119890002 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646786931920 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19388] ppid=19376 vsize=1049380 CPUtime=0
/proc/19379/task/19388/stat : 19388 (java) S 19376 19376 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 119890002 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646785879424 140646894089803 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19389] ppid=19376 vsize=1049380 CPUtime=0
/proc/19379/task/19389/stat : 19389 (java) S 19376 19376 1750 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 11 0 119890960 1074565120 116409 18446744073709551615 4194304 4228012 140734226831488 140646784681824 140646894089803 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 14.18
Current children cumulated vsize (KiB) 1058548

[startup+14.8008 s]
/proc/loadavg: 1.12 1.38 1.33 2/71 19389
/proc/meminfo: memFree=32652/1022884 swapFree=0/0
[pid=19376] ppid=19375 vsize=9168 CPUtime=0
/proc/19376/stat : 19376 (p2cudf-full-1.1) S 19375 19376 1750 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 119889993 9388032 330 18446744073709551615 4194304 5129932 140733405299424 140733405297568 140700560954462 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/19376/statm: 2292 330 280 229 0 52 0
[pid=19379] ppid=19376 vsize=1050408 CPUtime=14.39
/proc/19379/stat : 19379 (java) S 19376 19376 1750 0 -1 4202496 122384 0 0 0 1392 47 0 0 20 0 11 0 119889994 1075617792 116425 18446744073709551615 4194304 4228012 140734226831488 140734226822512 140646894075509 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/19379/statm: 262602 116425 2381 9 0 249952 0
[pid=19379/tid=19380] ppid=19376 vsize=1050408 CPUtime=8.61
/proc/19379/task/19380/stat : 19380 (java) S 19376 19376 1750 0 -1 4202560 47814 0 0 0 836 25 0 0 20 0 11 0 119889995 1075617792 116425 18446744073709551615 4194304 4228012 140734226831488 140646900609968 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 2 0 0
[pid=19379/tid=19381] ppid=19376 vsize=1050408 CPUtime=1.31
/proc/19379/task/19381/stat : 19381 (java) S 19376 19376 1750 0 -1 4202560 53197 0 0 0 117 14 0 0 20 0 11 0 119889997 1075617792 116425 18446744073709551615 4194304 4228012 140734226831488 140646793247872 140646894089803 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19382] ppid=19376 vsize=1050408 CPUtime=0
/proc/19379/task/19382/stat : 19382 (java) S 19376 19376 1750 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 119889998 1075617792 116425 18446744073709551615 4194304 4228012 140734226831488 140646792194064 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19383] ppid=19376 vsize=1050408 CPUtime=0
/proc/19379/task/19383/stat : 19383 (java) S 19376 19376 1750 0 -1 4202560 8 0 0 0 0 0 0 0 20 0 11 0 119889998 1075617792 116425 18446744073709551615 4194304 4228012 140734226831488 140646791141280 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19384] ppid=19376 vsize=1050408 CPUtime=0
/proc/19379/task/19384/stat : 19384 (java) S 19376 19376 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 119890002 1075617792 116425 18446744073709551615 4194304 4228012 140734226831488 140646790089712 140646894097440 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19385] ppid=19376 vsize=1050408 CPUtime=2.25
/proc/19379/task/19385/stat : 19385 (java) S 19376 19376 1750 0 -1 4202560 11224 0 0 0 220 5 0 0 20 0 11 0 119890002 1075617792 116425 18446744073709551615 4194304 4228012 140734226831488 140646789037072 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19386] ppid=19376 vsize=1050408 CPUtime=2.18
/proc/19379/task/19386/stat : 19386 (java) S 19376 19376 1750 0 -1 4202560 8847 0 0 0 216 2 0 0 20 0 11 0 119890002 1075617792 116425 18446744073709551615 4194304 4228012 140734226831488 140646787984400 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19387] ppid=19376 vsize=1050408 CPUtime=0
/proc/19379/task/19387/stat : 19387 (java) S 19376 19376 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 119890002 1075617792 116425 18446744073709551615 4194304 4228012 140734226831488 140646786931920 140646894088916 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19379/tid=19388] ppid=19376 vsize=1050408 CPUtime=0.01
/proc/19379/task/19388/stat : 19388 (java) S 19376 19376 1750 0 -1 4202560 1 0 0 0 1 0 0 0 20 0 11 0 119890002 1075617792 116425 18446744073709551615 4194304 4228012 140734226831488 140646785879424 140646894089803 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 14.39
Current children cumulated vsize (KiB) 1059576

[startup+15.2068 s]
/proc/loadavg: 1.12 1.38 1.33 2/71 19389
/proc/meminfo: memFree=32652/1022884 swapFree=0/0
[pid=19376] ppid=19375 vsize=9168 CPUtime=0
/proc/19376/stat : 19376 (p2cudf-full-1.1) S 19375 19376 1750 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 119889993 9388032 330 18446744073709551615 4194304 5129932 140733405299424 140733405297568 140700560954462 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/19376/statm: 2292 330 280 229 0 52 0
[pid=19379] ppid=19376 vsize=0 CPUtime=14.5
/proc/19379/stat : 19379 (java) Z 19376 19376 1750 0 -1 4203532 122398 0 0 0 1401 49 0 0 20 0 2 0 119889994 0 0 18446744073709551615 0 0 0 0 0 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/19379/statm: 0 0 0 0 0 0 0
Current children cumulated CPU time (s) 14.5
Current children cumulated vsize (KiB) 9168

Child status: 0
Real time (s): 15.2562
CPU time (s): 14.5609
CPU user time (s): 14.0169
CPU system time (s): 0.544034
CPU usage (%): 95.4425
Max. virtual memory (cumulated for all children) (KiB): 1060840

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 14.0169
system time used= 0.544034
maximum resident set size= 465748
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 123159
page faults= 0
swaps= 0
block input operations= 42368
block output operations= 184
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 1087
involuntary context switches= 3714

runsolver used 0.044002 second user time and 0.120007 second system time

The end