Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 5 additions & 3 deletions apps/starry/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -142,11 +142,13 @@ packages in a staging root during prebuild, injects runtime artifacts to the
app overlay, then runs nginx smoke tests inside StarryOS.

```bash
cargo xtask starry app run -t nginx --arch x86_64
cargo xtask starry app qemu -t nginx --arch x86_64
```

`apps/starry/nginx` maintains four directories: `smoke`, `phase`, `stress`, and
`debug`. Currently only smoke is connected as nginx test entry in tgoskits workflows.
`apps/starry/nginx` keeps the CI-discovered smoke QEMU configs at the app root,
and keeps manual `all`/`phase`/`debug` QEMU configs under `qemu/`. The guest
entrypoint is `runner/nginx-runner.sh`; currently only smoke is connected as the
nginx test entry in tgoskits workflows.

## Orange Pi 5 Plus UVC

Expand Down
49 changes: 23 additions & 26 deletions apps/starry/nginx/README.md
Original file line number Diff line number Diff line change
@@ -1,38 +1,35 @@
# Starry Nginx App

This app organizes nginx tests into four directories:
Starry 下 nginx 应用的构建与测试入口。

- `smoke/`: CI entry smoke test (the only connected nginx test in tgoskits)
- `phase/`: stage-unit tests named by `x-x`, such as `nginx-1-3-lifecycle-tests.sh`
- `stress/`: pressure test planning and future scripts
- `debug/`: flexible issue-focused scripts
## 测试模式

## CI-Connected Entry
guest 内统一入口 `/usr/bin/nginx-runner.sh <mode>`:

Only smoke is connected:
| mode | 用途 | CI |
|------|------|----|
| `smoke` | 仅 smoke | ✅ 唯一接入上层 CI |
| `phase <id>` | 单阶段复测 | ❌ 手工 |
| `all` | smoke + 全部 phase(阶段强隔离) | ❌ 手工 |
| `stress` | 压测(当前 skip) | ❌ 手工 |
| `debug <name>` | 单问题调试 | ❌ 手工 |

```bash
cargo xtask starry app run -t nginx --arch riscv64
```

`qemu-*.toml` starts `/usr/bin/nginx-smoke-tests.sh` only.

## Local Development CLI
QEMU 入口按用途分目录:根 `qemu-<arch>.toml`(CI)、`qemu/all/`(手工全量)、
`qemu/phase/`(手工单阶段)、`qemu/debug/`(手工调试)。

Unified local CLI script:
## 用法

```bash
./apps/starry/nginx/nginx-cli-tests.sh smoke
./apps/starry/nginx/nginx-cli-tests.sh phase1
./apps/starry/nginx/nginx-cli-tests.sh phase2
./apps/starry/nginx/nginx-cli-tests.sh all
```

## Build/Prepare Logic
# CI smoke(四架构)
cargo xtask starry app qemu -t nginx --arch x86_64 \
--qemu-config apps/starry/nginx/qemu-x86_64.toml

`prebuild.sh` injects only smoke entry and shared mirror helper into guest overlay:
# 手工单阶段
cargo xtask starry app qemu -t nginx --arch x86_64 \
--qemu-config apps/starry/nginx/qemu/phase/qemu-x86_64-phase31.toml
```

- `/usr/bin/nginx-smoke-tests.sh`
- `/usr/bin/nginx-alpine-mirror.sh`
## 详细设计

Mirror helper: `apps/starry/nginx/nginx-alpine-mirror.sh`.
完整设计(目录结构、统一入口 marker 规则、all 模式阶段隔离契约、TOML 整合规则、
迁移步骤)见 [`www/nginx-ci-refactor-proposal.md`](../../../www/nginx-ci-refactor-proposal.md)。
10 changes: 10 additions & 0 deletions apps/starry/nginx/build-aarch64-unknown-none-softfloat.toml
Original file line number Diff line number Diff line change
@@ -0,0 +1,10 @@
target = "aarch64-unknown-none-softfloat"
log = "Warn"
features = [
"qemu",
"ax-driver/virtio-blk",
"ax-driver/virtio-net",
"ax-driver/virtio-gpu",
"ax-driver/virtio-input",
"ax-driver/virtio-socket",
]
14 changes: 14 additions & 0 deletions apps/starry/nginx/build-loongarch64-unknown-none-softfloat.toml
Original file line number Diff line number Diff line change
@@ -0,0 +1,14 @@
target = "loongarch64-unknown-none-softfloat"
axconfig_overrides = ["plat.phys-memory-size=0x8000_0000"]
log = "Warn"
features = [
"ax-hal/loongarch64-qemu-virt",
"qemu",
"ax-driver/plat-static",
"ax-driver/virtio-blk",
"ax-driver/virtio-net",
"ax-driver/virtio-gpu",
"ax-driver/virtio-input",
"ax-driver/virtio-socket",
]
plat_dyn = false
48 changes: 48 additions & 0 deletions apps/starry/nginx/debug/ISSUE-004-bad-method-probe-instability.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,48 @@
# ISSUE-004: BAD Method Probe Instability

## Status

- State: deferred (temporarily bypassed in phase2)
- Scope: `BAD / HTTP/1.1` verification path in stage 2
- Impact: does not block phase2 main flow

## Symptom

- In some runs, `busybox nc` returns an empty response (`<empty>`) for both:
- `BAD / HTTP/1.1`
- `GET / HTTP/1.1`
- This can make a strict raw-probe assertion fail even when nginx behavior is normal.

## Confirmed Observations

- `curl -X BAD http://127.0.0.1:8080/...` stably returns `405`.
- `nc.openbsd` raw BAD request stably returns `HTTP/1.1 405 Not Allowed`.
- `busybox nc` may return `<empty>` under the same request pattern.

## Current Decision

- Keep phase2 BAD-method node as bypass (known issue log only).
- Do not use `busybox nc` as pass/fail oracle for this node.
- Continue tracking through debug scripts:
- `nginx-2-0-bad-method-debug.sh`
- `nginx-2-0-bad-method-matrix.sh`

## Repro Commands

```bash
cargo xtask starry app qemu -t nginx --arch x86_64 --qemu-config apps/starry/nginx/qemu/debug/qemu-x86_64-bad-method-debug.toml
cargo xtask starry app qemu -t nginx --arch x86_64 --qemu-config apps/starry/nginx/qemu/debug/qemu-x86_64-bad-method-matrix.toml
```

Optional phase20 (HTTP basic) retest:

```bash
cargo xtask starry app qemu -t nginx --arch x86_64 --qemu-config apps/starry/nginx/qemu/phase/qemu-x86_64-phase20.toml
```

## Next Follow-up

- Add a minimal socket-level probe outside nginx to isolate whether this is:
- `busybox nc` behavior under StarryOS, or
- StarryOS socket timing/EOF behavior exposed by `busybox nc`.
- After root cause is confirmed and fixed, restore strict assertion for the phase2 BAD-method node.
119 changes: 119 additions & 0 deletions apps/starry/nginx/debug/ISSUE-005-x86-short-connection-timeout.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,119 @@
# ISSUE-005: x86 Short Connection Timeout

## Status

- State: investigating
- Scope: x86_64 Starry nginx phase31 short-connection loop
- Impact: can fail `nginx-runner.sh all` at `phase31` with `NGINX_PHASE31_TEST_FAILED`

## Symptom

- `phase31` runs many short HTTP connections against nginx on `127.0.0.1:8080`.
- On x86_64, the loop can exceed the per-probe or per-phase timeout budget.
- The terminal failure usually appears as:

```text
NGINX_RUNNER_PHASE_BEGIN phase=phase31
NGINX_PHASE31_TEST_FAILED
NGINX_PHASE31_LOG: 100 short connections
NGINX_RUNNER_PHASE_FAIL phase=phase31 rc=1
NGINX_RUNNER_FAILED phase=phase31
```

Older logs also showed:

```text
NGINX_PHASE31_LOG: watchdog timeout
Terminated
```

## Confirmed Observations

- riscv64 passed the same nginx phase path.
- x86_64 standalone `phase31` can fail, so the issue is not only cross-phase state from `all`.
- A focused short-connection debug run once failed around iteration 143 with `curl rc=7` and `connection refused` while nginx received `SIGTERM`.
- Raising the debug runner budget to 1800s made the timeout-wrapped short-connection debug pass 120 iterations.
- Running the same debug loop without per-request `timeout` also passed 120 iterations.
- The x86 loop is still very slow: `curl` reports tens of milliseconds of HTTP time, but the wall-clock loop averages several seconds per request.
- A timing microbench shows the slow path starts before nginx/socket handling:

| Bench | x86_64 | riscv64 |
| --- | ---: | ---: |
| shell arithmetic, 100 iters | 1s | 0s |
| shell builtin `:`, 100 iters | 1s | 0s |
| `/bin/true`, 100 iters | 32s | 10s |
| `/bin/busybox true`, 100 iters | 38s | 10s |
| `/bin/echo ok`, 100 iters | 36s | 15s |
| `/bin/sleep 0`, 100 iters | 30s | 19s |
| `/bin/date +%s`, 20 iters | 9s | 2s |
| `/bin/sleep 1`, 5 iters | 6s | 5s |
| `timeout 5 /bin/true`, 100 iters | 63s | 23s |
| direct nginx `curl`, 40 iters | 91s | 31s |
| `timeout 10 curl`, 40 iters | 106s | 34s |

- `sleep 1` is roughly correct, so the primary issue is not a simple timer-frequency error.
- Shell builtins are fast, while every external command has high fixed cost, so the primary issue is likely in x86 process launch/exec/exit/wait or user/kernel transition overhead.
- `timeout` adds another external process and timer/signal layer, which makes the phase31 `timeout curl` loop more vulnerable.

## Current Hypothesis

- The HTTP request itself is not the main cost.
- The x86_64 path spends excessive wall time in short-lived external command handling.
- The current strongest suspects are x86 `execve` page-table work, x86 user/kernel transition overhead, and vfork/exec/wait scheduling latency.
- The original `timeout 5 curl ...` assertion is therefore close to the x86 timing cliff and can fail nondeterministically.

## Debugging Work So Far

- Reproduced the original failure shape from `phase31`: `NGINX_PHASE31_TEST_FAILED` followed by `NGINX_RUNNER_FAILED phase=phase31`.
- Verified that standalone x86_64 `phase31` can fail, so the issue is not only caused by earlier phases in `all`.
- Added `nginx-3-1-short-connection-debug.sh` to run the same short-connection pattern with per-iteration curl status, stderr, nginx process state, socket state, and log tails.
- The first timeout-wrapped debug run failed around iteration 143 with `curl rc=7` and `connection refused`; nginx had received `SIGTERM`, which matched the runner/default watchdog budget expiring rather than a stable nginx accept failure.
- Raised the debug runner budget to 1800s and confirmed timeout-wrapped short connections can complete 120 iterations on x86_64.
- Disabled per-request `timeout` in a direct debug run and confirmed 120 iterations also pass, but still take several hundred seconds.
- Added `nginx-3-1-x86-timing-debug.sh` to split shell-only work from external-command, timeout, and curl loops.
- Added a riscv64 timing-debug QEMU config and ran the same timing script as an architecture baseline.

## Phase Workaround

- `apps/starry/nginx/phase/nginx-3-1-short-connection-tests.sh` keeps the same HTTP assertion: 100 independent `curl -fsS` short connections must succeed.
- The per-curl wall-clock timeout was raised from 5s to 15s through `SHORT_CONN_CURL_TIMEOUT`.
- This does not weaken the response correctness check; it only avoids treating the current x86 external-command overhead as an nginx failure.
- The runner phase budget remains the outer bound. The measured x86 timing debug still fits well below the standalone phase budget after this per-operation relaxation.

## Code Pointers

- `os/StarryOS/kernel/src/syscall/task/clone.rs`: `CloneArgs::do_clone`, vfork setup and parent wait.
- `os/StarryOS/kernel/src/syscall/task/execve.rs`: `do_execve`, per-exec address-space creation, ELF load, and page-table switch.
- `os/StarryOS/kernel/src/task/mod.rs`: `ProcessData::wait_vfork_done` / `notify_vfork_done`.
- `components/axcpu/src/x86_64/uspace.rs`: x86 user context entry/exit and per-run FS/GS MSR handling.
- `components/axcpu/src/x86_64/trap.S`: `enter_user` syscall/iret return path.
- `components/axcpu/src/x86_64/context.rs`: task context switch and user page-table switch.

## Suspicious Implementation Details

- `execve` creates and installs a fresh address space for every external command. On x86_64 this includes kernel mapping copy, CR3 switch, and TLB effects that shell builtins avoid.
- x86 user entry/exit does FS/GS MSR handling around `UserContext::run()`. Short-lived commands execute many syscall/user-return cycles during dynamic loader startup and process exit.
- Fresh x86 `UserContext::new()` after `execve` may initially return through the `iretq` path instead of the faster syscall-return path.
- BusyBox shell likely uses `vfork`/`CLONE_VFORK` for external commands. The parent blocks in `ProcessData::wait_vfork_done()` until the child execs or exits, so scheduling or wakeup latency is paid once per command.
- `timeout curl` adds another external process plus timer/signal/wait behavior, which explains why it is significantly slower than direct `curl` and why phase31 is sensitive to a 5s per-operation deadline.

## Debug Scripts

- `nginx-3-1-short-connection-debug.sh`: nginx short-connection reproduction with detailed curl/nginx/socket logs.
- `nginx-3-1-x86-timing-debug.sh`: microbench to compare shell loop, `/bin/true`, `timeout true`, direct curl, and timeout-wrapped curl.

## Repro Commands

```bash
cargo xtask starry app qemu -t nginx --arch x86_64 --qemu-config apps/starry/nginx/qemu/debug/qemu-x86_64-short-connection-debug.toml
cargo xtask starry app qemu -t nginx --arch x86_64 --qemu-config apps/starry/nginx/qemu/debug/qemu-x86_64-short-connection-direct-debug.toml
cargo xtask starry app qemu -t nginx --arch x86_64 --qemu-config apps/starry/nginx/qemu/debug/qemu-x86_64-timing-debug.toml
cargo xtask starry app qemu -t nginx --arch riscv64 --qemu-config apps/starry/nginx/qemu/debug/qemu-riscv64-timing-debug.toml
```

## Next Follow-up

- The bottleneck appears before networking: inspect x86 short-lived process execution first.
- Compare `execve` page-table switching costs on x86, especially CR3/TLB work in `components/axcpu/src/x86_64/context.rs` and address-space replacement in `do_execve`.
- Inspect x86 user/kernel round-trip overhead in `components/axcpu/src/x86_64/uspace.rs` and `components/axcpu/src/x86_64/trap.S`.
- Inspect vfork/exec/wait wakeup latency in `CloneArgs::do_clone`, `ProcessData::wait_vfork_done`, `notify_vfork_done`, and `sys_waitpid`.
7 changes: 6 additions & 1 deletion apps/starry/nginx/debug/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -5,8 +5,13 @@ This directory stores flexible debug scripts for single issue reproduction and d
Current scripts:

- `nginx-http-basic-tests.sh`: early HTTP basic script kept for issue-level debugging.
- `nginx-2-0-bad-method-debug.sh`: focused probe for stage 2.0 BAD method (`BAD / HTTP/1.1`) instability.
- `nginx-3-1-short-connection-debug.sh`: focused reproduction for phase31 short-connection timeout behavior.
- `nginx-3-1-x86-timing-debug.sh`: x86_64 timing microbench for process, timeout, and curl loops.

Rule:

- Debug scripts are free-form and can focus on one syscall or one behavior path.
- Debug scripts are not connected to tgoskits nginx CI entry.
- Debug scripts are not auto-discovered by tgoskits nginx CI. Run them manually through
`cargo xtask starry app qemu -t nginx --arch <arch> --qemu-config apps/starry/nginx/qemu/debug/<config>.toml`,
which enters the guest via `/usr/bin/nginx-runner.sh debug <name>`.
110 changes: 110 additions & 0 deletions apps/starry/nginx/debug/nginx-2-0-bad-method-debug.sh
Original file line number Diff line number Diff line change
@@ -0,0 +1,110 @@
#!/bin/sh
set -eu

BASE=/tmp/nginx-phase2-bad-method
CONF="$BASE/conf/http-basic.conf"
WWW="$BASE/www"
OUT="$BASE/out"
LOGDIR="$BASE/logs"
TIMEOUT_CMD=

log() { printf 'NGINX_BAD_METHOD_DEBUG_LOG: %s\n' "$*"; }
fail() { printf 'NGINX_BAD_METHOD_DEBUG_FAILED\n'; log "$*"; exit 1; }

init_timeout_cmd() {
if command -v timeout >/dev/null 2>&1; then TIMEOUT_CMD='timeout'; return; fi
if busybox timeout 2>&1 | grep -qi 'usage'; then TIMEOUT_CMD='busybox timeout'; return; fi
fail "timeout command not available"
}

run_with_timeout() { sec=$1; shift; $TIMEOUT_CMD "$sec" "$@"; }

cleanup_nginx() {
killall -q nginx 2>/dev/null || true
sleep 1
killall -q -9 nginx 2>/dev/null || true
}

prepare_packages() {
repo_file=/etc/apk/repositories
original_repos="$(cat "$repo_file")"
for mirror in https://mirrors.cernet.edu.cn/alpine https://dl-cdn.alpinelinux.org/alpine; do
printf '%s\n' "$original_repos" | sed "s#http://[^/]*/alpine/#$mirror/#g;s#https://[^/]*/alpine/#$mirror/#g" > "$repo_file"
rm -f /lib/apk/db/lock
if run_with_timeout 40 apk --timeout 40 update && run_with_timeout 40 apk --timeout 40 add nginx curl busybox-extras; then return 0; fi
done
return 1
}

prepare_tree() {
rm -rf "$BASE"
mkdir -p "$BASE/conf" "$WWW" "$LOGDIR" "$OUT"
printf 'BAD_METHOD_DEBUG_OK\n' > "$WWW/index.html"
cat > "$CONF" <<'EOF'
daemon off;
master_process off;
worker_processes 1;
error_log /tmp/nginx-phase2-bad-method/logs/error.log debug;
pid /tmp/nginx-phase2-bad-method/nginx.pid;
events { worker_connections 64; }
http { include /etc/nginx/mime.types; access_log /tmp/nginx-phase2-bad-method/logs/access.log; server { listen 127.0.0.1:8080; root /tmp/nginx-phase2-bad-method/www; location / { index index.html; } } }
EOF
}

start_nginx() {
nginx -t -c "$CONF" -p "$BASE/" || return 1
nginx -c "$CONF" -p "$BASE/" > "$LOGDIR/nginx-stdout.log" 2>&1 &
i=0
while [ "$i" -lt 6 ]; do
run_with_timeout 5 curl -fsS -o /dev/null http://127.0.0.1:8080/ >/dev/null 2>&1 && return 0
i=$((i + 1))
sleep 1
done
return 1
}

probe_bad_method() {
if command -v nc >/dev/null 2>&1; then
NC='nc'
elif busybox nc 2>&1 | grep -qi 'usage'; then
NC='busybox nc'
else
fail "nc not available"
fi
code=$(run_with_timeout 3 curl -sS -o /dev/null -w '%{http_code}' -X BAD http://127.0.0.1:8080/ || true)
[ -n "$code" ] || code='<empty>'
log "curl_bad_method_status=$code"

i=1
while [ "$i" -le 5 ]; do
out="$OUT/bad-$i.raw"
{ printf 'BAD / HTTP/1.1\r\nHost: localhost\r\nConnection: close\r\n\r\n'; } | run_with_timeout 4 sh -c "$NC 127.0.0.1 8080" > "$out" || true
tr -d '\r' < "$out" > "$OUT/bad-$i.norm"
status=$(sed -n '1p' "$OUT/bad-$i.norm" || true)
[ -n "$status" ] || status='<empty>'
log "probe=$i status=$status"
i=$((i + 1))
done
if grep -Eq '^HTTP/1.1 (400|405)' "$OUT"/bad-*.norm; then
printf 'NGINX_BAD_METHOD_DEBUG_PASSED\n'
return 0
fi
log "no 400/405 hit in 5 probes"
return 1
}

init_timeout_cmd
trap cleanup_nginx EXIT INT TERM
prepare_packages || fail "prepare packages"
prepare_tree || fail "prepare tree"
start_nginx || fail "start nginx"
probe_bad_method || {
if [ -f "$LOGDIR/error.log" ]; then
tail_line=$(sed -n '$p' "$LOGDIR/error.log" || true)
[ -n "$tail_line" ] || tail_line='<empty>'
log "error_log_tail=$tail_line"
fi
cleanup_nginx
fail "bad method probes"
}
cleanup_nginx
Loading