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/rand461.cudf.s-e-l.log.runsolver ./packup2mp4tr-0.6 /home/misc2010/data/2011/incremental/s-e-l/rand461.cudf /home/misc2010/tmp/201108241238/packup2mp4tr-0.6/rand461.cudf.s-e-l.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.11 1.05 1.01 5/34 13841
/proc/meminfo: memFree=502564/1048576 swapFree=0/0
[pid=13840] ppid=13839 vsize=2572 CPUtime=0
/proc/13840/stat : 13840 (packup2mp4tr-0.) R 13839 13840 1511 34817 1511 4202496 361 0 0 0 0 0 0 0 25 0 1 0 3283189 2633728 274 1283457024 134512640 135304128 4289010816 18446744073709551615 4294960130 0 65538 4 84480 0 0 0 17 0 0 0 0
/proc/13840/statm: 643 274 233 194 0 30 0
[pid=13841] ppid=13840 vsize=2572 CPUtime=0
/proc/13841/stat : 13841 (packup2mp4tr-0.) R 13840 13840 1511 34817 1511 4202560 0 0 0 0 0 0 0 0 25 0 1 0 3283189 2633728 41 1283457024 134512640 135304128 4289010816 18446744073709551615 4294960130 0 65538 4 84480 0 0 0 17 0 0 0 0
/proc/13841/statm: 643 41 0 194 0 30 0

[startup+0.119218 s]
/proc/loadavg: 1.11 1.05 1.01 5/34 13841
/proc/meminfo: memFree=502564/1048576 swapFree=0/0
[pid=13840] ppid=13839 vsize=2572 CPUtime=0
/proc/13840/stat : 13840 (packup2mp4tr-0.) S 13839 13840 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 3283189 2633728 274 1283457024 134512640 135304128 4289010816 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/13840/statm: 643 274 233 194 0 30 0
[pid=13841] ppid=13840 vsize=8204 CPUtime=0.12
/proc/13841/stat : 13841 (packup) R 13840 13840 1511 34817 1511 4202496 1552 0 0 0 12 0 0 0 25 0 1 0 3283189 8400896 1481 1283457024 134512640 134752139 4291514032 18446744073709551615 134682087 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/13841/statm: 2051 1481 286 59 0 1215 0
Current children cumulated CPU time (s) 0.12
Current children cumulated vsize (KiB) 10776

[startup+0.209261 s]
/proc/loadavg: 1.11 1.05 1.01 5/34 13841
/proc/meminfo: memFree=502564/1048576 swapFree=0/0
[pid=13840] ppid=13839 vsize=2572 CPUtime=0
/proc/13840/stat : 13840 (packup2mp4tr-0.) S 13839 13840 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 3283189 2633728 274 1283457024 134512640 135304128 4289010816 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/13840/statm: 643 274 233 194 0 30 0
[pid=13841] ppid=13840 vsize=11372 CPUtime=0.2
/proc/13841/stat : 13841 (packup) R 13840 13840 1511 34817 1511 4202496 2339 0 0 0 20 0 0 0 25 0 1 0 3283189 11644928 2268 1283457024 134512640 134752139 4291514032 18446744073709551615 134705846 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/13841/statm: 2843 2268 286 59 0 2007 0
Current children cumulated CPU time (s) 0.2
Current children cumulated vsize (KiB) 13944

[startup+0.309269 s]
/proc/loadavg: 1.11 1.05 1.01 5/34 13841
/proc/meminfo: memFree=502564/1048576 swapFree=0/0
[pid=13840] ppid=13839 vsize=2572 CPUtime=0
/proc/13840/stat : 13840 (packup2mp4tr-0.) S 13839 13840 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 3283189 2633728 274 1283457024 134512640 135304128 4289010816 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/13840/statm: 643 274 233 194 0 30 0
[pid=13841] ppid=13840 vsize=14540 CPUtime=0.3
/proc/13841/stat : 13841 (packup) R 13840 13840 1511 34817 1511 4202496 3124 0 0 0 30 0 0 0 25 0 1 0 3283189 14888960 3053 1283457024 134512640 134752139 4291514032 18446744073709551615 134681839 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/13841/statm: 3635 3053 286 59 0 2799 0
Current children cumulated CPU time (s) 0.3
Current children cumulated vsize (KiB) 17112

[startup+0.709366 s]
/proc/loadavg: 1.11 1.05 1.01 5/34 13841
/proc/meminfo: memFree=502564/1048576 swapFree=0/0
[pid=13840] ppid=13839 vsize=2572 CPUtime=0
/proc/13840/stat : 13840 (packup2mp4tr-0.) S 13839 13840 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 3283189 2633728 274 1283457024 134512640 135304128 4289010816 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/13840/statm: 643 274 233 194 0 30 0
[pid=13841] ppid=13840 vsize=25296 CPUtime=0.7
/proc/13841/stat : 13841 (packup) R 13840 13840 1511 34817 1511 4202496 5806 0 0 0 68 2 0 0 25 0 1 0 3283189 25903104 5735 1283457024 134512640 134752139 4291514032 18446744073709551615 134681493 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/13841/statm: 6324 5735 286 59 0 5488 0
Current children cumulated CPU time (s) 0.7
Current children cumulated vsize (KiB) 27868

[startup+1.50957 s]
/proc/loadavg: 1.18 1.07 1.01 2/35 13842
/proc/meminfo: memFree=461632/1048576 swapFree=0/0
[pid=13840] ppid=13839 vsize=2572 CPUtime=0
/proc/13840/stat : 13840 (packup2mp4tr-0.) S 13839 13840 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 3283189 2633728 274 1283457024 134512640 135304128 4289010816 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/13840/statm: 643 274 233 194 0 30 0
[pid=13841] ppid=13840 vsize=45604 CPUtime=1.42
/proc/13841/stat : 13841 (packup) S 13840 13840 1511 34817 1511 4202496 11025 0 0 0 121 21 0 0 25 0 1 0 3283189 46698496 10637 1283457024 134512640 134752139 4291514032 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/13841/statm: 11401 10637 325 59 0 10565 0
Current children cumulated CPU time (s) 1.42
Current children cumulated vsize (KiB) 48176

[startup+3.11036 s]
/proc/loadavg: 1.18 1.07 1.01 2/37 13844
/proc/meminfo: memFree=442380/1048576 swapFree=0/0
[pid=13840] ppid=13839 vsize=2572 CPUtime=0
/proc/13840/stat : 13840 (packup2mp4tr-0.) S 13839 13840 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 3283189 2633728 274 1283457024 134512640 135304128 4289010816 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/13840/statm: 643 274 233 194 0 30 0
[pid=13841] ppid=13840 vsize=45604 CPUtime=1.42
/proc/13841/stat : 13841 (packup) S 13840 13840 1511 34817 1511 4202496 11025 0 0 0 121 21 0 0 25 0 1 0 3283189 46698496 10637 1283457024 134512640 134752139 4291514032 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/13841/statm: 11401 10637 325 59 0 10565 0
[pid=13843] ppid=13841 vsize=1676 CPUtime=0
/proc/13843/stat : 13843 (sh) S 13841 13840 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 25 0 1 0 3283332 1716224 124 1283457024 134512640 134593992 4289881552 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/13843/statm: 419 124 108 20 0 46 0
[pid=13844] ppid=13843 vsize=35940 CPUtime=1.66
/proc/13844/stat : 13844 (minisatp_32) R 13843 13840 1511 34817 1511 4202496 10992 0 0 0 156 10 0 0 25 0 1 0 3283333 36802560 8489 1283457024 134512640 135413687 4291966944 18446744073709551615 134689045 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/13844/statm: 8985 8489 107 220 0 8763 0
Current children cumulated CPU time (s) 3.08
Current children cumulated vsize (KiB) 85792

[startup+6.31107 s]
/proc/loadavg: 1.17 1.07 1.01 2/37 13846
/proc/meminfo: memFree=410016/1048576 swapFree=0/0
[pid=13840] ppid=13839 vsize=2572 CPUtime=0
/proc/13840/stat : 13840 (packup2mp4tr-0.) S 13839 13840 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 3283189 2633728 274 1283457024 134512640 135304128 4289010816 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/13840/statm: 643 274 233 194 0 30 0
[pid=13841] ppid=13840 vsize=45608 CPUtime=3.51
/proc/13841/stat : 13841 (packup) S 13840 13840 1511 34817 1511 4202496 11106 11624 0 0 139 36 165 11 18 0 1 0 3283189 46702592 10654 1283457024 134512640 134752139 4291514032 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/13841/statm: 11402 10654 333 59 0 10566 0
[pid=13845] ppid=13841 vsize=1672 CPUtime=0
/proc/13845/stat : 13845 (sh) S 13841 13840 1511 34817 1511 4202496 145 0 0 0 0 0 0 0 18 0 1 0 3283542 1712128 123 1283457024 134512640 134593992 4287105824 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/13845/statm: 418 123 108 20 0 45 0
[pid=13846] ppid=13845 vsize=77180 CPUtime=2.77
/proc/13846/stat : 13846 (minisatp_32) R 13845 13840 1511 34817 1511 4202496 24529 0 0 0 258 19 0 0 25 0 1 0 3283543 79032320 17659 1283457024 134512640 135413687 4291501936 18446744073709551615 134699051 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/13846/statm: 19295 17659 107 220 0 19073 0
Current children cumulated CPU time (s) 6.28
Current children cumulated vsize (KiB) 127032

[startup+12.7129 s]
/proc/loadavg: 1.15 1.07 1.01 2/37 13848
/proc/meminfo: memFree=359432/1048576 swapFree=0/0
[pid=13840] ppid=13839 vsize=2572 CPUtime=0
/proc/13840/stat : 13840 (packup2mp4tr-0.) S 13839 13840 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 3283189 2633728 274 1283457024 134512640 135304128 4289010816 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/13840/statm: 643 274 233 194 0 30 0
[pid=13841] ppid=13840 vsize=45612 CPUtime=7.69
/proc/13841/stat : 13841 (packup) S 13840 13840 1511 34817 1511 4202496 11202 37861 0 0 151 58 525 35 18 0 1 0 3283189 46706688 10661 1283457024 134512640 134752139 4291514032 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/13841/statm: 11403 10661 333 59 0 10567 0
[pid=13847] ppid=13841 vsize=1672 CPUtime=0
/proc/13847/stat : 13847 (sh) S 13841 13840 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 18 0 1 0 3283962 1712128 124 1283457024 134512640 134593992 4293267712 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/13847/statm: 418 124 108 20 0 45 0
[pid=13848] ppid=13847 vsize=114172 CPUtime=4.99
/proc/13848/stat : 13848 (minisatp_32) R 13847 13840 1511 34817 1511 4202496 39320 0 0 0 465 34 0 0 25 0 1 0 3283962 116912128 25029 1283457024 134512640 135413687 4290916064 18446744073709551615 134697182 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/13848/statm: 28543 25029 109 220 0 28321 0
Current children cumulated CPU time (s) 12.68
Current children cumulated vsize (KiB) 164028

[startup+25.5065 s]
/proc/loadavg: 1.12 1.06 1.01 2/37 13850
/proc/meminfo: memFree=310452/1048576 swapFree=0/0
[pid=13840] ppid=13839 vsize=2572 CPUtime=0
/proc/13840/stat : 13840 (packup2mp4tr-0.) S 13839 13840 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 3283189 2633728 274 1283457024 134512640 135304128 4289010816 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/13840/statm: 643 274 233 194 0 30 0
[pid=13841] ppid=13840 vsize=45616 CPUtime=13.27
/proc/13841/stat : 13841 (packup) S 13840 13840 1511 34817 1511 4202496 11279 77508 0 0 171 73 1012 71 18 0 1 0 3283189 46710784 10662 1283457024 134512640 134752139 4291514032 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/13841/statm: 11404 10662 333 59 0 10568 0
[pid=13849] ppid=13841 vsize=1676 CPUtime=0
/proc/13849/stat : 13849 (sh) S 13841 13840 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 18 0 1 0 3284519 1716224 124 1283457024 134512640 134593992 4289094928 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/13849/statm: 419 124 108 20 0 46 0
[pid=13850] ppid=13849 vsize=166320 CPUtime=12.19
/proc/13850/stat : 13850 (minisatp_32) R 13849 13840 1511 34817 1511 4202496 55931 0 0 0 1186 33 0 0 25 0 1 0 3284520 170311680 36745 1283457024 134512640 135413687 4287626176 18446744073709551615 134649456 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/13850/statm: 41580 36745 110 220 0 41358 0
Current children cumulated CPU time (s) 25.46
Current children cumulated vsize (KiB) 216184

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

[startup+25.6065 s]
/proc/loadavg: 1.12 1.06 1.01 2/37 13850
/proc/meminfo: memFree=310452/1048576 swapFree=0/0
[pid=13840] ppid=13839 vsize=2572 CPUtime=0
/proc/13840/stat : 13840 (packup2mp4tr-0.) S 13839 13840 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 3283189 2633728 274 1283457024 134512640 135304128 4289010816 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/13840/statm: 643 274 233 194 0 30 0
[pid=13841] ppid=13840 vsize=45616 CPUtime=13.27
/proc/13841/stat : 13841 (packup) S 13840 13840 1511 34817 1511 4202496 11279 77508 0 0 171 73 1012 71 18 0 1 0 3283189 46710784 10662 1283457024 134512640 134752139 4291514032 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/13841/statm: 11404 10662 333 59 0 10568 0
[pid=13849] ppid=13841 vsize=1676 CPUtime=0
/proc/13849/stat : 13849 (sh) S 13841 13840 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 18 0 1 0 3284519 1716224 124 1283457024 134512640 134593992 4289094928 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/13849/statm: 419 124 108 20 0 46 0
[pid=13850] ppid=13849 vsize=166320 CPUtime=12.29
/proc/13850/stat : 13850 (minisatp_32) R 13849 13840 1511 34817 1511 4202496 55934 0 0 0 1196 33 0 0 25 0 1 0 3284520 170311680 36748 1283457024 134512640 135413687 4287626176 18446744073709551615 134649535 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/13850/statm: 41580 36748 110 220 0 41358 0
Current children cumulated CPU time (s) 25.56
Current children cumulated vsize (KiB) 216184

[startup+38.4109 s]
/proc/loadavg: 1.10 1.06 1.01 2/37 13850
/proc/meminfo: memFree=309708/1048576 swapFree=0/0
[pid=13840] ppid=13839 vsize=2572 CPUtime=0
/proc/13840/stat : 13840 (packup2mp4tr-0.) S 13839 13840 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 3283189 2633728 274 1283457024 134512640 135304128 4289010816 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/13840/statm: 643 274 233 194 0 30 0
[pid=13841] ppid=13840 vsize=45616 CPUtime=13.27
/proc/13841/stat : 13841 (packup) S 13840 13840 1511 34817 1511 4202496 11279 77508 0 0 171 73 1012 71 18 0 1 0 3283189 46710784 10662 1283457024 134512640 134752139 4291514032 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/13841/statm: 11404 10662 333 59 0 10568 0
[pid=13849] ppid=13841 vsize=1676 CPUtime=0
/proc/13849/stat : 13849 (sh) S 13841 13840 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 18 0 1 0 3284519 1716224 124 1283457024 134512640 134593992 4289094928 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/13849/statm: 419 124 108 20 0 46 0
[pid=13850] ppid=13849 vsize=166848 CPUtime=25.09
/proc/13850/stat : 13850 (minisatp_32) R 13849 13840 1511 34817 1511 4202496 56299 0 0 0 2475 34 0 0 25 0 1 0 3284520 170852352 36929 1283457024 134512640 135413687 4287626176 18446744073709551615 134649535 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/13850/statm: 41712 36929 110 220 0 41490 0
Current children cumulated CPU time (s) 38.36
Current children cumulated vsize (KiB) 216712

[startup+41.6121 s]
/proc/loadavg: 1.09 1.06 1.01 2/37 13850
/proc/meminfo: memFree=309708/1048576 swapFree=0/0
[pid=13840] ppid=13839 vsize=2572 CPUtime=0
/proc/13840/stat : 13840 (packup2mp4tr-0.) S 13839 13840 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 3283189 2633728 274 1283457024 134512640 135304128 4289010816 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/13840/statm: 643 274 233 194 0 30 0
[pid=13841] ppid=13840 vsize=45616 CPUtime=13.27
/proc/13841/stat : 13841 (packup) S 13840 13840 1511 34817 1511 4202496 11279 77508 0 0 171 73 1012 71 18 0 1 0 3283189 46710784 10662 1283457024 134512640 134752139 4291514032 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/13841/statm: 11404 10662 333 59 0 10568 0
[pid=13849] ppid=13841 vsize=1676 CPUtime=0
/proc/13849/stat : 13849 (sh) S 13841 13840 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 18 0 1 0 3284519 1716224 124 1283457024 134512640 134593992 4289094928 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/13849/statm: 419 124 108 20 0 46 0
[pid=13850] ppid=13849 vsize=166848 CPUtime=28.29
/proc/13850/stat : 13850 (minisatp_32) R 13849 13840 1511 34817 1511 4202496 56333 0 0 0 2795 34 0 0 25 0 1 0 3284520 170852352 36963 1283457024 134512640 135413687 4287626176 18446744073709551615 134649574 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/13850/statm: 41712 36963 110 220 0 41490 0
Current children cumulated CPU time (s) 41.56
Current children cumulated vsize (KiB) 216712

[startup+44.8131 s]
/proc/loadavg: 1.09 1.06 1.01 2/37 13850
/proc/meminfo: memFree=309584/1048576 swapFree=0/0
[pid=13840] ppid=13839 vsize=2572 CPUtime=0
/proc/13840/stat : 13840 (packup2mp4tr-0.) S 13839 13840 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 3283189 2633728 274 1283457024 134512640 135304128 4289010816 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/13840/statm: 643 274 233 194 0 30 0
[pid=13841] ppid=13840 vsize=45616 CPUtime=13.27
/proc/13841/stat : 13841 (packup) S 13840 13840 1511 34817 1511 4202496 11279 77508 0 0 171 73 1012 71 18 0 1 0 3283189 46710784 10662 1283457024 134512640 134752139 4291514032 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/13841/statm: 11404 10662 333 59 0 10568 0
[pid=13849] ppid=13841 vsize=1676 CPUtime=0
/proc/13849/stat : 13849 (sh) S 13841 13840 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 18 0 1 0 3284519 1716224 124 1283457024 134512640 134593992 4289094928 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/13849/statm: 419 124 108 20 0 46 0
[pid=13850] ppid=13849 vsize=166848 CPUtime=31.49
/proc/13850/stat : 13850 (minisatp_32) R 13849 13840 1511 34817 1511 4202496 56363 0 0 0 3115 34 0 0 25 0 1 0 3284520 170852352 36992 1283457024 134512640 135413687 4287626176 18446744073709551615 134649456 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/13850/statm: 41712 36992 110 220 0 41490 0
Current children cumulated CPU time (s) 44.76
Current children cumulated vsize (KiB) 216712

[startup+46.4138 s]
/proc/loadavg: 1.08 1.06 1.01 2/37 13850
/proc/meminfo: memFree=309584/1048576 swapFree=0/0
[pid=13840] ppid=13839 vsize=2572 CPUtime=0
/proc/13840/stat : 13840 (packup2mp4tr-0.) S 13839 13840 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 3283189 2633728 274 1283457024 134512640 135304128 4289010816 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/13840/statm: 643 274 233 194 0 30 0
[pid=13841] ppid=13840 vsize=45616 CPUtime=13.27
/proc/13841/stat : 13841 (packup) S 13840 13840 1511 34817 1511 4202496 11279 77508 0 0 171 73 1012 71 18 0 1 0 3283189 46710784 10662 1283457024 134512640 134752139 4291514032 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/13841/statm: 11404 10662 333 59 0 10568 0
[pid=13849] ppid=13841 vsize=1676 CPUtime=0
/proc/13849/stat : 13849 (sh) S 13841 13840 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 18 0 1 0 3284519 1716224 124 1283457024 134512640 134593992 4289094928 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/13849/statm: 419 124 108 20 0 46 0
[pid=13850] ppid=13849 vsize=166848 CPUtime=33.09
/proc/13850/stat : 13850 (minisatp_32) R 13849 13840 1511 34817 1511 4202496 56372 0 0 0 3275 34 0 0 25 0 1 0 3284520 170852352 37001 1283457024 134512640 135413687 4287626176 18446744073709551615 134649479 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/13850/statm: 41712 37001 110 220 0 41490 0
Current children cumulated CPU time (s) 46.36
Current children cumulated vsize (KiB) 216712

[startup+46.814 s]
/proc/loadavg: 1.08 1.06 1.01 2/37 13850
/proc/meminfo: memFree=309584/1048576 swapFree=0/0
[pid=13840] ppid=13839 vsize=2572 CPUtime=0
/proc/13840/stat : 13840 (packup2mp4tr-0.) S 13839 13840 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 3283189 2633728 274 1283457024 134512640 135304128 4289010816 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/13840/statm: 643 274 233 194 0 30 0
[pid=13841] ppid=13840 vsize=45616 CPUtime=13.27
/proc/13841/stat : 13841 (packup) S 13840 13840 1511 34817 1511 4202496 11279 77508 0 0 171 73 1012 71 18 0 1 0 3283189 46710784 10662 1283457024 134512640 134752139 4291514032 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/13841/statm: 11404 10662 333 59 0 10568 0
[pid=13849] ppid=13841 vsize=1676 CPUtime=0
/proc/13849/stat : 13849 (sh) S 13841 13840 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 18 0 1 0 3284519 1716224 124 1283457024 134512640 134593992 4289094928 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/13849/statm: 419 124 108 20 0 46 0
[pid=13850] ppid=13849 vsize=166848 CPUtime=33.49
/proc/13850/stat : 13850 (minisatp_32) R 13849 13840 1511 34817 1511 4202496 56444 0 0 0 3315 34 0 0 25 0 1 0 3284520 170852352 37072 1283457024 134512640 135413687 4287626176 18446744073709551615 134649456 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/13850/statm: 41712 37072 110 220 0 41490 0
Current children cumulated CPU time (s) 46.76
Current children cumulated vsize (KiB) 216712

[startup+47.2042 s]
/proc/loadavg: 1.08 1.06 1.01 2/37 13850
/proc/meminfo: memFree=309584/1048576 swapFree=0/0
[pid=13840] ppid=13839 vsize=2572 CPUtime=0
/proc/13840/stat : 13840 (packup2mp4tr-0.) S 13839 13840 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 3283189 2633728 274 1283457024 134512640 135304128 4289010816 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/13840/statm: 643 274 233 194 0 30 0
[pid=13841] ppid=13840 vsize=45616 CPUtime=13.27
/proc/13841/stat : 13841 (packup) S 13840 13840 1511 34817 1511 4202496 11279 77508 0 0 171 73 1012 71 18 0 1 0 3283189 46710784 10662 1283457024 134512640 134752139 4291514032 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/13841/statm: 11404 10662 333 59 0 10568 0
[pid=13849] ppid=13841 vsize=1676 CPUtime=0
/proc/13849/stat : 13849 (sh) S 13841 13840 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 18 0 1 0 3284519 1716224 124 1283457024 134512640 134593992 4289094928 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/13849/statm: 419 124 108 20 0 46 0
[pid=13850] ppid=13849 vsize=158060 CPUtime=33.88
/proc/13850/stat : 13850 (minisatp_32) R 13849 13840 1511 34817 1511 4202496 58387 0 0 0 3353 35 0 0 25 0 1 0 3284520 161853440 34982 1283457024 134512640 135413687 4287626176 18446744073709551615 134597339 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/13850/statm: 39515 34982 118 220 0 39293 0
Current children cumulated CPU time (s) 47.15
Current children cumulated vsize (KiB) 207924

[startup+47.3043 s]
/proc/loadavg: 1.08 1.06 1.01 2/35 13850
/proc/meminfo: memFree=460648/1048576 swapFree=0/0
[pid=13840] ppid=13839 vsize=2572 CPUtime=0
/proc/13840/stat : 13840 (packup2mp4tr-0.) S 13839 13840 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 3283189 2633728 274 1283457024 134512640 135304128 4289010816 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/13840/statm: 643 274 233 194 0 30 0
[pid=13841] ppid=13840 vsize=44452 CPUtime=47.27
/proc/13841/stat : 13841 (packup) R 13840 13840 1511 34817 1511 4202496 20423 136044 0 0 177 76 4366 108 18 0 1 0 3283189 45518848 10384 1283457024 134512640 134752139 4291514032 18446744073709551615 4157633949 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/13841/statm: 11113 10384 346 59 0 10277 0
Current children cumulated CPU time (s) 47.27
Current children cumulated vsize (KiB) 47024

Child status: 0
Real time (s): 47.3423
CPU time (s): 47.311
CPU user time (s): 45.4628
CPU system time (s): 1.84811
CPU usage (%): 99.9338
Max. virtual memory (cumulated for all children) (KiB): 233544

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 45.4628
system time used= 1.84811
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 157348
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= 646

runsolver used 0 second user time and 0.012 second system time

The end