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/26f3d4cc-d470-11df-9e6c-00163e3d3b7c.cudf.dudf-real.log.runsolver ./packup2mp4tr-0.6 /home/misc2010/data/2011/dudf-real//26f3d4cc-d470-11df-9e6c-00163e3d3b7c.cudf /home/misc2010/tmp/201108241238/packup2mp4tr-0.6/26f3d4cc-d470-11df-9e6c-00163e3d3b7c.cudf.dudf-real.result 

Enforcing CPUTime limit (soft limit, will send signal-name then SIGKILL): 290 seconds
Enforcing CPUTime limit (hard limit, will send SIGXCPU): 320 seconds
Enforcing VSIZE limit (soft limit, will send signal-name then SIGKILL): 1150976 KiB
Enforcing VSIZE limit (hard limit, stack expansion will fail with SIGSEGV, brk() and mmap() will return ENOMEM): 1202176 KiB
Current StackSize limit: 8192 KiB


[startup+0 s]
/proc/loadavg: 1.30 1.17 1.06 3/35 9373
/proc/meminfo: memFree=444856/1048576 swapFree=0/0
[pid=9372] ppid=9371 vsize=2576 CPUtime=0
/proc/9372/stat : 9372 (packup2mp4tr-0.) R 9371 9372 1511 34817 1511 4202496 361 0 0 0 0 0 0 0 25 0 1 0 2147629 2637824 275 1283457024 134512640 135304128 4290397600 18446744073709551615 4294960130 0 65538 4 84480 0 0 0 17 0 0 0 0
/proc/9372/statm: 644 275 233 194 0 31 0
[pid=9373] ppid=9372 vsize=2576 CPUtime=0
/proc/9373/stat : 9373 (packup2mp4tr-0.) R 9372 9372 1511 34817 1511 4202560 0 0 0 0 0 0 0 0 25 0 1 0 2147629 2637824 42 1283457024 134512640 135304128 4290397600 18446744073709551615 4294960130 0 65538 4 84480 0 0 0 17 0 0 0 0
/proc/9373/statm: 644 42 0 194 0 31 0

[startup+0.129381 s]
/proc/loadavg: 1.30 1.17 1.06 3/35 9373
/proc/meminfo: memFree=444856/1048576 swapFree=0/0
[pid=9372] ppid=9371 vsize=2576 CPUtime=0
/proc/9372/stat : 9372 (packup2mp4tr-0.) S 9371 9372 1511 34817 1511 4202496 379 0 0 0 0 0 0 0 25 0 1 0 2147629 2637824 275 1283457024 134512640 135304128 4290397600 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9372/statm: 644 275 233 194 0 31 0
[pid=9373] ppid=9372 vsize=8112 CPUtime=0.12
/proc/9373/stat : 9373 (packup) R 9372 9372 1511 34817 1511 4202496 1520 0 0 0 12 0 0 0 25 0 1 0 2147629 8306688 1448 1283457024 134512640 134752139 4289819872 18446744073709551615 134681674 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/9373/statm: 2028 1448 286 59 0 1192 0
Current children cumulated CPU time (s) 0.12
Current children cumulated vsize (KiB) 10688

[startup+0.209397 s]
/proc/loadavg: 1.30 1.17 1.06 3/35 9373
/proc/meminfo: memFree=444856/1048576 swapFree=0/0
[pid=9372] ppid=9371 vsize=2576 CPUtime=0
/proc/9372/stat : 9372 (packup2mp4tr-0.) S 9371 9372 1511 34817 1511 4202496 379 0 0 0 0 0 0 0 25 0 1 0 2147629 2637824 275 1283457024 134512640 135304128 4290397600 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9372/statm: 644 275 233 194 0 31 0
[pid=9373] ppid=9372 vsize=10488 CPUtime=0.2
/proc/9373/stat : 9373 (packup) R 9372 9372 1511 34817 1511 4202496 2121 0 0 0 20 0 0 0 25 0 1 0 2147629 10739712 2049 1283457024 134512640 134752139 4289819872 18446744073709551615 4156832431 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/9373/statm: 2622 2049 286 59 0 1786 0
Current children cumulated CPU time (s) 0.2
Current children cumulated vsize (KiB) 13064

[startup+0.309421 s]
/proc/loadavg: 1.30 1.17 1.06 3/35 9373
/proc/meminfo: memFree=444856/1048576 swapFree=0/0
[pid=9372] ppid=9371 vsize=2576 CPUtime=0
/proc/9372/stat : 9372 (packup2mp4tr-0.) S 9371 9372 1511 34817 1511 4202496 379 0 0 0 0 0 0 0 25 0 1 0 2147629 2637824 275 1283457024 134512640 135304128 4290397600 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9372/statm: 644 275 233 194 0 31 0
[pid=9373] ppid=9372 vsize=13340 CPUtime=0.3
/proc/9373/stat : 9373 (packup) R 9372 9372 1511 34817 1511 4202496 2827 0 0 0 30 0 0 0 25 0 1 0 2147629 13660160 2755 1283457024 134512640 134752139 4289819872 18446744073709551615 134681672 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/9373/statm: 3335 2755 286 59 0 2499 0
Current children cumulated CPU time (s) 0.3
Current children cumulated vsize (KiB) 15916

[startup+0.709513 s]
/proc/loadavg: 1.30 1.17 1.06 3/35 9373
/proc/meminfo: memFree=444856/1048576 swapFree=0/0
[pid=9372] ppid=9371 vsize=2576 CPUtime=0
/proc/9372/stat : 9372 (packup2mp4tr-0.) S 9371 9372 1511 34817 1511 4202496 379 0 0 0 0 0 0 0 25 0 1 0 2147629 2637824 275 1283457024 134512640 135304128 4290397600 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9372/statm: 644 275 233 194 0 31 0
[pid=9373] ppid=9372 vsize=23312 CPUtime=0.7
/proc/9373/stat : 9373 (packup) R 9372 9372 1511 34817 1511 4202496 5334 0 0 0 70 0 0 0 25 0 1 0 2147629 23871488 5262 1283457024 134512640 134752139 4289819872 18446744073709551615 134681659 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/9373/statm: 5828 5262 286 59 0 4992 0
Current children cumulated CPU time (s) 0.7
Current children cumulated vsize (KiB) 25888

[startup+1.50971 s]
/proc/loadavg: 1.35 1.18 1.06 2/35 9374
/proc/meminfo: memFree=411124/1048576 swapFree=0/0
[pid=9372] ppid=9371 vsize=2576 CPUtime=0
/proc/9372/stat : 9372 (packup2mp4tr-0.) S 9371 9372 1511 34817 1511 4202496 379 0 0 0 0 0 0 0 25 0 1 0 2147629 2637824 275 1283457024 134512640 135304128 4290397600 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9372/statm: 644 275 233 194 0 31 0
[pid=9373] ppid=9372 vsize=44796 CPUtime=1.5
/proc/9373/stat : 9373 (packup) R 9372 9372 1511 34817 1511 4202496 10828 0 0 0 133 17 0 0 25 0 1 0 2147629 45871104 10463 1283457024 134512640 134752139 4289819872 18446744073709551615 4294960130 0 65536 18950 8192 0 0 0 17 0 0 0 0
/proc/9373/statm: 11199 10463 324 59 0 10363 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 47372

[startup+3.11009 s]
/proc/loadavg: 1.35 1.18 1.06 2/37 9376
/proc/meminfo: memFree=386540/1048576 swapFree=0/0
[pid=9372] ppid=9371 vsize=2576 CPUtime=0
/proc/9372/stat : 9372 (packup2mp4tr-0.) S 9371 9372 1511 34817 1511 4202496 379 0 0 0 0 0 0 0 25 0 1 0 2147629 2637824 275 1283457024 134512640 135304128 4290397600 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9372/statm: 644 275 233 194 0 31 0
[pid=9373] ppid=9372 vsize=44796 CPUtime=1.5
/proc/9373/stat : 9373 (packup) S 9372 9372 1511 34817 1511 4202496 10830 0 0 0 133 17 0 0 25 0 1 0 2147629 45871104 10464 1283457024 134512640 134752139 4289819872 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/9373/statm: 11199 10464 325 59 0 10363 0
[pid=9375] ppid=9373 vsize=1668 CPUtime=0
/proc/9375/stat : 9375 (sh) S 9373 9372 1511 34817 1511 4202496 145 0 0 0 0 0 0 0 25 0 1 0 2147780 1708032 123 1283457024 134512640 134593992 4291928000 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9375/statm: 417 123 108 20 0 44 0
[pid=9376] ppid=9375 vsize=48480 CPUtime=1.59
/proc/9376/stat : 9376 (minisatp_32) R 9375 9372 1511 34817 1511 4202496 14901 0 0 0 137 22 0 0 25 0 1 0 2147781 49643520 11108 1283457024 134512640 135413687 4291000048 18446744073709551615 134661798 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/9376/statm: 12120 11108 106 220 0 11898 0
Current children cumulated CPU time (s) 3.09
Current children cumulated vsize (KiB) 97520

[startup+6.31095 s]
/proc/loadavg: 1.33 1.18 1.06 2/37 9378
/proc/meminfo: memFree=385920/1048576 swapFree=0/0
[pid=9372] ppid=9371 vsize=2576 CPUtime=0
/proc/9372/stat : 9372 (packup2mp4tr-0.) S 9371 9372 1511 34817 1511 4202496 379 0 0 0 0 0 0 0 25 0 1 0 2147629 2637824 275 1283457024 134512640 135304128 4290397600 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9372/statm: 644 275 233 194 0 31 0
[pid=9373] ppid=9372 vsize=44800 CPUtime=4.78
/proc/9373/stat : 9373 (packup) S 9372 9372 1511 34817 1511 4202496 10946 28142 0 0 142 38 268 30 18 0 1 0 2147629 45875200 10482 1283457024 134512640 134752139 4289819872 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/9373/statm: 11200 10482 333 59 0 10364 0
[pid=9377] ppid=9373 vsize=1676 CPUtime=0
/proc/9377/stat : 9377 (sh) S 9373 9372 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 18 0 1 0 2148109 1716224 124 1283457024 134512640 134593992 4289271088 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9377/statm: 419 124 108 20 0 46 0
[pid=9378] ppid=9377 vsize=42812 CPUtime=1.5
/proc/9378/stat : 9378 (minisatp_32) R 9377 9372 1511 34817 1511 4202496 12525 0 0 0 134 16 0 0 25 0 1 0 2148110 43839488 9828 1283457024 134512640 135413687 4289078560 18446744073709551615 134967014 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/9378/statm: 10703 9828 107 220 0 10481 0
Current children cumulated CPU time (s) 6.28
Current children cumulated vsize (KiB) 91864

[startup+12.7134 s]
/proc/loadavg: 1.30 1.18 1.06 2/37 9380
/proc/meminfo: memFree=336328/1048576 swapFree=0/0
[pid=9372] ppid=9371 vsize=2576 CPUtime=0
/proc/9372/stat : 9372 (packup2mp4tr-0.) S 9371 9372 1511 34817 1511 4202496 379 0 0 0 0 0 0 0 25 0 1 0 2147629 2637824 275 1283457024 134512640 135304128 4290397600 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9372/statm: 644 275 233 194 0 31 0
[pid=9373] ppid=9372 vsize=44804 CPUtime=9.53
/proc/9373/stat : 9373 (packup) S 9372 9372 1511 34817 1511 4202496 11056 72770 0 0 156 55 684 58 18 0 1 0 2147629 45879296 10492 1283457024 134512640 134752139 4289819872 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/9373/statm: 11201 10492 333 59 0 10365 0
[pid=9379] ppid=9373 vsize=1672 CPUtime=0
/proc/9379/stat : 9379 (sh) S 9373 9372 1511 34817 1511 4202496 145 0 0 0 0 0 0 0 18 0 1 0 2148584 1712128 123 1283457024 134512640 134593992 4288400480 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9379/statm: 418 123 108 20 0 45 0
[pid=9380] ppid=9379 vsize=74236 CPUtime=3.14
/proc/9380/stat : 9380 (minisatp_32) R 9379 9372 1511 34817 1511 4202496 26504 0 0 0 294 20 0 0 25 0 1 0 2148584 76017664 16121 1283457024 134512640 135413687 4291862480 18446744073709551615 134572355 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/9380/statm: 18559 16121 107 220 0 18337 0
Current children cumulated CPU time (s) 12.67
Current children cumulated vsize (KiB) 123288

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

[startup+12.8135 s]
/proc/loadavg: 1.30 1.18 1.06 2/37 9380
/proc/meminfo: memFree=336328/1048576 swapFree=0/0
[pid=9372] ppid=9371 vsize=2576 CPUtime=0
/proc/9372/stat : 9372 (packup2mp4tr-0.) S 9371 9372 1511 34817 1511 4202496 379 0 0 0 0 0 0 0 25 0 1 0 2147629 2637824 275 1283457024 134512640 135304128 4290397600 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9372/statm: 644 275 233 194 0 31 0
[pid=9373] ppid=9372 vsize=44804 CPUtime=9.53
/proc/9373/stat : 9373 (packup) S 9372 9372 1511 34817 1511 4202496 11056 72770 0 0 156 55 684 58 18 0 1 0 2147629 45879296 10492 1283457024 134512640 134752139 4289819872 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/9373/statm: 11201 10492 333 59 0 10365 0
[pid=9379] ppid=9373 vsize=1672 CPUtime=0
/proc/9379/stat : 9379 (sh) S 9373 9372 1511 34817 1511 4202496 145 0 0 0 0 0 0 0 18 0 1 0 2148584 1712128 123 1283457024 134512640 134593992 4288400480 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9379/statm: 418 123 108 20 0 45 0
[pid=9380] ppid=9379 vsize=83312 CPUtime=3.24
/proc/9380/stat : 9380 (minisatp_32) R 9379 9372 1511 34817 1511 4202496 28692 0 0 0 304 20 0 0 25 0 1 0 2148584 85311488 18309 1283457024 134512640 135413687 4291862480 18446744073709551615 134629283 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/9380/statm: 20828 18309 107 220 0 20606 0
Current children cumulated CPU time (s) 12.77
Current children cumulated vsize (KiB) 132364

[startup+16.0142 s]
/proc/loadavg: 1.27 1.17 1.06 2/37 9382
/proc/meminfo: memFree=378984/1048576 swapFree=0/0
[pid=9372] ppid=9371 vsize=2576 CPUtime=0
/proc/9372/stat : 9372 (packup2mp4tr-0.) S 9371 9372 1511 34817 1511 4202496 379 0 0 0 0 0 0 0 25 0 1 0 2147629 2637824 275 1283457024 134512640 135304128 4290397600 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9372/statm: 644 275 233 194 0 31 0
[pid=9373] ppid=9372 vsize=44808 CPUtime=14.41
/proc/9373/stat : 9373 (packup) S 9372 9372 1511 34817 1511 4202496 11152 113820 0 0 174 68 1116 83 18 0 1 0 2147629 45883392 10493 1283457024 134512640 134752139 4289819872 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/9373/statm: 11202 10493 333 59 0 10366 0
[pid=9381] ppid=9373 vsize=1668 CPUtime=0
/proc/9381/stat : 9381 (sh) S 9373 9372 1511 34817 1511 4202496 145 0 0 0 0 0 0 0 18 0 1 0 2149072 1708032 123 1283457024 134512640 134593992 4294250992 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9381/statm: 417 123 108 20 0 44 0
[pid=9382] ppid=9381 vsize=54964 CPUtime=1.57
/proc/9382/stat : 9382 (minisatp_32) R 9381 9372 1511 34817 1511 4202496 14797 0 0 0 140 17 0 0 25 0 1 0 2149072 56283136 12274 1283457024 134512640 135413687 4286812928 18446744073709551615 134535512 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/9382/statm: 13741 12274 90 220 0 13519 0
Current children cumulated CPU time (s) 15.98
Current children cumulated vsize (KiB) 104016

[startup+19.205 s]
/proc/loadavg: 1.27 1.17 1.06 2/37 9382
/proc/meminfo: memFree=284496/1048576 swapFree=0/0
[pid=9372] ppid=9371 vsize=2576 CPUtime=0
/proc/9372/stat : 9372 (packup2mp4tr-0.) S 9371 9372 1511 34817 1511 4202496 379 0 0 0 0 0 0 0 25 0 1 0 2147629 2637824 275 1283457024 134512640 135304128 4290397600 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9372/statm: 644 275 233 194 0 31 0
[pid=9373] ppid=9372 vsize=44808 CPUtime=14.41
/proc/9373/stat : 9373 (packup) S 9372 9372 1511 34817 1511 4202496 11152 113820 0 0 174 68 1116 83 18 0 1 0 2147629 45883392 10493 1283457024 134512640 134752139 4289819872 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/9373/statm: 11202 10493 333 59 0 10366 0
[pid=9381] ppid=9373 vsize=1668 CPUtime=0
/proc/9381/stat : 9381 (sh) S 9373 9372 1511 34817 1511 4202496 145 0 0 0 0 0 0 0 18 0 1 0 2149072 1708032 123 1283457024 134512640 134593992 4294250992 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9381/statm: 417 123 108 20 0 44 0
[pid=9382] ppid=9381 vsize=144724 CPUtime=4.76
/proc/9382/stat : 9382 (minisatp_32) R 9381 9372 1511 34817 1511 4202496 48225 0 0 0 441 35 0 0 25 0 1 0 2149072 148197376 31138 1283457024 134512640 135413687 4286812928 18446744073709551615 134696685 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/9382/statm: 36181 31138 107 220 0 35959 0
Current children cumulated CPU time (s) 19.17
Current children cumulated vsize (KiB) 193776

[startup+20.0053 s]
/proc/loadavg: 1.27 1.17 1.06 2/37 9382
/proc/meminfo: memFree=275816/1048576 swapFree=0/0
[pid=9372] ppid=9371 vsize=2576 CPUtime=0
/proc/9372/stat : 9372 (packup2mp4tr-0.) S 9371 9372 1511 34817 1511 4202496 379 0 0 0 0 0 0 0 25 0 1 0 2147629 2637824 275 1283457024 134512640 135304128 4290397600 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9372/statm: 644 275 233 194 0 31 0
[pid=9373] ppid=9372 vsize=44808 CPUtime=14.41
/proc/9373/stat : 9373 (packup) S 9372 9372 1511 34817 1511 4202496 11152 113820 0 0 174 68 1116 83 18 0 1 0 2147629 45883392 10493 1283457024 134512640 134752139 4289819872 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/9373/statm: 11202 10493 333 59 0 10366 0
[pid=9381] ppid=9373 vsize=1668 CPUtime=0
/proc/9381/stat : 9381 (sh) S 9373 9372 1511 34817 1511 4202496 145 0 0 0 0 0 0 0 18 0 1 0 2149072 1708032 123 1283457024 134512640 134593992 4294250992 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9381/statm: 417 123 108 20 0 44 0
[pid=9382] ppid=9381 vsize=160032 CPUtime=5.56
/proc/9382/stat : 9382 (minisatp_32) R 9381 9372 1511 34817 1511 4202496 53234 0 0 0 519 37 0 0 25 0 1 0 2149072 163872768 34869 1283457024 134512640 135413687 4286812928 18446744073709551615 134649344 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/9382/statm: 40008 34869 107 220 0 39786 0
Current children cumulated CPU time (s) 19.97
Current children cumulated vsize (KiB) 209084

[startup+20.4054 s]
/proc/loadavg: 1.27 1.17 1.06 2/37 9382
/proc/meminfo: memFree=275816/1048576 swapFree=0/0
[pid=9372] ppid=9371 vsize=2576 CPUtime=0
/proc/9372/stat : 9372 (packup2mp4tr-0.) S 9371 9372 1511 34817 1511 4202496 379 0 0 0 0 0 0 0 25 0 1 0 2147629 2637824 275 1283457024 134512640 135304128 4290397600 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9372/statm: 644 275 233 194 0 31 0
[pid=9373] ppid=9372 vsize=44808 CPUtime=14.41
/proc/9373/stat : 9373 (packup) S 9372 9372 1511 34817 1511 4202496 11152 113820 0 0 174 68 1116 83 18 0 1 0 2147629 45883392 10493 1283457024 134512640 134752139 4289819872 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/9373/statm: 11202 10493 333 59 0 10366 0
[pid=9381] ppid=9373 vsize=1668 CPUtime=0
/proc/9381/stat : 9381 (sh) S 9373 9372 1511 34817 1511 4202496 145 0 0 0 0 0 0 0 18 0 1 0 2149072 1708032 123 1283457024 134512640 134593992 4294250992 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9381/statm: 417 123 108 20 0 44 0
[pid=9382] ppid=9381 vsize=170524 CPUtime=5.96
/proc/9382/stat : 9382 (minisatp_32) R 9381 9372 1511 34817 1511 4202496 55936 0 0 0 557 39 0 0 25 0 1 0 2149072 174616576 37470 1283457024 134512640 135413687 4286812928 18446744073709551615 134960810 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/9382/statm: 42631 37470 107 220 0 42409 0
Current children cumulated CPU time (s) 20.37
Current children cumulated vsize (KiB) 219576

[startup+20.8055 s]
/proc/loadavg: 1.27 1.17 1.06 2/37 9382
/proc/meminfo: memFree=275816/1048576 swapFree=0/0
[pid=9372] ppid=9371 vsize=2576 CPUtime=0
/proc/9372/stat : 9372 (packup2mp4tr-0.) S 9371 9372 1511 34817 1511 4202496 379 0 0 0 0 0 0 0 25 0 1 0 2147629 2637824 275 1283457024 134512640 135304128 4290397600 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9372/statm: 644 275 233 194 0 31 0
[pid=9373] ppid=9372 vsize=43644 CPUtime=20.78
/proc/9373/stat : 9373 (packup) R 9372 9372 1511 34817 1511 4202496 20330 171109 0 0 180 72 1700 126 18 0 1 0 2147629 44691456 10215 1283457024 134512640 134752139 4289819872 18446744073709551615 4157179283 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/9373/statm: 10911 10215 346 59 0 10075 0
Current children cumulated CPU time (s) 20.78
Current children cumulated vsize (KiB) 46220

Child status: 0
Real time (s): 20.8538
CPU time (s): 20.8333
CPU user time (s): 18.8452
CPU system time (s): 1.98812
CPU usage (%): 99.9016
Max. virtual memory (cumulated for all children) (KiB): 226652

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

runsolver used 0.012 second user time and 0 second system time

The end