From 7100365f53983bd1fca8a621af134b89d430505b Mon Sep 17 00:00:00 2001 From: Alexsander Hamir Date: Mon, 9 Feb 2026 15:20:18 -0800 Subject: [PATCH] Add concurrency test results (1-10-30-50-100) and analysis to problem_tracker --- concurrency_100_requests_100.txt | 124 +++++++++++++++++++++++++++++++ concurrency_10_requests_100.txt | 124 +++++++++++++++++++++++++++++++ concurrency_1_requests_100.txt | 124 +++++++++++++++++++++++++++++++ concurrency_30_requests_100.txt | 124 +++++++++++++++++++++++++++++++ concurrency_50_requests_100.txt | 124 +++++++++++++++++++++++++++++++ problem_tracker.md | 103 +++++++++++++++++++++++++ 6 files changed, 723 insertions(+) create mode 100644 concurrency_100_requests_100.txt create mode 100644 concurrency_10_requests_100.txt create mode 100644 concurrency_1_requests_100.txt create mode 100644 concurrency_30_requests_100.txt create mode 100644 concurrency_50_requests_100.txt diff --git a/concurrency_100_requests_100.txt b/concurrency_100_requests_100.txt new file mode 100644 index 00000000000..234c9a65069 --- /dev/null +++ b/concurrency_100_requests_100.txt @@ -0,0 +1,124 @@ +=== 100 requests, 100 users, fire-as-fast-as-possible === +User mode: none, Key mode: shared +Latency = time from request start until last byte of response received + [OK] User 40 request 1: 9.101s + [OK] User 22 request 1: 11.645s + [OK] User 58 request 1: 6.576s + [OK] User 23 request 1: 11.521s + [OK] User 42 request 1: 8.842s + [OK] User 54 request 1: 7.141s + [OK] User 37 request 1: 9.548s + [OK] User 52 request 1: 7.424s + [OK] User 1 request 1: 14.657s + [OK] User 13 request 1: 12.937s + [OK] User 35 request 1: 9.830s + [OK] User 44 request 1: 8.561s + [OK] User 36 request 1: 9.690s + [OK] User 21 request 1: 11.802s + [OK] User 48 request 1: 7.995s + [OK] User 32 request 1: 10.255s + [OK] User 57 request 1: 6.719s + [OK] User 55 request 1: 7.001s + [OK] User 51 request 1: 7.568s + [OK] User 14 request 1: 12.797s + [OK] User 60 request 1: 6.297s + [OK] User 41 request 1: 8.985s + [OK] User 4 request 1: 14.217s + [OK] User 34 request 1: 9.979s + [OK] User 38 request 1: 9.414s + [OK] User 59 request 1: 6.443s + [OK] User 62 request 1: 6.030s + [OK] User 65 request 1: 5.615s + [OK] User 67 request 1: 5.335s + [OK] User 63 request 1: 5.900s + [OK] User 61 request 1: 6.182s + [OK] User 68 request 1: 5.194s + [OK] User 30 request 1: 10.565s + [OK] User 12 request 1: 13.106s + [OK] User 2 request 1: 14.534s + [OK] User 64 request 1: 5.759s + [OK] User 19 request 1: 12.109s + [OK] User 66 request 1: 5.487s + [OK] User 72 request 1: 4.641s + [OK] User 70 request 1: 4.923s + [OK] User 71 request 1: 4.782s + [OK] User 79 request 1: 3.653s + [OK] User 77 request 1: 3.937s + [OK] User 75 request 1: 4.218s + [OK] User 74 request 1: 4.360s + [OK] User 76 request 1: 4.078s + [OK] User 69 request 1: 5.065s + [OK] User 83 request 1: 3.086s + [OK] User 73 request 1: 4.502s + [OK] User 6 request 1: 13.970s + [OK] User 80 request 1: 3.516s + [OK] User 78 request 1: 3.798s + [OK] User 82 request 1: 3.236s + [OK] User 84 request 1: 2.951s + [OK] User 86 request 1: 2.668s + [OK] User 85 request 1: 2.809s + [OK] User 88 request 1: 2.384s + [OK] User 89 request 1: 2.242s + [OK] User 87 request 1: 2.526s + [OK] User 81 request 1: 3.379s + [OK] User 93 request 1: 1.675s + [OK] User 90 request 1: 2.101s + [OK] User 92 request 1: 1.820s + [OK] User 97 request 1: 1.116s + [OK] User 91 request 1: 1.964s + [OK] User 95 request 1: 1.396s + [OK] User 99 request 1: 0.834s + [OK] User 96 request 1: 1.256s + [OK] User 94 request 1: 1.537s + [OK] User 100 request 1: 0.698s + [OK] User 18 request 1: 12.288s + [OK] User 98 request 1: 0.979s + [OK] User 8 request 1: 13.698s + [OK] User 11 request 1: 13.275s + [OK] User 15 request 1: 12.711s + [OK] User 7 request 1: 14.019s + [OK] User 25 request 1: 11.483s + [OK] User 17 request 1: 12.616s + [OK] User 29 request 1: 10.921s + [OK] User 24 request 1: 11.624s + [OK] User 56 request 1: 7.101s + [OK] User 27 request 1: 11.203s + [OK] User 5 request 1: 14.311s + [OK] User 45 request 1: 8.669s + [OK] User 53 request 1: 7.534s + [OK] User 49 request 1: 8.102s + [OK] User 46 request 1: 8.528s + [OK] User 39 request 1: 9.517s + [OK] User 31 request 1: 10.648s + [OK] User 28 request 1: 11.071s + [OK] User 47 request 1: 8.387s + [OK] User 9 request 1: 13.753s + [OK] User 50 request 1: 7.960s + [OK] User 10 request 1: 13.613s + [OK] User 26 request 1: 11.353s + [OK] User 33 request 1: 10.365s + [OK] User 43 request 1: 8.953s + [OK] User 20 request 1: 12.194s + [OK] User 3 request 1: 14.608s + [OK] User 16 request 1: 12.767s + +[OK] 100 succeeded, [FAIL] 0 failed + +Latency (successful): + min: 0.698s + avg: 7.721s + max: 14.657s + p95: 14.019s + p99: 14.608s + +Requests above threshold (successful only): + Above 1s: 97/100 (97.0%) + Above 2s: 90/100 (90.0%) + Above 3s: 83/100 (83.0%) + Above 4s: 76/100 (76.0%) + Above 5s: 69/100 (69.0%) + Above 6s: 62/100 (62.0%) + Above 7s: 56/100 (56.0%) + Above 8s: 48/100 (48.0%) + Above 9s: 40/100 (40.0%) + Above 10s: 33/100 (33.0%) diff --git a/concurrency_10_requests_100.txt b/concurrency_10_requests_100.txt new file mode 100644 index 00000000000..8733f88f3de --- /dev/null +++ b/concurrency_10_requests_100.txt @@ -0,0 +1,124 @@ +=== 100 requests, 10 users, fire-as-fast-as-possible === +User mode: none, Key mode: shared +Latency = time from request start until last byte of response received + [OK] User 9 request 1: 0.608s + [OK] User 7 request 1: 0.896s + [OK] User 5 request 1: 1.195s + [OK] User 3 request 1: 1.481s + [OK] User 9 request 2: 0.013s + [OK] User 7 request 2: 0.013s + [OK] User 5 request 2: 0.013s + [OK] User 3 request 2: 0.014s + [OK] User 3 request 3: 0.014s + [OK] User 7 request 3: 0.017s + [OK] User 9 request 3: 0.018s + [OK] User 5 request 3: 0.016s + [OK] User 3 request 4: 0.012s + [OK] User 7 request 4: 0.013s + [OK] User 9 request 4: 0.014s + [OK] User 5 request 4: 0.014s + [OK] User 3 request 5: 0.016s + [OK] User 7 request 5: 0.016s + [OK] User 9 request 5: 0.015s + [OK] User 5 request 5: 0.016s + [OK] User 3 request 6: 0.016s + [OK] User 7 request 6: 0.015s + [OK] User 9 request 6: 0.015s + [OK] User 5 request 6: 0.015s + [OK] User 3 request 7: 0.014s + [OK] User 7 request 7: 0.014s + [OK] User 9 request 7: 0.014s + [OK] User 5 request 7: 0.014s + [OK] User 3 request 8: 0.013s + [OK] User 7 request 8: 0.013s + [OK] User 9 request 8: 0.013s + [OK] User 5 request 8: 0.013s + [OK] User 7 request 9: 0.012s + [OK] User 3 request 9: 0.014s + [OK] User 9 request 9: 0.013s + [OK] User 5 request 9: 0.014s + [OK] User 9 request 10: 0.012s + [OK] User 3 request 10: 0.013s + [OK] User 7 request 10: 0.015s + [OK] User 5 request 10: 0.012s + [OK] User 1 request 1: 2.034s + [OK] User 8 request 1: 1.014s + [OK] User 2 request 1: 1.894s + [OK] User 10 request 1: 0.730s + [OK] User 6 request 1: 1.317s + [OK] User 4 request 1: 1.596s + [OK] User 1 request 2: 0.030s + [OK] User 2 request 2: 0.025s + [OK] User 10 request 2: 0.025s + [OK] User 8 request 2: 0.026s + [OK] User 4 request 2: 0.025s + [OK] User 6 request 2: 0.026s + [OK] User 1 request 3: 0.018s + [OK] User 2 request 3: 0.020s + [OK] User 10 request 3: 0.020s + [OK] User 8 request 3: 0.020s + [OK] User 6 request 3: 0.021s + [OK] User 4 request 3: 0.021s + [OK] User 1 request 4: 0.015s + [OK] User 2 request 4: 0.021s + [OK] User 4 request 4: 0.019s + [OK] User 10 request 4: 0.023s + [OK] User 8 request 4: 0.023s + [OK] User 6 request 4: 0.022s + [OK] User 1 request 5: 0.021s + [OK] User 8 request 5: 0.019s + [OK] User 6 request 5: 0.019s + [OK] User 10 request 5: 0.022s + [OK] User 4 request 5: 0.024s + [OK] User 2 request 5: 0.024s + [OK] User 1 request 6: 0.020s + [OK] User 8 request 6: 0.021s + [OK] User 10 request 6: 0.020s + [OK] User 6 request 6: 0.022s + [OK] User 4 request 6: 0.021s + [OK] User 2 request 6: 0.021s + [OK] User 1 request 7: 0.020s + [OK] User 8 request 7: 0.018s + [OK] User 6 request 7: 0.018s + [OK] User 10 request 7: 0.019s + [OK] User 4 request 7: 0.019s + [OK] User 2 request 7: 0.019s + [OK] User 1 request 8: 0.021s + [OK] User 6 request 8: 0.020s + [OK] User 4 request 8: 0.019s + [OK] User 2 request 8: 0.019s + [OK] User 10 request 8: 0.022s + [OK] User 8 request 8: 0.025s + [OK] User 1 request 9: 0.019s + [OK] User 2 request 9: 0.020s + [OK] User 6 request 9: 0.022s + [OK] User 4 request 9: 0.022s + [OK] User 10 request 9: 0.021s + [OK] User 8 request 9: 0.021s + [OK] User 1 request 10: 0.024s + [OK] User 2 request 10: 0.019s + [OK] User 6 request 10: 0.019s + [OK] User 4 request 10: 0.019s + [OK] User 10 request 10: 0.018s + [OK] User 8 request 10: 0.019s + +[OK] 100 succeeded, [FAIL] 0 failed + +Latency (successful): + min: 0.012s + avg: 0.144s + max: 2.034s + p95: 1.195s + p99: 1.894s + +Requests above threshold (successful only): + Above 1s: 7/100 (7.0%) + Above 2s: 1/100 (1.0%) + Above 3s: 0/100 (0.0%) + Above 4s: 0/100 (0.0%) + Above 5s: 0/100 (0.0%) + Above 6s: 0/100 (0.0%) + Above 7s: 0/100 (0.0%) + Above 8s: 0/100 (0.0%) + Above 9s: 0/100 (0.0%) + Above 10s: 0/100 (0.0%) diff --git a/concurrency_1_requests_100.txt b/concurrency_1_requests_100.txt new file mode 100644 index 00000000000..43da30b566c --- /dev/null +++ b/concurrency_1_requests_100.txt @@ -0,0 +1,124 @@ +=== 100 requests, 1 users, fire-as-fast-as-possible === +User mode: none, Key mode: shared +Latency = time from request start until last byte of response received + [OK] User 1 request 1: 0.716s + [OK] User 1 request 2: 0.006s + [OK] User 1 request 3: 0.005s + [OK] User 1 request 4: 0.005s + [OK] User 1 request 5: 0.005s + [OK] User 1 request 6: 0.004s + [OK] User 1 request 7: 0.005s + [OK] User 1 request 8: 0.005s + [OK] User 1 request 9: 0.005s + [OK] User 1 request 10: 0.005s + [OK] User 1 request 11: 0.005s + [OK] User 1 request 12: 0.005s + [OK] User 1 request 13: 0.008s + [OK] User 1 request 14: 0.007s + [OK] User 1 request 15: 0.005s + [OK] User 1 request 16: 0.005s + [OK] User 1 request 17: 0.005s + [OK] User 1 request 18: 0.005s + [OK] User 1 request 19: 0.005s + [OK] User 1 request 20: 0.005s + [OK] User 1 request 21: 0.005s + [OK] User 1 request 22: 0.005s + [OK] User 1 request 23: 0.005s + [OK] User 1 request 24: 0.005s + [OK] User 1 request 25: 0.005s + [OK] User 1 request 26: 0.006s + [OK] User 1 request 27: 0.006s + [OK] User 1 request 28: 0.005s + [OK] User 1 request 29: 0.006s + [OK] User 1 request 30: 0.005s + [OK] User 1 request 31: 0.005s + [OK] User 1 request 32: 0.005s + [OK] User 1 request 33: 0.006s + [OK] User 1 request 34: 0.005s + [OK] User 1 request 35: 0.005s + [OK] User 1 request 36: 0.005s + [OK] User 1 request 37: 0.005s + [OK] User 1 request 38: 0.004s + [OK] User 1 request 39: 0.005s + [OK] User 1 request 40: 0.006s + [OK] User 1 request 41: 0.006s + [OK] User 1 request 42: 0.006s + [OK] User 1 request 43: 0.006s + [OK] User 1 request 44: 0.006s + [OK] User 1 request 45: 0.005s + [OK] User 1 request 46: 0.005s + [OK] User 1 request 47: 0.005s + [OK] User 1 request 48: 0.005s + [OK] User 1 request 49: 0.005s + [OK] User 1 request 50: 0.006s + [OK] User 1 request 51: 0.005s + [OK] User 1 request 52: 0.005s + [OK] User 1 request 53: 0.005s + [OK] User 1 request 54: 0.005s + [OK] User 1 request 55: 0.005s + [OK] User 1 request 56: 0.005s + [OK] User 1 request 57: 0.005s + [OK] User 1 request 58: 0.004s + [OK] User 1 request 59: 0.004s + [OK] User 1 request 60: 0.004s + [OK] User 1 request 61: 0.004s + [OK] User 1 request 62: 0.004s + [OK] User 1 request 63: 0.004s + [OK] User 1 request 64: 0.006s + [OK] User 1 request 65: 0.005s + [OK] User 1 request 66: 0.005s + [OK] User 1 request 67: 0.005s + [OK] User 1 request 68: 0.005s + [OK] User 1 request 69: 0.005s + [OK] User 1 request 70: 0.006s + [OK] User 1 request 71: 0.006s + [OK] User 1 request 72: 0.005s + [OK] User 1 request 73: 0.005s + [OK] User 1 request 74: 0.005s + [OK] User 1 request 75: 0.005s + [OK] User 1 request 76: 0.007s + [OK] User 1 request 77: 0.007s + [OK] User 1 request 78: 0.006s + [OK] User 1 request 79: 0.007s + [OK] User 1 request 80: 0.007s + [OK] User 1 request 81: 0.007s + [OK] User 1 request 82: 0.006s + [OK] User 1 request 83: 0.007s + [OK] User 1 request 84: 0.006s + [OK] User 1 request 85: 0.005s + [OK] User 1 request 86: 0.005s + [OK] User 1 request 87: 0.005s + [OK] User 1 request 88: 0.005s + [OK] User 1 request 89: 0.006s + [OK] User 1 request 90: 0.006s + [OK] User 1 request 91: 0.005s + [OK] User 1 request 92: 0.005s + [OK] User 1 request 93: 0.006s + [OK] User 1 request 94: 0.005s + [OK] User 1 request 95: 0.005s + [OK] User 1 request 96: 0.005s + [OK] User 1 request 97: 0.006s + [OK] User 1 request 98: 0.005s + [OK] User 1 request 99: 0.005s + [OK] User 1 request 100: 0.006s + +[OK] 100 succeeded, [FAIL] 0 failed + +Latency (successful): + min: 0.004s + avg: 0.012s + max: 0.716s + p95: 0.007s + p99: 0.008s + +Requests above threshold (successful only): + Above 1s: 0/100 (0.0%) + Above 2s: 0/100 (0.0%) + Above 3s: 0/100 (0.0%) + Above 4s: 0/100 (0.0%) + Above 5s: 0/100 (0.0%) + Above 6s: 0/100 (0.0%) + Above 7s: 0/100 (0.0%) + Above 8s: 0/100 (0.0%) + Above 9s: 0/100 (0.0%) + Above 10s: 0/100 (0.0%) diff --git a/concurrency_30_requests_100.txt b/concurrency_30_requests_100.txt new file mode 100644 index 00000000000..af11746da43 --- /dev/null +++ b/concurrency_30_requests_100.txt @@ -0,0 +1,124 @@ +=== 100 requests, 30 users, fire-as-fast-as-possible === +User mode: none, Key mode: shared +Latency = time from request start until last byte of response received + [OK] User 6 request 1: 3.861s + [OK] User 29 request 1: 0.670s + [OK] User 10 request 1: 3.311s + [OK] User 4 request 1: 4.154s + [OK] User 22 request 1: 1.653s + [OK] User 15 request 1: 2.626s + [OK] User 30 request 1: 0.547s + [OK] User 13 request 1: 2.906s + [OK] User 23 request 1: 1.521s + [OK] User 11 request 1: 3.185s + [OK] User 7 request 1: 3.743s + [OK] User 27 request 1: 0.967s + [OK] User 14 request 1: 2.772s + [OK] User 19 request 1: 2.079s + [OK] User 3 request 1: 4.309s + [OK] User 8 request 1: 3.609s + [OK] User 6 request 2: 0.050s + [OK] User 29 request 2: 0.053s + [OK] User 10 request 2: 0.055s + [OK] User 4 request 2: 0.055s + [OK] User 22 request 2: 0.055s + [OK] User 15 request 2: 0.057s + [OK] User 30 request 2: 0.053s + [OK] User 23 request 2: 0.053s + [OK] User 7 request 2: 0.053s + [OK] User 11 request 2: 0.053s + [OK] User 13 request 2: 0.054s + [OK] User 27 request 2: 0.052s + [OK] User 14 request 2: 0.053s + [OK] User 19 request 2: 0.054s + [OK] User 3 request 2: 0.054s + [OK] User 8 request 2: 0.053s + [OK] User 6 request 3: 0.049s + [OK] User 29 request 3: 0.050s + [OK] User 10 request 3: 0.048s + [OK] User 4 request 3: 0.049s + [OK] User 22 request 3: 0.049s + [OK] User 15 request 3: 0.048s + [OK] User 30 request 3: 0.048s + [OK] User 23 request 3: 0.051s + [OK] User 7 request 3: 0.052s + [OK] User 11 request 3: 0.052s + [OK] User 13 request 3: 0.052s + [OK] User 27 request 3: 0.050s + [OK] User 14 request 3: 0.050s + [OK] User 3 request 3: 0.049s + [OK] User 19 request 3: 0.049s + [OK] User 8 request 3: 0.048s + [OK] User 6 request 4: 0.037s + [OK] User 10 request 4: 0.030s + [OK] User 4 request 4: 0.025s + [OK] User 7 request 4: 0.020s + [OK] User 3 request 4: 0.018s + [OK] User 8 request 4: 0.018s + [OK] User 21 request 1: 2.028s + [OK] User 18 request 1: 2.444s + [OK] User 17 request 1: 2.584s + [OK] User 9 request 1: 3.694s + [OK] User 26 request 1: 1.335s + [OK] User 12 request 1: 3.279s + [OK] User 2 request 1: 4.690s + [OK] User 1 request 1: 4.836s + [OK] User 20 request 1: 2.175s + [OK] User 16 request 1: 2.731s + [OK] User 5 request 1: 4.264s + [OK] User 28 request 1: 1.069s + [OK] User 24 request 1: 1.628s + [OK] User 25 request 1: 1.491s + [OK] User 21 request 2: 0.043s + [OK] User 18 request 2: 0.043s + [OK] User 17 request 2: 0.044s + [OK] User 9 request 2: 0.044s + [OK] User 26 request 2: 0.045s + [OK] User 12 request 2: 0.045s + [OK] User 1 request 2: 0.044s + [OK] User 2 request 2: 0.044s + [OK] User 20 request 2: 0.044s + [OK] User 16 request 2: 0.044s + [OK] User 5 request 2: 0.044s + [OK] User 28 request 2: 0.045s + [OK] User 24 request 2: 0.044s + [OK] User 25 request 2: 0.044s + [OK] User 21 request 3: 0.044s + [OK] User 18 request 3: 0.044s + [OK] User 17 request 3: 0.045s + [OK] User 9 request 3: 0.044s + [OK] User 12 request 3: 0.044s + [OK] User 26 request 3: 0.046s + [OK] User 2 request 3: 0.043s + [OK] User 16 request 3: 0.044s + [OK] User 1 request 3: 0.047s + [OK] User 20 request 3: 0.044s + [OK] User 5 request 3: 0.044s + [OK] User 28 request 3: 0.042s + [OK] User 24 request 3: 0.042s + [OK] User 25 request 3: 0.041s + [OK] User 9 request 4: 0.022s + [OK] User 2 request 4: 0.020s + [OK] User 1 request 4: 0.016s + [OK] User 5 request 4: 0.014s + +[OK] 100 succeeded, [FAIL] 0 failed + +Latency (successful): + min: 0.014s + avg: 0.833s + max: 4.836s + p95: 3.861s + p99: 4.690s + +Requests above threshold (successful only): + Above 1s: 27/100 (27.0%) + Above 2s: 21/100 (21.0%) + Above 3s: 12/100 (12.0%) + Above 4s: 5/100 (5.0%) + Above 5s: 0/100 (0.0%) + Above 6s: 0/100 (0.0%) + Above 7s: 0/100 (0.0%) + Above 8s: 0/100 (0.0%) + Above 9s: 0/100 (0.0%) + Above 10s: 0/100 (0.0%) diff --git a/concurrency_50_requests_100.txt b/concurrency_50_requests_100.txt new file mode 100644 index 00000000000..7a922c0e1c3 --- /dev/null +++ b/concurrency_50_requests_100.txt @@ -0,0 +1,124 @@ +=== 100 requests, 50 users, fire-as-fast-as-possible === +User mode: none, Key mode: shared +Latency = time from request start until last byte of response received + [OK] User 36 request 1: 2.515s + [OK] User 11 request 1: 5.994s + [OK] User 34 request 1: 2.794s + [OK] User 50 request 1: 0.562s + [OK] User 3 request 1: 7.134s + [OK] User 37 request 1: 2.378s + [OK] User 24 request 1: 4.185s + [OK] User 7 request 1: 6.573s + [OK] User 44 request 1: 1.402s + [OK] User 40 request 1: 1.968s + [OK] User 2 request 1: 7.291s + [OK] User 47 request 1: 0.991s + [OK] User 31 request 1: 3.221s + [OK] User 15 request 1: 5.447s + [OK] User 18 request 1: 5.029s + [OK] User 22 request 1: 4.472s + [OK] User 10 request 1: 6.145s + [OK] User 20 request 1: 4.751s + [OK] User 16 request 1: 5.309s + [OK] User 13 request 1: 5.726s + [OK] User 32 request 1: 3.083s + [OK] User 30 request 1: 3.361s + [OK] User 4 request 1: 7.001s + [OK] User 19 request 1: 4.891s + [OK] User 28 request 1: 3.642s + [OK] User 36 request 2: 0.049s + [OK] User 34 request 2: 0.049s + [OK] User 50 request 2: 0.049s + [OK] User 3 request 2: 0.049s + [OK] User 11 request 2: 0.049s + [OK] User 24 request 2: 0.055s + [OK] User 44 request 2: 0.055s + [OK] User 37 request 2: 0.056s + [OK] User 7 request 2: 0.056s + [OK] User 2 request 2: 0.066s + [OK] User 31 request 2: 0.066s + [OK] User 15 request 2: 0.066s + [OK] User 18 request 2: 0.066s + [OK] User 22 request 2: 0.066s + [OK] User 10 request 2: 0.066s + [OK] User 16 request 2: 0.065s + [OK] User 13 request 2: 0.066s + [OK] User 30 request 2: 0.065s + [OK] User 4 request 2: 0.065s + [OK] User 19 request 2: 0.065s + [OK] User 28 request 2: 0.064s + [OK] User 40 request 2: 0.067s + [OK] User 47 request 2: 0.067s + [OK] User 32 request 2: 0.066s + [OK] User 20 request 2: 0.066s + [OK] User 39 request 1: 2.344s + [OK] User 43 request 1: 1.793s + [OK] User 29 request 1: 3.743s + [OK] User 45 request 1: 1.514s + [OK] User 1 request 1: 7.689s + [OK] User 35 request 1: 2.909s + [OK] User 41 request 1: 2.074s + [OK] User 49 request 1: 0.956s + [OK] User 46 request 1: 1.374s + [OK] User 27 request 1: 4.029s + [OK] User 48 request 1: 1.103s + [OK] User 42 request 1: 1.942s + [OK] User 17 request 1: 5.421s + [OK] User 38 request 1: 2.501s + [OK] User 33 request 1: 3.196s + [OK] User 14 request 1: 5.839s + [OK] User 23 request 1: 4.586s + [OK] User 8 request 1: 6.678s + [OK] User 26 request 1: 4.170s + [OK] User 21 request 1: 4.864s + [OK] User 6 request 1: 6.975s + [OK] User 5 request 1: 7.115s + [OK] User 25 request 1: 4.310s + [OK] User 12 request 1: 6.120s + [OK] User 9 request 1: 6.539s + [OK] User 39 request 2: 0.052s + [OK] User 43 request 2: 0.057s + [OK] User 45 request 2: 0.056s + [OK] User 1 request 2: 0.056s + [OK] User 41 request 2: 0.056s + [OK] User 49 request 2: 0.056s + [OK] User 46 request 2: 0.055s + [OK] User 35 request 2: 0.056s + [OK] User 29 request 2: 0.057s + [OK] User 27 request 2: 0.056s + [OK] User 48 request 2: 0.066s + [OK] User 17 request 2: 0.066s + [OK] User 38 request 2: 0.066s + [OK] User 33 request 2: 0.066s + [OK] User 23 request 2: 0.066s + [OK] User 26 request 2: 0.065s + [OK] User 21 request 2: 0.065s + [OK] User 5 request 2: 0.065s + [OK] User 25 request 2: 0.065s + [OK] User 9 request 2: 0.065s + [OK] User 8 request 2: 0.066s + [OK] User 14 request 2: 0.067s + [OK] User 6 request 2: 0.066s + [OK] User 42 request 2: 0.069s + [OK] User 12 request 2: 0.067s + +[OK] 100 succeeded, [FAIL] 0 failed + +Latency (successful): + min: 0.049s + avg: 2.087s + max: 7.689s + p95: 6.975s + p99: 7.291s + +Requests above threshold (successful only): + Above 1s: 47/100 (47.0%) + Above 2s: 40/100 (40.0%) + Above 3s: 33/100 (33.0%) + Above 4s: 27/100 (27.0%) + Above 5s: 18/100 (18.0%) + Above 6s: 11/100 (11.0%) + Above 7s: 5/100 (5.0%) + Above 8s: 0/100 (0.0%) + Above 9s: 0/100 (0.0%) + Above 10s: 0/100 (0.0%) diff --git a/problem_tracker.md b/problem_tracker.md index aadf6c64bff..a929f7d0a97 100644 --- a/problem_tracker.md +++ b/problem_tracker.md @@ -249,3 +249,106 @@ The latency spike is high regardless of whether a user is passed to the payload 1. **User parameter has no impact** - Passing a user to the request payload doesn't affect first request latency 2. **Cache has no impact** - Response caching ON vs OFF shows identical performance (~15s avg) 3. **Latency is proxy overhead** - 15s average suggests infrastructure (DB, Redis, auth) is the bottleneck, not LLM calls since the LLM server is running locally. + +--- + +## Minimal Configuration Test Results + +### Test with `test_config_minimal.yaml` (no DB, no Redis, no callbacks, no alerting) + +- [x] **Test completed:** `validation_123.txt` + +| Config | File | avg | p95 | max | Above 1s | +|--------|------|-----|-----|-----|----------| +| **Minimal config** | `validation_123.txt` | **8.654s** | 15.065s | 15.807s | 100% | +| Full config (cache ON) | `user_none_1_request_per_user_local_llm_cache_on.txt` | 15.204s | 26.543s | 27.706s | 100% | +| Full config (cache OFF) | `user_none_1_requests_per_user_local_llm_cache_off.txt` | 15.449s | 26.317s | 27.430s | 100% | + +**Improvement: 43% faster** (15.2s → 8.6s avg) + +### Critical Findings + +1. **Removing DB/Redis/callbacks cuts latency nearly in half** + - Proves the 6.5s overhead comes from database operations, Redis, alerting infrastructure + +2. **BUT: 8.6s is still very slow for a local mock LLM** + - Local LLM mock likely responds in milliseconds + - Proxy adds ~8.6s overhead **even with everything disabled** + - Same wave pattern persists (early: 15s, mid: 6-8s, late: 1.5-4s) + +3. **Root cause is in core proxy code, not features** + - The bulk of latency comes from the proxy itself, not external network calls + - Likely issues: + - Request queueing/serialization (requests blocking each other) + - Poor concurrency handling + - Auth/router logic overhead + - Python async event loop bottlenecks + +--- + +## Conclusions + +1. **User parameter:** No impact +2. **Cache:** No impact +3. **Database/Redis/Alerting:** Adds ~6.5s overhead (15.2s → 8.6s) +4. **Core proxy code:** Adds ~8.6s overhead even with bare minimum config +5. **Total overhead:** ~15s for complex config processing 100 concurrent requests + +**Next action:** Profile the proxy request path to identify the specific bottleneck in core code (likely concurrency/queueing) + +## cProfile: Per-Request Hotspots (minimal config, no DB/Redis) + +Profile captured with `test_config_minimal.yaml`. Ordered by cumtime, normalized per request: + +| Component | Calls | Cumtime | Per-call (est.) | Notes | +| ------------------------------------ | --------- | ------- | --------------- | ---------------------------------- | +| user_api_key_auth | 200 | 12.58s | ~63ms | Auth entry point | +| _user_api_key_auth_builder | 100 | 12.55s | **~125ms** | Main auth logic | +| log_db_metrics wrapper | 100 | 12.53s | **~125ms** | Still in path despite no DB | +| FastAPI solve_dependencies | 1600/200 | 12.61s | ~63ms | Dependency injection for chat route| +| Starlette/FastAPI middleware/routing | 600 | ~12.7s | ~21ms | Middleware stack | +| annotationlib call_annotate_function | 23400 | 8.28s | ~0.4ms × many | Python 3.14 annotation processing | +| router acompletion | 586 | 0.67s | ~1ms | LLM call path (mostly I/O) | + +**Key finding:** Auth + log_db_metrics ≈ **125ms per request** even with no database. Expected for a simple master_key compare: microseconds. + +**Optimization targets (in order):** +1. Auth path + log_db_metrics – ensure early return when master-key-only (no DB) +2. FastAPI dependency resolution – reduce number of injected dependencies on chat route +3. Lazy/conditional Prisma import – avoid loading Prisma when DB not configured + +--- + +## Concurrency Test 1-10-30-50-100 + +**Setup:** Minimal config (`test_config_minimal.yaml`), no user in payload, master key auth, local LLM mock at localhost:8090. 100 total requests per run; concurrency = number of simulated users. + +### Results + +| Concurrency | File | avg | p95 | max | >1s | >5s | >10s | +|-------------|------|-----|-----|-----|-----|-----|------| +| 1 | `concurrency_1_requests_100.txt` | 0.012s | 0.007s | 0.716s | 0% | 0% | 0% | +| 10 | `concurrency_10_requests_100.txt` | 0.144s | 1.195s | 2.034s | 7% | 0% | 0% | +| 30 | `concurrency_30_requests_100.txt` | 0.833s | 3.861s | 4.836s | 27% | 0% | 0% | +| 50 | `concurrency_50_requests_100.txt` | 2.087s | 6.975s | 7.689s | 47% | 18% | 0% | +| 100 | `concurrency_100_requests_100.txt` | 7.721s | 14.019s | 14.657s | 97% | 69% | 33% | + +### Analysis + +1. **Steep degradation with concurrency** — Average latency grows ~640× from 12 ms (c=1) to 7.7 s (c=100). p95 grows from 7 ms to 14 s. + +2. **First request vs later requests** — At c=1, the first request is ~716 ms (cold/auth path), then ~5 ms per request. At c=10/30/50, the first request per user is 0.5–4 s, while subsequent requests are ~15–70 ms. At c=100, every request is effectively a “first” request (1 per user), so all pay the full contention cost. + +3. **Evidence of queueing/serialization** — Higher concurrency yields much worse latency despite the same total load. This points to limited parallelism: requests appear to be processed in waves rather than truly in parallel. + +4. **Tail latency** — At c=100, 33% of requests exceed 10 s. Worst-case (14.6 s) is far above the ~5 ms steady-state per-request cost, indicating substantial proxy overhead under load. + +5. **Config context** — These runs use minimal config (no DB, Redis, callbacks) and the Prisma fast-path fix, so the bottleneck is in core proxy handling: auth, routing, and/or async event-loop behavior under concurrency. + +### Checklist + +- [x] Concurrency 1 → `concurrency_1_requests_100.txt` +- [x] Concurrency 10 → `concurrency_10_requests_100.txt` +- [x] Concurrency 30 → `concurrency_30_requests_100.txt` +- [x] Concurrency 50 → `concurrency_50_requests_100.txt` +- [x] Concurrency 100 → `concurrency_100_requests_100.txt` \ No newline at end of file