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/rand439.cudf.s-e-l-s.log.runsolver ./packup2mp4tr-0.6 /home/misc2010/data/2011/incremental/s-e-l-s/rand439.cudf /home/misc2010/tmp/201108241238/packup2mp4tr-0.6/rand439.cudf.s-e-l-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.10 1.05 1.01 5/36 11729
/proc/meminfo: memFree=540568/1048576 swapFree=0/0
[pid=11728] ppid=11727 vsize=2576 CPUtime=0
/proc/11728/stat : 11728 (packup2mp4tr-0.) S 11727 11728 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2743035 2637824 275 1283457024 134512640 135304128 4289680672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/11728/statm: 644 275 233 194 0 31 0
[pid=11729] ppid=11728 vsize=4384 CPUtime=0.02
/proc/11729/stat : 11729 (packup) R 11728 11728 1511 34817 1511 4202496 594 0 0 0 2 0 0 0 25 0 1 0 2743035 4489216 522 1283457024 134512640 134752139 4288330656 18446744073709551615 134626427 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/11729/statm: 1096 522 286 59 0 260 0

[startup+0.138575 s]
/proc/loadavg: 1.10 1.05 1.01 5/36 11729
/proc/meminfo: memFree=540568/1048576 swapFree=0/0
[pid=11728] ppid=11727 vsize=2576 CPUtime=0
/proc/11728/stat : 11728 (packup2mp4tr-0.) S 11727 11728 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2743035 2637824 275 1283457024 134512640 135304128 4289680672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/11728/statm: 644 275 233 194 0 31 0
[pid=11729] ppid=11728 vsize=9080 CPUtime=0.14
/proc/11729/stat : 11729 (packup) R 11728 11728 1511 34817 1511 4202496 1773 0 0 0 14 0 0 0 25 0 1 0 2743035 9297920 1701 1283457024 134512640 134752139 4288330656 18446744073709551615 4157685103 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/11729/statm: 2270 1701 286 59 0 1434 0
Current children cumulated CPU time (s) 0.14
Current children cumulated vsize (KiB) 11656

[startup+0.208588 s]
/proc/loadavg: 1.10 1.05 1.01 5/36 11729
/proc/meminfo: memFree=540568/1048576 swapFree=0/0
[pid=11728] ppid=11727 vsize=2576 CPUtime=0
/proc/11728/stat : 11728 (packup2mp4tr-0.) S 11727 11728 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2743035 2637824 275 1283457024 134512640 135304128 4289680672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/11728/statm: 644 275 233 194 0 31 0
[pid=11729] ppid=11728 vsize=11720 CPUtime=0.2
/proc/11729/stat : 11729 (packup) R 11728 11728 1511 34817 1511 4202496 2421 0 0 0 20 0 0 0 25 0 1 0 2743035 12001280 2349 1283457024 134512640 134752139 4288330656 18446744073709551615 134682058 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/11729/statm: 2930 2349 286 59 0 2094 0
Current children cumulated CPU time (s) 0.2
Current children cumulated vsize (KiB) 14296

[startup+0.308607 s]
/proc/loadavg: 1.10 1.05 1.01 5/36 11729
/proc/meminfo: memFree=540568/1048576 swapFree=0/0
[pid=11728] ppid=11727 vsize=2576 CPUtime=0
/proc/11728/stat : 11728 (packup2mp4tr-0.) S 11727 11728 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2743035 2637824 275 1283457024 134512640 135304128 4289680672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/11728/statm: 644 275 233 194 0 31 0
[pid=11729] ppid=11728 vsize=14952 CPUtime=0.31
/proc/11729/stat : 11729 (packup) R 11728 11728 1511 34817 1511 4202496 3212 0 0 0 29 2 0 0 25 0 1 0 2743035 15310848 3140 1283457024 134512640 134752139 4288330656 18446744073709551615 4157842028 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/11729/statm: 3738 3140 286 59 0 2902 0
Current children cumulated CPU time (s) 0.31
Current children cumulated vsize (KiB) 17528

[startup+0.708682 s]
/proc/loadavg: 1.10 1.05 1.01 5/36 11729
/proc/meminfo: memFree=540568/1048576 swapFree=0/0
[pid=11728] ppid=11727 vsize=2576 CPUtime=0
/proc/11728/stat : 11728 (packup2mp4tr-0.) S 11727 11728 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2743035 2637824 275 1283457024 134512640 135304128 4289680672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/11728/statm: 644 275 233 194 0 31 0
[pid=11729] ppid=11728 vsize=26252 CPUtime=0.71
/proc/11729/stat : 11729 (packup) R 11728 11728 1511 34817 1511 4202496 6062 0 0 0 68 3 0 0 25 0 1 0 2743035 26882048 5990 1283457024 134512640 134752139 4288330656 18446744073709551615 134706154 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/11729/statm: 6563 5990 286 59 0 5727 0
Current children cumulated CPU time (s) 0.71
Current children cumulated vsize (KiB) 28828

[startup+1.50886 s]
/proc/loadavg: 1.10 1.05 1.01 2/37 11730
/proc/meminfo: memFree=508468/1048576 swapFree=0/0
[pid=11728] ppid=11727 vsize=2576 CPUtime=0
/proc/11728/stat : 11728 (packup2mp4tr-0.) S 11727 11728 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2743035 2637824 275 1283457024 134512640 135304128 4289680672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/11728/statm: 644 275 233 194 0 31 0
[pid=11729] ppid=11728 vsize=52584 CPUtime=1.5
/proc/11729/stat : 11729 (packup) R 11728 11728 1511 34817 1511 4202496 12992 0 0 0 146 4 0 0 25 0 1 0 2743035 53846016 12580 1283457024 134512640 134752139 4288330656 18446744073709551615 134667650 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/11729/statm: 13146 12580 306 59 0 12310 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 55160

[startup+3.11029 s]
/proc/loadavg: 1.09 1.05 1.01 2/37 11730
/proc/meminfo: memFree=474740/1048576 swapFree=0/0
[pid=11728] ppid=11727 vsize=2576 CPUtime=0
/proc/11728/stat : 11728 (packup2mp4tr-0.) S 11727 11728 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2743035 2637824 275 1283457024 134512640 135304128 4289680672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/11728/statm: 644 275 233 194 0 31 0
[pid=11729] ppid=11728 vsize=67772 CPUtime=2.23
/proc/11729/stat : 11729 (packup) S 11728 11728 1511 34817 1511 4202496 16808 0 0 0 189 34 0 0 25 0 1 0 2743035 69398528 16044 1283457024 134512640 134752139 4288330656 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/11729/statm: 16943 16044 325 59 0 16107 0
Current children cumulated CPU time (s) 2.23
Current children cumulated vsize (KiB) 70348
heavy processes:

[startup+6.30485 s]
/proc/loadavg: 1.09 1.05 1.01 2/38 11734
/proc/meminfo: memFree=472740/1048576 swapFree=0/0
[pid=11728] ppid=11727 vsize=2576 CPUtime=0
/proc/11728/stat : 11728 (packup2mp4tr-0.) S 11727 11728 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2743035 2637824 275 1283457024 134512640 135304128 4289680672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/11728/statm: 644 275 233 194 0 31 0
[pid=11729] ppid=11728 vsize=67776 CPUtime=5.35
/proc/11729/stat : 11729 (packup) S 11728 11728 1511 34817 1511 4202496 16904 15708 0 0 213 60 244 18 18 0 1 0 2743035 69402624 16063 1283457024 134512640 134752139 4288330656 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/11729/statm: 16944 16063 333 59 0 16108 0
[pid=11733] ppid=11729 vsize=1672 CPUtime=0
/proc/11733/stat : 11733 (sh) S 11729 11728 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 20 0 1 0 2743582 1712128 124 1283457024 134512640 134593992 4292724864 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/11733/statm: 418 124 108 20 0 45 0
[pid=11734] ppid=11733 vsize=23912 CPUtime=0.82
/proc/11734/stat : 11734 (minisatp_32) R 11733 11728 1511 34817 1511 4202496 5282 0 0 0 81 1 0 0 25 0 1 0 2743583 24485888 4609 1283457024 134512640 135413687 4294945472 18446744073709551615 134752627 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/11734/statm: 5978 4609 77 220 0 5756 0
Current children cumulated CPU time (s) 6.17
Current children cumulated vsize (KiB) 95936

[startup+12.7068 s]
/proc/loadavg: 1.08 1.05 1.01 2/38 11734
/proc/meminfo: memFree=351972/1048576 swapFree=0/0
[pid=11728] ppid=11727 vsize=2576 CPUtime=0
/proc/11728/stat : 11728 (packup2mp4tr-0.) S 11727 11728 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2743035 2637824 275 1283457024 134512640 135304128 4289680672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/11728/statm: 644 275 233 194 0 31 0
[pid=11729] ppid=11728 vsize=67776 CPUtime=5.35
/proc/11729/stat : 11729 (packup) S 11728 11728 1511 34817 1511 4202496 16904 15708 0 0 213 60 244 18 18 0 1 0 2743035 69402624 16063 1283457024 134512640 134752139 4288330656 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/11729/statm: 16944 16063 333 59 0 16108 0
[pid=11733] ppid=11729 vsize=1672 CPUtime=0
/proc/11733/stat : 11733 (sh) S 11729 11728 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 20 0 1 0 2743582 1712128 124 1283457024 134512640 134593992 4292724864 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/11733/statm: 418 124 108 20 0 45 0
[pid=11734] ppid=11733 vsize=134404 CPUtime=7.22
/proc/11734/stat : 11734 (minisatp_32) R 11733 11728 1511 34817 1511 4202496 44668 0 0 0 690 32 0 0 25 0 1 0 2743583 137629696 29297 1283457024 134512640 135413687 4294945472 18446744073709551615 134597363 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/11734/statm: 33601 29297 117 220 0 33379 0
Current children cumulated CPU time (s) 12.57
Current children cumulated vsize (KiB) 206428

[startup+25.5138 s]
/proc/loadavg: 1.06 1.05 1.01 2/38 11738
/proc/meminfo: memFree=440632/1048576 swapFree=0/0
[pid=11728] ppid=11727 vsize=2576 CPUtime=0
/proc/11728/stat : 11728 (packup2mp4tr-0.) S 11727 11728 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2743035 2637824 275 1283457024 134512640 135304128 4289680672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/11728/statm: 644 275 233 194 0 31 0
[pid=11729] ppid=11728 vsize=67784 CPUtime=23.52
/proc/11729/stat : 11729 (packup) S 11728 11728 1511 34817 1511 4202496 17129 118843 0 0 260 115 1887 90 19 0 1 0 2743035 69410816 16076 1283457024 134512640 134752139 4288330656 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/11729/statm: 16946 16076 333 59 0 16110 0
[pid=11737] ppid=11729 vsize=1672 CPUtime=0
/proc/11737/stat : 11737 (sh) S 11729 11728 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 2745410 1712128 124 1283457024 134512640 134593992 4294226416 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/11737/statm: 418 124 108 20 0 45 0
[pid=11738] ppid=11737 vsize=42620 CPUtime=1.77
/proc/11738/stat : 11738 (minisatp_32) R 11737 11728 1511 34817 1511 4202496 10172 0 0 0 174 3 0 0 25 0 1 0 2745410 43642880 9176 1283457024 134512640 135413687 4292255792 18446744073709551615 134715682 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/11738/statm: 10655 9176 77 220 0 10433 0
Current children cumulated CPU time (s) 25.29
Current children cumulated vsize (KiB) 114652

[startup+51.107 s]
/proc/loadavg: 1.04 1.04 1.00 2/38 11738
/proc/meminfo: memFree=68632/1048576 swapFree=0/0
[pid=11728] ppid=11727 vsize=2576 CPUtime=0
/proc/11728/stat : 11728 (packup2mp4tr-0.) S 11727 11728 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2743035 2637824 275 1283457024 134512640 135304128 4289680672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/11728/statm: 644 275 233 194 0 31 0
[pid=11729] ppid=11728 vsize=67784 CPUtime=23.52
/proc/11729/stat : 11729 (packup) S 11728 11728 1511 34817 1511 4202496 17129 118843 0 0 260 115 1887 90 19 0 1 0 2743035 69410816 16076 1283457024 134512640 134752139 4288330656 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/11729/statm: 16946 16076 333 59 0 16110 0
[pid=11737] ppid=11729 vsize=1672 CPUtime=0
/proc/11737/stat : 11737 (sh) S 11729 11728 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 2745410 1712128 124 1283457024 134512640 134593992 4294226416 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/11737/statm: 418 124 108 20 0 45 0
[pid=11738] ppid=11737 vsize=422992 CPUtime=27.25
/proc/11738/stat : 11738 (minisatp_32) R 11737 11728 1511 34817 1511 4202496 144479 0 0 0 2632 93 0 0 25 0 1 0 2745410 433143808 93054 1283457024 134512640 135413687 4292255792 18446744073709551615 134649535 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/11738/statm: 105748 93054 110 220 0 105526 0
Current children cumulated CPU time (s) 50.77
Current children cumulated vsize (KiB) 495024

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

[startup+51.207 s]
/proc/loadavg: 1.04 1.04 1.00 2/38 11738
/proc/meminfo: memFree=68632/1048576 swapFree=0/0
[pid=11728] ppid=11727 vsize=2576 CPUtime=0
/proc/11728/stat : 11728 (packup2mp4tr-0.) S 11727 11728 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2743035 2637824 275 1283457024 134512640 135304128 4289680672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/11728/statm: 644 275 233 194 0 31 0
[pid=11729] ppid=11728 vsize=67784 CPUtime=23.52
/proc/11729/stat : 11729 (packup) S 11728 11728 1511 34817 1511 4202496 17129 118843 0 0 260 115 1887 90 19 0 1 0 2743035 69410816 16076 1283457024 134512640 134752139 4288330656 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/11729/statm: 16946 16076 333 59 0 16110 0
[pid=11737] ppid=11729 vsize=1672 CPUtime=0
/proc/11737/stat : 11737 (sh) S 11729 11728 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 2745410 1712128 124 1283457024 134512640 134593992 4294226416 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/11737/statm: 418 124 108 20 0 45 0
[pid=11738] ppid=11737 vsize=422992 CPUtime=27.35
/proc/11738/stat : 11738 (minisatp_32) R 11737 11728 1511 34817 1511 4202496 144481 0 0 0 2642 93 0 0 25 0 1 0 2745410 433143808 93056 1283457024 134512640 135413687 4292255792 18446744073709551615 134650344 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/11738/statm: 105748 93056 110 220 0 105526 0
Current children cumulated CPU time (s) 50.87
Current children cumulated vsize (KiB) 495024

[startup+54.4079 s]
/proc/loadavg: 1.04 1.04 1.00 2/38 11738
/proc/meminfo: memFree=99012/1048576 swapFree=0/0
[pid=11728] ppid=11727 vsize=2576 CPUtime=0
/proc/11728/stat : 11728 (packup2mp4tr-0.) S 11727 11728 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2743035 2637824 275 1283457024 134512640 135304128 4289680672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/11728/statm: 644 275 233 194 0 31 0
[pid=11729] ppid=11728 vsize=67784 CPUtime=23.52
/proc/11729/stat : 11729 (packup) S 11728 11728 1511 34817 1511 4202496 17129 118843 0 0 260 115 1887 90 19 0 1 0 2743035 69410816 16076 1283457024 134512640 134752139 4288330656 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/11729/statm: 16946 16076 333 59 0 16110 0
[pid=11737] ppid=11729 vsize=1672 CPUtime=0
/proc/11737/stat : 11737 (sh) S 11729 11728 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 2745410 1712128 124 1283457024 134512640 134593992 4294226416 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/11737/statm: 418 124 108 20 0 45 0
[pid=11738] ppid=11737 vsize=423576 CPUtime=30.54
/proc/11738/stat : 11738 (minisatp_32) R 11737 11728 1511 34817 1511 4202496 145716 0 0 0 2959 95 0 0 25 0 1 0 2745410 433741824 93278 1283457024 134512640 135413687 4292255792 18446744073709551615 134649470 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/11738/statm: 105894 93278 110 220 0 105672 0
Current children cumulated CPU time (s) 54.06
Current children cumulated vsize (KiB) 495608

[startup+57.6089 s]
/proc/loadavg: 1.03 1.04 1.00 2/38 11738
/proc/meminfo: memFree=98268/1048576 swapFree=0/0
[pid=11728] ppid=11727 vsize=2576 CPUtime=0
/proc/11728/stat : 11728 (packup2mp4tr-0.) S 11727 11728 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2743035 2637824 275 1283457024 134512640 135304128 4289680672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/11728/statm: 644 275 233 194 0 31 0
[pid=11729] ppid=11728 vsize=67784 CPUtime=23.52
/proc/11729/stat : 11729 (packup) S 11728 11728 1511 34817 1511 4202496 17129 118843 0 0 260 115 1887 90 19 0 1 0 2743035 69410816 16076 1283457024 134512640 134752139 4288330656 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/11729/statm: 16946 16076 333 59 0 16110 0
[pid=11737] ppid=11729 vsize=1672 CPUtime=0
/proc/11737/stat : 11737 (sh) S 11729 11728 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 2745410 1712128 124 1283457024 134512640 134593992 4294226416 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/11737/statm: 418 124 108 20 0 45 0
[pid=11738] ppid=11737 vsize=424072 CPUtime=33.74
/proc/11738/stat : 11738 (minisatp_32) R 11737 11728 1511 34817 1511 4202496 146527 0 0 0 3278 96 0 0 25 0 1 0 2745410 434249728 93617 1283457024 134512640 135413687 4292255792 18446744073709551615 134650150 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/11738/statm: 106018 93617 110 220 0 105796 0
Current children cumulated CPU time (s) 57.26
Current children cumulated vsize (KiB) 496104

[startup+58.4091 s]
/proc/loadavg: 1.03 1.04 1.00 2/38 11738
/proc/meminfo: memFree=97524/1048576 swapFree=0/0
[pid=11728] ppid=11727 vsize=2576 CPUtime=0
/proc/11728/stat : 11728 (packup2mp4tr-0.) S 11727 11728 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2743035 2637824 275 1283457024 134512640 135304128 4289680672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/11728/statm: 644 275 233 194 0 31 0
[pid=11729] ppid=11728 vsize=67784 CPUtime=23.52
/proc/11729/stat : 11729 (packup) S 11728 11728 1511 34817 1511 4202496 17129 118843 0 0 260 115 1887 90 19 0 1 0 2743035 69410816 16076 1283457024 134512640 134752139 4288330656 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/11729/statm: 16946 16076 333 59 0 16110 0
[pid=11737] ppid=11729 vsize=1672 CPUtime=0
/proc/11737/stat : 11737 (sh) S 11729 11728 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 2745410 1712128 124 1283457024 134512640 134593992 4294226416 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/11737/statm: 418 124 108 20 0 45 0
[pid=11738] ppid=11737 vsize=424072 CPUtime=34.54
/proc/11738/stat : 11738 (minisatp_32) R 11737 11728 1511 34817 1511 4202496 146552 0 0 0 3358 96 0 0 25 0 1 0 2745410 434249728 93642 1283457024 134512640 135413687 4292255792 18446744073709551615 134649456 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/11738/statm: 106018 93642 110 220 0 105796 0
Current children cumulated CPU time (s) 58.06
Current children cumulated vsize (KiB) 496104

[startup+58.8092 s]
/proc/loadavg: 1.03 1.04 1.00 2/38 11738
/proc/meminfo: memFree=97524/1048576 swapFree=0/0
[pid=11728] ppid=11727 vsize=2576 CPUtime=0
/proc/11728/stat : 11728 (packup2mp4tr-0.) S 11727 11728 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2743035 2637824 275 1283457024 134512640 135304128 4289680672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/11728/statm: 644 275 233 194 0 31 0
[pid=11729] ppid=11728 vsize=67784 CPUtime=23.52
/proc/11729/stat : 11729 (packup) S 11728 11728 1511 34817 1511 4202496 17129 118843 0 0 260 115 1887 90 19 0 1 0 2743035 69410816 16076 1283457024 134512640 134752139 4288330656 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/11729/statm: 16946 16076 333 59 0 16110 0
[pid=11737] ppid=11729 vsize=1672 CPUtime=0
/proc/11737/stat : 11737 (sh) S 11729 11728 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 2745410 1712128 124 1283457024 134512640 134593992 4294226416 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/11737/statm: 418 124 108 20 0 45 0
[pid=11738] ppid=11737 vsize=424072 CPUtime=34.94
/proc/11738/stat : 11738 (minisatp_32) R 11737 11728 1511 34817 1511 4202496 147026 0 0 0 3398 96 0 0 25 0 1 0 2745410 434249728 93651 1283457024 134512640 135413687 4292255792 18446744073709551615 134649535 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/11738/statm: 106018 93651 110 220 0 105796 0
Current children cumulated CPU time (s) 58.46
Current children cumulated vsize (KiB) 496104

[startup+59.2133 s]
/proc/loadavg: 1.03 1.04 1.00 2/38 11738
/proc/meminfo: memFree=97524/1048576 swapFree=0/0
[pid=11728] ppid=11727 vsize=2576 CPUtime=0
/proc/11728/stat : 11728 (packup2mp4tr-0.) S 11727 11728 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2743035 2637824 275 1283457024 134512640 135304128 4289680672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/11728/statm: 644 275 233 194 0 31 0
[pid=11729] ppid=11728 vsize=66048 CPUtime=58.88
/proc/11729/stat : 11729 (packup) R 11728 11728 1511 34817 1511 4202496 30201 266030 0 0 267 118 5313 190 18 0 1 0 2743035 67633152 15654 1283457024 134512640 134752139 4288330656 18446744073709551615 134694179 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/11729/statm: 16512 15654 345 59 0 15676 0
Current children cumulated CPU time (s) 58.88
Current children cumulated vsize (KiB) 68624

[startup+59.3035 s]
/proc/loadavg: 1.03 1.04 1.00 2/38 11738
/proc/meminfo: memFree=97524/1048576 swapFree=0/0
[pid=11728] ppid=11727 vsize=2576 CPUtime=0
/proc/11728/stat : 11728 (packup2mp4tr-0.) S 11727 11728 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2743035 2637824 275 1283457024 134512640 135304128 4289680672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/11728/statm: 644 275 233 194 0 31 0
[pid=11729] ppid=11728 vsize=0 CPUtime=58.96
/proc/11729/stat : 11729 (packup) R 11728 11728 1511 34817 1511 4202500 31776 266030 0 0 275 118 5313 190 18 0 1 0 2743035 0 0 1283457024 0 0 0 0 0 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/11729/statm: 0 0 0 0 0 0 0
Current children cumulated CPU time (s) 58.96
Current children cumulated vsize (KiB) 2576

Child status: 0
Real time (s): 59.3058
CPU time (s): 58.9797
CPU user time (s): 55.8875
CPU system time (s): 3.09219
CPU usage (%): 99.4501
Max. virtual memory (cumulated for all children) (KiB): 544344

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 55.8875
system time used= 3.09219
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 298195
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= 25
involuntary context switches= 807

runsolver used 0 second user time and 0 second system time

The end