[Bug]: PHP 8.3.13 ftp_fput() gets "Interrupted system call error" unless we use '-d ddtrace.disabled=1' as agument to PHP process call

[bravoman]

Bug report

These were our logs when we started out investigating our FTP upload issue:

12:52:58 WARNING   [php] Warning: ftp_fput(): Interrupted system call ["exception" => ErrorException { …}]
12:52:59 WARNING   [php] Warning: ftp_fput(): Connection timed out ["exception" => ErrorException { …}]
12:52:59 WARNING   [php] Warning: ftp_fput(): Accepted data connection ["exception" => ErrorException { …}]
{"message":"Warning: ftp_fput(): Interrupted system call","context":{"exception":{"class":"ErrorException","message":"Warning: ftp_fput(): Interrupted system call","code":0,"file":"/var/www/aud.portal.medido.com/releases/2.5.7/vendor/league/flysystem-ftp/FtpAdapter.php:171"}},"level":300,"level_name":"WARNING","channel":"php","datetime":"2024-11-14T12:52:58.057227+01:00","extra":{}}
{"message":"Warning: ftp_fput(): Connection timed out","context":{"exception":{"class":"ErrorException","message":"Warning: ftp_fput(): Connection timed out","code":0,"file":"/var/www/aud.portal.medido.com/releases/2.5.7/vendor/league/flysystem-ftp/FtpAdapter.php:171"}},"level":300,"level_name":"WARNING","channel":"php","datetime":"2024-11-14T12:52:59.137343+01:00","extra":{}}
{"message":"Warning: ftp_fput(): Accepted data connection","context":{"exception":{"class":"ErrorException","message":"Warning: ftp_fput(): Accepted data connection","code":0,"file":"/var/www/aud.portal.medido.com/releases/2.5.7/vendor/league/flysystem-ftp/FtpAdapter.php:171"}},"level":300,"level_name":"WARNING","channel":"php","datetime":"2024-11-14T12:52:59.173437+01:00","extra":{}}
{"message":"The file could not be uploaded to the ftp server.","context":{"error":"Unable to write file at location: event/daily/2024-11-14T12:52:39+01:00.csv. writing the file failed","file":"event/daily/2024-11-14T12:52:39+01:00.csv"},"level":400,"level_name":"ERROR","channel":"app","datetime":"2024-11-14T12:52:59.177240+01:00","extra":{}}
12:52:59 ERROR     [app] The file could not be uploaded to the ftp server. ["error" => "Unable to write file at location: event/daily/2024-11-14T12:52:39+01:00.csv. writing the file failed","file" => "event/daily/2024-11-14T12:52:39+01:00.csv"]
{"message":"Finished data export for collector <App\\DataExport\\Collector\\EventDataCollector> and target <App\\DataExport\\Target\\FtpDataTarget>.","context":{},"level":200,"level_name":"INFO","channel":"app","datetime":"2024-11-14T12:52:59.181522+01:00","extra":{}}
12:52:59 INFO      [app] Finished data export for collector <App\DataExport\Collector\EventDataCollector> and target <App\DataExport\Target\FtpDataTarget>.

This consistently went wrong in our process unless used something like this as we workaround php -d ddtrace.disabled=1 some-script-handling-ftp-upload.php.

PHP version

8.3.13

Tracer or profiler version

1.4.2

Installed extensions

No response

Output of phpinfo()

[PHP Modules]
bcmath
calendar
Core
ctype
curl
date
ddappsec
ddtrace
dom
exif
FFI
fileinfo
filter
ftp
gettext
hash
iconv
imap
intl
json
libxml
mbstring
mongodb
mysqli
mysqlnd
openssl
pcntl
pcre
PDO
pdo_mysql
Phar
posix
random
readline
Reflection
session
shmop
SimpleXML
soap
sockets
sodium
SPL
standard
sysvmsg
sysvsem
sysvshm
tokenizer
xml
xmlreader
xmlwriter
xsl
Zend OPcache
zip
zlib

[Zend Modules]
Zend OPcache
ddappsec
ddtrace

Upgrading from

not applicable

[bwoebi]

Hey @bravoman,

thanks for bringing this to my attention. From a preliminary analysis of the ftp extension code, it seems like PHP uses poll(2) internally, which will be interrupted by any signal arriving and return EINTR, which is what you observe. There's no built-in resumption on EINTR in the ftp extension code, which I'd classify as a bug within the ftp extension.

The tracer uses a signal to notify about new events being available, which triggers this behaviour. In particular it's used for remote config delivery. This can be disabled via datadog.remote_config_enabled=0.

I'll open a bug report on the php-src repository to have this properly fixed for ftp.

[bwoebi]

I've opened php/php-src#16800.

[bravoman]

datadog.remote_config_enabled=0 so this could be another workaround for us?

[bwoebi]

@bravoman Yes.

We also identified a workaround we can implement in dd-trace: mask signal handling as long as ftp functions are being run. I'll check tomorrow how easy it is to just quickly implement that.

[bwoebi]

Seems it was easy enough (see #2957). We'll release that early next week.