はじめに
これは前回の記事からの続きです。
とりあえずやっつけで Cisco Unified IP Phone Services Application (長い) を作ってみましたが、アクセスがあるたびに Node.js で表示用の画像を作ってるのでパフォーマンスが気になります。
ほら、もしかしたら数百人いる環境で使われるかもしれないし。(などと)
テスト先環境
- ProLiant TM200 (Intel(R) Xeon(R) CPU D-1518) から 仮想2コア
- Debian 12.4
- Node.js v18.19.0
Apache Bench で計測してみる
- リクエスト総数: 10000
- 同時リクエスト数: 200
- Lengthエラー報告: 無効
※ すなわちコマンドとしては ab -n 10000 -c 200 -l テスト先URL
※ Lengthエラー報告を無効にしているのは、アクセスするタイミングでエオルゼア時間が変わるためです。(エオルゼア時間が違う = 画像が違う)
ケース1:対策無し
アクセスがあるたびに愚直に下記のような画像を生成して応答する場合を計測してみましょう。
Document Path: /api/et1.png
Document Length: Variable
Concurrency Level: 200
Time taken for tests: 42.979 seconds
Complete requests: 10000
Failed requests: 0
Total transferred: 19671292 bytes
HTML transferred: 18221292 bytes
Requests per second: 232.67 [#/sec] (mean)
Time per request: 859.583 [ms] (mean)
Time per request: 4.298 [ms] (mean, across all concurrent requests)
Transfer rate: 446.97 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 1 1.1 1 11
Processing: 14 854 205.2 883 1614
Waiting: 6 854 205.2 882 1614
Total: 15 855 205.2 884 1614
Percentage of the requests served within a certain time (ms)
50% 884
66% 909
75% 937
80% 963
90% 1050
95% 1081
98% 1118
99% 1457
100% 1614 (longest request)
……うん、ひどいですね。
最大で約1.6秒も遅れるようでは時計として成立しません。(個人の感想です)
ケース2:送る画像をモノクロPNGにしてみる
どうせ画像内で白と黒しか使ってないので下記のようなモノクロ画像にして送信してみるのはどうでしょう?
Document Path: /api/et2.png
Document Length: Variable
Concurrency Level: 200
Time taken for tests: 19.664 seconds
Complete requests: 10000
Failed requests: 0
Total transferred: 6144377 bytes
HTML transferred: 4694377 bytes
Requests per second: 508.54 [#/sec] (mean)
Time per request: 393.287 [ms] (mean)
Time per request: 1.966 [ms] (mean, across all concurrent requests)
Transfer rate: 305.14 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 1 0.8 1 8
Processing: 12 390 86.1 401 751
Waiting: 4 390 86.1 401 751
Total: 13 391 86.2 402 754
Percentage of the requests served within a certain time (ms)
50% 402
66% 424
75% 439
80% 451
90% 484
95% 520
98% 544
99% 604
100% 754 (longest request)
最大リクエスト完了時間がケース1の46.7%にまで改善しました。
それでも0.7秒なので、もうちょっとなんとかなってほしいですね。
ケース3: フルカラーPNGを事前生成して、そのデータを返す
エオルゼア時間は現実時間ベースなので、未来のエオルゼア時間を前もって求めることができます。
このことを利用して、エオルゼア時間の画像を先に作ってキャッシュしておいたものを送信する実装を行ってみました。
Document Path: /api/et3.png
Document Length: Variable
Concurrency Level: 200
Time taken for tests: 5.456 seconds
Complete requests: 10000
Failed requests: 0
Total transferred: 21366343 bytes
HTML transferred: 19916343 bytes
Requests per second: 1832.76 [#/sec] (mean)
Time per request: 109.125 [ms] (mean)
Time per request: 0.546 [ms] (mean, across all concurrent requests)
Transfer rate: 3824.15 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 1 1.8 1 13
Processing: 5 107 38.4 112 202
Waiting: 2 107 38.4 112 201
Total: 10 109 38.5 114 202
Percentage of the requests served within a certain time (ms)
50% 114
66% 128
75% 138
80% 144
90% 157
95% 165
98% 173
99% 179
100% 202 (longest request)
あれ、なんかめっちゃいい。
ケース4: モノクロPNGを事前生成して、そのデータを返す
ケース2と3の合わせ技も試してみましょう。
Document Path: /api/et4.png
Document Length: Variable
Concurrency Level: 200
Time taken for tests: 5.390 seconds
Complete requests: 10000
Failed requests: 0
Total transferred: 6099120 bytes
HTML transferred: 4649120 bytes
Requests per second: 1855.29 [#/sec] (mean)
Time per request: 107.800 [ms] (mean)
Time per request: 0.539 [ms] (mean, across all concurrent requests)
Transfer rate: 1105.04 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 1 1.0 1 8
Processing: 10 106 36.1 108 202
Waiting: 2 106 36.1 108 201
Total: 11 107 36.2 109 202
Percentage of the requests served within a certain time (ms)
50% 109
66% 123
75% 134
80% 140
90% 152
95% 164
98% 179
99% 190
100% 202 (longest request)
あれっ、ケース3とほとんど差がないの???
おわりに
Cisco Unified IP Phone Services Application、皆さんもぜひ作ってみてください。
まず実機を手に入れるところから
おまけ: 今回の検証に使用したコード
// ============================================================ #
// Copyright (c) 2024 CIB-MC
// Released under the MIT license
// https://opensource.org/licenses/mit-license.php
// ============================================================ #
const express = require('express');
const app = express();
const createCanvas = require('canvas')
app.get('/api/et1.png', (req, res) => {
let dt = new Date();
let buffer = createEtPng(dt, true);
res.set('content-type', 'image/png');
res.end(buffer);
});
app.get('/api/et2.png', (req, res) => {
let dt = new Date();
let buffer = createEtPng(dt, false);
res.set('content-type', 'image/png');
res.end(buffer);
});
let cache_et3 = {};
let cache_et4 = {};
app.get('/api/et3.png', (req, res) => {
let dt = new Date();
let buffer = cache_et3['_' + Math.floor(dt.getTime() / 1000)];
if (!buffer) {
console.log('Cache mishit!')
res.status(404).end();
return;
}
res.set('content-type', 'image/png');
res.end(buffer);
});
app.get('/api/et4.png', (req, res) => {
let dt = new Date();
let buffer = cache_et4['_' + Math.floor(dt.getTime() / 1000)];
if (!buffer) {
console.log('Cache mishit!')
res.status(404).end();
return;
}
res.set('content-type', 'image/png');
res.end(buffer);
});
const CACHE_TTL = 20;
const cacheCreateStartup = () => {
let dt = new Date();
for (let i = 0; i < CACHE_TTL; i++) {
dt.setSeconds(dt.getSeconds() + 1, 0);
const cache_key = '_' + Math.floor(dt.getTime() / 1000);
cache_et3[cache_key] = createEtPng(dt, true);
cache_et4[cache_key] = createEtPng(dt, false);
console.log(cache_key + " precreated.");
}
console.log("--> Cache precreate done!");
}
const cacheCreate = () => {
let dt = new Date();
dt.setSeconds(dt.getSeconds() + 10, 0);
const cache_key = '_' + Math.floor(dt.getTime() / 1000);
if (!(cache_key in cache_et3)) {
cache_et3[cache_key] = createEtPng(dt, true);
console.log('Cache ' + cache_key + ' created for et3.');
}
if (!(cache_key in cache_et4)) {
cache_et4[cache_key] = createEtPng(dt, false);
console.log('Cache ' + cache_key + ' created for et4.');
}
}
const cachePurge = () => {
let count_et3 = 0;
let count_et4 = 0;
let dt = new Date();
let dt_ttl_over = dt.setSeconds(dt.getSeconds() - CACHE_TTL, 0);
for(let key in cache_et3) {
let key_ts = parseInt(key.replace('_', '')) * 1000;
let key_dt = new Date(key_ts);
if (key_dt < dt_ttl_over) {
delete cache_et3[key];
count_et3++;
}
}
for(let key in cache_et4) {
let key_ts = parseInt(key.replace('_', '')) * 1000;
let key_dt = new Date(key_ts);
if (key_dt < dt_ttl_over) {
delete cache_et4[key];
count_et4++;
}
}
console.log('Purged ' + count_et3 + '&' + count_et4 + ' cache(s).')
}
class EorzeaDatetime {
weekepoch = 0;
constructor(datetime) {
var dt = datetime ? datetime : new Date();
var dt_jst = new Date(dt.toLocaleString({ timeZone: 'Asia/Tokyo' }))
var dt_ws = new Date(dt_jst.getFullYear(), dt_jst.getMonth(), dt_jst.getDate() - dt_jst.getDay(), 0, 0, 0, 0);
this.weekepoch = (dt_jst.getTime() * (1440 / 70)) - (dt_ws.getTime() * (1440 / 70));
}
getHours() {
return Math.floor(this.weekepoch / 3600000) % 24;
}
getMinutes() {
return Math.floor(this.weekepoch / 60000) % 60;
}
getSeconds() {
return Math.floor(this.weekepoch / 1000) % 60;
}
}
function appendZero(str, digits) {
str = '' + str;
while (str.length < digits) {
str = "0" + str;
}
return str;
}
const createEtPng = (dt_arg, is_color) => {
let dt = structuredClone(dt_arg);
const canvas = createCanvas(320, 156);
const ctx = canvas.getContext('2d', {pixelFormat: is_color ? 'RGB24' : 'A1'});
ctx.fillStyle = is_color ? "#000" : 'rgba(0,0,0,0)';
ctx.fillRect(0,0,320,156);
dt.setMilliseconds(dt.getMilliseconds() + 500);
let edt = new EorzeaDatetime(dt);
ctx.fillStyle = is_color ? "#fff" : 'rgba(0,0,0,1)';
ctx.textAlign = 'center';
ctx.font = "normal 30px monospace";
ctx.fillText('Eorzea Time', 160, 40);
ctx.font = "bold 60px monospace";
ctx.fillText(appendZero(edt.getHours(), 2) + ':' + appendZero(edt.getMinutes(),2), 160, 120);
return canvas.toBuffer("image/png");
}
app.listen(3000, () => {
cacheCreateStartup();
setInterval(cachePurge, 1000 * 30);
setInterval(cacheCreate, 250);
console.log('Server listening on port 3000');
});