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/201108251442/packup2mp4pa-0.6/rand176.cudf.s-e-l-s-s.log.runsolver ./packup2mp4pa-0.6 /home/misc2010/data/2011/incremental/s-e-l-s-s//rand176.cudf /home/misc2010/tmp/201108251442/packup2mp4pa-0.6/rand176.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: 0.93 0.88 0.50 5/36 5258
/proc/meminfo: memFree=391028/1048576 swapFree=0/0
[pid=5257] ppid=5256 vsize=2572 CPUtime=0
/proc/5257/stat : 5257 (packup2mp4pa-0.) R 5256 5257 4778 34817 4778 4202496 362 0 0 0 0 0 0 0 25 0 1 0 10005164 2633728 275 1283457024 134512640 135304128 4291544800 18446744073709551615 4294960130 0 65538 4 84480 0 0 0 17 0 0 0 0
/proc/5257/statm: 643 275 233 194 0 30 0
[pid=5258] ppid=5257 vsize=2572 CPUtime=0
/proc/5258/stat : 5258 (packup2mp4pa-0.) R 5257 5257 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 1 0 10005164 2633728 42 1283457024 134512640 135304128 4291544800 18446744073709551615 4294960130 0 65538 4 84480 0 0 0 17 0 0 0 0
/proc/5258/statm: 643 42 0 194 0 30 0

[startup+0.190432 s]
/proc/loadavg: 0.93 0.88 0.50 5/36 5258
/proc/meminfo: memFree=391028/1048576 swapFree=0/0
[pid=5257] ppid=5256 vsize=2572 CPUtime=0
/proc/5257/stat : 5257 (packup2mp4pa-0.) S 5256 5257 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 25 0 1 0 10005164 2633728 275 1283457024 134512640 135304128 4291544800 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/5257/statm: 643 275 233 194 0 30 0
[pid=5258] ppid=5257 vsize=10788 CPUtime=0.17
/proc/5258/stat : 5258 (packup) R 5257 5257 4778 34817 4778 4202496 2186 0 0 0 14 3 0 0 25 0 1 0 10005164 11046912 2115 1283457024 134512640 134752139 4294424944 18446744073709551615 4156916451 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/5258/statm: 2697 2115 286 59 0 1861 0
Current children cumulated CPU time (s) 0.17
Current children cumulated vsize (KiB) 13360

[startup+0.213072 s]
/proc/loadavg: 0.93 0.88 0.50 5/36 5258
/proc/meminfo: memFree=391028/1048576 swapFree=0/0
[pid=5257] ppid=5256 vsize=2572 CPUtime=0
/proc/5257/stat : 5257 (packup2mp4pa-0.) S 5256 5257 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 25 0 1 0 10005164 2633728 275 1283457024 134512640 135304128 4291544800 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/5257/statm: 643 275 233 194 0 30 0
[pid=5258] ppid=5257 vsize=11580 CPUtime=0.19
/proc/5258/stat : 5258 (packup) R 5257 5257 4778 34817 4778 4202496 2387 0 0 0 16 3 0 0 25 0 1 0 10005164 11857920 2316 1283457024 134512640 134752139 4294424944 18446744073709551615 134682090 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/5258/statm: 2895 2316 286 59 0 2059 0
Current children cumulated CPU time (s) 0.19
Current children cumulated vsize (KiB) 14152

[startup+0.303089 s]
/proc/loadavg: 0.93 0.88 0.50 5/36 5258
/proc/meminfo: memFree=391028/1048576 swapFree=0/0
[pid=5257] ppid=5256 vsize=2572 CPUtime=0
/proc/5257/stat : 5257 (packup2mp4pa-0.) S 5256 5257 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 25 0 1 0 10005164 2633728 275 1283457024 134512640 135304128 4291544800 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/5257/statm: 643 275 233 194 0 30 0
[pid=5258] ppid=5257 vsize=14440 CPUtime=0.28
/proc/5258/stat : 5258 (packup) R 5257 5257 4778 34817 4778 4202496 3115 0 0 0 23 5 0 0 25 0 1 0 10005164 14786560 3044 1283457024 134512640 134752139 4294424944 18446744073709551615 134682011 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/5258/statm: 3610 3044 286 59 0 2774 0
Current children cumulated CPU time (s) 0.28
Current children cumulated vsize (KiB) 17012

[startup+0.703147 s]
/proc/loadavg: 0.93 0.88 0.50 5/36 5258
/proc/meminfo: memFree=391028/1048576 swapFree=0/0
[pid=5257] ppid=5256 vsize=2572 CPUtime=0
/proc/5257/stat : 5257 (packup2mp4pa-0.) S 5256 5257 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 25 0 1 0 10005164 2633728 275 1283457024 134512640 135304128 4291544800 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/5257/statm: 643 275 233 194 0 30 0
[pid=5258] ppid=5257 vsize=25868 CPUtime=0.68
/proc/5258/stat : 5258 (packup) R 5257 5257 4778 34817 4778 4202496 5968 0 0 0 63 5 0 0 25 0 1 0 10005164 26488832 5897 1283457024 134512640 134752139 4294424944 18446744073709551615 134683324 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/5258/statm: 6467 5897 286 59 0 5631 0
Current children cumulated CPU time (s) 0.68
Current children cumulated vsize (KiB) 28440

[startup+1.50329 s]
/proc/loadavg: 0.93 0.88 0.50 2/36 5259
/proc/meminfo: memFree=358544/1048576 swapFree=0/0
[pid=5257] ppid=5256 vsize=2572 CPUtime=0
/proc/5257/stat : 5257 (packup2mp4pa-0.) S 5256 5257 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 25 0 1 0 10005164 2633728 275 1283457024 134512640 135304128 4291544800 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/5257/statm: 643 275 233 194 0 30 0
[pid=5258] ppid=5257 vsize=52208 CPUtime=1.49
/proc/5258/stat : 5258 (packup) R 5257 5257 4778 34817 4778 4202496 12618 0 0 0 142 7 0 0 25 0 1 0 10005164 53460992 12498 1283457024 134512640 134752139 4294424944 18446744073709551615 134646423 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/5258/statm: 13052 12498 316 59 0 12216 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 54780

[startup+3.10352 s]
/proc/loadavg: 0.93 0.88 0.50 2/38 5261
/proc/meminfo: memFree=328008/1048576 swapFree=0/0
[pid=5257] ppid=5256 vsize=2572 CPUtime=0
/proc/5257/stat : 5257 (packup2mp4pa-0.) S 5256 5257 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 25 0 1 0 10005164 2633728 275 1283457024 134512640 135304128 4291544800 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/5257/statm: 643 275 233 194 0 30 0
[pid=5258] ppid=5257 vsize=57948 CPUtime=1.89
/proc/5258/stat : 5258 (packup) S 5257 5257 4778 34817 4778 4202496 14051 0 0 0 164 25 0 0 25 0 1 0 10005164 59338752 13691 1283457024 134512640 134752139 4294424944 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/5258/statm: 14487 13691 324 59 0 13651 0
[pid=5260] ppid=5258 vsize=1668 CPUtime=0
/proc/5260/stat : 5260 (sh) S 5258 5257 4778 34817 4778 4202496 146 0 0 0 0 0 0 0 25 0 1 0 10005354 1708032 123 1283457024 134512640 134593992 4294890128 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/5260/statm: 417 123 108 20 0 44 0
[pid=5261] ppid=5260 vsize=28516 CPUtime=1.19
/proc/5261/stat : 5261 (minisatp_32) R 5260 5257 4778 34817 4778 4202496 6502 0 0 0 113 6 0 0 25 0 1 0 10005355 29200384 5870 1283457024 134512640 135413687 4289664432 18446744073709551615 134988446 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/5261/statm: 7129 5870 85 220 0 6907 0
Current children cumulated CPU time (s) 3.08
Current children cumulated vsize (KiB) 90704

[startup+6.31401 s]
/proc/loadavg: 0.93 0.88 0.50 2/38 5263
/proc/meminfo: memFree=309540/1048576 swapFree=0/0
[pid=5257] ppid=5256 vsize=2572 CPUtime=0
/proc/5257/stat : 5257 (packup2mp4pa-0.) S 5256 5257 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 25 0 1 0 10005164 2633728 275 1283457024 134512640 135304128 4291544800 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/5257/statm: 643 275 233 194 0 30 0
[pid=5258] ppid=5257 vsize=57952 CPUtime=4.17
/proc/5258/stat : 5258 (packup) S 5257 5257 4778 34817 4778 4202496 14120 13101 0 0 182 41 175 19 18 0 1 0 10005164 59342848 13700 1283457024 134512640 134752139 4294424944 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/5258/statm: 14488 13700 332 59 0 13652 0
[pid=5262] ppid=5258 vsize=1672 CPUtime=0
/proc/5262/stat : 5262 (sh) S 5258 5257 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 10005583 1712128 123 1283457024 134512640 134593992 4288838864 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/5262/statm: 418 123 108 20 0 45 0
[pid=5263] ppid=5262 vsize=66692 CPUtime=2.12
/proc/5263/stat : 5263 (minisatp_32) R 5262 5257 4778 34817 4778 4202496 20262 0 0 0 188 24 0 0 25 0 1 0 10005584 68292608 15049 1283457024 134512640 135413687 4289209664 18446744073709551615 134526684 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/5263/statm: 16673 15049 108 220 0 16451 0
Current children cumulated CPU time (s) 6.29
Current children cumulated vsize (KiB) 128888

[startup+12.7055 s]
/proc/loadavg: 0.94 0.89 0.50 2/38 5263
/proc/meminfo: memFree=153300/1048576 swapFree=0/0
[pid=5257] ppid=5256 vsize=2572 CPUtime=0
/proc/5257/stat : 5257 (packup2mp4pa-0.) S 5256 5257 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 25 0 1 0 10005164 2633728 275 1283457024 134512640 135304128 4291544800 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/5257/statm: 643 275 233 194 0 30 0
[pid=5258] ppid=5257 vsize=57952 CPUtime=4.17
/proc/5258/stat : 5258 (packup) S 5257 5257 4778 34817 4778 4202496 14120 13101 0 0 182 41 175 19 18 0 1 0 10005164 59342848 13700 1283457024 134512640 134752139 4294424944 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/5258/statm: 14488 13700 332 59 0 13652 0
[pid=5262] ppid=5258 vsize=1672 CPUtime=0
/proc/5262/stat : 5262 (sh) S 5258 5257 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 10005583 1712128 123 1283457024 134512640 134593992 4288838864 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/5262/statm: 418 123 108 20 0 45 0
[pid=5263] ppid=5262 vsize=192744 CPUtime=8.5
/proc/5263/stat : 5263 (minisatp_32) R 5262 5257 4778 34817 4778 4202496 61480 0 0 0 804 46 0 0 25 0 1 0 10005584 197369856 41188 1283457024 134512640 135413687 4289209664 18446744073709551615 134649555 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/5263/statm: 48186 41188 109 220 0 47964 0
Current children cumulated CPU time (s) 12.67
Current children cumulated vsize (KiB) 254940

[startup+25.5119 s]
/proc/loadavg: 0.95 0.89 0.51 2/38 5263
/proc/meminfo: memFree=79148/1048576 swapFree=0/0
[pid=5257] ppid=5256 vsize=2572 CPUtime=0
/proc/5257/stat : 5257 (packup2mp4pa-0.) S 5256 5257 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 25 0 1 0 10005164 2633728 275 1283457024 134512640 135304128 4291544800 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/5257/statm: 643 275 233 194 0 30 0
[pid=5258] ppid=5257 vsize=57952 CPUtime=4.17
/proc/5258/stat : 5258 (packup) S 5257 5257 4778 34817 4778 4202496 14120 13101 0 0 182 41 175 19 18 0 1 0 10005164 59342848 13700 1283457024 134512640 134752139 4294424944 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/5258/statm: 14488 13700 332 59 0 13652 0
[pid=5262] ppid=5258 vsize=1672 CPUtime=0
/proc/5262/stat : 5262 (sh) S 5258 5257 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 10005583 1712128 123 1283457024 134512640 134593992 4288838864 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/5262/statm: 418 123 108 20 0 45 0
[pid=5263] ppid=5262 vsize=284592 CPUtime=21.29
/proc/5263/stat : 5263 (minisatp_32) R 5262 5257 4778 34817 4778 4202496 102066 0 0 0 2063 66 0 0 25 0 1 0 10005584 291422208 63707 1283457024 134512640 135413687 4289209664 18446744073709551615 134649535 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/5263/statm: 71148 63707 110 220 0 70926 0
Current children cumulated CPU time (s) 25.46
Current children cumulated vsize (KiB) 346788

[startup+51.1087 s]
/proc/loadavg: 0.97 0.90 0.52 2/38 5263
/proc/meminfo: memFree=40708/1048576 swapFree=0/0
[pid=5257] ppid=5256 vsize=2572 CPUtime=0
/proc/5257/stat : 5257 (packup2mp4pa-0.) S 5256 5257 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 25 0 1 0 10005164 2633728 275 1283457024 134512640 135304128 4291544800 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/5257/statm: 643 275 233 194 0 30 0
[pid=5258] ppid=5257 vsize=57952 CPUtime=4.17
/proc/5258/stat : 5258 (packup) S 5257 5257 4778 34817 4778 4202496 14120 13101 0 0 182 41 175 19 18 0 1 0 10005164 59342848 13700 1283457024 134512640 134752139 4294424944 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/5258/statm: 14488 13700 332 59 0 13652 0
[pid=5262] ppid=5258 vsize=1672 CPUtime=0
/proc/5262/stat : 5262 (sh) S 5258 5257 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 10005583 1712128 123 1283457024 134512640 134593992 4288838864 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/5262/statm: 418 123 108 20 0 45 0
[pid=5263] ppid=5262 vsize=318932 CPUtime=46.85
/proc/5263/stat : 5263 (minisatp_32) R 5262 5257 4778 34817 4778 4202496 115589 0 0 0 4613 72 0 0 25 0 1 0 10005584 326586368 73270 1283457024 134512640 135413687 4289209664 18446744073709551615 134649535 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/5263/statm: 79733 73270 110 220 0 79511 0
Current children cumulated CPU time (s) 51.02
Current children cumulated vsize (KiB) 381128

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

[startup+51.2087 s]
/proc/loadavg: 0.97 0.90 0.52 2/38 5263
/proc/meminfo: memFree=40708/1048576 swapFree=0/0
[pid=5257] ppid=5256 vsize=2572 CPUtime=0
/proc/5257/stat : 5257 (packup2mp4pa-0.) S 5256 5257 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 25 0 1 0 10005164 2633728 275 1283457024 134512640 135304128 4291544800 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/5257/statm: 643 275 233 194 0 30 0
[pid=5258] ppid=5257 vsize=57952 CPUtime=4.17
/proc/5258/stat : 5258 (packup) S 5257 5257 4778 34817 4778 4202496 14120 13101 0 0 182 41 175 19 18 0 1 0 10005164 59342848 13700 1283457024 134512640 134752139 4294424944 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/5258/statm: 14488 13700 332 59 0 13652 0
[pid=5262] ppid=5258 vsize=1672 CPUtime=0
/proc/5262/stat : 5262 (sh) S 5258 5257 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 10005583 1712128 123 1283457024 134512640 134593992 4288838864 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/5262/statm: 418 123 108 20 0 45 0
[pid=5263] ppid=5262 vsize=318932 CPUtime=46.95
/proc/5263/stat : 5263 (minisatp_32) R 5262 5257 4778 34817 4778 4202496 115591 0 0 0 4623 72 0 0 25 0 1 0 10005584 326586368 73272 1283457024 134512640 135413687 4289209664 18446744073709551615 134649568 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/5263/statm: 79733 73272 110 220 0 79511 0
Current children cumulated CPU time (s) 51.12
Current children cumulated vsize (KiB) 381128

[startup+64.0122 s]
/proc/loadavg: 0.97 0.90 0.53 2/37 5263
/proc/meminfo: memFree=45676/1048576 swapFree=0/0
[pid=5257] ppid=5256 vsize=2572 CPUtime=0
/proc/5257/stat : 5257 (packup2mp4pa-0.) S 5256 5257 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 25 0 1 0 10005164 2633728 275 1283457024 134512640 135304128 4291544800 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/5257/statm: 643 275 233 194 0 30 0
[pid=5258] ppid=5257 vsize=57952 CPUtime=4.17
/proc/5258/stat : 5258 (packup) S 5257 5257 4778 34817 4778 4202496 14120 13101 0 0 182 41 175 19 18 0 1 0 10005164 59342848 13700 1283457024 134512640 134752139 4294424944 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/5258/statm: 14488 13700 332 59 0 13652 0
[pid=5262] ppid=5258 vsize=1672 CPUtime=0
/proc/5262/stat : 5262 (sh) S 5258 5257 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 10005583 1712128 123 1283457024 134512640 134593992 4288838864 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/5262/statm: 418 123 108 20 0 45 0
[pid=5263] ppid=5262 vsize=319384 CPUtime=59.75
/proc/5263/stat : 5263 (minisatp_32) R 5262 5257 4778 34817 4778 4202496 122230 0 0 0 5901 74 0 0 25 0 1 0 10005584 327049216 72169 1283457024 134512640 135413687 4289209664 18446744073709551615 134650062 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/5263/statm: 79846 72169 110 220 0 79624 0
Current children cumulated CPU time (s) 63.92
Current children cumulated vsize (KiB) 381580

[startup+70.4044 s]
/proc/loadavg: 0.98 0.90 0.53 2/37 5263
/proc/meminfo: memFree=44188/1048576 swapFree=0/0
[pid=5257] ppid=5256 vsize=2572 CPUtime=0
/proc/5257/stat : 5257 (packup2mp4pa-0.) S 5256 5257 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 25 0 1 0 10005164 2633728 275 1283457024 134512640 135304128 4291544800 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/5257/statm: 643 275 233 194 0 30 0
[pid=5258] ppid=5257 vsize=57952 CPUtime=4.17
/proc/5258/stat : 5258 (packup) S 5257 5257 4778 34817 4778 4202496 14120 13101 0 0 182 41 175 19 18 0 1 0 10005164 59342848 13700 1283457024 134512640 134752139 4294424944 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/5258/statm: 14488 13700 332 59 0 13652 0
[pid=5262] ppid=5258 vsize=1672 CPUtime=0
/proc/5262/stat : 5262 (sh) S 5258 5257 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 10005583 1712128 123 1283457024 134512640 134593992 4288838864 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/5262/statm: 418 123 108 20 0 45 0
[pid=5263] ppid=5262 vsize=319732 CPUtime=66.15
/proc/5263/stat : 5263 (minisatp_32) R 5262 5257 4778 34817 4778 4202496 122935 0 0 0 6541 74 0 0 25 0 1 0 10005584 327405568 72404 1283457024 134512640 135413687 4289209664 18446744073709551615 134649456 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/5263/statm: 79933 72404 110 220 0 79711 0
Current children cumulated CPU time (s) 70.32
Current children cumulated vsize (KiB) 381928

[startup+76.8062 s]
/proc/loadavg: 0.98 0.90 0.53 2/37 5263
/proc/meminfo: memFree=44188/1048576 swapFree=0/0
[pid=5257] ppid=5256 vsize=2572 CPUtime=0
/proc/5257/stat : 5257 (packup2mp4pa-0.) S 5256 5257 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 25 0 1 0 10005164 2633728 275 1283457024 134512640 135304128 4291544800 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/5257/statm: 643 275 233 194 0 30 0
[pid=5258] ppid=5257 vsize=57952 CPUtime=4.17
/proc/5258/stat : 5258 (packup) S 5257 5257 4778 34817 4778 4202496 14120 13101 0 0 182 41 175 19 18 0 1 0 10005164 59342848 13700 1283457024 134512640 134752139 4294424944 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/5258/statm: 14488 13700 332 59 0 13652 0
[pid=5262] ppid=5258 vsize=1672 CPUtime=0
/proc/5262/stat : 5262 (sh) S 5258 5257 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 10005583 1712128 123 1283457024 134512640 134593992 4288838864 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/5262/statm: 418 123 108 20 0 45 0
[pid=5263] ppid=5262 vsize=319732 CPUtime=72.55
/proc/5263/stat : 5263 (minisatp_32) R 5262 5257 4778 34817 4778 4202496 123096 0 0 0 7181 74 0 0 25 0 1 0 10005584 327405568 72560 1283457024 134512640 135413687 4289209664 18446744073709551615 134649535 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/5263/statm: 79933 72560 110 220 0 79711 0
Current children cumulated CPU time (s) 76.72
Current children cumulated vsize (KiB) 381928

[startup+78.4064 s]
/proc/loadavg: 0.98 0.90 0.53 2/37 5263
/proc/meminfo: memFree=43940/1048576 swapFree=0/0
[pid=5257] ppid=5256 vsize=2572 CPUtime=0
/proc/5257/stat : 5257 (packup2mp4pa-0.) S 5256 5257 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 25 0 1 0 10005164 2633728 275 1283457024 134512640 135304128 4291544800 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/5257/statm: 643 275 233 194 0 30 0
[pid=5258] ppid=5257 vsize=57952 CPUtime=4.17
/proc/5258/stat : 5258 (packup) S 5257 5257 4778 34817 4778 4202496 14120 13101 0 0 182 41 175 19 18 0 1 0 10005164 59342848 13700 1283457024 134512640 134752139 4294424944 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/5258/statm: 14488 13700 332 59 0 13652 0
[pid=5262] ppid=5258 vsize=1672 CPUtime=0
/proc/5262/stat : 5262 (sh) S 5258 5257 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 10005583 1712128 123 1283457024 134512640 134593992 4288838864 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/5262/statm: 418 123 108 20 0 45 0
[pid=5263] ppid=5262 vsize=319732 CPUtime=74.15
/proc/5263/stat : 5263 (minisatp_32) R 5262 5257 4778 34817 4778 4202496 123145 0 0 0 7341 74 0 0 25 0 1 0 10005584 327405568 72603 1283457024 134512640 135413687 4289209664 18446744073709551615 134649456 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/5263/statm: 79933 72603 110 220 0 79711 0
Current children cumulated CPU time (s) 78.32
Current children cumulated vsize (KiB) 381928

[startup+79.2065 s]
/proc/loadavg: 0.98 0.90 0.53 2/37 5263
/proc/meminfo: memFree=43816/1048576 swapFree=0/0
[pid=5257] ppid=5256 vsize=2572 CPUtime=0
/proc/5257/stat : 5257 (packup2mp4pa-0.) S 5256 5257 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 25 0 1 0 10005164 2633728 275 1283457024 134512640 135304128 4291544800 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/5257/statm: 643 275 233 194 0 30 0
[pid=5258] ppid=5257 vsize=57952 CPUtime=4.17
/proc/5258/stat : 5258 (packup) S 5257 5257 4778 34817 4778 4202496 14120 13101 0 0 182 41 175 19 18 0 1 0 10005164 59342848 13700 1283457024 134512640 134752139 4294424944 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/5258/statm: 14488 13700 332 59 0 13652 0
[pid=5262] ppid=5258 vsize=1672 CPUtime=0
/proc/5262/stat : 5262 (sh) S 5258 5257 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 10005583 1712128 123 1283457024 134512640 134593992 4288838864 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/5262/statm: 418 123 108 20 0 45 0
[pid=5263] ppid=5262 vsize=319732 CPUtime=74.95
/proc/5263/stat : 5263 (minisatp_32) R 5262 5257 4778 34817 4778 4202496 123173 0 0 0 7421 74 0 0 25 0 1 0 10005584 327405568 72627 1283457024 134512640 135413687 4289209664 18446744073709551615 134649535 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/5263/statm: 79933 72627 110 220 0 79711 0
Current children cumulated CPU time (s) 79.12
Current children cumulated vsize (KiB) 381928

[startup+80.0069 s]
/proc/loadavg: 0.98 0.90 0.53 2/37 5263
/proc/meminfo: memFree=43816/1048576 swapFree=0/0
[pid=5257] ppid=5256 vsize=2572 CPUtime=0
/proc/5257/stat : 5257 (packup2mp4pa-0.) S 5256 5257 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 25 0 1 0 10005164 2633728 275 1283457024 134512640 135304128 4291544800 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/5257/statm: 643 275 233 194 0 30 0
[pid=5258] ppid=5257 vsize=57952 CPUtime=4.17
/proc/5258/stat : 5258 (packup) S 5257 5257 4778 34817 4778 4202496 14120 13101 0 0 182 41 175 19 18 0 1 0 10005164 59342848 13700 1283457024 134512640 134752139 4294424944 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/5258/statm: 14488 13700 332 59 0 13652 0
[pid=5262] ppid=5258 vsize=1672 CPUtime=0
/proc/5262/stat : 5262 (sh) S 5258 5257 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 10005583 1712128 123 1283457024 134512640 134593992 4288838864 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/5262/statm: 418 123 108 20 0 45 0
[pid=5263] ppid=5262 vsize=320536 CPUtime=75.75
/proc/5263/stat : 5263 (minisatp_32) R 5262 5257 4778 34817 4778 4202496 123899 0 0 0 7500 75 0 0 25 0 1 0 10005584 328228864 72825 1283457024 134512640 135413687 4289209664 18446744073709551615 134651774 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/5263/statm: 80134 72825 110 220 0 79912 0
Current children cumulated CPU time (s) 79.92
Current children cumulated vsize (KiB) 382732

[startup+80.4125 s]
/proc/loadavg: 0.98 0.91 0.54 2/37 5263
/proc/meminfo: memFree=55348/1048576 swapFree=0/0
[pid=5257] ppid=5256 vsize=2572 CPUtime=0
/proc/5257/stat : 5257 (packup2mp4pa-0.) S 5256 5257 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 25 0 1 0 10005164 2633728 275 1283457024 134512640 135304128 4291544800 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/5257/statm: 643 275 233 194 0 30 0
[pid=5258] ppid=5257 vsize=57952 CPUtime=4.17
/proc/5258/stat : 5258 (packup) S 5257 5257 4778 34817 4778 4202496 14120 13101 0 0 182 41 175 19 18 0 1 0 10005164 59342848 13700 1283457024 134512640 134752139 4294424944 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/5258/statm: 14488 13700 332 59 0 13652 0
[pid=5262] ppid=5258 vsize=1672 CPUtime=0
/proc/5262/stat : 5262 (sh) S 5258 5257 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 10005583 1712128 123 1283457024 134512640 134593992 4288838864 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/5262/statm: 418 123 108 20 0 45 0
[pid=5263] ppid=5262 vsize=0 CPUtime=76.15
/proc/5263/stat : 5263 (minisatp_32) R 5262 5257 4778 34817 4778 4202500 123914 0 0 0 7538 77 0 0 25 0 1 0 10005584 0 0 1283457024 0 0 0 0 0 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/5263/statm: 0 0 0 0 0 0 0
Current children cumulated CPU time (s) 80.32
Current children cumulated vsize (KiB) 62196

[startup+80.5123 s]
/proc/loadavg: 0.98 0.91 0.54 2/37 5263
/proc/meminfo: memFree=55348/1048576 swapFree=0/0
[pid=5257] ppid=5256 vsize=2572 CPUtime=0
/proc/5257/stat : 5257 (packup2mp4pa-0.) S 5256 5257 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 25 0 1 0 10005164 2633728 275 1283457024 134512640 135304128 4291544800 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/5257/statm: 643 275 233 194 0 30 0
[pid=5258] ppid=5257 vsize=54684 CPUtime=80.42
/proc/5258/stat : 5258 (packup) R 5257 5257 4778 34817 4778 4202496 26195 137162 0 0 189 43 7714 96 18 0 1 0 10005164 55996416 13134 1283457024 134512640 134752139 4294424944 18446744073709551615 4156904878 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/5258/statm: 13671 13134 345 59 0 12835 0
Current children cumulated CPU time (s) 80.42
Current children cumulated vsize (KiB) 57256

Child status: 0
Real time (s): 80.5666
CPU time (s): 80.493
CPU user time (s): 79.0809
CPU system time (s): 1.41209
CPU usage (%): 99.9087
Max. virtual memory (cumulated for all children) (KiB): 411932

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 79.0809
system time used= 1.41209
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 164265
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= 12
involuntary context switches= 1009

runsolver used 0.008 second user time and 0 second system time

The end