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/201108311143/aspcud-1.5/rand59.cudf.dudf-random.log.runsolver ./aspcud-1.5 /home/misc2010/data/2011/dudf-random//rand59.cudf /home/misc2010/tmp/201108311143/aspcud-1.5/rand59.cudf.dudf-random.result -sum(installedsize) 

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.14 1.09 1.03 5/40 25668
/proc/meminfo: memFree=730708/1048576 swapFree=0/0
[pid=25666] ppid=25665 vsize=2588 CPUtime=0
/proc/25666/stat : 25666 (aspcud-1.5) S 25665 25666 19908 34817 19908 4202496 372 0 0 0 0 0 0 0 18 0 1 0 63641241 2650112 279 1283457024 134512640 135304128 4288535552 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0
/proc/25666/statm: 647 279 234 194 0 34 0
[pid=25667] ppid=25666 vsize=2588 CPUtime=0
/proc/25667/stat : 25667 (aspcud-1.5) R 25666 25666 19908 34817 19908 4202560 110 0 0 0 0 0 0 0 25 0 1 0 63641241 2650112 132 1283457024 134512640 135304128 4288535552 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/25667/statm: 647 132 86 194 0 34 0
[pid=25668] ppid=25667 vsize=2588 CPUtime=0
/proc/25668/stat : 25668 (aspcud-1.5) R 25667 25666 19908 34817 19908 4202560 0 0 0 0 0 0 0 0 25 0 1 0 63641241 2650112 46 1283457024 134512640 135304128 4288535552 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/25668/statm: 647 46 0 194 0 34 0

[startup+0.134008 s]
/proc/loadavg: 1.14 1.09 1.03 5/40 25668
/proc/meminfo: memFree=730708/1048576 swapFree=0/0
[pid=25666] ppid=25665 vsize=2596 CPUtime=0
/proc/25666/stat : 25666 (aspcud-1.5) S 25665 25666 19908 34817 19908 4202496 580 1523 0 0 0 0 0 0 25 0 1 0 63641241 2658304 298 1283457024 134512640 135304128 4288535552 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25666/statm: 649 298 251 194 0 36 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+0.206013 s]
/proc/loadavg: 1.14 1.09 1.03 5/40 25668
/proc/meminfo: memFree=730708/1048576 swapFree=0/0
[pid=25666] ppid=25665 vsize=2596 CPUtime=0
/proc/25666/stat : 25666 (aspcud-1.5) S 25665 25666 19908 34817 19908 4202496 580 1523 0 0 0 0 0 0 25 0 1 0 63641241 2658304 298 1283457024 134512640 135304128 4288535552 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25666/statm: 649 298 251 194 0 36 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+0.308335 s]
/proc/loadavg: 1.14 1.09 1.03 5/40 25668
/proc/meminfo: memFree=730708/1048576 swapFree=0/0
[pid=25666] ppid=25665 vsize=2596 CPUtime=0
/proc/25666/stat : 25666 (aspcud-1.5) S 25665 25666 19908 34817 19908 4202496 580 1523 0 0 0 0 0 0 25 0 1 0 63641241 2658304 298 1283457024 134512640 135304128 4288535552 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25666/statm: 649 298 251 194 0 36 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+0.706037 s]
/proc/loadavg: 1.14 1.09 1.03 5/40 25668
/proc/meminfo: memFree=730708/1048576 swapFree=0/0
[pid=25666] ppid=25665 vsize=2596 CPUtime=0
/proc/25666/stat : 25666 (aspcud-1.5) S 25665 25666 19908 34817 19908 4202496 580 1523 0 0 0 0 0 0 25 0 1 0 63641241 2658304 298 1283457024 134512640 135304128 4288535552 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25666/statm: 649 298 251 194 0 36 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+1.50916 s]
/proc/loadavg: 1.14 1.09 1.03 2/42 25677
/proc/meminfo: memFree=693200/1048576 swapFree=0/0
[pid=25666] ppid=25665 vsize=2596 CPUtime=1.28
/proc/25666/stat : 25666 (aspcud-1.5) R 25665 25666 19908 34817 19908 4202496 580 10186 0 0 0 0 126 2 19 0 1 0 63641241 2658304 298 1283457024 134512640 135304128 4288535552 18446744073709551615 4294960130 0 65536 4 1132560123 0 0 0 17 0 0 0 0
/proc/25666/statm: 649 298 251 194 0 36 0
[pid=25675] ppid=25666 vsize=3268 CPUtime=0.08
/proc/25675/stat : 25675 (clasp) R 25666 25666 19908 34817 19908 4202496 712 0 0 0 8 0 0 0 18 0 1 0 63641242 3346432 580 1283457024 134512640 136285277 4289221760 18446744073709551615 134960065 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25675/statm: 817 580 234 433 0 382 0
[pid=25676] ppid=25666 vsize=0 CPUtime=0.05
/proc/25676/stat : 25676 (gringo) Z 25666 25666 19908 34817 19908 4202508 929 0 0 0 5 0 0 0 18 0 1 0 63641242 0 0 1283457024 0 0 0 0 0 0 0 6 16384 18446744071564254338 0 0 17 0 0 0 0
/proc/25676/statm: 0 0 0 0 0 0 0
Current children cumulated CPU time (s) 1.41
Current children cumulated vsize (KiB) 5864

[startup+3.10942 s]
/proc/loadavg: 1.14 1.09 1.03 3/41 25678
/proc/meminfo: memFree=714008/1048576 swapFree=0/0
[pid=25666] ppid=25665 vsize=2596 CPUtime=1.33
/proc/25666/stat : 25666 (aspcud-1.5) S 25665 25666 19908 34817 19908 4202496 580 11115 0 0 0 0 131 2 17 0 1 0 63641241 2658304 298 1283457024 134512640 135304128 4288535552 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25666/statm: 649 298 251 194 0 36 0
[pid=25675] ppid=25666 vsize=3268 CPUtime=1.69
/proc/25675/stat : 25675 (clasp) R 25666 25666 19908 34817 19908 4202496 712 0 0 0 169 0 0 0 20 0 1 0 63641242 3346432 580 1283457024 134512640 136285277 4289221760 18446744073709551615 134959509 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25675/statm: 817 580 234 433 0 382 0
Current children cumulated CPU time (s) 3.02
Current children cumulated vsize (KiB) 5864

[startup+6.31001 s]
/proc/loadavg: 1.13 1.08 1.03 3/40 25678
/proc/meminfo: memFree=714016/1048576 swapFree=0/0
[pid=25666] ppid=25665 vsize=2596 CPUtime=1.33
/proc/25666/stat : 25666 (aspcud-1.5) S 25665 25666 19908 34817 19908 4202496 580 11115 0 0 0 0 131 2 17 0 1 0 63641241 2658304 298 1283457024 134512640 135304128 4288535552 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25666/statm: 649 298 251 194 0 36 0
[pid=25675] ppid=25666 vsize=3268 CPUtime=4.88
/proc/25675/stat : 25675 (clasp) R 25666 25666 19908 34817 19908 4202496 712 0 0 0 488 0 0 0 25 0 1 0 63641242 3346432 580 1283457024 134512640 136285277 4289221760 18446744073709551615 134930649 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25675/statm: 817 580 234 433 0 382 0
Current children cumulated CPU time (s) 6.21
Current children cumulated vsize (KiB) 5864

[startup+12.7113 s]
/proc/loadavg: 1.12 1.08 1.03 2/40 25679
/proc/meminfo: memFree=714016/1048576 swapFree=0/0
[pid=25666] ppid=25665 vsize=2596 CPUtime=1.33
/proc/25666/stat : 25666 (aspcud-1.5) S 25665 25666 19908 34817 19908 4202496 580 11115 0 0 0 0 131 2 17 0 1 0 63641241 2658304 298 1283457024 134512640 135304128 4288535552 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25666/statm: 649 298 251 194 0 36 0
[pid=25675] ppid=25666 vsize=3268 CPUtime=11.28
/proc/25675/stat : 25675 (clasp) R 25666 25666 19908 34817 19908 4202496 712 0 0 0 1128 0 0 0 25 0 1 0 63641242 3346432 580 1283457024 134512640 136285277 4289221760 18446744073709551615 134964959 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25675/statm: 817 580 234 433 0 382 0
Current children cumulated CPU time (s) 12.61
Current children cumulated vsize (KiB) 5864

[startup+25.5041 s]
/proc/loadavg: 1.09 1.08 1.02 2/40 25680
/proc/meminfo: memFree=714016/1048576 swapFree=0/0
[pid=25666] ppid=25665 vsize=2596 CPUtime=1.33
/proc/25666/stat : 25666 (aspcud-1.5) S 25665 25666 19908 34817 19908 4202496 580 11115 0 0 0 0 131 2 17 0 1 0 63641241 2658304 298 1283457024 134512640 135304128 4288535552 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25666/statm: 649 298 251 194 0 36 0
[pid=25675] ppid=25666 vsize=3268 CPUtime=24.06
/proc/25675/stat : 25675 (clasp) R 25666 25666 19908 34817 19908 4202496 712 0 0 0 2406 0 0 0 25 0 1 0 63641242 3346432 580 1283457024 134512640 136285277 4289221760 18446744073709551615 134959552 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25675/statm: 817 580 234 433 0 382 0
Current children cumulated CPU time (s) 25.39
Current children cumulated vsize (KiB) 5864

[startup+51.1092 s]
/proc/loadavg: 1.06 1.07 1.02 2/40 25682
/proc/meminfo: memFree=714016/1048576 swapFree=0/0
[pid=25666] ppid=25665 vsize=2596 CPUtime=1.33
/proc/25666/stat : 25666 (aspcud-1.5) S 25665 25666 19908 34817 19908 4202496 580 11115 0 0 0 0 131 2 17 0 1 0 63641241 2658304 298 1283457024 134512640 135304128 4288535552 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25666/statm: 649 298 251 194 0 36 0
[pid=25675] ppid=25666 vsize=3268 CPUtime=49.66
/proc/25675/stat : 25675 (clasp) R 25666 25666 19908 34817 19908 4202496 712 0 0 0 4965 1 0 0 25 0 1 0 63641242 3346432 580 1283457024 134512640 136285277 4289221760 18446744073709551615 134955202 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25675/statm: 817 580 234 433 0 382 0
Current children cumulated CPU time (s) 50.99
Current children cumulated vsize (KiB) 5864

[startup+102.309 s]
/proc/loadavg: 1.02 1.06 1.02 2/39 25682
/proc/meminfo: memFree=714040/1048576 swapFree=0/0
[pid=25666] ppid=25665 vsize=2596 CPUtime=1.33
/proc/25666/stat : 25666 (aspcud-1.5) S 25665 25666 19908 34817 19908 4202496 580 11115 0 0 0 0 131 2 17 0 1 0 63641241 2658304 298 1283457024 134512640 135304128 4288535552 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25666/statm: 649 298 251 194 0 36 0
[pid=25675] ppid=25666 vsize=3268 CPUtime=100.84
/proc/25675/stat : 25675 (clasp) R 25666 25666 19908 34817 19908 4202496 712 0 0 0 10082 2 0 0 25 0 1 0 63641242 3346432 580 1283457024 134512640 136285277 4289221760 18446744073709551615 134733711 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25675/statm: 817 580 234 433 0 382 0
Current children cumulated CPU time (s) 102.17
Current children cumulated vsize (KiB) 5864

[startup+162.304 s]
/proc/loadavg: 1.01 1.05 1.01 2/38 25682
/proc/meminfo: memFree=714048/1048576 swapFree=0/0
[pid=25666] ppid=25665 vsize=2596 CPUtime=1.33
/proc/25666/stat : 25666 (aspcud-1.5) S 25665 25666 19908 34817 19908 4202496 580 11115 0 0 0 0 131 2 17 0 1 0 63641241 2658304 298 1283457024 134512640 135304128 4288535552 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25666/statm: 649 298 251 194 0 36 0
[pid=25675] ppid=25666 vsize=3268 CPUtime=160.79
/proc/25675/stat : 25675 (clasp) R 25666 25666 19908 34817 19908 4202496 712 0 0 0 16077 2 0 0 25 0 1 0 63641242 3346432 580 1283457024 134512640 136285277 4289221760 18446744073709551615 134930729 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25675/statm: 817 580 234 433 0 382 0
Current children cumulated CPU time (s) 162.12
Current children cumulated vsize (KiB) 5864

[startup+222.306 s]
/proc/loadavg: 1.00 1.03 1.00 2/38 25682
/proc/meminfo: memFree=714048/1048576 swapFree=0/0
[pid=25666] ppid=25665 vsize=2596 CPUtime=1.33
/proc/25666/stat : 25666 (aspcud-1.5) S 25665 25666 19908 34817 19908 4202496 580 11115 0 0 0 0 131 2 17 0 1 0 63641241 2658304 298 1283457024 134512640 135304128 4288535552 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25666/statm: 649 298 251 194 0 36 0
[pid=25675] ppid=25666 vsize=3268 CPUtime=220.76
/proc/25675/stat : 25675 (clasp) R 25666 25666 19908 34817 19908 4202496 712 0 0 0 22074 2 0 0 25 0 1 0 63641242 3346432 580 1283457024 134512640 136285277 4289221760 18446744073709551615 134930675 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25675/statm: 817 580 234 433 0 382 0
Current children cumulated CPU time (s) 222.09
Current children cumulated vsize (KiB) 5864

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

[startup+224.006 s]
/proc/loadavg: 1.00 1.03 1.00 2/38 25682
/proc/meminfo: memFree=714048/1048576 swapFree=0/0
[pid=25666] ppid=25665 vsize=2596 CPUtime=1.33
/proc/25666/stat : 25666 (aspcud-1.5) S 25665 25666 19908 34817 19908 4202496 580 11115 0 0 0 0 131 2 17 0 1 0 63641241 2658304 298 1283457024 134512640 135304128 4288535552 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25666/statm: 649 298 251 194 0 36 0
[pid=25675] ppid=25666 vsize=3268 CPUtime=222.46
/proc/25675/stat : 25675 (clasp) R 25666 25666 19908 34817 19908 4202496 712 0 0 0 22244 2 0 0 25 0 1 0 63641242 3346432 580 1283457024 134512640 136285277 4289221760 18446744073709551615 134964988 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25675/statm: 817 580 234 433 0 382 0
Current children cumulated CPU time (s) 223.79
Current children cumulated vsize (KiB) 5864

[startup+227.207 s]
/proc/loadavg: 1.00 1.03 1.00 2/38 25682
/proc/meminfo: memFree=714048/1048576 swapFree=0/0
[pid=25666] ppid=25665 vsize=2596 CPUtime=1.33
/proc/25666/stat : 25666 (aspcud-1.5) S 25665 25666 19908 34817 19908 4202496 580 11115 0 0 0 0 131 2 17 0 1 0 63641241 2658304 298 1283457024 134512640 135304128 4288535552 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25666/statm: 649 298 251 194 0 36 0
[pid=25675] ppid=25666 vsize=3268 CPUtime=225.66
/proc/25675/stat : 25675 (clasp) R 25666 25666 19908 34817 19908 4202496 712 0 0 0 22564 2 0 0 25 0 1 0 63641242 3346432 580 1283457024 134512640 136285277 4289221760 18446744073709551615 134733771 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25675/statm: 817 580 234 433 0 382 0
Current children cumulated CPU time (s) 226.99
Current children cumulated vsize (KiB) 5864

[startup+228.807 s]
/proc/loadavg: 1.00 1.03 1.00 2/38 25682
/proc/meminfo: memFree=714048/1048576 swapFree=0/0
[pid=25666] ppid=25665 vsize=2596 CPUtime=1.33
/proc/25666/stat : 25666 (aspcud-1.5) S 25665 25666 19908 34817 19908 4202496 580 11115 0 0 0 0 131 2 17 0 1 0 63641241 2658304 298 1283457024 134512640 135304128 4288535552 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25666/statm: 649 298 251 194 0 36 0
[pid=25675] ppid=25666 vsize=3268 CPUtime=227.26
/proc/25675/stat : 25675 (clasp) R 25666 25666 19908 34817 19908 4202496 712 0 0 0 22724 2 0 0 25 0 1 0 63641242 3346432 580 1283457024 134512640 136285277 4289221760 18446744073709551615 134718767 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25675/statm: 817 580 234 433 0 382 0
Current children cumulated CPU time (s) 228.59
Current children cumulated vsize (KiB) 5864

[startup+229.607 s]
/proc/loadavg: 1.00 1.03 1.00 2/38 25682
/proc/meminfo: memFree=714048/1048576 swapFree=0/0
[pid=25666] ppid=25665 vsize=2596 CPUtime=1.33
/proc/25666/stat : 25666 (aspcud-1.5) S 25665 25666 19908 34817 19908 4202496 580 11115 0 0 0 0 131 2 17 0 1 0 63641241 2658304 298 1283457024 134512640 135304128 4288535552 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25666/statm: 649 298 251 194 0 36 0
[pid=25675] ppid=25666 vsize=3268 CPUtime=228.06
/proc/25675/stat : 25675 (clasp) R 25666 25666 19908 34817 19908 4202496 712 0 0 0 22804 2 0 0 25 0 1 0 63641242 3346432 580 1283457024 134512640 136285277 4289221760 18446744073709551615 134960040 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25675/statm: 817 580 234 433 0 382 0
Current children cumulated CPU time (s) 229.39
Current children cumulated vsize (KiB) 5864

[startup+230.407 s]
/proc/loadavg: 1.00 1.03 1.00 2/38 25682
/proc/meminfo: memFree=714048/1048576 swapFree=0/0
[pid=25666] ppid=25665 vsize=2596 CPUtime=1.33
/proc/25666/stat : 25666 (aspcud-1.5) S 25665 25666 19908 34817 19908 4202496 580 11115 0 0 0 0 131 2 17 0 1 0 63641241 2658304 298 1283457024 134512640 135304128 4288535552 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25666/statm: 649 298 251 194 0 36 0
[pid=25675] ppid=25666 vsize=3268 CPUtime=228.85
/proc/25675/stat : 25675 (clasp) R 25666 25666 19908 34817 19908 4202496 712 0 0 0 22883 2 0 0 25 0 1 0 63641242 3346432 580 1283457024 134512640 136285277 4289221760 18446744073709551615 134735687 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25675/statm: 817 580 234 433 0 382 0
Current children cumulated CPU time (s) 230.18
Current children cumulated vsize (KiB) 5864

[startup+230.808 s]
/proc/loadavg: 1.00 1.03 1.00 2/38 25682
/proc/meminfo: memFree=714048/1048576 swapFree=0/0
[pid=25666] ppid=25665 vsize=2596 CPUtime=1.33
/proc/25666/stat : 25666 (aspcud-1.5) S 25665 25666 19908 34817 19908 4202496 580 11115 0 0 0 0 131 2 17 0 1 0 63641241 2658304 298 1283457024 134512640 135304128 4288535552 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/25666/statm: 649 298 251 194 0 36 0
[pid=25675] ppid=25666 vsize=3268 CPUtime=229.25
/proc/25675/stat : 25675 (clasp) R 25666 25666 19908 34817 19908 4202496 712 0 0 0 22923 2 0 0 25 0 1 0 63641242 3346432 580 1283457024 134512640 136285277 4289221760 18446744073709551615 134735607 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/25675/statm: 817 580 234 433 0 382 0
Current children cumulated CPU time (s) 230.58
Current children cumulated vsize (KiB) 5864

Child status: 0
Real time (s): 230.868
CPU time (s): 230.654
CPU user time (s): 230.602
CPU system time (s): 0.052003
CPU usage (%): 99.9075
Max. virtual memory (cumulated for all children) (KiB): 34784

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 230.602
system time used= 0.052003
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 15955
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= 121
involuntary context switches= 2915

runsolver used 0 second user time and 0 second system time

The end