From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.2 (2018-09-13) on dcvr.yhbt.net X-Spam-Level: X-Spam-Status: No, score=-2.6 required=3.0 tests=BAYES_00,DKIM_ADSP_CUSTOM_MED, FORGED_GMAIL_RCVD,FREEMAIL_FORGED_FROMDOMAIN,FREEMAIL_FROM, HEADER_FROM_DIFFERENT_DOMAINS,MAILING_LIST_MULTI,RCVD_IN_DNSWL_MED, SPF_HELO_NONE,SPF_PASS,UNPARSEABLE_RELAY shortcircuit=no autolearn=no autolearn_force=no version=3.4.2 Received: from neon.ruby-lang.org (neon.ruby-lang.org [221.186.184.75]) by dcvr.yhbt.net (Postfix) with ESMTP id A877A1F55B for ; Mon, 18 May 2020 00:21:48 +0000 (UTC) Received: from neon.ruby-lang.org (localhost [IPv6:::1]) by neon.ruby-lang.org (Postfix) with ESMTP id 67B741209B5; Mon, 18 May 2020 09:21:21 +0900 (JST) Received: from o1678948x4.outbound-mail.sendgrid.net (o1678948x4.outbound-mail.sendgrid.net [167.89.48.4]) by neon.ruby-lang.org (Postfix) with ESMTPS id C113D1209AD for ; Mon, 18 May 2020 09:21:18 +0900 (JST) Received: by filter0072p3las1.sendgrid.net with SMTP id filter0072p3las1-27465-5EC1D50E-3 2020-05-18 00:21:34.105943849 +0000 UTC m=+184896.574280760 Received: from herokuapp.com (unknown) by geopod-ismtpd-4-0 (SG) with ESMTP id 8EKJz3M7QMOCc9R_z5DSkQ for ; Mon, 18 May 2020 00:21:33.954 +0000 (UTC) Date: Mon, 18 May 2020 00:21:34 +0000 (UTC) From: koshigoeb@gmail.com Message-ID: References: Mime-Version: 1.0 X-Redmine-MailingListIntegration-Message-Ids: 74211 X-Redmine-Project: ruby-master X-Redmine-Issue-Tracker: Bug X-Redmine-Issue-Id: 16780 X-Redmine-Issue-Author: rgerard X-Redmine-Issue-Assignee: naruse X-Redmine-Sender: koshigoe X-Mailer: Redmine X-Redmine-Host: bugs.ruby-lang.org X-Redmine-Site: Ruby Issue Tracking System X-Auto-Response-Suppress: All Auto-Submitted: auto-generated X-SG-EID: =?us-ascii?Q?bzD+HcsK5qP+djwFuO0RaRXwrWN5UIv70e24U2U6Ps095BZweKuSSp7G9e5OkQ?= =?us-ascii?Q?o1fnesPIFRk+d=2FZA9g=2F8T7GiwF1RIYQ8Zv1MM8e?= =?us-ascii?Q?0OZ+0=2FohU6YikQi0HtGsOBfx6MEGwcSk3ZcL8o3?= =?us-ascii?Q?h77=2F4um8Tu7T=2Ff9s8XaxMhbpt8xM=2F4jqTWmBKWY?= =?us-ascii?Q?veaBBj0jamPcv4rklc3Tr3UmIxea=2FmL6eQA=3D=3D?= To: ruby-core@ruby-lang.org X-ML-Name: ruby-core X-Mail-Count: 98419 Subject: [ruby-core:98419] [Ruby master Bug#16780] Net::FTP PUT command issuing Net::ReadTimeout too quickly X-BeenThere: ruby-core@ruby-lang.org X-Mailman-Version: 2.1.15 Precedence: list Reply-To: Ruby developers List-Id: Ruby developers List-Unsubscribe: , List-Post: List-Help: List-Subscribe: , Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: 7bit Errors-To: ruby-core-bounces@ruby-lang.org Sender: "ruby-core" Issue #16780 has been updated by koshigoe (Masataka SUZUKI). I'm facing the same problem. The `Net::FTP#close` suppresses exception about `Socket#shutdown` and `Socket#read`. - https://github.com/ruby/ruby/blob/a0c7c23c9cec0d0ffcba012279cd652d28ad5bf3/lib/net/ftp.rb#L1340-L1355 ~~~ruby def close if @sock and not @sock.closed? begin @sock.shutdown(Socket::SHUT_WR) rescue nil orig, self.read_timeout = self.read_timeout, 3 @sock.read rescue nil ensure @sock.close self.read_timeout = orig end end end ~~~ Should I do the same when closing data connection? ~~~diff diff --git a/lib/net/ftp.rb b/lib/net/ftp.rb index d1e545c0c8..610027dc38 100644 --- a/lib/net/ftp.rb +++ b/lib/net/ftp.rb @@ -634,9 +634,9 @@ def retrbinary(cmd, blocksize, rest_offset = nil) # :yield: data while data = conn.read(blocksize) yield(data) end - conn.shutdown(Socket::SHUT_WR) + conn.shutdown(Socket::SHUT_WR) rescue nil conn.read_timeout = 1 - conn.read + conn.read rescue nil ensure conn.close if conn end @@ -659,9 +659,9 @@ def retrlines(cmd) # :yield: line while line = conn.gets yield(line.sub(/\r?\n\z/, ""), !line.match(/\n\z/).nil?) end - conn.shutdown(Socket::SHUT_WR) + conn.shutdown(Socket::SHUT_WR) rescue nil conn.read_timeout = 1 - conn.read + conn.read rescue nil ensure conn.close if conn end @@ -688,9 +688,9 @@ def storbinary(cmd, file, blocksize, rest_offset = nil) # :yield: data conn.write(buf) yield(buf) if block_given? end - conn.shutdown(Socket::SHUT_WR) + conn.shutdown(Socket::SHUT_WR) rescue nil conn.read_timeout = 1 - conn.read + conn.read rescue nil ensure conn.close if conn end @@ -724,9 +724,9 @@ def storlines(cmd, file) # :yield: line conn.write(buf) yield(buf) if block_given? end - conn.shutdown(Socket::SHUT_WR) + conn.shutdown(Socket::SHUT_WR) rescue nil conn.read_timeout = 1 - conn.read + conn.read rescue nil ensure conn.close if conn end ~~~ ---------------------------------------- Bug #16780: Net::FTP PUT command issuing Net::ReadTimeout too quickly https://bugs.ruby-lang.org/issues/16780#change-85689 * Author: rgerard (Ryan Gerard) * Status: Assigned * Priority: Normal * Assignee: naruse (Yui NARUSE) * ruby -v: 2.7.1 * Backport: 2.5: UNKNOWN, 2.6: UNKNOWN, 2.7: UNKNOWN ---------------------------------------- This is my first time writing up an issue for this community, so I apologize if this is written in an abnormal way than your normal issues. We recently upgraded from ruby 2.6.5 to 2.7.1. Almost immediately, we started seeing issues with some of our application code that utilizes Net::FTP. All calls to #put to an external FTP server we communicate with were resulting in a Net::ReadTimeout exception being throw. Upon examination of the external FTP server, we can see that the file was successfully transferred, although the Net::ReadTimeout exception begin thrown caused confusion on our end. Looking over the changes that were part of the ruby 2.7.0 release, I believe this commit (https://github.com/ruby/ruby/commit/5be34d6a3310065850c0c530db6936415124b5d9), which was a fix for this bug (https://bugs.ruby-lang.org/issues/16413) is the root of the issue. I translated the japanese, and I understand that the change to add the `begin` and `ensure` blocks were to make sure the connection was closed in case an exception is thrown during the transfer. However, the additional change to the connection read_timeout to 1 second was a little puzzling. I can see that this logic was copied from `retrbinary` and `retrlines`, but I'm uncertain why the connection read_timeout should be changed to 1 second. I believe the right fix is to remove the change to the connection read_timeout. Here is the stack trace for the exception we're getting during the call to #put: ``` ruby Net::ReadTimeout with # /usr/local/lib/ruby/2.7.0/net/protocol.rb:217:in `rbuf_fill' /usr/local/lib/ruby/2.7.0/net/protocol.rb:159:in `read' /usr/local/lib/ruby/2.7.0/net/ftp.rb:1475:in `read' /usr/local/lib/ruby/2.7.0/net/ftp.rb:693:in `block (2 levels) in storbinary' /usr/local/lib/ruby/2.7.0/net/ftp.rb:308:in `with_binary' /usr/local/lib/ruby/2.7.0/net/ftp.rb:684:in `block in storbinary' /usr/local/lib/ruby/2.7.0/monitor.rb:202:in `synchronize' /usr/local/lib/ruby/2.7.0/monitor.rb:202:in `mon_synchronize' /usr/local/lib/ruby/2.7.0/net/ftp.rb:683:in `storbinary' /usr/local/lib/ruby/2.7.0/net/ftp.rb:843:in `putbinaryfile' /usr/local/lib/ruby/2.7.0/net/ftp.rb:871:in `put' ``` -- https://bugs.ruby-lang.org/