Ask a Question

System.InvalidOperationException: Not enough data

0 votes
by (120 points)

Getting the following exception while uploading the files.

System.InvalidOperationException: Not enough data.
at Rebex.Net.CCD.T()
at Rebex.Net.CCD.I()
at Rebex.Net.SftpAttributes..ctor(CCD W, Int32 O)
at Rebex.Net.QVD..ctor(Byte[] W, Int32 O, Int32 C, Encoding N, Int32 V)
at Rebex.Net.ZND.JC(VCD& W)
at Rebex.Net.ZND.JC(UInt32 W, Boolean O)
at Rebex.Net.ZND.MC(VCD W, UInt32 O, JCD C)
at Rebex.Net.ZND.GO(String W, Boolean O, Boolean C, Boolean N, MND V, IND& D, JCD A)
at Rebex.Net.Sftp.HEO(String W, Boolean O, Boolean

Applies to: Rebex SFTP
by (72.7k points)
Can you please create communication log in Debug level and post it here or send it to support@rebex.net for analysis? It can be done as described at https://www.rebex.net/kb/logging/
by (120 points)
2019-04-02 15:16:24.380 VERBOSE Sftp(1)[1] SSH: Sending packet SSH_MSG_USERAUTH_REQUEST (43 bytes).
 0000 |32-00-00-00-0C-69-74-61 6C-67-61-73-77-61-74-65| 2....italgaswate
 0010 |72-00-00-00-0E-73-73-68 2D-63-6F-6E-6E-65-63-74| r....ssh-connect
 0020 |69-6F-6E-00-00-00-04-6E 6F-6E-65               | ion....none
2019-04-02 15:16:24.396 VERBOSE Sftp(1)[7] SSH: Received packet SSH_MSG_USERAUTH_FAILURE (14 bytes).
 0000 |33-00-00-00-08-70-61-73 73-77-6F-72-64-00      | 3....password.
2019-04-02 15:16:24.396 DEBUG Sftp(1)[1] SSH: Allowed authentication methods for 'italgaswater': password.
2019-04-02 15:16:24.411 DEBUG Sftp(1)[1] SSH: Trying password authentication for 'italgaswater'.
2019-04-02 15:16:24.411 VERBOSE Sftp(1)[1] SSH: Sending packet SSH_MSG_USERAUTH_REQUEST (58 bytes).
 0000 |32-00-00-00-0C-69-74-61 6C-67-61-73-77-61-74-65| 2....italgaswate
 0010 |72-00-00-00-0E-73-73-68 2D-63-6F-6E-6E-65-63-74| r....ssh-connect
 0020 |69-6F-6E-00-00-00-08-70 61-73-73-77-6F-72-64-00| ion....password.
 0030 |00-00-00-06-**-**-**-** **-**                  | ....******
2019-04-02 15:16:24.442 VERBOSE Sftp(1)[7] SSH: Received packet SSH_MSG_USERAUTH_SUCCESS (1 bytes).
 0000 |34                                             | 4
2019-04-02 15:16:24.442 DEBUG Sftp(1)[1] SSH: Authentication successful.
2019-04-02 15:16:24.458 VERBOSE Sftp(1)[1] SSH: Sending packet SSH_MSG_CHANNEL_OPEN (24 bytes).
 0000 |5A-00-00-00-07-73-65-73 73-69-6F-6E-00-00-00-00| Z....session....
 0010 |00-02-00-00-00-01-F8-00                        | ........
2019-04-02 15:16:24.489 VERBOSE Sftp(1)[7] SSH: Received packet SSH_MSG_CHANNEL_OPEN_CONFIRMATION (17 bytes).
 0000 |5B-00-00-00-00-00-00-00 00-FF-FF-FF-FF-00-00-80| [...............
 0010 |00                                             | .
2019-04-02 15:16:24.489 DEBUG Sftp(1)[1] SSH: Requesting subsystem 'sftp'.
2019-04-02 15:16:24.489 VERBOSE Sftp(1)[1] SSH: Sending packet SSH_MSG_CHANNEL_REQUEST (27 bytes).
 0000 |62-00-00-00-00-00-00-00 09-73-75-62-73-79-73-74| b........subsyst
 0010 |65-6D-01-00-00-00-04-73 66-74-70               | em.....sftp
2019-04-02 15:16:24.521 VERBOSE Sftp(1)[7] SSH: Received packet SSH_MSG_CHANNEL_SUCCESS (5 bytes).
 0000 |63-00-00-00-00                                 | c....
2019-04-02 15:16:24.536 VERBOSE Sftp(1)[1] SSH: Sending packet SSH_MSG_CHANNEL_DATA (18 bytes).
 0000 |5E-00-00-00-00-00-00-00 09-00-00-00-05-01-00-00| ^...............
 0010 |00-04                                          | ..
2019-04-02 15:16:24.536 INFO Sftp(1)[1] Command: SSH_FXP_INIT (4)
2019-04-02 15:16:24.552 VERBOSE Sftp(1)[7] SSH: Received packet SSH_MSG_CHANNEL_DATA (204 bytes).
 0000 |5E-00-00-00-00-00-00-00 C3-00-00-00-BF-02-00-00| ^...............
 0010 |00-04-00-00-00-08-76-65 72-73-69-6F-6E-73-00-00| ......versions..
 0020 |00-09-32-2C-33-2C-34-2C 35-2C-36-00-00-00-07-6E| ..2,3,4,5,6....n
 0030 |65-77-6C-69-6E-65-00-00 00-01-0A-00-00-00-11-66| ewline.........f
 0040 |73-79-6E-63-40-6F-70-65 6E-73-73-68-2E-63-6F-6D| sync@openssh.com
 0050 |00-00-00-01-31-00-00-00 18-70-6F-73-69-78-2D-72| ....1....posix-r
 0060 |65-6E-61-6D-65-40-6F-70 65-6E-73-73-68-2E-63-6F| ename@openssh.co
 0070 |6D-00-00-00-01-31-00-00 00-13-73-74-61-74-76-66| m....1....statvf
 0080 |73-40-6F-70-65-6E-73-73 68-2E-63-6F-6D-00-00-00| s@openssh.com...
 0090 |01-32-00-00-00-14-66-73 74-61-74-76-66-73-40-6F| .2....fstatvfs@o
 00A0 |70-65-6E-73-73-68-2E-63 6F-6D-00-00-00-01-32-00| penssh.com....2.
 00B0 |00-00-14-68-61-72-64-6C 69-6E-6B-40-6F-70-65-6E| ...hardlink@open
 00C0 |73-73-68-2E-63-6F-6D-00 00-00-01-31            | ssh.com....1
2019-04-02 15:16:24.567 INFO Sftp(1)[1] Response: SSH_FXP_VERSION (4, 7 extensions)
2019-04-02 15:16:24.567 INFO Sftp(1)[1] Info: Using SFTP v4 on a Unix-like platform.
2019-04-02 15:16:24.567 VERBOSE Sftp(1)[1] SSH: Sending packet SSH_MSG_CHANNEL_DATA (23 bytes).
 0000 |5E-00-00-00-00-00-00-00 0E-00-00-00-0A-10-00-00| ^...............
 0010 |00-01-00-00-00-01-2E                           | .......
2019-04-02 15:16:24.567 INFO Sftp(1)[1] Command: SSH_FXP_REALPATH (1, '.')
2019-04-02 15:16:24.599 VERBOSE Sftp(1)[7] SSH: Received packet SSH_MSG_CHANNEL_DATA (32 bytes).
 0000 |5E-00-00-00-00-00-00-00 17-00-00-00-13-68-00-00| ^............h..
 0010 |00-01-00-00-00-01-00-00 00-01-2F-00-00-00-00-02| ........../.....
2019-04-02 15:16:24.599 INFO Sftp(1)[1] Response: SSH_FXP_NAME (1, 1 item)
2019-04-02 15:16:24.599 INFO Sftp(1)[1] Info: Current directory is '/'.
2019-04-02 15:16:24.614 VERBOSE Sftp(1)[1] SSH: Sending packet SSH_MSG_CHANNEL_DATA (31 bytes).
 0000 |5E-00-00-00-00-00-00-00 16-00-00-00-12-11-00-00| ^...............
 0010 |00-02-00-00-00-05-2F-54 65-73-74-00-00-00-B5   | ....../Test....
2019-04-02 15:16:24.614 INFO Sftp(1)[1] Command: SSH_FXP_STAT (2, '/Test')
2019-04-02 15:16:24.646 VERBOSE Sftp(1)[7] SSH: Received packet SSH_MSG_CHANNEL_DATA (75 bytes).
 0000 |5E-00-00-00-00-00-00-00 42-00-00-00-3E-69-00-00| ^.......B...>i..
 0010 |00-02-00-00-00-B5-02-00 00-00-00-00-00-10-00-00| ................
 0020 |00-00-0C-69-74-61-6C-67 61-73-77-61-74-65-72-00| ...italgaswater.
 0030 |00-00-0C-69-74-61-6C-67 61-73-77-61-74-65-72-00| ...italgaswater.
 0040 |00-01-F8-00-00-00-00-5C 76-6C-31               | .......\vl1
2019-04-02 15:16:24.646 ERROR Sftp(1)[1] Info: System.InvalidOperationException: Not enough data.
   at Rebex.Net.CCD.T()
   at Rebex.Net.CCD.I()
   at Rebex.Net.SftpAttributes..ctor(CCD W, Int32 O)
   at Rebex.Net.QVD..ctor(Byte[] W, Int32 O, Int32 C, Encoding N, Int32 V)
   at Rebex.Net.ZND.JC(VCD& W)
   at Rebex.Net.ZND.JC(UInt32 W, Boolean O)
   at Rebex.Net.ZND.MC(VCD W, UInt32 O, JCD C)
   at Rebex.Net.ZND.GO(String W, Boolean O, Boolean C, Boolean N, MND V, IND& D, JCD A)
   at Rebex.Net.Sftp.HEO(String W, Boolean O, Boolean C, Boolean N, JCD V)

1 Answer

0 votes
by (72.7k points)

Thank you for the log. It showed that the server sent malformed packet according to SFTP v4 specification (see section 5).

The received SSH_FXP_STAT packet contains SFTP flags: 0xB5

Which corresponds to fields:

SSH_FILEXFER_ATTR_SIZE              0x00000001
SSH_FILEXFER_ATTR_PERMISSIONS       0x00000004
SSH_FILEXFER_ATTR_CREATETIME        0x00000010
SSH_FILEXFER_ATTR_MODIFYTIME        0x00000020
SSH_FILEXFER_ATTR_OWNERGROUP        0x00000080

The fields and its corresponding values are:

int64    size          0x01000
string   owner         italgaswater
string   group         italgaswater
uint32   permissions   0x01F8
uint64   createtime    0x5C766C31
uint64   mtime         !!! not enough data

The solution is to report this issue to the server vendor, so the issue is fixed on the server.

As a workaround, please disable SFTP v4 by setting the Sftp.Settings.DisableSftp4 property to true.

Can you please post here what SFTP server you are using and which version?
It can be read from log (assign logger before calling Connect method). Locate line like this:

DEBUG Sftp(1)[9] SSH: Server is 'SSH-2.0-ServerSoftware_X.Y'.
Show 8 previous comments
by (1.2k points)
Sorry, I can't provide anything beside the above. This is a already shipped application that I cannot modify anymore for now, unfortunately :-(.
by (147k points)
We will add an option to the next version that will make it possible enable the existing mod_sftp workaround. This is just a guess, but perhaps it would help.
by (147k points)
edited by
Please try enabling this with the latest R6.1 release and let us know whether it helps:
    Rebex.Security.Cryptography.CryptoHelper.SetOption(sftp.Settings, "EnableRedundantCreateTimeWorkaround", true); // 'sftp' is your instance of Sftp object
by (147k points)
Starting with Rebex SFTP R6.3, the workaround can be enabled using Sftp.Settings.EnableMissingCreateTimeWorkaround property.
by (1.2k points)
Thank you very much. Just downloaded and changed my code to use the new property
...