CI showed exit=1 in ~3s with empty docker logs after /data/opendkim was created. Log each entrypoint step and trap ERR with LINENO; also read the container LogPath and docker logs by container id when compose logs are empty. Co-Authored-By: Composer <noreply@cursor.com> Co-authored-by: Cursor <cursoragent@cursor.com>
This commit is contained in:
@@ -6,6 +6,12 @@
|
|||||||
# looks like a permissions or packaging problem (and so the e2e hostname-gate
|
# looks like a permissions or packaging problem (and so the e2e hostname-gate
|
||||||
# tests see the FATAL text rather than an earlier set -e abort).
|
# tests see the FATAL text rather than an earlier set -e abort).
|
||||||
set -e
|
set -e
|
||||||
|
# #region agent log
|
||||||
|
# Debug: CI showed exit=1 with empty docker logs after /data/opendkim was
|
||||||
|
# created — surface the failing line under set -e (session 816647).
|
||||||
|
trap 'echo "entrypoint: command failed at line $LINENO (exit $?)" >&2' ERR
|
||||||
|
step() { echo "entrypoint: $*" >&2; }
|
||||||
|
# #endregion
|
||||||
|
|
||||||
# SELFPOST_HOSTNAME is an identity, not a setting with a safe default: it must
|
# SELFPOST_HOSTNAME is an identity, not a setting with a safe default: it must
|
||||||
# simultaneously match the PTR/rDNS record, the certificate CN/SAN, and the
|
# simultaneously match the PTR/rDNS record, the certificate CN/SAN, and the
|
||||||
@@ -62,6 +68,7 @@ esac
|
|||||||
# trees under /data as other users. Go's testing.TempDir is 0700, and a bare
|
# trees under /data as other users. Go's testing.TempDir is 0700, and a bare
|
||||||
# chown would leave that mode in place — opendkim then cannot read KeyTable and
|
# chown would leave that mode in place — opendkim then cannot read KeyTable and
|
||||||
# the container crash-loops (e2e TestHostnameGate/valid_hostname_starts).
|
# the container crash-loops (e2e TestHostnameGate/valid_hostname_starts).
|
||||||
|
step "chown/chmod /data"
|
||||||
chown panel:panel /data
|
chown panel:panel /data
|
||||||
chmod 755 /data
|
chmod 755 /data
|
||||||
# Restored backups or previously-created state may contain panel-owned files
|
# Restored backups or previously-created state may contain panel-owned files
|
||||||
@@ -69,6 +76,7 @@ chmod 755 /data
|
|||||||
# later phase deliberately hands to another service. /data/log is exempt: it is
|
# later phase deliberately hands to another service. /data/log is exempt: it is
|
||||||
# deliberately owned by postfix (postlogd writes the delivery log there) and is
|
# deliberately owned by postfix (postlogd writes the delivery log there) and is
|
||||||
# normalised on its own below.
|
# normalised on its own below.
|
||||||
|
step "normalize existing /data children"
|
||||||
find /data -mindepth 1 -maxdepth 1 ! -user panel ! -name log -exec chown -R panel:panel {} +
|
find /data -mindepth 1 -maxdepth 1 ! -user panel ! -name log -exec chown -R panel:panel {} +
|
||||||
|
|
||||||
# DKIM key tree (spec 6, 9). The panel (user `panel`) generates keys and writes
|
# DKIM key tree (spec 6, 9). The panel (user `panel`) generates keys and writes
|
||||||
@@ -80,6 +88,7 @@ find /data -mindepth 1 -maxdepth 1 ! -user panel ! -name log -exec chown -R pane
|
|||||||
# - private keys and tables group-readable (0640);
|
# - private keys and tables group-readable (0640);
|
||||||
# - both table files present (empty is fine) BEFORE OpenDKIM starts, so the
|
# - both table files present (empty is fine) BEFORE OpenDKIM starts, so the
|
||||||
# daemon comes up cleanly with no domains yet.
|
# daemon comes up cleanly with no domains yet.
|
||||||
|
step "opendkim tree"
|
||||||
mkdir -p /data/opendkim/keys
|
mkdir -p /data/opendkim/keys
|
||||||
for t in /data/opendkim/KeyTable /data/opendkim/SigningTable; do
|
for t in /data/opendkim/KeyTable /data/opendkim/SigningTable; do
|
||||||
[ -e "$t" ] || : > "$t"
|
[ -e "$t" ] || : > "$t"
|
||||||
@@ -94,6 +103,7 @@ find /data/opendkim/keys -type f -name '*.private' -exec chmod 0640 {} +
|
|||||||
# clients. Share it through the `selfpost` group the same way as the DKIM tree:
|
# clients. Share it through the `selfpost` group the same way as the DKIM tree:
|
||||||
# setgid directory so new files inherit the group, and the database itself
|
# setgid directory so new files inherit the group, and the database itself
|
||||||
# group-readable (0640).
|
# group-readable (0640).
|
||||||
|
step "sasl tree"
|
||||||
mkdir -p /data/sasl
|
mkdir -p /data/sasl
|
||||||
chown -R panel:selfpost /data/sasl
|
chown -R panel:selfpost /data/sasl
|
||||||
chmod 2750 /data/sasl
|
chmod 2750 /data/sasl
|
||||||
@@ -102,6 +112,7 @@ chmod 2750 /data/sasl
|
|||||||
# Postfix sender_login_maps (spec 5.1). The panel writes it; Postfix reads it.
|
# Postfix sender_login_maps (spec 5.1). The panel writes it; Postfix reads it.
|
||||||
# Ensure the file exists (empty is fine) before Postfix starts so a reload that
|
# Ensure the file exists (empty is fine) before Postfix starts so a reload that
|
||||||
# references it never fails on a missing file, and keep it group-readable.
|
# references it never fails on a missing file, and keep it group-readable.
|
||||||
|
step "postfix sender map"
|
||||||
mkdir -p /data/postfix
|
mkdir -p /data/postfix
|
||||||
[ -e /data/postfix/sender_login_maps ] || : > /data/postfix/sender_login_maps
|
[ -e /data/postfix/sender_login_maps ] || : > /data/postfix/sender_login_maps
|
||||||
chown -R panel:selfpost /data/postfix
|
chown -R panel:selfpost /data/postfix
|
||||||
@@ -119,6 +130,7 @@ chmod 0640 /data/postfix/sender_login_maps
|
|||||||
# directory keeps the shared group on anything created inside it later, and
|
# directory keeps the shared group on anything created inside it later, and
|
||||||
# 2750 keeps it group-traversable but not group-writable — logrotate refuses to
|
# 2750 keeps it group-traversable but not group-writable — logrotate refuses to
|
||||||
# rotate a log whose directory is writable by a non-root group.
|
# rotate a log whose directory is writable by a non-root group.
|
||||||
|
step "mail.log tree"
|
||||||
mkdir -p /data/log
|
mkdir -p /data/log
|
||||||
[ -e /data/log/mail.log ] || : > /data/log/mail.log
|
[ -e /data/log/mail.log ] || : > /data/log/mail.log
|
||||||
chown -R postfix:selfpost /data/log
|
chown -R postfix:selfpost /data/log
|
||||||
@@ -133,6 +145,7 @@ find /data/log -type f -exec chmod 0640 {} +
|
|||||||
# each socket created inside inherits group `selfpost`, and group-traversable
|
# each socket created inside inherits group `selfpost`, and group-traversable
|
||||||
# (2750) lets postfix reach it. Without this, smtpd cannot talk to OpenDKIM and,
|
# (2750) lets postfix reach it. Without this, smtpd cannot talk to OpenDKIM and,
|
||||||
# because signing is strict (default_action=tempfail), rejects all mail.
|
# because signing is strict (default_action=tempfail), rejects all mail.
|
||||||
|
step "milter run dirs"
|
||||||
mkdir -p /run/opendkim /run/selfpost
|
mkdir -p /run/opendkim /run/selfpost
|
||||||
chown opendkim:selfpost /run/opendkim
|
chown opendkim:selfpost /run/opendkim
|
||||||
chown panel:selfpost /run/selfpost
|
chown panel:selfpost /run/selfpost
|
||||||
@@ -142,6 +155,8 @@ chmod 2750 /run/opendkim /run/selfpost
|
|||||||
# 5). Kept out of the image build so cert paths, rate limits, hostname and the
|
# 5). Kept out of the image build so cert paths, rate limits, hostname and the
|
||||||
# optional 587 service are all driven by env at run time, and re-derived on every
|
# optional 587 service are all driven by env at run time, and re-derived on every
|
||||||
# start the same way the /data normalisation above is.
|
# start the same way the /data normalisation above is.
|
||||||
|
step "postfix-config.sh"
|
||||||
/usr/local/bin/postfix-config.sh
|
/usr/local/bin/postfix-config.sh
|
||||||
|
|
||||||
|
step "exec supervisord"
|
||||||
exec /usr/bin/supervisord -c /etc/supervisor/supervisord.conf
|
exec /usr/bin/supervisord -c /etc/supervisor/supervisord.conf
|
||||||
|
|||||||
@@ -128,6 +128,21 @@ func runEntrypointBackground(t *testing.T, hostnameEnv string) (output string, s
|
|||||||
inspect, _ := exec.Command("docker", "inspect", name, "--format",
|
inspect, _ := exec.Command("docker", "inspect", name, "--format",
|
||||||
"status={{.State.Status}} exit={{.State.ExitCode}} err={{.State.Error}} oom={{.State.OOMKilled}} started={{.State.StartedAt}} finished={{.State.FinishedAt}}").CombinedOutput()
|
"status={{.State.Status}} exit={{.State.ExitCode}} err={{.State.Error}} oom={{.State.OOMKilled}} started={{.State.StartedAt}} finished={{.State.FinishedAt}}").CombinedOutput()
|
||||||
logs, logErr := exec.Command("docker", "logs", name).CombinedOutput()
|
logs, logErr := exec.Command("docker", "logs", name).CombinedOutput()
|
||||||
|
// Exited containers sometimes yield empty `docker logs` in CI; also read
|
||||||
|
// the JSON-file log path docker recorded on the container.
|
||||||
|
logPathOut, _ := exec.Command("docker", "inspect", name, "--format", "{{.LogPath}}").CombinedOutput()
|
||||||
|
logPath := strings.TrimSpace(string(logPathOut))
|
||||||
|
logFileHead := ""
|
||||||
|
if logPath != "" {
|
||||||
|
if b, e := os.ReadFile(logPath); e == nil {
|
||||||
|
logFileHead = truncateForDebug(string(b), 4000)
|
||||||
|
if strings.TrimSpace(string(logs)) == "" && len(b) > 0 {
|
||||||
|
logs = b
|
||||||
|
}
|
||||||
|
} else {
|
||||||
|
logFileHead = "read LogPath: " + e.Error()
|
||||||
|
}
|
||||||
|
}
|
||||||
dataMode, _ := exec.Command("docker", "exec", name, "stat", "-c", "%a %U:%G", "/data").CombinedOutput()
|
dataMode, _ := exec.Command("docker", "exec", name, "stat", "-c", "%a %U:%G", "/data").CombinedOutput()
|
||||||
opendkimStat, _ := exec.Command("docker", "exec", name, "stat", "-c", "%a %U:%G", "/data/opendkim").CombinedOutput()
|
opendkimStat, _ := exec.Command("docker", "exec", name, "stat", "-c", "%a %U:%G", "/data/opendkim").CombinedOutput()
|
||||||
keyTableStat, _ := exec.Command("docker", "exec", name, "stat", "-c", "%a %U:%G", "/data/opendkim/KeyTable").CombinedOutput()
|
keyTableStat, _ := exec.Command("docker", "exec", name, "stat", "-c", "%a %U:%G", "/data/opendkim/KeyTable").CombinedOutput()
|
||||||
@@ -157,6 +172,8 @@ func runEntrypointBackground(t *testing.T, hostnameEnv string) (output string, s
|
|||||||
"waitErr": fmt.Sprintf("%v", err),
|
"waitErr": fmt.Sprintf("%v", err),
|
||||||
"logErr": fmt.Sprintf("%v", logErr),
|
"logErr": fmt.Sprintf("%v", logErr),
|
||||||
"logLen": len(logs),
|
"logLen": len(logs),
|
||||||
|
"logPath": logPath,
|
||||||
|
"logFileHead": logFileHead,
|
||||||
})
|
})
|
||||||
agentDebugLog("H3", "hostname_gate_test.go:post-wait", "supervisor and logs", map[string]any{
|
agentDebugLog("H3", "hostname_gate_test.go:post-wait", "supervisor and logs", map[string]any{
|
||||||
"supervisorctl": strings.TrimSpace(string(supStatus)),
|
"supervisorctl": strings.TrimSpace(string(supStatus)),
|
||||||
@@ -167,8 +184,11 @@ func runEntrypointBackground(t *testing.T, hostnameEnv string) (output string, s
|
|||||||
diag := string(logs)
|
diag := string(logs)
|
||||||
if strings.TrimSpace(diag) == "" {
|
if strings.TrimSpace(diag) == "" {
|
||||||
diag = "(empty docker logs)\ninspect: " + strings.TrimSpace(string(inspect)) +
|
diag = "(empty docker logs)\ninspect: " + strings.TrimSpace(string(inspect)) +
|
||||||
|
"\nlogPath: " + logPath +
|
||||||
|
"\nlogFileHead: " + logFileHead +
|
||||||
"\nsupervisorctl: " + strings.TrimSpace(string(supStatus)) +
|
"\nsupervisorctl: " + strings.TrimSpace(string(supStatus)) +
|
||||||
"\n/data mode: " + strings.TrimSpace(string(dataMode))
|
"\n/data mode: " + strings.TrimSpace(string(dataMode)) +
|
||||||
|
"\nhost /data: " + hostDataListing
|
||||||
}
|
}
|
||||||
return diag, err == nil
|
return diag, err == nil
|
||||||
}
|
}
|
||||||
|
|||||||
@@ -54,17 +54,36 @@ func checkSupervisorProcesses(s *stack) error {
|
|||||||
ps, _ := s.compose("ps", "-a", "--format", "json")
|
ps, _ := s.compose("ps", "-a", "--format", "json")
|
||||||
inspectOut, _ := exec.Command("docker", "ps", "-a", "--filter", "name=selfpost-e2e",
|
inspectOut, _ := exec.Command("docker", "ps", "-a", "--filter", "name=selfpost-e2e",
|
||||||
"--format", "{{.Names}} {{.Status}} {{.ID}}").CombinedOutput()
|
"--format", "{{.Names}} {{.Status}} {{.ID}}").CombinedOutput()
|
||||||
|
// compose logs can be empty for a fast-exit container; pull docker logs by id.
|
||||||
|
rawDockerLogs := ""
|
||||||
|
for _, line := range strings.Split(string(inspectOut), "\n") {
|
||||||
|
fields := strings.Fields(line)
|
||||||
|
if len(fields) < 3 || !strings.Contains(fields[0], "selfpost-1") {
|
||||||
|
continue
|
||||||
|
}
|
||||||
|
id := fields[len(fields)-1]
|
||||||
|
if b, e := exec.Command("docker", "logs", id).CombinedOutput(); e == nil {
|
||||||
|
rawDockerLogs = string(b)
|
||||||
|
} else {
|
||||||
|
rawDockerLogs = e.Error() + "\n" + string(b)
|
||||||
|
}
|
||||||
|
if strings.TrimSpace(logs) == "" && strings.TrimSpace(rawDockerLogs) != "" {
|
||||||
|
logs = rawDockerLogs
|
||||||
|
}
|
||||||
|
break
|
||||||
|
}
|
||||||
dataPath := filepath.Join(s.stageDir, "data")
|
dataPath := filepath.Join(s.stageDir, "data")
|
||||||
dataMode := ""
|
dataMode := ""
|
||||||
if fi, e := os.Stat(dataPath); e == nil {
|
if fi, e := os.Stat(dataPath); e == nil {
|
||||||
dataMode = fmt.Sprintf("%04o", fi.Mode().Perm())
|
dataMode = fmt.Sprintf("%04o", fi.Mode().Perm())
|
||||||
}
|
}
|
||||||
entrypointSnippet, _ := exec.Command("docker", "run", "--rm", "--entrypoint", "sh", "selfpost:e2e",
|
entrypointSnippet, _ := exec.Command("docker", "run", "--rm", "--entrypoint", "sh", "selfpost:e2e",
|
||||||
"-c", "grep -n 'chmod 755 /data\\|SELFPOST_HOSTNAME is not set' /usr/local/bin/entrypoint.sh | head -20").CombinedOutput()
|
"-c", "grep -n 'chmod 755 /data\\|entrypoint: command failed\\|step()' /usr/local/bin/entrypoint.sh | head -30").CombinedOutput()
|
||||||
agentDebugLog("H4", "process_check.go:fail", "compose selfpost not ready", map[string]any{
|
agentDebugLog("H4", "process_check.go:fail", "compose selfpost not ready", map[string]any{
|
||||||
"waitErr": err.Error(),
|
"waitErr": err.Error(),
|
||||||
"logsLen": len(logs),
|
"logsLen": len(logs),
|
||||||
"logsHead": truncateForDebug(logs, 4000),
|
"logsHead": truncateForDebug(logs, 4000),
|
||||||
|
"rawDockerLogsHead": truncateForDebug(rawDockerLogs, 4000),
|
||||||
"composePs": truncateForDebug(string(ps), 2000),
|
"composePs": truncateForDebug(string(ps), 2000),
|
||||||
"dockerPs": strings.TrimSpace(string(inspectOut)),
|
"dockerPs": strings.TrimSpace(string(inspectOut)),
|
||||||
"hostDataMode": dataMode,
|
"hostDataMode": dataMode,
|
||||||
@@ -74,8 +93,8 @@ func checkSupervisorProcesses(s *stack) error {
|
|||||||
"snippet": strings.TrimSpace(string(entrypointSnippet)),
|
"snippet": strings.TrimSpace(string(entrypointSnippet)),
|
||||||
})
|
})
|
||||||
// #endregion
|
// #endregion
|
||||||
return fmt.Errorf("%w\n==== selfpost logs ====\n%s\n==== docker ps ====\n%s\n==== entrypoint markers ====\n%s",
|
return fmt.Errorf("%w\n==== selfpost logs ====\n%s\n==== docker logs (by id) ====\n%s\n==== docker ps ====\n%s\n==== entrypoint markers ====\n%s",
|
||||||
err, logs, inspectOut, entrypointSnippet)
|
err, logs, rawDockerLogs, inspectOut, entrypointSnippet)
|
||||||
}
|
}
|
||||||
return nil
|
return nil
|
||||||
}
|
}
|
||||||
|
|||||||
Reference in New Issue
Block a user