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: /home/misc2010/bin/runsolver -s SIGUSR1 -M 1124 -C 290 -d 10 -w /home/misc2010/tmp/201012061533/p2cudf-paranoid-1.9/rand7141b1.cudf.impossible.log.runsolver ./p2cudf-paranoid-1.9 /home/misc2010/data/2010/impossible//rand7141b1.cudf /home/misc2010/tmp/201012061533/p2cudf-paranoid-1.9/rand7141b1.cudf.impossible.result 

Enforcing CPUTime limit (soft limit, will send signal-name then SIGKILL): 290 seconds
Enforcing CPUTime limit (hard limit, will send SIGXCPU): 320 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.20 1.10 1.07 6/48 15995
/proc/meminfo: memFree=723536/1048576 swapFree=2078752/2097144
[pid=15992] ppid=15991 vsize=2572 CPUtime=0
/proc/15992/stat : 15992 (p2cudf-paranoid) S 15991 15992 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 23 0 1 0 875654073 2633728 273 1283457024 134512640 135304128 4292439984 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15992/statm: 643 273 233 194 0 29 0
[pid=15993] ppid=15992 vsize=2576 CPUtime=0
/proc/15993/stat : 15993 (p2cudf) S 15992 15992 2059 34821 2220 4202496 357 0 0 0 0 0 0 0 23 0 1 0 875654073 2637824 275 1283457024 134512640 135304128 4292122480 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0
/proc/15993/statm: 644 275 234 194 0 30 0
[pid=15994] ppid=15993 vsize=2576 CPUtime=0
/proc/15994/stat : 15994 (p2cudf) R 15993 15992 2059 34821 2220 4202560 92 0 0 0 0 0 0 0 25 0 1 0 875654074 2637824 117 1283457024 134512640 135304128 4292122480 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/15994/statm: 644 117 75 194 0 30 0
[pid=15995] ppid=15994 vsize=2576 CPUtime=0
/proc/15995/stat : 15995 (p2cudf) R 15994 15992 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 1 0 875654074 2637824 42 1283457024 134512640 135304128 4292122480 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/15995/statm: 644 42 0 194 0 30 0

[startup+0.114073 s]
/proc/loadavg: 1.20 1.10 1.07 6/48 15995
/proc/meminfo: memFree=723536/1048576 swapFree=2078752/2097144
[pid=15992] ppid=15991 vsize=2572 CPUtime=0
/proc/15992/stat : 15992 (p2cudf-paranoid) S 15991 15992 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 23 0 1 0 875654073 2633728 273 1283457024 134512640 135304128 4292439984 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15992/statm: 643 273 233 194 0 29 0
[pid=15993] ppid=15992 vsize=2580 CPUtime=0.02
/proc/15993/stat : 15993 (p2cudf) S 15992 15992 2059 34821 2220 4202496 392 2997 0 1 0 0 2 0 25 0 1 0 875654073 2641920 283 1283457024 134512640 135304128 4292122480 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15993/statm: 645 283 241 194 0 31 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5152

[startup+0.204094 s]
/proc/loadavg: 1.20 1.10 1.07 6/48 15995
/proc/meminfo: memFree=723536/1048576 swapFree=2078752/2097144
[pid=15992] ppid=15991 vsize=2572 CPUtime=0
/proc/15992/stat : 15992 (p2cudf-paranoid) S 15991 15992 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 23 0 1 0 875654073 2633728 273 1283457024 134512640 135304128 4292439984 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15992/statm: 643 273 233 194 0 29 0
[pid=15993] ppid=15992 vsize=2580 CPUtime=0.02
/proc/15993/stat : 15993 (p2cudf) S 15992 15992 2059 34821 2220 4202496 392 2997 0 1 0 0 2 0 25 0 1 0 875654073 2641920 283 1283457024 134512640 135304128 4292122480 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15993/statm: 645 283 241 194 0 31 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5152

[startup+0.304103 s]
/proc/loadavg: 1.20 1.10 1.07 6/48 15995
/proc/meminfo: memFree=723536/1048576 swapFree=2078752/2097144
[pid=15992] ppid=15991 vsize=2572 CPUtime=0
/proc/15992/stat : 15992 (p2cudf-paranoid) S 15991 15992 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 23 0 1 0 875654073 2633728 273 1283457024 134512640 135304128 4292439984 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15992/statm: 643 273 233 194 0 29 0
[pid=15993] ppid=15992 vsize=2580 CPUtime=0.02
/proc/15993/stat : 15993 (p2cudf) S 15992 15992 2059 34821 2220 4202496 392 2997 0 1 0 0 2 0 25 0 1 0 875654073 2641920 283 1283457024 134512640 135304128 4292122480 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15993/statm: 645 283 241 194 0 31 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5152

[startup+0.706179 s]
/proc/loadavg: 1.20 1.10 1.07 6/48 15995
/proc/meminfo: memFree=723536/1048576 swapFree=2078752/2097144
[pid=15992] ppid=15991 vsize=2572 CPUtime=0
/proc/15992/stat : 15992 (p2cudf-paranoid) S 15991 15992 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 23 0 1 0 875654073 2633728 273 1283457024 134512640 135304128 4292439984 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15992/statm: 643 273 233 194 0 29 0
[pid=15993] ppid=15992 vsize=2580 CPUtime=0.02
/proc/15993/stat : 15993 (p2cudf) S 15992 15992 2059 34821 2220 4202496 392 2997 0 1 0 0 2 0 25 0 1 0 875654073 2641920 283 1283457024 134512640 135304128 4292122480 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15993/statm: 645 283 241 194 0 31 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5152

[startup+1.50413 s]
/proc/loadavg: 1.20 1.10 1.07 4/57 16015
/proc/meminfo: memFree=684300/1048576 swapFree=2078752/2097144
[pid=15992] ppid=15991 vsize=2572 CPUtime=0
/proc/15992/stat : 15992 (p2cudf-paranoid) S 15991 15992 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 23 0 1 0 875654073 2633728 273 1283457024 134512640 135304128 4292439984 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15992/statm: 643 273 233 194 0 29 0
[pid=15993] ppid=15992 vsize=2580 CPUtime=0.02
/proc/15993/stat : 15993 (p2cudf) S 15992 15992 2059 34821 2220 4202496 392 2997 0 1 0 0 2 0 25 0 1 0 875654073 2641920 283 1283457024 134512640 135304128 4292122480 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15993/statm: 645 283 241 194 0 31 0
[pid=16006] ppid=15993 vsize=868520 CPUtime=1.43
/proc/16006/stat : 16006 (java) S 15993 15992 2059 34821 2220 4202496 19421 0 1 0 134 9 0 0 25 0 10 0 875654077 889364480 17188 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/16006/statm: 217130 17188 1741 10 0 214220 0
[pid=16006/tid=16007] ppid=15993 vsize=868520 CPUtime=0.66
/proc/16006/task/16007/stat : 16007 (java) R 15993 15992 2059 34821 2220 4202560 12723 0 1 0 61 5 0 0 25 0 10 0 875654078 889364480 17188 1283457024 134512640 134550932 4293689232 18446744073709551615 4096072343 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=16006/tid=16008] ppid=15993 vsize=868520 CPUtime=0
/proc/16006/task/16008/stat : 16008 (java) S 15993 15992 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 18 0 10 0 875654079 889364480 17188 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 0 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16009] ppid=15993 vsize=868520 CPUtime=0
/proc/16006/task/16009/stat : 16009 (java) S 15993 15992 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 25 0 10 0 875654080 889364480 17188 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16010] ppid=15993 vsize=868520 CPUtime=0
/proc/16006/task/16010/stat : 16010 (java) S 15993 15992 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 10 0 875654080 889364480 17188 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16011] ppid=15993 vsize=868520 CPUtime=0
/proc/16006/task/16011/stat : 16011 (java) S 15993 15992 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875654082 889364480 17188 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16012] ppid=15993 vsize=868520 CPUtime=0.34
/proc/16006/task/16012/stat : 16012 (java) S 15993 15992 2059 34821 2220 4202560 2746 0 0 0 32 2 0 0 24 0 10 0 875654082 889364480 17188 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16013] ppid=15993 vsize=868520 CPUtime=0.41
/proc/16006/task/16013/stat : 16013 (java) S 15993 15992 2059 34821 2220 4202560 2839 0 0 0 41 0 0 0 25 0 10 0 875654082 889364480 17188 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16014] ppid=15993 vsize=868520 CPUtime=0
/proc/16006/task/16014/stat : 16014 (java) S 15993 15992 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875654082 889364480 17188 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16015] ppid=15993 vsize=868520 CPUtime=0
/proc/16006/task/16015/stat : 16015 (java) S 15993 15992 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 10 0 875654082 889364480 17188 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.45
Current children cumulated vsize (KiB) 873672

[startup+3.10861 s]
/proc/loadavg: 1.18 1.10 1.07 2/57 16015
/proc/meminfo: memFree=527500/1048576 swapFree=2078752/2097144
[pid=15992] ppid=15991 vsize=2572 CPUtime=0
/proc/15992/stat : 15992 (p2cudf-paranoid) S 15991 15992 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 23 0 1 0 875654073 2633728 273 1283457024 134512640 135304128 4292439984 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15992/statm: 643 273 233 194 0 29 0
[pid=15993] ppid=15992 vsize=2580 CPUtime=0.02
/proc/15993/stat : 15993 (p2cudf) S 15992 15992 2059 34821 2220 4202496 392 2997 0 1 0 0 2 0 25 0 1 0 875654073 2641920 283 1283457024 134512640 135304128 4292122480 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15993/statm: 645 283 241 194 0 31 0
[pid=16006] ppid=15993 vsize=868520 CPUtime=2.92
/proc/16006/stat : 16006 (java) S 15993 15992 2059 34821 2220 4202496 70808 0 1 0 261 31 0 0 25 0 10 0 875654077 889364480 68575 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/16006/statm: 217130 68575 1743 10 0 214220 0
[pid=16006/tid=16007] ppid=15993 vsize=868520 CPUtime=1.79
/proc/16006/task/16007/stat : 16007 (java) R 15993 15992 2059 34821 2220 4202560 50245 0 1 0 157 22 0 0 25 0 10 0 875654078 889364480 68575 1283457024 134512640 134550932 4293689232 18446744073709551615 4095727429 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=16006/tid=16008] ppid=15993 vsize=868520 CPUtime=0.29
/proc/16006/task/16008/stat : 16008 (java) S 15993 15992 2059 34821 2220 4202560 13857 0 0 0 25 4 0 0 16 0 10 0 875654079 889364480 68575 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 0 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16009] ppid=15993 vsize=868520 CPUtime=0
/proc/16006/task/16009/stat : 16009 (java) S 15993 15992 2059 34821 2220 4202560 10 0 0 0 0 0 0 0 18 0 10 0 875654080 889364480 68575 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16010] ppid=15993 vsize=868520 CPUtime=0
/proc/16006/task/16010/stat : 16010 (java) S 15993 15992 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 18 0 10 0 875654080 889364480 68575 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16011] ppid=15993 vsize=868520 CPUtime=0
/proc/16006/task/16011/stat : 16011 (java) S 15993 15992 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875654082 889364480 68575 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16012] ppid=15993 vsize=868520 CPUtime=0.39
/proc/16006/task/16012/stat : 16012 (java) S 15993 15992 2059 34821 2220 4202560 2756 0 0 0 37 2 0 0 18 0 10 0 875654082 889364480 68575 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16013] ppid=15993 vsize=868520 CPUtime=0.41
/proc/16006/task/16013/stat : 16013 (java) S 15993 15992 2059 34821 2220 4202560 2839 0 0 0 41 0 0 0 25 0 10 0 875654082 889364480 68575 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16014] ppid=15993 vsize=868520 CPUtime=0
/proc/16006/task/16014/stat : 16014 (java) S 15993 15992 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875654082 889364480 68575 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16015] ppid=15993 vsize=868520 CPUtime=0
/proc/16006/task/16015/stat : 16015 (java) S 15993 15992 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 10 0 875654082 889364480 68575 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 2.94
Current children cumulated vsize (KiB) 873672

[startup+6.30947 s]
/proc/loadavg: 1.18 1.10 1.07 3/58 16016
/proc/meminfo: memFree=347720/1048576 swapFree=2078752/2097144
[pid=15992] ppid=15991 vsize=2572 CPUtime=0
/proc/15992/stat : 15992 (p2cudf-paranoid) S 15991 15992 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 23 0 1 0 875654073 2633728 273 1283457024 134512640 135304128 4292439984 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15992/statm: 643 273 233 194 0 29 0
[pid=15993] ppid=15992 vsize=2580 CPUtime=0.02
/proc/15993/stat : 15993 (p2cudf) S 15992 15992 2059 34821 2220 4202496 392 2997 0 1 0 0 2 0 25 0 1 0 875654073 2641920 283 1283457024 134512640 135304128 4292122480 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15993/statm: 645 283 241 194 0 31 0
[pid=16006] ppid=15993 vsize=872068 CPUtime=6.09
/proc/16006/stat : 16006 (java) S 15993 15992 2059 34821 2220 4202496 93132 0 1 0 567 42 0 0 25 0 11 0 875654077 892997632 88808 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/16006/statm: 218017 88808 1774 10 0 215107 0
[pid=16006/tid=16007] ppid=15993 vsize=872068 CPUtime=2.99
/proc/16006/task/16007/stat : 16007 (java) R 15993 15992 2059 34821 2220 4202560 50448 0 1 0 276 23 0 0 25 0 11 0 875654078 892997632 88808 1283457024 134512640 134550932 4293689232 18446744073709551615 4096636938 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=16006/tid=16008] ppid=15993 vsize=872068 CPUtime=0.75
/proc/16006/task/16008/stat : 16008 (java) S 15993 15992 2059 34821 2220 4202560 32859 0 0 0 61 14 0 0 16 0 11 0 875654079 892997632 88808 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 0 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16009] ppid=15993 vsize=872068 CPUtime=0
/proc/16006/task/16009/stat : 16009 (java) S 15993 15992 2059 34821 2220 4202560 10 0 0 0 0 0 0 0 18 0 11 0 875654080 892997632 88808 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16010] ppid=15993 vsize=872068 CPUtime=0
/proc/16006/task/16010/stat : 16010 (java) S 15993 15992 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 18 0 11 0 875654080 892997632 88808 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16011] ppid=15993 vsize=872068 CPUtime=0
/proc/16006/task/16011/stat : 16011 (java) S 15993 15992 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 875654082 892997632 88808 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16012] ppid=15993 vsize=872068 CPUtime=1.9
/proc/16006/task/16012/stat : 16012 (java) S 15993 15992 2059 34821 2220 4202560 5871 0 0 0 187 3 0 0 15 0 11 0 875654082 892997632 88808 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16013] ppid=15993 vsize=872068 CPUtime=0.41
/proc/16006/task/16013/stat : 16013 (java) S 15993 15992 2059 34821 2220 4202560 2839 0 0 0 41 0 0 0 25 0 11 0 875654082 892997632 88808 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16014] ppid=15993 vsize=872068 CPUtime=0
/proc/16006/task/16014/stat : 16014 (java) S 15993 15992 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 875654082 892997632 88808 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16015] ppid=15993 vsize=872068 CPUtime=0
/proc/16006/task/16015/stat : 16015 (java) R 15993 15992 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 11 0 875654082 892997632 88808 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=16006/tid=16016] ppid=15993 vsize=872068 CPUtime=0
/proc/16006/task/16016/stat : 16016 (java) S 15993 15992 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 11 0 875654665 892997632 88808 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.11
Current children cumulated vsize (KiB) 877220

[startup+12.7118 s]
/proc/loadavg: 1.38 1.14 1.08 4/58 16036
/proc/meminfo: memFree=349580/1048576 swapFree=2078752/2097144
[pid=15992] ppid=15991 vsize=2572 CPUtime=0
/proc/15992/stat : 15992 (p2cudf-paranoid) S 15991 15992 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 23 0 1 0 875654073 2633728 273 1283457024 134512640 135304128 4292439984 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15992/statm: 643 273 233 194 0 29 0
[pid=15993] ppid=15992 vsize=2580 CPUtime=0.02
/proc/15993/stat : 15993 (p2cudf) S 15992 15992 2059 34821 2220 4202496 392 2997 0 1 0 0 2 0 25 0 1 0 875654073 2641920 283 1283457024 134512640 135304128 4292122480 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15993/statm: 645 283 241 194 0 31 0
[pid=16006] ppid=15993 vsize=870492 CPUtime=12.49
/proc/16006/stat : 16006 (java) S 15993 15992 2059 34821 2220 4202496 102978 0 1 0 1204 45 0 0 25 0 11 0 875654077 891383808 98035 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/16006/statm: 217623 98035 1793 10 0 214713 0
[pid=16006/tid=16007] ppid=15993 vsize=870492 CPUtime=8.22
/proc/16006/task/16007/stat : 16007 (java) R 15993 15992 2059 34821 2220 4202560 50456 0 1 0 798 24 0 0 25 0 11 0 875654078 891383808 98035 1283457024 134512640 134550932 4293689232 18446744073709551615 4096662537 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=16006/tid=16008] ppid=15993 vsize=870492 CPUtime=1.4
/proc/16006/task/16008/stat : 16008 (java) S 15993 15992 2059 34821 2220 4202560 42632 0 0 0 124 16 0 0 16 0 11 0 875654079 891383808 98035 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 0 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16009] ppid=15993 vsize=870492 CPUtime=0
/proc/16006/task/16009/stat : 16009 (java) S 15993 15992 2059 34821 2220 4202560 10 0 0 0 0 0 0 0 18 0 11 0 875654080 891383808 98035 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16010] ppid=15993 vsize=870492 CPUtime=0
/proc/16006/task/16010/stat : 16010 (java) S 15993 15992 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 18 0 11 0 875654080 891383808 98035 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16011] ppid=15993 vsize=870492 CPUtime=0
/proc/16006/task/16011/stat : 16011 (java) S 15993 15992 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 875654082 891383808 98035 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16012] ppid=15993 vsize=870492 CPUtime=2.44
/proc/16006/task/16012/stat : 16012 (java) S 15993 15992 2059 34821 2220 4202560 5924 0 0 0 240 4 0 0 15 0 11 0 875654082 891383808 98035 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16013] ppid=15993 vsize=870492 CPUtime=0.41
/proc/16006/task/16013/stat : 16013 (java) S 15993 15992 2059 34821 2220 4202560 2839 0 0 0 41 0 0 0 25 0 11 0 875654082 891383808 98035 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16014] ppid=15993 vsize=870492 CPUtime=0
/proc/16006/task/16014/stat : 16014 (java) S 15993 15992 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 875654082 891383808 98035 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16015] ppid=15993 vsize=870492 CPUtime=0
/proc/16006/task/16015/stat : 16015 (java) S 15993 15992 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 11 0 875654082 891383808 98035 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 12.51
Current children cumulated vsize (KiB) 875644

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

[startup+13.2119 s]
/proc/loadavg: 1.38 1.14 1.08 2/58 16037
/proc/meminfo: memFree=310892/1048576 swapFree=2078752/2097144
[pid=15992] ppid=15991 vsize=2572 CPUtime=0
/proc/15992/stat : 15992 (p2cudf-paranoid) S 15991 15992 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 23 0 1 0 875654073 2633728 273 1283457024 134512640 135304128 4292439984 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15992/statm: 643 273 233 194 0 29 0
[pid=15993] ppid=15992 vsize=2580 CPUtime=0.02
/proc/15993/stat : 15993 (p2cudf) S 15992 15992 2059 34821 2220 4202496 392 2997 0 1 0 0 2 0 25 0 1 0 875654073 2641920 283 1283457024 134512640 135304128 4292122480 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15993/statm: 645 283 241 194 0 31 0
[pid=16006] ppid=15993 vsize=870492 CPUtime=12.99
/proc/16006/stat : 16006 (java) S 15993 15992 2059 34821 2220 4202496 102978 0 1 0 1254 45 0 0 25 0 11 0 875654077 891383808 98035 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/16006/statm: 217623 98035 1793 10 0 214713 0
[pid=16006/tid=16007] ppid=15993 vsize=870492 CPUtime=8.7
/proc/16006/task/16007/stat : 16007 (java) R 15993 15992 2059 34821 2220 4202560 50456 0 1 0 846 24 0 0 25 0 11 0 875654078 891383808 98035 1283457024 134512640 134550932 4293689232 18446744073709551615 4096639892 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=16006/tid=16008] ppid=15993 vsize=870492 CPUtime=1.4
/proc/16006/task/16008/stat : 16008 (java) S 15993 15992 2059 34821 2220 4202560 42632 0 0 0 124 16 0 0 16 0 11 0 875654079 891383808 98035 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 0 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16009] ppid=15993 vsize=870492 CPUtime=0
/proc/16006/task/16009/stat : 16009 (java) S 15993 15992 2059 34821 2220 4202560 10 0 0 0 0 0 0 0 18 0 11 0 875654080 891383808 98035 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16010] ppid=15993 vsize=870492 CPUtime=0
/proc/16006/task/16010/stat : 16010 (java) S 15993 15992 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 18 0 11 0 875654080 891383808 98035 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16011] ppid=15993 vsize=870492 CPUtime=0
/proc/16006/task/16011/stat : 16011 (java) S 15993 15992 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 875654082 891383808 98035 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16012] ppid=15993 vsize=870492 CPUtime=2.46
/proc/16006/task/16012/stat : 16012 (java) S 15993 15992 2059 34821 2220 4202560 5924 0 0 0 242 4 0 0 15 0 11 0 875654082 891383808 98035 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16013] ppid=15993 vsize=870492 CPUtime=0.41
/proc/16006/task/16013/stat : 16013 (java) S 15993 15992 2059 34821 2220 4202560 2839 0 0 0 41 0 0 0 25 0 11 0 875654082 891383808 98035 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16014] ppid=15993 vsize=870492 CPUtime=0
/proc/16006/task/16014/stat : 16014 (java) S 15993 15992 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 875654082 891383808 98035 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16015] ppid=15993 vsize=870492 CPUtime=0
/proc/16006/task/16015/stat : 16015 (java) S 15993 15992 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 11 0 875654082 891383808 98035 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 13.01
Current children cumulated vsize (KiB) 875644

[startup+13.6049 s]
/proc/loadavg: 1.38 1.14 1.08 2/58 16037
/proc/meminfo: memFree=310892/1048576 swapFree=2078752/2097144
[pid=15992] ppid=15991 vsize=2572 CPUtime=0
/proc/15992/stat : 15992 (p2cudf-paranoid) S 15991 15992 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 23 0 1 0 875654073 2633728 273 1283457024 134512640 135304128 4292439984 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15992/statm: 643 273 233 194 0 29 0
[pid=15993] ppid=15992 vsize=2580 CPUtime=0.02
/proc/15993/stat : 15993 (p2cudf) S 15992 15992 2059 34821 2220 4202496 392 2997 0 1 0 0 2 0 25 0 1 0 875654073 2641920 283 1283457024 134512640 135304128 4292122480 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15993/statm: 645 283 241 194 0 31 0
[pid=16006] ppid=15993 vsize=870492 CPUtime=13.2
/proc/16006/stat : 16006 (java) S 15993 15992 2059 34821 2220 4202496 102984 0 1 0 1275 45 0 0 25 0 11 0 875654077 891383808 98041 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/16006/statm: 217623 98041 1793 10 0 214713 0
[pid=16006/tid=16007] ppid=15993 vsize=870492 CPUtime=8.88
/proc/16006/task/16007/stat : 16007 (java) S 15993 15992 2059 34821 2220 4202560 50462 0 1 0 864 24 0 0 25 0 11 0 875654078 891383808 98041 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16008] ppid=15993 vsize=870492 CPUtime=1.4
/proc/16006/task/16008/stat : 16008 (java) S 15993 15992 2059 34821 2220 4202560 42632 0 0 0 124 16 0 0 16 0 11 0 875654079 891383808 98041 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 0 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16009] ppid=15993 vsize=870492 CPUtime=0
/proc/16006/task/16009/stat : 16009 (java) S 15993 15992 2059 34821 2220 4202560 10 0 0 0 0 0 0 0 18 0 11 0 875654080 891383808 98041 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16010] ppid=15993 vsize=870492 CPUtime=0
/proc/16006/task/16010/stat : 16010 (java) S 15993 15992 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 18 0 11 0 875654080 891383808 98041 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16011] ppid=15993 vsize=870492 CPUtime=0
/proc/16006/task/16011/stat : 16011 (java) S 15993 15992 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 875654082 891383808 98041 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16012] ppid=15993 vsize=870492 CPUtime=2.49
/proc/16006/task/16012/stat : 16012 (java) S 15993 15992 2059 34821 2220 4202560 5924 0 0 0 245 4 0 0 16 0 11 0 875654082 891383808 98041 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16013] ppid=15993 vsize=870492 CPUtime=0.41
/proc/16006/task/16013/stat : 16013 (java) S 15993 15992 2059 34821 2220 4202560 2839 0 0 0 41 0 0 0 25 0 11 0 875654082 891383808 98041 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16014] ppid=15993 vsize=870492 CPUtime=0
/proc/16006/task/16014/stat : 16014 (java) S 15993 15992 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 875654082 891383808 98041 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16015] ppid=15993 vsize=870492 CPUtime=0
/proc/16006/task/16015/stat : 16015 (java) S 15993 15992 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 11 0 875654082 891383808 98041 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 13.22
Current children cumulated vsize (KiB) 875644

[startup+14.005 s]
/proc/loadavg: 1.38 1.14 1.08 1/58 16041
/proc/meminfo: memFree=310892/1048576 swapFree=2078752/2097144
[pid=15992] ppid=15991 vsize=2572 CPUtime=0
/proc/15992/stat : 15992 (p2cudf-paranoid) S 15991 15992 2059 34821 2220 4202496 377 0 0 0 0 0 0 0 23 0 1 0 875654073 2633728 273 1283457024 134512640 135304128 4292439984 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15992/statm: 643 273 233 194 0 29 0
[pid=15993] ppid=15992 vsize=2580 CPUtime=0.02
/proc/15993/stat : 15993 (p2cudf) S 15992 15992 2059 34821 2220 4202496 392 2997 0 1 0 0 2 0 25 0 1 0 875654073 2641920 283 1283457024 134512640 135304128 4292122480 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15993/statm: 645 283 241 194 0 31 0
[pid=16006] ppid=15993 vsize=870492 CPUtime=13.24
/proc/16006/stat : 16006 (java) S 15993 15992 2059 34821 2220 4202496 102985 0 1 0 1278 46 0 0 25 0 10 0 875654077 891383808 98042 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/16006/statm: 217623 98042 1793 10 0 214713 0
[pid=16006/tid=16007] ppid=15993 vsize=870492 CPUtime=8.88
/proc/16006/task/16007/stat : 16007 (java) S 15993 15992 2059 34821 2220 4202560 50462 0 1 0 864 24 0 0 20 0 10 0 875654078 891383808 98042 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16008] ppid=15993 vsize=870492 CPUtime=1.4
/proc/16006/task/16008/stat : 16008 (java) S 15993 15992 2059 34821 2220 4202560 42632 0 0 0 124 16 0 0 16 0 10 0 875654079 891383808 98042 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 0 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16009] ppid=15993 vsize=870492 CPUtime=0
/proc/16006/task/16009/stat : 16009 (java) S 15993 15992 2059 34821 2220 4202560 10 0 0 0 0 0 0 0 18 0 10 0 875654080 891383808 98042 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16010] ppid=15993 vsize=870492 CPUtime=0
/proc/16006/task/16010/stat : 16010 (java) S 15993 15992 2059 34821 2220 4202560 6 0 0 0 0 0 0 0 18 0 10 0 875654080 891383808 98042 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16011] ppid=15993 vsize=870492 CPUtime=0
/proc/16006/task/16011/stat : 16011 (java) S 15993 15992 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875654082 891383808 98042 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16012] ppid=15993 vsize=870492 CPUtime=2.49
/proc/16006/task/16012/stat : 16012 (java) S 15993 15992 2059 34821 2220 4202560 5924 0 0 0 245 4 0 0 16 0 10 0 875654082 891383808 98042 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16013] ppid=15993 vsize=870492 CPUtime=0.41
/proc/16006/task/16013/stat : 16013 (java) S 15993 15992 2059 34821 2220 4202560 2839 0 0 0 41 0 0 0 25 0 10 0 875654082 891383808 98042 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16014] ppid=15993 vsize=870492 CPUtime=0
/proc/16006/task/16014/stat : 16014 (java) S 15993 15992 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875654082 891383808 98042 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
[pid=16006/tid=16015] ppid=15993 vsize=870492 CPUtime=0
/proc/16006/task/16015/stat : 16015 (java) S 15993 15992 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 15 0 10 0 875654082 891383808 98042 1283457024 134512640 134550932 4293689232 18446744073709551615 4294960130 0 4 0 16800975 18446612132549436544 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 13.26
Current children cumulated vsize (KiB) 875644

Child status: 0
Real time (s): 14.0643
CPU time (s): 13.3048
CPU user time (s): 12.8168
CPU system time (s): 0.48803
CPU usage (%): 94.5998
Max. virtual memory (cumulated for all children) (KiB): 878300

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 12.8168
system time used= 0.48803
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 106777
page faults= 2
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 1593
involuntary context switches= 1616

runsolver used 0 second user time and 0.024001 second system time

The end