mail send debug

2026-08-08 23:17:17 +03:00
parent 3e01f4b391
commit 28fc484c9f
3 changed files with 102 additions and 24 deletions
@@ -5,11 +5,14 @@
 declare(strict_types=1);

 $config = require __DIR__ . '/config.php';
+require_once __DIR__ . '/_debug.php';

 // Never leak PHP errors into the response; any uncaught throwable becomes a JSON 500.
 ini_set('display_errors', '0');
 set_exception_handler(function (Throwable $e): void {
    error_log('[casadoc-api] ' . $e);
+    // TEMPORARY.
+    debug_log('[' . ($_SERVER['REQUEST_URI'] ?? '?') . '] uncaught: ' . $e);
    if (!headers_sent()) {
        http_response_code(500);
        header('Content-Type: application/json; charset=utf-8');
@@ -2,9 +2,11 @@
 // SMTP delivery via PHPMailer (already a project dependency).

 require_once __DIR__ . '/../../../vendor/autoload.php';
+require_once __DIR__ . '/_debug.php';

 use Dotenv\Dotenv;
 use PHPMailer\PHPMailer\PHPMailer;
+use PHPMailer\PHPMailer\SMTP;

 Dotenv::createImmutable([dirname(__DIR__, 2), dirname(__DIR__, 3)])->safeLoad();

@@ -19,6 +21,14 @@ function mail_env(string $key, string $default = ''): string
 /** Never surfaces the SMTP error to the caller: it can leak host and credentials. */
 function send_mail(string $to, string $subject, string $html): bool
 {
+    $where = sprintf(
+        '%s@%s:%s (%s)',
+        mail_env('MAIL_USERNAME'),
+        mail_env('MAIL_HOST', 'localhost'),
+        mail_env('MAIL_PORT', '587'),
+        mail_env('MAIL_ENCRYPTION', 'none')
+    );
+
    $mail = new PHPMailer(true);
    try {
        $mail->isSMTP();
@@ -32,30 +42,68 @@ function send_mail(string $to, string $subject, string $html): bool
        // Default is 300s: an unreachable SMTP would otherwise stall registration.
        $mail->Timeout    = 10;

-        $mail->setFrom(
-            mail_env('MAIL_FROM_ADDRESS', 'noreply@casadoc.app'),
-            mail_env('MAIL_FROM_NAME', 'CasaDoc')
-        );
+        $from = mail_env('MAIL_FROM_ADDRESS', 'noreply@casadoc.app');
+        // Without this the Message-ID is generated as <...@localhost>, which some
+        // providers treat as a spam signal.
+        if ($domain = substr(strrchr($from, '@') ?: '', 1)) {
+            $mail->Hostname = $domain;
+        }
+
+        $mail->setFrom($from, mail_env('MAIL_FROM_NAME', 'CasaDoc'));
        $mail->addAddress($to);
        $mail->isHTML(true);
        $mail->Subject = $subject;
        $mail->Body    = $html;

+        // TEMPORARY
+        $queued = '';
+        $mail->SMTPDebug = SMTP::DEBUG_CONNECTION;
+        $mail->Debugoutput = static function (string $str, int $level) use (&$queued): void {
+            foreach (preg_split('/\R/', rtrim($str)) as $line) {
+                if (trim($line) === '') {
+                    continue;
+                }
+                if (preg_match('/SERVER -> CLIENT: (250 (?!SIZE)\S.*)$/', $line, $m)) {
+                    $queued = trim($m[1]);
+                }
+                debug_log("  smtp[{$level}] " . rtrim($line));
+            }
+        };
+        debug_log(sprintf(
+            'mail: sending to %s via %s | from=%s | subject=%s | %d bytes html',
+            $to,
+            $where,
+            $from,
+            $subject,
+            strlen($html)
+        ));
+
+        $started = microtime(true);
        $mail->send();

+        debug_log(sprintf(
+            'mail: SENT to %s in %d ms | message-id=%s | accepted by server: %s',
+            $to,
+            (int) round((microtime(true) - $started) * 1000),
+            $mail->getLastMessageID() ?: '(none)',
+            $queued ?: '(not captured)'
+        ));
+
        return true;
    } catch (Throwable $e) {
        // Without the connection details a failure is indistinguishable from a
        // wrong recipient address. The password is never logged.
-        error_log(sprintf(
-            'mail failed to %s via %s@%s:%s (%s): %s',
+        $reason = sprintf(
+            'mail FAILED to %s via %s: %s',
            $to,
-            mail_env('MAIL_USERNAME'),
-            mail_env('MAIL_HOST', 'localhost'),
-            mail_env('MAIL_PORT', '587'),
-            mail_env('MAIL_ENCRYPTION', 'none'),
+            $where,
            $mail->ErrorInfo ?: $e->getMessage()
-        ));
+        );
+        error_log($reason);
+        debug_log($reason);
+        if ($e->getMessage() !== '' && $e->getMessage() !== $mail->ErrorInfo) {
+            debug_log('  exception: ' . get_class($e) . ': ' . $e->getMessage());
+        }

        return false;
    }
@@ -72,5 +120,12 @@ function send_code_mail(string $to, string $code, bool $isReset = false): bool
        . '<p style="font-size:28px;font-weight:bold;letter-spacing:4px">' . htmlspecialchars($code) . '</p>'
        . '<p>The code expires in 15 minutes. If you did not request it, ignore this e-mail.</p>';

+    debug_log(sprintf(
+        'code: %s code %s for %s',
+        $isReset ? 'password reset' : 'verification',
+        $code,
+        $to
+    ));
+
    return send_mail($to, $subject, $html);
 }
@@ -27,6 +27,8 @@ $in       = body();
 $email    = trim((string) ($in['email'] ?? ''));
 $password = (string) ($in['password'] ?? '');

+debug_log("register: {$email}");
+
 $fields = [];
 if (!filter_var($email, FILTER_VALIDATE_EMAIL)) {
    $fields['email'] = ['Valid email required'];
@@ -35,27 +37,45 @@ if (strlen($password) < 8) {
    $fields['password'] = ['At least 8 characters'];
 }
 if ($fields) {
+    debug_log('register: rejected, ' . json_encode($fields) . ' — no code is sent');
    json_error(422, 'Validation failed', $fields);
 }

-$exists = $pdo->prepare('SELECT 1 FROM auth_users WHERE email = ? LIMIT 1');
+$exists = $pdo->prepare('SELECT id, created_at, email_verified_at FROM auth_users WHERE email = ? LIMIT 1');
 $exists->execute([$email]);
-if ($exists->fetchColumn()) {
+if ($row = $exists->fetch()) {
+    debug_log(sprintf(
+        'register: already registered — id=%s created_at=%s verified=%s. No code is sent; log in instead.',
+        $row['id'],
+        $row['created_at'],
+        $row['email_verified_at'] ?: 'no'
+    ));
    json_error(422, 'Validation failed', ['email' => ['Already registered']]);
 }

-// role_id 2 is "User"; 1 is "Admin" and must never be handed out here.
-$pdo->prepare(
-    "INSERT INTO auth_users (email, password, first_name, last_name, role_id, status, email_verified_at, created_at, updated_at)
-     VALUES (?, ?, ?, ?, 2, 'Active', NULL, NOW(), NOW())"
-)->execute([
-    $email,
-    password_hash($password, PASSWORD_DEFAULT),
-    trim((string) ($in['first_name'] ?? '')) ?: null,
-    trim((string) ($in['last_name'] ?? '')) ?: null,
-]);
+$pdo->beginTransaction();
+try {
+    // role_id 2 is "User"; 1 is "Admin" and must never be handed out here.
+    $pdo->prepare(
+        "INSERT INTO auth_users (email, password, first_name, last_name, role_id, status, email_verified_at, created_at, updated_at)
+         VALUES (?, ?, ?, ?, 2, 'Active', NULL, NOW(), NOW())"
+    )->execute([
+        $email,
+        password_hash($password, PASSWORD_DEFAULT),
+        trim((string) ($in['first_name'] ?? '')) ?: null,
+        trim((string) ($in['last_name'] ?? '')) ?: null,
+    ]);

-if ($code = issue_code($pdo, 'auth_email_verifications', $email)) {
+    $code = issue_code($pdo, 'auth_email_verifications', $email);
+    $pdo->commit();
+    debug_log('register: account created, code ' . ($code ? 'issued' : 'THROTTLED (one per 60s)'));
+} catch (Throwable $e) {
+    $pdo->rollBack();
+    debug_log('register: rolled back — ' . $e->getMessage());
+    throw $e;
+}
+
+if ($code) {
    send_code_mail($email, $code);
 }