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/rand953.cudf.s-e-l-s-s.log.runsolver ./packup2mp4tr-0.6 /home/misc2010/data/2011/incremental/s-e-l-s-s//rand953.cudf /home/misc2010/tmp/201108241238/packup2mp4tr-0.6/rand953.cudf.s-e-l-s-s.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.00 1.00 1.00 5/36 18933
/proc/meminfo: memFree=566672/1048576 swapFree=0/0
[pid=18932] ppid=18931 vsize=2572 CPUtime=0
/proc/18932/stat : 18932 (packup2mp4tr-0.) S 18931 18932 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 4225434 2633728 274 1283457024 134512640 135304128 4288982128 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/18932/statm: 643 274 233 194 0 30 0
[pid=18933] ppid=18932 vsize=4108 CPUtime=0
/proc/18933/stat : 18933 (packup) R 18932 18932 1511 34817 1511 4202496 509 0 0 0 0 0 0 0 25 0 1 0 4225434 4206592 438 1283457024 134512640 134752139 4289340560 18446744073709551615 134681682 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/18933/statm: 1027 438 286 59 0 191 0

[startup+0.212342 s]
/proc/loadavg: 1.00 1.00 1.00 5/36 18933
/proc/meminfo: memFree=566672/1048576 swapFree=0/0
[pid=18932] ppid=18931 vsize=2572 CPUtime=0
/proc/18932/stat : 18932 (packup2mp4tr-0.) S 18931 18932 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 4225434 2633728 274 1283457024 134512640 135304128 4288982128 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/18932/statm: 643 274 233 194 0 30 0
[pid=18933] ppid=18932 vsize=11576 CPUtime=0.2
/proc/18933/stat : 18933 (packup) R 18932 18932 1511 34817 1511 4202496 2373 0 0 0 19 1 0 0 25 0 1 0 4225434 11853824 2302 1283457024 134512640 134752139 4289340560 18446744073709551615 134643751 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/18933/statm: 2894 2302 286 59 0 2058 0
Current children cumulated CPU time (s) 0.2
Current children cumulated vsize (KiB) 14148

[startup+0.302367 s]
/proc/loadavg: 1.00 1.00 1.00 5/36 18933
/proc/meminfo: memFree=566672/1048576 swapFree=0/0
[pid=18932] ppid=18931 vsize=2572 CPUtime=0
/proc/18932/stat : 18932 (packup2mp4tr-0.) S 18931 18932 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 4225434 2633728 274 1283457024 134512640 135304128 4288982128 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/18932/statm: 643 274 233 194 0 30 0
[pid=18933] ppid=18932 vsize=14304 CPUtime=0.29
/proc/18933/stat : 18933 (packup) R 18932 18932 1511 34817 1511 4202496 3082 0 0 0 28 1 0 0 25 0 1 0 4225434 14647296 3011 1283457024 134512640 134752139 4289340560 18446744073709551615 134681663 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/18933/statm: 3576 3011 286 59 0 2740 0
Current children cumulated CPU time (s) 0.29
Current children cumulated vsize (KiB) 16876

[startup+0.412407 s]
/proc/loadavg: 1.00 1.00 1.00 5/36 18933
/proc/meminfo: memFree=566672/1048576 swapFree=0/0
[pid=18932] ppid=18931 vsize=2572 CPUtime=0
/proc/18932/stat : 18932 (packup2mp4tr-0.) S 18931 18932 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 4225434 2633728 274 1283457024 134512640 135304128 4288982128 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/18932/statm: 643 274 233 194 0 30 0
[pid=18933] ppid=18932 vsize=17604 CPUtime=0.4
/proc/18933/stat : 18933 (packup) R 18932 18932 1511 34817 1511 4202496 3905 0 0 0 38 2 0 0 25 0 1 0 4225434 18026496 3834 1283457024 134512640 134752139 4289340560 18446744073709551615 4157105952 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/18933/statm: 4401 3834 286 59 0 3565 0
Current children cumulated CPU time (s) 0.4
Current children cumulated vsize (KiB) 20176

[startup+0.702476 s]
/proc/loadavg: 1.00 1.00 1.00 5/36 18933
/proc/meminfo: memFree=566672/1048576 swapFree=0/0
[pid=18932] ppid=18931 vsize=2572 CPUtime=0
/proc/18932/stat : 18932 (packup2mp4tr-0.) S 18931 18932 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 4225434 2633728 274 1283457024 134512640 135304128 4288982128 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/18932/statm: 643 274 233 194 0 30 0
[pid=18933] ppid=18932 vsize=25468 CPUtime=0.69
/proc/18933/stat : 18933 (packup) R 18932 18932 1511 34817 1511 4202496 5872 0 0 0 63 6 0 0 25 0 1 0 4225434 26079232 5801 1283457024 134512640 134752139 4289340560 18446744073709551615 134706148 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/18933/statm: 6367 5801 286 59 0 5531 0
Current children cumulated CPU time (s) 0.69
Current children cumulated vsize (KiB) 28040

[startup+1.50271 s]
/proc/loadavg: 1.00 1.00 1.00 2/37 18935
/proc/meminfo: memFree=531816/1048576 swapFree=0/0
[pid=18932] ppid=18931 vsize=2572 CPUtime=0
/proc/18932/stat : 18932 (packup2mp4tr-0.) S 18931 18932 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 4225434 2633728 274 1283457024 134512640 135304128 4288982128 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/18932/statm: 643 274 233 194 0 30 0
[pid=18933] ppid=18932 vsize=50048 CPUtime=1.49
/proc/18933/stat : 18933 (packup) R 18932 18932 1511 34817 1511 4202496 12074 0 0 0 143 6 0 0 25 0 1 0 4225434 51249152 11954 1283457024 134512640 134752139 4289340560 18446744073709551615 4157134255 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/18933/statm: 12512 11954 306 59 0 11676 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 52620

[startup+3.10309 s]
/proc/loadavg: 1.00 1.00 1.00 2/37 18935
/proc/meminfo: memFree=497716/1048576 swapFree=0/0
[pid=18932] ppid=18931 vsize=2572 CPUtime=0
/proc/18932/stat : 18932 (packup2mp4tr-0.) S 18931 18932 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 4225434 2633728 274 1283457024 134512640 135304128 4288982128 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/18932/statm: 643 274 233 194 0 30 0
[pid=18933] ppid=18932 vsize=70732 CPUtime=2.39
/proc/18933/stat : 18933 (packup) S 18932 18932 1511 34817 1511 4202496 17553 0 0 0 200 39 0 0 25 0 1 0 4225434 72429568 16764 1283457024 134512640 134752139 4289340560 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/18933/statm: 17683 16764 325 59 0 16847 0
Current children cumulated CPU time (s) 2.39
Current children cumulated vsize (KiB) 73304
heavy processes:

[startup+6.3047 s]
/proc/loadavg: 1.00 1.00 1.00 2/37 18937
/proc/meminfo: memFree=496980/1048576 swapFree=0/0
[pid=18932] ppid=18931 vsize=2572 CPUtime=0
/proc/18932/stat : 18932 (packup2mp4tr-0.) S 18931 18932 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 4225434 2633728 274 1283457024 134512640 135304128 4288982128 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/18932/statm: 643 274 233 194 0 30 0
[pid=18933] ppid=18932 vsize=70736 CPUtime=5.65
/proc/18933/stat : 18933 (packup) S 18932 18932 1511 34817 1511 4202496 17657 15857 0 0 223 70 236 36 18 0 1 0 4225434 72433664 16783 1283457024 134512640 134752139 4289340560 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/18933/statm: 17684 16783 333 59 0 16848 0
Current children cumulated CPU time (s) 5.65
Current children cumulated vsize (KiB) 73308

[startup+12.7075 s]
/proc/loadavg: 1.00 1.00 1.00 2/39 18940
/proc/meminfo: memFree=333640/1048576 swapFree=0/0
[pid=18932] ppid=18931 vsize=2572 CPUtime=0
/proc/18932/stat : 18932 (packup2mp4tr-0.) S 18931 18932 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 4225434 2633728 274 1283457024 134512640 135304128 4288982128 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/18932/statm: 643 274 233 194 0 30 0
[pid=18933] ppid=18932 vsize=70740 CPUtime=12.66
/proc/18933/stat : 18933 (packup) R 18932 18932 1511 34817 1511 4202496 17787 70077 0 0 229 74 878 85 18 0 1 0 4225434 72437760 16795 1283457024 134512640 134752139 4289340560 18446744073709551615 4157135667 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/18933/statm: 17685 16795 333 59 0 16849 0
Current children cumulated CPU time (s) 12.66
Current children cumulated vsize (KiB) 73312

[startup+25.5122 s]
/proc/loadavg: 1.00 1.00 1.00 2/38 18944
/proc/meminfo: memFree=459020/1048576 swapFree=0/0
[pid=18932] ppid=18931 vsize=2572 CPUtime=0
/proc/18932/stat : 18932 (packup2mp4tr-0.) S 18931 18932 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 4225434 2633728 274 1283457024 134512640 135304128 4288982128 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/18932/statm: 643 274 233 194 0 30 0
[pid=18933] ppid=18932 vsize=70744 CPUtime=23.39
/proc/18933/stat : 18933 (packup) S 18932 18932 1511 34817 1511 4202496 17892 132170 0 0 280 124 1782 153 19 0 1 0 4225434 72441856 16796 1283457024 134512640 134752139 4289340560 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/18933/statm: 17686 16796 333 59 0 16850 0
[pid=18943] ppid=18933 vsize=1672 CPUtime=0
/proc/18943/stat : 18943 (sh) S 18933 18932 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 4227790 1712128 124 1283457024 134512640 134593992 4292155376 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/18943/statm: 418 124 108 20 0 45 0
[pid=18944] ppid=18943 vsize=44816 CPUtime=1.98
/proc/18944/stat : 18944 (minisatp_32) R 18943 18932 1511 34817 1511 4202496 11265 0 0 0 190 8 0 0 25 0 1 0 4227791 45891584 9905 1283457024 134512640 135413687 4294242832 18446744073709551615 134988446 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/18944/statm: 11204 9905 85 220 0 10982 0
Current children cumulated CPU time (s) 25.37
Current children cumulated vsize (KiB) 119804

[startup+51.1051 s]
/proc/loadavg: 1.00 1.00 1.00 2/38 18944
/proc/meminfo: memFree=176052/1048576 swapFree=0/0
[pid=18932] ppid=18931 vsize=2572 CPUtime=0
/proc/18932/stat : 18932 (packup2mp4tr-0.) S 18931 18932 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 4225434 2633728 274 1283457024 134512640 135304128 4288982128 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/18932/statm: 643 274 233 194 0 30 0
[pid=18933] ppid=18932 vsize=70744 CPUtime=23.39
/proc/18933/stat : 18933 (packup) S 18932 18932 1511 34817 1511 4202496 17892 132170 0 0 280 124 1782 153 19 0 1 0 4225434 72441856 16796 1283457024 134512640 134752139 4289340560 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/18933/statm: 17686 16796 333 59 0 16850 0
[pid=18943] ppid=18933 vsize=1672 CPUtime=0
/proc/18943/stat : 18943 (sh) S 18933 18932 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 4227790 1712128 124 1283457024 134512640 134593992 4292155376 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/18943/statm: 418 124 108 20 0 45 0
[pid=18944] ppid=18943 vsize=402008 CPUtime=27.47
/proc/18944/stat : 18944 (minisatp_32) R 18943 18932 1511 34817 1511 4202496 135263 0 0 0 2660 87 0 0 25 0 1 0 4227791 411656192 88845 1283457024 134512640 135413687 4294242832 18446744073709551615 134971471 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/18944/statm: 100502 88845 110 220 0 100280 0
Current children cumulated CPU time (s) 50.86
Current children cumulated vsize (KiB) 476996

[startup+102.305 s]
/proc/loadavg: 1.00 1.00 1.00 2/37 18944
/proc/meminfo: memFree=50572/1048576 swapFree=0/0
[pid=18932] ppid=18931 vsize=2572 CPUtime=0
/proc/18932/stat : 18932 (packup2mp4tr-0.) S 18931 18932 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 4225434 2633728 274 1283457024 134512640 135304128 4288982128 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/18932/statm: 643 274 233 194 0 30 0
[pid=18933] ppid=18932 vsize=70744 CPUtime=23.39
/proc/18933/stat : 18933 (packup) S 18932 18932 1511 34817 1511 4202496 17892 132170 0 0 280 124 1782 153 19 0 1 0 4225434 72441856 16796 1283457024 134512640 134752139 4289340560 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/18933/statm: 17686 16796 333 59 0 16850 0
[pid=18943] ppid=18933 vsize=1672 CPUtime=0
/proc/18943/stat : 18943 (sh) S 18933 18932 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 4227790 1712128 124 1283457024 134512640 134593992 4292155376 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/18943/statm: 418 124 108 20 0 45 0
[pid=18944] ppid=18943 vsize=507300 CPUtime=78.62
/proc/18944/stat : 18944 (minisatp_32) R 18943 18932 1511 34817 1511 4202496 179131 0 0 0 7752 110 0 0 25 0 1 0 4227791 519475200 110891 1283457024 134512640 135413687 4294242832 18446744073709551615 134649535 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/18944/statm: 126825 110891 110 220 0 126603 0
Current children cumulated CPU time (s) 102.01
Current children cumulated vsize (KiB) 582288

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

[startup+102.405 s]
/proc/loadavg: 1.00 1.00 1.00 2/37 18944
/proc/meminfo: memFree=50572/1048576 swapFree=0/0
[pid=18932] ppid=18931 vsize=2572 CPUtime=0
/proc/18932/stat : 18932 (packup2mp4tr-0.) S 18931 18932 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 4225434 2633728 274 1283457024 134512640 135304128 4288982128 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/18932/statm: 643 274 233 194 0 30 0
[pid=18933] ppid=18932 vsize=70744 CPUtime=23.39
/proc/18933/stat : 18933 (packup) S 18932 18932 1511 34817 1511 4202496 17892 132170 0 0 280 124 1782 153 19 0 1 0 4225434 72441856 16796 1283457024 134512640 134752139 4289340560 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/18933/statm: 17686 16796 333 59 0 16850 0
[pid=18943] ppid=18933 vsize=1672 CPUtime=0
/proc/18943/stat : 18943 (sh) S 18933 18932 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 4227790 1712128 124 1283457024 134512640 134593992 4292155376 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/18943/statm: 418 124 108 20 0 45 0
[pid=18944] ppid=18943 vsize=507300 CPUtime=78.72
/proc/18944/stat : 18944 (minisatp_32) R 18943 18932 1511 34817 1511 4202496 179134 0 0 0 7762 110 0 0 25 0 1 0 4227791 519475200 110894 1283457024 134512640 135413687 4294242832 18446744073709551615 134649744 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/18944/statm: 126825 110894 110 220 0 126603 0
Current children cumulated CPU time (s) 102.11
Current children cumulated vsize (KiB) 582288

[startup+115.209 s]
/proc/loadavg: 1.00 1.00 1.00 2/37 18944
/proc/meminfo: memFree=49704/1048576 swapFree=0/0
[pid=18932] ppid=18931 vsize=2572 CPUtime=0
/proc/18932/stat : 18932 (packup2mp4tr-0.) S 18931 18932 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 4225434 2633728 274 1283457024 134512640 135304128 4288982128 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/18932/statm: 643 274 233 194 0 30 0
[pid=18933] ppid=18932 vsize=70744 CPUtime=23.39
/proc/18933/stat : 18933 (packup) S 18932 18932 1511 34817 1511 4202496 17892 132170 0 0 280 124 1782 153 19 0 1 0 4225434 72441856 16796 1283457024 134512640 134752139 4289340560 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/18933/statm: 17686 16796 333 59 0 16850 0
[pid=18943] ppid=18933 vsize=1672 CPUtime=0
/proc/18943/stat : 18943 (sh) S 18933 18932 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 4227790 1712128 124 1283457024 134512640 134593992 4292155376 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/18943/statm: 418 124 108 20 0 45 0
[pid=18944] ppid=18943 vsize=507300 CPUtime=91.52
/proc/18944/stat : 18944 (minisatp_32) R 18943 18932 1511 34817 1511 4202496 179890 0 0 0 9042 110 0 0 25 0 1 0 4227791 519475200 111106 1283457024 134512640 135413687 4294242832 18446744073709551615 134649574 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/18944/statm: 126825 111106 110 220 0 126603 0
Current children cumulated CPU time (s) 114.91
Current children cumulated vsize (KiB) 582288

[startup+121.611 s]
/proc/loadavg: 1.00 1.00 1.00 2/37 18944
/proc/meminfo: memFree=49704/1048576 swapFree=0/0
[pid=18932] ppid=18931 vsize=2572 CPUtime=0
/proc/18932/stat : 18932 (packup2mp4tr-0.) S 18931 18932 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 4225434 2633728 274 1283457024 134512640 135304128 4288982128 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/18932/statm: 643 274 233 194 0 30 0
[pid=18933] ppid=18932 vsize=70744 CPUtime=23.39
/proc/18933/stat : 18933 (packup) S 18932 18932 1511 34817 1511 4202496 17892 132170 0 0 280 124 1782 153 19 0 1 0 4225434 72441856 16796 1283457024 134512640 134752139 4289340560 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/18933/statm: 17686 16796 333 59 0 16850 0
[pid=18943] ppid=18933 vsize=1672 CPUtime=0
/proc/18943/stat : 18943 (sh) S 18933 18932 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 4227790 1712128 124 1283457024 134512640 134593992 4292155376 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/18943/statm: 418 124 108 20 0 45 0
[pid=18944] ppid=18943 vsize=507300 CPUtime=97.93
/proc/18944/stat : 18944 (minisatp_32) R 18943 18932 1511 34817 1511 4202496 179963 0 0 0 9681 112 0 0 25 0 1 0 4227791 519475200 111178 1283457024 134512640 135413687 4294242832 18446744073709551615 134649535 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/18944/statm: 126825 111178 110 220 0 126603 0
Current children cumulated CPU time (s) 121.32
Current children cumulated vsize (KiB) 582288

[startup+124.812 s]
/proc/loadavg: 1.00 1.00 1.00 2/37 18944
/proc/meminfo: memFree=49704/1048576 swapFree=0/0
[pid=18932] ppid=18931 vsize=2572 CPUtime=0
/proc/18932/stat : 18932 (packup2mp4tr-0.) S 18931 18932 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 4225434 2633728 274 1283457024 134512640 135304128 4288982128 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/18932/statm: 643 274 233 194 0 30 0
[pid=18933] ppid=18932 vsize=70744 CPUtime=23.39
/proc/18933/stat : 18933 (packup) S 18932 18932 1511 34817 1511 4202496 17892 132170 0 0 280 124 1782 153 19 0 1 0 4225434 72441856 16796 1283457024 134512640 134752139 4289340560 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/18933/statm: 17686 16796 333 59 0 16850 0
[pid=18943] ppid=18933 vsize=1672 CPUtime=0
/proc/18943/stat : 18943 (sh) S 18933 18932 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 4227790 1712128 124 1283457024 134512640 134593992 4292155376 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/18943/statm: 418 124 108 20 0 45 0
[pid=18944] ppid=18943 vsize=526268 CPUtime=101.12
/proc/18944/stat : 18944 (minisatp_32) R 18943 18932 1511 34817 1511 4202496 179995 0 0 0 9999 113 0 0 25 0 1 0 4227791 538898432 111210 1283457024 134512640 135413687 4294242832 18446744073709551615 134649456 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/18944/statm: 131567 111210 110 220 0 131345 0
Current children cumulated CPU time (s) 124.51
Current children cumulated vsize (KiB) 601256

[startup+125.612 s]
/proc/loadavg: 1.00 1.00 1.00 2/37 18944
/proc/meminfo: memFree=49704/1048576 swapFree=0/0
[pid=18932] ppid=18931 vsize=2572 CPUtime=0
/proc/18932/stat : 18932 (packup2mp4tr-0.) S 18931 18932 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 4225434 2633728 274 1283457024 134512640 135304128 4288982128 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/18932/statm: 643 274 233 194 0 30 0
[pid=18933] ppid=18932 vsize=70744 CPUtime=23.39
/proc/18933/stat : 18933 (packup) S 18932 18932 1511 34817 1511 4202496 17892 132170 0 0 280 124 1782 153 19 0 1 0 4225434 72441856 16796 1283457024 134512640 134752139 4289340560 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/18933/statm: 17686 16796 333 59 0 16850 0
[pid=18943] ppid=18933 vsize=1672 CPUtime=0
/proc/18943/stat : 18943 (sh) S 18933 18932 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 4227790 1712128 124 1283457024 134512640 134593992 4292155376 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/18943/statm: 418 124 108 20 0 45 0
[pid=18944] ppid=18943 vsize=526268 CPUtime=101.92
/proc/18944/stat : 18944 (minisatp_32) R 18943 18932 1511 34817 1511 4202496 180004 0 0 0 10079 113 0 0 25 0 1 0 4227791 538898432 111219 1283457024 134512640 135413687 4294242832 18446744073709551615 134649535 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/18944/statm: 131567 111219 110 220 0 131345 0
Current children cumulated CPU time (s) 125.31
Current children cumulated vsize (KiB) 601256

[startup+126.412 s]
/proc/loadavg: 1.00 1.00 1.00 2/37 18944
/proc/meminfo: memFree=49704/1048576 swapFree=0/0
[pid=18932] ppid=18931 vsize=2572 CPUtime=0
/proc/18932/stat : 18932 (packup2mp4tr-0.) S 18931 18932 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 4225434 2633728 274 1283457024 134512640 135304128 4288982128 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/18932/statm: 643 274 233 194 0 30 0
[pid=18933] ppid=18932 vsize=70744 CPUtime=23.39
/proc/18933/stat : 18933 (packup) S 18932 18932 1511 34817 1511 4202496 17892 132170 0 0 280 124 1782 153 19 0 1 0 4225434 72441856 16796 1283457024 134512640 134752139 4289340560 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/18933/statm: 17686 16796 333 59 0 16850 0
[pid=18943] ppid=18933 vsize=1672 CPUtime=0
/proc/18943/stat : 18943 (sh) S 18933 18932 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 4227790 1712128 124 1283457024 134512640 134593992 4292155376 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/18943/statm: 418 124 108 20 0 45 0
[pid=18944] ppid=18943 vsize=526268 CPUtime=102.72
/proc/18944/stat : 18944 (minisatp_32) R 18943 18932 1511 34817 1511 4202496 180011 0 0 0 10159 113 0 0 25 0 1 0 4227791 538898432 111226 1283457024 134512640 135413687 4294242832 18446744073709551615 134649535 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/18944/statm: 131567 111226 110 220 0 131345 0
Current children cumulated CPU time (s) 126.11
Current children cumulated vsize (KiB) 601256

[startup+126.813 s]
/proc/loadavg: 1.00 1.00 1.00 2/37 18944
/proc/meminfo: memFree=47472/1048576 swapFree=0/0
[pid=18932] ppid=18931 vsize=2572 CPUtime=0
/proc/18932/stat : 18932 (packup2mp4tr-0.) S 18931 18932 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 4225434 2633728 274 1283457024 134512640 135304128 4288982128 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/18932/statm: 643 274 233 194 0 30 0
[pid=18933] ppid=18932 vsize=70748 CPUtime=126.53
/proc/18933/stat : 18933 (packup) R 18932 18932 1511 34817 1511 4202496 17947 312993 0 0 281 124 11976 272 18 0 1 0 4225434 72445952 16797 1283457024 134512640 134752139 4289340560 18446744073709551615 4157135645 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/18933/statm: 17687 16797 333 59 0 16851 0
Current children cumulated CPU time (s) 126.53
Current children cumulated vsize (KiB) 73320

[startup+126.913 s]
/proc/loadavg: 1.00 1.00 1.00 2/37 18944
/proc/meminfo: memFree=47472/1048576 swapFree=0/0
[pid=18932] ppid=18931 vsize=2572 CPUtime=0
/proc/18932/stat : 18932 (packup2mp4tr-0.) S 18931 18932 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 4225434 2633728 274 1283457024 134512640 135304128 4288982128 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/18932/statm: 643 274 233 194 0 30 0
[pid=18933] ppid=18932 vsize=69008 CPUtime=126.63
/proc/18933/stat : 18933 (packup) R 18932 18932 1511 34817 1511 4202496 31547 312993 0 0 288 127 11976 272 18 0 1 0 4225434 70664192 16375 1283457024 134512640 134752139 4289340560 18446744073709551615 4157097373 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/18933/statm: 17252 16375 346 59 0 16416 0
Current children cumulated CPU time (s) 126.63
Current children cumulated vsize (KiB) 71580

Child status: 0
Real time (s): 127.005
CPU time (s): 126.74
CPU user time (s): 122.72
CPU system time (s): 4.02025
CPU usage (%): 99.7911
Max. virtual memory (cumulated for all children) (KiB): 630492

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 122.72
system time used= 4.02025
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 346565
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= 23
involuntary context switches= 1628

runsolver used 0 second user time and 0.012 second system time

The end