Skip to content

fix: count every PHP-FPM stage, stop panicking on a bad URI, report scrape failures - #24

Merged
dimoschi merged 3 commits into
masterfrom
fix/upstream-bug-sweep
Sep 13, 2026
Merged

dimoschi merged 3 commits into
masterfrom
fix/upstream-bug-sweep

Conversation

@dimoschi

@dimoschi dimoschi commented Sep 13, 2026 •

Copy link
Copy Markdown
Collaborator

Why this PR exists

You asked how so many bugs went unnoticed. Rather than keep surfacing them one at a time, this is the result of a deliberate sweep of phpfpm/, phpfpm/fcgi/, cmd/, internal/server/ and main.go.

Six defects. Five are inherited from upstream and untouched since the fork, and two have open upstream issues that have gone unexplained for years.

Fixes

1. Process accounting — hipages#322, hipages#419

CountProcessState put Finishing, Ending and Getting request information in empty switch cases. Go has no implicit fallthrough, so those processes counted as neither active nor idle and vanished from the total:

6 processes in: active=2 idle=1 total=3   (3 unaccounted for)

PHP-FPM treats a child as idle only while it is accepting and everything else as active. README.md already claimed this flag "will emulate PHP-FPMs implementation including the accumulation of multiple states" — the code simply did not do what its own docs said.

This is consistent with upstream hipages#322, "Why phpfpm_total_processes is a dynamically changing value", open since 2023 with no explanation: under load, processes cycle through the dropped stages and the total sags toward the active count. I can't confirm that reporter used --phpfpm.fix-process-count, so treat it as a strong match rather than a proven one.

The Creating stage was missing entirely — it is a documented stage in php-src sapi/fpm/fpm/fpm_request.c (verified against the requests_stages array), and it is the Unknown process state 'Creating' log spam in upstream hipages#419.

An unrecognised stage is still logged, but now counts as active, so a future PHP release cannot silently shrink the total again.

2. Panic on a malformed scrape URI

url.Parse returns a nil *url.URL alongside its error. parseURL dereferenced it in the error branch:

uri, err := url.Parse(rawurl)
if err != nil {
    return uri.Scheme, uri.Host, uri.Path, err   // uri is nil
}

A single bad --phpfpm.scrape-uri killed the process, and because it runs inside the scrape goroutine there was nothing to recover it. Introduced 2018-03-18 in upstream #23. Not reported upstream.

3. get exited 0 when every scrape failed

PoolManager.Update unconditionally returned nil, so get's log.Fatal("Could not update pool") was unreachable. It now returns the joined per-pool errors; get prints whatever it collected, then exits non-zero. Pool.error already logs each failure, so the redundant second log in the update goroutine is gone.

4. An invalid --log.level killed the process

log.Fatalf with a dead lvl = logrus.InfoLevel assignment directly above it, showing the intent was to fall back. An unusable log level is no reason to take a running exporter's metrics away.

5. Nil logger panic

The package logger was nil until SetLogger ran, so the first unrecognised process state panicked for library callers. It now defaults to a discarding logger, and SetLogger ignores nil.

6. initialPodEnlisting returned an always-nil error

Removed. This is the last outstanding unparam finding.

Behaviour changes

  • phpfpm_{active,idle,total}_processes values change under --phpfpm.fix-process-count. Totals go up, because processes that were being dropped are now counted. This is the point of the fix, but it will move graphs.
  • get now exits 1 if any target failed. Scripts that ignored the exit code are unaffected; scripts that checked it now get the truth.

Tests

Every fix has a test written failing first. Notably TestCountProcessStateCountsEveryReportedProcess asserts active + idle == total == len(processes) across all eight stages, which is the invariant that was broken.

Verification

$ mise exec -- go test ./... -race
ok  	github.com/hackthebox/php-fpm_exporter/internal/server
ok  	github.com/hackthebox/php-fpm_exporter/phpfpm
ok  	github.com/hackthebox/php-fpm_exporter/phpfpm/fcgi

Confirmed against the built binary: the malformed URI now logs an error instead of panicking, an invalid log level falls back, and get returns exit 1 on scrape failure and 0 otherwise.

golangci-lint (v2.12.2, as CI pins): 5 issues on master → 4 here, none new.

Known gap

The 8 remaining mutation survivors are all in cmd/ — the exit-code branch and the log-level fallback message — and are accepted on the same basis as the earlier batch: cmd is wiring and is untested by design. Moving get's body into internal/ is tracked in #25.

…crape failures

Six defects found in one sweep, five of them inherited from upstream and
untouched since the fork.

Process accounting (hipages#322, hipages#419). CountProcessState put
Finishing, Ending and Getting request information in empty switch cases, so they
counted as neither active nor idle and disappeared from the total: six processes
in, total=3 out. PHP-FPM itself treats a child as idle only while it is
accepting and everything else as active, which is also what README.md already
claimed this flag did. The Creating stage was missing entirely, which is the
'Unknown process state' log spam in hipages#419; it is a documented stage in php-src
sapi/fpm/fpm/fpm_request.c. An unrecognised stage is still logged but now counts
as active, so a future PHP release cannot silently shrink the total.

parseURL dereferenced the nil *url.URL that url.Parse returns alongside its
error. A malformed --phpfpm.scrape-uri therefore panicked, and since it runs in
the scrape goroutine it took the process with it. Present since 2018.

PoolManager.Update always returned nil, so get's 'Could not update pool' branch
was unreachable and the command exited 0 even when every target failed. It now
returns the joined per-pool errors, and get prints what it collected before
exiting non-zero. Pool.error already logs each failure, so the redundant second
log in the update goroutine is gone.

An invalid --log.level called Fatalf and killed the process, with a dead
fallback assignment directly above it showing the intent. It now warns and falls
back to info rather than taking a running exporter's metrics away.

The package logger was nil until SetLogger ran, so the first unrecognised
process state panicked for library callers. It defaults to discarding and
SetLogger ignores nil.

initialPodEnlisting returned an error that was always nil.
GitHub issues are disabled on this repo, so AGENTS.md is where a known follow-up
has to live. cmd/get.go still holds the output formatting logic that internal/
should own, which is why its mutation survivors had to be accepted rather than
covered.
Issues are enabled on the repo now, so the note can reference #25 rather than
standing in for a tracker.
@dimoschi
dimoschi merged commit 647bee3 into master Sep 13, 2026
7 checks passed
@dimoschi
dimoschi deleted the fix/upstream-bug-sweep branch September 13, 2026 20:34
dimoschi added a commit that referenced this pull request Sep 13, 2026
* refactor(get): move the get command's body out of cmd into internal/get

Closes #25.

cmd/get.go held the PoolManager construction and the json/text/spew output
switch inside a cobra Run closure, none of it reachable from a test. That is the
same shape server.go had before #20, and it is why the mutation survivors in #24
had to be accepted rather than covered.

internal/get exposes Run(cfg, w io.Writer) error, writing to an injected writer
so every format can be asserted. cmd/get.go is now a Config, a call, and an exit
code.

One behaviour change falls out of it: an unrecognised --out value is an error
rather than a logged message, so it exits non-zero instead of silently
succeeding with no output. Writing to stdout is also checked now, so a failed
write is reported rather than discarded.

* test(get): assert the rendered table, not just its labels

The first pass only checked that each label appeared, against a fixture whose
values were all zero, so dropping any single row was invisible. Each field now
carries a distinct value, and the blank separator between pools and the wrapping
of an overlong value are asserted too.

* test(get): pin the scrape timeout and the table's truncation

The configured ScrapeTimeout was not asserted, so dropping it and silently
falling back to the package default went unnoticed.

Writing the wrapping test also corrected an assumption: uitable elides an
overlong cell at MaxColWidth rather than wrapping it, so a scrape URI longer
than 80 characters is shown truncated. The test now documents that rather than
claiming the value is preserved.

Uses a generic pool name in the fixture.

* refactor: delete branches no test could reach, and stop logging failures twice

Following the principle that a mutation survivor no test can kill is either dead
code or a missing test, rather than something to accept.

The JSON encode error was unreachable: everything PoolManager marshals is a
string, int64, map or slice, and both custom MarshalJSON methods return a nil
error unconditionally. Encoding straight to the writer removes the branch and
leaves one error a caller can actually hit, the write.

uitable's Wrap had no effect: rendering the same table with it on and off is
byte-identical, because MaxColWidth elides the cell first. Deleted rather than
pinned. The width itself does matter and is now asserted through its effect, by
measuring the widest rendered cell, so an off-by-one either way fails.

Pool.error logged every scrape failure and so did collectPools, so the server
path emitted two lines per failure per scrape. That predates this branch; adding
the joined error to Update made it three. Pool.error now only records, leaving
the line that carries context.

The test logger was discarding Info, Debug and Error, which is why the first
attempt at this test passed against the very duplication it was meant to catch.

* test(get): assert the column cap against a literal, not the constant

The width assertion compared the measured cell against maxColWidth, so changing
the constant moved the expectation with it and the test could never fail. It now
compares against 80 directly, which is the contract a reader of the output
depends on.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant