Intermittent File Write Failures with fwrite #1007

g-ra · 2024-08-27T15:55:41Z

What happened?

Description:
I'm encountering an issue where file writing operations using fwrite occasionally fail when running under FrankenPHP. Sometimes files are not physically created on the server, but the filesize and file_exists functions report them as existing correctly. The code is designed to handle image uploads encoded in Base64, and it works reliably in development environments (e.g., Docker for Windows, Docker for Mac). However, under FrankenPHP in production, files are often missing, even though all the code logic suggests they should have been created successfully.

public function base64ToFile(string $base64, string $fileName, string $storage = Files::STORAGE_PATH): array
{
    if (!is_dir($storage)) {
        $this->imageService->makeDirPath($storage);
    }

    $resultUploadFile = [];

    // Replace spaces with "+"
    $base64 = str_replace(' ', '+', $base64);

    // Split the data by comma
    $data = explode(',', $base64);

    $this->logger->critical('Uploading image: ' . $fileName, ['base64' => $base64, 'data' => $data]);

    // Ensure the Base64 string is properly formatted
    if (!isset($data[1])) {
        throw new LogicException('Invalid Base64 string format.');
    }

    $outputFile = $storage . '/' . $fileName;

    // Attempt to open the file for writing
    $ifp = fopen($outputFile, 'wb');

    if (!$ifp) {
        throw new LogicException('Failed to create file: ' . $outputFile);
    }

    // Attempt to decode the Base64 data
    $decodedData = base64_decode($data[1], true);

    if ($decodedData === false) {
        fclose($ifp);
        throw new LogicException('Failed to decode Base64 data.');
    }

    // Attempt to write the decoded data to the file
    $fwrite = fwrite($ifp, $decodedData);

    if ($fwrite === false) {
        fclose($ifp);
        throw new LogicException('Failed to write data to file: ' . $outputFile);
    }

    // Attempt to close the file
    $close = fclose($ifp);

    if (!$close) {
        throw new LogicException('Failed to close file: ' . $outputFile);
    }

    // Verify the file exists and is not empty
    if (file_exists($outputFile) && filesize($outputFile) > 0) {
        $resultUploadFile = [
            'name' => $fileName,
            'path' => $outputFile,
            'size' => filesize($outputFile),
            'mimeType' => mime_content_type($outputFile),
        ];
    } else {
        throw new LogicException('File does not exist or is zero-sized: ' . $outputFile);
    }

    return $resultUploadFile;
}

Issue: Intermittent file creation failures with fwrite. Sometimes files are not physically created on the server, but the filesize and file_exists functions report them as existing correctly.
Expected Behavior: The file should be consistently created with the correct size, matching the decoded Base64 data.
Observed Behavior: The file is either not created physically on the server, without throwing any exceptions or errors in some cases.
The code above shows that we try to handle all possible errors in production and log them (Grafana, Sentry), but no exceptions are being thrown inside the code, the file sizes are reported correctly, and the file is said to exist. However, in reality, the file is physically missing. How could this happen? Where could the file be stuck? Is fwrite being altered by FrankenPHP?

What complicates things is that we cannot reproduce this error in the development environment—10 out of 10 messages are processed without errors. The issue only occurs on the production server, about every other time. The configurations are the same as those specified in the API Platform documentation.

We have verified that base64_decode is functioning correctly; the content is decoded properly.

Versions:
FrankenPHP: 1.2.4
API Platform: 3.3.11
PHP: 8.3.10

Build Type

ENV CGO_ENABLED=1 XCADDY_SETCAP=1
ENV XCADDY_GO_BUILD_FLAGS="-ldflags \"-w -s -extldflags '-Wl,-z,stack-size=0x80000'\""
ENV CGO_CFLAGS="-fPIC" \
    CGO_LDFLAGS="-pie" \
    GOFLAGS="-buildmode=pie"
RUN xcaddy build \
	--output /usr/local/bin/frankenphp \
	--with github.com/dunglas/frankenphp=./ \
	--with github.com/dunglas/frankenphp/caddy=./caddy/ \
	# Mercure and Vulcain are included in the official build, but feel free to remove them
	--with github.com/dunglas/caddy-cbrotli \
	--with github.com/dunglas/mercure/caddy \
	--with github.com/dunglas/vulcain/caddy \
	# Add extra Caddy modules here
	--with github.com/darkweak/souin/plugins/caddy@fa61769ccc4499e8c72d994cd1b866d80bca3f7f \
	--with github.com/darkweak/souin@fa61769ccc4499e8c72d994cd1b866d80bca3f7f

Worker Mode

No

Operating System

GNU/Linux

CPU Architecture

x86_64

PHP configuration

Relevant log output

No response

dunglas · 2024-08-27T16:04:38Z

It's unlikely a FrankenPHP problem. It's more likely an upstream PHP bug. Would you mind opening a report on the PHP bug tracker, please?

It may be related to PHP's realpath cache. You can try to inspect it using https://www.php.net/manual/en/function.realpath-cache-get.php

dunglas · 2024-08-27T16:06:14Z

It may also be an OS-level configuration issue or even a hardware issue.

g-ra · 2024-08-27T16:43:21Z

so we added clearstatcache
This is not at all what we expected to see from the team realpath_cache_get()

 public function base64ToFile(string $base64, string $fileName, string $storage = Files::STORAGE_PATH): array
    {
        // Очистка кэша файловой системы перед началом операции
        clearstatcache(true);

        if (!is_dir($storage)) {
            $this->imageService->makeDirPath($storage);
        }

        $resultUploadFile = [];

        // Заменим пробелы на "+" (если они есть)
        $base64 = str_replace(' ', '+', $base64);

        // Разделим данные по запятой
        $data = explode(',', $base64);

        $this->logger->critical('Загружаем изображение: ' . $fileName, ['base64' => $base64, 'data' => $data]);

        // Проверим, содержит ли строка base64 нужную часть
        if (!isset($data[1])) {
            throw new LogicException('Неправильный формат base64 строки.');
        }

        $outputFile = $storage . '/' . $fileName;

        // Проверим кэш realpath до открытия файла
        $realpathCacheBefore = realpath_cache_get();
        $this->logger->debug('Realpath cache before fopen', ['cache' => $realpathCacheBefore]);

        // Попробуем открыть файл для записи
        $ifp = fopen($outputFile, 'wb');

        if (!$ifp) {
            throw new LogicException('Не удалось создать файл: ' . $outputFile);
        }

        // Проверим кэш realpath после открытия файла
        $realpathCacheAfter = realpath_cache_get();
        $this->logger->debug('Realpath cache after fopen', ['cache' => $realpathCacheAfter]);

        // Попробуем записать данные
        $decodedData = base64_decode($data[1], true);

        if ($decodedData === false) {
            fclose($ifp);
            throw new LogicException('Не удалось декодировать данные из base64.');
        }

        $fwrite = fwrite($ifp, $decodedData);

        if ($fwrite === false) {
            fclose($ifp);
            throw new LogicException('Не удалось записать данные в файл: ' . $outputFile);
        }

        // Попробуем закрыть файл
        $close = fclose($ifp);

        if (!$close) {
            throw new LogicException('Не удалось закрыть файл: ' . $outputFile);
        }

        // Очистка кэша файловой системы перед проверкой файла
        clearstatcache(true);

        // Проверим, существует ли файл и его размер
        if (file_exists($outputFile) && filesize($outputFile) > 0) {
            $resultUploadFile = [
                'name' => $fileName,
                'path' => $outputFile,
                'size' => filesize($outputFile),
                'mimeType' => mime_content_type($outputFile),
            ];
        } else {
            // Логирование перед выбросом исключения
            $this->logger->critical('Файл не существует или его размер нулевой', [
                'outputFile' => $outputFile,
                'file_exists' => file_exists($outputFile),
                'filesize' => filesize($outputFile),
            ]);
            throw new LogicException('Файл не существует или его размер нулевой: ' . $outputFile);
        }

        return $resultUploadFile;
    }

{
  "message": "Realpath cache before fopen",
  "context": {
    "cache": {
      "/app/vendor/composer/../jean85/pretty-package-versions/src/Exception/ReplacedPackageException.php": {
        "key": 1741092222027618325,
        "is_dir": false,
        "realpath": "/app/vendor/jean85/pretty-package-versions/src/Exception/ReplacedPackageException.php",
        "expires": 1724777085
      },
      "/app/vendor/composer/../sentry": {
        "key": 1.446892102405996e+19,
        "is_dir": true,
        "realpath": "/app/vendor/sentry",
        "expires": 1724777085
      },
      "/app/vendor/composer/../jean85/pretty-package-versions/src/Exception": {
        "key": 3445354377935876193,
        "is_dir": true,
        "realpath": "/app/vendor/jean85/pretty-package-versions/src/Exception",
        "expires": 1724777085
      },
      "/app/vendor/composer/../sentry/sentry": {
        "key": 6272597904363654282,
        "is_dir": true,
        "realpath": "/app/vendor/sentry/sentry",
        "expires": 1724777085
      },
      "/app/vendor": {
        "key": 1.3015001708359334e+19,
        "is_dir": true,
        "realpath": "/app/vendor",
        "expires": 1724777085
      },
      "/app": {
        "key": 1.6713224331187438e+19,
        "is_dir": true,
        "realpath": "/app",
        "expires": 1724777085
      },
      "/app/vendor/composer/../sentry/sentry/src/EventHint.php": {
        "key": 1.7758701366703495e+19,
        "is_dir": false,
        "realpath": "/app/vendor/sentry/sentry/src/EventHint.php",
        "expires": 1724777085
      },
      "/app/vendor/composer/../sentry/sentry/src/Context/RuntimeContext.php": {
        "key": 1.6710990675478868e+19,
        "is_dir": false,
        "realpath": "/app/vendor/sentry/sentry/src/Context/RuntimeContext.php",
        "expires": 1724777085
      },
      "/app/public": {
        "key": 1.5243278467568677e+19,
        "is_dir": true,
        "realpath": "/app/public",
        "expires": 1724777085
      },
      "/app/vendor/composer/../sentry/sentry/src/Util": {
        "key": 1095891862287442116,
        "is_dir": true,
        "realpath": "/app/vendor/sentry/sentry/src/Util",
        "expires": 1724777085
      },
      "/app/vendor/composer/../sentry/sentry/src/HttpClient/Request.php": {
        "key": 1.5625849210520429e+19,
        "is_dir": false,
        "realpath": "/app/vendor/sentry/sentry/src/HttpClient/Request.php",
        "expires": 1724777085
      },
      "/app/vendor/composer/../sentry/sentry/src/Serializer/Traits": {
        "key": 1776066386257523924,
        "is_dir": true,
        "realpath": "/app/vendor/sentry/sentry/src/Serializer/Traits",
        "expires": 1724777085
      },
      "/app/vendor/composer/../sentry/sentry/src/Serializer/EnvelopItems/EventItem.php": {
        "key": 1.5933480081714735e+19,
        "is_dir": false,
        "realpath": "/app/vendor/sentry/sentry/src/Serializer/EnvelopItems/EventItem.php",
        "expires": 1724777085
      },
      "/app/vendor/composer/../sentry/sentry/src/Event.php": {
        "key": 8369552226389327082,
        "is_dir": false,
        "realpath": "/app/vendor/sentry/sentry/src/Event.php",
        "expires": 1724777085
      },
      "/app/vendor/composer/../sentry/sentry/src/EventType.php": {
        "key": 2104146432693591282,
        "is_dir": false,
        "realpath": "/app/vendor/sentry/sentry/src/EventType.php",
        "expires": 1724777085
      },
      "/app/vendor/composer/../sentry/sentry/src/Serializer/EnvelopItems": {
        "key": 1.2561112554925214e+19,
        "is_dir": true,
        "realpath": "/app/vendor/sentry/sentry/src/Serializer/EnvelopItems",
        "expires": 1724777085
      },
      "/app/vendor/composer/../sentry/sentry/src/HttpClient": {
        "key": 719252581589170437,
        "is_dir": true,
        "realpath": "/app/vendor/sentry/sentry/src/HttpClient",
        "expires": 1724777085
      },
      "/app/vendor/composer/../sentry/sentry/src/Util/PHPVersion.php": {
        "key": 2264952045549354257,
        "is_dir": false,
        "realpath": "/app/vendor/sentry/sentry/src/Util/PHPVersion.php",
        "expires": 1724777085
      },
      "/app/vendor/composer/../jean85/pretty-package-versions/src/Exception/ProvidedPackageException.php": {
        "key": 3574769449742036248,
        "is_dir": false,
        "realpath": "/app/vendor/jean85/pretty-package-versions/src/Exception/ProvidedPackageException.php",
        "expires": 1724777085
      },
      "/app/vendor/composer/../jean85/pretty-package-versions/src/Version.php": {
        "key": 7171796831494803744,
        "is_dir": false,
        "realpath": "/app/vendor/jean85/pretty-package-versions/src/Version.php",
        "expires": 1724777085
      },
      "/app/vendor/composer/../sentry/sentry/src/HttpClient/Response.php": {
        "key": 4322384182332903827,
        "is_dir": false,
        "realpath": "/app/vendor/sentry/sentry/src/HttpClient/Response.php",
        "expires": 1724777085
      },
      "/app/vendor/composer/../jean85/pretty-package-versions/src/PrettyVersions.php": {
        "key": 6763236034658460087,
        "is_dir": false,
        "realpath": "/app/vendor/jean85/pretty-package-versions/src/PrettyVersions.php",
        "expires": 1724777085
      },
      "/app/vendor/composer/../sentry/sentry/src/EventId.php": {
        "key": 94009043791754705,
        "is_dir": false,
        "realpath": "/app/vendor/sentry/sentry/src/EventId.php",
        "expires": 1724777085
      },
      "/app/vendor/composer/../jean85/pretty-package-versions/src": {
        "key": 9.434994950313943e+18,
        "is_dir": true,
        "realpath": "/app/vendor/jean85/pretty-package-versions/src",
        "expires": 1724777085
      },
      "/app/vendor/composer/../sentry/sentry/src/Serializer/EnvelopItems/EnvelopeItemInterface.php": {
        "key": 1.0037600243047813e+19,
        "is_dir": false,
        "realpath": "/app/vendor/sentry/sentry/src/Serializer/EnvelopItems/EnvelopeItemInterface.php",
        "expires": 1724777085
      },
      "/app/vendor/composer/../sentry/sentry/src": {
        "key": 8322071668617851429,
        "is_dir": true,
        "realpath": "/app/vendor/sentry/sentry/src",
        "expires": 1724777085
      },
      "/app/vendor/composer/../sentry/sentry/src/Severity.php": {
        "key": 1.3582131811012135e+19,
        "is_dir": false,
        "realpath": "/app/vendor/sentry/sentry/src/Severity.php",
        "expires": 1724777085
      },
      "/app/public/docs": {
        "key": 5650992460004997723,
        "is_dir": true,
        "realpath": "/app/public/docs",
        "expires": 1724777085
      },
      "/app/vendor/composer/../sentry/sentry/src/Util/JSON.php": {
        "key": 1.5143241224616065e+19,
        "is_dir": false,
        "realpath": "/app/vendor/sentry/sentry/src/Util/JSON.php",
        "expires": 1724777085
      },
      "/app/vendor/composer/../sentry/sentry/src/Serializer/Traits/BreadcrumbSeralizerTrait.php": {
        "key": 2561871025314508417,
        "is_dir": false,
        "realpath": "/app/vendor/sentry/sentry/src/Serializer/Traits/BreadcrumbSeralizerTrait.php",
        "expires": 1724777085
      },
      "/app/vendor/composer": {
        "key": 4032976807495550755,
        "is_dir": true,
        "realpath": "/app/vendor/composer",
        "expires": 1724777085
      },
      "/app/vendor/composer/../jean85/pretty-package-versions/src/Exception/VersionMissingExceptionInterface.php": {
        "key": 8063390730718990118,
        "is_dir": false,
        "realpath": "/app/vendor/jean85/pretty-package-versions/src/Exception/VersionMissingExceptionInterface.php",
        "expires": 1724777085
      },
      "/app/vendor/composer/../sentry/sentry/src/Serializer/Traits/StacktraceFrameSeralizerTrait.php": {
        "key": 1.283470655353177e+19,
        "is_dir": false,
        "realpath": "/app/vendor/sentry/sentry/src/Serializer/Traits/StacktraceFrameSeralizerTrait.php",
        "expires": 1724777085
      },
      "/app/public/docs/images": {
        "key": 1.0784815990806798e+19,
        "is_dir": true,
        "realpath": "/app/public/docs/images",
        "expires": 1724777085
      },
      "/app/vendor/composer/../sentry/sentry/src/Util/Http.php": {
        "key": 1.4179318176191566e+19,
        "is_dir": false,
        "realpath": "/app/vendor/sentry/sentry/src/Util/Http.php",
        "expires": 1724777085
      },
      "/app/vendor/composer/../sentry/sentry/src/Context": {
        "key": 1.2181631176805368e+19,
        "is_dir": true,
        "realpath": "/app/vendor/sentry/sentry/src/Context",
        "expires": 1724777085
      },
      "/app/vendor/composer/../sentry/sentry/src/Context/OsContext.php": {
        "key": 1.792637288150366e+19,
        "is_dir": false,
        "realpath": "/app/vendor/sentry/sentry/src/Context/OsContext.php",
        "expires": 1724777085
      },
      "/app/vendor/composer/../jean85": {
        "key": 8484177489321305050,
        "is_dir": true,
        "realpath": "/app/vendor/jean85",
        "expires": 1724777085
      },
      "/app/vendor/composer/../jean85/pretty-package-versions": {
        "key": 1.817422153822317e+19,
        "is_dir": true,
        "realpath": "/app/vendor/jean85/pretty-package-versions",
        "expires": 1724777085
      },
      "/app/vendor/composer/../sentry/sentry/src/Serializer": {
        "key": 1.3826839458664196e+19,
        "is_dir": true,
        "realpath": "/app/vendor/sentry/sentry/src/Serializer",
        "expires": 1724777085
      }
    }
  },
  "level": 100,
  "level_name": "DEBUG",
  "channel": "app",
  "datetime": "2024-08-27T16:34:45.678179+00:00",
  "extra": {}
}

upd:
I'll try to create a bug in PHP, but before that we'll try to find a workaround and a more stable solution.

ok i did it php/php-src#15600

g-ra added the bug Something isn't working label Aug 27, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Intermittent File Write Failures with fwrite #1007

Intermittent File Write Failures with fwrite #1007

g-ra commented Aug 27, 2024 •

edited

Loading

dunglas commented Aug 27, 2024

dunglas commented Aug 27, 2024

g-ra commented Aug 27, 2024 •

edited

Loading

Intermittent File Write Failures with fwrite #1007

Intermittent File Write Failures with fwrite #1007

Comments

g-ra commented Aug 27, 2024 • edited Loading

What happened?

Build Type

Worker Mode

Operating System

CPU Architecture

PHP configuration

Relevant log output

dunglas commented Aug 27, 2024

dunglas commented Aug 27, 2024

g-ra commented Aug 27, 2024 • edited Loading

g-ra commented Aug 27, 2024 •

edited

Loading

g-ra commented Aug 27, 2024 •

edited

Loading