search

robinrodricks / FluentFTP

An FTP and FTPS client for .NET & .NET Standard, optimized for speed. Provides extensive FTP commands, File uploads/downloads, SSL/TLS connections, Automatic directory listing parsing, File hashing/checksums, File permissions/CHMOD, FTP proxies, FXP support, UTF-8 support, Async/await support, Powershell support and more. Written entirely in C#.
MIT License
2.99k stars 646 forks source link

Issue with AS400 change - AfterConnect actions cannot be undone #1571

Closed smeiff closed 1 month ago

smeiff commented 1 month ago

FTP Server OS: Unix

FTP Server Type: IBM CS FTP (z/OS, OS/400)

Client Computer OS: Windows

FluentFTP Version: 49.0.2+

Framework: .NET 8

Breaking change was introduced that modified the LISTFMT and NAMEFMT. This causes a change to the file name structure sent to the server.

When LISTFMT = 0 file name is expected FILE/MEMBER

When LISTFMT = 1 file name is expected MEMBER.FILE

This is due the change 7e50a828aa87ef0e1507ee1634817a04168f9375 https://github.com/robinrodricks/FluentFTP/commit/7e50a828aa87ef0e1507ee1634817a04168f9375

We either have to implement our own BaseFileServer, or change our code to start using FILE_NAME.FILE syntax. Can we please have a way built in to use the prior version? We would prefer to continue to write the file as MEMBER.MEMBER.

Logs :

"QSYS.LIB/LIBRARY_NAME.LIB" is current library

vs

"QS36FMCDB" is current library

FanDjango commented 1 month ago

Why do you not issue a EXECUTE of LISTFMT and NAMEFMT back to the one you want after connect?

Small additional code on your part?

Note that without these LISTFMT and NAMEFMT settings GetListing parse will not work as hoped. The LISTFMT=1 and NAMEFMT=1 settings are thus more suitable.

FanDjango commented 1 month ago

Alternative: we make the initial LISTFMT and NAMEFMT settings afer connect to be configurable as an option.

We either have to implement our own BaseFileServer, or change our code to start using FILE_NAME.FILE syntax. Can we please have a way built in to use the prior version? We would prefer to continue to write the file as MEMBER.MEMBER.

I am sure that we can find a way to support both paradigms.

smeiff commented 1 month ago

I see. I tried calling the execute for both lines but I still was receiving the same error message from the server about invalid extensions.

On Wed, May 8, 2024, 4:57 PM FanDjango @.***> wrote:

Why do you not issue a EXECUTE of LISTFMT and NAMEFMT back to the one you want?

Small additional code on your part?

Note that without these LISTFMT and NAMEFMT settings GetListing parse will not work as hoped.

— Reply to this email directly, view it on GitHub https://github.com/robinrodricks/FluentFTP/issues/1571#issuecomment-2101441959, or unsubscribe https://github.com/notifications/unsubscribe-auth/ABJFAIWTZFRB3W7HSEHQFBDZBKGTZAVCNFSM6AAAAABHNVJ6G2VHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDCMBRGQ2DCOJVHE . You are receiving this because you authored the thread.Message ID: @.***>

FanDjango commented 1 month ago

In that case it would perhaps be expedient to see both your attempts to "re"-set the values with EXECUTE and the actual connection in a verbose log. Let's look at what is happening in detail.

smeiff commented 1 month ago

It appears it resets the NAMEFMT back to 1 once it is about to send the file. 

[08:58:50 DBG] >         AutoConnect()
[08:58:50 DBG] >         AutoDetect(CloneConnection = False, FirstOnly = True, IncludeImplicit = True, AbortOnTimeout = True, RequireEncryption = False, ProtocolPriority = [Tls11, Tls12])
[08:58:50 DBG] Status:   Auto-Detect trying encryption mode "Auto" with "Tls11, Tls12"
[08:58:50 DBG] >         Connect(False)
[08:58:50 DBG] Status:   FluentFTP 50.0.1.0(.NET 6.0) AsyncFtpClient
[08:58:50 INF] Status:   Connecting to IP #1= 1.1.1.1:21
[08:58:50 DBG] Status:   Waiting for a response
[08:58:50 DBG] Response: 220-QTCP at myftp.server.com.
[08:58:50 INF] Response: 220 Connection will close if idle more than 10 minutes. [739014.541d]
[08:58:50 INF] Status:   Detected FTP server: IBMOS400FTP
[08:58:50 INF] Command:  AUTH TLS
[08:58:50 DBG] Status:   Waiting for response to: AUTH TLS
[08:58:50 INF] Response: 431 Requested security mechanism not available at this time. [3ms]
[08:58:50 INF] Command:  USER ***
[08:58:50 DBG] Status:   Waiting for response to: USER ***
[08:58:50 INF] Response: 331 Enter password. [1ms]
[08:58:50 INF] Command:  PASS ***
[08:58:50 DBG] Status:   Waiting for response to: PASS ***
[08:58:50 INF] Response: 230 *** logged on. [2ms]
[08:58:50 INF] Command:  FEAT
[08:58:50 DBG] Status:   Waiting for response to: FEAT
[08:58:50 DBG] Response: 211-Feature listing follows:
Response: AUTH TLS
Response: AUTH GSS
Response: CCC
Response: PBSZ
Response: PROT
Response: ADAT
Response: ENC
Response: MIC
Response: CONF
[08:58:50 INF] Response: 211 End of feature listing. [46ms]
[08:58:50 INF] Status:   Text encoding: System.Text.UTF8Encoding+UTF8EncodingSealed
[08:58:50 INF] Command:  OPTS UTF8 ON
[08:58:50 DBG] Status:   Waiting for response to: OPTS UTF8 ON
[08:58:50 INF] Response: 501 OPTS unsuccessful; specified subcommand not recognized. [1ms]
[08:58:50 INF] Command:  SYST
[08:58:50 DBG] Status:   Waiting for response to: SYST
[08:58:50 INF] Response: 215  OS/400 is the remote operating system. The TCP/IP version is "V7R4M0". [1ms]
[08:58:50 DBG] Status:   Active ServerHandler is: IBMOS400FTP
[08:58:50 DBG] Status:   Listing parser set to: IBMOS400
[08:58:50 INF] Command:  SITE LISTFMT 1
[08:58:50 DBG] Status:   Waiting for response to: SITE LISTFMT 1
[08:58:50 INF] Response: 250 Directory listing format (LISTFMT) option set to 1. [1ms]
[08:58:50 INF] Command:  SITE NAMEFMT 1
[08:58:50 DBG] Status:   Waiting for response to: SITE NAMEFMT 1
[08:58:50 INF] Response: 250  Now using naming format "1". [<1ms]
[08:58:50 INF] Command:  PWD
[08:58:50 DBG] Status:   Waiting for response to: PWD
[08:58:50 INF] Response: 257 "/QSYS.LIB/DEFAULT_LIBRARY.LIB" is current library. [1ms]
[08:58:50 INF] Command:  SITE LISTFMT 0
[08:58:50 DBG] Status:   Waiting for response to: SITE LISTFMT 0
[08:58:50 INF] Response: 250 Directory listing format (LISTFMT) option set to 0. [1ms]
[08:58:50 INF] Command:  SITE NAMEFMT 0
[08:58:50 DBG] Status:   Waiting for response to: SITE NAMEFMT 0
[08:58:50 INF] Response: 250  Now using naming format "0". [1ms]
[08:58:50 DBG] >         UploadStream("FILE_NAME.FILE_NAME", Overwrite, False)
[08:58:50 DBG] >         FileExists("FILE_NAME.FILE_NAME")
[08:58:50 DBG] >         GetNameListing("/QSYS.LIB/DEFAULT_LIBRARY.LIB")
[08:58:50 INF] Command:  TYPE I
[08:58:50 DBG] Status:   Waiting for response to: TYPE I
[08:58:50 INF] Response: 200 Representation type is binary IMAGE. [1ms]
[08:58:50 DBG] >         OpenDataStreamAsync("NLST /QSYS.LIB/DEFAULT_LIBRARY.LIB", 0)
[08:58:50 DBG] >         OpenPassiveDataStreamAsync(PASV, "NLST /QSYS.LIB/DEFAULT_LIBRARY.LIB", 0)
[08:58:50 INF] Command:  PASV
[08:58:50 DBG] Status:   Waiting for response to: PASV
[08:58:50 INF] Response: 227 Entering Passive Mode (1.1.1.1,189,255). [1ms]
[08:58:50 DBG] Status:   PASV advertised a non-routable IPAD. Using original connect dnsname/IPAD
[08:58:50 INF] Status:   Connecting to IP #1= 1.1.1.1:9999
[08:58:50 INF] Command:  NLST /QSYS.LIB/DEFAULT_LIBRARY.LIB
[08:58:50 DBG] Status:   Waiting for response to: NLST /QSYS.LIB/DEFAULT_LIBRARY.LIB
[08:58:50 DBG] Response: 125-NAMEFMT set to 1.
[08:58:50 INF] Response: 125 List started. [15ms]
[08:58:50 DBG] +---------------------------------------+
[08:58:50 DBG] Listing:  FILE_NAME.FILE/FILE_NAME.MBR
[08:58:50 DBG] Listing:  FILE_NAME.FILE/FILE_NAME.MBR
[08:58:50 DBG] Status:   Disposing(async) FtpSocketStream(data connection of AsyncFtpClient)
[08:58:50 DBG] >         CloseDataStream()
[08:58:50 DBG] Status:   Waiting for response to: NLST /QSYS.LIB/DEFAULT_LIBRARY.LIB
[08:58:50 INF] Response: 250 List completed. [67ms]
[08:58:50 DBG] +---------------------------------------+
[08:58:50 DBG] >         OpenWrite("FILE_NAME.FILE_NAME", ASCII, -1, False)
[08:58:50 INF] Command:  TYPE A
[08:58:50 DBG] Status:   Waiting for response to: TYPE A
[08:58:50 INF] Response: 200 Representation type is ASCII nonprint. [2ms]
[08:58:50 DBG] >         OpenDataStreamAsync("STOR FILE_NAME.FILE_NAME", 0)
[08:58:50 DBG] >         OpenPassiveDataStreamAsync(PASV, "STOR FILE_NAME.FILE_NAME", 0)
[08:58:50 INF] Command:  PASV
[08:58:50 DBG] Status:   Waiting for response to: PASV
[08:58:50 INF] Response: 227 Entering Passive Mode (1.1.1.1,76,102). [1ms]
[08:58:50 DBG] Status:   PASV advertised a non-routable IPAD. Using original connect dnsname/IPAD
[08:58:50 INF] Status:   Connecting to IP #1= 1.1.1.1:19558
[08:58:50 INF] Command:  STOR FILE_NAME.FILE_NAME
[08:58:50 DBG] Status:   Waiting for response to: STOR FILE_NAME.FILE_NAME
[08:58:50 INF] Response: 501 Unknown extension in database file name. [<1ms]
[08:58:50 DBG] Status:   Disposing(async) FtpSocketStream(data connection of AsyncFtpClient)
[08:58:50 DBG] >         CloseDataStream()
[08:58:50 DBG] Status:   Error encountered uploading file
[08:58:50 DBG] >         Disconnect()
[08:58:50 INF] Command:  QUIT
[08:58:50 DBG] Status:   Waiting for response to: QUIT
[08:58:50 INF] Response: 221 QUIT subcommand received. [1ms]
[08:58:50 DBG] Status:   Disposing(async) FtpSocketStream(control connection of AsyncFtpClient)
FanDjango commented 1 month ago

Thank you very much for this log.

As you already noted,

[08:58:50 INF] Command:  NLST /QSYS.LIB/DEFAULT_LIBRARY.LIB
[08:58:50 DBG] Status:   Waiting for response to: NLST /QSYS.LIB/DEFAULT_LIBRARY.LIB
[08:58:50 DBG] Response: 125-NAMEFMT set to 1.
[08:58:50 INF] Response: 125 List started. [15ms]

this 125-NAMEFMT set to 1 as part of the response to the NLST command is the problem.

You are the second to report such a "strange" NAMEFMT command that certainly was not issued by FluentFTP.

The first such report can be found here: here

That report is actually what prompted the AfterConnect action to be added.

Before any more "quick fixes" muddle up things up further, I would like to understand more about problem.

You seem to be able to test this more directly than the other user, who needs to deploy to customers and then gather information back. If that is the case, would you help in finding out the logic behing the unsolicited NAMEFMT commands?

What would interest me most, initially, is: What does the verbose log of the same transfer look like if use a FluentFTP version before the change? I would suppose that the unsolicited "NAMEFMT set to 1" does not happen?

smeiff commented 1 month ago

Here are the logs by implementing custom server handler without the AfterConnected calls. 

[09:18:49 DBG] >         Connect(False)
[09:18:49 DBG] Status:   FluentFTP 50.0.1.0(.NET 6.0) AsyncFtpClient
[09:18:49 INF] Status:   Connecting to IP #1= [1.1.1.1:21](http://1.1.1.1:21/)
[09:18:49 DBG] Status:   Waiting for a response
[09:18:49 DBG] Response: 220-QTCP at [myftp.server.com](http://myftp.server.com/).
[09:18:49 INF] Response: 220 Connection will close if idle more than 10 minutes. [739014.555d]
[09:18:49 INF] Status:   Detected FTP server: IBMOS400FTP
[09:18:49 INF] Command:  AUTH TLS
[09:18:49 DBG] Status:   Waiting for response to: AUTH TLS
[09:18:49 INF] Response: 431 Requested security mechanism not available at this time. [1ms]
[09:18:49 INF] Command:  USER ***
[09:18:49 DBG] Status:   Waiting for response to: USER ***
[09:18:49 INF] Response: 331 Enter password. [1ms]
[09:18:49 INF] Command:  PASS ***
[09:18:49 DBG] Status:   Waiting for response to: PASS ***
[09:18:49 INF] Response: 230 *** logged on. [2ms]
[09:18:49 INF] Command:  FEAT
[09:18:49 DBG] Status:   Waiting for response to: FEAT
[09:18:49 DBG] Response: 211-Feature listing follows:
Response: AUTH TLS
Response: AUTH GSS
Response: CCC
Response: PBSZ
Response: PROT
Response: ADAT
Response: ENC
Response: MIC
Response: CONF
[09:18:49 INF] Response: 211 End of feature listing. [49ms]
[09:18:49 INF] Status:   Text encoding: System.Text.UTF8Encoding+UTF8EncodingSealed
[09:18:49 INF] Command:  OPTS UTF8 ON
[09:18:49 DBG] Status:   Waiting for response to: OPTS UTF8 ON
[09:18:49 INF] Response: 501 OPTS unsuccessful; specified subcommand not recognized. [1ms]
[09:18:49 INF] Command:  SYST
[09:18:49 DBG] Status:   Waiting for response to: SYST
[09:18:49 INF] Response: 215  OS/400 is the remote operating system. The TCP/IP version is "V7R4M0". [1ms]
[09:18:49 DBG] Status:   Active ServerHandler is: IBMOS400FTP
[09:18:49 DBG] Status:   Listing parser set to: IBMOS400
[09:18:49 INF] Command:  PWD
[09:18:49 DBG] Status:   Waiting for response to: PWD
[09:18:49 INF] Response: 257 "DEFAULT_LIRBARY" is current library. [<1ms]
[09:18:49 DBG] >         UploadStream("FILE_NAME.FILE_NAME", Overwrite, False)
[09:18:49 DBG] >         FileExists("FILE_NAME.FILE_NAME")
[09:18:49 DBG] >         GetNameListing("DEFAULT_LIRBARY")
[09:18:49 INF] Command:  TYPE I
[09:18:49 DBG] Status:   Waiting for response to: TYPE I
[09:18:49 INF] Response: 200 Representation type is binary IMAGE. [<1ms]
[09:18:49 DBG] >         OpenDataStreamAsync("NLST DEFAULT_LIRBARY", 0)
[09:18:49 DBG] >         OpenPassiveDataStreamAsync(PASV, "NLST DEFAULT_LIRBARY", 0)
[09:18:49 INF] Command:  PASV
[09:18:49 DBG] Status:   Waiting for response to: PASV
[09:18:49 INF] Response: 227 Entering Passive Mode (1.1.1.1,81,20). [1ms]
[09:18:49 DBG] Status:   PASV advertised a non-routable IPAD. Using original connect dnsname/IPAD
[09:18:49 INF] Status:   Connecting to IP #1= [1.1.1.1:20756](http://1.1.1.1:20756/)
[09:18:49 INF] Command:  NLST DEFAULT_LIRBARY
[09:18:49 DBG] Status:   Waiting for response to: NLST DEFAULT_LIRBARY
[09:18:49 INF] Response: 125 List started. [12ms]
[09:18:49 DBG] +---------------------------------------+
[09:18:49 DBG] Listing:  FILE_NAME.FILE_NAME
[09:18:49 DBG] Listing:  FILE_NAME.FILE_NAME
[09:18:49 DBG] Status:   Disposing(async) FtpSocketStream(data connection of AsyncFtpClient)
[09:18:49 DBG] >         CloseDataStream()
[09:18:49 DBG] Status:   Waiting for response to: NLST DEFAULT_LIRBARY
[09:18:49 INF] Response: 250 List completed. [60ms]
[09:18:49 DBG] +---------------------------------------+
[09:18:49 DBG] >         OpenWrite("FILE_NAME.FILE_NAME", ASCII, -1, False)
[09:18:49 INF] Command:  TYPE A
[09:18:49 DBG] Status:   Waiting for response to: TYPE A
[09:18:49 INF] Response: 200 Representation type is ASCII nonprint. [<1ms]
[09:18:49 DBG] >         OpenDataStreamAsync("STOR FILE_NAME.FILE_NAME", 0)
[09:18:49 DBG] >         OpenPassiveDataStreamAsync(PASV, "STOR FILE_NAME.FILE_NAME", 0)
[09:18:49 INF] Command:  PASV
[09:18:49 DBG] Status:   Waiting for response to: PASV
[09:18:49 INF] Response: 227 Entering Passive Mode (1.1.1.1,253,158). [1ms]
[09:18:49 DBG] Status:   PASV advertised a non-routable IPAD. Using original connect dnsname/IPAD
[09:18:49 INF] Status:   Connecting to IP #1= [1.1.1.1:64926](http://1.1.1.1:64926/)
[09:18:49 INF] Command:  STOR FILE_NAME.FILE_NAME
[09:18:49 DBG] Status:   Waiting for response to: STOR FILE_NAME.FILE_NAME
[09:18:49 INF] Response: 150 Sending file to member FILE_NAME in file FILE_NAME in library DEFAULT_LIRBARY. [1ms]
[09:18:49 DBG] Status:   Uploaded 0 bytes
[09:18:49 DBG] Status:   Disposing(async) FtpSocketStream(data connection of AsyncFtpClient)
[09:18:49 DBG] Status:   Waiting for response to: STOR FILE_NAME.FILE_NAME
[09:18:49 INF] Response: 226 File transfer completed successfully. [53ms]
[09:18:49 DBG] >         Disconnect()
[09:18:49 INF] Command:  QUIT
[09:18:49 DBG] Status:   Waiting for response to: QUIT
[09:18:49 INF] Response: 221 QUIT subcommand received. [<1ms]
[09:18:49 DBG] Status:   Disposing(async) FtpSocketStream(control connection of AsyncFtpClient)
FanDjango commented 1 month ago

OK. Back to the original one, where you tried to set NAMEFMT back to zero. But we forgot one detail: previously after connect there was a PWD command (done with NAMEFMT 1). So the GetNameListing was done with a path/filename from the PWD, and IBM i saw the leading slash and set NAMEFMT to 1, etc. etc. which contradicted what you actually want. It is probably a "convenience" for the user that they programmed into it.

Try setting NAMEMFT (and LISTFMT) to zero, and then execute a PWD which should then contain the NAMEFMT 0 pwd format, this then goes into GetNameListing. This should do it.

FanDjango commented 1 month ago

Meanwhile here I will think about how to solve the actual problem: The desired NAMEFMT (and LISTFMT) settings are lost when an automatic reconnect takes place and simply setting these to 1 on connect as a solution to that is good for most users but not for all (you, for example).

smeiff commented 1 month ago

Adding PWD after resetting values to 0 did not work. PWD returned the correct path, but was then followed up with GetNameListing("QSYS.LIB/LIBRARY.LIB") which is what we see when it think the NAMEFMT is set to 1.

I still did see the call later stating NAMEFMT is 1.

FanDjango commented 1 month ago

Adding PWD after resetting values to 0 did not work. PWD returned the correct path, but was then followed up with GetNameListing("QSYS.LIB/LIBRARY.LIB") which is what we see when it think the NAMEFMT is set to 1.

Thanks for trying that.

I will try to find out where GetNameListing("QSYS.LIB/LIBRARY.LIB") is coming from, then. Because I think that this causes the NAMEFMT 1 to be issued automatically.

FanDjango commented 1 month ago

This will need a few more days, currently testing a few things. Please stand by.

But: Do I read this correctly:

Here are the logs by implementing custom server handler without the AfterConnected calls.

You have got a workaround, so that this issue is no longer quite so urgent?

smeiff commented 1 month ago

Correct, not urgent. However just found out the initial directory listing being printed breaks the application entirely. Our folder is so large it sits printing out the directory until it times out. Will have to revert.

FanDjango commented 1 month ago

The initial NLST is solely for the purpose of determining: Does the file already exist on the server, does it need to be deleted first. OVERWRITE is what causes this to happen. Examine the parameters available to the upload to perhaps circumvent this. If you know the file exists, consider deleting it yourself and then dont use OVERWRITE.

FanDjango commented 1 month ago

However just found out the initial directory listing being printed breaks the application entirely. Our folder is so large it sits printing out the directory until it times out. Will have to revert.

And that did not happen in the old version of FluentFTP?

That's why I was hoping for a LOG of the version "where it works" instead of a log, where you use a custom handler that does not do the initial commands.

So something else also must have changed...

On my system I am having trouble reproducing this - no database available right now.

FanDjango commented 1 month ago

I mean to say, that I can remove the inititial setting of NAMEFMT and LISTFMT on connect (or make it configurable), but your experience seems to show that something beyond that is also different. You removed the initial settings with your custom server handler and still there was something going wrong.

smeiff commented 1 month ago

Edit: I could not get v50 to work. I made a mistake testing.

The last version I found to work was v39.0.1. This version does not use the newer logging platform. We were using OnLogEvent to throw into our logger. These are the logs captured from this version

[08:55:23 DBG] TestSendingFTPtoGMI  entry point
[08:55:23 DBG] >         AutoConnectAsync()
[08:55:23 DBG] >         AutoDetectAsync(True, False)
[08:55:23 DBG] >         ConnectAsync()
[08:55:23 INF] Status:   Connecting to ***:21
[08:55:23 DBG] Response: 220-QTCP at [myftp.com](http://myftp.com/).
[08:55:23 INF] Response: 220 Connection will close if idle more than 5 minutes.
[08:55:23 INF] Status:   Detected FTP server: IBMOS400FTP
[08:55:23 INF] Command:  AUTH TLS
[08:55:23 INF] Response: 431 Requested security mechanism not available at this time.
[08:55:23 INF] Command:  USER ***
[08:55:23 INF] Response: 331 Enter password.
[08:55:23 INF] Command:  PASS ***
[08:55:23 INF] Response: 230 USERNAME logged on.
[08:55:23 INF] Command:  FEAT
[08:55:24 DBG] Response: 211-Feature listing follows:
Response: AUTH TLS
Response: AUTH GSS
Response: CCC
Response: PBSZ
Response: PROT
Response: ADAT
Response: ENC
Response: MIC
Response: CONF
[08:55:24 INF] Response: 211 End of feature listing.
[08:55:24 INF] Status:   Text encoding: System.Text.UTF8Encoding+UTF8EncodingSealed
[08:55:24 INF] Command:  OPTS UTF8 ON
[08:55:24 INF] Response: 501 OPTS unsuccessful; specified subcommand not recognized.
[08:55:24 INF] Command:  SYST
[08:55:24 INF] Response: 215  OS/400 is the remote operating system. The TCP/IP version is "V7R4M0".
[08:55:24 DBG] Status:   Listing parser set to: IBMOS400
[08:55:24 DBG] >         UploadStreamAsync("TEST.TEST", Overwrite, False)
[08:55:24 DBG] >         FileExistsAsync("TEST.TEST")
[08:55:24 INF] Command:  PWD
[08:55:24 INF] Response: 257 " MYLIBRARY " is current library.
[08:55:24 DBG] >         GetNameListingAsync("MYLIBRARY ")
[08:55:24 INF] Command:  TYPE I
[08:55:24 INF] Response: 200 Representation type is binary IMAGE.
[08:55:24 DBG] >         OpenPassiveDataStreamAsync(PASV, "NLST MYLIBRARY / MYLIBRARY ", 0)
[08:55:24 INF] Command:  PASV
[08:55:24 INF] Response: 227 Entering Passive Mode (10,120,29,43,199,255).
[08:55:24 INF] Status:   Connecting to ***:51199
[08:55:24 INF] Command:  NLST MYLIBRARY / MYLIBRARY
[08:55:24 INF] Response: 125 List started.
[08:55:24 DBG] +---------------------------------------+
[08:55:24 DBG] Listing:  MYLIBRARY.LCE.LCE
[08:55:24 DBG] Listing:  [MYLIBRARY.PS.PS](http://mylibrary.ps.ps/)
[08:55:24 DBG] Listing:  MYLIBRARY. MYLIBRARY
[08:55:24 DBG] Status:   Disposing FtpSocketStream...
[08:55:24 DBG] >         CloseDataStream()
[08:55:24 INF] Response: 250 List completed.
[08:55:24 DBG] +---------------------------------------+
[08:55:24 DBG] Status:   Disposing FtpSocketStream...
[08:55:24 DBG] >         OpenWriteAsync("TEST.TEST", ASCII)
[08:55:24 DBG] >         GetFileSizeAsync("TEST.TEST", -1)
[08:55:24 INF] Command:  TYPE A
[08:55:24 INF] Response: 200 Representation type is ASCII nonprint.
[08:55:24 DBG] >         OpenPassiveDataStreamAsync(PASV, "STOR TEST.TEST", 0)
[08:55:24 INF] Command:  PASV
[08:55:24 INF] Response: 227 Entering Passive Mode (10,120,29,43,141,166).
[08:55:24 INF] Status:   Connecting to ***:36262
[08:55:24 INF] Command:  STOR TEST.TEST
[08:55:24 INF] Response: 150 Sending file to member TEST in file TEST in library MYLIBRARY.
[08:55:24 DBG] Status:   Disposing FtpSocketStream...
[08:55:24 INF] Response: 226 File transfer completed successfully.
[08:55:24 INF] Command:  QUIT
[08:55:24 INF] Response: 221 QUIT subcommand received.
[08:55:24 DBG] Status:   Disposing FtpSocketStream...
FanDjango commented 1 month ago

I am thoroughly confused now. Logs (filenames, dirnames) are different, redacted. You say logging is also contributing in some fashion.

Although you have provided logs (thank you for that), you will realise that none of them relate to each other in such a fashion that I can deduce some sort of logic from them.

All I can confirm, is that it would be a good idea to allow the user to disable the initial AfterConnect actions.

But I cannot see that that is the only problem you are having. So even if the AfterConnect actions do not take place, does it then work?

smeiff commented 1 month ago

Understandable. Sorry for not keeping the same names in the replacement. The directory output is much different than the listing in the newer version. I'm not sure why it's logging library_name.lce.lce or any of those instead of the actual files on the server like we see in v50. It sounds like the logic in the older version was just broken and we were benefiting from this.

In the example on v50 I was using a custom server handler where it did not send the NAMEFMT and LISTFMT commands. Therefore I did not have to undo those commands. It would be much cleaner to have the AfterConnect logic optional as right now I have to specify the server type ahead of time so the code knows which server handler to use.

In the end it looks like we will be sticking with v39 due to the required directory listing in the newer versions that breaks the functionality. We just have way too many files sitting on the FTP.

FanDjango commented 1 month ago

In the end it looks like we will be sticking with v39 due to the required directory listing in the newer versions that breaks the functionality.

I suggest you moderate your statement. It is an untruth.

required directory listing in the newer versions

There are ways to avoid this, it is not "required", it is done for users who want this convenience. Since the server provides no way to ascertain the existance of a file, we resort to listing the entire directory to find this out. If you were so versatile as to simply delete the file first (and ignore a possible failure to delete a non-existant file), then perform the upload by setting the flags to not check for existence, no NLST of huge proportions would be done.

I am closing this issue as each and every step above has been a non-sequitur and we are not progressing at all.

This:

All I can confirm, is that it would be a good idea to allow the user to disable the initial AfterConnect actions.

is all that remains.

FanDjango commented 3 weeks ago

AfterConnected commands can now be disabled by setting Config.EnableAfterConnected to false, this has been merged into current master and will at some point in time be released to Nuget.