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/201108241238/packup2mp4tr-0.6/56e31304-c17a-11df-b070-00163e3d3b7c.cudf.dudf-real.log.runsolver ./packup2mp4tr-0.6 /home/misc2010/data/2011/dudf-real//56e31304-c17a-11df-b070-00163e3d3b7c.cudf /home/misc2010/tmp/201108241238/packup2mp4tr-0.6/56e31304-c17a-11df-b070-00163e3d3b7c.cudf.dudf-real.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.01 1.12 1.12 4/34 25874
/proc/meminfo: memFree=346680/1048576 swapFree=0/0
[pid=25873] ppid=25872 vsize=2572 CPUtime=0
/proc/25873/stat : 25873 (packup2mp4tr-0.) S 25872 25873 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 4797911 2633728 275 1283457024 134512640 135304128 4291430032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/25873/statm: 643 275 233 194 0 30 0
[pid=25874] ppid=25873 vsize=3848 CPUtime=0
/proc/25874/stat : 25874 (packup) R 25873 25873 1511 34817 1511 4202496 455 0 0 0 0 0 0 0 25 0 1 0 4797911 3940352 384 1283457024 134512640 134752139 4288848880 18446744073709551615 4157679864 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/25874/statm: 962 384 286 59 0 126 0

[startup+0.168185 s]
/proc/loadavg: 1.01 1.12 1.12 4/34 25874
/proc/meminfo: memFree=346680/1048576 swapFree=0/0
[pid=25873] ppid=25872 vsize=2572 CPUtime=0
/proc/25873/stat : 25873 (packup2mp4tr-0.) S 25872 25873 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 4797911 2633728 275 1283457024 134512640 135304128 4291430032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/25873/statm: 643 275 233 194 0 30 0
[pid=25874] ppid=25873 vsize=9352 CPUtime=0.16
/proc/25874/stat : 25874 (packup) R 25873 25873 1511 34817 1511 4202496 1823 0 0 0 16 0 0 0 25 0 1 0 4797911 9576448 1752 1283457024 134512640 134752139 4288848880 18446744073709551615 134681663 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/25874/statm: 2338 1752 286 59 0 1502 0
Current children cumulated CPU time (s) 0.16
Current children cumulated vsize (KiB) 11924

[startup+0.208191 s]
/proc/loadavg: 1.01 1.12 1.12 4/34 25874
/proc/meminfo: memFree=346680/1048576 swapFree=0/0
[pid=25873] ppid=25872 vsize=2572 CPUtime=0
/proc/25873/stat : 25873 (packup2mp4tr-0.) S 25872 25873 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 4797911 2633728 275 1283457024 134512640 135304128 4291430032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/25873/statm: 643 275 233 194 0 30 0
[pid=25874] ppid=25873 vsize=10540 CPUtime=0.2
/proc/25874/stat : 25874 (packup) R 25873 25873 1511 34817 1511 4202496 2115 0 0 0 20 0 0 0 25 0 1 0 4797911 10792960 2044 1283457024 134512640 134752139 4288848880 18446744073709551615 134681674 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/25874/statm: 2635 2044 286 59 0 1799 0
Current children cumulated CPU time (s) 0.2
Current children cumulated vsize (KiB) 13112

[startup+0.30822 s]
/proc/loadavg: 1.01 1.12 1.12 4/34 25874
/proc/meminfo: memFree=346680/1048576 swapFree=0/0
[pid=25873] ppid=25872 vsize=2572 CPUtime=0
/proc/25873/stat : 25873 (packup2mp4tr-0.) S 25872 25873 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 4797911 2633728 275 1283457024 134512640 135304128 4291430032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/25873/statm: 643 275 233 194 0 30 0
[pid=25874] ppid=25873 vsize=13244 CPUtime=0.3
/proc/25874/stat : 25874 (packup) R 25873 25873 1511 34817 1511 4202496 2811 0 0 0 29 1 0 0 25 0 1 0 4797911 13561856 2740 1283457024 134512640 134752139 4288848880 18446744073709551615 4157711789 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/25874/statm: 3311 2740 286 59 0 2475 0
Current children cumulated CPU time (s) 0.3
Current children cumulated vsize (KiB) 15816

[startup+0.708308 s]
/proc/loadavg: 1.01 1.12 1.12 4/34 25874
/proc/meminfo: memFree=346680/1048576 swapFree=0/0
[pid=25873] ppid=25872 vsize=2572 CPUtime=0
/proc/25873/stat : 25873 (packup2mp4tr-0.) S 25872 25873 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 4797911 2633728 275 1283457024 134512640 135304128 4291430032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/25873/statm: 643 275 233 194 0 30 0
[pid=25874] ppid=25873 vsize=23076 CPUtime=0.7
/proc/25874/stat : 25874 (packup) R 25873 25873 1511 34817 1511 4202496 5274 0 0 0 69 1 0 0 25 0 1 0 4797911 23629824 5203 1283457024 134512640 134752139 4288848880 18446744073709551615 4157684644 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/25874/statm: 5769 5203 286 59 0 4933 0
Current children cumulated CPU time (s) 0.7
Current children cumulated vsize (KiB) 25648

[startup+1.50856 s]
/proc/loadavg: 1.01 1.12 1.12 2/35 25875
/proc/meminfo: memFree=314256/1048576 swapFree=0/0
[pid=25873] ppid=25872 vsize=2572 CPUtime=0
/proc/25873/stat : 25873 (packup2mp4tr-0.) S 25872 25873 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 4797911 2633728 275 1283457024 134512640 135304128 4291430032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/25873/statm: 643 275 233 194 0 30 0
[pid=25874] ppid=25873 vsize=44288 CPUtime=1.5
/proc/25874/stat : 25874 (packup) R 25873 25873 1511 34817 1511 4202496 10704 0 0 0 136 14 0 0 25 0 1 0 4797911 45350912 10353 1283457024 134512640 134752139 4288848880 18446744073709551615 4294960130 0 65536 18950 8192 0 0 0 17 0 0 0 0
/proc/25874/statm: 11072 10353 324 59 0 10236 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 46860

[startup+3.10886 s]
/proc/loadavg: 1.01 1.12 1.12 2/37 25877
/proc/meminfo: memFree=289672/1048576 swapFree=0/0
[pid=25873] ppid=25872 vsize=2572 CPUtime=0
/proc/25873/stat : 25873 (packup2mp4tr-0.) S 25872 25873 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 4797911 2633728 275 1283457024 134512640 135304128 4291430032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/25873/statm: 643 275 233 194 0 30 0
[pid=25874] ppid=25873 vsize=44288 CPUtime=1.5
/proc/25874/stat : 25874 (packup) S 25873 25873 1511 34817 1511 4202496 10706 0 0 0 136 14 0 0 25 0 1 0 4797911 45350912 10354 1283457024 134512640 134752139 4288848880 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/25874/statm: 11072 10354 325 59 0 10236 0
[pid=25876] ppid=25874 vsize=1668 CPUtime=0
/proc/25876/stat : 25876 (sh) S 25874 25873 1511 34817 1511 4202496 145 0 0 0 0 0 0 0 25 0 1 0 4798061 1708032 123 1283457024 134512640 134593992 4293075152 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/25876/statm: 417 123 108 20 0 44 0
[pid=25877] ppid=25876 vsize=40008 CPUtime=1.6
/proc/25877/stat : 25877 (minisatp_32) R 25876 25873 1511 34817 1511 4202496 13324 0 0 0 142 18 0 0 25 0 1 0 4798062 40968192 9353 1283457024 134512640 135413687 4293712272 18446744073709551615 134686270 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/25877/statm: 10002 9353 106 220 0 9780 0
Current children cumulated CPU time (s) 3.1
Current children cumulated vsize (KiB) 88536

[startup+6.30948 s]
/proc/loadavg: 1.01 1.12 1.12 2/37 25879
/proc/meminfo: memFree=267980/1048576 swapFree=0/0
[pid=25873] ppid=25872 vsize=2572 CPUtime=0
/proc/25873/stat : 25873 (packup2mp4tr-0.) S 25872 25873 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 4797911 2633728 275 1283457024 134512640 135304128 4291430032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/25873/statm: 643 275 233 194 0 30 0
[pid=25874] ppid=25873 vsize=44292 CPUtime=4.16
/proc/25874/stat : 25874 (packup) S 25873 25873 1511 34817 1511 4202496 10785 16045 0 0 152 25 220 19 18 0 1 0 4797911 45355008 10370 1283457024 134512640 134752139 4288848880 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/25874/statm: 11073 10370 333 59 0 10237 0
[pid=25878] ppid=25874 vsize=1668 CPUtime=0
/proc/25878/stat : 25878 (sh) S 25874 25873 1511 34817 1511 4202496 145 0 0 0 0 0 0 0 18 0 1 0 4798329 1708032 123 1283457024 134512640 134593992 4289043712 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/25878/statm: 417 123 108 20 0 44 0
[pid=25879] ppid=25878 vsize=57644 CPUtime=2.12
/proc/25879/stat : 25879 (minisatp_32) R 25878 25873 1511 34817 1511 4202496 18633 0 0 0 196 16 0 0 25 0 1 0 4798329 59027456 12777 1283457024 134512640 135413687 4290854608 18446744073709551615 134649535 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/25879/statm: 14411 12777 107 220 0 14189 0
Current children cumulated CPU time (s) 6.28
Current children cumulated vsize (KiB) 106176

[startup+12.7108 s]
/proc/loadavg: 1.01 1.11 1.12 2/37 25883
/proc/meminfo: memFree=286704/1048576 swapFree=0/0
[pid=25873] ppid=25872 vsize=2572 CPUtime=0
/proc/25873/stat : 25873 (packup2mp4tr-0.) S 25872 25873 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 4797911 2633728 275 1283457024 134512640 135304128 4291430032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/25873/statm: 643 275 233 194 0 30 0
[pid=25874] ppid=25873 vsize=44300 CPUtime=11.28
/proc/25874/stat : 25874 (packup) S 25873 25873 1511 34817 1511 4202496 10939 69390 0 0 180 54 831 63 18 0 1 0 4797911 45363200 10379 1283457024 134512640 134752139 4288848880 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/25874/statm: 11075 10379 333 59 0 10239 0
[pid=25882] ppid=25874 vsize=1676 CPUtime=0
/proc/25882/stat : 25882 (sh) S 25874 25873 1511 34817 1511 4202496 147 0 0 0 0 0 0 0 18 0 1 0 4799041 1716224 124 1283457024 134512640 134593992 4287874016 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/25882/statm: 419 124 108 20 0 46 0
[pid=25883] ppid=25882 vsize=51752 CPUtime=1.4
/proc/25883/stat : 25883 (minisatp_32) R 25882 25873 1511 34817 1511 4202496 13564 0 0 0 131 9 0 0 25 0 1 0 4799042 52994048 11428 1283457024 134512640 135413687 4290164272 18446744073709551615 134996974 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/25883/statm: 12938 11428 90 220 0 12716 0
Current children cumulated CPU time (s) 12.68
Current children cumulated vsize (KiB) 100300

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

[startup+12.8108 s]
/proc/loadavg: 1.01 1.11 1.12 2/37 25883
/proc/meminfo: memFree=286704/1048576 swapFree=0/0
[pid=25873] ppid=25872 vsize=2572 CPUtime=0
/proc/25873/stat : 25873 (packup2mp4tr-0.) S 25872 25873 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 4797911 2633728 275 1283457024 134512640 135304128 4291430032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/25873/statm: 643 275 233 194 0 30 0
[pid=25874] ppid=25873 vsize=44300 CPUtime=11.28
/proc/25874/stat : 25874 (packup) S 25873 25873 1511 34817 1511 4202496 10939 69390 0 0 180 54 831 63 18 0 1 0 4797911 45363200 10379 1283457024 134512640 134752139 4288848880 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/25874/statm: 11075 10379 333 59 0 10239 0
[pid=25882] ppid=25874 vsize=1676 CPUtime=0
/proc/25882/stat : 25882 (sh) S 25874 25873 1511 34817 1511 4202496 147 0 0 0 0 0 0 0 18 0 1 0 4799041 1716224 124 1283457024 134512640 134593992 4287874016 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/25882/statm: 419 124 108 20 0 46 0
[pid=25883] ppid=25882 vsize=61764 CPUtime=1.5
/proc/25883/stat : 25883 (minisatp_32) R 25882 25873 1511 34817 1511 4202496 17376 0 0 0 138 12 0 0 25 0 1 0 4799042 63246336 13935 1283457024 134512640 135413687 4290164272 18446744073709551615 134656321 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/25883/statm: 15441 13935 90 220 0 15219 0
Current children cumulated CPU time (s) 12.78
Current children cumulated vsize (KiB) 110312

[startup+16.0118 s]
/proc/loadavg: 1.01 1.11 1.12 2/37 25883
/proc/meminfo: memFree=199284/1048576 swapFree=0/0
[pid=25873] ppid=25872 vsize=2572 CPUtime=0
/proc/25873/stat : 25873 (packup2mp4tr-0.) S 25872 25873 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 4797911 2633728 275 1283457024 134512640 135304128 4291430032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/25873/statm: 643 275 233 194 0 30 0
[pid=25874] ppid=25873 vsize=44300 CPUtime=11.28
/proc/25874/stat : 25874 (packup) S 25873 25873 1511 34817 1511 4202496 10939 69390 0 0 180 54 831 63 18 0 1 0 4797911 45363200 10379 1283457024 134512640 134752139 4288848880 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/25874/statm: 11075 10379 333 59 0 10239 0
[pid=25882] ppid=25874 vsize=1676 CPUtime=0
/proc/25882/stat : 25882 (sh) S 25874 25873 1511 34817 1511 4202496 147 0 0 0 0 0 0 0 18 0 1 0 4799041 1716224 124 1283457024 134512640 134593992 4287874016 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/25882/statm: 419 124 108 20 0 46 0
[pid=25883] ppid=25882 vsize=125968 CPUtime=4.7
/proc/25883/stat : 25883 (minisatp_32) R 25882 25873 1511 34817 1511 4202496 44051 0 0 0 442 28 0 0 25 0 1 0 4799042 128991232 28321 1283457024 134512640 135413687 4290164272 18446744073709551615 134698776 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/25883/statm: 31492 28321 107 220 0 31270 0
Current children cumulated CPU time (s) 15.98
Current children cumulated vsize (KiB) 174516

[startup+16.812 s]
/proc/loadavg: 1.01 1.11 1.12 2/37 25883
/proc/meminfo: memFree=175972/1048576 swapFree=0/0
[pid=25873] ppid=25872 vsize=2572 CPUtime=0
/proc/25873/stat : 25873 (packup2mp4tr-0.) S 25872 25873 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 4797911 2633728 275 1283457024 134512640 135304128 4291430032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/25873/statm: 643 275 233 194 0 30 0
[pid=25874] ppid=25873 vsize=44300 CPUtime=11.28
/proc/25874/stat : 25874 (packup) S 25873 25873 1511 34817 1511 4202496 10939 69390 0 0 180 54 831 63 18 0 1 0 4797911 45363200 10379 1283457024 134512640 134752139 4288848880 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/25874/statm: 11075 10379 333 59 0 10239 0
[pid=25882] ppid=25874 vsize=1676 CPUtime=0
/proc/25882/stat : 25882 (sh) S 25874 25873 1511 34817 1511 4202496 147 0 0 0 0 0 0 0 18 0 1 0 4799041 1716224 124 1283457024 134512640 134593992 4287874016 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/25882/statm: 419 124 108 20 0 46 0
[pid=25883] ppid=25882 vsize=165432 CPUtime=5.5
/proc/25883/stat : 25883 (minisatp_32) R 25882 25873 1511 34817 1511 4202496 53286 0 0 0 516 34 0 0 25 0 1 0 4799042 169402368 35471 1283457024 134512640 135413687 4290164272 18446744073709551615 134686559 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/25883/statm: 41358 35471 107 220 0 41136 0
Current children cumulated CPU time (s) 16.78
Current children cumulated vsize (KiB) 213980

[startup+17.2121 s]
/proc/loadavg: 1.01 1.11 1.12 2/37 25883
/proc/meminfo: memFree=175972/1048576 swapFree=0/0
[pid=25873] ppid=25872 vsize=2572 CPUtime=0
/proc/25873/stat : 25873 (packup2mp4tr-0.) S 25872 25873 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 4797911 2633728 275 1283457024 134512640 135304128 4291430032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/25873/statm: 643 275 233 194 0 30 0
[pid=25874] ppid=25873 vsize=44300 CPUtime=11.28
/proc/25874/stat : 25874 (packup) S 25873 25873 1511 34817 1511 4202496 10939 69390 0 0 180 54 831 63 18 0 1 0 4797911 45363200 10379 1283457024 134512640 134752139 4288848880 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/25874/statm: 11075 10379 333 59 0 10239 0
[pid=25882] ppid=25874 vsize=1676 CPUtime=0
/proc/25882/stat : 25882 (sh) S 25874 25873 1511 34817 1511 4202496 147 0 0 0 0 0 0 0 18 0 1 0 4799041 1716224 124 1283457024 134512640 134593992 4287874016 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/25882/statm: 419 124 108 20 0 46 0
[pid=25883] ppid=25882 vsize=173228 CPUtime=5.9
/proc/25883/stat : 25883 (minisatp_32) R 25882 25873 1511 34817 1511 4202496 55032 0 0 0 556 34 0 0 25 0 1 0 4799042 177385472 37151 1283457024 134512640 135413687 4290164272 18446744073709551615 134696952 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/25883/statm: 43307 37151 107 220 0 43085 0
Current children cumulated CPU time (s) 17.18
Current children cumulated vsize (KiB) 221776

[startup+17.6122 s]
/proc/loadavg: 1.01 1.11 1.12 2/37 25883
/proc/meminfo: memFree=164936/1048576 swapFree=0/0
[pid=25873] ppid=25872 vsize=2572 CPUtime=0
/proc/25873/stat : 25873 (packup2mp4tr-0.) S 25872 25873 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 4797911 2633728 275 1283457024 134512640 135304128 4291430032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/25873/statm: 643 275 233 194 0 30 0
[pid=25874] ppid=25873 vsize=44300 CPUtime=11.28
/proc/25874/stat : 25874 (packup) S 25873 25873 1511 34817 1511 4202496 10939 69390 0 0 180 54 831 63 18 0 1 0 4797911 45363200 10379 1283457024 134512640 134752139 4288848880 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/25874/statm: 11075 10379 333 59 0 10239 0
[pid=25882] ppid=25874 vsize=1676 CPUtime=0
/proc/25882/stat : 25882 (sh) S 25874 25873 1511 34817 1511 4202496 147 0 0 0 0 0 0 0 18 0 1 0 4799041 1716224 124 1283457024 134512640 134593992 4287874016 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/25882/statm: 419 124 108 20 0 46 0
[pid=25883] ppid=25882 vsize=160164 CPUtime=6.3
/proc/25883/stat : 25883 (minisatp_32) R 25882 25873 1511 34817 1511 4202496 56805 0 0 0 594 36 0 0 25 0 1 0 4799042 164007936 34493 1283457024 134512640 135413687 4290164272 18446744073709551615 134597339 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/25883/statm: 40041 34493 117 220 0 39819 0
Current children cumulated CPU time (s) 17.58
Current children cumulated vsize (KiB) 208712

[startup+17.704 s]
/proc/loadavg: 1.01 1.11 1.12 2/37 25883
/proc/meminfo: memFree=164936/1048576 swapFree=0/0
[pid=25873] ppid=25872 vsize=2572 CPUtime=0
/proc/25873/stat : 25873 (packup2mp4tr-0.) S 25872 25873 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 4797911 2633728 275 1283457024 134512640 135304128 4291430032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/25873/statm: 643 275 233 194 0 30 0
[pid=25874] ppid=25873 vsize=43332 CPUtime=17.68
/proc/25874/stat : 25874 (packup) R 25873 25873 1511 34817 1511 4202496 19624 126345 0 0 184 58 1425 101 18 0 1 0 4797911 44371968 10149 1283457024 134512640 134752139 4288848880 18446744073709551615 4157674909 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/25874/statm: 10833 10149 345 59 0 9997 0
Current children cumulated CPU time (s) 17.68
Current children cumulated vsize (KiB) 45904

Child status: 0
Real time (s): 17.7603
CPU time (s): 17.7451
CPU user time (s): 16.141
CPU system time (s): 1.6041
CPU usage (%): 99.9147
Max. virtual memory (cumulated for all children) (KiB): 228852

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 16.141
system time used= 1.6041
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 147193
page faults= 0
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 19
involuntary context switches= 271

runsolver used 0 second user time and 0 second system time

The end