From d89903406c332fa33759554aa436195511749ef4 Mon Sep 17 00:00:00 2001 From: Wu Sheng Date: Sat, 1 Aug 2026 23:46:00 +0800 Subject: [PATCH] chore(test): upgrade the mock collector and drop the seed workaround The pinned mock-collector image dated from October 2022, 13 commits behind the tool's master. Move it to c6b91a0e, which carries the fix for the first-insert race in SegmentItems/LogItems (apache/skywalking-agent-test-tool#65): when two processes reported their first segment for the same service name concurrently, the collector silently dropped one while both reporters got HTTP 200. sw_fork_support worked around that race by seeding the service name with a parent-only /ping request and waiting for the collector to register it before triggering the concurrent parent/child reports. The collector no longer needs the help, so the endpoint, the seed step and the extra expected segment are gone and the test is back to asserting exactly the cross-fork trace it is about. The upgrade also picks up the validator changes made since 2022, one of which affected us. LogAssert now sorts both the expected and the actual logs by their body text before comparing them pairwise (apache/skywalking-agent-test-tool#59), and the sort uses the raw expected string, so a matcher such as `text: not null` participates as the literal "not null". sw_loguru matches its two logging-module records that way while the records themselves led with the default layout's timestamp, so they sorted first and their placeholders last, inverting the pairing. Pin a layout that leads with the logger name, which sorts after the placeholders and orders the two records deterministically, and reorder the expected entries to match; SWFormatter is still exercised. Its expected.data.yml is the only one in the tree with a non-empty logItems block, so no other test is affected. Also refresh CLAUDE.md: supported Python and grpcio floor, the current plugin list, the agent's fork/prefork lifecycle, and the plugin-test validation notes. --- CLAUDE.md | 53 ++++++++++++++++--- .../plugin/data/sw_loguru/docker-compose.yml | 6 +++ tests/plugin/data/sw_loguru/expected.data.yml | 19 ++++--- tests/plugin/docker-compose.base.yml | 2 +- .../web/sw_fork_support/expected.data.yml | 21 +------- .../web/sw_fork_support/services/app.py | 8 --- .../web/sw_fork_support/test_fork_support.py | 19 +------ 7 files changed, 67 insertions(+), 61 deletions(-) diff --git a/CLAUDE.md b/CLAUDE.md index 62884252..d47cce23 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -38,9 +38,10 @@ tools/ ## Python Version Support -- **Current (master):** Python 3.8 - 3.11 (tested in CI), declared >=3.8 <=3.13 -- **In-progress (PR #374):** Dropping 3.8, adding 3.12 + 3.13 to CI matrix -- **Upcoming:** Python 3.14 support needed +- Declared `>=3.10, <3.15`; CI runs the plugin/unit matrix on Python 3.10 - 3.14. +- The agent requires `grpcio >= 1.83`. The generated protobuf stubs refuse an older grpcio + at import (`GRPC_GENERATED_VERSION`), so the codegen `grpcio-tools` in the Makefile is + pinned in lockstep — bumping it raises the runtime floor for every user. ## Build & Development @@ -72,6 +73,32 @@ Plugin-specific settings (all via `SW_` env vars): Filter functions: `config.ignore_http_method_check(method)`, `config.ignore_grpc_method_check(method)` +## Agent Lifecycle & Fork Support + +`SkyWalkingAgent` (skywalking/agent/__init__.py) has two entry points: + +- `start()` — full agent: `config.finalize()` (once per lineage; `finalize_name` is NOT + idempotent), `log.install()` + `plugins.install()`, then `__bootstrap()` creates the queues, + the protocol client (the gRPC channel lives here) and the reporter threads. +- `start_prefork_master()` — instrumentation only: everything above EXCEPT queues, protocol + and threads. Used for the Gunicorn master. + +**Never create a gRPC channel before `fork()`.** With grpcio >= 1.80 a channel that survives +`fork()` produces `Kick Failure` stderr spam and can silently deadlock the child inside gRPC's +own at-fork handlers (grpc/grpc#43055, apache/skywalking#13958). So: + +- Gunicorn (`sw-python run -p gunicorn`): master instruments only, each forked worker runs the + full agent via the `os.register_at_fork(after_in_child=...)` hook. The master is not a + service instance. uWSGI has always worked this way, via its `@postfork` hook. +- `SW_AGENT_ASYNCIO_ENHANCEMENT` has no fork support at all and is rejected under `-p`. +- Explicit `os.fork()` over gRPC is unreliable regardless (reporters enter gRPC independently + of requests) — document HTTP/Kafka for forking apps. + +`agent.started()` reports whether reporting is live in this process. It is False in a prefork +master, where `is_segment_queue_full()` returns True so span creation short-circuits to +`NoopSpan` and `archive_*` drop — otherwise instrumented code running at `--preload` import +time would hit uninitialized queues. + ## Context & Carrier API Details ### get_context() Signatures @@ -281,6 +308,8 @@ class TestPlugin(TestPluginBase): - Services install the plugin lib via `pip install -r /app/requirements.txt` - Use `sw-python run python3 /app/services/provider.py` to start with agent - External services (Redis, Kafka, etc.) added as needed with healthchecks +- The mock collector is pinned by image SHA in `docker-compose.base.yml`. Bumping it also + pulls in validator changes — verify the whole plugin matrix on CI, not just one test. ### Expected Data Format (expected.data.yml) @@ -306,7 +335,17 @@ segmentItems: skipAnalysis: false ``` -Validation operators: `not null`, `gt 0`, exact string match. +Validation operators: `not null`, `gt 0`, `start with`, `end with`, exact string match. + +Validation notes: +- Segments and spans are matched by content, and the expected `segmentSize` / span count must + match exactly; only services named in the expected file are checked. +- `logItems` entries are ORDER-SIGNIFICANT: the collector sorts expected and actual logs by + their raw body text before comparing pairwise, so a `text: not null` placeholder sorts as + the literal string `"not null"`. See `sw_loguru`, which pins a log layout to keep the + ordering deterministic — it is the only test asserting `logItems`. +- `prepare()` fixtures should call `.raise_for_status()`; otherwise an HTTP error passes the + fixture silently and surfaces later as a confusing empty-data diff. ### Running Tests @@ -334,10 +373,10 @@ poetry run pytest -v $(bash tests/gather_test_paths.sh) 7. Run `make doc-gen` to regenerate Plugins.md 8. Verify with `make lint` -## All 35 Plugins +## All 38 Plugins -Web: sw_flask, sw_django, sw_fastapi, sw_sanic, sw_tornado, sw_bottle, sw_pyramid, sw_falcon -HTTP: sw_requests, sw_urllib3, sw_urllib_request, sw_aiohttp, sw_httpx, sw_http_server +Web: sw_flask, sw_django, sw_fastapi, sw_sanic, sw_sanic_v2, sw_tornado, sw_bottle, sw_pyramid, sw_falcon, sw_falcon_v3 +HTTP: sw_requests, sw_urllib3, sw_urllib3_v2, sw_urllib_request, sw_aiohttp, sw_httpx, sw_http_server Database: sw_pymysql, sw_mysqlclient, sw_psycopg, sw_psycopg2, sw_pymongo, sw_elasticsearch, sw_happybase, sw_neo4j, sw_asyncpg Cache: sw_redis, sw_aioredis MQ: sw_kafka, sw_rabbitmq, sw_celery, sw_pulsar, sw_confluent_kafka, sw_aiormq, sw_amqp diff --git a/tests/plugin/data/sw_loguru/docker-compose.yml b/tests/plugin/data/sw_loguru/docker-compose.yml index 1ab330a6..ab45d8c9 100644 --- a/tests/plugin/data/sw_loguru/docker-compose.yml +++ b/tests/plugin/data/sw_loguru/docker-compose.yml @@ -44,6 +44,12 @@ services: SW_AGENT_NAME: provider SW_AGENT_LOGGING_LEVEL: DEBUG SW_AGENT_LOG_REPORTER_LEVEL: INFO + # The collector sorts expected and actual logs by their body text before comparing + # them pairwise, so the reported text must order deterministically. The default + # layout leads with the timestamp, which sorts the `logging` records ahead of the + # loguru ones and ahead of the `not null` placeholders they are matched by; leading + # with the logger name keeps them last and stable. See expected.data.yml. + SW_AGENT_LOG_REPORTER_LAYOUT: '%(name)s [%(threadName)s] %(levelname)s - %(message)s' consumer: extends: diff --git a/tests/plugin/data/sw_loguru/expected.data.yml b/tests/plugin/data/sw_loguru/expected.data.yml index afc8d0a5..fc5d7507 100644 --- a/tests/plugin/data/sw_loguru/expected.data.yml +++ b/tests/plugin/data/sw_loguru/expected.data.yml @@ -15,6 +15,11 @@ # limitations under the License. # +# The collector sorts expected and actual logs by their body text and then compares them +# pairwise, so the order here is significant. The two loguru records sort by their literal +# text; the two `logging` records are matched by `text: not null`, which sorts after them, +# and among themselves they follow the order the collector sees - CRITICAL before ERROR, +# given the log layout pinned in docker-compose.yml. logItems: - serviceName: provider logSize: 4 @@ -46,7 +51,7 @@ logItems: body: type: 'text' content: - text: not null + text: 'Loguru provider warning reported.' traceContext: traceId: not null traceSegmentId: not null @@ -54,9 +59,9 @@ logItems: tags: data: - key: level - value: ERROR + value: WARNING - key: logger - value: not null + value: loguru - key: thread value: not null layer: '' @@ -66,7 +71,7 @@ logItems: body: type: 'text' content: - text: 'Loguru provider warning reported.' + text: not null traceContext: traceId: not null traceSegmentId: not null @@ -74,9 +79,9 @@ logItems: tags: data: - key: level - value: WARNING + value: CRITICAL - key: logger - value: loguru + value: not null - key: thread value: not null layer: '' @@ -94,7 +99,7 @@ logItems: tags: data: - key: level - value: CRITICAL + value: ERROR - key: logger value: not null - key: thread diff --git a/tests/plugin/docker-compose.base.yml b/tests/plugin/docker-compose.base.yml index 2ae89506..5798bbcf 100644 --- a/tests/plugin/docker-compose.base.yml +++ b/tests/plugin/docker-compose.base.yml @@ -20,7 +20,7 @@ version: '2.1' services: collector: - image: ghcr.io/apache/skywalking-agent-test-tool/mock-collector:7f20775e0631356c4823d9372b09d653db0e6540 + image: ghcr.io/apache/skywalking-agent-test-tool/mock-collector:c6b91a0eaef16d427268e9806d5df65949e2a9bf ports: - 19876:19876 - 12800:12800 diff --git a/tests/plugin/web/sw_fork_support/expected.data.yml b/tests/plugin/web/sw_fork_support/expected.data.yml index 6608c16a..29e8b48d 100644 --- a/tests/plugin/web/sw_fork_support/expected.data.yml +++ b/tests/plugin/web/sw_fork_support/expected.data.yml @@ -17,27 +17,8 @@ segmentItems: - serviceName: provider - segmentSize: 3 + segmentSize: 2 segments: - - segmentId: not null - spans: - - operationName: /ping - parentSpanId: -1 - spanId: 0 - spanLayer: Http - tags: - - key: http.method - value: GET - - key: http.url - value: http://0.0.0.0:9090/ping - - key: http.status_code - value: '200' - startTime: gt 0 - endTime: gt 0 - componentId: 7001 - spanType: Entry - peer: not null - skipAnalysis: false - segmentId: not null spans: - operationName: /users diff --git a/tests/plugin/web/sw_fork_support/services/app.py b/tests/plugin/web/sw_fork_support/services/app.py index 17d023b6..7a80d26a 100644 --- a/tests/plugin/web/sw_fork_support/services/app.py +++ b/tests/plugin/web/sw_fork_support/services/app.py @@ -50,14 +50,6 @@ def users(): frontend = Flask('frontend') - # readiness/warm-up endpoint: its segment arrives alone and seeds the service name - # in the mock collector, whose first-insert for a service is not concurrency-safe - # (SegmentItems.addSegmentItem check-then-act) — the parent and child later report - # their /users segments concurrently under the same service name - @frontend.route('/ping', methods=['GET']) - def ping(): - return jsonify({'song': 'Despacito'}) - @frontend.route('/users', methods=['GET']) def call_backend(): res = requests.get('http://127.0.0.1:9091/users', timeout=5) diff --git a/tests/plugin/web/sw_fork_support/test_fork_support.py b/tests/plugin/web/sw_fork_support/test_fork_support.py index b246c94f..9a4d18a6 100644 --- a/tests/plugin/web/sw_fork_support/test_fork_support.py +++ b/tests/plugin/web/sw_fork_support/test_fork_support.py @@ -14,7 +14,6 @@ # See the License for the specific language governing permissions and # limitations under the License. # -import time from typing import Callable import pytest @@ -26,10 +25,7 @@ @pytest.fixture def prepare(): # type: () -> Callable - # /ping (parent-only) also seeds the service name in the mock collector before the - # parent and child post their /users segments concurrently: the collector's very first - # insert for a service name is not concurrency-safe and can silently drop one segment - return lambda *_: requests.get('http://0.0.0.0:9090/ping', timeout=5).raise_for_status() + return lambda *_: requests.get('http://0.0.0.0:9090/users', timeout=5).raise_for_status() class TestPlugin(TestPluginBase): @@ -44,19 +40,6 @@ class TestPlugin(TestPluginBase): @pytest.mark.parametrize('version', ['grpcio>=1.83']) def test_plugin(self, docker_compose, version): - # the /ping seed segment must be REGISTERED by the collector before /users makes - # the parent and child report concurrently, otherwise all three segments can be - # in flight together and the collector's first-insert race still drops one - for _ in range(30): - if '/ping' in requests.get('http://localhost:12800/receiveData', timeout=5).text: - break - time.sleep(1) - else: - raise Exception('the /ping seed segment never reached the collector') - - response = requests.get('http://0.0.0.0:9090/users', timeout=5) - assert response.status_code == 200 - self.validate() stdout, stderr = docker_compose.get_logs()