Skip to content

test(error-log-logger): don't assert a fixed JSON key order for the broker list#13703

Open
nic-6443 wants to merge 1 commit into
apache:masterfrom
nic-6443:fix/error-log-logger-kafka-key-order
Open

test(error-log-logger): don't assert a fixed JSON key order for the broker list#13703
nic-6443 wants to merge 1 commit into
apache:masterfrom
nic-6443:fix/error-log-logger-kafka-key-order

Conversation

@nic-6443

Copy link
Copy Markdown
Member

Description

t/plugin/error-log-logger-kafka.t TEST 10 fails intermittently, for example in this run:

Failed test 't/plugin/error-log-logger-kafka.t TEST 10: put metadata with kafka tls and log an
error message - send via TLS - pattern "(?^:sending a batch logs to kafka brokers:
\[\{"host":"127.0.0.1","port":9093\}\])" should match a line in error.log (req 0)'

This is not a timing problem. The block asserts the broker list against a literal string:

qr/sending a batch logs to kafka brokers: \[\{"host":"127.0.0.1","port":9093\}\]/

but the plugin produces it with core.json.delay_encode(config.kafka.brokers) (apisix/plugins/error-log-logger.lua:391), and cjson serialises a Lua table in hash order. That order is not stable between runs, so the encoder sometimes emits the keys the other way round and the pattern misses a line that is present.

Running the block 12 times shows both encodings:

9x  [{"host":"127.0.0.1","port":9093}]   -> matches the pattern, passes
3x  [{"port":9093,"host":"127.0.0.1"}]   -> does not match, fails

The giveaway in a failing run is that the later message matches while the batch line does not, which cannot happen if the line were merely late:

ok 3 - ... pattern "(?^:send data to kafka: .*this is a error message for tls test)" matches a line
not ok 4 - ... pattern "(?^:sending a batch logs to kafka brokers: \[\{"host":"127.0.0.1","port":9093\}\])"

Change

Match the host and the port as two independent patterns, so the assertion holds whatever order the encoder picks and still checks both values. This follows the same order-tolerant style already used in TEST 2 of this file (qr/broker_config is: \{.*"refresh_interval":1000/).

How this was verified

Against a local kafka with the TLS listener from #13607, running the block in isolation:

  • before the change: 12 runs, the 3 that encoded port-first failed, the 9 that encoded host-first passed;
  • after the change: 14 runs, all passed, including 3 that encoded port-first.

Raising --- wait does not fix this — I tried it, and a run still failed with the batch line flushed 1s after the error was logged, well inside the window.

Checklist

  • I have explained the need for this PR and the problem it solves
  • I have explained the changes or the new features added to this PR
  • I have added tests corresponding to this change
  • I have updated the documentation to reflect this change
  • I have verified that this change is backward compatible

…roker list

TEST 10 matches the broker list the plugin logs against a literal
`[{"host":"127.0.0.1","port":9093}]`. The plugin builds that string with
`core.json.delay_encode(config.kafka.brokers)`, and cjson serialises a Lua
table in hash order, which is not stable across runs. When the encoder emits
`[{"port":9093,"host":"127.0.0.1"}]` instead, the pattern misses and the
block fails.

Match the host and the port as two independent patterns so the assertion
holds whatever order the encoder picks, without weakening what it checks.

Observed over 12 runs of the block before the change: 9 runs encoded
host-first and passed, 3 encoded port-first and failed. With the change, 14
runs pass, 3 of which encoded port-first.
@dosubot dosubot Bot added size:XS This PR changes 0-9 lines, ignoring generated files. bug Something isn't working labels Jul 17, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

bug Something isn't working size:XS This PR changes 0-9 lines, ignoring generated files.

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants