Test execution hang in test1_Ftp4JSimple

[amottier]

In my attempt to build Waarp from sources available in https://github.com/fredericBregier/Waarp-All/tree/v3.6.0 I'm now facing an issue related to test execution.

Here is the latest logs I got when Waarp Ftp R66 client tests are executed:

Starting test: test1_Ftp4JSimple
10:29:26.614 [main] WARN  org.waarp.ftp.client.AbstractFtpClient - org.waarp.ftp.client.AbstractFtpClient.testFtp4J(AbstractFtpClient.java:172) : First connexion
10:29:26.902 [main] WARN  org.waarp.ftp.client.AbstractFtpClient - org.waarp.ftp.client.AbstractFtpClient.testFtp4J(AbstractFtpClient.java:182) : Create Dirs
.
10:29:26.923 [main] WARN  org.waarp.ftp.client.AbstractFtpClient - org.waarp.ftp.client.AbstractFtpClient.testFtp4J(AbstractFtpClient.java:193) : Feature commands
SITE: true
SITE CRC: true
CRC: true
MD5: true
SHA1: true
DIGEST: true
10:29:26.944 [main] WARN  org.waarp.ftp.client.AbstractFtpClient - org.waarp.ftp.client.AbstractFtpClient.testFtp4J(AbstractFtpClient.java:201) : Logout
10:29:26.947 [main] WARN  org.waarp.ftp.client.AbstractFtpClient - org.waarp.ftp.client.AbstractFtpClient.testFtp4J(AbstractFtpClient.java:205) : Will start 1 Threads
10:29:27.117 [pool-1-thread-1] WARN  org.waarp.ftp.client.transaction.FtpClientThread - org.waarp.ftp.client.transaction.FtpClientThread.run(FtpClientThread.java:123) : T0 change mode passive

On another attempt I also got the following logs:

15:24:33.403 [pool-1-thread-1] WARN  org.waarp.ftp.client.transaction.FtpClientThread - org.waarp.ftp.client.transaction.FtpClientThread.run(FtpClientThread.java:123) : T0 change mode passive
...
15:24:33.863 [Data-3] WARN  org.waarp.ftp.core.data.handler.DataNetworkHandler - org.waarp.ftp.core.data.handler.DataNetworkHandler.channelActive(DataNetworkHandler.java:227) : DataChannel immediately closed since RETR is not ok at startup
15:24:34.062 [Data-4] WARN  org.waarp.ftp.core.data.handler.DataNetworkHandler - org.waarp.ftp.core.data.handler.DataNetworkHandler.channelActive(DataNetworkHandler.java:227) : DataChannel immediately closed since RETR is not ok at startup
15:24:34.067 [pool-1-thread-1] ERROR org.waarp.ftp.client.WaarpFtp4jClient - org.waarp.ftp.client.WaarpFtp4jClient.transferFile(WaarpFtp4jClient.java:505) : null: Retrieve operation not allowed
15:24:35.409 [Data-3] WARN  org.waarp.ftp.core.data.FtpTransferControl - org.waarp.ftp.core.data.FtpTransferControl.abortTransfer(FtpTransferControl.java:603) : Abort problem : No Command currently running
15:24:35.412 [Data-3] WARN  org.waarp.ftp.core.data.FtpTransferControl - org.waarp.ftp.core.data.FtpTransferControl.setTransferAbortedFromInternal(FtpTransferControl.java:700) : Command cancelled
15:24:35.592 [Data-4] WARN  org.waarp.ftp.core.data.FtpTransferControl - org.waarp.ftp.core.data.FtpTransferControl.abortTransfer(FtpTransferControl.java:603) : Abort problem : No Command currently running

I guess that the hang is probably related to awaitTermination that is configured to wait for 12000 seconds (200 minutes).

Also I think the calculation System.currentTimeMillis() - 120000 * 60; might be wrong because it should be * 1000 instead of * 60 to convert from seconds to milliseconds.

If I can provide more information in order to help debugging please let me know.

[fredericBregier]

I will check !
Note that FTP(S) tests are highly sensible to speed since we are in local (127.0.0.1 loopback network), and therefore sometimes, the time of networking operation is too fast compared to FTP control vs data program actions (FTP protocol implies to manage 2 different connections in the same time with not enough information to be 100% sure the data connection is opened by the final correct client : wel known security hole). The FTP(S) server program tries its best to ensure security, in the price of extra computation that can be not fully compatible with "loopback" based tests.
However, it shall not be an issue (or rare), so the reason I will double check.

[fredericBregier]

@amottier I think I found it.
FTP control is somehow difficult (in particular in passive mode since there is no clue of who is trying to connect to the data port opened by the server), but now it is more likely to be more accurate, and moreover, active mode is now perfectly clear.
3.6.0 will correct this.

[fredericBregier]

@amottier Thanks !

[amottier]

I can confirm that I'm now able to have a successful build. Thanks a lot @fredericBregier!