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/rand439.cudf.s-e-l-s.log.runsolver ./packup2mp4pa-0.6 /home/misc2010/data/2011/incremental/s-e-l-s/rand439.cudf /home/misc2010/tmp/201108251442/packup2mp4pa-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.57 1.28 1.10 4/34 12641
/proc/meminfo: memFree=356172/1048576 swapFree=0/0
[pid=12640] ppid=12639 vsize=2576 CPUtime=0
/proc/12640/stat : 12640 (packup2mp4pa-0.) S 12639 12640 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 10582971 2637824 275 1283457024 134512640 135304128 4289717552 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/12640/statm: 644 275 233 194 0 31 0
[pid=12641] ppid=12640 vsize=3716 CPUtime=0
/proc/12641/stat : 12641 (packup) R 12640 12640 4778 34817 4778 4202496 406 0 0 0 0 0 0 0 25 0 1 0 10582971 3805184 334 1283457024 134512640 134752139 4287873840 18446744073709551615 134681516 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/12641/statm: 929 334 286 59 0 93 0

[startup+0.123656 s]
/proc/loadavg: 1.57 1.28 1.10 4/34 12641
/proc/meminfo: memFree=356172/1048576 swapFree=0/0
[pid=12640] ppid=12639 vsize=2576 CPUtime=0
/proc/12640/stat : 12640 (packup2mp4pa-0.) S 12639 12640 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 10582971 2637824 275 1283457024 134512640 135304128 4289717552 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/12640/statm: 644 275 233 194 0 31 0
[pid=12641] ppid=12640 vsize=8552 CPUtime=0.12
/proc/12641/stat : 12641 (packup) R 12640 12640 4778 34817 4778 4202496 1636 0 0 0 11 1 0 0 25 0 1 0 10582971 8757248 1564 1283457024 134512640 134752139 4287873840 18446744073709551615 134681733 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/12641/statm: 2138 1564 286 59 0 1302 0
Current children cumulated CPU time (s) 0.12
Current children cumulated vsize (KiB) 11128

[startup+0.213668 s]
/proc/loadavg: 1.57 1.28 1.10 4/34 12641
/proc/meminfo: memFree=356172/1048576 swapFree=0/0
[pid=12640] ppid=12639 vsize=2576 CPUtime=0
/proc/12640/stat : 12640 (packup2mp4pa-0.) S 12639 12640 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 10582971 2637824 275 1283457024 134512640 135304128 4289717552 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/12640/statm: 644 275 233 194 0 31 0
[pid=12641] ppid=12640 vsize=11852 CPUtime=0.21
/proc/12641/stat : 12641 (packup) R 12640 12640 4778 34817 4778 4202496 2467 0 0 0 20 1 0 0 25 0 1 0 10582971 12136448 2395 1283457024 134512640 134752139 4287873840 18446744073709551615 134681765 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/12641/statm: 2963 2395 286 59 0 2127 0
Current children cumulated CPU time (s) 0.21
Current children cumulated vsize (KiB) 14428

[startup+0.303682 s]
/proc/loadavg: 1.57 1.28 1.10 4/34 12641
/proc/meminfo: memFree=356172/1048576 swapFree=0/0
[pid=12640] ppid=12639 vsize=2576 CPUtime=0
/proc/12640/stat : 12640 (packup2mp4pa-0.) S 12639 12640 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 10582971 2637824 275 1283457024 134512640 135304128 4289717552 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/12640/statm: 644 275 233 194 0 31 0
[pid=12641] ppid=12640 vsize=14820 CPUtime=0.3
/proc/12641/stat : 12641 (packup) R 12640 12640 4778 34817 4778 4202496 3187 0 0 0 25 5 0 0 25 0 1 0 10582971 15175680 3115 1283457024 134512640 134752139 4287873840 18446744073709551615 4294960130 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/12641/statm: 3705 3115 286 59 0 2869 0
Current children cumulated CPU time (s) 0.3
Current children cumulated vsize (KiB) 17396

[startup+0.703735 s]
/proc/loadavg: 1.57 1.28 1.10 4/34 12641
/proc/meminfo: memFree=356172/1048576 swapFree=0/0
[pid=12640] ppid=12639 vsize=2576 CPUtime=0
/proc/12640/stat : 12640 (packup2mp4pa-0.) S 12639 12640 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 10582971 2637824 275 1283457024 134512640 135304128 4289717552 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/12640/statm: 644 275 233 194 0 31 0
[pid=12641] ppid=12640 vsize=26252 CPUtime=0.7
/proc/12641/stat : 12641 (packup) R 12640 12640 4778 34817 4778 4202496 6042 0 0 0 64 6 0 0 25 0 1 0 10582971 26882048 5970 1283457024 134512640 134752139 4287873840 18446744073709551615 4157196490 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/12641/statm: 6563 5970 286 59 0 5727 0
Current children cumulated CPU time (s) 0.7
Current children cumulated vsize (KiB) 28828

[startup+1.51384 s]
/proc/loadavg: 1.57 1.28 1.10 2/35 12642
/proc/meminfo: memFree=323300/1048576 swapFree=0/0
[pid=12640] ppid=12639 vsize=2576 CPUtime=0
/proc/12640/stat : 12640 (packup2mp4pa-0.) S 12639 12640 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 10582971 2637824 275 1283457024 134512640 135304128 4289717552 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/12640/statm: 644 275 233 194 0 31 0
[pid=12641] ppid=12640 vsize=55364 CPUtime=1.51
/proc/12641/stat : 12641 (packup) R 12640 12640 4778 34817 4778 4202496 13421 0 0 0 139 12 0 0 25 0 1 0 10582971 56692736 13080 1283457024 134512640 134752139 4287873840 18446744073709551615 4294960130 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/12641/statm: 13841 13080 321 59 0 13005 0
Current children cumulated CPU time (s) 1.51
Current children cumulated vsize (KiB) 57940

[startup+3.10423 s]
/proc/loadavg: 1.52 1.27 1.10 2/37 12644
/proc/meminfo: memFree=293632/1048576 swapFree=0/0
[pid=12640] ppid=12639 vsize=2576 CPUtime=0
/proc/12640/stat : 12640 (packup2mp4pa-0.) S 12639 12640 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 10582971 2637824 275 1283457024 134512640 135304128 4289717552 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/12640/statm: 644 275 233 194 0 31 0
[pid=12641] ppid=12640 vsize=55364 CPUtime=1.79
/proc/12641/stat : 12641 (packup) S 12640 12640 4778 34817 4778 4202496 13425 0 0 0 150 29 0 0 25 0 1 0 10582971 56692736 13083 1283457024 134512640 134752139 4287873840 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/12641/statm: 13841 13083 324 59 0 13005 0
[pid=12643] ppid=12641 vsize=1672 CPUtime=0.01
/proc/12643/stat : 12643 (sh) S 12641 12640 4778 34817 4778 4202496 145 0 0 0 0 1 0 0 25 0 1 0 10583150 1712128 123 1283457024 134512640 134593992 4291055344 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/12643/statm: 418 123 108 20 0 45 0
[pid=12644] ppid=12643 vsize=29964 CPUtime=1.29
/proc/12644/stat : 12644 (minisatp_32) R 12643 12640 4778 34817 4778 4202496 7160 0 0 0 113 16 0 0 25 0 1 0 10583152 30683136 6360 1283457024 134512640 135413687 4293372224 18446744073709551615 134697151 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/12644/statm: 7491 6360 89 220 0 7269 0
Current children cumulated CPU time (s) 3.09
Current children cumulated vsize (KiB) 89576

[startup+6.30569 s]
/proc/loadavg: 1.52 1.27 1.10 2/37 12646
/proc/meminfo: memFree=269708/1048576 swapFree=0/0
[pid=12640] ppid=12639 vsize=2576 CPUtime=0
/proc/12640/stat : 12640 (packup2mp4pa-0.) S 12639 12640 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 10582971 2637824 275 1283457024 134512640 135304128 4289717552 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/12640/statm: 644 275 233 194 0 31 0
[pid=12641] ppid=12640 vsize=55368 CPUtime=3.81
/proc/12641/stat : 12641 (packup) S 12640 12640 4778 34817 4778 4202496 13493 11194 0 0 160 50 152 19 18 0 1 0 10582971 56696832 13092 1283457024 134512640 134752139 4287873840 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/12641/statm: 13842 13092 332 59 0 13006 0
[pid=12645] ppid=12641 vsize=1672 CPUtime=0
/proc/12645/stat : 12645 (sh) S 12641 12640 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 10583352 1712128 123 1283457024 134512640 134593992 4294789760 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/12645/statm: 418 123 108 20 0 45 0
[pid=12646] ppid=12645 vsize=89120 CPUtime=2.48
/proc/12646/stat : 12646 (minisatp_32) R 12645 12640 4778 34817 4778 4202496 25275 0 0 0 233 15 0 0 25 0 1 0 10583353 91258880 19288 1283457024 134512640 135413687 4288218192 18446744073709551615 134689048 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/12646/statm: 22280 19288 107 220 0 22058 0
Current children cumulated CPU time (s) 6.29
Current children cumulated vsize (KiB) 148736

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

[startup+6.40572 s]
/proc/loadavg: 1.52 1.27 1.10 2/37 12646
/proc/meminfo: memFree=269708/1048576 swapFree=0/0
[pid=12640] ppid=12639 vsize=2576 CPUtime=0
/proc/12640/stat : 12640 (packup2mp4pa-0.) S 12639 12640 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 10582971 2637824 275 1283457024 134512640 135304128 4289717552 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/12640/statm: 644 275 233 194 0 31 0
[pid=12641] ppid=12640 vsize=55368 CPUtime=3.81
/proc/12641/stat : 12641 (packup) S 12640 12640 4778 34817 4778 4202496 13493 11194 0 0 160 50 152 19 18 0 1 0 10582971 56696832 13092 1283457024 134512640 134752139 4287873840 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/12641/statm: 13842 13092 332 59 0 13006 0
[pid=12645] ppid=12641 vsize=1672 CPUtime=0
/proc/12645/stat : 12645 (sh) S 12641 12640 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 10583352 1712128 123 1283457024 134512640 134593992 4294789760 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/12645/statm: 418 123 108 20 0 45 0
[pid=12646] ppid=12645 vsize=90572 CPUtime=2.58
/proc/12646/stat : 12646 (minisatp_32) R 12645 12640 4778 34817 4778 4202496 25966 0 0 0 243 15 0 0 25 0 1 0 10583353 92745728 19955 1283457024 134512640 135413687 4288218192 18446744073709551615 134700116 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/12646/statm: 22643 19955 107 220 0 22421 0
Current children cumulated CPU time (s) 6.39
Current children cumulated vsize (KiB) 150188

[startup+8.00613 s]
/proc/loadavg: 1.48 1.27 1.10 2/37 12646
/proc/meminfo: memFree=222588/1048576 swapFree=0/0
[pid=12640] ppid=12639 vsize=2576 CPUtime=0
/proc/12640/stat : 12640 (packup2mp4pa-0.) S 12639 12640 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 10582971 2637824 275 1283457024 134512640 135304128 4289717552 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/12640/statm: 644 275 233 194 0 31 0
[pid=12641] ppid=12640 vsize=55368 CPUtime=3.81
/proc/12641/stat : 12641 (packup) S 12640 12640 4778 34817 4778 4202496 13493 11194 0 0 160 50 152 19 18 0 1 0 10582971 56696832 13092 1283457024 134512640 134752139 4287873840 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/12641/statm: 13842 13092 332 59 0 13006 0
[pid=12645] ppid=12641 vsize=1672 CPUtime=0
/proc/12645/stat : 12645 (sh) S 12641 12640 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 10583352 1712128 123 1283457024 134512640 134593992 4294789760 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/12645/statm: 418 123 108 20 0 45 0
[pid=12646] ppid=12645 vsize=90332 CPUtime=4.18
/proc/12646/stat : 12646 (minisatp_32) R 12645 12640 4778 34817 4778 4202496 28660 0 0 0 401 17 0 0 25 0 1 0 10583353 92499968 19954 1283457024 134512640 135413687 4288218192 18446744073709551615 134649535 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/12646/statm: 22583 19954 109 220 0 22361 0
Current children cumulated CPU time (s) 7.99
Current children cumulated vsize (KiB) 149948

[startup+8.8064 s]
/proc/loadavg: 1.48 1.27 1.10 2/37 12646
/proc/meminfo: memFree=222588/1048576 swapFree=0/0
[pid=12640] ppid=12639 vsize=2576 CPUtime=0
/proc/12640/stat : 12640 (packup2mp4pa-0.) S 12639 12640 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 10582971 2637824 275 1283457024 134512640 135304128 4289717552 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/12640/statm: 644 275 233 194 0 31 0
[pid=12641] ppid=12640 vsize=55368 CPUtime=3.81
/proc/12641/stat : 12641 (packup) S 12640 12640 4778 34817 4778 4202496 13493 11194 0 0 160 50 152 19 18 0 1 0 10582971 56696832 13092 1283457024 134512640 134752139 4287873840 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/12641/statm: 13842 13092 332 59 0 13006 0
[pid=12645] ppid=12641 vsize=1672 CPUtime=0
/proc/12645/stat : 12645 (sh) S 12641 12640 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 10583352 1712128 123 1283457024 134512640 134593992 4294789760 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/12645/statm: 418 123 108 20 0 45 0
[pid=12646] ppid=12645 vsize=90332 CPUtime=4.98
/proc/12646/stat : 12646 (minisatp_32) R 12645 12640 4778 34817 4778 4202496 28681 0 0 0 481 17 0 0 25 0 1 0 10583353 92499968 19975 1283457024 134512640 135413687 4288218192 18446744073709551615 134649456 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/12646/statm: 22583 19975 110 220 0 22361 0
Current children cumulated CPU time (s) 8.79
Current children cumulated vsize (KiB) 149948

[startup+9.20652 s]
/proc/loadavg: 1.48 1.27 1.10 2/37 12646
/proc/meminfo: memFree=222588/1048576 swapFree=0/0
[pid=12640] ppid=12639 vsize=2576 CPUtime=0
/proc/12640/stat : 12640 (packup2mp4pa-0.) S 12639 12640 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 10582971 2637824 275 1283457024 134512640 135304128 4289717552 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/12640/statm: 644 275 233 194 0 31 0
[pid=12641] ppid=12640 vsize=55368 CPUtime=3.81
/proc/12641/stat : 12641 (packup) S 12640 12640 4778 34817 4778 4202496 13493 11194 0 0 160 50 152 19 18 0 1 0 10582971 56696832 13092 1283457024 134512640 134752139 4287873840 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/12641/statm: 13842 13092 332 59 0 13006 0
[pid=12645] ppid=12641 vsize=1672 CPUtime=0
/proc/12645/stat : 12645 (sh) S 12641 12640 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 10583352 1712128 123 1283457024 134512640 134593992 4294789760 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/12645/statm: 418 123 108 20 0 45 0
[pid=12646] ppid=12645 vsize=90332 CPUtime=5.38
/proc/12646/stat : 12646 (minisatp_32) R 12645 12640 4778 34817 4778 4202496 28689 0 0 0 521 17 0 0 25 0 1 0 10583353 92499968 19983 1283457024 134512640 135413687 4288218192 18446744073709551615 134649574 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/12646/statm: 22583 19983 110 220 0 22361 0
Current children cumulated CPU time (s) 9.19
Current children cumulated vsize (KiB) 149948

[startup+9.40659 s]
/proc/loadavg: 1.48 1.27 1.10 2/37 12646
/proc/meminfo: memFree=222588/1048576 swapFree=0/0
[pid=12640] ppid=12639 vsize=2576 CPUtime=0
/proc/12640/stat : 12640 (packup2mp4pa-0.) S 12639 12640 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 10582971 2637824 275 1283457024 134512640 135304128 4289717552 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/12640/statm: 644 275 233 194 0 31 0
[pid=12641] ppid=12640 vsize=55368 CPUtime=3.81
/proc/12641/stat : 12641 (packup) S 12640 12640 4778 34817 4778 4202496 13493 11194 0 0 160 50 152 19 18 0 1 0 10582971 56696832 13092 1283457024 134512640 134752139 4287873840 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/12641/statm: 13842 13092 332 59 0 13006 0
[pid=12645] ppid=12641 vsize=1672 CPUtime=0
/proc/12645/stat : 12645 (sh) S 12641 12640 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 10583352 1712128 123 1283457024 134512640 134593992 4294789760 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/12645/statm: 418 123 108 20 0 45 0
[pid=12646] ppid=12645 vsize=90332 CPUtime=5.58
/proc/12646/stat : 12646 (minisatp_32) R 12645 12640 4778 34817 4778 4202496 28691 0 0 0 541 17 0 0 25 0 1 0 10583353 92499968 19985 1283457024 134512640 135413687 4288218192 18446744073709551615 134649535 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/12646/statm: 22583 19985 110 220 0 22361 0
Current children cumulated CPU time (s) 9.39
Current children cumulated vsize (KiB) 149948

[startup+9.50661 s]
/proc/loadavg: 1.48 1.27 1.10 2/37 12646
/proc/meminfo: memFree=222588/1048576 swapFree=0/0
[pid=12640] ppid=12639 vsize=2576 CPUtime=0
/proc/12640/stat : 12640 (packup2mp4pa-0.) S 12639 12640 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 10582971 2637824 275 1283457024 134512640 135304128 4289717552 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/12640/statm: 644 275 233 194 0 31 0
[pid=12641] ppid=12640 vsize=54596 CPUtime=9.49
/proc/12641/stat : 12641 (packup) R 12640 12640 4778 34817 4778 4202496 24516 40042 0 0 163 54 695 37 18 0 1 0 10582971 55906304 12911 1283457024 134512640 134752139 4287873840 18446744073709551615 4159238337 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/12641/statm: 13649 12911 344 59 0 12813 0
Current children cumulated CPU time (s) 9.49
Current children cumulated vsize (KiB) 57172

Child status: 0
Real time (s): 9.57626
CPU time (s): 9.5686
CPU user time (s): 8.65254
CPU system time (s): 0.916057
CPU usage (%): 99.92
Max. virtual memory (cumulated for all children) (KiB): 159668

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 8.65254
system time used= 0.916057
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 65969
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= 11
involuntary context switches= 165

runsolver used 0 second user time and 0 second system time

The end