PHPのFTP(S)通信でphp_connect_nonb() failed: Operation now in progress (115)

現象

<?php
$c = ftp_ssl_connect('<host name>', 21);
ftp_login($c, '<user name>', '<password>');
ftp_pasv($c, true);
ftp_put($c, 'test', 'hoge', FTP_BINARY);

こんな感じでFTP(S)でファイルを送ろうとすると以下のエラーがでて送信に失敗することがある。
(PHP v 7.2.12で確認)

PHP Warning:  ftp_put(): php_connect_nonb() failed: Operation now in progress (115)

原因

エラーメッセージを見ても何が起きているのかさっぱりわからないのでPHPのコードを読んで見る。
（結論が先に知りたい人は対処法へどうぞ）

ext/ftp/ftp.c

if (php_connect_nonb(fd, (struct sockaddr*) &ftp->pasvaddr, size, &tv) == -1) {
    php_error_docref(NULL, E_WARNING, "php_connect_nonb() failed: %s (%d)", strerror(errno), errno);
    goto bail;
}

エラーを出しているのはこのへんで見ての通りphp_connect_nonb()関数がエラーになっていると推測できる

php_connect_nonb()はマクロになっていて

main/php_network.h

#define php_connect_nonb(sock, addr, addrlen, timeout) \
	php_network_connect_socket((sock), (addr), (addrlen), 0, (timeout), NULL, NULL)

実態はここにある。

main/network.c

PHPAPI int php_network_connect_socket(php_socket_t sockfd,
		const struct sockaddr *addr,
		socklen_t addrlen,
		int asynchronous,
		struct timeval *timeout,
		zend_string **error_string,
		int *error_code)
{
	php_non_blocking_flags_t orig_flags;
	int n;
	int error = 0;
	socklen_t len;
	int ret = 0;

	SET_SOCKET_BLOCKING_MODE(sockfd, orig_flags);

	if ((n = connect(sockfd, addr, addrlen)) != 0) {
		error = php_socket_errno();

		if (error_code) {
			*error_code = error;
		}

		if (error != EINPROGRESS) {
			if (error_string) {
				*error_string = php_socket_error_str(error);
			}

			return -1;
		}
		if (asynchronous && error == EINPROGRESS) {
			/* this is fine by us */
			return 0;
		}
	}

	if (n == 0) {
		goto ok;
	}
# ifdef PHP_WIN32
	/* The documentation for connect() says in case of non-blocking connections
	 * the select function reports success in the writefds set and failure in
	 * the exceptfds set. Indeed, using PHP_POLLREADABLE results in select
	 * failing only due to the timeout and not immediately as would be
	 * expected when a connection is actively refused. This way,
	 * php_pollfd_for will return a mask with POLLOUT if the connection
	 * is successful and with POLLPRI otherwise. */
	if ((n = php_pollfd_for(sockfd, POLLOUT|POLLPRI, timeout)) == 0) {
#else
	if ((n = php_pollfd_for(sockfd, PHP_POLLREADABLE|POLLOUT, timeout)) == 0) {
#endif
		error = PHP_TIMEOUT_ERROR_VALUE;
	}

	if (n > 0) {
		len = sizeof(error);
		/*
		   BSD-derived systems set errno correctly
		   Solaris returns -1 from getsockopt in case of error
		   */
		if (getsockopt(sockfd, SOL_SOCKET, SO_ERROR, (char*)&error, &len) != 0) {
			ret = -1;
		}
	} else {
		/* whoops: sockfd has disappeared */
		ret = -1;
	}

ok:
	if (!asynchronous) {
		/* back to blocking mode */
		RESTORE_SOCKET_BLOCKING_MODE(sockfd, orig_flags);
	}

	if (error_code) {
		*error_code = error;
	}

	if (error) {
		ret = -1;
		if (error_string) {
			*error_string = php_socket_error_str(error);
		}
	}
	return ret;
}

どうやらOperation now in progress (115)はEINPROGRESSから来ているらしい。
常に非同期でconnectするため最初のconnectでEINPROGRESSが帰るのは正常だが、
asynchronous=trueの場合その後同期処理のためにpollで接続完了を待つ。
だがpollはエラーが起きてもerrnoを更新しないため、接続に失敗したときerrno=EINPROGRESSの状態で返ってしまっているように見える。

再現手順

適当なFTPSサーバーを用意しコントロールコネクション用のポートを開けつつ、データコネクション用のポートをすべて閉めてそこに接続してファイルを送信しようとすると該当のWARNINGが出る。ちなみにコントロールコネクション用のポートを閉めた場合も当然失敗するが、そのときはWARNINGが出ない。

対処法

要はFTPサーバーとのデータコネクションの接続に失敗したということなのでそれに応じた対処をするのが良いと思われる。
筆者の場合はたまにしか起きないので、リトライを入れるようにしたら問題なくなった。