Skip to content

Healthy fresh install logs ~178 "Migration failed" lines while all 53 migrations succeed #285

Description

@sarahmccuan

Low priority / cosmetic — nothing is actually broken. Filing because the log output is misleading enough to cost real time when diagnosing a genuine migration failure.

Describe the bug

A completely healthy fresh install writes ~178 Migration failed: lines to the PHP error log, while every one of the 53 migrations is recorded as applied:

$ docker logs lwt 2>&1 | grep -c "Migration failed:"
178

mysql> SELECT status, COUNT(*) FROM _migrations GROUP BY status;
applied  53          -- zero failed

Breakdown of those 178 lines:

Count Message Why it is expected
170 Table 'x' doesn't exist SQL 1146, on HARMLESS_SQL_ERRORS
7 Failed to add the foreign key constraint resolved by the runner's own second pass
1 Duplicate column name 'UsRecoveryCodeHash' SQL 1060, on HARMLESS_SQL_ERRORS

The 170 all name legacy pre-rename tables — archivedtexts, tags2, wordtags, texttags, textitems2, newsfeeds, feedlinks, temptextitems. db/schema/baseline.sql creates those under their modern names, so a fresh install never has the old ones and the legacy migrations that rename them fail by design.

Cause

Migrations::runMigrationFile() logs unconditionally, before the failure is classified:

// Migrations.php:722
error_log("Migration failed: $filename - " . $e->getMessage());
if ($firstError === null && !self::isHarmlessFailure($e)) {
    $firstError = $e->getMessage();
}

Only the classification is filtered; the log line fires for every failing statement, harmless or not. The wording is also identical in both cases, so "expected on a fresh install" and "your schema is broken" are indistinguishable in the log.

Why it matters despite being cosmetic

This directly obscured #275. On that install 8 statements genuinely failed (errno 150, errno 194, Got error 41 from storage engine InnoDB) and were buried among ~170 identical-looking harmless ones. Worse, the real cause was in the MariaDB container's log, while these lines go to the web container's log, with nothing correlating them.

Suggested

Move the log inside the classification and distinguish the two: harmless statement failures at debug level (or silent), genuine ones logged as errors. The HARMLESS_SQL_ERRORS check already exists — it just runs after the logging rather than gating it.

Related, and not cosmetic

While reading this code I noticed the failed-migration retry can never fire on a fresh install, which seems worth separate attention:

// Migrations.php:933-941
$newMigrations = array_diff($allMigrations, self::getRecordedMigrations());
$retryMigrations = [];
if (count($newMigrations) > 0) {
    $retryMigrations = array_intersect(self::getRetryableMigrations(), $allMigrations);
}

getRecordedMigrations() returns every filename with a row regardless of status. On a fresh install, run 1 records all 53; on run 2 $newMigrations is therefore empty, the if never entered, and $retryMigrations stays empty. MAX_ATTEMPTS = 3 is never reached — attempts stays at 1 forever. Retry-on-upgrade appears intentional per the docblock, but the effect is that a fresh install that fails stays broken until a later release happens to add a migration file.

Server

  • LWT 3.4.2-fork (v003004002)
  • PHP 8.4.24, MariaDB 12.1.2, Apache 2.4.68 (Debian), Docker on Windows

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't workingdatabaseDatabase-related issues

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions