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/201012070034/apt-pbo-trendy-1.0.6/cb0e73b0-0ffd-11df-9e59-00163e2c8d72.cudf.debian-dudf.log.runsolver ./apt-pbo-trendy-1.0.6 /home/misc2010/data/2010/debian-dudf//cb0e73b0-0ffd-11df-9e59-00163e2c8d72.cudf /home/misc2010/tmp/201012070034/apt-pbo-trendy-1.0.6/cb0e73b0-0ffd-11df-9e59-00163e2c8d72.cudf.debian-dudf.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.07 1.04 1.01 4/41 2985 /proc/meminfo: memFree=789504/1048576 swapFree=2080276/2097144 [pid=2983] ppid=2982 vsize=1676 CPUtime=0 /proc/2983/stat : 2983 (sh) S 2982 2983 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 885080548 1716224 129 1283457024 134512640 134594024 4292278112 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/2983/statm: 419 129 112 20 0 45 0 [pid=2985] ppid=2983 vsize=5016 CPUtime=0.02 /proc/2985/stat : 2985 (apt-pbo) R 2983 2983 4159 34819 4229 4202496 939 0 0 0 2 0 0 0 25 0 1 0 885080548 5136384 878 1283457024 134512640 135744540 4293255040 18446744073709551615 4158714755 0 0 128 0 0 0 0 17 0 0 0 0 /proc/2985/statm: 1254 878 410 301 0 518 0 [startup+0.16879 s] /proc/loadavg: 1.07 1.04 1.01 4/41 2985 /proc/meminfo: memFree=789504/1048576 swapFree=2080276/2097144 [pid=2983] ppid=2982 vsize=1676 CPUtime=0 /proc/2983/stat : 2983 (sh) S 2982 2983 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 885080548 1716224 129 1283457024 134512640 134594024 4292278112 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/2983/statm: 419 129 112 20 0 45 0 [pid=2985] ppid=2983 vsize=8352 CPUtime=0.04 /proc/2985/stat : 2985 (apt-pbo) R 2983 2983 4159 34819 4229 4202496 1587 413 0 0 4 0 0 0 25 0 1 0 885080548 8552448 1421 1283457024 134512640 135744540 4293255040 18446744073709551615 4294960130 0 0 128 0 0 0 0 17 0 0 0 0 /proc/2985/statm: 2088 1421 646 301 0 821 0 Current children cumulated CPU time (s) 0.04 Current children cumulated vsize (KiB) 10028 [startup+0.208793 s] /proc/loadavg: 1.07 1.04 1.01 4/41 2985 /proc/meminfo: memFree=789504/1048576 swapFree=2080276/2097144 [pid=2983] ppid=2982 vsize=1676 CPUtime=0 /proc/2983/stat : 2983 (sh) S 2982 2983 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 885080548 1716224 129 1283457024 134512640 134594024 4292278112 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/2983/statm: 419 129 112 20 0 45 0 [pid=2985] ppid=2983 vsize=8352 CPUtime=0.04 /proc/2985/stat : 2985 (apt-pbo) S 2983 2983 4159 34819 4229 4202496 1607 413 0 0 4 0 0 0 25 0 1 0 885080548 8552448 1422 1283457024 134512640 135744540 4293255040 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/2985/statm: 2088 1422 646 301 0 821 0 Current children cumulated CPU time (s) 0.04 Current children cumulated vsize (KiB) 10028 [startup+0.308817 s] /proc/loadavg: 1.07 1.04 1.01 4/41 2985 /proc/meminfo: memFree=789504/1048576 swapFree=2080276/2097144 [pid=2983] ppid=2982 vsize=1676 CPUtime=0 /proc/2983/stat : 2983 (sh) S 2982 2983 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 885080548 1716224 129 1283457024 134512640 134594024 4292278112 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/2983/statm: 419 129 112 20 0 45 0 [pid=2985] ppid=2983 vsize=8352 CPUtime=0.04 /proc/2985/stat : 2985 (apt-pbo) S 2983 2983 4159 34819 4229 4202496 1607 413 0 0 4 0 0 0 25 0 1 0 885080548 8552448 1422 1283457024 134512640 135744540 4293255040 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/2985/statm: 2088 1422 646 301 0 821 0 Current children cumulated CPU time (s) 0.04 Current children cumulated vsize (KiB) 10028 [startup+0.708911 s] /proc/loadavg: 1.07 1.04 1.01 4/41 2985 /proc/meminfo: memFree=789504/1048576 swapFree=2080276/2097144 [pid=2983] ppid=2982 vsize=1676 CPUtime=0 /proc/2983/stat : 2983 (sh) S 2982 2983 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 885080548 1716224 129 1283457024 134512640 134594024 4292278112 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/2983/statm: 419 129 112 20 0 45 0 [pid=2985] ppid=2983 vsize=8352 CPUtime=0.04 /proc/2985/stat : 2985 (apt-pbo) S 2983 2983 4159 34819 4229 4202496 1607 413 0 0 4 0 0 0 25 0 1 0 885080548 8552448 1422 1283457024 134512640 135744540 4293255040 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/2985/statm: 2088 1422 646 301 0 821 0 Current children cumulated CPU time (s) 0.04 Current children cumulated vsize (KiB) 10028 [startup+1.50909 s] /proc/loadavg: 1.07 1.04 1.01 2/43 2989 /proc/meminfo: memFree=767788/1048576 swapFree=2080276/2097144 [pid=2983] ppid=2982 vsize=1676 CPUtime=0 /proc/2983/stat : 2983 (sh) S 2982 2983 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 885080548 1716224 129 1283457024 134512640 134594024 4292278112 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/2983/statm: 419 129 112 20 0 45 0 [pid=2985] ppid=2983 vsize=8352 CPUtime=0.04 /proc/2985/stat : 2985 (apt-pbo) S 2983 2983 4159 34819 4229 4202496 1607 413 0 0 4 0 0 0 25 0 1 0 885080548 8552448 1422 1283457024 134512640 135744540 4293255040 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/2985/statm: 2088 1422 646 301 0 821 0 [pid=2989] ppid=2985 vsize=30180 CPUtime=1.45 /proc/2989/stat : 2989 (cudftodeb.nativ) R 2985 2983 4159 34819 4229 4202496 7212 0 0 0 142 3 0 0 25 0 1 0 885080554 30904320 7130 1283457024 134512640 135029684 4286601632 18446744073709551615 135003825 0 0 0 1024 0 0 0 17 0 0 0 0 /proc/2989/statm: 7545 7130 247 127 0 6928 0 Current children cumulated CPU time (s) 1.49 Current children cumulated vsize (KiB) 40208 [startup+3.10951 s] /proc/loadavg: 1.07 1.04 1.01 2/43 2989 /proc/meminfo: memFree=746088/1048576 swapFree=2080276/2097144 [pid=2983] ppid=2982 vsize=1676 CPUtime=0 /proc/2983/stat : 2983 (sh) S 2982 2983 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 885080548 1716224 129 1283457024 134512640 134594024 4292278112 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/2983/statm: 419 129 112 20 0 45 0 [pid=2985] ppid=2983 vsize=8352 CPUtime=0.04 /proc/2985/stat : 2985 (apt-pbo) S 2983 2983 4159 34819 4229 4202496 1607 413 0 0 4 0 0 0 25 0 1 0 885080548 8552448 1422 1283457024 134512640 135744540 4293255040 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/2985/statm: 2088 1422 646 301 0 821 0 [pid=2989] ppid=2985 vsize=52356 CPUtime=3.06 /proc/2989/stat : 2989 (cudftodeb.nativ) R 2985 2983 4159 34819 4229 4202496 12747 0 0 0 266 40 0 0 25 0 1 0 885080554 53612544 12665 1283457024 134512640 135029684 4286601632 18446744073709551615 4294960130 0 0 0 1024 0 0 0 17 0 0 0 0 /proc/2989/statm: 13089 12665 258 127 0 12472 0 Current children cumulated CPU time (s) 3.1 Current children cumulated vsize (KiB) 62384 [startup+6.31456 s] /proc/loadavg: 1.06 1.04 1.00 1/44 2997 /proc/meminfo: memFree=750740/1048576 swapFree=2080276/2097144 [pid=2983] ppid=2982 vsize=1676 CPUtime=0 /proc/2983/stat : 2983 (sh) S 2982 2983 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 885080548 1716224 129 1283457024 134512640 134594024 4292278112 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/2983/statm: 419 129 112 20 0 45 0 [pid=2985] ppid=2983 vsize=22368 CPUtime=4.82 /proc/2985/stat : 2985 (apt-pbo) S 2983 2983 4159 34819 4229 4202496 5685 20584 0 163 17 4 392 69 18 0 1 0 885080548 22904832 4815 1283457024 134512640 135744540 4293255040 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/2985/statm: 5592 4815 3443 301 0 1417 0 Current children cumulated CPU time (s) 4.82 Current children cumulated vsize (KiB) 24044 heavy processes: [startup+12.7066 s] /proc/loadavg: 1.06 1.04 1.00 2/43 3003 /proc/meminfo: memFree=714672/1048576 swapFree=2080276/2097144 [pid=2983] ppid=2982 vsize=1676 CPUtime=0 /proc/2983/stat : 2983 (sh) S 2982 2983 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 885080548 1716224 129 1283457024 134512640 134594024 4292278112 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/2983/statm: 419 129 112 20 0 45 0 [pid=2985] ppid=2983 vsize=23960 CPUtime=6.52 /proc/2985/stat : 2985 (apt-pbo) S 2983 2983 4159 34819 4229 4202496 6209 25310 0 163 20 10 523 99 18 0 1 0 885080548 24535040 5216 1283457024 134512640 135744540 4293255040 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/2985/statm: 5990 5216 3446 301 0 1815 0 [pid=3003] ppid=2985 vsize=32828 CPUtime=5.25 /proc/3003/stat : 3003 (wbo) R 2985 2983 4159 34819 4229 4202496 8410 0 0 0 514 11 0 0 25 0 1 0 885081293 33615872 7941 1283457024 4194304 5578286 140736999247488 18446744073709551615 4200762 0 0 0 3 0 0 0 17 0 0 0 0 /proc/3003/statm: 8207 7941 157 338 0 7866 0 Current children cumulated CPU time (s) 11.77 Current children cumulated vsize (KiB) 58464 [startup+25.5101 s] /proc/loadavg: 1.04 1.03 1.00 2/43 3003 /proc/meminfo: memFree=693972/1048576 swapFree=2080276/2097144 [pid=2983] ppid=2982 vsize=1676 CPUtime=0 /proc/2983/stat : 2983 (sh) S 2982 2983 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 885080548 1716224 129 1283457024 134512640 134594024 4292278112 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/2983/statm: 419 129 112 20 0 45 0 [pid=2985] ppid=2983 vsize=23960 CPUtime=6.52 /proc/2985/stat : 2985 (apt-pbo) S 2983 2983 4159 34819 4229 4202496 6209 25310 0 163 20 10 523 99 18 0 1 0 885080548 24535040 5216 1283457024 134512640 135744540 4293255040 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/2985/statm: 5990 5216 3446 301 0 1815 0 [pid=3003] ppid=2985 vsize=50524 CPUtime=18.02 /proc/3003/stat : 3003 (wbo) R 2985 2983 4159 34819 4229 4202496 12853 0 0 0 1789 13 0 0 25 0 1 0 885081293 51736576 12384 1283457024 4194304 5578286 140736999247488 18446744073709551615 4200602 0 0 0 3 0 0 0 17 0 0 0 0 /proc/3003/statm: 12631 12384 157 338 0 12290 0 Current children cumulated CPU time (s) 24.54 Current children cumulated vsize (KiB) 76160 [startup+51.1074 s] /proc/loadavg: 1.03 1.03 1.00 2/43 3003 /proc/meminfo: memFree=672520/1048576 swapFree=2080276/2097144 [pid=2983] ppid=2982 vsize=1676 CPUtime=0 /proc/2983/stat : 2983 (sh) S 2982 2983 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 885080548 1716224 129 1283457024 134512640 134594024 4292278112 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/2983/statm: 419 129 112 20 0 45 0 [pid=2985] ppid=2983 vsize=23960 CPUtime=6.52 /proc/2985/stat : 2985 (apt-pbo) S 2983 2983 4159 34819 4229 4202496 6209 25310 0 163 20 10 523 99 18 0 1 0 885080548 24535040 5216 1283457024 134512640 135744540 4293255040 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/2985/statm: 5990 5216 3446 301 0 1815 0 [pid=3003] ppid=2985 vsize=72096 CPUtime=43.57 /proc/3003/stat : 3003 (wbo) R 2985 2983 4159 34819 4229 4202496 18240 0 0 0 4339 18 0 0 25 0 1 0 885081293 73826304 17771 1283457024 4194304 5578286 140736999247488 18446744073709551615 4200272 0 0 0 3 0 0 0 17 0 0 0 0 /proc/3003/statm: 18024 17771 157 338 0 17683 0 Current children cumulated CPU time (s) 50.09 Current children cumulated vsize (KiB) 97732 [startup+102.313 s] /proc/loadavg: 1.01 1.02 1.00 2/43 3003 /proc/meminfo: memFree=642388/1048576 swapFree=2080276/2097144 [pid=2983] ppid=2982 vsize=1676 CPUtime=0 /proc/2983/stat : 2983 (sh) S 2982 2983 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 885080548 1716224 129 1283457024 134512640 134594024 4292278112 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/2983/statm: 419 129 112 20 0 45 0 [pid=2985] ppid=2983 vsize=23960 CPUtime=6.52 /proc/2985/stat : 2985 (apt-pbo) S 2983 2983 4159 34819 4229 4202496 6209 25310 0 163 20 10 523 99 18 0 1 0 885080548 24535040 5216 1283457024 134512640 135744540 4293255040 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/2985/statm: 5990 5216 3446 301 0 1815 0 [pid=3003] ppid=2985 vsize=101868 CPUtime=94.74 /proc/3003/stat : 3003 (wbo) R 2985 2983 4159 34819 4229 4202496 25677 0 0 0 9447 27 0 0 25 0 1 0 885081293 104312832 25208 1283457024 4194304 5578286 140736999247488 18446744073709551615 4200618 0 0 0 3 0 0 0 17 0 0 0 0 /proc/3003/statm: 25467 25208 157 338 0 25126 0 Current children cumulated CPU time (s) 101.26 Current children cumulated vsize (KiB) 127504 [startup+162.313 s] /proc/loadavg: 1.00 1.02 1.00 2/43 3003 /proc/meminfo: memFree=624408/1048576 swapFree=2080276/2097144 [pid=2983] ppid=2982 vsize=1676 CPUtime=0 /proc/2983/stat : 2983 (sh) S 2982 2983 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 885080548 1716224 129 1283457024 134512640 134594024 4292278112 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/2983/statm: 419 129 112 20 0 45 0 [pid=2985] ppid=2983 vsize=23960 CPUtime=6.53 /proc/2985/stat : 2985 (apt-pbo) S 2983 2983 4159 34819 4229 4202496 6209 25310 0 163 20 11 523 99 18 0 1 0 885080548 24535040 5216 1283457024 134512640 135744540 4293255040 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/2985/statm: 5990 5216 3446 301 0 1815 0 [pid=3003] ppid=2985 vsize=119956 CPUtime=154.65 /proc/3003/stat : 3003 (wbo) R 2985 2983 4159 34819 4229 4202496 30200 0 0 0 15434 31 0 0 25 0 1 0 885081293 122834944 29731 1283457024 4194304 5578286 140736999247488 18446744073709551615 4200618 0 0 0 3 0 0 0 17 0 0 0 0 /proc/3003/statm: 29989 29731 157 338 0 29648 0 Current children cumulated CPU time (s) 161.18 Current children cumulated vsize (KiB) 145592 Maximum VSize exceeded: sending signal-name then SIGKILL [startup+197.805 s] /proc/loadavg: 1.24 1.06 1.02 1/43 3003 /proc/meminfo: memFree=5228/1048576 swapFree=1913316/2097144 [pid=2983] ppid=2982 vsize=1676 CPUtime=0 /proc/2983/stat : 2983 (sh) S 2982 2983 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 885080548 1716224 129 1283457024 134512640 134594024 4292278112 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/2983/statm: 419 129 112 20 0 45 0 [pid=2985] ppid=2983 vsize=23960 CPUtime=6.54 /proc/2985/stat : 2985 (apt-pbo) S 2983 2983 4159 34819 4229 4202496 6210 25310 0 163 20 12 523 99 18 0 1 0 885080548 24535040 5216 1283457024 134512640 135744540 4293255040 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/2985/statm: 5990 5216 3446 301 0 1815 0 [pid=3003] ppid=2985 vsize=1128900 CPUtime=188.3 /proc/3003/stat : 3003 (wbo) D 2985 2983 4159 34819 4229 4204544 282550 0 0 0 18700 130 0 0 24 0 1 0 885081293 1155993600 240244 1283457024 4194304 5578286 140736999247488 18446744073709551615 4291078 0 0 0 3 18446744071564332537 0 0 17 0 0 0 0 /proc/3003/statm: 282225 240244 159 338 0 281884 0 Current children cumulated CPU time (s) 194.84 Current children cumulated vsize (KiB) 1154536 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+197.805 s] /proc/loadavg: 1.24 1.06 1.02 1/43 3003 /proc/meminfo: memFree=5228/1048576 swapFree=1913316/2097144 [pid=2983] ppid=2982 vsize=1676 CPUtime=0 /proc/2983/stat : 2983 (sh) S 2982 2983 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 885080548 1716224 129 1283457024 134512640 134594024 4292278112 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/2983/statm: 419 129 112 20 0 45 0 [pid=2985] ppid=2983 vsize=23960 CPUtime=6.54 /proc/2985/stat : 2985 (apt-pbo) S 2983 2983 4159 34819 4229 4202496 6210 25310 0 163 20 12 523 99 18 0 1 0 885080548 24535040 5216 1283457024 134512640 135744540 4293255040 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/2985/statm: 5990 5216 3446 301 0 1815 0 [pid=3003] ppid=2985 vsize=1128900 CPUtime=188.3 /proc/3003/stat : 3003 (wbo) D 2985 2983 4159 34819 4229 4204544 282550 0 0 0 18700 130 0 0 24 0 1 0 885081293 1155993600 240244 1283457024 4194304 5578286 140736999247488 18446744073709551615 4291078 0 0 0 3 18446744071564332537 0 0 17 0 0 0 0 /proc/3003/statm: 282225 240244 159 338 0 281884 0 Current children cumulated CPU time (s) 194.84 Current children cumulated vsize (KiB) 1154536 Child ended because it received signal 10 (SIGUSR1) # WARNING: # CPU time reported by wait4() is probably wrong ! # wait4(...,&childrusage) returns 2983 and gives # childrusage.ru_utime.tv_sec=5 # childrusage.ru_utime.tv_usec=440340 # childrusage.ru_stime.tv_sec=1 # childrusage.ru_stime.tv_usec=112069 # CPU time returned by wait4() is 6.55241 # while last known CPU time is 194.84 # # Solver probably didn't/couldn't wait for its children # Using CPU time of the last sample as value... Real time (s): 197.969 CPU time (s): 194.84 CPU user time (s): 192.43 CPU system time (s): 2.41 CPU usage (%): 98.4194 Max. virtual memory (cumulated for all children) (KiB): 1154536 getrusage(RUSAGE_CHILDREN,...) data: user time used= 5.44034 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= 31928 page faults= 163 swaps= 0 block input operations= 0 block output operations= 0 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 46954 involuntary context switches= 39051 runsolver used 0 second user time and 0.012 second system time The end