Serv-U FTP Server sometimes returns "Bad message." when attempting to read a file.

Yet another SFTP server that seems to clash with our implementation. :/

Here's the test code used to generate this log:

``` java
import java.io.InputStream;

import net.schmizz.sshj.SSHClient;
import net.schmizz.sshj.sftp.SFTPEngine;
import net.schmizz.sshj.sftp.StatefulSFTPClient;
import net.schmizz.sshj.transport.verification.PromiscuousVerifier;

import org.apache.commons.io.IOUtils;

public class SSHTest {
public static void main(String[] args)
throws Exception {
SSHClient client = new SSHClient();
try {
client.addHostKeyVerifier(new PromiscuousVerifier());
client.connect("10.211.55.6", 22);
client.authPassword("test", "test");

StatefulSFTPClient sftp = new StatefulSFTPClient(new SFTPEngine(client).init());
try {
System.out.println("File Exists: " + sftp.statExistence("test.txt"));

InputStream input = sftp.open("test.txt").getInputStream();
IOUtils.copy(input, System.out);
IOUtils.closeQuietly(input);
} finally {
if (sftp != null) {
sftp.close();
}
}
} finally {
client.close();
}
}
}
```

SSHJ Logs:

```
06-07-2012 16:27:55.170 [main] n.s.sshj.common.SecurityUtils INFO: Trying to register BouncyCastle as a JCE provider
06-07-2012 16:27:55.932 [main] n.s.sshj.common.SecurityUtils INFO: Registration succeeded
06-07-2012 16:27:56.067 [main] n.s.sshj.transport.TransportImpl INFO: Client identity string: SSH-2.0-SSHJ_0_8
06-07-2012 16:27:56.117 [main] n.s.sshj.transport.TransportImpl INFO: Server identity string: SSH-2.0-Serv-U_12.0.0.2
06-07-2012 16:27:56.146 [reader] n.s.sshj.transport.KeyExchanger INFO: Received SSH_MSG_KEXINIT
06-07-2012 16:27:56.150 [main] n.s.sshj.transport.KeyExchanger INFO: Sending SSH_MSG_KEXINIT
06-07-2012 16:27:56.171 [reader] n.s.sshj.transport.KeyExchanger DEBUG: Negotiated algorithms: [ kex=diffie-hellman-group14-sha1; sig=ssh-rsa; c2sCipher=aes128-ctr; s2cCipher=aes128-ctr; c2sMAC=hmac-sha1; s2cMAC=hmac-sha1; c2sComp=none; s2cComp=none ]
06-07-2012 16:27:56.254 [reader] n.s.sshj.transport.kex.DHG14 INFO: Sending SSH_MSG_KEXDH_INIT
06-07-2012 16:27:56.349 [reader] n.s.sshj.transport.KeyExchanger INFO: Received kex followup data
06-07-2012 16:27:56.349 [reader] n.s.sshj.transport.kex.DHG14 INFO: Received SSH_MSG_KEXDH_REPLY
06-07-2012 16:27:56.471 [reader] n.s.sshj.transport.KeyExchanger DEBUG: Trying to verify host key with net.schmizz.sshj.transport.verification.PromiscuousVerifier@16e1eea8
06-07-2012 16:27:56.472 [reader] n.s.sshj.transport.KeyExchanger INFO: Sending SSH_MSG_NEWKEYS
06-07-2012 16:27:56.474 [reader] n.s.sshj.transport.KeyExchanger INFO: Received SSH_MSG_NEWKEYS
06-07-2012 16:27:56.483 [main] n.s.sshj.SSHClient INFO: Key exchange took 0.364 seconds
06-07-2012 16:27:56.486 [main] n.s.sshj.transport.TransportImpl DEBUG: Sending SSH_MSG_SERVICE_REQUEST for ssh-userauth
06-07-2012 16:27:56.667 [main] n.s.sshj.transport.TransportImpl INFO: Setting active service to ssh-userauth
06-07-2012 16:27:56.667 [main] n.s.sshj.userauth.UserAuthImpl INFO: Trying `password` auth...
06-07-2012 16:27:56.668 [main] n.s.sshj.userauth.method.AuthPassword INFO: Requesting password for [AccountResource] test@10.211.55.6
06-07-2012 16:27:56.685 [main] n.s.sshj.userauth.UserAuthImpl INFO: `password` auth successful
06-07-2012 16:27:56.685 [main] n.s.sshj.transport.TransportImpl INFO: Setting active service to ssh-connection
06-07-2012 16:27:56.699 [main] n.s.sshj.connection.ConnectionImpl INFO: Attaching `session` channel (#0)
06-07-2012 16:27:56.706 [reader] n.s.sshj.connection.channel.direct.SessionChannel INFO: Initialized - < session channel: id=0, recipient=0, localWin=[winSize=2097152], remoteWin=[winSize=2147483647] >
06-07-2012 16:27:56.706 [main] n.s.sshj.connection.channel.direct.SessionChannel INFO: Will request `sftp` subsystem
06-07-2012 16:27:56.706 [main] n.s.sshj.connection.channel.direct.SessionChannel INFO: Sending channel request for `subsystem`
06-07-2012 16:27:56.749 [main] n.s.sshj.connection.channel.Window$Remote DEBUG: Consuming by 9 down to 2147483638
06-07-2012 16:27:56.761 [reader] n.s.sshj.connection.channel.Window$Local DEBUG: Consuming by 9 down to 2097143
06-07-2012 16:27:56.770 [main] n.s.sshj.sftp.SFTPEngine INFO: Server version 3
06-07-2012 16:27:56.774 [main] n.s.sshj.sftp.SFTPEngine DEBUG: Sending Request{1;REALPATH}
06-07-2012 16:27:56.774 [main] n.s.sshj.connection.channel.Window$Remote DEBUG: Consuming by 14 down to 2147483624
06-07-2012 16:27:56.806 [sftp reader] n.s.sshj.sftp.PacketReader DEBUG: Received NAME packet
06-07-2012 16:27:56.806 [reader] n.s.sshj.connection.channel.Window$Local DEBUG: Consuming by 27 down to 2097116
06-07-2012 16:27:56.806 [main] n.s.sshj.sftp.StatefulSFTPClient INFO: Start dir = /
06-07-2012 16:27:56.806 [main] n.s.sshj.sftp.SFTPEngine DEBUG: Sending Request{2;STAT}
06-07-2012 16:27:56.807 [main] n.s.sshj.connection.channel.Window$Remote DEBUG: Consuming by 22 down to 2147483602
06-07-2012 16:27:56.820 [reader] n.s.sshj.connection.channel.Window$Local DEBUG: Consuming by 41 down to 2097075
06-07-2012 16:27:56.821 [sftp reader] n.s.sshj.sftp.PacketReader DEBUG: Received ATTRS packet
06-07-2012 16:27:56.825 [main] n.s.sshj.sftp.StatefulSFTPClient DEBUG: Opening `/test.txt`
06-07-2012 16:27:56.826 [main] n.s.sshj.sftp.SFTPEngine DEBUG: Sending Request{3;OPEN}
06-07-2012 16:27:56.826 [main] n.s.sshj.connection.channel.Window$Remote DEBUG: Consuming by 30 down to 2147483572
06-07-2012 16:27:56.852 [sftp reader] n.s.sshj.sftp.PacketReader DEBUG: Received HANDLE packet
06-07-2012 16:27:56.852 [reader] n.s.sshj.connection.channel.Window$Local DEBUG: Consuming by 17 down to 2097058
06-07-2012 16:27:56.858 [main] n.s.sshj.sftp.SFTPEngine DEBUG: Sending Request{4;READ}
06-07-2012 16:27:56.858 [main] n.s.sshj.connection.channel.Window$Remote DEBUG: Consuming by 31 down to 2147483541
06-07-2012 16:27:56.875 [reader] n.s.sshj.connection.channel.Window$Local DEBUG: Consuming by 35 down to 2097023
06-07-2012 16:27:56.875 [sftp reader] n.s.sshj.sftp.PacketReader DEBUG: Received STATUS packet
06-07-2012 16:27:56.878 [main] n.s.sshj.connection.channel.direct.SessionChannel INFO: Sending close
06-07-2012 16:27:56.902 [reader] n.s.sshj.connection.channel.direct.SessionChannel INFO: Got close
06-07-2012 16:27:56.926 [reader] n.s.sshj.connection.ConnectionImpl INFO: Forgetting `session` channel (#0)
06-07-2012 16:27:56.926 [main] n.s.sshj.transport.TransportImpl DEBUG: Default disconnect listener - BY_APPLICATION
06-07-2012 16:27:56.927 [main] n.s.sshj.connection.ConnectionImpl DEBUG: Notified of net.schmizz.sshj.transport.TransportException: [BY_APPLICATION] Disconnected
06-07-2012 16:27:56.927 [main] n.s.sshj.transport.TransportImpl DEBUG: Sending SSH_MSG_DISCONNECT: reason=[BY_APPLICATION], msg=[]
06-07-2012 16:27:56.936 [reader] n.s.sshj.transport.Reader DEBUG: Stopping
Exception in thread "main" net.schmizz.sshj.sftp.SFTPException: Bad message.
at net.schmizz.sshj.sftp.Response.error(Response.java:113)
at net.schmizz.sshj.sftp.Response.ensureStatusIs(Response.java:106)
at net.schmizz.sshj.sftp.RemoteFile.read(RemoteFile.java:66)
at net.schmizz.sshj.sftp.RemoteFile$RemoteFileInputStream.read(RemoteFile.java:179)
at java.io.InputStream.read(InputStream.java:82)
at org.apache.commons.io.IOUtils.copyLarge(IOUtils.java:1383)
at org.apache.commons.io.IOUtils.copy(IOUtils.java:1357)
at SSHTest.main(SSHTest.java:26)
```

stdout:

```
File Exists: [size=176;uid=176,gid=0;mode=[mask=100666];atime=1339099826,mtime=1339088332;]
```

Server Logs:

```
[02] Thu 07Jun12 16:27:56 - (000014) User "test" logged in
[31] Thu 07Jun12 16:27:56 - (000014) SSH2_MSG_USERAUTH_SUCCESS: successful login
[30] Thu 07Jun12 16:27:56 - (000014) SSH_FXP_INIT: client version 3 (SSHJ_0_8)
[31] Thu 07Jun12 16:27:56 - (000014) SSH_FXP_VERSION: server version 3
[30] Thu 07Jun12 16:27:56 - (000014) {0x00000001} SSH_FXP_REALPATH: path: "."
[31] Thu 07Jun12 16:27:56 - (000014) {0x00000001} SSH_FXP_NAME: path: "/"
[30] Thu 07Jun12 16:27:56 - (000014) {0x00000002} SSH_FXP_STAT: path: "/test.txt"
[31] Thu 07Jun12 16:27:56 - (000014) {0x00000002} SSH_FXP_ATTRS
[30] Thu 07Jun12 16:27:56 - (000014) {0x00000003} SSH_FXP_OPEN: path: "/test.txt"
[31] Thu 07Jun12 16:27:56 - (000014) {0x00000003} SSH_FXP_HANDLE: file handle: 0x000003e8
[30] Thu 07Jun12 16:27:56 - (000014) {0x00000004} SSH_FXP_READ
[31] Thu 07Jun12 16:27:56 - (000014) {0x00000004} SSH_FX_BAD_MESSAGE: Bad message.
[31] Thu 07Jun12 16:27:56 - (000014) SSH_MSG_DISCONNECT: client has requested a disconnect. Reason code: 11
[02] Thu 07Jun12 16:27:56 - (000014) Closed session
[02] Thu 07Jun12 16:27:56 - (000014) User "test" logged out
```

Trial version is available at http://www.serv-u.com/dn.asp. Very basic setup, just added domain for testing, added user test/test and set up an empty directory. Test file was filled with "this is a test" about 5 times. First few attempts to read the file actually worked, subsequent attempts sometimes worked, sometimes didn't work (results were sporadic).