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/rand230.cudf.s-e.log.runsolver ./packup2mp4tr-0.6 /home/misc2010/data/2011/incremental/s-e/rand230.cudf /home/misc2010/tmp/201108241238/packup2mp4tr-0.6/rand230.cudf.s-e.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 1.01 0.99 4/36 6635
/proc/meminfo: memFree=690572/1048576 swapFree=0/0
[pid=6634] ppid=6633 vsize=2572 CPUtime=0
/proc/6634/stat : 6634 (packup2mp4tr-0.) S 6633 6634 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 1697136 2633728 274 1283457024 134512640 135304128 4289004672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/6634/statm: 643 274 233 194 0 30 0
[pid=6635] ppid=6634 vsize=3712 CPUtime=0
/proc/6635/stat : 6635 (packup) R 6634 6634 1511 34817 1511 4202496 424 0 0 0 0 0 0 0 25 0 1 0 1697137 3801088 352 1283457024 134512640 134752139 4291638992 18446744073709551615 134681583 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/6635/statm: 928 352 286 59 0 92 0

[startup+0.125078 s]
/proc/loadavg: 0.93 1.01 0.99 4/36 6635
/proc/meminfo: memFree=690572/1048576 swapFree=0/0
[pid=6634] ppid=6633 vsize=2572 CPUtime=0
/proc/6634/stat : 6634 (packup2mp4tr-0.) S 6633 6634 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 1697136 2633728 274 1283457024 134512640 135304128 4289004672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/6634/statm: 643 274 233 194 0 30 0
[pid=6635] ppid=6634 vsize=8360 CPUtime=0.12
/proc/6635/stat : 6635 (packup) R 6634 6634 1511 34817 1511 4202496 1580 0 0 0 11 1 0 0 25 0 1 0 1697137 8560640 1508 1283457024 134512640 134752139 4291638992 18446744073709551615 134623039 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/6635/statm: 2090 1508 286 59 0 1254 0
Current children cumulated CPU time (s) 0.12
Current children cumulated vsize (KiB) 10932

[startup+0.205088 s]
/proc/loadavg: 0.93 1.01 0.99 4/36 6635
/proc/meminfo: memFree=690572/1048576 swapFree=0/0
[pid=6634] ppid=6633 vsize=2572 CPUtime=0
/proc/6634/stat : 6634 (packup2mp4tr-0.) S 6633 6634 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 1697136 2633728 274 1283457024 134512640 135304128 4289004672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/6634/statm: 643 274 233 194 0 30 0
[pid=6635] ppid=6634 vsize=11000 CPUtime=0.2
/proc/6635/stat : 6635 (packup) R 6634 6634 1511 34817 1511 4202496 2238 0 0 0 18 2 0 0 25 0 1 0 1697137 11264000 2166 1283457024 134512640 134752139 4291638992 18446744073709551615 134681152 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/6635/statm: 2750 2166 286 59 0 1914 0
Current children cumulated CPU time (s) 0.2
Current children cumulated vsize (KiB) 13572

[startup+0.305114 s]
/proc/loadavg: 0.93 1.01 0.99 4/36 6635
/proc/meminfo: memFree=690572/1048576 swapFree=0/0
[pid=6634] ppid=6633 vsize=2572 CPUtime=0
/proc/6634/stat : 6634 (packup2mp4tr-0.) S 6633 6634 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 1697136 2633728 274 1283457024 134512640 135304128 4289004672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/6634/statm: 643 274 233 194 0 30 0
[pid=6635] ppid=6634 vsize=14072 CPUtime=0.3
/proc/6635/stat : 6635 (packup) R 6634 6634 1511 34817 1511 4202496 2999 0 0 0 28 2 0 0 25 0 1 0 1697137 14409728 2927 1283457024 134512640 134752139 4291638992 18446744073709551615 4157601199 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/6635/statm: 3518 2927 286 59 0 2682 0
Current children cumulated CPU time (s) 0.3
Current children cumulated vsize (KiB) 16644

[startup+0.705225 s]
/proc/loadavg: 0.93 1.01 0.99 4/36 6635
/proc/meminfo: memFree=690572/1048576 swapFree=0/0
[pid=6634] ppid=6633 vsize=2572 CPUtime=0
/proc/6634/stat : 6634 (packup2mp4tr-0.) S 6633 6634 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 1697136 2633728 274 1283457024 134512640 135304128 4289004672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/6634/statm: 643 274 233 194 0 30 0
[pid=6635] ppid=6634 vsize=28328 CPUtime=0.7
/proc/6635/stat : 6635 (packup) R 6634 6634 1511 34817 1511 4202496 6600 0 0 0 60 10 0 0 25 0 1 0 1697137 29007872 6414 1283457024 134512640 134752139 4291638992 18446744073709551615 4294960130 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/6635/statm: 7082 6414 321 59 0 6246 0
Current children cumulated CPU time (s) 0.7
Current children cumulated vsize (KiB) 30900

[startup+1.50543 s]
/proc/loadavg: 0.93 1.01 0.99 2/39 6638
/proc/meminfo: memFree=658148/1048576 swapFree=0/0
[pid=6634] ppid=6633 vsize=2572 CPUtime=0
/proc/6634/stat : 6634 (packup2mp4tr-0.) S 6633 6634 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 1697136 2633728 274 1283457024 134512640 135304128 4289004672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/6634/statm: 643 274 233 194 0 30 0
[pid=6635] ppid=6634 vsize=28328 CPUtime=0.79
/proc/6635/stat : 6635 (packup) S 6634 6634 1511 34817 1511 4202496 6604 0 0 0 65 14 0 0 25 0 1 0 1697137 29007872 6417 1283457024 134512640 134752139 4291638992 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/6635/statm: 7082 6417 324 59 0 6246 0
[pid=6637] ppid=6635 vsize=1676 CPUtime=0
/proc/6637/stat : 6637 (sh) S 6635 6634 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 25 0 1 0 1697216 1716224 124 1283457024 134512640 134593992 4290156048 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6637/statm: 419 124 108 20 0 46 0
[pid=6638] ppid=6637 vsize=16520 CPUtime=0.7
/proc/6638/stat : 6638 (minisatp_32) R 6637 6634 1511 34817 1511 4202496 5053 0 0 0 64 6 0 0 25 0 1 0 1697217 16916480 3864 1283457024 134512640 135413687 4291905488 18446744073709551615 134691048 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/6638/statm: 4130 3864 108 220 0 3908 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 49096

[startup+3.10578 s]
/proc/loadavg: 0.93 1.01 0.99 2/39 6640
/proc/meminfo: memFree=657156/1048576 swapFree=0/0
[pid=6634] ppid=6633 vsize=2572 CPUtime=0
/proc/6634/stat : 6634 (packup2mp4tr-0.) S 6633 6634 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 1697136 2633728 274 1283457024 134512640 135304128 4289004672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/6634/statm: 643 274 233 194 0 30 0
[pid=6635] ppid=6634 vsize=28332 CPUtime=1.85
/proc/6635/stat : 6635 (packup) S 6634 6634 1511 34817 1511 4202496 6667 7090 0 0 75 21 83 6 18 0 1 0 1697137 29011968 6430 1283457024 134512640 134752139 4291638992 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/6635/statm: 7083 6430 332 59 0 6247 0
[pid=6639] ppid=6635 vsize=1668 CPUtime=0
/proc/6639/stat : 6639 (sh) S 6635 6634 1511 34817 1511 4202496 145 0 0 0 0 0 0 0 18 0 1 0 1697324 1708032 123 1283457024 134512640 134593992 4288003072 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6639/statm: 417 123 108 20 0 44 0
[pid=6640] ppid=6639 vsize=42020 CPUtime=1.23
/proc/6640/stat : 6640 (minisatp_32) R 6639 6634 1511 34817 1511 4202496 12975 0 0 0 115 8 0 0 25 0 1 0 1697324 43028480 9330 1283457024 134512640 135413687 4291735472 18446744073709551615 134699739 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/6640/statm: 10505 9330 107 220 0 10283 0
Current children cumulated CPU time (s) 3.08
Current children cumulated vsize (KiB) 74592

[startup+6.30653 s]
/proc/loadavg: 0.94 1.01 0.99 2/39 6643
/proc/meminfo: memFree=623552/1048576 swapFree=0/0
[pid=6634] ppid=6633 vsize=2572 CPUtime=0
/proc/6634/stat : 6634 (packup2mp4tr-0.) S 6633 6634 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 1697136 2633728 274 1283457024 134512640 135304128 4289004672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/6634/statm: 643 274 233 194 0 30 0
[pid=6635] ppid=6634 vsize=28340 CPUtime=6.28
/proc/6635/stat : 6635 (packup) R 6634 6634 1511 34817 1511 4202496 6786 45185 0 0 89 32 477 30 18 0 1 0 1697137 29020160 6436 1283457024 134512640 134752139 4291638992 18446744073709551615 4157898675 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/6635/statm: 7085 6436 332 59 0 6249 0
Current children cumulated CPU time (s) 6.28
Current children cumulated vsize (KiB) 30912

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

[startup+6.40656 s]
/proc/loadavg: 0.94 1.01 0.99 2/39 6643
/proc/meminfo: memFree=623552/1048576 swapFree=0/0
[pid=6634] ppid=6633 vsize=2572 CPUtime=0
/proc/6634/stat : 6634 (packup2mp4tr-0.) S 6633 6634 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 1697136 2633728 274 1283457024 134512640 135304128 4289004672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/6634/statm: 643 274 233 194 0 30 0
[pid=6635] ppid=6634 vsize=28340 CPUtime=6.38
/proc/6635/stat : 6635 (packup) S 6634 6634 1511 34817 1511 4202496 6787 45185 0 0 92 39 477 30 18 0 1 0 1697137 29020160 6436 1283457024 134512640 134752139 4291638992 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/6635/statm: 7085 6436 332 59 0 6249 0
Current children cumulated CPU time (s) 6.38
Current children cumulated vsize (KiB) 30912

[startup+9.6077 s]
/proc/loadavg: 0.94 1.01 0.99 2/39 6645
/proc/meminfo: memFree=608060/1048576 swapFree=0/0
[pid=6634] ppid=6633 vsize=2572 CPUtime=0
/proc/6634/stat : 6634 (packup2mp4tr-0.) S 6633 6634 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 1697136 2633728 274 1283457024 134512640 135304128 4289004672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/6634/statm: 643 274 233 194 0 30 0
[pid=6635] ppid=6634 vsize=28340 CPUtime=6.38
/proc/6635/stat : 6635 (packup) S 6634 6634 1511 34817 1511 4202496 6787 45185 0 0 92 39 477 30 18 0 1 0 1697137 29020160 6436 1283457024 134512640 134752139 4291638992 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/6635/statm: 7085 6436 332 59 0 6249 0
[pid=6644] ppid=6635 vsize=1672 CPUtime=0
/proc/6644/stat : 6644 (sh) S 6635 6634 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 1697777 1712128 124 1283457024 134512640 134593992 4293052624 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6644/statm: 418 124 108 20 0 45 0
[pid=6645] ppid=6644 vsize=83356 CPUtime=3.19
/proc/6645/stat : 6645 (minisatp_32) R 6644 6634 1511 34817 1511 4202496 29201 0 0 0 308 11 0 0 25 0 1 0 1697777 85356544 17702 1283457024 134512640 135413687 4291245872 18446744073709551615 134683914 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/6645/statm: 20839 17702 107 220 0 20617 0
Current children cumulated CPU time (s) 9.57
Current children cumulated vsize (KiB) 115940

[startup+11.2057 s]
/proc/loadavg: 0.94 1.00 0.99 2/39 6645
/proc/meminfo: memFree=575572/1048576 swapFree=0/0
[pid=6634] ppid=6633 vsize=2572 CPUtime=0
/proc/6634/stat : 6634 (packup2mp4tr-0.) S 6633 6634 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 1697136 2633728 274 1283457024 134512640 135304128 4289004672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/6634/statm: 643 274 233 194 0 30 0
[pid=6635] ppid=6634 vsize=28340 CPUtime=6.38
/proc/6635/stat : 6635 (packup) S 6634 6634 1511 34817 1511 4202496 6787 45185 0 0 92 39 477 30 18 0 1 0 1697137 29020160 6436 1283457024 134512640 134752139 4291638992 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/6635/statm: 7085 6436 332 59 0 6249 0
[pid=6644] ppid=6635 vsize=1672 CPUtime=0
/proc/6644/stat : 6644 (sh) S 6635 6634 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 1697777 1712128 124 1283457024 134512640 134593992 4293052624 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6644/statm: 418 124 108 20 0 45 0
[pid=6645] ppid=6644 vsize=102488 CPUtime=4.73
/proc/6645/stat : 6645 (minisatp_32) R 6644 6634 1511 34817 1511 4202496 36851 0 0 0 460 13 0 0 25 0 1 0 1697777 104947712 22182 1283457024 134512640 135413687 4291245872 18446744073709551615 134650147 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/6645/statm: 25622 22182 110 220 0 25400 0
Current children cumulated CPU time (s) 11.11
Current children cumulated vsize (KiB) 135072

[startup+12.0059 s]
/proc/loadavg: 0.94 1.00 0.99 2/39 6645
/proc/meminfo: memFree=575572/1048576 swapFree=0/0
[pid=6634] ppid=6633 vsize=2572 CPUtime=0
/proc/6634/stat : 6634 (packup2mp4tr-0.) S 6633 6634 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 1697136 2633728 274 1283457024 134512640 135304128 4289004672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/6634/statm: 643 274 233 194 0 30 0
[pid=6635] ppid=6634 vsize=28340 CPUtime=6.38
/proc/6635/stat : 6635 (packup) S 6634 6634 1511 34817 1511 4202496 6787 45185 0 0 92 39 477 30 18 0 1 0 1697137 29020160 6436 1283457024 134512640 134752139 4291638992 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/6635/statm: 7085 6436 332 59 0 6249 0
[pid=6644] ppid=6635 vsize=1672 CPUtime=0
/proc/6644/stat : 6644 (sh) S 6635 6634 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 1697777 1712128 124 1283457024 134512640 134593992 4293052624 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6644/statm: 418 124 108 20 0 45 0
[pid=6645] ppid=6644 vsize=102488 CPUtime=5.53
/proc/6645/stat : 6645 (minisatp_32) R 6644 6634 1511 34817 1511 4202496 36926 0 0 0 540 13 0 0 25 0 1 0 1697777 104947712 22251 1283457024 134512640 135413687 4291245872 18446744073709551615 134649535 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/6645/statm: 25622 22251 110 220 0 25400 0
Current children cumulated CPU time (s) 11.91
Current children cumulated vsize (KiB) 135072

[startup+12.406 s]
/proc/loadavg: 0.94 1.00 0.99 2/39 6645
/proc/meminfo: memFree=575448/1048576 swapFree=0/0
[pid=6634] ppid=6633 vsize=2572 CPUtime=0
/proc/6634/stat : 6634 (packup2mp4tr-0.) S 6633 6634 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 1697136 2633728 274 1283457024 134512640 135304128 4289004672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/6634/statm: 643 274 233 194 0 30 0
[pid=6635] ppid=6634 vsize=28340 CPUtime=6.38
/proc/6635/stat : 6635 (packup) S 6634 6634 1511 34817 1511 4202496 6787 45185 0 0 92 39 477 30 18 0 1 0 1697137 29020160 6436 1283457024 134512640 134752139 4291638992 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/6635/statm: 7085 6436 332 59 0 6249 0
[pid=6644] ppid=6635 vsize=1672 CPUtime=0
/proc/6644/stat : 6644 (sh) S 6635 6634 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 1697777 1712128 124 1283457024 134512640 134593992 4293052624 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6644/statm: 418 124 108 20 0 45 0
[pid=6645] ppid=6644 vsize=102960 CPUtime=5.93
/proc/6645/stat : 6645 (minisatp_32) R 6644 6634 1511 34817 1511 4202496 37016 0 0 0 580 13 0 0 25 0 1 0 1697777 105431040 22330 1283457024 134512640 135413687 4291245872 18446744073709551615 134649574 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/6645/statm: 25740 22330 110 220 0 25518 0
Current children cumulated CPU time (s) 12.31
Current children cumulated vsize (KiB) 135544

[startup+12.5065 s]
/proc/loadavg: 0.94 1.00 0.99 2/39 6645
/proc/meminfo: memFree=575448/1048576 swapFree=0/0
[pid=6634] ppid=6633 vsize=2572 CPUtime=0
/proc/6634/stat : 6634 (packup2mp4tr-0.) S 6633 6634 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 1697136 2633728 274 1283457024 134512640 135304128 4289004672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/6634/statm: 643 274 233 194 0 30 0
[pid=6635] ppid=6634 vsize=28340 CPUtime=6.38
/proc/6635/stat : 6635 (packup) S 6634 6634 1511 34817 1511 4202496 6787 45185 0 0 92 39 477 30 18 0 1 0 1697137 29020160 6436 1283457024 134512640 134752139 4291638992 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/6635/statm: 7085 6436 332 59 0 6249 0
[pid=6644] ppid=6635 vsize=1672 CPUtime=0
/proc/6644/stat : 6644 (sh) S 6635 6634 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 1697777 1712128 124 1283457024 134512640 134593992 4293052624 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6644/statm: 418 124 108 20 0 45 0
[pid=6645] ppid=6644 vsize=97304 CPUtime=6.03
/proc/6645/stat : 6645 (minisatp_32) R 6644 6634 1511 34817 1511 4202496 37027 0 0 0 588 15 0 0 25 0 1 0 1697777 99639296 20270 1283457024 134512640 135413687 4291245872 18446744073709551615 134992593 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/6645/statm: 24326 20270 118 220 0 24104 0
Current children cumulated CPU time (s) 12.41
Current children cumulated vsize (KiB) 129888

Child status: 0
Real time (s): 12.5901
CPU time (s): 12.5128
CPU user time (s): 11.6567
CPU system time (s): 0.856053
CPU usage (%): 99.3859
Max. virtual memory (cumulated for all children) (KiB): 141788

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 11.6567
system time used= 0.856053
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 95327
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= 20
involuntary context switches= 211

runsolver used 0 second user time and 0 second system time

The end