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/rand268.cudf.log.runsolver /home/competition/p2cudf-full-1.15/p2cudf-full-1.15 /home/competition/data/upgrade/easy/rand268.cudf /tmp/misc2012/2012-09-02-22:42/full/p2cudf-full-1.15/trendy-size/upgrade/easy/rand268.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

[startup+0 s]
/proc/loadavg: 1.09 1.30 1.18 2/59 3428
/proc/meminfo: memFree=510836/1022884 swapFree=0/0
[pid=3428] ppid=3427 vsize=3152 CPUtime=0
/proc/3428/stat : 3428 (runsolver) R 3427 1733 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 1 0 119879615 3227648 32 18446744073709551615 134512640 134586868 4293508000 4293506048 4152099888 0 0 16781316 24578 0 0 0 17 0 0 0 0 0 0
/proc/3428/statm: 788 32 0 19 0 73 0
Current StackSize limit: 8192 KiB


[startup+0.196465 s]
/proc/loadavg: 1.09 1.30 1.18 2/59 3428
/proc/meminfo: memFree=510836/1022884 swapFree=0/0
[pid=3428] ppid=3427 vsize=9168 CPUtime=0
/proc/3428/stat : 3428 (p2cudf-full-1.1) S 3427 3428 1733 0 -1 4202496 454 290 2 1 0 0 0 0 20 0 1 0 119879615 9388032 331 18446744073709551615 4194304 5129932 140736623295392 140736623293536 139893606450270 0 65536 16781316 65538 0 0 0 17 0 0 0 2 0 0
/proc/3428/statm: 2292 331 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+0.200377 s]
/proc/loadavg: 1.09 1.30 1.18 2/59 3428
/proc/meminfo: memFree=510836/1022884 swapFree=0/0
[pid=3428] ppid=3427 vsize=9168 CPUtime=0
/proc/3428/stat : 3428 (p2cudf-full-1.1) S 3427 3428 1733 0 -1 4202496 454 290 2 1 0 0 0 0 20 0 1 0 119879615 9388032 331 18446744073709551615 4194304 5129932 140736623295392 140736623293536 139893606450270 0 65536 16781316 65538 0 0 0 17 0 0 0 2 0 0
/proc/3428/statm: 2292 331 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+0.300286 s]
/proc/loadavg: 1.09 1.30 1.18 2/59 3428
/proc/meminfo: memFree=510836/1022884 swapFree=0/0
[pid=3428] ppid=3427 vsize=9168 CPUtime=0
/proc/3428/stat : 3428 (p2cudf-full-1.1) S 3427 3428 1733 0 -1 4202496 454 290 2 1 0 0 0 0 20 0 1 0 119879615 9388032 331 18446744073709551615 4194304 5129932 140736623295392 140736623293536 139893606450270 0 65536 16781316 65538 0 0 0 17 0 0 0 2 0 0
/proc/3428/statm: 2292 331 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+0.700231 s]
/proc/loadavg: 1.09 1.30 1.18 2/59 3428
/proc/meminfo: memFree=510836/1022884 swapFree=0/0
[pid=3428] ppid=3427 vsize=9168 CPUtime=0
/proc/3428/stat : 3428 (p2cudf-full-1.1) S 3427 3428 1733 0 -1 4202496 454 290 2 1 0 0 0 0 20 0 1 0 119879615 9388032 331 18446744073709551615 4194304 5129932 140736623295392 140736623293536 139893606450270 0 65536 16781316 65538 0 0 0 17 0 0 0 2 0 0
/proc/3428/statm: 2292 331 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+1.50072 s]
/proc/loadavg: 1.09 1.30 1.18 4/70 3440
/proc/meminfo: memFree=481724/1022884 swapFree=0/0
[pid=3428] ppid=3427 vsize=9168 CPUtime=0
/proc/3428/stat : 3428 (p2cudf-full-1.1) S 3427 3428 1733 0 -1 4202496 454 290 2 1 0 0 0 0 20 0 1 0 119879615 9388032 331 18446744073709551615 4194304 5129932 140736623295392 140736623293536 139893606450270 0 65536 16781316 65538 0 0 0 17 0 0 0 2 0 0
/proc/3428/statm: 2292 331 280 229 0 52 0
[pid=3431] ppid=3428 vsize=1035348 CPUtime=1.15
/proc/3431/stat : 3431 (java) S 3428 3428 1733 0 -1 4202496 18536 0 20 0 105 10 0 0 20 0 10 0 119879619 1060196352 17004 18446744073709551615 4194304 4228012 140735346410224 140735346401248 139849806319221 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 8 0 0
/proc/3431/statm: 258837 17004 2347 9 0 246187 0
[pid=3431/tid=3432] ppid=3428 vsize=1035348 CPUtime=0.57
/proc/3431/task/3432/stat : 3432 (java) R 3428 3428 1733 0 -1 4202560 10402 0 8 0 49 8 0 0 20 0 10 0 119879629 1060196352 17004 18446744073709551615 4194304 4228012 140735346410224 139849812845216 139849710786095 0 4 0 16800975 0 0 0 -1 0 0 0 21 0 0
[pid=3431/tid=3433] ppid=3428 vsize=1035348 CPUtime=0
/proc/3431/task/3433/stat : 3433 (java) S 3428 3428 1733 0 -1 4202560 4 0 0 0 0 0 0 0 20 0 10 0 119879645 1060196352 17004 18446744073709551615 4194304 4228012 140735346410224 139849705491584 139849806333515 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3434] ppid=3428 vsize=1035348 CPUtime=0
/proc/3431/task/3434/stat : 3434 (java) S 3428 3428 1733 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 10 0 119879646 1060196352 17004 18446744073709551615 4194304 4228012 140735346410224 139849704437776 139849806332628 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3435] ppid=3428 vsize=1035348 CPUtime=0
/proc/3431/task/3435/stat : 3435 (java) S 3428 3428 1733 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 10 0 119879646 1060196352 17004 18446744073709551615 4194304 4228012 140735346410224 139849703384992 139849806332628 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3436] ppid=3428 vsize=1035348 CPUtime=0
/proc/3431/task/3436/stat : 3436 (java) S 3428 3428 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 119879651 1060196352 17004 18446744073709551615 4194304 4228012 140735346410224 139849702333424 139849806341152 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3437] ppid=3428 vsize=1035348 CPUtime=0.3
/proc/3431/task/3437/stat : 3437 (java) R 3428 3428 1733 0 -1 4202560 4140 0 0 0 28 2 0 0 20 0 10 0 119879651 1060196352 17004 18446744073709551615 4194304 4228012 140735346410224 139849701266120 139849790151335 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3438] ppid=3428 vsize=1035348 CPUtime=0.25
/proc/3431/task/3438/stat : 3438 (java) R 3428 3428 1733 0 -1 4202560 2715 0 0 0 25 0 0 0 20 0 10 0 119879651 1060196352 17004 18446744073709551615 4194304 4228012 140735346410224 139849700213336 139849790178202 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3439] ppid=3428 vsize=1035348 CPUtime=0
/proc/3431/task/3439/stat : 3439 (java) S 3428 3428 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119879651 1060196352 17004 18446744073709551615 4194304 4228012 140735346410224 139849699175632 139849806332628 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3440] ppid=3428 vsize=1035348 CPUtime=0
/proc/3431/task/3440/stat : 3440 (java) S 3428 3428 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119879651 1060196352 17004 18446744073709551615 4194304 4228012 140735346410224 139849698123136 139849806333515 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 1.15
Current children cumulated vsize (KiB) 1044516

[startup+3.10076 s]
/proc/loadavg: 1.25 1.33 1.19 4/70 3440
/proc/meminfo: memFree=375704/1022884 swapFree=0/0
[pid=3428] ppid=3427 vsize=9168 CPUtime=0
/proc/3428/stat : 3428 (p2cudf-full-1.1) S 3427 3428 1733 0 -1 4202496 454 290 2 1 0 0 0 0 20 0 1 0 119879615 9388032 331 18446744073709551615 4194304 5129932 140736623295392 140736623293536 139893606450270 0 65536 16781316 65538 0 0 0 17 0 0 0 2 0 0
/proc/3428/statm: 2292 331 280 229 0 52 0
[pid=3431] ppid=3428 vsize=1054880 CPUtime=2.74
/proc/3431/stat : 3431 (java) S 3428 3428 1733 0 -1 4202496 76473 0 20 0 242 32 0 0 20 0 10 0 119879619 1080197120 71043 18446744073709551615 4194304 4228012 140735346410224 140735346401248 139849806319221 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 8 0 0
/proc/3431/statm: 263720 71043 2368 9 0 251070 0
[pid=3431/tid=3432] ppid=3428 vsize=1054880 CPUtime=1.23
/proc/3431/task/3432/stat : 3432 (java) R 3428 3428 1733 0 -1 4202560 47397 0 8 0 99 24 0 0 20 0 10 0 119879629 1080197120 71043 18446744073709551615 4194304 4228012 140735346410224 139849812845248 139849710719152 0 4 0 16800975 0 0 0 -1 0 0 0 21 0 0
[pid=3431/tid=3433] ppid=3428 vsize=1054880 CPUtime=0.16
/proc/3431/task/3433/stat : 3433 (java) S 3428 3428 1733 0 -1 4202560 7957 0 0 0 14 2 0 0 20 0 10 0 119879645 1080197120 71043 18446744073709551615 4194304 4228012 140735346410224 139849705491584 139849806333515 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3434] ppid=3428 vsize=1054880 CPUtime=0
/proc/3431/task/3434/stat : 3434 (java) S 3428 3428 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 119879646 1080197120 71043 18446744073709551615 4194304 4228012 140735346410224 139849704437776 139849806332628 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3435] ppid=3428 vsize=1054880 CPUtime=0
/proc/3431/task/3435/stat : 3435 (java) S 3428 3428 1733 0 -1 4202560 8 0 0 0 0 0 0 0 20 0 10 0 119879646 1080197120 71043 18446744073709551615 4194304 4228012 140735346410224 139849703384992 139849806332628 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3436] ppid=3428 vsize=1054880 CPUtime=0
/proc/3431/task/3436/stat : 3436 (java) S 3428 3428 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 119879651 1080197120 71043 18446744073709551615 4194304 4228012 140735346410224 139849702333424 139849806341152 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3437] ppid=3428 vsize=1054880 CPUtime=0.7
/proc/3431/task/3437/stat : 3437 (java) S 3428 3428 1733 0 -1 4202560 9361 0 0 0 66 4 0 0 20 0 10 0 119879651 1080197120 71043 18446744073709551615 4194304 4228012 140735346410224 139849701280784 139849806332628 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3438] ppid=3428 vsize=1054880 CPUtime=0.61
/proc/3431/task/3438/stat : 3438 (java) S 3428 3428 1733 0 -1 4202560 10480 0 0 0 59 2 0 0 20 0 10 0 119879651 1080197120 71043 18446744073709551615 4194304 4228012 140735346410224 139849700228112 139849806332628 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3439] ppid=3428 vsize=1054880 CPUtime=0
/proc/3431/task/3439/stat : 3439 (java) S 3428 3428 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119879651 1080197120 71043 18446744073709551615 4194304 4228012 140735346410224 139849699175632 139849806332628 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3440] ppid=3428 vsize=1054880 CPUtime=0
/proc/3431/task/3440/stat : 3440 (java) S 3428 3428 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119879651 1080197120 71043 18446744073709551615 4194304 4228012 140735346410224 139849698123136 139849806333515 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 2.74
Current children cumulated vsize (KiB) 1064048

[startup+6.30072 s]
/proc/loadavg: 1.25 1.33 1.19 2/70 3440
/proc/meminfo: memFree=69052/1022884 swapFree=0/0
[pid=3428] ppid=3427 vsize=9168 CPUtime=0
/proc/3428/stat : 3428 (p2cudf-full-1.1) S 3427 3428 1733 0 -1 4202496 454 290 2 1 0 0 0 0 20 0 1 0 119879615 9388032 331 18446744073709551615 4194304 5129932 140736623295392 140736623293536 139893606450270 0 65536 16781316 65538 0 0 0 17 0 0 0 2 0 0
/proc/3428/statm: 2292 331 280 229 0 52 0
[pid=3431] ppid=3428 vsize=1049040 CPUtime=5.87
/proc/3431/stat : 3431 (java) S 3428 3428 1733 0 -1 4202496 113969 0 20 0 535 52 0 0 20 0 10 0 119879619 1074216960 107545 18446744073709551615 4194304 4228012 140735346410224 140735346401248 139849806319221 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 8 0 0
/proc/3431/statm: 262260 107545 2370 9 0 249610 0
[pid=3431/tid=3432] ppid=3428 vsize=1049040 CPUtime=3.09
/proc/3431/task/3432/stat : 3432 (java) R 3428 3428 1733 0 -1 4202560 47466 0 8 0 282 27 0 0 20 0 10 0 119879629 1074216960 107545 18446744073709551615 4194304 4228012 140735346410224 139849812853184 139849790841961 0 4 0 16800975 0 0 0 -1 0 0 0 23 0 0
[pid=3431/tid=3433] ppid=3428 vsize=1049040 CPUtime=1.06
/proc/3431/task/3433/stat : 3433 (java) S 3428 3428 1733 0 -1 4202560 45257 0 0 0 87 19 0 0 20 0 10 0 119879645 1074216960 107545 18446744073709551615 4194304 4228012 140735346410224 139849705491584 139849806333515 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3434] ppid=3428 vsize=1049040 CPUtime=0
/proc/3431/task/3434/stat : 3434 (java) S 3428 3428 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 119879646 1074216960 107545 18446744073709551615 4194304 4228012 140735346410224 139849704437776 139849806332628 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3435] ppid=3428 vsize=1049040 CPUtime=0
/proc/3431/task/3435/stat : 3435 (java) S 3428 3428 1733 0 -1 4202560 8 0 0 0 0 0 0 0 20 0 10 0 119879646 1074216960 107545 18446744073709551615 4194304 4228012 140735346410224 139849703384992 139849806332628 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3436] ppid=3428 vsize=1049040 CPUtime=0
/proc/3431/task/3436/stat : 3436 (java) S 3428 3428 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 119879651 1074216960 107545 18446744073709551615 4194304 4228012 140735346410224 139849702333424 139849806341152 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3437] ppid=3428 vsize=1049040 CPUtime=0.9
/proc/3431/task/3437/stat : 3437 (java) R 3428 3428 1733 0 -1 4202560 9385 0 0 0 86 4 0 0 20 0 10 0 119879651 1074216960 107545 18446744073709551615 4194304 4228012 140735346410224 139849701280528 139849790595198 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3438] ppid=3428 vsize=1049040 CPUtime=0.79
/proc/3431/task/3438/stat : 3438 (java) R 3428 3428 1733 0 -1 4202560 10583 0 0 0 77 2 0 0 20 0 10 0 119879651 1074216960 107545 18446744073709551615 4194304 4228012 140735346410224 139849700227856 139849789429921 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3439] ppid=3428 vsize=1049040 CPUtime=0
/proc/3431/task/3439/stat : 3439 (java) S 3428 3428 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119879651 1074216960 107545 18446744073709551615 4194304 4228012 140735346410224 139849699175632 139849806332628 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3440] ppid=3428 vsize=1049040 CPUtime=0
/proc/3431/task/3440/stat : 3440 (java) S 3428 3428 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119879651 1074216960 107545 18446744073709551615 4194304 4228012 140735346410224 139849698123136 139849806333515 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 5.87
Current children cumulated vsize (KiB) 1058208

[startup+12.7009 s]
/proc/loadavg: 1.31 1.34 1.19 3/71 3441
/proc/meminfo: memFree=43128/1022884 swapFree=0/0
[pid=3428] ppid=3427 vsize=9168 CPUtime=0
/proc/3428/stat : 3428 (p2cudf-full-1.1) S 3427 3428 1733 0 -1 4202496 454 290 2 1 0 0 0 0 20 0 1 0 119879615 9388032 331 18446744073709551615 4194304 5129932 140736623295392 140736623293536 139893606450270 0 65536 16781316 65538 0 0 0 17 0 0 0 2 0 0
/proc/3428/statm: 2292 331 280 229 0 52 0
[pid=3431] ppid=3428 vsize=1038564 CPUtime=11.77
/proc/3431/stat : 3431 (java) S 3428 3428 1733 0 -1 4202496 123133 0 20 0 1120 57 0 0 20 0 11 0 119879619 1063489536 113114 18446744073709551615 4194304 4228012 140735346410224 140735346401248 139849806319221 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 8 0 0
/proc/3431/statm: 259641 113114 2381 9 0 246991 0
[pid=3431/tid=3432] ppid=3428 vsize=1038564 CPUtime=5.86
/proc/3431/task/3432/stat : 3432 (java) S 3428 3428 1733 0 -1 4202560 47790 0 8 0 558 28 0 0 20 0 11 0 119879629 1063489536 113114 18446744073709551615 4194304 4228012 140735346410224 139849812853680 139849806332628 0 4 0 16800975 0 0 0 -1 0 0 0 24 0 0
[pid=3431/tid=3433] ppid=3428 vsize=1038564 CPUtime=1.32
/proc/3431/task/3433/stat : 3433 (java) S 3428 3428 1733 0 -1 4202560 53197 0 0 0 110 22 0 0 20 0 11 0 119879645 1063489536 113114 18446744073709551615 4194304 4228012 140735346410224 139849705491584 139849806333515 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3434] ppid=3428 vsize=1038564 CPUtime=0
/proc/3431/task/3434/stat : 3434 (java) S 3428 3428 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 119879646 1063489536 113114 18446744073709551615 4194304 4228012 140735346410224 139849704437776 139849806332628 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3435] ppid=3428 vsize=1038564 CPUtime=0
/proc/3431/task/3435/stat : 3435 (java) S 3428 3428 1733 0 -1 4202560 8 0 0 0 0 0 0 0 20 0 11 0 119879646 1063489536 113114 18446744073709551615 4194304 4228012 140735346410224 139849703384992 139849806332628 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3436] ppid=3428 vsize=1038564 CPUtime=0
/proc/3431/task/3436/stat : 3436 (java) S 3428 3428 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 119879651 1063489536 113114 18446744073709551615 4194304 4228012 140735346410224 139849702333424 139849806341152 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3437] ppid=3428 vsize=1038564 CPUtime=2.44
/proc/3431/task/3437/stat : 3437 (java) S 3428 3428 1733 0 -1 4202560 9490 0 0 0 240 4 0 0 20 0 11 0 119879651 1063489536 113114 18446744073709551615 4194304 4228012 140735346410224 139849701280784 139849806332628 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3438] ppid=3428 vsize=1038564 CPUtime=2.1
/proc/3431/task/3438/stat : 3438 (java) S 3428 3428 1733 0 -1 4202560 11366 0 0 0 208 2 0 0 20 0 11 0 119879651 1063489536 113114 18446744073709551615 4194304 4228012 140735346410224 139849700228112 139849806332628 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3439] ppid=3428 vsize=1038564 CPUtime=0
/proc/3431/task/3439/stat : 3439 (java) S 3428 3428 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 119879651 1063489536 113114 18446744073709551615 4194304 4228012 140735346410224 139849699175632 139849806332628 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3440] ppid=3428 vsize=1038564 CPUtime=0.01
/proc/3431/task/3440/stat : 3440 (java) S 3428 3428 1733 0 -1 4202560 0 0 0 0 1 0 0 0 20 0 11 0 119879651 1063489536 113114 18446744073709551615 4194304 4228012 140735346410224 139849698123136 139849806333515 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 11.77
Current children cumulated vsize (KiB) 1047732

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

[startup+12.801 s]
/proc/loadavg: 1.31 1.34 1.19 3/71 3441
/proc/meminfo: memFree=43128/1022884 swapFree=0/0
[pid=3428] ppid=3427 vsize=9168 CPUtime=0
/proc/3428/stat : 3428 (p2cudf-full-1.1) S 3427 3428 1733 0 -1 4202496 454 290 2 1 0 0 0 0 20 0 1 0 119879615 9388032 331 18446744073709551615 4194304 5129932 140736623295392 140736623293536 139893606450270 0 65536 16781316 65538 0 0 0 17 0 0 0 2 0 0
/proc/3428/statm: 2292 331 280 229 0 52 0
[pid=3431] ppid=3428 vsize=1038564 CPUtime=11.82
/proc/3431/stat : 3431 (java) S 3428 3428 1733 0 -1 4202496 123136 0 20 0 1124 58 0 0 20 0 11 0 119879619 1063489536 113117 18446744073709551615 4194304 4228012 140735346410224 140735346401248 139849806319221 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 8 0 0
/proc/3431/statm: 259641 113117 2381 9 0 246991 0
[pid=3431/tid=3432] ppid=3428 vsize=1038564 CPUtime=5.86
/proc/3431/task/3432/stat : 3432 (java) S 3428 3428 1733 0 -1 4202560 47790 0 8 0 558 28 0 0 20 0 11 0 119879629 1063489536 113117 18446744073709551615 4194304 4228012 140735346410224 139849812853680 139849806332628 0 4 0 16800975 0 0 0 -1 0 0 0 24 0 0
[pid=3431/tid=3433] ppid=3428 vsize=1038564 CPUtime=1.32
/proc/3431/task/3433/stat : 3433 (java) S 3428 3428 1733 0 -1 4202560 53197 0 0 0 110 22 0 0 20 0 11 0 119879645 1063489536 113117 18446744073709551615 4194304 4228012 140735346410224 139849705491584 139849806333515 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3434] ppid=3428 vsize=1038564 CPUtime=0
/proc/3431/task/3434/stat : 3434 (java) S 3428 3428 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 119879646 1063489536 113117 18446744073709551615 4194304 4228012 140735346410224 139849704437776 139849806332628 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3435] ppid=3428 vsize=1038564 CPUtime=0
/proc/3431/task/3435/stat : 3435 (java) S 3428 3428 1733 0 -1 4202560 8 0 0 0 0 0 0 0 20 0 11 0 119879646 1063489536 113117 18446744073709551615 4194304 4228012 140735346410224 139849703384992 139849806332628 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3436] ppid=3428 vsize=1038564 CPUtime=0
/proc/3431/task/3436/stat : 3436 (java) S 3428 3428 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 119879651 1063489536 113117 18446744073709551615 4194304 4228012 140735346410224 139849702333424 139849806341152 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3437] ppid=3428 vsize=1038564 CPUtime=2.44
/proc/3431/task/3437/stat : 3437 (java) S 3428 3428 1733 0 -1 4202560 9490 0 0 0 240 4 0 0 20 0 11 0 119879651 1063489536 113117 18446744073709551615 4194304 4228012 140735346410224 139849701280784 139849806332628 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3438] ppid=3428 vsize=1038564 CPUtime=2.1
/proc/3431/task/3438/stat : 3438 (java) S 3428 3428 1733 0 -1 4202560 11366 0 0 0 208 2 0 0 20 0 11 0 119879651 1063489536 113117 18446744073709551615 4194304 4228012 140735346410224 139849700228112 139849806332628 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3439] ppid=3428 vsize=1038564 CPUtime=0
/proc/3431/task/3439/stat : 3439 (java) S 3428 3428 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 119879651 1063489536 113117 18446744073709551615 4194304 4228012 140735346410224 139849699175632 139849806332628 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3431/tid=3440] ppid=3428 vsize=1038564 CPUtime=0.01
/proc/3431/task/3440/stat : 3440 (java) S 3428 3428 1733 0 -1 4202560 0 0 0 0 1 0 0 0 20 0 11 0 119879651 1063489536 113117 18446744073709551615 4194304 4228012 140735346410224 139849698123136 139849806333515 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 11.82
Current children cumulated vsize (KiB) 1047732

[startup+12.9009 s]
/proc/loadavg: 1.31 1.34 1.19 3/71 3441
/proc/meminfo: memFree=43128/1022884 swapFree=0/0
[pid=3428] ppid=3427 vsize=9168 CPUtime=0
/proc/3428/stat : 3428 (p2cudf-full-1.1) S 3427 3428 1733 0 -1 4202496 454 290 2 1 0 0 0 0 20 0 1 0 119879615 9388032 331 18446744073709551615 4194304 5129932 140736623295392 140736623293536 139893606450270 0 65536 16781316 65538 0 0 0 17 0 0 0 2 0 0
/proc/3428/statm: 2292 331 280 229 0 52 0
[pid=3431] ppid=3428 vsize=0 CPUtime=11.92
/proc/3431/stat : 3431 (java) Z 3428 3428 1733 0 -1 4203532 123146 0 20 0 1130 62 0 0 20 0 2 0 119879619 0 0 18446744073709551615 0 0 0 0 0 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 8 0 0
/proc/3431/statm: 0 0 0 0 0 0 0
Current children cumulated CPU time (s) 11.92
Current children cumulated vsize (KiB) 9168

Child status: 0
Real time (s): 12.9017
CPU time (s): 11.9287
CPU user time (s): 11.3047
CPU system time (s): 0.624039
CPU usage (%): 92.4584
Max. virtual memory (cumulated for all children) (KiB): 1065248

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 11.3047
system time used= 0.624039
maximum resident set size= 465100
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 123903
page faults= 23
swaps= 0
block input operations= 44880
block output operations= 184
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 1066
involuntary context switches= 3355

runsolver used 0.020001 second user time and 0.116007 second system time

The end