add timing for Process start, stop, total request time (#91)

config.example.yaml

@@ -3,7 +3,7 @@
 healthCheckTimeout: 90
 
 # valid log levels: debug, info (default), warn, error
-logLevel: info
+logLevel: debug
 
 models:
   "llama":

examples/aider-qwq-coder/README.md

@@ -0,0 +1,153 @@
+# aider, QwQ, Qwen-Coder 2.5 and llama-swap
+
+This guide show how to use aider and llama-swap to get a 100% local coding co-pilot setup. The focus is on the trickest part which is configuring aider, llama-swap and llama-server to work together.
+
+## Here's what you you need:
+
+- aider - [installation docs](https://aider.chat/docs/install.html)
+- llama-server - [download latest release](https://github.com/ggml-org/llama.cpp/releases)
+- llama-swap - [download latest release](https://github.com/mostlygeek/llama-swap/releases)
+- [QwQ 32B](https://huggingface.co/bartowski/Qwen_QwQ-32B-GGUF) and [Qwen Coder 2.5 32B](https://huggingface.co/bartowski/Qwen2.5-Coder-32B-Instruct-GGUF) models
+- 24GB VRAM video card
+
+## Running aider
+
+The goal is getting this command line to work:
+
+```sh
+aider --architect \
+    --no-show-model-warnings \
+    --model openai/QwQ \
+    --editor-model openai/qwen-coder-32B \
+    --model-settings-file aider.model.settings.yml \
+    --openai-api-key "sk-na" \
+    --openai-api-base "http://10.0.1.24:8080/v1" \
+```
+
+Set `--openai-api-base` to the IP and port where your llama-swap is running.
+
+## Create an aider model settings file
+
+```yaml
+# aider.model.settings.yml
+
+#
+# !!! important: model names must match llama-swap configuration names !!!
+#
+
+- name: "openai/QwQ"
+  edit_format: diff
+  extra_params:
+    max_tokens: 16384
+    top_p: 0.95
+    top_k: 40
+    presence_penalty: 0.1
+    repetition_penalty: 1
+    num_ctx: 16384
+  use_temperature: 0.6
+  reasoning_tag: think
+  weak_model_name: "openai/qwen-coder-32B"
+  editor_model_name: "openai/qwen-coder-32B"
+
+- name: "openai/qwen-coder-32B"
+  edit_format: diff
+  extra_params:
+    max_tokens: 16384
+    top_p: 0.8
+    top_k: 20
+    repetition_penalty: 1.05
+  use_temperature: 0.6
+  reasoning_tag: think
+  editor_edit_format: editor-diff
+  editor_model_name: "openai/qwen-coder-32B"
+```
+
+## llama-swap configuration
+
+```yaml
+# config.yaml
+
+# The parameters are tweaked to fit model+context into 24GB VRAM GPUs
+models:
+  "qwen-coder-32B":
+    proxy: "http://127.0.0.1:8999"
+    cmd: >
+      /path/to/llama-server
+      --host 127.0.0.1 --port 8999 --flash-attn --slots
+      --ctx-size 16000
+      --cache-type-k q8_0 --cache-type-v q8_0
+       -ngl 99
+      --model /path/to/Qwen2.5-Coder-32B-Instruct-Q4_K_M.gguf
+
+  "QwQ":
+    proxy: "http://127.0.0.1:9503"
+    cmd: >
+      /path/to/llama-server
+      --host 127.0.0.1 --port 9503 --flash-attn --metrics--slots
+      --cache-type-k q8_0 --cache-type-v q8_0
+      --ctx-size 32000
+      --samplers "top_k;top_p;min_p;temperature;dry;typ_p;xtc"
+      --temp 0.6 --repeat-penalty 1.1 --dry-multiplier 0.5
+      --min-p 0.01 --top-k 40 --top-p 0.95
+      -ngl 99
+      --model /mnt/nvme/models/bartowski/Qwen_QwQ-32B-Q4_K_M.gguf
+```
+
+## Advanced, Dual GPU Configuration
+
+If you have _dual 24GB GPUs_ you can use llama-swap profiles to avoid swapping between QwQ and Qwen Coder.
+
+In llama-swap's configuration file:
+
+1. add a `profiles` section with `aider` as the profile name
+2. using the `env` field to specify the GPU IDs for each model
+
+```yaml
+# config.yaml
+
+# Add a profile for aider
+profiles:
+  aider:
+    - qwen-coder-32B
+    - QwQ
+
+models:
+  "qwen-coder-32B":
+    # manually set the GPU to run on
+    env:
+      - "CUDA_VISIBLE_DEVICES=0"
+    proxy: "http://127.0.0.1:8999"
+    cmd: /path/to/llama-server ...
+
+  "QwQ":
+    # manually set the GPU to run on
+    env:
+      - "CUDA_VISIBLE_DEVICES=1"
+    proxy: "http://127.0.0.1:9503"
+    cmd: /path/to/llama-server ...
+```
+
+Append the profile tag, `aider:`, to the model names in the model settings file
+
+```yaml
+# aider.model.settings.yml
+- name: "openai/aider:QwQ"
+  weak_model_name: "openai/aider:qwen-coder-32B-aider"
+  editor_model_name: "openai/aider:qwen-coder-32B-aider"
+
+- name: "openai/aider:qwen-coder-32B"
+  editor_model_name: "openai/aider:qwen-coder-32B-aider"
+```
+
+Run aider with:
+
+```sh
+$ aider --architect \
+    --no-show-model-warnings \
+    --model openai/aider:QwQ \
+    --editor-model openai/aider:qwen-coder-32B \
+    --config aider.conf.yml \
+    --model-settings-file aider.model.settings.yml
+    --openai-api-key "sk-na" \
+    --openai-api-base "http://10.0.1.24:8080/v1"
+```

examples/aider-qwq-coder/aider.model.settings.dualgpu.yml

@@ -0,0 +1,28 @@
+# this makes use of llama-swap's profile feature to
+# keep the architect and editor models in VRAM on different GPUs
+
+- name: "openai/aider:QwQ"
+  edit_format: diff
+  extra_params:
+    max_tokens: 16384
+    top_p: 0.95
+    top_k: 40
+    presence_penalty: 0.1
+    repetition_penalty: 1
+    num_ctx: 16384
+  use_temperature: 0.6
+  reasoning_tag: think
+  weak_model_name: "openai/aider:qwen-coder-32B"
+  editor_model_name: "openai/aider:qwen-coder-32B"
+
+- name: "openai/aider:qwen-coder-32B"
+  edit_format: diff
+  extra_params:
+    max_tokens: 16384
+    top_p: 0.8
+    top_k: 20
+    repetition_penalty: 1.05
+  use_temperature: 0.6
+  reasoning_tag: think
+  editor_edit_format: editor-diff
+  editor_model_name: "openai/aider:qwen-coder-32B"

examples/aider-qwq-coder/aider.model.settings.yml

@@ -0,0 +1,26 @@
+- name: "openai/QwQ"
+  edit_format: diff
+  extra_params:
+    max_tokens: 16384
+    top_p: 0.95
+    top_k: 40
+    presence_penalty: 0.1
+    repetition_penalty: 1
+    num_ctx: 16384
+  use_temperature: 0.6
+  reasoning_tag: think
+  weak_model_name: "openai/qwen-coder-32B"
+  editor_model_name: "openai/qwen-coder-32B"
+
+- name: "openai/qwen-coder-32B"
+  edit_format: diff
+  extra_params:
+    max_tokens: 16384
+    top_p: 0.8
+    top_k: 20
+    repetition_penalty: 1.05
+  use_temperature: 0.6
+  reasoning_tag: think
+  editor_edit_format: editor-diff
+  editor_model_name: "openai/qwen-coder-32B"
+

examples/aider-qwq-coder/llama-swap.yaml

@@ -0,0 +1,49 @@
+healthCheckTimeout: 300
+logLevel: debug
+
+profiles:
+    aider:
+      - qwen-coder-32B
+      - QwQ
+
+models:
+  "qwen-coder-32B":
+    env:
+      - "CUDA_VISIBLE_DEVICES=0"
+    aliases:
+      - coder
+    proxy: "http://127.0.0.1:8999"
+
+    # set appropriate paths for your environment
+    cmd: >
+      /path/to/llama-server
+      --host 127.0.0.1 --port 8999 --flash-attn --slots
+      --ctx-size 16000
+      --ctx-size-draft 16000
+      --model /path/to/Qwen2.5-Coder-32B-Instruct-Q4_K_M.gguf
+      --model-draft /path/to/Qwen2.5-Coder-1.5B-Instruct-Q8_0.gguf
+      -ngl 99 -ngld 99
+      --draft-max 16 --draft-min 4 --draft-p-min 0.4
+      --cache-type-k q8_0 --cache-type-v q8_0
+  "QwQ":
+    env:
+      - "CUDA_VISIBLE_DEVICES=1"
+    proxy: "http://127.0.0.1:9503"
+
+    # set appropriate paths for your environment
+    cmd: >
+      /path/to/llama-server
+      --host 127.0.0.1 --port 9503
+      --flash-attn --metrics
+      --slots
+      --model /path/to/Qwen_QwQ-32B-Q4_K_M.gguf
+      --cache-type-k q8_0 --cache-type-v q8_0
+      --ctx-size 32000
+      --samplers "top_k;top_p;min_p;temperature;dry;typ_p;xtc"
+      --temp 0.6
+      --repeat-penalty 1.1
+      --dry-multiplier 0.5
+      --min-p 0.01
+      --top-k 40
+      --top-p 0.95
+      -ngl 99 -ngld 99

proxy/html/logs.html

@@ -12,32 +12,65 @@
             flex-direction: column;
             font-family: "Courier New", Courier, monospace;
         }
-        #log-controls {
+        .log-container {
-            margin: 0.5em;
             display: flex;
-            align-items: center;
-            justify-content: space-between; /* Spaces out elements evenly */
-        }
-        #log-controls input {
-            flex: 1;
-        }
-        #log-controls input:focus {
-           outline: none; /* Ensures no outline is shown when the input is focused */
-        }
-        #log-stream {
             flex: 1;
+            gap: 0.5em;
             margin: 0.5em;
+            min-height: 0;
+        }
+        .log-column {
+            display: flex;
+            flex-direction: column;
+            flex: 1;
+            min-width: 0;
+            transition: flex 0.3s ease;
+        }
+        .log-column.minimized {
+            flex: 0.1;
+            max-width: 50px;
+            border: 1px solid #777;
+            color: green;
+        }
+        .log-controls {
+            display: grid;
+            grid-template-columns: 1fr auto;
+            gap: 0.5em;
+            margin-bottom: 0.5em;
+        }
+        .log-controls input {
+            width: 100%;
+            padding: 4px;
+        }
+        .log-controls input:focus {
+           outline: none;
+        }
+        .log-stream {
+            flex: 1;
             padding: 1em;
             background: #f4f4f4;
             overflow-y: auto;
-            white-space: pre-wrap; /* Ensures line wrapping */
+            white-space: pre-wrap;
-            word-wrap: break-word; /* Ensures long words wrap */
+            word-wrap: break-word;
+            min-height: 0;
         }
 
         .regex-error {
             background-color: #ff0000 !important;
         }
 
+        /* Make headers clickable and show pointer cursor */
+        h2 {
+            cursor: pointer;
+            user-select: none;
+            margin: 0 0 0.5em 0;
+            padding: 0.5em;
+        }
+
+        h2:hover {
+            background-color: rgba(0, 0, 0, 0.05);
+        }
+
         /* Dark mode styles */
         @media (prefers-color-scheme: dark) {
             body {
@@ -45,101 +78,181 @@
                 color: #fff;
             }
 
-            #log-stream {
+            .log-stream {
                 background: #444;
                 color: #fff;
             }
 
-            #log-controls input {
+            .log-controls input {
                 background: #555;
                 color: #fff;
                 border: 1px solid #777;
             }
 
-            #log-controls button {
+            .log-controls button {
                 background: #555;
                 color: #fff;
                 border: 1px solid #777;
             }
+
+            h2:hover {
+                background-color: rgba(255, 255, 255, 0.1);
+            }
+        }
+
+        /* Hide content when minimized */
+        .log-column.minimized .log-controls,
+        .log-column.minimized .log-stream {
+            display: none;
+        }
+
+        .log-column.minimized h2 {
+            writing-mode: vertical-rl;
+            text-orientation: mixed;
+            transform: rotate(180deg);
+            white-space: nowrap;
+            margin: auto;
         }
     </style>
 </head>
 <body>
-    <pre id="log-stream">Waiting for logs...</pre>
+    <div class="log-container">
-    <div id="log-controls">
+        <div class="log-column">
-        <input type="text" id="filter-input" placeholder="regex filter">
+            <h2>Proxy Logs</h2>
-        <button id="clear-button">clear</button>
+            <div class="log-controls">
+                <input type="text" id="proxy-filter-input" placeholder="proxy regex filter">
+                <button id="proxy-clear-button">clear</button>
+            </div>
+            <pre class="log-stream" id="proxy-log-stream">Waiting for proxy logs...</pre>
+        </div>
+        <div class="log-column minimized">
+            <h2>Upstream Logs</h2>
+            <div class="log-controls">
+                <input type="text" id="upstream-filter-input" placeholder="upstream regex filter">
+                <button id="upstream-clear-button">clear</button>
+            </div>
+            <pre class="log-stream" id="upstream-log-stream">Waiting for upstream logs...</pre>
+        </div>
     </div>
     <script>
-        const logStream = document.getElementById('log-stream');
+        class LogStream {
-        const filterInput = document.getElementById('filter-input');
+            constructor(streamElement, filterInput, clearButton, endpoint) {
-        var logData = "";
+                this.streamElement = streamElement;
-        let regexFilter = null;
+                this.filterInput = filterInput;
+                this.clearButton = clearButton;
+                this.endpoint = endpoint;
+                this.logData = "";
+                this.regexFilter = null;
+                this.eventSource = null;
 
-        function setupEventSource() {
+                this.initialize();
-            if (typeof(EventSource) !== "undefined") {
-                const eventSource = new EventSource("/logs/streamSSE");
-
-                eventSource.onmessage = function(event) {
-                    logData += event.data;
-                    render()
-                };
-
-                eventSource.onerror = function(err) {
-                    logData = "EventSource failed: " + err.message;
-                };
-            } else {
-                logData = "SSE Not supported by this browser."
             }
-        }
 
-        // poor-ai's react  ¯\_(ツ)_/¯
+            initialize() {
-        function render() {
+                this.filterInput.addEventListener('input', () => this.updateFilter());
-            if (regexFilter) {
+                this.clearButton.addEventListener('click', () => {
-                const lines = logData.split('\n');
+                    this.filterInput.value = "";
-                const filteredLines = lines.filter(line => {
+                    this.regexFilter = null;
-                    return regexFilter === null || regexFilter.test(line);
+                    this.render();
                 });
-
+                this.setupEventSource();
-                if (filteredLines.length > 0) {
-                    logStream.textContent = filteredLines.join('\n') + '\n';
-                } else {
-                    logStream.textContent = "";
-                }
-            } else {
-                logStream.textContent = logData;
             }
 
-            logStream.scrollTop = logStream.scrollHeight;
+            setupEventSource() {
-        }
+                if (typeof(EventSource) === "undefined") {
+                    this.logData = "SSE Not supported by this browser.";
+                    this.render();
+                    return;
+                }
+
+                const connect = () => {
+                    this.eventSource = new EventSource(this.endpoint);
+
+                    this.eventSource.onmessage = (event) => {
+                        this.logData += event.data;
+                        this.render();
+                    };
+
+                    this.eventSource.onerror = (err) => {
+                        // Close the current connection
+                        this.eventSource.close();
+
+                        this.logData += "\nConnection lost. Retrying in 5 seconds...\n";
+                        this.render();
+
+                        // Attempt to reconnect after 5 seconds
+                        setTimeout(() => {
+                            this.logData += "Attempting to reconnect...\n";
+                            this.render();
+                            connect();
+                        }, 5000);
+                    };
+                };
+
+                // Initial connection
+                connect();
+            }
+
+            render() {
+                let content = this.logData;
+
+                if (this.regexFilter) {
+                    const lines = content.split('\n');
+                    const filteredLines = lines.filter(line => this.regexFilter.test(line));
+                    content = filteredLines.length > 0 ? filteredLines.join('\n') + '\n' : "";
+                }
+
+                this.streamElement.textContent = content;
+                this.streamElement.scrollTop = this.streamElement.scrollHeight;
+            }
+
+            updateFilter() {
+                const pattern = this.filterInput.value.trim();
+                this.filterInput.classList.remove('regex-error');
+
+                if (!pattern) {
+                    this.regexFilter = null;
+                    this.render();
+                    return;
+                }
 
-        function updateFilter() {
-            const pattern = filterInput.value.trim();
-            filterInput.classList.remove('regex-error');
-            if (pattern) {
                 try {
-                    regexFilter = new RegExp(pattern);
+                    this.regexFilter = new RegExp(pattern);
                 } catch (e) {
                     console.error("Invalid regex pattern:", e);
-                    regexFilter = null;
+                    this.regexFilter = null;
-                    filterInput.classList.add('regex-error');
+                    this.filterInput.classList.add('regex-error');
-                    return
+                    return;
                 }
-            } else {
-                regexFilter = null;
-            }
 
-            render();
+                this.render();
+            }
         }
 
-        filterInput.addEventListener('input', updateFilter);
+        // Initialize both log streams
-        document.getElementById('clear-button').addEventListener('click', () => {
+        document.addEventListener('DOMContentLoaded', () => {
-            filterInput.value = "";
+            new LogStream(
-            regexFilter = null;
+                document.getElementById('proxy-log-stream'),
-            render();
+                document.getElementById('proxy-filter-input'),
+                document.getElementById('proxy-clear-button'),
+                "/logs/streamSSE/proxy"
+            );
+
+            new LogStream(
+                document.getElementById('upstream-log-stream'),
+                document.getElementById('upstream-filter-input'),
+                document.getElementById('upstream-clear-button'),
+                "/logs/streamSSE/upstream"
+            );
+
+            // Initialize clickable headers
+            document.querySelectorAll('h2').forEach(header => {
+                header.addEventListener('click', () => {
+                    const column = header.closest('.log-column');
+                    column.classList.toggle('minimized');
+                });
+            });
         });
-        setupEventSource();
-        updateFilter();
     </script>
 </body>
 </html>

proxy/process.go

@@ -303,6 +303,11 @@ func (p *Process) Shutdown() {
 // stopCommand will send a SIGTERM to the process and wait for it to exit.
 // If it does not exit within 5 seconds, it will send a SIGKILL.
 func (p *Process) stopCommand(sigtermTTL time.Duration) {
+	stopStartTime := time.Now()
+	defer func() {
+		p.proxyLogger.Debugf("Process [%s] stopCommand took %v", p.ID, time.Since(stopStartTime))
+	}()
+
 	sigtermTimeout, cancelTimeout := context.WithTimeout(context.Background(), sigtermTTL)
 	defer cancelTimeout()
 
@@ -369,6 +374,8 @@ func (p *Process) checkHealthEndpoint(healthURL string) error {
 }
 
 func (p *Process) ProxyRequest(w http.ResponseWriter, r *http.Request) {
+	requestBeginTime := time.Now()
+	var startDuration time.Duration
 
 	// prevent new requests from being made while stopping or irrecoverable
 	currentState := p.CurrentState()
@@ -385,11 +392,13 @@ func (p *Process) ProxyRequest(w http.ResponseWriter, r *http.Request) {
 
 	// start the process on demand
 	if p.CurrentState() != StateReady {
+		beginStartTime := time.Now()
 		if err := p.start(); err != nil {
 			errstr := fmt.Sprintf("unable to start process: %s", err)
 			http.Error(w, errstr, http.StatusBadGateway)
 			return
 		}
+		startDuration = time.Since(beginStartTime)
 	}
 
 	proxyTo := p.config.Proxy
@@ -433,4 +442,8 @@ func (p *Process) ProxyRequest(w http.ResponseWriter, r *http.Request) {
 			return
 		}
 	}
+
+	totalTime := time.Since(requestBeginTime)
+	p.proxyLogger.Debugf("Process [%s] request %s - start: %v, total: %v",
+		p.ID, r.RequestURI, startDuration, totalTime)
 }