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/rand450.cudf.s-e-l-s.log.runsolver ./packup2mp4pa-0.6 /home/misc2010/data/2011/incremental/s-e-l-s/rand450.cudf /home/misc2010/tmp/201108251442/packup2mp4pa-0.6/rand450.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: 0.98 1.14 1.13 4/34 14060
/proc/meminfo: memFree=386292/1048576 swapFree=0/0
[pid=14059] ppid=14058 vsize=2568 CPUtime=0
/proc/14059/stat : 14059 (packup2mp4pa-0.) S 14058 14059 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 18 0 1 0 10635684 2629632 273 1283457024 134512640 135304128 4293615840 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/14059/statm: 642 273 233 194 0 29 0
[pid=14060] ppid=14059 vsize=3552 CPUtime=0.01
/proc/14060/stat : 14060 (packup) R 14059 14059 4778 34817 4778 4202496 350 0 0 0 0 1 0 0 25 0 1 0 10635684 3637248 279 1283457024 134512640 134752139 4289121376 18446744073709551615 4294960130 0 0 0 0 0 0 0 17 0 0 0 0
/proc/14060/statm: 888 279 245 59 0 52 0

[startup+0.123249 s]
/proc/loadavg: 0.98 1.14 1.13 4/34 14060
/proc/meminfo: memFree=386292/1048576 swapFree=0/0
[pid=14059] ppid=14058 vsize=2568 CPUtime=0
/proc/14059/stat : 14059 (packup2mp4pa-0.) S 14058 14059 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 18 0 1 0 10635684 2629632 273 1283457024 134512640 135304128 4293615840 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/14059/statm: 642 273 233 194 0 29 0
[pid=14060] ppid=14059 vsize=8548 CPUtime=0.12
/proc/14060/stat : 14060 (packup) R 14059 14059 4778 34817 4778 4202496 1642 0 0 0 10 2 0 0 25 0 1 0 10635684 8753152 1571 1283457024 134512640 134752139 4289121376 18446744073709551615 134681191 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/14060/statm: 2137 1571 286 59 0 1301 0
Current children cumulated CPU time (s) 0.12
Current children cumulated vsize (KiB) 11116

[startup+0.213267 s]
/proc/loadavg: 0.98 1.14 1.13 4/34 14060
/proc/meminfo: memFree=386292/1048576 swapFree=0/0
[pid=14059] ppid=14058 vsize=2568 CPUtime=0
/proc/14059/stat : 14059 (packup2mp4pa-0.) S 14058 14059 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 18 0 1 0 10635684 2629632 273 1283457024 134512640 135304128 4293615840 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/14059/statm: 642 273 233 194 0 29 0
[pid=14060] ppid=14059 vsize=11980 CPUtime=0.21
/proc/14060/stat : 14060 (packup) R 14059 14059 4778 34817 4778 4202496 2498 0 0 0 18 3 0 0 25 0 1 0 10635684 12267520 2427 1283457024 134512640 134752139 4289121376 18446744073709551615 134643367 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/14060/statm: 2995 2427 286 59 0 2159 0
Current children cumulated CPU time (s) 0.21
Current children cumulated vsize (KiB) 14548

[startup+0.303287 s]
/proc/loadavg: 0.98 1.14 1.13 4/34 14060
/proc/meminfo: memFree=386292/1048576 swapFree=0/0
[pid=14059] ppid=14058 vsize=2568 CPUtime=0
/proc/14059/stat : 14059 (packup2mp4pa-0.) S 14058 14059 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 18 0 1 0 10635684 2629632 273 1283457024 134512640 135304128 4293615840 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/14059/statm: 642 273 233 194 0 29 0
[pid=14060] ppid=14059 vsize=14816 CPUtime=0.3
/proc/14060/stat : 14060 (packup) R 14059 14059 4778 34817 4778 4202496 3199 0 0 0 27 3 0 0 25 0 1 0 10635684 15171584 3128 1283457024 134512640 134752139 4289121376 18446744073709551615 4157353124 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/14060/statm: 3704 3128 286 59 0 2868 0
Current children cumulated CPU time (s) 0.3
Current children cumulated vsize (KiB) 17384

[startup+0.703369 s]
/proc/loadavg: 0.98 1.14 1.13 4/34 14060
/proc/meminfo: memFree=386292/1048576 swapFree=0/0
[pid=14059] ppid=14058 vsize=2568 CPUtime=0
/proc/14059/stat : 14059 (packup2mp4pa-0.) S 14058 14059 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 18 0 1 0 10635684 2629632 273 1283457024 134512640 135304128 4293615840 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/14059/statm: 642 273 233 194 0 29 0
[pid=14060] ppid=14059 vsize=26380 CPUtime=0.7
/proc/14060/stat : 14060 (packup) R 14059 14059 4778 34817 4778 4202496 6081 0 0 0 67 3 0 0 25 0 1 0 10635684 27013120 6010 1283457024 134512640 134752139 4289121376 18446744073709551615 4157343535 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/14060/statm: 6595 6010 286 59 0 5759 0
Current children cumulated CPU time (s) 0.7
Current children cumulated vsize (KiB) 28948

[startup+1.50354 s]
/proc/loadavg: 0.98 1.14 1.13 2/35 14061
/proc/meminfo: memFree=353172/1048576 swapFree=0/0
[pid=14059] ppid=14058 vsize=2568 CPUtime=0
/proc/14059/stat : 14059 (packup2mp4pa-0.) S 14058 14059 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 18 0 1 0 10635684 2629632 273 1283457024 134512640 135304128 4293615840 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/14059/statm: 642 273 233 194 0 29 0
[pid=14060] ppid=14059 vsize=55660 CPUtime=1.5
/proc/14060/stat : 14060 (packup) R 14059 14059 4778 34817 4778 4202496 13481 0 0 0 144 6 0 0 25 0 1 0 10635684 56995840 13138 1283457024 134512640 134752139 4289121376 18446744073709551615 4294960130 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/14060/statm: 13915 13138 321 59 0 13079 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 58228

[startup+3.10382 s]
/proc/loadavg: 0.98 1.14 1.13 2/37 14063
/proc/meminfo: memFree=323256/1048576 swapFree=0/0
[pid=14059] ppid=14058 vsize=2568 CPUtime=0
/proc/14059/stat : 14059 (packup2mp4pa-0.) S 14058 14059 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 18 0 1 0 10635684 2629632 273 1283457024 134512640 135304128 4293615840 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/14059/statm: 642 273 233 194 0 29 0
[pid=14060] ppid=14059 vsize=55660 CPUtime=1.79
/proc/14060/stat : 14060 (packup) S 14059 14059 4778 34817 4778 4202496 13485 0 0 0 155 24 0 0 25 0 1 0 10635684 56995840 13141 1283457024 134512640 134752139 4289121376 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/14060/statm: 13915 13141 324 59 0 13079 0
[pid=14062] ppid=14060 vsize=1668 CPUtime=0
/proc/14062/stat : 14062 (sh) S 14060 14059 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 25 0 1 0 10635862 1708032 123 1283457024 134512640 134593992 4289420640 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/14062/statm: 417 123 108 20 0 44 0
[pid=14063] ppid=14062 vsize=30444 CPUtime=1.31
/proc/14063/stat : 14063 (minisatp_32) R 14062 14059 4778 34817 4778 4202496 7349 0 0 0 116 15 0 0 25 0 1 0 10635864 31174656 6524 1283457024 134512640 135413687 4293073136 18446744073709551615 134692025 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/14063/statm: 7611 6524 87 220 0 7389 0
Current children cumulated CPU time (s) 3.1
Current children cumulated vsize (KiB) 90340

[startup+6.30474 s]
/proc/loadavg: 0.98 1.13 1.12 2/37 14065
/proc/meminfo: memFree=302920/1048576 swapFree=0/0
[pid=14059] ppid=14058 vsize=2568 CPUtime=0
/proc/14059/stat : 14059 (packup2mp4pa-0.) S 14058 14059 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 18 0 1 0 10635684 2629632 273 1283457024 134512640 135304128 4293615840 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/14059/statm: 642 273 233 194 0 29 0
[pid=14060] ppid=14059 vsize=55664 CPUtime=4.14
/proc/14060/stat : 14060 (packup) S 14059 14059 4778 34817 4778 4202496 13549 13551 0 0 170 41 183 20 18 0 1 0 10635684 56999936 13150 1283457024 134512640 134752139 4289121376 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/14060/statm: 13916 13150 332 59 0 13080 0
[pid=14064] ppid=14060 vsize=1672 CPUtime=0
/proc/14064/stat : 14064 (sh) S 14060 14059 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 10636098 1712128 123 1283457024 134512640 134593992 4288892128 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/14064/statm: 418 123 108 20 0 45 0
[pid=14065] ppid=14064 vsize=62036 CPUtime=2.15
/proc/14065/stat : 14065 (minisatp_32) R 14064 14059 4778 34817 4778 4202496 18878 0 0 0 194 21 0 0 25 0 1 0 10636099 63524864 13758 1283457024 134512640 135413687 4289244496 18446744073709551615 134530526 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/14065/statm: 15509 13758 107 220 0 15287 0
Current children cumulated CPU time (s) 6.29
Current children cumulated vsize (KiB) 121940

[startup+12.7067 s]
/proc/loadavg: 1.06 1.15 1.13 2/37 14065
/proc/meminfo: memFree=165536/1048576 swapFree=0/0
[pid=14059] ppid=14058 vsize=2568 CPUtime=0
/proc/14059/stat : 14059 (packup2mp4pa-0.) S 14058 14059 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 18 0 1 0 10635684 2629632 273 1283457024 134512640 135304128 4293615840 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/14059/statm: 642 273 233 194 0 29 0
[pid=14060] ppid=14059 vsize=55664 CPUtime=4.14
/proc/14060/stat : 14060 (packup) S 14059 14059 4778 34817 4778 4202496 13549 13551 0 0 170 41 183 20 18 0 1 0 10635684 56999936 13150 1283457024 134512640 134752139 4289121376 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/14060/statm: 13916 13150 332 59 0 13080 0
[pid=14064] ppid=14060 vsize=1672 CPUtime=0
/proc/14064/stat : 14064 (sh) S 14060 14059 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 10636098 1712128 123 1283457024 134512640 134593992 4288892128 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/14064/statm: 418 123 108 20 0 45 0
[pid=14065] ppid=14064 vsize=204916 CPUtime=8.55
/proc/14065/stat : 14065 (minisatp_32) R 14064 14059 4778 34817 4778 4202496 66824 0 0 0 812 43 0 0 25 0 1 0 10636099 209833984 45292 1283457024 134512640 135413687 4289244496 18446744073709551615 134981020 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/14065/statm: 51229 45292 110 220 0 51007 0
Current children cumulated CPU time (s) 12.69
Current children cumulated vsize (KiB) 264820

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

[startup+12.8068 s]
/proc/loadavg: 1.06 1.15 1.13 2/37 14065
/proc/meminfo: memFree=165536/1048576 swapFree=0/0
[pid=14059] ppid=14058 vsize=2568 CPUtime=0
/proc/14059/stat : 14059 (packup2mp4pa-0.) S 14058 14059 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 18 0 1 0 10635684 2629632 273 1283457024 134512640 135304128 4293615840 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/14059/statm: 642 273 233 194 0 29 0
[pid=14060] ppid=14059 vsize=55664 CPUtime=4.14
/proc/14060/stat : 14060 (packup) S 14059 14059 4778 34817 4778 4202496 13549 13551 0 0 170 41 183 20 18 0 1 0 10635684 56999936 13150 1283457024 134512640 134752139 4289121376 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/14060/statm: 13916 13150 332 59 0 13080 0
[pid=14064] ppid=14060 vsize=1672 CPUtime=0
/proc/14064/stat : 14064 (sh) S 14060 14059 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 10636098 1712128 123 1283457024 134512640 134593992 4288892128 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/14064/statm: 418 123 108 20 0 45 0
[pid=14065] ppid=14064 vsize=206764 CPUtime=8.65
/proc/14065/stat : 14065 (minisatp_32) R 14064 14059 4778 34817 4778 4202496 67659 0 0 0 822 43 0 0 25 0 1 0 10636099 211726336 46098 1283457024 134512640 135413687 4289244496 18446744073709551615 134698448 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/14065/statm: 51691 46098 110 220 0 51469 0
Current children cumulated CPU time (s) 12.79
Current children cumulated vsize (KiB) 266668

[startup+14.4073 s]
/proc/loadavg: 1.06 1.15 1.13 2/39 14067
/proc/meminfo: memFree=142944/1048576 swapFree=0/0
[pid=14059] ppid=14058 vsize=2568 CPUtime=0
/proc/14059/stat : 14059 (packup2mp4pa-0.) S 14058 14059 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 18 0 1 0 10635684 2629632 273 1283457024 134512640 135304128 4293615840 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/14059/statm: 642 273 233 194 0 29 0
[pid=14060] ppid=14059 vsize=55664 CPUtime=4.14
/proc/14060/stat : 14060 (packup) S 14059 14059 4778 34817 4778 4202496 13549 13551 0 0 170 41 183 20 18 0 1 0 10635684 56999936 13150 1283457024 134512640 134752139 4289121376 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/14060/statm: 13916 13150 332 59 0 13080 0
[pid=14064] ppid=14060 vsize=1672 CPUtime=0
/proc/14064/stat : 14064 (sh) S 14060 14059 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 10636098 1712128 123 1283457024 134512640 134593992 4288892128 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/14064/statm: 418 123 108 20 0 45 0
[pid=14065] ppid=14064 vsize=209468 CPUtime=10.25
/proc/14065/stat : 14065 (minisatp_32) R 14064 14059 4778 34817 4778 4202496 69227 0 0 0 981 44 0 0 25 0 1 0 10636099 214495232 47187 1283457024 134512640 135413687 4289244496 18446744073709551615 134653618 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/14065/statm: 52367 47187 110 220 0 52145 0
Current children cumulated CPU time (s) 14.39
Current children cumulated vsize (KiB) 269372

[startup+15.2076 s]
/proc/loadavg: 1.06 1.15 1.13 2/39 14067
/proc/meminfo: memFree=142944/1048576 swapFree=0/0
[pid=14059] ppid=14058 vsize=2568 CPUtime=0
/proc/14059/stat : 14059 (packup2mp4pa-0.) S 14058 14059 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 18 0 1 0 10635684 2629632 273 1283457024 134512640 135304128 4293615840 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/14059/statm: 642 273 233 194 0 29 0
[pid=14060] ppid=14059 vsize=55664 CPUtime=4.14
/proc/14060/stat : 14060 (packup) S 14059 14059 4778 34817 4778 4202496 13549 13551 0 0 170 41 183 20 18 0 1 0 10635684 56999936 13150 1283457024 134512640 134752139 4289121376 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/14060/statm: 13916 13150 332 59 0 13080 0
[pid=14064] ppid=14060 vsize=1672 CPUtime=0
/proc/14064/stat : 14064 (sh) S 14060 14059 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 10636098 1712128 123 1283457024 134512640 134593992 4288892128 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/14064/statm: 418 123 108 20 0 45 0
[pid=14065] ppid=14064 vsize=209468 CPUtime=11.05
/proc/14065/stat : 14065 (minisatp_32) R 14064 14059 4778 34817 4778 4202496 69667 0 0 0 1061 44 0 0 25 0 1 0 10636099 214495232 47216 1283457024 134512640 135413687 4289244496 18446744073709551615 134649574 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/14065/statm: 52367 47216 110 220 0 52145 0
Current children cumulated CPU time (s) 15.19
Current children cumulated vsize (KiB) 269372

[startup+16.0079 s]
/proc/loadavg: 1.06 1.15 1.13 2/39 14067
/proc/meminfo: memFree=142572/1048576 swapFree=0/0
[pid=14059] ppid=14058 vsize=2568 CPUtime=0
/proc/14059/stat : 14059 (packup2mp4pa-0.) S 14058 14059 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 18 0 1 0 10635684 2629632 273 1283457024 134512640 135304128 4293615840 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/14059/statm: 642 273 233 194 0 29 0
[pid=14060] ppid=14059 vsize=55664 CPUtime=4.14
/proc/14060/stat : 14060 (packup) S 14059 14059 4778 34817 4778 4202496 13549 13551 0 0 170 41 183 20 18 0 1 0 10635684 56999936 13150 1283457024 134512640 134752139 4289121376 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/14060/statm: 13916 13150 332 59 0 13080 0
[pid=14064] ppid=14060 vsize=1672 CPUtime=0
/proc/14064/stat : 14064 (sh) S 14060 14059 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 10636098 1712128 123 1283457024 134512640 134593992 4288892128 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/14064/statm: 418 123 108 20 0 45 0
[pid=14065] ppid=14064 vsize=209468 CPUtime=11.84
/proc/14065/stat : 14065 (minisatp_32) R 14064 14059 4778 34817 4778 4202496 70083 0 0 0 1140 44 0 0 25 0 1 0 10636099 214495232 47224 1283457024 134512640 135413687 4289244496 18446744073709551615 134649424 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/14065/statm: 52367 47224 110 220 0 52145 0
Current children cumulated CPU time (s) 15.98
Current children cumulated vsize (KiB) 269372

[startup+16.408 s]
/proc/loadavg: 1.06 1.15 1.13 2/39 14067
/proc/meminfo: memFree=142572/1048576 swapFree=0/0
[pid=14059] ppid=14058 vsize=2568 CPUtime=0
/proc/14059/stat : 14059 (packup2mp4pa-0.) S 14058 14059 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 18 0 1 0 10635684 2629632 273 1283457024 134512640 135304128 4293615840 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/14059/statm: 642 273 233 194 0 29 0
[pid=14060] ppid=14059 vsize=54308 CPUtime=16.37
/proc/14060/stat : 14060 (packup) R 14059 14059 4778 34817 4778 4202496 25146 83792 0 0 178 43 1349 67 18 0 1 0 10635684 55611392 12824 1283457024 134512640 134752139 4289121376 18446744073709551615 4157334944 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/14060/statm: 13577 12824 345 59 0 12741 0
Current children cumulated CPU time (s) 16.37
Current children cumulated vsize (KiB) 56876

Child status: 0
Real time (s): 16.438
CPU time (s): 16.413
CPU user time (s): 15.301
CPU system time (s): 1.11207
CPU usage (%): 99.8478
Max. virtual memory (cumulated for all children) (KiB): 270352

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

runsolver used 0 second user time and 0 second system time

The end