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: runsolver -s SIGUSR1 -M 1124 -C 300 -d 10 -w /tmp/misc2012/2012-09-02-22:42/full/aspcud-full-1.7/slowlink/real/978532fa-c730-11df-b070-00163e3d3b7c.cudf.log.runsolver /home/competition/aspcud-full-1.7/aspcud-full /home/competition/data/real/978532fa-c730-11df-b070-00163e3d3b7c.cudf /tmp/misc2012/2012-09-02-22:42/full/aspcud-full-1.7/slowlink/real/978532fa-c730-11df-b070-00163e3d3b7c.cudf.result -sum(changed,installedsize),-count(removed),-notuptodate(solution),-count(changed) 

Enforcing CPUTime limit (soft limit, will send signal-name then SIGKILL): 300 seconds
Enforcing CPUTime limit (hard limit, will send SIGXCPU): 330 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

[startup+0 s]
/proc/loadavg: 0.89 0.94 0.98 2/59 4050
/proc/meminfo: memFree=580760/1022884 swapFree=0/0
[pid=4050] ppid=4049 vsize=3152 CPUtime=0
/proc/4050/stat : 4050 (runsolver) R 4049 1733 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 1 0 120149903 3227648 32 18446744073709551615 134512640 134586868 4289402624 4289400672 4152165424 0 0 16781316 24578 0 0 0 17 0 0 0 0 0 0
/proc/4050/statm: 788 32 0 19 0 73 0
Current StackSize limit: 8192 KiB


[startup+0.115274 s]
/proc/loadavg: 0.89 0.94 0.98 2/59 4050
/proc/meminfo: memFree=580760/1022884 swapFree=0/0
[pid=4050] ppid=4049 vsize=9212 CPUtime=0.02
/proc/4050/stat : 4050 (aspcud-full) S 4049 4050 1733 0 -1 4202496 739 3620 0 0 0 0 2 0 20 0 1 0 120149903 9433088 364 18446744073709551615 4194304 5129932 140736795747968 140736795746624 139917211391070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/4050/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 9212

[startup+0.200399 s]
/proc/loadavg: 0.89 0.94 0.98 2/59 4050
/proc/meminfo: memFree=580760/1022884 swapFree=0/0
[pid=4050] ppid=4049 vsize=9212 CPUtime=0.02
/proc/4050/stat : 4050 (aspcud-full) S 4049 4050 1733 0 -1 4202496 739 3620 0 0 0 0 2 0 20 0 1 0 120149903 9433088 364 18446744073709551615 4194304 5129932 140736795747968 140736795746624 139917211391070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/4050/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 9212

[startup+0.300261 s]
/proc/loadavg: 0.89 0.94 0.98 2/59 4050
/proc/meminfo: memFree=580760/1022884 swapFree=0/0
[pid=4050] ppid=4049 vsize=9212 CPUtime=0.02
/proc/4050/stat : 4050 (aspcud-full) S 4049 4050 1733 0 -1 4202496 739 3620 0 0 0 0 2 0 20 0 1 0 120149903 9433088 364 18446744073709551615 4194304 5129932 140736795747968 140736795746624 139917211391070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/4050/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 9212

[startup+0.700195 s]
/proc/loadavg: 0.89 0.94 0.98 2/59 4050
/proc/meminfo: memFree=580760/1022884 swapFree=0/0
[pid=4050] ppid=4049 vsize=9212 CPUtime=0.02
/proc/4050/stat : 4050 (aspcud-full) S 4049 4050 1733 0 -1 4202496 739 3620 0 0 0 0 2 0 20 0 1 0 120149903 9433088 364 18446744073709551615 4194304 5129932 140736795747968 140736795746624 139917211391070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/4050/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 9212

[startup+1.50024 s]
/proc/loadavg: 0.89 0.94 0.98 1/61 4066
/proc/meminfo: memFree=521836/1022884 swapFree=0/0
[pid=4050] ppid=4049 vsize=9212 CPUtime=0.02
/proc/4050/stat : 4050 (aspcud-full) S 4049 4050 1733 0 -1 4202496 739 3620 0 0 0 0 2 0 20 0 1 0 120149903 9433088 364 18446744073709551615 4194304 5129932 140736795747968 140736795746624 139917211391070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/4050/statm: 2303 364 303 229 0 63 0
[pid=4066] ppid=4050 vsize=51500 CPUtime=1.38
/proc/4066/stat : 4066 (cudf2lp) R 4050 4050 1733 0 -1 4202496 15362 0 0 0 132 6 0 0 20 0 1 0 120149905 52736000 11962 18446744073709551615 4194304 5690517 140737367374096 140737367371736 4340504 0 0 16781316 0 0 0 0 17 0 0 0 8 0 0
/proc/4066/statm: 12875 11962 160 366 0 12506 0
Current children cumulated CPU time (s) 1.4
Current children cumulated vsize (KiB) 60712

[startup+3.10026 s]
/proc/loadavg: 0.89 0.94 0.98 2/61 4067
/proc/meminfo: memFree=545396/1022884 swapFree=0/0
[pid=4050] ppid=4049 vsize=9212 CPUtime=2.02
/proc/4050/stat : 4050 (aspcud-full) S 4049 4050 1733 0 -1 4202496 763 29064 0 0 0 0 190 12 20 0 1 0 120149903 9433088 364 18446744073709551615 4194304 5129932 140736795747968 140736795746624 139917211391070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/4050/statm: 2303 364 303 229 0 63 0
[pid=4067] ppid=4050 vsize=53900 CPUtime=0.98
/proc/4067/stat : 4067 (gringo) R 4050 4050 1733 0 -1 4202496 14431 0 0 0 92 6 0 0 20 0 1 0 120150114 55193600 11810 18446744073709551615 4194304 6531320 140735969264464 140735969261064 4330265 0 0 16781316 16386 0 0 0 17 0 0 0 0 0 0
/proc/4067/statm: 13475 11810 277 571 0 12896 0
Current children cumulated CPU time (s) 3
Current children cumulated vsize (KiB) 63112

[startup+6.30025 s]
/proc/loadavg: 0.89 0.94 0.98 2/61 4067
/proc/meminfo: memFree=254616/1022884 swapFree=0/0
[pid=4050] ppid=4049 vsize=9212 CPUtime=2.02
/proc/4050/stat : 4050 (aspcud-full) S 4049 4050 1733 0 -1 4202496 763 29064 0 0 0 0 190 12 20 0 1 0 120149903 9433088 364 18446744073709551615 4194304 5129932 140736795747968 140736795746624 139917211391070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/4050/statm: 2303 364 303 229 0 63 0
[pid=4067] ppid=4050 vsize=435564 CPUtime=4.15
/proc/4067/stat : 4067 (gringo) R 4050 4050 1733 0 -1 4202496 101857 0 0 0 383 32 0 0 20 0 1 0 120150114 446017536 93090 18446744073709551615 4194304 6531320 140735969264464 140735969261448 4363191 0 0 16781316 16386 0 0 0 17 0 0 0 0 0 0
/proc/4067/statm: 108891 93090 283 571 0 108312 0
Current children cumulated CPU time (s) 6.17
Current children cumulated vsize (KiB) 444776

[startup+12.7003 s]
/proc/loadavg: 0.91 0.94 0.98 2/62 4069
/proc/meminfo: memFree=393364/1022884 swapFree=0/0
[pid=4050] ppid=4049 vsize=9212 CPUtime=6.85
/proc/4050/stat : 4050 (aspcud-full) S 4049 4050 1733 0 -1 4202496 801 138102 0 0 0 0 628 57 20 0 1 0 120149903 9433088 364 18446744073709551615 4194304 5129932 140736795747968 140736795746032 139917211391070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/4050/statm: 2303 364 303 229 0 63 0
[pid=4068] ppid=4050 vsize=141576 CPUtime=5.67
/proc/4068/stat : 4068 (clasp) R 4050 4050 1733 0 -1 4202496 41426 0 0 0 556 11 0 0 20 0 1 0 120150601 144973824 34984 18446744073709551615 4194304 6238623 140733218095072 140733218092096 4356208 0 0 16781316 18946 0 0 0 17 0 0 0 0 0 0
/proc/4068/statm: 35394 34984 263 500 0 34891 0
[pid=4069] ppid=4050 vsize=22040 CPUtime=0.01
/proc/4069/stat : 4069 (parse.py) S 4050 4050 1733 0 -1 4202496 1319 0 0 0 0 1 0 0 20 0 1 0 120150601 22568960 1128 18446744073709551615 4194304 6642060 140736283853664 140736283852024 140665110046496 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/4069/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 12.53
Current children cumulated vsize (KiB) 172828

[startup+25.5003 s]
/proc/loadavg: 0.92 0.94 0.98 2/62 4069
/proc/meminfo: memFree=393240/1022884 swapFree=0/0
[pid=4050] ppid=4049 vsize=9212 CPUtime=6.85
/proc/4050/stat : 4050 (aspcud-full) S 4049 4050 1733 0 -1 4202496 801 138102 0 0 0 0 628 57 20 0 1 0 120149903 9433088 364 18446744073709551615 4194304 5129932 140736795747968 140736795746032 139917211391070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/4050/statm: 2303 364 303 229 0 63 0
[pid=4068] ppid=4050 vsize=141576 CPUtime=18.37
/proc/4068/stat : 4068 (clasp) R 4050 4050 1733 0 -1 4202496 41426 0 0 0 1826 11 0 0 20 0 1 0 120150601 144973824 34984 18446744073709551615 4194304 6238623 140733218095072 140733218092096 4407011 0 0 16781316 18946 0 0 0 17 0 0 0 0 0 0
/proc/4068/statm: 35394 34984 263 500 0 34891 0
[pid=4069] ppid=4050 vsize=22040 CPUtime=0.01
/proc/4069/stat : 4069 (parse.py) S 4050 4050 1733 0 -1 4202496 1319 0 0 0 0 1 0 0 20 0 1 0 120150601 22568960 1128 18446744073709551615 4194304 6642060 140736283853664 140736283852024 140665110046496 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/4069/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 25.23
Current children cumulated vsize (KiB) 172828

[startup+51.1003 s]
/proc/loadavg: 0.95 0.95 0.98 2/62 4069
/proc/meminfo: memFree=392992/1022884 swapFree=0/0
[pid=4050] ppid=4049 vsize=9212 CPUtime=6.85
/proc/4050/stat : 4050 (aspcud-full) S 4049 4050 1733 0 -1 4202496 801 138102 0 0 0 0 628 57 20 0 1 0 120149903 9433088 364 18446744073709551615 4194304 5129932 140736795747968 140736795746032 139917211391070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/4050/statm: 2303 364 303 229 0 63 0
[pid=4068] ppid=4050 vsize=141576 CPUtime=43.79
/proc/4068/stat : 4068 (clasp) R 4050 4050 1733 0 -1 4202496 41504 0 0 0 4367 12 0 0 20 0 1 0 120150601 144973824 35062 18446744073709551615 4194304 6238623 140733218095072 140733218092096 4677462 0 0 16781316 18946 0 0 0 17 0 0 0 0 0 0
/proc/4068/statm: 35394 35062 263 500 0 34891 0
[pid=4069] ppid=4050 vsize=22040 CPUtime=0.01
/proc/4069/stat : 4069 (parse.py) S 4050 4050 1733 0 -1 4202496 1319 0 0 0 0 1 0 0 20 0 1 0 120150601 22568960 1128 18446744073709551615 4194304 6642060 140736283853664 140736283852024 140665110046496 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/4069/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 50.65
Current children cumulated vsize (KiB) 172828

[startup+102.3 s]
/proc/loadavg: 0.98 0.95 0.98 2/62 4069
/proc/meminfo: memFree=383692/1022884 swapFree=0/0
[pid=4050] ppid=4049 vsize=9212 CPUtime=6.85
/proc/4050/stat : 4050 (aspcud-full) S 4049 4050 1733 0 -1 4202496 801 138102 0 0 0 0 628 57 20 0 1 0 120149903 9433088 364 18446744073709551615 4194304 5129932 140736795747968 140736795746032 139917211391070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/4050/statm: 2303 364 303 229 0 63 0
[pid=4068] ppid=4050 vsize=153868 CPUtime=94.61
/proc/4068/stat : 4068 (clasp) R 4050 4050 1733 0 -1 4202496 43808 0 0 0 9449 12 0 0 20 0 1 0 120150601 157560832 37366 18446744073709551615 4194304 6238623 140733218095072 140733218092096 4355623 0 0 16781316 18946 0 0 0 17 0 0 0 0 0 0
/proc/4068/statm: 38467 37366 263 500 0 37964 0
[pid=4069] ppid=4050 vsize=22040 CPUtime=0.01
/proc/4069/stat : 4069 (parse.py) S 4050 4050 1733 0 -1 4202496 1319 0 0 0 0 1 0 0 20 0 1 0 120150601 22568960 1128 18446744073709551615 4194304 6642060 140736283853664 140736283852024 140665110046496 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/4069/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 101.47
Current children cumulated vsize (KiB) 185120

[startup+162.3 s]
/proc/loadavg: 1.35 1.04 1.01 2/62 4320
/proc/meminfo: memFree=182928/1022884 swapFree=0/0
[pid=4050] ppid=4049 vsize=9212 CPUtime=6.85
/proc/4050/stat : 4050 (aspcud-full) S 4049 4050 1733 0 -1 4202496 801 138102 0 0 0 0 628 57 20 0 1 0 120149903 9433088 364 18446744073709551615 4194304 5129932 140736795747968 140736795746032 139917211391070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/4050/statm: 2303 364 303 229 0 63 0
[pid=4068] ppid=4050 vsize=206200 CPUtime=148.39
/proc/4068/stat : 4068 (clasp) R 4050 4050 1733 0 -1 4202496 56835 0 0 0 14816 23 0 0 20 0 1 0 120150601 211148800 50393 18446744073709551615 4194304 6238623 140733218095072 140733218092096 4407044 0 0 16781316 18946 0 0 0 17 0 0 0 0 0 0
/proc/4068/statm: 51550 50393 263 500 0 51047 0
[pid=4069] ppid=4050 vsize=22040 CPUtime=0.01
/proc/4069/stat : 4069 (parse.py) S 4050 4050 1733 0 -1 4202496 1319 0 0 0 0 1 0 0 20 0 1 0 120150601 22568960 1128 18446744073709551615 4194304 6642060 140736283853664 140736283852024 140665110046496 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/4069/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 155.25
Current children cumulated vsize (KiB) 237452

[startup+222.303 s]
/proc/loadavg: 1.13 1.03 1.00 2/62 4320
/proc/meminfo: memFree=154408/1022884 swapFree=0/0
[pid=4050] ppid=4049 vsize=9212 CPUtime=6.85
/proc/4050/stat : 4050 (aspcud-full) S 4049 4050 1733 0 -1 4202496 801 138102 0 0 0 0 628 57 20 0 1 0 120149903 9433088 364 18446744073709551615 4194304 5129932 140736795747968 140736795746032 139917211391070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/4050/statm: 2303 364 303 229 0 63 0
[pid=4068] ppid=4050 vsize=237696 CPUtime=207.95
/proc/4068/stat : 4068 (clasp) R 4050 4050 1733 0 -1 4202496 64643 0 0 0 20767 28 0 0 20 0 1 0 120150601 243400704 58201 18446744073709551615 4194304 6238623 140733218095072 140733218091624 4684903 0 0 16781316 18946 0 0 0 17 0 0 0 0 0 0
/proc/4068/statm: 59424 58201 263 500 0 58921 0
[pid=4069] ppid=4050 vsize=22040 CPUtime=0.01
/proc/4069/stat : 4069 (parse.py) S 4050 4050 1733 0 -1 4202496 1319 0 0 0 0 1 0 0 20 0 1 0 120150601 22568960 1128 18446744073709551615 4194304 6642060 140736283853664 140736283852024 140665110046496 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/4069/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 214.81
Current children cumulated vsize (KiB) 268948

[startup+282.3 s]
/proc/loadavg: 1.05 1.02 1.00 2/62 4320
/proc/meminfo: memFree=121052/1022884 swapFree=0/0
[pid=4050] ppid=4049 vsize=9212 CPUtime=6.85
/proc/4050/stat : 4050 (aspcud-full) S 4049 4050 1733 0 -1 4202496 801 138102 0 0 0 0 628 57 20 0 1 0 120149903 9433088 364 18446744073709551615 4194304 5129932 140736795747968 140736795746032 139917211391070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/4050/statm: 2303 364 303 229 0 63 0
[pid=4068] ppid=4050 vsize=270068 CPUtime=267.51
/proc/4068/stat : 4068 (clasp) R 4050 4050 1733 0 -1 4202496 72768 0 0 0 26716 35 0 0 20 0 1 0 120150601 276549632 66326 18446744073709551615 4194304 6238623 140733218095072 140733218092096 4407104 0 0 16781316 18946 0 0 0 17 0 0 0 0 0 0
/proc/4068/statm: 67517 66326 263 500 0 67014 0
[pid=4069] ppid=4050 vsize=22040 CPUtime=0.01
/proc/4069/stat : 4069 (parse.py) S 4050 4050 1733 0 -1 4202496 1319 0 0 0 0 1 0 0 20 0 1 0 120150601 22568960 1128 18446744073709551615 4194304 6642060 140736283853664 140736283852024 140665110046496 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/4069/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 274.37
Current children cumulated vsize (KiB) 301320



Maximum CPU time exceeded: sending signal-name then SIGKILL

[startup+308.2 s]
/proc/loadavg: 1.03 1.02 1.00 2/62 4320
/proc/meminfo: memFree=83356/1022884 swapFree=0/0
[pid=4050] ppid=4049 vsize=9212 CPUtime=6.85
/proc/4050/stat : 4050 (aspcud-full) S 4049 4050 1733 0 -1 4202496 801 138102 0 0 0 0 628 57 20 0 1 0 120149903 9433088 364 18446744073709551615 4194304 5129932 140736795747968 140736795746032 139917211391070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/4050/statm: 2303 364 303 229 0 63 0
[pid=4068] ppid=4050 vsize=308004 CPUtime=293.21
/proc/4068/stat : 4068 (clasp) R 4050 4050 1733 0 -1 4202496 82205 0 0 0 29283 38 0 0 20 0 1 0 120150601 315396096 75763 18446744073709551615 4194304 6238623 140733218095072 140733218092096 4306755 0 0 16781316 18946 0 0 0 17 0 0 0 0 0 0
/proc/4068/statm: 77001 75763 263 500 0 76498 0
[pid=4069] ppid=4050 vsize=22040 CPUtime=0.01
/proc/4069/stat : 4069 (parse.py) S 4050 4050 1733 0 -1 4202496 1319 0 0 0 0 1 0 0 20 0 1 0 120150601 22568960 1128 18446744073709551615 4194304 6642060 140736283853664 140736283852024 140665110046496 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/4069/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 300.07
Current children cumulated vsize (KiB) 339256

Sending User defined signal 1 to process tree (bottom up)
Sleeping 10 seconds

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

[startup+308.2 s]
/proc/loadavg: 1.03 1.02 1.00 2/62 4320
/proc/meminfo: memFree=83356/1022884 swapFree=0/0
[pid=4050] ppid=4049 vsize=9212 CPUtime=6.85
/proc/4050/stat : 4050 (aspcud-full) S 4049 4050 1733 0 -1 4202496 801 138102 0 0 0 0 628 57 20 0 1 0 120149903 9433088 364 18446744073709551615 4194304 5129932 140736795747968 140736795746032 139917211391070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/4050/statm: 2303 364 303 229 0 63 0
[pid=4068] ppid=4050 vsize=308004 CPUtime=293.21
/proc/4068/stat : 4068 (clasp) R 4050 4050 1733 0 -1 4202496 82205 0 0 0 29283 38 0 0 20 0 1 0 120150601 315396096 75763 18446744073709551615 4194304 6238623 140733218095072 140733218092096 4306755 0 0 16781316 18946 0 0 0 17 0 0 0 0 0 0
/proc/4068/statm: 77001 75763 263 500 0 76498 0
[pid=4069] ppid=4050 vsize=22040 CPUtime=0.01
/proc/4069/stat : 4069 (parse.py) S 4050 4050 1733 0 -1 4202496 1319 0 0 0 0 1 0 0 20 0 1 0 120150601 22568960 1128 18446744073709551615 4194304 6642060 140736283853664 140736283852024 140665110046496 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/4069/statm: 5510 1128 508 598 0 596 0
Current children cumulated CPU time (s) 300.07
Current children cumulated vsize (KiB) 339256

Child status: 0
Real time (s): 308.246
CPU time (s): 300.143
CPU user time (s): 299.135
CPU system time (s): 1.00806
CPU usage (%): 97.3711
Max. virtual memory (cumulated for all children) (KiB): 476516

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 299.135
system time used= 1.00806
maximum resident set size= 401068
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 222778
page faults= 0
swaps= 0
block input operations= 43848
block output operations= 46928
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 89
involuntary context switches= 36814

runsolver used 0.476029 second user time and 1.14407 second system time

The end