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
f39b49556dd49753598ee63b4803a057b8c63098
1 file changed
+7
-8
src/log.ts
+7
-8
@@ -93,14 +93,14 @@ export const logMw: Koa.Middleware = async (ctx, next) => {
93
if (dontLogNet.compiled()(ctx.ip)) return
94
const isError = ctx.status >= 400
95
const logger = isError && accessErrorLog || accessLogger
96
- const rotate = logRotation.get()?.[0]
96
let { stream, last, path } = logger
97
if (!stream) return
99
- logger.last = reqStart
98
+ const rotate = logRotation.get()?.[0]
99
+ const reqEnd = logger.last = new Date()
100
if (rotate && last) { // rotation enabled and a file exists?
101
- const passed = Number(reqStart) - Number(last)
101
+ const passed = Number(reqEnd) - Number(last)
102
- 3600_000 // be pessimistic and count a possible DST change
103
- const t = reqStart
103
+ const t = reqEnd
104
if (rotate === 'm' && (passed >= 31 * DAY || t.getMonth() !== last.getMonth())
105
|| 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
106
|| rotate === 'w' && (passed >= 7 * DAY || t.getDay() < last.getDay())) {
@@ -118,13 +118,12 @@ export const logMw: Koa.Middleware = async (ctx, next) => {
118
}
119
}
120
const format = '%s - %s [%s] "%s %s HTTP/%s" %d %s %s\n' // Apache's Common Log Format
121
- // keep reqStart for duration/rotation, but log time should reflect when the line is actually written
122
- const a = new Date().toString().split(' ') // like nginx, our default log contains the time of log writing
121
+ const a = reqEnd.toString().split(' ') // like nginx, our default log contains the time of log writing
122
const date = `${a[2]}/${a[1]}/${a[3]}:${a[4]} ${a[5]?.slice(3)}`
123
const user = getCurrentUsername(ctx) || userAtStart
124
const length = ctx.state.length ?? ctx.length
125
const uri = ctx.originalUrl
127
- const duration = (Date.now() - Number(reqStart)) / 1000
126
+ const duration = (Number(reqEnd) - Number(reqStart)) / 1000
127
ctx.logExtra(ctx.vfsNode && {
128
speed: Math.round(length / duration),
129
...ctx.state.includesLastByte && ctx.res.finished && { dl: 1 }
@@ -139,7 +138,7 @@ export const logMw: Koa.Middleware = async (ctx, next) => {
138
ctx.logExtra({ ua: ctx.get('user-agent') || undefined })
139
const extra = ctx.state.logExtra
140
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.
142
- events.emit(logger.name, { ctx, length, user, ts: reqStart, uri, extra })
141
+ events.emit(logger.name, { ctx, length, user, ts: reqEnd, uri, extra })
142
debounce(() => // once in a while we check if the file is still good (not deleted, etc), or we'll reopen it
143
statWithTimeout(logger.path).catch(() => logger.reopen())) // async = smoother but we may lose some entries
144
stream!.write(util.format( format,