8000 ws_ftp and packet order · Issue #260 · pkg/sftp · GitHub
[go: up one dir, main page]
More Web Proxy on the site http://driver.im/
Skip to content

ws_ftp and packet order #260

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom
Closed
purha opened this issue Jul 20, 2018 · 29 comments
Closed

ws_ftp and packet order #260

purha opened this issue Jul 20, 2018 · 29 comments
Assignees
@eikenb
Labels
bug

Comments

@purha
Copy link
purha commented Jul 20, 2018 •
edited
Loading

Hi,

using ws ftp pro (trial latest version) library seems to have issues.
This can be replicated using the sftp-server example, having for example 20 files with small amount of data, I tested 22 bytes.

Using command "C:\Program Files (x86)\Ipswitch\WS_FTP 12\wsftppro.exe" -s sftp-lib-conf:/path_to/github.com/pkg/sftp/examples/sftp-server/testfile* -d local:C:\temp\

Some of the files come as empty. Also sometimes just changing the directory in UI fails.

I think this is related to packets coming/going in wrong order. Temporary fix that I found was to set SftpServerWorkerCount=1

I debugged the issue and failing transfers it seems to read with offset greater than filesize, when server responds EOF the next packet with offset zero and correct data seems to be ignored by the client.

In succesfull transfers offset zero packet seems to come first.

This issue is not in openssh server, it seems to always receive offset zero first.

Mikko.
@eikenb eikenb added the bug label Jul 20, 2018
@eikenb
Copy link
Member
eikenb commented Jul 20, 2018

Thanks for the report. I'll see if I can get ws_ftp-pro working with wine so I can attempt to reproduce the issue.

@eikenb eikenb self-assigned this Jul 20, 2018
@eikenb
Copy link
Member
eikenb commented Jul 20, 2018

This is going to be a bit of a challenge. Grabbed ws-ftp-pro trial version and it installed fine with wine but the activation doesn't work. Wasn't able to active using the online method or the offline method. Both failed telling me to contact customer support.

@eikenb
Copy link
Member
eikenb commented Jul 20, 2018

I'm a bit stumped at how the 2 packets could get out of order. Packets must be responded to in the same order they are received in general and the packet-manager code was added to address this requirement. It keeps track of the incoming packets currently being handled by the workers and only responds when it can do it in order (buffering finished responses until earlier ones are ready).

The only thing that I can think of at the moment is the packet request-ids might not be sort-able. Every client I've tried so far has incremental packet-ids but the spec doesn't require this nor does it even require that they are unique.

@purha, if you could possible print out a few of the request-ids for these packets it would help at least eliminate that possibility. Thanks.

@purha
Copy link
Author
purha commented Jul 22, 2018

Hi,

I used one of the windows test images for virtualbox https://developer.microsoft.com/en-us/microsoft-edge/tools/vms/

This is log for downloading 5 files when one succeeded and others failed:

Listening on [::]:2022
2018/07/22 14:29:02 incoming id: 0
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 outgoing pkt: 0
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 0
2018/07/22 14:29:02 incoming id: 3294
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 outgoing pkt: 3294
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 0
2018/07/22 14:29:02 incoming id: 1110
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 outgoing pkt: 1110
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 0
2018/07/22 14:29:02 incoming id: 3021
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 outgoing pkt: 3021
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 0
2018/07/22 14:29:02 incoming id: 3021
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 statusFromError: error is *errors.errorString &errors.errorString{s:"EOF"}
2018/07/22 14:29:02 outgoing pkt: 3021
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 0
2018/07/22 14:29:02 incoming id: 1929
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 outgoing pkt: 1929
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 0
2018/07/22 14:29:02 incoming id: 2192
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 outgoing pkt: 2192
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 0
2018/07/22 14:29:02 incoming id: 1383
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 outgoing pkt: 1383
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 0
2018/07/22 14:29:02 incoming id: 2475
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 incoming id: 2475
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 2
2018/07/22 14:29:02 statusFromError: error is *errors.errorString &errors.errorString{s:"EOF"}
2018/07/22 14:29:02 outgoing pkt: 2475
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 outgoing pkt: 2475
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 0
2018/07/22 14:29:02 incoming id: 1929
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 outgoing pkt: 1929
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 0
2018/07/22 14:29:02 incoming id: 2192
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 outgoing pkt: 2192
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 0
2018/07/22 14:29:02 incoming id: 1383
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 outgoing pkt: 1383
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 0
2018/07/22 14:29:02 incoming id: 2475
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 incoming id: 2475
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 2
2018/07/22 14:29:02 statusFromError: error is *errors.errorString &errors.errorString{s:"EOF"}
2018/07/22 14:29:02 outgoing pkt: 2475
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 outgoing pkt: 2475
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 0
2018/07/22 14:29:02 incoming id: 1929
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 outgoing pkt: 1929
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 0
2018/07/22 14:29:02 incoming id: 2192
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 outgoing pkt: 2192
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 0
2018/07/22 14:29:02 incoming id: 1383
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 outgoing pkt: 1383
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 0
2018/07/22 14:29:02 incoming id: 2475
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 incoming id: 2475
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 2
2018/07/22 14:29:02 statusFromError: error is *errors.errorString &errors.errorString{s:"EOF"}
2018/07/22 14:29:02 outgoing pkt: 2475
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 outgoing pkt: 2475
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 0
2018/07/22 14:29:02 incoming id: 1929
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 outgoing pkt: 1929
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 0
2018/07/22 14:29:02 incoming id: 2192
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 outgoing pkt: 2192
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 0
2018/07/22 14:29:02 incoming id: 1383
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 outgoing pkt: 1383
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 0
2018/07/22 14:29:02 incoming id: 2475
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 incoming id: 2475
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 2
2018/07/22 14:29:02 statusFromError: error is *errors.errorString &errors.errorString{s:"EOF"}
2018/07/22 14:29:02 outgoing pkt: 2475
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 outgoing pkt: 2475
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 0
2018/07/22 14:29:02 incoming id: 1929
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 outgoing pkt: 1929
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 0
2018/07/22 14:29:02 incoming id: 2192
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 outgoing pkt: 2192
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 0
2018/07/22 14:29:02 incoming id: 1383
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 outgoing pkt: 1383
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 0
2018/07/22 14:29:02 incoming id: 2475
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 incoming id: 2475
2018/07/22 14:29:02 statusFromError: error is *errors.errorString &errors.errorString{s:"EOF"}
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 2
2018/07/22 14:29:02 outgoing pkt: 2475
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 outgoing pkt: 2475
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 0
2018/07/22 14:29:02 incoming id: 1929
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 1
2018/07/22 14:29:02 outgoing pkt: 1929
2018/07/22 14:29:02 break! -- outgoing: 0; incoming: 0

I hope this helps

@eikenb
Copy link
Member
eikenb commented Jul 22, 2018 •
edited
Loading

@purha Thanks!

This does seem to confirm my suspicions as those packet ids are not incremental, they do seem to jump around. My first idea to address this is to use an internal, incremental id for each packet and use that to ensure ordering it maintained. At first glance it seems like it might be fairly straightforward, but I'll need to dig into it to be sure.

@ali11011
Copy link

Hi,

we are facing a similar issue with the same client. we didn't have any issues downloading a trial version of the client.

Alistair

@eikenb
Copy link
Member
eikenb commented Jul 23, 2018

Thanks for reporting the issue @ali11011, I'm working on it and will report here when I have a branch ready for testing.

@eikenb
Copy link
Member
eikenb commented Jul 23, 2018

My naive thought that I could just embed the current packets in an ordered packet is not working out. A lot of type checking/asserting makes it pretty ugly. So I'm thinking of reversing things and embedding an ordering field in each packet. More code, but simpler.

@eikenb
Copy link
Member
eikenb commented Jul 24, 2018

Embedding the ordering into the existing packets is working out better. The request-server had things abstracted out enough that it was easy. The old filesystem server implementation not so much. But it is coming along.

@ali11011
Copy link

hi,

how is the progress coming along for this fix?

Alistair

@ali11011
Copy link
ali11011 commented Jul 25, 2018 •
edited
Loading

note we now have reports of 0kb files being generated on upload to the sFTP layer now as well as download

@eikenb
Copy link
Member
eikenb commented Jul 25, 2018

Sorry about the troubles. I'm still actively working on it though my second attempt also didn't work out as I'd hoped. I have another avenue I'm trying and am still hopeful to have it fixed this week.

Same problem would apply both uploading and downloading.

Best short term solution would be to use another SFTP client (filezilla, winscp, cyberduck, openssh's client).

@ali11011
Copy link

appreciate the efforts!!

i am afraid we cannot ask our customers to change their middle-ware solution because of a bug on our end.

@eikenb
Copy link
Member
eikenb commented Jul 26, 2018

Alternative short term solution would be to re-compile with SftpServerWorkerCount set to 1. Won't be as fast, but should fix this issue while I'm working on a better fix.

@ali11011
Copy link

we did this already yesterday, but for some reason it seems like we are still getting 0kb on upload. still waiting for 100% confirmation that issue is re-occurring, but it looks like it is

@ali11011
Copy link

well actually seems that it resolved issue for downloads. still waiting for confirmation of success for uploads. the performance impact is noticeable however, so looking forward to long term fix
< 8000 p class="text-center mt-3" data-hide-on-error>

@ali11011
Copy link

upload was not fixed by dropping worker count to 1

@eikenb
Copy link
Member
eikenb commented Jul 27, 2018

I have a branch which uses an internal count for ordering, which should fix this. I have finished the code and just pushed the branch (packet-embedded-in-ordered) and created a pull request (#263). I'm going to try to test it today by installing ws-ftp in a VM, but I have limited time and may not get done with it. If either of you ( @ali11011 or @purha) get a chance to test the branch please let me know how it goes. Thanks and thank you for your patience.

@eikenb
Copy link
Member
eikenb commented Jul 27, 2018

I'm having trouble reproducing this using the ws-ftp GUI from Win10 in a virtualbox to local linux system running the sftp-server example. Tried transferring up/down various files from 20 bytes to 4kb using the current master branch (wanted a baseline before trying the new branch).

Hopefully you guys have better luck testing. I'll try again later, but am giving up for now.

@purha
Copy link
Author
purha commented Jul 30, 2018

looks like it's not working properly with worker count = 8, here's the log, dirlist and single download:

Listening on [::]:2022
2018/07/30 13:30:38 incoming id (oid): 0 (1)
2018/07/30 13:30:38 break! -- outgoing: 0; incoming: 1
2018/07/30 13:30:38 outgoing id (oid): 0 (1)
2018/07/30 13:30:38 Sending packet: 0
2018/07/30 13:30:38 break! -- outgoing: 0; incoming: 0
2018/07/30 13:30:38 incoming id (oid): 3294 (2)
2018/07/30 13:30:38 break! -- outgoing: 0; incoming: 1
2018/07/30 13:30:38 outgoing id (oid): 3294 (2)
2018/07/30 13:30:38 Sending packet: 3294
2018/07/30 13:30:38 break! -- outgoing: 0; incoming: 0
2018/07/30 13:30:38 incoming id (oid): 1110 (3)
2018/07/30 13:30:38 break! -- outgoing: 0; incoming: 1
2018/07/30 13:30:38 outgoing id (oid): 1110 (3)
2018/07/30 13:30:38 Sending packet: 1110
2018/07/30 13:30:38 break! -- outgoing: 0; incoming: 0
2018/07/30 13:30:38 incoming id (oid): 3021 (4)
2018/07/30 13:30:38 break! -- outgoing: 0; incoming: 1
2018/07/30 13:30:38 outgoing id (oid): 3021 (4)
2018/07/30 13:30:38 Sending packet: 3021
2018/07/30 13:30:38 break! -- outgoing: 0; incoming: 0
2018/07/30 13:30:38 incoming id (oid): 3021 (5)
2018/07/30 13:30:38 statusFromError: error is *errors.errorString &errors.errorString{s:"EOF"}
2018/07/30 13:30:38 break! -- outgoing: 0; incoming: 1
2018/07/30 13:30:38 outgoing id (oid): 3021 (5)
2018/07/30 13:30:38 Sending packet: 3021
2018/07/30 13:30:38 break! -- outgoing: 0; incoming: 0
2018/07/30 13:30:38 incoming id (oid): 1929 (6)
2018/07/30 13:30:38 break! -- outgoing: 0; incoming: 1
2018/07/30 13:30:38 outgoing id (oid): 19 8000 29 (6)
2018/07/30 13:30:38 Sending packet: 1929
2018/07/30 13:30:38 break! -- outgoing: 0; incoming: 0
2018/07/30 13:30:38 incoming id (oid): 2192 (7)
2018/07/30 13:30:38 break! -- outgoing: 0; incoming: 1
2018/07/30 13:30:38 outgoing id (oid): 2192 (7)
2018/07/30 13:30:38 Sending packet: 2192
2018/07/30 13:30:38 break! -- outgoing: 0; incoming: 0
2018/07/30 13:30:38 incoming id (oid): 1383 (8)
2018/07/30 13:30:38 break! -- outgoing: 0; incoming: 1
2018/07/30 13:30:38 outgoing id (oid): 1383 (8)
2018/07/30 13:30:38 Sending packet: 1383
2018/07/30 13:30:38 break! -- outgoing: 0; incoming: 0
2018/07/30 13:30:38 incoming id (oid): 2475 (9)
2018/07/30 13:30:38 break! -- outgoing: 0; incoming: 1
2018/07/30 13:30:38 incoming id (oid): 2475 (10)
2018/07/30 13:30:38 break! -- outgoing: 0; incoming: 2
2018/07/30 13:30:38 statusFromError: error is *errors.errorString &errors.errorString{s:"EOF"}
2018/07/30 13:30:38 outgoing id (oid): 2475 (10)
2018/07/30 13:30:38 Sending packet: 2475
2018/07/30 13:30:38 break! -- outgoing: 0; incoming: 1
2018/07/30 13:30:38 outgoing id (oid): 2475 (9)
2018/07/30 13:30:38 Sending packet: 2475
2018/07/30 13:30:38 break! -- outgoing: 0; incoming: 0
2018/07/30 13:30:38 incoming id (oid): 1929 (11)
2018/07/30 13:30:38 break! -- outgoing: 0; incoming: 1
2018/07/30 13:30:38 outgoing id (oid): 1929 (11)
2018/07/30 13:30:38 Sending packet: 1929
2018/07/30 13:30:38 break! -- outgoing: 0; incoming: 0
2018/07/30 13:30:43 sftp client exited session.

however uploads seems to work fine even with 8 workers.

Here's the log for one worker and succesful download:

Listening on [::]:2022
2018/07/30 13:38:30 incoming id (oid): 0 (1)
2018/07/30 13:38:30 break! -- outgoing: 0; incoming: 1
2018/07/30 13:38:30 outgoing id (oid): 0 (1)
2018/07/30 13:38:30 Sending packet: 0
2018/07/30 13:38:30 break! -- outgoing: 0; incoming: 0
2018/07/30 13:38:30 incoming id (oid): 3294 (2)
2018/07/30 13:38:30 break! -- outgoing: 0; incoming: 1
2018/07/30 13:38:30 outgoing id (oid): 3294 (2)
2018/07/30 13:38:30 Sending packet: 3294
2018/07/30 13:38:30 break! -- outgoing: 0; incoming: 0
2018/07/30 13:38:30 incoming id (oid): 1110 (3)
2018/07/30 13:38:30 break! -- outgoing: 0; incoming: 1
2018/07/30 13:38:30 outgoing id (oid): 1110 (3)
2018/07/30 13:38:30 Sending packet: 1110
2018/07/30 13:38:30 break! -- outgoing: 0; incoming: 0
2018/07/30 13:38:30 incoming id (oid): 3021 (4)
2018/07/30 13:38:30 break! -- outgoing: 0; incoming: 1
2018/07/30 13:38:30 outgoing id (oid): 3021 (4)
2018/07/30 13:38:30 Sending packet: 3021
2018/07/30 13:38:30 break! -- outgoing: 0; incoming: 0
2018/07/30 13:38:30 incoming id (oid): 3021 (5)
2018/07/30 13:38:30 break! -- outgoing: 0; incoming: 1
2018/07/30 13:38:30 statusFromError: error is *errors.errorString &errors.errorString{s:"EOF"}
2018/07/30 13:38:30 outgoing id (oid): 3021 (5)
2018/07/30 13:38:30 Sending packet: 3021
2018/07/30 13:38:30 break! -- outgoing: 0; incoming: 0
2018/07/30 13:38:30 incoming id (oid): 1929 (6)
2018/07/30 13:38:30 break! -- outgoing: 0; incoming: 1
2018/07/30 13:38:30 outgoing id (oid): 1929 (6)
2018/07/30 13:38:30 Sending packet: 1929
2018/07/30 13:38:30 break! -- outgoing: 0; incoming: 0
2018/07/30 13:38:30 incoming id (oid): 2192 (7)
2018/07/30 13:38:30 break! -- outgoing: 0; incoming: 1
2018/07/30 13:38:30 outgoing id (oid): 2192 (7)
2018/07/30 13:38:30 Sending packet: 2192
2018/07/30 13:38:30 break! -- outgoing: 0; incoming: 0
2018/07/30 13:38:30 incoming id (oid): 1383 (8)
2018/07/30 13:38:30 break! -- outgoing: 0; incoming: 1
2018/07/30 13:38:30 outgoing id (oid): 1383 (8)
2018/07/30 13:38:30 Sending packet: 1383
2018/07/30 13:38:30 break! -- outgoing: 0; incoming: 0
2018/07/30 13:38:30 incoming id (oid): 2475 (9)
2018/07/30 13:38:30 break! -- outgoing: 0; incoming: 1
2018/07/30 13:38:30 incoming id (oid): 2475 (10)
2018/07/30 13:38:30 break! -- outgoing: 0; incoming: 2
2018/07/30 13:38:30 outgoing id (oid): 2475 (9)
2018/07/30 13:38:30 Sending packet: 2475
2018/07/30 13:38:30 break! -- outgoing: 0; incoming: 1
2018/07/30 13:38:30 statusFromError: error is *errors.errorString &errors.errorString{s:"EOF"}
2018/07/30 13:38:30 outgoing id (oid): 2475 (10)
2018/07/30 13:38:30 Sending packet: 2475
2018/07/30 13:38:30 break! -- outgoing: 0; incoming: 0
2018/07/30 13:38:30 incoming id (oid): 1929 (11)
2018/07/30 13:38:30 break! -- outgoing: 0; incoming: 1
2018/07/30 13:38:30 outgoing id (oid): 1929 (11)
2018/07/30 13:38:30 Sending packet: 1929
2018/07/30 13:38:30 break! -- outgoing: 0; incoming: 0
2018/07/30 13:38:35 sftp client exited session.

@eikenb
Copy link
Member
eikenb commented Jul 30, 2018

2018/07/30 13:30:38 incoming id (oid): 2475 (9)
2018/07/30 13:30:38 break! -- outgoing: 0; incoming: 1
2018/07/30 13:30:38 incoming id (oid): 2475 (10)
2018/07/30 13:30:38 break! -- outgoing: 0; incoming: 2
2018/07/30 13:30:38 statusFromError: error is *errors.errorString &errors.errorString{s:"EOF"}
2018/07/30 13:30:38 outgoing id (oid): 2475 (10)
2018/07/30 13:30:38 Sending packet: 2475
2018/07/30 13:30:38 break! -- outgoing: 0; incoming: 1
2018/07/30 13:30:38 outgoing id (oid): 2475 (9)
2018/07/30 13:30:38 Sending packet: 2475

That bit... 10 is sent before 9. That should be impossible, so something is amiss there.

I really wish this was easier to reproduce. Anyone have any tips for reproducing this please pass them along.

@eikenb
Copy link
Member
eikenb commented Jul 30, 2018 •
edited
Loading

I see it... ws-ftp gave 2 packets in a row the same id and I'm still using the packet's id to determine if the packet is the right one to send. Seems insane to use the same id in a row like that, but it is legal. Reading the spec it is legal for them to use the same id for every packet. Guess I need to just ignore that and use the order-id for all this.

One minute... I'll update the PR with the changed code.

@eikenb
Copy link
Member
eikenb commented Jul 30, 2018 •
edited
Loading

@purha @ali11011 Just pushed the branch (force push) to update the PR. Please try again if you get a chance.

Thanks!

@eikenb
Copy link
Member
eikenb commented Jul 30, 2018 •
edited
Loading

I've been able to reproduce it a couple times on the master branch and not on my new branch. I'm doing it manually in the GUI and so can't abuse it much, but seems hopeful. Please let me know if you're able to test it some more. Thanks.

@purha
Copy link
Author
purha commented Jul 31, 2018

looks like now it's working properly, thanks @eikenb !

@eikenb
Copy link
Member
eikenb commented Jul 31, 2018

@ali11011 Can you also test it? I'd like additional confirmation of its behavior before merging if possible. Thanks.

@ali11011
Copy link
ali11011 commented Aug 1, 2018

Hi yes. all looks good, we have a full day of production usage with no issues!

@eikenb
Copy link
Member
eikenb commented Aug 1, 2018

Excellent! Thanks @ali11011 and @purha for all your help with this issue. I'll get that code merged and a new release out hopefully today.

@eikenb eikenb closed this as completed in 7f7e75b Aug 1, 2018
eikenb added a commit that referenced this issue Aug 1, 2018
@eikenb
Merge pull request #263 from pkg/packet-embedded-in-ordered
6b9fa10 
ensure packet responses in same order as requests

Fixes #260
@eikenb
Copy link
Member
eikenb commented Aug 1, 2018

Just pushed v1.8.1 with the fix for this included.
Thanks again.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@eikenb eikenb

Labels
bug
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@eikenb @purha @ali11011
0