perf(middleware/logger): optimize color status #3603

exoego · 2024-10-31T15:29:29Z

This PR optimizescolorStatus function in Logger middleware.

Performance-wise, both if-else version and switch version is the best.
I chose switch version which appears cleaner to me.

I've noticed some status codes (e.g. 700) are unreachable, so deleted.

// Node
> new Response("", {status:800, statusText:"aa"})
Uncaught RangeError: init["status"] must be in the range of 200 to 599, inclusive.
    at initializeResponse (node:internal/deps/undici/undici:9030:15)
    at new Response (node:internal/deps/undici/undici:8822:9)

// Bun
> new Response("", {status:600})
2 | new Response("", {
    ^
RangeError: The status provided (600) must be 101 or in the range of [200, 599]

// Deno
> new Response("", {status:800, statusText:"aa"})

Uncaught RangeError: The status provided (800) is not equal to 101 and outside the range [200, 599]
    at initializeAResponse (ext:deno_fetch/23_response.js:183:11)
    at new Response (ext:deno_fetch/23_response.js:338:5)
    at <anonymous>:1:22

Benchmark

import { bench, run } from 'mitata'

const colorStatus = (status, colorEnabled) => {
  const out = {
    7: colorEnabled ? `\x1b[35m${status}\x1b[0m` : `${status}`,
    5: colorEnabled ? `\x1b[31m${status}\x1b[0m` : `${status}`,
    4: colorEnabled ? `\x1b[33m${status}\x1b[0m` : `${status}`,
    3: colorEnabled ? `\x1b[36m${status}\x1b[0m` : `${status}`,
    2: colorEnabled ? `\x1b[32m${status}\x1b[0m` : `${status}`,
    1: colorEnabled ? `\x1b[32m${status}\x1b[0m` : `${status}`,
    0: colorEnabled ? `\x1b[33m${status}\x1b[0m` : `${status}`,
  }
  const calculateStatus = (status / 100) | 0
  return out[calculateStatus]
}

const optDict = (status, colorEnabled) => {
  if (!colorEnabled) {
    return `${status}`
  }
  const out = {
    7: `\x1b[35m${status}\x1b[0m`,
    5: `\x1b[31m${status}\x1b[0m`,
    4: `\x1b[33m${status}\x1b[0m`,
    3: `\x1b[36m${status}\x1b[0m`,
    2: `\x1b[32m${status}\x1b[0m`,
    1: `\x1b[32m${status}\x1b[0m`,
    0: `\x1b[33m${status}\x1b[0m`,
  }
  const calculateStatus = (status / 100) | 0
  return out[calculateStatus]
}

const optIfElse = (status, colorEnabled) => {
  if (!colorEnabled) {
    return `${status}`
  }
  const calculateStatus = (status / 100) | 0
  if (calculateStatus === 7) {
    return `\x1b[35m${status}\x1b[0m`
  } else if (calculateStatus === 5) {
    return `\x1b[31m${status}\x1b[0m`
  } else if (calculateStatus === 3) {
    return `\x1b[36m${status}\x1b[0m`
  } else if (calculateStatus === 2 || calculateStatus === 1) {
    return `\x1b[32m${status}\x1b[0m`
  } else if (calculateStatus === 4 || calculateStatus === 0) {
    return `\x1b[33m${status}\x1b[0m`
  }
}
const optSwitch = (status, colorEnabled) => {
  if (!colorEnabled) {
    return `${status}`
  }
  switch ((status / 100) | 0) {
    case 7: return `\x1b[35m${status}\x1b[0m`
    case 5: return `\x1b[31m${status}\x1b[0m`
    case 3: return `\x1b[36m${status}\x1b[0m`
    case 2:
    case 1: return `\x1b[32m${status}\x1b[0m`
    case 4:
    case 0: return `\x1b[33m${status}\x1b[0m`
  }
}

bench('base', () => {
  const s = colorStatus(400, true)
})

bench('dict', () => {
  const s = optDict(400, true)
})

bench('if-else', () => {
  const s = optIfElse(400, true)
})

bench('switch', () => {
  const s = optSwitch(400, true)
})

await run()

282 times faster on Node:

runtime: node 22.4.0 (arm64-darwin)

benchmark              avg (min … max) p75   p99    (min … top 1%)
-------------------------------------- -------------------------------
base                     36.09 ns/iter  34.52 ns █                    
                (32.88 ns … 160.75 ns)  69.75 ns █▄▂▁▁▁▁▁▁▁▂▂▁▁▁▁▁▁▁▁▁
dict                      9.05 ns/iter   7.79 ns █▂                   
                 (6.70 ns … 163.55 ns)  34.16 ns ██▁▁▁▁▁▁▁▁▁▁▁▁▂▁▁▁▁▁▁
if-else                 127.68 ps/iter 132.08 ps         █             !
                (101.56 ps … 56.40 ns) 152.59 ps ▁▁▁▁▁▁▁▁█▁▁▁▇▁▁▁▁▁▁▁▁
switch                  127.49 ps/iter 122.07 ps           █           !
                (101.56 ps … 54.14 ns) 142.58 ps ▁▁▁▁▁▁▁▁▁▁█▁▁▁▁▃▁▁▁▁▁

1020 times faster on Bun:

runtime: bun 1.1.33 (arm64-darwin)

benchmark              avg (min … max) p75   p99    (min … top 1%)
-------------------------------------- -------------------------------
base                    107.27 ns/iter 103.91 ns █                    
               (101.11 ns … 196.16 ns) 162.03 ns █▆▂▂▁▁▁▁▁▁▁▁▁▁▁▁▁▂▁▁▁
dict                     79.73 ns/iter  77.79 ns █▃                   
                (73.59 ns … 157.91 ns) 134.04 ns ██▅▂▁▁▁▁▁▁▁▁▁▁▁▁▁▂▁▁▁
if-else                  93.71 ps/iter 101.56 ps           █         ▂ !
                 (61.04 ps … 72.85 ns) 101.81 ps ▁▁▁▁▁▁▁▁▁▁█▁▁▁▁▇▁▁▁▁█
switch                   94.10 ps/iter 101.81 ps           ▆         █ !
                 (61.04 ps … 14.82 ns) 101.81 ps ▁▁▁▁▁▁▁▁▁▁█▁▁▁▁▅▁▁▁▁█

479 times faster on Deno:

runtime: deno 2.0.4 (aarch64-apple-darwin)

benchmark              avg (min … max) p75   p99    (min … top 1%)
-------------------------------------- -------------------------------
base                     43.71 ns/iter  48.78 ns █                    
                (38.66 ns … 167.20 ns)  64.42 ns █▆▃▁▁▁▁▂▇▃▂▂▁▁▁▁▁▁▁▁▁
dict                      9.86 ns/iter   7.82 ns █                    
                 (6.78 ns … 184.60 ns)  22.84 ns ██▁▁▁▁▁▁▁▁▁▁▄▃▂▁▁▁▁▁▁
if-else                  99.32 ps/iter 101.81 ps           █    ▆      !
                 (71.04 ps … 61.65 ns) 111.82 ps ▁▁▁▁▁▁▁▁▁▁█▁▁▁▁█▁▁▁▁▁
switch                   99.70 ps/iter 101.81 ps           █    ▇      !
                 (71.04 ps … 73.63 ns) 111.82 ps ▁▁▁▁▁▁▁▁▁▁█▁▁▁▁█▁▁▁▁▁

The author should do the following, if applicable

Add tests
Run tests
bun run format:fix && bun run lint:fix to format the code
Add TSDoc/JSDoc to document the code

codecov · 2024-10-31T15:34:32Z

Codecov Report

All modified and coverable lines are covered by tests ✅

Project coverage is 94.71%. Comparing base (4dd8b2b) to head (66f35bf).
Report is 8 commits behind head on main.

Additional details and impacted files

@@            Coverage Diff             @@
##             main    #3603      +/-   ##
==========================================
- Coverage   94.71%   94.71%   -0.01%     
==========================================
  Files         158      158              
  Lines        9555     9554       -1     
  Branches     2813     2885      +72     
==========================================
- Hits         9050     9049       -1     
  Misses        505      505

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

src/middleware/logger/index.test.ts

yusukebe · 2024-11-01T07:50:56Z

src/middleware/logger/index.ts

+  // Fallback to unsupported status code.
+  // E.g.) Bun and Deno supports new Response with 101, but Node.js does not.
+  // And those may evolve to accept more status.
+  return `${status}`


Is this line tested?

The line is covered for color-disabled case.
But not covered for currently unsupported status code, because test always fail if we test 100 or 700.
This fallback will help when Response supports 100 or other in future.

Hi @exoego, thanks for creating the pull request.

It's a fine line as to whether we need to overwrite the object and test it, but it's better if there is test, so how about testing it with the following code?

diff --git a/src/middleware/logger/index.test.ts b/src/middleware/logger/index.test.ts index 0623fc64..7c7e4689 100644 --- a/src/middleware/logger/index.test.ts +++ b/src/middleware/logger/index.test.ts @@ -32,7 +32,12 @@ describe('Logger by Middleware', () => { return c.redirect('/empty', 301) }) app.get('/server-error', (c) => { - return c.text('', 511) + const res = new Response('', { status: 511 }) + if (c.req.query('status')) { + // test status code not yet supported by runtime `Response` object + Object.defineProperty(res, 'status', { value: parseInt(c.req.query('status') as string) }) + } + return res }) }) @@ -95,6 +100,22 @@ describe('Logger by Middleware', () => { expect(log.startsWith('--> GET /server-error \x1b[31m511\x1b[0m')).toBe(true) expect(log).toMatch(/m?s$/) }) + + it('Log status 100', async () => { + const res = await app.request('http://localhost/server-error?status=100') + expect(res).not.toBeNull() + expect(res.status).toBe(100) + expect(log.startsWith('--> GET /server-error 100')).toBe(true) + expect(log).toMatch(/m?s$/) + }) + + it('Log status 700', async () => { + const res = await app.request('http://localhost/server-error?status=700') + expect(res).not.toBeNull() + expect(res.status).toBe(700) + expect(log.startsWith('--> GET /server-error 700')).toBe(true) + expect(log).toMatch(/m?s$/) + }) }) describe('Logger by Middleware in NO_COLOR', () => {

Oh that's hacky but nice.
Done in 66f35bf

yusukebe · 2024-11-01T07:52:39Z

@exoego

Thanks!

I've noticed some status codes (e.g. 700) are unreachable, so deleted.

You are right. Good point!

yusukebe

LGTM!

yusukebe · 2024-11-02T07:16:41Z

@exoego @usualoma Thanks!

Merging now.

refactor(logger): optimize colors status

a744446

exoego changed the title ~~refactor(logger): optimize colors status~~ perf(logger): optimize colors status Oct 31, 2024

exoego added 2 commits November 1, 2024 06:30

refactor(logger): add failing test

9e9e900

refactor(logger): remove unreachable cases. Response accepts 200-599

0b7121a

exoego force-pushed the refactor-colorStatus branch from a95bcce to 0b7121a Compare October 31, 2024 21:42

refactor(logger): added fallback

e5adc98

exoego changed the title ~~perf(logger): optimize colors status~~ perf(middleware/logger): optimize colors status Nov 1, 2024

exoego changed the title ~~perf(middleware/logger): optimize colors status~~ perf(middleware/logger): optimize color status Nov 1, 2024

yusukebe reviewed Nov 1, 2024

View reviewed changes

exoego added 2 commits November 2, 2024 09:00

perf(middleware/logger): cleanup tests

e6b8041

perf(middleware/logger): test unsupported status code forcibly

66f35bf

yusukebe approved these changes Nov 2, 2024

View reviewed changes

yusukebe merged commit f3577a1 into honojs:main Nov 2, 2024
16 checks passed

exoego deleted the refactor-colorStatus branch November 2, 2024 08:14

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

perf(middleware/logger): optimize color status #3603

perf(middleware/logger): optimize color status #3603

exoego commented Oct 31, 2024 •

edited

Loading

codecov bot commented Oct 31, 2024 •

edited

Loading

yusukebe Nov 1, 2024

exoego Nov 2, 2024

usualoma Nov 2, 2024

exoego Nov 2, 2024

usualoma Nov 2, 2024

yusukebe commented Nov 1, 2024

yusukebe left a comment

yusukebe commented Nov 2, 2024

perf(middleware/logger): optimize color status #3603

perf(middleware/logger): optimize color status #3603

Conversation

exoego commented Oct 31, 2024 • edited Loading

Benchmark

The author should do the following, if applicable

codecov bot commented Oct 31, 2024 • edited Loading

Codecov Report

yusukebe Nov 1, 2024

Choose a reason for hiding this comment

exoego Nov 2, 2024

Choose a reason for hiding this comment

usualoma Nov 2, 2024

Choose a reason for hiding this comment

exoego Nov 2, 2024

Choose a reason for hiding this comment

usualoma Nov 2, 2024

Choose a reason for hiding this comment

yusukebe commented Nov 1, 2024

yusukebe left a comment

Choose a reason for hiding this comment

yusukebe commented Nov 2, 2024

exoego commented Oct 31, 2024 •

edited

Loading

codecov bot commented Oct 31, 2024 •

edited

Loading