fix: on log rotation, new entry could be end up in the old log file
Massimo Melina committed
Apr 1, 2026 at 17:59 UTC
34f66e36fdf0ffcef595f789d9548b64ba9cedd8
1 file changed
+7
-8
src/log.ts
+7
-8
@@ -95,14 +95,14 @@ export const logMw: Koa.Middleware = async (ctx, next) => {
95
if (dontLogNet.compiled()(ctx.ip)) return
96
const isError = ctx.status >= 400
97
const logger = isError && accessErrorLog || accessLogger
98
- const rotate = logRotation.get()?.[0]
98
let { stream, last, path } = logger
99
if (!stream) return
101
- logger.last = reqStart
100
+ const rotate = logRotation.get()?.[0]
101
+ const reqEnd = logger.last = new Date()
102
if (rotate && last) { // rotation enabled and a file exists?
103
- const passed = Number(reqStart) - Number(last)
103
+ const passed = Number(reqEnd) - Number(last)
104
- 3600_000 // be pessimistic and count a possible DST change
105
- const t = reqStart
105
+ const t = reqEnd
106
if (rotate === 'm' && (passed >= 31 * DAY || t.getMonth() !== last.getMonth())
107
|| rotate === 'd' && (passed >= DAY || t.getDate() !== last.getDate()) // checking passed will solve the case when the day of the month is the same but a month has passed
108
|| rotate === 'w' && (passed >= 7 * DAY || t.getDay() < last.getDay())) {
@@ -120,13 +120,12 @@ export const logMw: Koa.Middleware = async (ctx, next) => {
120
}
121
}
122
const format = '%s - %s [%s] "%s %s HTTP/%s" %d %s %s\n' // Apache's Common Log Format
123
- // keep reqStart for duration/rotation, but log time should reflect when the line is actually written
124
- const a = new Date().toString().split(' ') // like nginx, our default log contains the time of log writing
123
+ const a = reqEnd.toString().split(' ') // like nginx, our default log contains the time of log writing
124
const date = `${a[2]}/${a[1]}/${a[3]}:${a[4]} ${a[5]?.slice(3)}`
125
const user = getCurrentUsername(ctx) || userAtStart
126
const length = ctx.state.length ?? ctx.length
127
const uri = ctx.originalUrl
129
- const duration = (Date.now() - Number(reqStart)) / 1000
128
+ const duration = (Number(reqEnd) - Number(reqStart)) / 1000
129
ctx.logExtra(ctx.vfsNode && {
130
speed: Math.round(length / duration),
131
...ctx.state.includesLastByte && ctx.res.finished && { dl: 1 }
@@ -141,7 +140,7 @@ export const logMw: Koa.Middleware = async (ctx, next) => {
140
ctx.logExtra({ ua: ctx.get('user-agent') || undefined })
141
const extra = ctx.state.logExtra
142
if (events.anyListener(logger.name)) // small optimization: this event can happen often, while most times there's no listener, and the parameters object is constructed pointlessly. A benchmark measured it 20% faster (just the line), while maybe it was not necessary.
144
- events.emit(logger.name, { ctx, length, user, ts: reqStart, uri, extra })
143
+ events.emit(logger.name, { ctx, length, user, ts: reqEnd, uri, extra })
144
debounce(() => // once in a while we check if the file is still good (not deleted, etc), or we'll reopen it
145
statWithTimeout(logger.path).catch(() => logger.reopen())) // async = smoother but we may lose some entries
146
stream!.write(util.format( format,