login about faq

I have a remote client that for some reason fails to connect to our FTP server. All other remote clients using the same agent are able to connect successfully.

However with this remote client I'm not able to see why it's failing. I do not have access to the the remote client system. Below is the redacted client and server logs.

On the FTP server I can see in the log where the control channel was opened and that an AUTH 234 as sent, and then 60 seconds later that the control channel is closed.

Any help in determining where the error is or even where to start looking would be appreciated.

Client Log:

2012-11-12-03:55:29 --> OpenConnection
2012-11-12-03:55:29 --> FTP Connection:xxx.yyy.com:21
2012-11-12-03:55:29 --> ChilkatLog:
2012-11-12-03:55:29 --> UnlockComponent:
2012-11-12-03:55:29 --> DllDate: Nov 3 2012
2012-11-12-03:55:29 --> UnlockPrefix: xxxxxxx
2012-11-12-03:55:29 --> Username: xxxxxxxx
2012-11-12-03:55:29 --> Architecture: Little Endian; 32-bit
2012-11-12-03:55:29 --> Language: .NET 2.0
2012-11-12-03:55:29 --> VerboseLogging: 0
2012-11-12-03:55:29 --> component: Ftp2
2012-11-12-03:55:29 --> unlockCode: xxxxxxxx
2012-11-12-03:55:29 --> RegKey:
2012-11-12-03:55:29 --> LibDate: Oct 18 2012
2012-11-12-03:55:29 --> requiresPerm: 0
2012-11-12-03:55:29 --> re-parsing expire date...
2012-11-12-03:55:29 --> Component successfully unlocked using permanent unlock code.
2012-11-12-03:55:29 --> --RegKey
2012-11-12-03:55:29 --> --UnlockComponent
2012-11-12-03:55:29 --> --ChilkatLog
2012-11-12-03:55:29 -->
2012-11-12-03:55:29 --> FTPSecurityProtocol= AuthTls = True
2012-11-12-03:55:29 --> FTPConnectTimeout= 60
2012-11-12-03:55:29 --> FTP Connect xxx.yyy.com
2012-11-12-03:55:29 --> ftp_OnProgressInfo: SocketConnect :xxx.yyy.com:21
2012-11-12-03:55:29 --> ftp_OnProgressInfo: HostnameResolve : xxx.yyy.com
2012-11-12-03:55:29 --> ftp_OnProgressInfo: ResolvedToIp : xxx.yyy.com.zzz
2012-11-12-03:55:30 --> ftp_OnProgressInfo: SocketConnected : xxx.yyy.com:21
2012-11-12-03:55:30 --> ftp_OnProgressInfo: FtpCmdResp : 220 Microsoft FTP Service
2012-11-12-03:55:30 --> ftp_OnProgressInfo: FtpCmdSent : AUTH TLS
2012-11-12-03:55:30 --> ftp_OnProgressInfo: FtpCmdResp : 234 AUTH command ok. Expecting TLS Negotiation.
2012-11-12-03:55:30 --> ftp_OnProgressInfo: SslHandshake : Starting
2012-11-12-03:56:30 --> FTP Open Error: FTP.Connect Error:ChilkatLog:
2012-11-12-03:56:30 --> Connect_Ftp2:
2012-11-12-03:56:30 --> DllDate: Nov 3 2012
2012-11-12-03:56:30 --> UnlockPrefix: xxx
2012-11-12-03:56:30 --> Username: xxx
2012-11-12-03:56:30 --> Architecture: Little Endian; 32-bit
2012-11-12-03:56:30 --> Language: .NET 2.0
2012-11-12-03:56:30 --> VerboseLogging: 1
2012-11-12-03:56:30 --> ProgressMonitoring:
2012-11-12-03:56:30 --> enabled: yes
2012-11-12-03:56:30 --> heartbeatMs: 0
2012-11-12-03:56:30 --> sendBufferSize: 65536
2012-11-12-03:56:30 --> --ProgressMonitoring
2012-11-12-03:56:30 --> ImplicitSsl: 0
2012-11-12-03:56:30 --> AuthTls: 1
2012-11-12-03:56:30 --> AuthSsl: 0
2012-11-12-03:56:30 --> Hostname: xxx.yyy.com
2012-11-12-03:56:30 --> Port: 21
2012-11-12-03:56:30 --> IdleTimeoutMs: 60000
2012-11-12-03:56:30 --> ConnectTimeout: 60
2012-11-12-03:56:30 --> HeartbeatMs: 0
2012-11-12-03:56:30 --> ConnectTimeoutMs_1: 60000
2012-11-12-03:56:30 --> calling ConnectSocket2
2012-11-12-03:56:30 --> IPV6 enabled connect with NO heartbeat.
2012-11-12-03:56:30 --> connectingTo: xxx.yyy.com
2012-11-12-03:56:30 --> resolveHostname1:
2012-11-12-03:56:30 --> dnsCacheLookup: xxx.yyy.com
2012-11-12-03:56:30 --> Resolving domain name (IPV4)
2012-11-12-03:56:30 --> --resolveHostname1
2012-11-12-03:56:30 --> GetHostByNameHB_ipv4: Elapsed time: 109 millisec
2012-11-12-03:56:30 --> myIP_1: xxx.yyy.com.zzz
2012-11-12-03:56:30 --> myPort_1: 4182
2012-11-12-03:56:30 --> connect successful (1)
2012-11-12-03:56:30 --> Turning on TCP_NODELAY.
2012-11-12-03:56:30 --> socketOptions:
2012-11-12-03:56:30 --> SO_SNDBUF: 8192
2012-11-12-03:56:30 --> SO_RCVBUF: 8192
2012-11-12-03:56:30 --> TCP_NODELAY: 1
2012-11-12-03:56:30 --> --socketOptions
2012-11-12-03:56:30 --> initialStatus: 220
2012-11-12-03:56:30 --> initialResponse: 220 Microsoft FTP Service
2012-11-12-03:56:30 --> converting to secure connection...
2012-11-12-03:56:30 --> ssl_protocol_3: default
2012-11-12-03:56:30 --> ConvertToTls_4:
2012-11-12-03:56:30 --> establishChannel2_1:
2012-11-12-03:56:30 --> clientHandshake:
2012-11-12-03:56:30 --> clientHelloMajorMinorVersion: 3.1
2012-11-12-03:56:30 --> buildClientHello:
2012-11-12-03:56:30 --> majorVersion: 3
2012-11-12-03:56:30 --> minorVersion: 1
2012-11-12-03:56:30 --> numRandomBytes: 32
2012-11-12-03:56:30 --> sessionIdSize: 0
2012-11-12-03:56:30 --> numCipherSuites: 10
2012-11-12-03:56:30 --> numCompressionMethods: 1
2012-11-12-03:56:30 --> --buildClientHello
2012-11-12-03:56:30 --> Timeout waiting to read socket or accept connection
2012-11-12-03:56:30 --> timeoutMs: 60000
2012-11-12-03:56:30 --> Timed out waiting for incoming SSL/TLS messages.
2012-11-12-03:56:30 --> timeoutMs: 60000
2012-11-12-03:56:30 --> Expected ServerHello but did not receive it.
2012-11-12-03:56:30 --> --clientHandshake
2012-11-12-03:56:30 --> Client handshake failed. (1)
2012-11-12-03:56:30 --> connectionClosed: 0
2012-11-12-03:56:30 --> --establishChannel2_1
2012-11-12-03:56:30 --> --ConvertToTls_4
2012-11-12-03:56:30 --> Failed to convert channel to SSL/TLS
2012-11-12-03:56:30 --> Failed to connect to FTP server.
2012-11-12-03:56:30 --> Failed.
2012-11-12-03:56:30 --> --Connect_Ftp2
2012-11-12-03:56:30 --> --ChilkatLog
2012-11-12-03:56:30 -->
2012-11-12-03:56:30 --> SetProcessComplete()
2012-11-12-03:56:30 --> Sending Email
2012-11-12-03:56:36 --> AutoExit enabled. Complete

Server log:

Fields: date time c-ip c-port cs-username s-ip s-port cs-method cs-uri-stem sc-status sc-win32-status sc-substatus cs-bytes x-session x-fullpath

2012-11-12 20:56:07 100.100.6.158 41079 - 200.200.126.250 21 ControlChannelOpened - - 0 0 0 000fc106-45f3-4ea9-9a6d-74511f2e323f -
2012-11-12 20:56:07 100.100.6.158 41079 - 200.200.126.250 21 AUTH TLS 234 0 0 10 000fc106-45f3-4ea9-9a6d-74511f2e323f -
2012-11-12 20:58:14 100.100.6.158 41079 - 200.200.126.250 21 ControlChannelClosed - - 258 0 0 000fc106-45f3-4ea9-9a6d-74511f2e323f -

asked Nov 12 '12 at 16:39

cody's gravatar image

cody
6224


The LastErrorText indicates that the server never responds to the ClientHello message which is what begins the SSL/TLS handshake. It should respond with a ServerHello. If this server is on an IP that I can access, then please provide the IP address. Testing would not require a login because we are only testing the establishment of the SSL/TLS channel, which comes before authentication.

link

answered Nov 13 '12 at 10:27

chilkat's gravatar image

chilkat ♦♦
11.8k316358420

Did you get a chance to look ?

(Nov 13 '12 at 21:55) cody

I gave it a try and it worked fine for me. Here's my LastErrorText followed by the SessionLog

ChilkatLog:
  ConnectOnly_Ftp2:
    DllDate: Nov 12 2012
    UnlockPrefix: UNTTSTFTP
    Username: CK2007:Chilkat
    Architecture: Little Endian; 32-bit
    Language: .NET 2.0
    VerboseLogging: 0
    ProgressMonitoring:
      enabled: yes
      heartbeatMs: 0
      sendBufferSize: 65536
    --ProgressMonitoring
    ImplicitSsl: 0
    AuthTls: 1
    AuthSsl: 0
    Hostname: 173.192.126.250
    Port: 21
    IdleTimeoutMs: 60000
    ConnectTimeout: 60
    HeartbeatMs: 0
    ConnectTimeoutMs_1: 60000
    calling ConnectSocket2
    IPV6 enabled connect with NO heartbeat.
    This is an IPV4 numeric address...
    AddrInfoList:
      AddrInfo:
        ai_flags: 4
        ai_family: 2
        ai_socktype: 1
        ai_protocol: 0
        ai_addrlen: 16
        ai_canonname: (NULL)
      --AddrInfo
    --AddrInfoList
    Connect using IPV4.
    ipAddress1: 173.192.126.250
    myIP_3: 192.168.1.115
    myPort_3: 3822
    connect successful (2)
    Turning on TCP_NODELAY.
    socketOptions:
      SO_SNDBUF: 8192
      SO_RCVBUF: 8192
      TCP_NODELAY: 1
    --socketOptions
    initialStatus: 220
    initialResponse: 220 Microsoft FTP Service
    converting to secure connection...
    sentCommand: AUTH TLS
    receivedResponse: 234 AUTH command ok. Expecting TLS Negotiation.
    ssl_protocol_3: default
    ConvertToTls_4:
      establishChannel2_1:
        clientHandshake:
          clientHelloMajorMinorVersion: 3.1
          buildClientHello:
            majorVersion: 3
            minorVersion: 1
            numRandomBytes: 32
            sessionIdSize: 0
            numCipherSuites: 10
            numCompressionMethods: 1
          --buildClientHello
          handshakeMessageType: ServerHello
          handshakeMessageLen: 0x46
          processHandshakeMessage:
            MessageType: ServerHello
            Processing ServerHello...
            ServerHello:
              MajorVersion: 3
              MinorVersion: 1
              SessionIdLen: 32
              CipherSuite: RSA_WITH_AES_128_CBC_SHA
              CipherSuite: 00,2f
              CompressionMethod: 0
              Queueing ServerHello message.
              ServerHello is OK.
            --ServerHello
          --processHandshakeMessage
          handshakeMessageType: Certificate
          handshakeMessageLen: 0x88b
          processHandshakeMessage:
            MessageType: Certificate
            ProcessCertificates:
              Certificate:
                derSize: 1189
                certSubjectCN: posbackup1.aptidata.com
                certSerial: 017177
                certIssuerCN: GeoTrust SSL CA
              --Certificate
              Certificate:
                derSize: 989
                certSubjectCN: GeoTrust SSL CA
                certSerial: 0236D0
                certIssuerCN: GeoTrust Global CA
              --Certificate
              NumCertificates: 2
              Queueing Certificates message...
            --ProcessCertificates
          --processHandshakeMessage
          handshakeMessageType: ServerHelloDone
          handshakeMessageLen: 0x0
          processHandshakeMessage:
            MessageType: ServerHelloDone
            Queueing HelloDone message.
          --processHandshakeMessage
          HandshakeQueue:
            MessageType: ServerHello
            MessageType: Certificate
            MessageType: ServerHelloDone
          --HandshakeQueue
          Dequeued ServerHello message.
          Dequeued Certificate message.
          DequeuedMessageType: ServerHelloDone
          OK to ServerHelloDone!
          No client certificate required by the server.
          Encrypted pre-master secret with server certificate RSA public key is OK.
          Sending ClientKeyExchange...
          Sent ClientKeyExchange message.
          Sending ChangeCipherSpec...
          Sent ChangeCipherSpec message.
          Derived keys.
          Installed new outgoing security params.
          Sending FINISHED message..
          algorithm: aes
          keyLength: 128
          Sent FINISHED message..
          ccsProtocolType: 1
          handshakeMessageType: HandshakeFinished
          handshakeMessageLen: 0xc
          processHandshakeMessage:
            MessageType: HandshakeFinished
            FinishedMsgLen: 12
            Queueing Finished message.
          --processHandshakeMessage
          Dequeue the FINISHED message...
          Dequeued Finished message.
          Handshake completed successfully.
        --clientHandshake
        Secure Channel Established.
      --establishChannel2_1
    --ConvertToTls_4
    isConnected: 1
    successfully converted to secure connection...
    Success.
  --ConnectOnly_Ftp2
--ChilkatLog

220 Microsoft FTP Service . AUTH TLS 234 AUTH command ok. Expecting TLS Negotiation. . PBSZ 0 200 PBSZ command successful. . PROT P 200 PROT command successful.

link

answered Nov 13 '12 at 23:23

chilkat's gravatar image

chilkat ♦♦
11.8k316358420

Ok, could it be a firewall issue on the client restricting high port numbers for incoming requests? So that the FTP server is unable to respond with the 'hello' message?

link

answered Nov 14 '12 at 07:39

cody's gravatar image

cody
6224

Probably a firewall issue, or some sort of software on your client-side that blocks the communications. (If the problem was on the server-side, I'd experience the same issue.) It shouldn't be a port number issue. The FTP control connection to port 21 on the server was established. "Explicit SSL/TLS" means the unencrypted (normal) TCP connection is first established. (And that is successful in your case.) The next step is to convert the connection to SSL/TLS. The "AUTH TLS" command is sent to tell the server of the client's desire to do this, and the SSL/TLS connection handshake begins. The client sends the "ClientHello" and then expects to receive the server's "ServerHello", but it's getting blocked and the client times out

link

answered Nov 14 '12 at 10:45

chilkat's gravatar image

chilkat ♦♦
11.8k316358420

Your answer
toggle preview

Follow this question

By Email:

Once you sign in you will be able to subscribe for any updates here

By RSS:

Answers

Answers and Comments

Markdown Basics

  • *italic* or __italic__
  • **bold** or __bold__
  • link:[text](http://url.com/ "title")
  • image?![alt text](/path/img.jpg "title")
  • numbered list: 1. Foo 2. Bar
  • to add a line break simply add two spaces to where you would like the new line to be.
  • basic HTML tags are also supported

Tags:

×131
×90

Asked: Nov 12 '12 at 16:39

Seen: 9,450 times

Last updated: Nov 14 '12 at 10:45

powered by OSQA