事象
ensure
節を使って Net::FTP#close
しても、コネクションが残ってしまう事象に遭遇。
$ ruby -v
ruby 2.6.5p114 (2019-10-01 revision 67812) [x86_64-darwin18]
原因
Net::FTP#put
で確立するデータコネクションが #write
などで例外が発生した時に切断されていない模様。
# https://github.com/ruby/ruby/blob/00f4c13e22967de1d7e42085b2fc32bf6718f580/lib/net/ftp.rb#L683-L707
def storbinary(cmd, file, blocksize, rest_offset = nil) # :yield: data
if rest_offset
file.seek(rest_offset, IO::SEEK_SET)
end
synchronize do
with_binary(true) do
conn = transfercmd(cmd)
loop do
buf = file.read(blocksize)
break if buf == nil
conn.write(buf)
yield(buf) if block_given?
end
conn.close
voidresp
end
end
rescue Errno::EPIPE
# EPIPE, in this case, means that the data connection was unexpectedly
# terminated. Rather than just raising EPIPE to the caller, check the
# response on the control connection. If getresp doesn't raise a more
# appropriate exception, re-raise the original exception.
getresp
raise
end
再現
適当な FTP サーバーを動かして確認。
$ docker run --rm \
-p 20-21:20-21 \
-p 21100-21110:21100-21110 \
-e FTP_USER=user \
-e FTP_PASS=pass \
-e PASV_ADDRESS=localhost \
-e PASV_MIN_PORT=21100 \
-e PASV_MAX_PORT=21110 \
fauria/vsftpd
再現スクリプト
require 'net/ftp'
def upload
ftp = Net::FTP.new
ftp.read_timeout = 0.1
ftp.passive = true
ftp.connect('localhost')
ftp.login('user', 'pass')
i = 0
ftp.put(__FILE__, '/uploaded', 1) do |data|
i += 1
raise 'Bomb' if i > 3
end
rescue => e
puts e.message
ensure
unless ftp.closed?
ftp.close
puts 'closed.'
end
end
11.times { upload }
puts 'wait'
loop {}
$ ruby test.rb
Bomb
closed.
Net::ReadTimeout with #<Socket:fd 11>
closed.
Net::ReadTimeout with #<Socket:fd 11>
closed.
Net::ReadTimeout with #<Socket:fd 11>
closed.
Net::ReadTimeout with #<Socket:fd 11>
closed.
Net::ReadTimeout with #<Socket:fd 11>
closed.
Net::ReadTimeout with #<Socket:fd 11>
closed.
Net::ReadTimeout with #<Socket:fd 11>
closed.
Net::ReadTimeout with #<Socket:fd 11>
closed.
Net::ReadTimeout with #<Socket:fd 11>
closed.
Net::ReadTimeout with #<Socket:fd 11>
closed.
wait
コネクション
$ lsof -i:21100-21110
Before
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
com.docke 1354 koshigoe 17u IPv6 0x370c9672434eb1d5 0t0 TCP *:21110 (LISTEN)
com.docke 1354 koshigoe 19u IPv6 0x370c9672434eac15 0t0 TCP *:21109 (LISTEN)
com.docke 1354 koshigoe 21u IPv6 0x370c9672434e9ad5 0t0 TCP *:21108 (LISTEN)
com.docke 1354 koshigoe 23u IPv6 0x370c967241a28e15 0t0 TCP *:21107 (LISTEN)
com.docke 1354 koshigoe 25u IPv6 0x370c967241a2aad5 0t0 TCP *:21106 (LISTEN)
com.docke 1354 koshigoe 29u IPv6 0x370c967241a29f55 0t0 TCP *:21105 (LISTEN)
com.docke 1354 koshigoe 31u IPv6 0x370c9672557d9c15 0t0 TCP *:21104 (LISTEN)
com.docke 1354 koshigoe 33u IPv6 0x370c9672557d9655 0t0 TCP *:21103 (LISTEN)
com.docke 1354 koshigoe 35u IPv6 0x370c9672557d7f55 0t0 TCP *:21102 (LISTEN)
com.docke 1354 koshigoe 37u IPv6 0x370c9672385aae15 0t0 TCP *:21101 (LISTEN)
com.docke 1354 koshigoe 39u IPv6 0x370c9672385ae1d5 0t0 TCP *:21100 (LISTEN)
After
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
com.docke 1354 koshigoe 17u IPv6 0x370c9672434eb1d5 0t0 TCP *:21110 (LISTEN)
com.docke 1354 koshigoe 19u IPv6 0x370c9672434eac15 0t0 TCP *:21109 (LISTEN)
com.docke 1354 koshigoe 21u IPv6 0x370c9672434e9ad5 0t0 TCP *:21108 (LISTEN)
com.docke 1354 koshigoe 23u IPv6 0x370c967241a28e15 0t0 TCP *:21107 (LISTEN)
com.docke 1354 koshigoe 25u IPv6 0x370c967241a2aad5 0t0 TCP *:21106 (LISTEN)
com.docke 1354 koshigoe 29u IPv6 0x370c967241a29f55 0t0 TCP *:21105 (LISTEN)
com.docke 1354 koshigoe 31u IPv6 0x370c9672557d9c15 0t0 TCP *:21104 (LISTEN)
com.docke 1354 koshigoe 33u IPv6 0x370c9672557d9655 0t0 TCP *:21103 (LISTEN)
com.docke 1354 koshigoe 35u IPv6 0x370c9672557d7f55 0t0 TCP *:21102 (LISTEN)
com.docke 1354 koshigoe 37u IPv6 0x370c9672385aae15 0t0 TCP *:21101 (LISTEN)
com.docke 1354 koshigoe 39u IPv6 0x370c9672385ae1d5 0t0 TCP *:21100 (LISTEN)
com.docke 1354 koshigoe 45u IPv6 0x370c9672557d6e15 0t0 TCP localhost:21104->localhost:64487 (ESTABLISHED)
com.docke 1354 koshigoe 47u IPv6 0x370c9672385adc15 0t0 TCP localhost:21106->localhost:64489 (ESTABLISHED)
com.docke 1354 koshigoe 49u IPv6 0x370c9672434ea095 0t0 TCP localhost:21103->localhost:64491 (ESTABLISHED)
com.docke 1354 koshigoe 51u IPv6 0x370c967253fc5095 0t0 TCP localhost:21100->localhost:64493 (ESTABLISHED)
com.docke 1354 koshigoe 53u IPv6 0x370c9672589ebc15 0t0 TCP localhost:21105->localhost:64495 (ESTABLISHED)
com.docke 1354 koshigoe 55u IPv6 0x370c9672589eb655 0t0 TCP localhost:21110->localhost:64497 (ESTABLISHED)
com.docke 1354 koshigoe 57u IPv6 0x370c967257775c15 0t0 TCP localhost:21107->localhost:64499 (ESTABLISHED)
com.docke 1354 koshigoe 59u IPv6 0x370c9672557d73d5 0t0 TCP localhost:21108->localhost:64501 (ESTABLISHED)
com.docke 1354 koshigoe 61u IPv6 0x370c9672591fd515 0t0 TCP localhost:21101->localhost:64503 (ESTABLISHED)
com.docke 1354 koshigoe 63u IPv6 0x370c9672591ff1d5 0t0 TCP localhost:21109->localhost:64505 (ESTABLISHED)
com.docke 1354 koshigoe 65u IPv6 0x370c9672592dd515 0t0 TCP localhost:21102->localhost:64507 (ESTABLISHED)
ruby 59669 koshigoe 14u IPv6 0x370c9672557d9095 0t0 TCP localhost:64487->localhost:21104 (ESTABLISHED)
ruby 59669 koshigoe 15u IPv6 0x370c9672557d6855 0t0 TCP localhost:64489->localhost:21106 (ESTABLISHED)
ruby 59669 koshigoe 16u IPv6 0x370c9672434ea655 0t0 TCP localhost:64491->localhost:21103 (ESTABLISHED)
ruby 59669 koshigoe 17u IPv6 0x370c967253fc4515 0t0 TCP localhost:64493->localhost:21100 (ESTABLISHED)
ruby 59669 koshigoe 18u IPv6 0x370c9672589eaad5 0t0 TCP localhost:64495->localhost:21105 (ESTABLISHED)
ruby 59669 koshigoe 19u IPv6 0x370c9672589e9995 0t0 TCP localhost:64497->localhost:21110 (ESTABLISHED)
ruby 59669 koshigoe 20u IPv6 0x370c9672589ec1d5 0t0 TCP localhost:64499->localhost:21107 (ESTABLISHED)
ruby 59669 koshigoe 21u IPv6 0x370c967241a2a515 0t0 TCP localhost:64501->localhost:21108 (ESTABLISHED)
ruby 59669 koshigoe 22u IPv6 0x370c9672591fdad5 0t0 TCP localhost:64503->localhost:21101 (ESTABLISHED)
ruby 59669 koshigoe 23u IPv6 0x370c9672591fec15 0t0 TCP localhost:64505->localhost:21109 (ESTABLISHED)
ruby 59669 koshigoe 24u IPv6 0x370c9672591fb855 0t0 TCP localhost:64507->localhost:21102 (ESTABLISHED)
FTP サーバー(vsftpd)のプロセス
$ ps aux | grep '[v]sftpd'
Before
root 1 0.0 0.0 11700 2660 ? Ss 11:40 0:00 /bin/bash /usr/sbin/run-vsftpd.sh
root 13 0.0 0.1 53292 3860 ? S 11:40 0:00 /usr/sbin/vsftpd /etc/vsftpd/vsftpd.conf
After
root 1 0.0 0.0 11700 2660 ? Ss 11:40 0:00 /bin/bash /usr/sbin/run-vsftpd.sh
root 13 0.0 0.1 53292 3996 ? S 11:40 0:00 /usr/sbin/vsftpd /etc/vsftpd/vsftpd.conf
nobody 58 0.0 0.1 75748 4628 ? Ss 11:43 0:00 /usr/sbin/vsftpd /etc/vsftpd/vsftpd.conf
ftp 60 0.0 0.1 75848 3860 ? S 11:43 0:00 /usr/sbin/vsftpd /etc/vsftpd/vsftpd.conf
nobody 61 0.0 0.1 75748 4628 ? Ss 11:43 0:00 /usr/sbin/vsftpd /etc/vsftpd/vsftpd.conf
ftp 63 0.0 0.1 75772 3860 ? S 11:43 0:00 /usr/sbin/vsftpd /etc/vsftpd/vsftpd.conf
nobody 64 0.0 0.1 75748 4628 ? Ss 11:43 0:00 /usr/sbin/vsftpd /etc/vsftpd/vsftpd.conf
ftp 66 0.0 0.1 75772 3860 ? S 11:43 0:00 /usr/sbin/vsftpd /etc/vsftpd/vsftpd.conf
nobody 69 0.0 0.1 75748 4628 ? Ss 11:43 0:00 /usr/sbin/vsftpd /etc/vsftpd/vsftpd.conf
ftp 71 0.0 0.1 75772 3860 ? S 11:43 0:00 /usr/sbin/vsftpd /etc/vsftpd/vsftpd.conf
nobody 72 0.0 0.1 75748 4628 ? Ss 11:43 0:00 /usr/sbin/vsftpd /etc/vsftpd/vsftpd.conf
ftp 74 0.0 0.1 75772 3860 ? S 11:43 0:00 /usr/sbin/vsftpd /etc/vsftpd/vsftpd.conf
nobody 75 0.0 0.1 75748 4628 ? Ss 11:43 0:00 /usr/sbin/vsftpd /etc/vsftpd/vsftpd.conf
ftp 77 0.0 0.1 75772 3860 ? S 11:43 0:00 /usr/sbin/vsftpd /etc/vsftpd/vsftpd.conf
nobody 78 0.0 0.1 75748 4632 ? Ss 11:43 0:00 /usr/sbin/vsftpd /etc/vsftpd/vsftpd.conf
ftp 80 0.0 0.1 75772 3864 ? S 11:43 0:00 /usr/sbin/vsftpd /etc/vsftpd/vsftpd.conf
nobody 81 0.0 0.1 75748 4632 ? Ss 11:43 0:00 /usr/sbin/vsftpd /etc/vsftpd/vsftpd.conf
ftp 83 0.0 0.1 75772 3864 ? S 11:43 0:00 /usr/sbin/vsftpd /etc/vsftpd/vsftpd.conf
nobody 84 0.0 0.1 75748 4632 ? Ss 11:43 0:00 /usr/sbin/vsftpd /etc/vsftpd/vsftpd.conf
ftp 86 0.0 0.1 75772 3864 ? S 11:43 0:00 /usr/sbin/vsftpd /etc/vsftpd/vsftpd.conf
nobody 87 0.0 0.1 75748 4632 ? Ss 11:43 0:00 /usr/sbin/vsftpd /etc/vsftpd/vsftpd.conf
ftp 89 0.0 0.1 75772 3864 ? S 11:43 0:00 /usr/sbin/vsftpd /etc/vsftpd/vsftpd.conf
nobody 90 0.0 0.1 75748 4632 ? Ss 11:43 0:00 /usr/sbin/vsftpd /etc/vsftpd/vsftpd.conf
ftp 92 0.0 0.1 75772 3864 ? S 11:43 0:00 /usr/sbin/vsftpd /etc/vsftpd/vsftpd.conf
対策
報告(相談)場所に迷った結果、Ruby Issue Tracking System に駆け込んでしまった。