RF suite/test context in the node logger is module-global, so log lines are attributed to the wrong worker when a node process is shared
维护者通常 1 天内回复
还没有人认领这个 Issue。
评估
- 难度
- 4/5
- 预计耗时
- 3-5 天
- 新手友好度
- 55/100
- Issue 类型
- 缺陷
- 描述清晰度
- 描述清楚
- 活跃度
- 活跃
- 技术栈
- typescript
调研方向
Start with node/playwright-wrapper/browser_logger.ts, then trace the per-peer state in node/playwright-wrapper/playwright-state.ts and the gRPC wrappers in node/playwright-wrapper/grpc-service.ts. Review the shared context and wrapper lifetimes, using the shared-node acceptance setup in tasks.py as the concurrency case. Done means concurrent sessions produce log lines with their own suite, test, and keyword context while preserving the emitted JSON shape.
由索引模型根据 Issue 内容生成。
描述
Describe the bug
The Robot Framework context that every node-side log line is stamped with is a module-level singleton:
const currentRFContext: RFKeywordContext = {};
const _kwContextStack: Array<{ kw_name?: string; kw_file?: string; kw_line?: number }> = [];
node/playwright-wrapper/browser_logger.ts:41-42
The pino mixin() reads it on every log call:
mixin() {
const { kw_name, kw_file, kw_line, test_id, test_name, suite_id, suite_name } = currentRFContext;
return {
seq: ++_seq,
...(suite_id !== undefined && { suite_id }),
...(suite_name !== undefined && { suite_name }),
...
node/playwright-wrapper/browser_logger.ts:139-153
and setRFContext writes it:
export async function setRFContext(request: Request_RFContext): Promise<Response_Empty> {
setRFTestContext(request.testId, request.testName);
setRFSuiteContext(request.suiteId, request.suiteName);
return emptyWithLog('RF context updated');
}
node/playwright-wrapper/playwright-state.ts:999-1003
Every other piece of state in the node process is kept per gRPC peer — PlaywrightServer holds one PlaywrightState per connection (node/playwright-wrapper/grpc-service.ts:39-57). The logging context is now the exception; the only other one, highlightDisposableCache, was made per-peer in #5211.
That matters whenever several Robot Framework processes share one node process, which is what ROBOT_FRAMEWORK_BROWSER_NODE_PORT is for. This repository's own acceptance tests do exactly that: tasks.py:1078-1081 spawns one node process and exports the port into the environment every pabot worker inherits.
With one writer per worker and one global destination, last writer wins for every worker. A log line emitted while worker A is inside a long-running call is stamped with whatever worker B most recently set, so suite_name, test_name and suite_id name a suite that has nothing to do with the line.
_kwContextStack is worse than last-writer-wins: setRFKeywordContext pushes and clearRFKeywordContext pops a single shared stack (browser_logger.ts:44-93). With concurrent workers the pairs interleave, so one worker's clearRFKeywordContext can restore another worker's saved kw_name/kw_file/kw_line, or pop a frame that was never its own.
Observed behaviour
From the artifact of run 35185010944 (Test results-windows-latest-1-3.10-22.x), playwright-log.txt:
{"level":"error","time":"2026-09-17T05:23:53.051Z","seq":63,
"suite_id":"s1-s1-s1-s1-s1",
"suite_name":"Test.08 Scope Tests.Suite 1.Suite 1.1.Suite 1.1.1",
"test_name":"Test.08 Scope Tests.Suite 1.Suite 1.1.Suite 1.1.1.Test Scope Settings Override Global Defaults",
"component":"browser-library","event_kind":"grpc_error","status":"failed","error_type":"TimeoutError2",
"msg":"page.goto: Timeout 5000ms exceeded.\nCall log:\n - navigating to \"http://localhost:54763/error.html\", waiting until \"load\""}
The line is attributed to Test.08 Scope Tests. It does not belong to that suite. Port 54763 is another worker's test server, and its own log (test-app/test-app-54763.log in the same artifact) says who owns it:
{"timestamp":"2026-09-17T05:23:46.976Z","event":"start_suite","name":"Auto Closing","pid":6272}
output.xml from the same run confirms it: the failure with that message is the suite setup of
Test.01 Browser Management.Auto Closing.Auto Closing, at 05:23:53.057.
So the one log line that explains the failure names the wrong suite, the wrong test, and the wrong suite id. The same applies to the surrounding newBrowser/newPage lines of that worker.
Why it matters
playwright-log.txt is the file the library points users at whenever a keyword fails:
See also file:///.../playwright-log.txt for additional details.
When a node process is shared, the suite/test fields in that file are not reliable, and there is nothing in the file to say so. Reconstructing which worker produced a line currently means cross-referencing unrelated evidence — in the case above, the context default-timeout values (5000 vs 10000 vs 1000) and the per-port test app logs.
This is an observability defect, not a behavioural one: no keyword does the wrong thing because of it. It is being filed separately because it is blocking an unrelated CI flake investigation, and because anyone running parallel Robot Framework against a shared node process is reading the same misattributed log.
Expected behaviour
A log line produced while serving one session's gRPC call carries that session's suite_id, suite_name, test_id, test_name and keyword fields, regardless of what other sessions are doing at the same time.
Suggested fix
The two halves have different lifetimes and want different mechanisms:
- Suite/test context is durable per session. It is set by its own
SetRFContextcall and has to survive until the next one, so it belongs with the other per-peer state — onPlaywrightState, whichgrpc-service.tsalready keys per peer. - Keyword context is per call.
setRFKeywordContext/clearRFKeywordContextare a push/pop pair around a single invocation, which is whatAsyncLocalStorageis for. Using a store per gRPC call removes the shared stack and its cross-worker pops.
mixin() then reads the current store rather than a module global. The gRPC wrappers in grpc-service.ts (wrapping, wrappingState, wrappingPage, wrappingStatePage, wrappingDebug) are a single choke point where the store can be established, since they already resolve the peer's state.
Nothing above changes keyword behaviour or the shape of the emitted JSON; only which worker's values appear in the fields.
Environment
Browser 20.5.0, Playwright 1.63.0, Robot Framework 7.1.1, Python 3.10.11, Windows, chromium. Observed against main at b986d017. Not platform specific — it needs only a shared node process with more than one worker.
- 主要语言
- Python
- 星标
- 662
- 派生
- 149
- 平均合并
- 6 小时 9 分钟
- 30 天内合并 PR
- 119
环境准备
- 没有 Dockerfile 或 Docker Compose 文件
- 没有 Pull Request 模板
- 阅读贡献指南
从这里开始
- 先读完整个 Issue,再读项目的贡献指南。
- 在 Issue 下留言说明你要接手 —— 这能避免两个人做同样的事。
- Fork 仓库,在一个分支上完成修改。
- 提交 Pull Request,并在描述里引用这个 Issue 编号。
MarketSquare/robotframework-browser 的其他 Issue
-
priority: high
难度 2/5 1-3 小时 新手友好度 75/100
MarketSquare/robotframework-browser#5306 · 2 条评论 ·
维护者通常 1 天内回复
-
难度 2/5 1-3 小时 新手友好度 78/100
MarketSquare/robotframework-browser#5153 ·
维护者通常 1 天内回复
-
Record Keyword: allow calling the recorded keyword in the current test case可能已有人在做 关联的 PR 仍在进行中或已合并。 未关闭
难度 3/5 1-2 天 新手友好度 65/100
MarketSquare/robotframework-browser#5513 ·
维护者通常 1 天内回复
-
难度 4/5 3-5 天 新手友好度 48/100
MarketSquare/robotframework-browser#5503 ·
维护者通常 1 天内回复
-
难度 3/5 1-2 天 新手友好度 78/100
MarketSquare/robotframework-browser#5502 ·
维护者通常 1 天内回复
查看 MarketSquare/robotframework-browser 的全部 Issue
相似的 Issue
-
physical
难度 2/5 1-3 小时 新手友好度 74/100
antonyrag/ragleap-core#1339 ·
-
enhancement good first issue
难度 2/5 1-3 小时 新手友好度 83/100
AllenCell/SubCellSeg#5 ·
-
[🐛 Bug]: oidc_authverifier.py strips trailing slash causing "Invalid token: Invalid issuer" error未关闭
难度 2/5 1-3 小时 新手友好度 76/100
keephq/keep#6934 · 1 个 reaction ·
维护者通常 1 天内回复
-
bug game: 01008BA02525A000 ios
难度 2/5 1-3 小时 新手友好度 76/100
维护者通常 1 天内回复
-
needs-triage
难度 1/5 1 小时以内 新手友好度 87/100
gke-labs/kube-agents#5501 ·
维护者通常 1 天内回复