ftp put failes on TwoFTP

[Falko Kellner]

I am trying to "bzr init" a remote branch on a host running twoftpd as a ftp server.
All directories are created (with good permission settings), but putting the info file to the temporary lock-directory failes.

I have the same problem if I init the bzr on the server directly, check it out and then commit changes.
I try doing this the whole day now with different versions of bzr even. Also I can find bugs that look related but not with this special error.. so - would be glad to hear some advice/see a fix :)

here's my bzr log.

Do 2009-08-13 10:51:51 +0200
0.011 bzr arguments: [u'init', u'log+ftp://my_username@my-host/my_project']
0.016 looking for plugins in /home/myusername/.bazaar/plugins
0.054 looking for plugins in /usr/lib/python2.5/site-packages/bzrlib/plugins
0.054 Plugin name bzrtools already loaded
0.063 encoding stdout as sys.stdout encoding 'ISO-8859-15'
0.074 mkdir ftp://my_username@my-host/my_project
0.074 FTP mkd: /my_project
0.074 Constructing FTP instance against ('my-host', None, 'my_username', '********', False)
1.220 encoding stdout as sys.stdout encoding 'ISO-8859-15'
6.687 --> None
6.688 get ftp://my_username@my-host/my_project/.bzr/branch-format
6.688 FTP get: /my_project/.bzr/branch-format
6.804 --> No such file: 'ftp://my_username@my-host/my_project/.bzr/branch-format': 550 Could not open input file: No such file or directory
6.804 0.116s
6.804 mkdir ftp://my_username@my-host/my_project
6.804 FTP mkd: /my_project
6.804 Constructing FTP instance against ('my-host', None, 'my_username', '********', False)
7.951 encoding stdout as sys.stdout encoding 'ISO-8859-15'
11.556 --> File exists: '/my_project': 550 Could not create directory: File exists
11.556 4.752s
11.556 stat ftp://my_username@my-host/my_project
11.556 FTP stat: /my_project
11.584 --> <bzrlib.transport.ftp.FtpStatResult object at 0xa08f4ec>
11.584 mkdir ftp://my_username@my-host/my_project/.bzr {'mode': 448}
11.584 FTP mkd: /my_project/.bzr
11.613 FTP site chmod: setting permissions to 0700 on /my_project/.bzr
11.642 --> None
11.642 stat ftp://my_username@my-host/my_project/.bzr
11.642 FTP stat: /my_project/.bzr
11.670 --> <bzrlib.transport.ftp.FtpStatResult object at 0xa08f6ac>
11.670 mkdir ftp://my_username@my-host/my_project/.bzr/branch-lock {'mode': 448}
11.670 FTP mkd: /my_project/.bzr/branch-lock
11.699 FTP site chmod: setting permissions to 0700 on /my_project/.bzr/branch-lock
11.727 --> None
11.727 mkdir ftp://my_username@my-host/my_project/.bzr/branch-lock/f5aryy5cpv.tmp
11.727 FTP mkd: /my_project/.bzr/branch-lock/f5aryy5cpv.tmp
11.756 --> None
11.757 put_bytes_non_atomic ftp://my_username@my-host/my_project/.bzr/branch-lock/f5aryy5cpv.tmp/info 'hostname: heaven\nnonce: 8u0jy18idetse3eo8b68\npid: 4868\nstart_ti...
11.757 FTP put: /my_project/.bzr/branch-lock/f5aryy5cpv.tmp/info
[ 4868] 2009-08-13 10:52:03.327 WARNING: Failure during ftp PUT. Deleting temporary file.
[ 4868] 2009-08-13 10:52:03.357 WARNING: FTP temporary error: 450 Could not locate file.. Retrying.
11.997 Constructing FTP instance against ('my-host', None, 'my_username', '********', False)
13.273 FTP put: /my_project/.bzr/branch-lock/f5aryy5cpv.tmp/info
[ 4868] 2009-08-13 10:52:04.859 WARNING: Failure during ftp PUT. Deleting temporary file.
[ 4868] 2009-08-13 10:52:04.889 WARNING: FTP temporary error: 450 Could not locate file.. Retrying.
13.530 Constructing FTP instance against ('my-host', None, 'my_username', '********', False)
14.639 -->
14.639 2.882s
14.643 Traceback (most recent call last):
  File "/usr/lib/python2.5/site-packages/bzrlib/commands.py", line 835, in exception_to_return_code
    return the_callable(*args, **kwargs)
  File "/usr/lib/python2.5/site-packages/bzrlib/commands.py", line 1030, in run_bzr
    ret = run(*run_argv)
  File "/usr/lib/python2.5/site-packages/bzrlib/commands.py", line 647, in run_argv_aliases
    return self.run(**all_cmd_args)
  File "/usr/lib/python2.5/site-packages/bzrlib/builtins.py", line 1709, in run
    possible_transports=[to_transport])
  File "/usr/lib/python2.5/site-packages/bzrlib/bzrdir.py", line 518, in create_branch_convenience
    bzrdir = BzrDir.create(base, format, possible_transports)
  File "/usr/lib/python2.5/site-packages/bzrlib/bzrdir.py", line 306, in create
    return format.initialize_on_transport(t)
  File "/usr/lib/python2.5/site-packages/bzrlib/bzrdir.py", line 1850, in initialize_on_transport
    return self._initialize_on_transport_vfs(transport)
  File "/usr/lib/python2.5/site-packages/bzrlib/bzrdir.py", line 1987, in _initialize_on_transport_vfs
    control_files.lock_write()
  File "/usr/lib/python2.5/site-packages/bzrlib/lockable_files.py", line 279, in lock_write
    token_from_lock = self._lock.lock_write(token=token)
  File "/usr/lib/python2.5/site-packages/bzrlib/lockdir.py", line 579, in lock_write
    return self.wait_lock()
  File "/usr/lib/python2.5/site-packages/bzrlib/lockdir.py", line 503, in wait_lock
    return self.attempt_lock()
  File "/usr/lib/python2.5/site-packages/bzrlib/lockdir.py", line 464, in attempt_lock
    result = self._attempt_lock()
  File "/usr/lib/python2.5/site-packages/bzrlib/lockdir.py", line 222, in _attempt_lock
    tmpname = self._create_pending_dir()
  File "/usr/lib/python2.5/site-packages/bzrlib/lockdir.py", line 286, in _create_pending_dir
    info_bytes)
  File "/usr/lib/python2.5/site-packages/bzrlib/transport/log.py", line 56, in _hook
    return self._log_and_call(hookname, relpath, *args, **kw)
  File "/usr/lib/python2.5/site-packages/bzrlib/transport/log.py", line 95, in _log_and_call
    return self._call_and_log_result(methodname, (relpath,) + args, kwargs)
  File "/usr/lib/python2.5/site-packages/bzrlib/transport/log.py", line 100, in _call_and_log_result
    result = getattr(self._decorated, methodname)(*args, **kwargs)
  File "/usr/lib/python2.5/site-packages/bzrlib/transport/__init__.py", line 899, in put_bytes_non_atomic
    dir_mode=dir_mode)
  File "/usr/lib/python2.5/site-packages/bzrlib/transport/__init__.py", line 941, in put_file_non_atomic
    return self.put_file(relpath, f, mode=mode)
  File "/usr/lib/python2.5/site-packages/bzrlib/transport/ftp/__init__.py", line 338, in put_file
    self.put_file(relpath, fp, mode, retries+1)
  File "/usr/lib/python2.5/site-packages/bzrlib/transport/ftp/__init__.py", line 337, in put_file
    self._reconnect()
  File "/usr/lib/python2.5/site-packages/bzrlib/transport/ftp/__init__.py", line 160, in _reconnect
    connection, credentials = self._create_connection(credentials)
  File "/usr/lib/python2.5/site-packages/bzrlib/transport/ftp/__init__.py", line 139, in _create_connection
    connection.connect(host=self._host, port=self._port)
  File "/usr/lib/python2.5/ftplib.py", line 132, in connect
    self.welcome = self.getresp()
  File "/usr/lib/python2.5/ftplib.py", line 207, in getresp
    resp = self.getmultiline()
  File "/usr/lib/python2.5/ftplib.py", line 193, in getmultiline
    line = self.getline()
  File "/usr/lib/python2.5/ftplib.py", line 183, in getline
    if not line: raise EOFError
EOFError

14.645 return code 4

greetz
Falko

[Martin Pool (mbp)]

Could you see if there's any error in the ftp server's log file?

--
Martin <http://launchpad.net/~mbp/>

[Martin Pool (mbp)]

I'm sorry you wasted a day on this.

It looks like we're just getting an unidentified error from the server when this occurs. I'm not sure what we can do next without either getting a network trace or a log file from the server.

[Falko Kellner (fkellner)]

Here is the complete ftp conversation (of one try of it all). Looking at it, it is a problem with the rename command after all.

To my limited knowledge about ftp-protocol, the line
RNFR /funracer/.bzr/branch-lock/wfs5nvw9af.tmp/info

should have been two lines like
RNFR /funracer/.bzr/branch-lock/wfs5nvw9af.tmp/info.tmp.1250162586.862513065.6404.1888585727
RNTO /funracer/.bzr/branch-lock/wfs5nvw9af.tmp/info

so that the file ../info.tmp.xyz gets ReNamedTO ../info.
If file given in RNFR does not exist, the server does not know what to rename and, yeah..

220-TwoFTPd server ready.
220 Authenticate first.
USER xxxxxxxxxx
331 Send PASS.
PASS xxxxxxxx
230 Ready to transfer files.
TYPE I
200 Transfer mode changed to BINARY.
TYPE I
200 Transfer mode changed to BINARY.
PASV
227 Entering Passive Mode (88,84,137,167,164,124).
STOR /funracer/.bzr/branch-lock/wfs5nvw9af.tmp/info.tmp.1250162586.862513065.6404.1888585727
150 Opened data connection.
226 File received successfully (0 bytes received).
RNFR /funracer/.bzr/branch-lock/wfs5nvw9af.tmp/info
450 Could not locate file.
DELE /funracer/.bzr/branch-lock/wfs5nvw9af.tmp/info.tmp.1250162586.862513065.6404.1888585727
250 File removed successfully.

[Falko Kellner (fkellner)]

not sure why this seems to be working for everyone, maybe no one is running debian testing nowadays :)
Here the default python version is 2.5, maybe this is the issue? i dont know, but it's the only reason i could think of why no one else experiences this problem..

in /bzrlib/transport/ftp/__init__.py I changed

    def _rename_and_overwrite(self, abs_from, abs_to, f):
        """Do a fancy rename on the remote server.
        Using the implementation provided by osutils.
        """
        osutils.fancy_rename(abs_from, abs_to,
            rename_func=lambda p1, p2: self._rename(p1, p2, f),
            unlink_func=lambda p: self._delete(p, f))

to

    def _rename_and_overwrite(self, abs_from, abs_to, f):
        """ fancy super rename is broken, simply do it! """
        self._rename(abs_from, abs_to, f)

and it works! yay! I never did anything in python, so replacing stuff i did not understand with stuff i do understand seemed the right way to solve this. Please look into the fancy rename function - it does not work!

[Falko Kellner (fkellner)]

ps: also does not work on suse11.1