mina-ftpserver-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Roger Marshall <roger.marsh...@aetopia.com>
Subject Uploads from FireFTP failing with "java.io.EOFException: Unexpected end of ZLIB input stream"
Date Tue, 28 Jul 2009 18:01:42 GMT
Hi,

I'm finding that uploads from FireFTP are failing frequently with  
"java.io.EOFException: Unexpected end of ZLIB input stream".

FireFTP then stalls for about 30 seconds before disconnecting,  
reconnecting, and retrying the upload (this time via 'APPE' rather  
than 'STOR'), which then works.

I wondered if it could be related to http://issues.apache.org/jira/browse/FTPSERVER-316 
  (but this issue is supposed to be fixed in 1.0.2)?

Transmit and Interarchy clients for OS X seem to work fine, but they  
do not appear to send 'MODE Z'.

Any suggestions as to how I can solve the problem, or do I need to  
raise an issue?

Thanks
--
Roger



Server:
- OS X 10.5.7
- Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_19- 
b02-304)
- Clean extract of Apache FtpServer 1.0.2 Release, started via 'bin/ 
ftpd.sh res/conf/ftpd-typical.xml'

Client:
- FireFTP 1.0.5 on Firefox 3.5.1 on OS X 10.4.11
- Connecting over LAN

Server Log:

[ INFO] 2009-07-28 18:03:52,251 [] [] Refreshing  
org 
.springframework 
.context.support.FileSystemXmlApplicationContext@724a9d: display name  
[org 
.springframework 
.context.support.FileSystemXmlApplicationContext@724a9d]; startup date  
[Tue Jul 28 18:03:52 BST 2009]; root of context hierarchy
[ INFO] 2009-07-28 18:03:52,324 [] [] Loading XML bean definitions  
from file [/Users/roger/Projects/apache-ftpserver-1.0.2/res/conf/ftpd- 
typical.xml]
[ INFO] 2009-07-28 18:03:52,699 [] [] Bean factory for application  
context  
[org 
.springframework 
.context.support.FileSystemXmlApplicationContext@724a9d]:  
org 
.springframework.beans.factory.support.DefaultListableBeanFactory@b0d33c
[ INFO] 2009-07-28 18:03:52,719 [] [] Pre-instantiating singletons in  
org 
.springframework 
.beans.factory.support.DefaultListableBeanFactory@b0d33c: defining  
beans  
[org 
.apache 
.ftpserver 
.listener 
.ListenerFactory 
#0 
,org 
.apache 
.ftpserver 
.usermanager 
.PropertiesUserManagerFactory 
#0,org.apache.ftpserver.FtpServerFactory#0,myServer]; root of factory  
hierarchy
[ INFO] 2009-07-28 18:03:52,996 [] [] FTP server started
[ INFO] 2009-07-28 18:04:03,449 [] [192.168.2.120] CREATED
[ INFO] 2009-07-28 18:04:03,458 [] [192.168.2.120] OPENED
[ INFO] 2009-07-28 18:04:03,479 [] [192.168.2.120] SENT: 220 Service  
ready for new user.


[ INFO] 2009-07-28 18:04:03,484 [] [192.168.2.120] RECEIVED: USER admin
[ INFO] 2009-07-28 18:04:03,491 [admin] [192.168.2.120] SENT: 331 User  
name okay, need password for admin.


[ INFO] 2009-07-28 18:04:03,581 [admin] [192.168.2.120] RECEIVED: PASS  
*****
[ INFO] 2009-07-28 18:04:03,602 [admin] [192.168.2.120] Login success  
- admin
[ INFO] 2009-07-28 18:04:03,603 [admin] [192.168.2.120] SENT: 230 User  
logged in, proceed.


[ INFO] 2009-07-28 18:04:03,603 [admin] [192.168.2.120] RECEIVED: FEAT
[ INFO] 2009-07-28 18:04:03,605 [admin] [192.168.2.120] SENT: 211- 
Extensions supported

  SIZE

  MDTM

  REST STREAM

  LANG en;zh-tw;ja;is

  MLST Size;Modify;Type;Perm

  AUTH SSL

  AUTH TLS

  MODE Z

  UTF8

  TVFS

  MD5

  MMD5

  MFMT

211 End


[ INFO] 2009-07-28 18:04:03,606 [admin] [192.168.2.120] RECEIVED: PWD
[ INFO] 2009-07-28 18:04:03,607 [admin] [192.168.2.120] SENT: 257 "/"  
is current directory.


[ INFO] 2009-07-28 18:04:08,593 [admin] [192.168.2.120] RECEIVED: TYPE I
[ INFO] 2009-07-28 18:04:08,596 [admin] [192.168.2.120] SENT: 200  
Command TYPE okay.


[ INFO] 2009-07-28 18:04:08,674 [admin] [192.168.2.120] RECEIVED: MODE Z
[ INFO] 2009-07-28 18:04:08,680 [admin] [192.168.2.120] SENT: 200  
Command MODE okay.


[ INFO] 2009-07-28 18:04:08,680 [admin] [192.168.2.120] RECEIVED: PASV
[ INFO] 2009-07-28 18:04:08,684 [admin] [192.168.2.120] SENT: 227  
Entering Passive Mode (192,168,2,111,242,122)


[ INFO] 2009-07-28 18:04:08,687 [admin] [192.168.2.120] RECEIVED: STOR  
some_file.flv
[ INFO] 2009-07-28 18:04:10,593 [admin] [192.168.2.120] File uploaded / 
some_file.flv
[ INFO] 2009-07-28 18:04:10,594 [admin] [192.168.2.120] SENT: 150 File  
status okay; about to open data connection.


[ INFO] 2009-07-28 18:04:10,594 [admin] [192.168.2.120] SENT: 226  
Transfer complete.

.
.
.

[ INFO] 2009-07-28 18:05:14,886 [admin] [192.168.2.120] RECEIVED: TYPE I
[ INFO] 2009-07-28 18:05:14,887 [admin] [192.168.2.120] SENT: 200  
Command TYPE okay.


[ INFO] 2009-07-28 18:05:14,888 [admin] [192.168.2.120] RECEIVED: PASV
[ INFO] 2009-07-28 18:05:14,889 [admin] [192.168.2.120] SENT: 227  
Entering Passive Mode (192,168,2,111,242,132)


[ INFO] 2009-07-28 18:05:14,892 [admin] [192.168.2.120] RECEIVED: STOR  
WM Components 2.2.2.3.dmg
[ WARN] 2009-07-28 18:06:14,893 [admin] [192.168.2.120] Exception  
during data transfer, closing data connection socket
java.io.EOFException: Unexpected end of ZLIB input stream
	at java.util.zip.InflaterInputStream.fill(InflaterInputStream.java:216)
	at java.util.zip.InflaterInputStream.read(InflaterInputStream.java:134)
	at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
	at java.io.BufferedInputStream.read1(BufferedInputStream.java:256)
	at java.io.BufferedInputStream.read(BufferedInputStream.java:313)
	at java.io.FilterInputStream.read(FilterInputStream.java:90)
	at  
org 
.apache.ftpserver.impl.IODataConnection.transfer(IODataConnection.java: 
243)
	at  
org 
.apache 
.ftpserver 
.impl.IODataConnection.transferFromClient(IODataConnection.java:136)
	at org.apache.ftpserver.command.impl.STOR.execute(STOR.java:146)
	at  
org 
.apache 
.ftpserver 
.impl.DefaultFtpHandler.messageReceived(DefaultFtpHandler.java:210)
	at  
org 
.apache 
.ftpserver 
.listener.nio.FtpHandlerAdapter.messageReceived(FtpHandlerAdapter.java: 
61)
	at org.apache.mina.core.filterchain.DefaultIoFilterChain 
$TailFilter.messageReceived(DefaultIoFilterChain.java:721)
	at  
org 
.apache 
.mina 
.core 
.filterchain 
.DefaultIoFilterChain 
.callNextMessageReceived(DefaultIoFilterChain.java:433)
	at org.apache.mina.core.filterchain.DefaultIoFilterChain.access 
$1200(DefaultIoFilterChain.java:47)
	at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl 
$1.messageReceived(DefaultIoFilterChain.java:801)
	at  
org 
.apache 
.ftpserver 
.listener.nio.FtpLoggingFilter.messageReceived(FtpLoggingFilter.java:85)
	at  
org 
.apache 
.mina 
.core 
.filterchain 
.DefaultIoFilterChain 
.callNextMessageReceived(DefaultIoFilterChain.java:433)
	at org.apache.mina.core.filterchain.DefaultIoFilterChain.access 
$1200(DefaultIoFilterChain.java:47)
	at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl 
$1.messageReceived(DefaultIoFilterChain.java:801)
	at  
org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java: 
71)
	at  
org 
.apache 
.mina.filter.logging.MdcInjectionFilter.filter(MdcInjectionFilter.java: 
136)
	at  
org 
.apache 
.mina 
.filter.util.CommonEventFilter.messageReceived(CommonEventFilter.java: 
70)
	at  
org 
.apache 
.mina 
.core 
.filterchain 
.DefaultIoFilterChain 
.callNextMessageReceived(DefaultIoFilterChain.java:433)
	at org.apache.mina.core.filterchain.DefaultIoFilterChain.access 
$1200(DefaultIoFilterChain.java:47)
	at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl 
$1.messageReceived(DefaultIoFilterChain.java:801)
	at org.apache.mina.filter.codec.ProtocolCodecFilter 
$ProtocolDecoderOutputImpl.flush(ProtocolCodecFilter.java:375)
	at  
org 
.apache 
.mina 
.filter 
.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:229)
	at  
org 
.apache 
.mina 
.core 
.filterchain 
.DefaultIoFilterChain 
.callNextMessageReceived(DefaultIoFilterChain.java:433)
	at org.apache.mina.core.filterchain.DefaultIoFilterChain.access 
$1200(DefaultIoFilterChain.java:47)
	at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl 
$1.messageReceived(DefaultIoFilterChain.java:801)
	at  
org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java: 
71)
	at org.apache.mina.core.session.IoEvent.run(IoEvent.java:63)
	at org.apache.mina.filter.executor.OrderedThreadPoolExecutor 
$Worker.runTask(OrderedThreadPoolExecutor.java:801)
	at org.apache.mina.filter.executor.OrderedThreadPoolExecutor 
$Worker.runTasks(OrderedThreadPoolExecutor.java:793)
	at org.apache.mina.filter.executor.OrderedThreadPoolExecutor 
$Worker.run(OrderedThreadPoolExecutor.java:735)
	at java.lang.Thread.run(Thread.java:613)
[ INFO] 2009-07-28 18:06:14,897 [admin] [192.168.2.120] SENT: 150 File  
status okay; about to open data connection.


[ INFO] 2009-07-28 18:06:14,897 [admin] [192.168.2.120] RECEIVED: QUIT
[ INFO] 2009-07-28 18:06:14,898 [admin] [192.168.2.120] CLOSED
[ INFO] 2009-07-28 18:06:24,896 [] [192.168.2.120] CREATED
[ INFO] 2009-07-28 18:06:24,896 [admin] [192.168.2.120] OPENED
[ INFO] 2009-07-28 18:06:24,897 [admin] [192.168.2.120] SENT: 220  
Service ready for new user.


[ INFO] 2009-07-28 18:06:24,901 [] [192.168.2.120] RECEIVED: USER admin
[ INFO] 2009-07-28 18:06:24,902 [admin] [192.168.2.120] SENT: 331 User  
name okay, need password for admin.


[ INFO] 2009-07-28 18:06:24,935 [admin] [192.168.2.120] RECEIVED: PASS  
*****
[ INFO] 2009-07-28 18:06:24,936 [admin] [192.168.2.120] Login success  
- admin
[ INFO] 2009-07-28 18:06:24,944 [admin] [192.168.2.120] SENT: 230 User  
logged in, proceed.


[ INFO] 2009-07-28 18:06:24,967 [admin] [192.168.2.120] RECEIVED: CWD /
[ INFO] 2009-07-28 18:06:24,968 [admin] [192.168.2.120] SENT: 250  
Directory changed to /


[ INFO] 2009-07-28 18:06:25,067 [admin] [192.168.2.120] RECEIVED: TYPE I
[ INFO] 2009-07-28 18:06:25,068 [admin] [192.168.2.120] SENT: 200  
Command TYPE okay.


[ INFO] 2009-07-28 18:06:25,072 [admin] [192.168.2.120] RECEIVED: SIZE  
WM Components 2.2.2.3.dmg
[ INFO] 2009-07-28 18:06:25,073 [admin] [192.168.2.120] SENT: 213  
10104832


[ INFO] 2009-07-28 18:06:25,087 [admin] [192.168.2.120] RECEIVED: MODE Z
[ INFO] 2009-07-28 18:06:25,088 [admin] [192.168.2.120] SENT: 200  
Command MODE okay.


[ INFO] 2009-07-28 18:06:25,091 [admin] [192.168.2.120] RECEIVED: PASV
[ INFO] 2009-07-28 18:06:25,093 [admin] [192.168.2.120] SENT: 227  
Entering Passive Mode (192,168,2,111,242,133)


[ INFO] 2009-07-28 18:06:25,095 [admin] [192.168.2.120] RECEIVED: APPE  
WM Components 2.2.2.3.dmg
[ INFO] 2009-07-28 18:06:25,168 [admin] [192.168.2.120] File uploaded / 
WM Components 2.2.2.3.dmg
[ INFO] 2009-07-28 18:06:25,168 [admin] [192.168.2.120] SENT: 150 File  
status okay; about to open data connection.


[ INFO] 2009-07-28 18:06:25,169 [admin] [192.168.2.120] SENT: 226  
Transfer complete.


[ INFO] 2009-07-28 18:06:25,171 [admin] [192.168.2.120] RECEIVED: TYPE A
[ INFO] 2009-07-28 18:06:25,171 [admin] [192.168.2.120] SENT: 200  
Command TYPE okay.


[ INFO] 2009-07-28 18:06:25,173 [admin] [192.168.2.120] RECEIVED: PASV
[ INFO] 2009-07-28 18:06:25,174 [admin] [192.168.2.120] SENT: 227  
Entering Passive Mode (192,168,2,111,242,134)


[ INFO] 2009-07-28 18:06:25,183 [admin] [192.168.2.120] RECEIVED: LIST
[ INFO] 2009-07-28 18:06:25,185 [admin] [192.168.2.120] SENT: 150 File  
status okay; about to open data connection.


[ INFO] 2009-07-28 18:06:25,186 [admin] [192.168.2.120] SENT: 226  
Closing data connection.


Mime
View raw message