後端容器啟動失敗：四個連環 Bug 的診斷與修復

分類： Bug Fix、Go、Azure App Service、golang-migrate
對象： 任何將 Go 後端部署至 Azure Web App for Containers 的開發者

背景

將 Go 後端容器成功推送至 Container Registry 並部署至 Azure Web App 後，雖然映像已可正常拉取，容器卻在啟動階段反覆 crash。從 Log stream 可看到四個連環錯誤，每修一個就出現下一個。本文逐一記錄症狀、根本原因與修復方式。

Bug 1 — 資料庫連線失敗：Login failed for user ''

症狀

{"level":"fatal","msg":"Failed to run database migration",
 "error":"failed to open database: mssql: login error: Login failed for user ''."}

容器一啟動就立即退出，完全沒有執行任何 migration。

根本原因

DATABASE_URL 中設定了 fedauth=ActiveDirectoryMSI，預期使用 Azure AD Managed Identity 認證，但 main.go 中匯入的是基礎 driver：

import _ "github.com/microsoft/go-mssqldb"

這個 driver 只支援 SQL 帳號密碼認證，完全忽略 fedauth= 參數，導致它以空白使用者名稱嘗試登入，SQL Server 因而拒絕連線。

Azure AD 認證有兩種正確做法：

做法說明
改用 go-mssqldb/azuread匯入 _ "github.com/microsoft/go-mssqldb/azuread" 並使用 "azuresql" driver
改用 golang-migrate 的 useMsi=true讓 migrate 函式庫自行透過 ADAL 取得 token

本次採用第二種做法，同時也修改 initDatabasePool 以 ADAL token provider 建立 database/sql 連線：

修復方式

1. 修改連線字串（環境變數）

# 錯誤（會被 base driver 靜默忽略）
DATABASE_URL=sqlserver://db.example.com?database=mydb&fedauth=ActiveDirectoryMSI&...

# 正確
DATABASE_URL=sqlserver://db.example.com?database=mydb&useMsi=true&encrypt=true&TrustServerCertificate=false

2. 修改 Go 程式碼，用 ADAL 取得 MSI token

import (
    "database/sql"
    "net/url"
    mssql "github.com/microsoft/go-mssqldb"
    adal  "github.com/Azure/go-autorest/autorest/adal"
)

func getMSITokenProvider(resource string) func() (string, error) {
    return func() (string, error) {
        spt, err := adal.NewServicePrincipalTokenFromManagedIdentity(resource, nil)
        if err != nil {
            return "", err
        }
        if err = spt.Refresh(); err != nil {
            return "", err
        }
        return spt.Token().AccessToken, nil
    }
}

func initDatabasePool(databaseURL string) (*sqlx.DB, error) {
    u, err := url.Parse(databaseURL)
    if err != nil {
        return nil, err
    }

    useMsi := u.Query().Get("useMsi") == "true"
    if useMsi {
        tokenProvider := getMSITokenProvider("https://database.windows.net/")
        connector, err := mssql.NewAccessTokenConnector(databaseURL, tokenProvider)
        if err != nil {
            return nil, err
        }
        return sqlx.NewDb(sql.OpenDB(connector), "sqlserver"), nil
    }

    return sqlx.Connect("sqlserver", databaseURL)
}

重點： Azure SQL 的 MSI resource URL 為 https://database.windows.net/，結尾斜線不可省略。

Bug 2 — Migration 反覆失敗：Invalid column name 'xxx'

症狀

{"level":"fatal","msg":"Failed to run database migration",
 "error":"migration failed: Invalid column name 'old_column_name'. in line 15: MERGE INTO some_table ..."}

Migration 從第 1 版開始跑，跑到中途某個 seed SQL 時因欄位不存在而失敗，schema_migrations 被標記為 dirty=true，下次啟動仍繼續失敗。

根本原因

部署流程分兩個階段：

  1. 在 Azure SQL Query Editor 執行 init.sql（一次性初始化腳本）
  2. 後端啟動時由 golang-migrate 執行 migration

init.sql 為了方便，直接包含了所有 migration 的最終狀態（含後期的欄位更名，例如 old_column_name → new_column_name）。執行完 init.sql 後，資料庫已是最新 schema，但 schema_migrations 追蹤表完全是空的。

後端啟動時，golang-migrate 看不到任何已完成的 migration，從第 1 版開始執行。早期的 migration（如 seed 測試資料）引用了舊欄位名稱，而 init.sql 已把那個欄位改名，導致 SQL 執行失敗。

init.sql 執行後：  schema 已是最終狀態，但 schema_migrations = 空
golang-migrate：   以為從未 migrate 過，從頭執行 → 欄位衝突 → dirty

修復方式

短期（已壞掉的環境）： 直接以 SQL 強制將版本設為最新

-- 將版本號改為你的最新 migration 編號
DELETE FROM schema_migrations;
INSERT INTO schema_migrations (version, dirty) VALUES (最新版本號, 0);

長期（防止再次發生）： 在 init.sql 結尾加入 schema_migrations 初始化

-- ============================================================
--  schema_migrations 版本追蹤（與 golang-migrate 同步）
--  init.sql 已套用所有 migration，在此設定版本號，
--  避免後端啟動時重跑 migration 造成欄位衝突。
-- ============================================================
IF OBJECT_ID(N'dbo.schema_migrations', N'U') IS NULL
BEGIN
    CREATE TABLE schema_migrations (
        version BIGINT NOT NULL PRIMARY KEY,
        dirty   BIT    NOT NULL
    );
END

DELETE FROM schema_migrations;
INSERT INTO schema_migrations (version, dirty) VALUES (最新版本號, 0);

版本號維護： 每新增一個 migration 檔案時，記得同步更新 init.sql 裡的版本號。

Bug 3 — 環境變數設定錯誤：invalid mode "xxx"

症狀

{"level":"fatal","msg":"Failed to create External API client",
 "error":"some-client: invalid mode \"prod\", must be 'mock' or 'http'"}

根本原因

部署腳本的預設值沿用了自訂的命名慣例（"prod"），但程式碼實際接受的值只有：

  • "http" — 呼叫真實的外部 API
  • "mock" — 使用 mock 資料（本地開發用）

部署腳本撰寫時沒有對照程式碼確認合法值，造成一個完全不必要的啟動錯誤。

修復方式

# deploy.ps1 — 修改前
$SOME_CLIENT_MODE = "prod"   # ❌ 程式碼不接受這個值

# deploy.ps1 — 修改後
$SOME_CLIENT_MODE = "http"   # ✅ 正確：正式環境使用真實 API

若已部署，可直接更新 App Settings，不需重新部署映像：

az webapp config appsettings set \
  --name my-backend-app \
  --resource-group my-resource-group \
  --settings SOME_CLIENT_MODE=http

小提醒： az webapp config appsettings set 只更新指定的 key，不會覆蓋其他設定，比 az rest PUT /config/appsettings 安全。

Bug 4 — 冷啟動時資料庫連線瞬斷：Read: EOF

症狀

{"level":"fatal","msg":"Failed to run database migration",
 "error":"failed to open database: Read: EOF"}

容器啟動後約 5–7 秒閃退，exit code 1。每次重啟都重現，沒有任何 retry 訊息。Log 顯示 migration 剛要開始就立刻失敗。

根本原因

Azure Web App for Containers 採用邊車（sidecar）架構：主容器與 MSI sidecar（負責核發 Managed Identity token）幾乎同時啟動。MSI sidecar 需要幾秒鐘才能就緒。

在這個短暫的空窗期（約 1–7 秒），golang-migrate 試圖開啟 TCP 連線，經過 TLS handshake 時遭遇 TCP RST 或連線中斷，因而回傳 Read: EOF。

golang-migrate 的 MigrationUp 不具備內建的 retry 機制——第一次連線失敗就直接回傳錯誤，由呼叫端負責處理。Go 程式在沒有 retry 保護的情況下直接呼叫 logger.Fatal，容器立即退出。

容器啟動
  ├─ MSI sidecar：正在初始化（尚未就緒）
  └─ Go 程式：立刻呼叫 MigrationUp
       └─ golang-migrate 開啟 TCP 連線 → Read: EOF
            └─ main.go 呼叫 logger.Fatal → 容器退出（exit 1）

修復方式

在呼叫 MigrationUp 前，加一層帶有指數退避（exponential backoff）的 retry 包裝：

// retryDB 以指數退避重試資料庫操作，最多重試 maxAttempts 次。
// 等待時間：2s → 4s → 8s → 16s（每次左移一位）
func retryDB(logger *zap.Logger, maxAttempts int, fn func() error) error {
    var err error
    for attempt := 0; attempt < maxAttempts; attempt++ {
        err = fn()
        if err == nil {
            return nil
        }
        if attempt < maxAttempts-1 {
            wait := time.Duration(1<<(attempt+1)) * time.Second
            logger.Warn("Database operation failed, retrying",
                zap.Int("attempt", attempt+1),
                zap.Duration("wait", wait),
                zap.Error(err),
            )
            time.Sleep(wait)
        }
    }
    return err
}

// 使用範例
err = retryDB(logger, 5, func() error {
    return databaseutil.MigrationUp(cfg.MigrationSource, cfg.DatabaseURL, logger)
})
if err != nil {
    logger.Fatal("Failed to run database migration", zap.Error(err))
}

這樣即使第一次連線遇到 EOF，程式會等待 2 秒後重試，最多嘗試 5 次（共可等待 30 秒），足以涵蓋 MSI sidecar 的啟動時間。

驗證

修復後重新建置映像並強制 Azure 拉取新版：

# 強制 Azure 拉取新映像（az webapp restart 只重啟，不重拉映像）
az webapp config container set \
  --name my-backend-app \
  --resource-group my-resource-group \
  --container-image-name "my-registry.azurecr.io/my-backend:latest"

若 retry 有發生，Log 會出現以下 warn 訊息，並最終成功啟動：

{"level":"warn","msg":"Database operation failed, retrying","attempt":1,"wait":"2s","error":"failed to open database: Read: EOF"}
{"level":"info","msg":"Current migration version","version":9,"dirty":false}
{"level":"info","msg":"Database schema is up to date, no migration required"}

若 MSI sidecar 已就緒，第一次連線即可成功，不會有 warn 訊息，容器直接順利啟動。

注意： az webapp restart 會使用本地快取的映像，不會拉取最新版本。若需強制更新，請使用 az webapp config container set 重新設定映像名稱。

偵錯流程回顧

四個 bug 必須依序排除——前一個 bug 掩蓋了後一個：

啟動失敗
  └─ Bug 1: Login failed for user ''
       └─ 修復後 → 繼續啟動
            └─ Bug 2: Invalid column name 'xxx' (migration dirty)
                 └─ 修復後 → 繼續啟動
                      └─ Bug 3: invalid mode "prod"
                           └─ 修復後 → 繼續啟動
                                └─ Bug 4: Read: EOF (MSI sidecar not ready)
                                     └─ 修復後 → 啟動成功 ✅

每次改一個問題就要重新部署或重啟容器，並等待 30–60 秒的 cold start 時間，再從 Log stream 確認下一個錯誤。

取得最新 container log 的方式（Azure CLI）：

# 快速方式（Kudu VFS API，不需解壓縮）
TOKEN=$(az account get-access-token --query accessToken -o tsv)
curl -H "Authorization: Bearer $TOKEN" \
     -H "Accept: text/plain" \
  "https://my-backend-app.scm.azurewebsites.net/api/vfs/LogFiles/YYYY_MM_DD_<instanceId>_default_docker.log" \
  | tail -30

# 完整下載方式
az webapp log download \
  --name my-backend-app \
  --resource-group my-resource-group \
  --log-file backend-logs.zip

最終確認

後端正常啟動後，Log 應呈現以下模式：

{"msg":"Database schema is up to date, no migration required"}
{"msg":"External API HTTP client initialized","base_url":"https://api.example.com"}
{"msg":"Application initialization","host":"0.0.0.0","port":"8080"}
{"msg":"Starting listening request","host":"0.0.0.0","port":"8080"}

以 HTTP 呼叫受保護的 API 端點，應回傳 401 Unauthorized（JSON 格式），而非 Azure 的 HTML 錯誤頁面：

curl https://my-backend-app.azurewebsites.net/api/some-protected-endpoint
# 預期回應：{"title":"Unauthorized","status":401,...}

重點整理

Bug症狀關鍵字根本原因修復
1Login failed for user ''base go-mssqldb driver 忽略 fedauth=改用 useMsi=true + ADAL token provider
2Invalid column name + migration dirtyinit.sql 與 golang-migrate 狀態不同步init.sql 末尾補 schema_migrations 初始化
3invalid mode "xxx"部署腳本使用無效的環境變數值對照程式碼確認合法值，改為 "http"
4Read: EOF (migration)MSI sidecar 啟動期間 TCP 連線瞬斷，無 retry加 retryDB 指數退避包裝（最多 5 次，最長 30s）

Related Posts

發佈留言

發佈留言必須填寫的電子郵件地址不會公開。 必填欄位標示為 *