Unable to connect (failed directory listing)

[driici]

Hello I have compiled latest proftpd with latest (but tried some older vesions of both) mod_proxy on debian 10 and having issues with connections

proftpd -V: https://pastebin.com/YwpkNXJU proftpd.conf: https://pastebin.com/EQ3yKpv4 (redacted password backend connection string)

I have also another instance of proftpd with mod_proxy on older machine (debian 8) and it works flawlessly - firewall config is same, proftpd config is same also.

Strange thing is that some connections are done OK, some fails after directory listing (MLSD or LIST command). Backend connection succeeded according logs. When listing fails, I was able to find some information from log, but not sure if they're relevant:

2020-04-20 12:40:18,950 mod_proxy/0.5[15455]: client sent RFC1918 address '10.8.0.2' in PORT command, ignoring it and using '46.36.xxx.xxx'
2020-04-20 12:40:19,538 mod_proxy/0.5[15455]: unable to connect to 46.36.xxx.xxx#0: Invalid argument

Is there any more informations I should provide? Thanks

[Castaglia]

Can you provide all the logs that you can, for both successful and failing directory listings? I'm hoping to see what might be different between the success and failure cases...

[driici]

Hi, thanks for your time. First connection in logs is failing, second one is OK. From my perspective I dont see much differences.

logs attached: ftp.zip

[Castaglia]

Thanks for those. Nothing standing out just yet. So, to get more data, would you mind adding more to your Trace directive? Specifically:

  Trace proxy:30 \
    command:20 \
    proxy.conn:30 \
    proxy.db:30 \
    proxy.forward:30 \
    proxy.ftp.conn:30 \
    proxy.ftp.ctrl:30 \
    proxy.ftp.data:30 \
    proxy.ftp.msg:30 \
    proxy.ftp.sess:30 \
    proxy.ftp.xfer:30 \
    proxy.inet:30 \
    proxy.netio:30 \
    proxy.random:30 \
    proxy.reverse:30 \
    proxy.reverse.db:30 \
    proxy.reverse.redis:30 \
    proxy.session:30 \
    proxy.tls:30 \
    proxy.tls.db:30 \
    proxy.tls.redis:30 \
    proxy.uri:30 \
    response:20

And then provide the logs for a successful, and failed, directory listing? Hopefully the increased logging will provide more clues.

[driici]

Hi, hope these will help. proftpd.notworking.zip proftpd.working.zip

[Castaglia]

Thanks for those; they do help.

In the not-working case, we see the "425 MLSD: Invalid argument" error response -- which can only come from here, based on the rest of the logs provided. And that, in turn, means that the proxy_ftp_conn_connect function here is the one returning the EINVAL error.

Looking at that function, we see that the only way the proxy_ftp_conn_connect function can return EINVAL -- without logging anything else, which we did not see in the provided logs -- is here, suggesting that either p (a memory pool) or remote_addr is null. That remote_addr comes from the "client sent RFC1918 address, ignoring it" code path in this situation. And there, a short-lived memory pool is used for that remote_addr object.

Based on this, I'm guessing that this PR might help? I'll work on trying to reproduce this exact scenario locally, but in the meantime, wanted to see if you, too, could test out the patch/PR, and see if it helps.

[driici]

Hello, sorry for delay. We had tested your commit, but have same issues.

[driici]

BUMP

[Castaglia]

@driici If I cannot reproduce the issue locally, then I cannot easily address/fix this. Barring that, I need something that reliably shows this error, in order to fix it.

[Castaglia]

@driici I'm hoping that https://github.com/Castaglia/proftpd-mod_proxy/commit/ebcf82c9f3e5668e2b0218712bba64ec3287d6be can also help to address this; can you try the latest mod_proxy code in your environment, and see if the issue has been addressed?

[aljasPOD]

I've encountered a similar issue (and spent a few hours debugging).

In my case the EINVAL was coming from the linux connect call (all the way from here).

Doing strace on the running binary gives this: While some versions of connect's man document some cases of EINVAL, I have not found this specific case there. It seems that the bind happens with an IPv6 (family) address, but the connect is with an IPv4.

Setting the ProxySourceAddress to the (IPv4) address of the host fixes the problem, the bind happens with a v4 address and the connection succeeds.

[Castaglia]

@aljasPOD thanks for digging into this! This reminds me of some logging changes I recently did for Issue #213, namely to try to add logging hints in cases where ProxySourceAddress might be needed. In the case of this other issue, the cause was a mismatch between public/privately routable IP addresses -- but this case here, of IPv6 vs IPv4 is another such scenario. I'll see about adding similar detection/logging, to try to make it clearer to admins what the solution might be.

[Castaglia]

Interestingly, I do see that mod_proxy attempts to handle such IPv6/IPv4 cases here -- but that's when establishing the backend control connection; when making the backend data connection (as for file transfers, directory listings) here, we are not doing similar checking, and we should be.

[Castaglia]

@driici Would you be able to test the latest mod_proxy code, to see if your issue still occurs? Thanks!

[Castaglia]

@driici Actually, in looking back through your logs with fresh eyes, I think the issue you encountered is different than that of @aljasPOD. The recent commits should make the behavior work for @aljasPOD -- but not for @driici.

Here's what I see, for @driici 's nonworking use case:

• Frontend FTP client connects to proxy, running on 46.36.37.xx; proxy selects backend of 46.36.39.xx
• Frontend FTP client sends PORT 10.8.0.2 to proxy, which should have rejected this sooner (since it means that client is saying "I contacted you, server at public IP 46.36.37.xx, but I want you to connect to me on private IP space address 10.8.0.2" (which usually indicates a naive/badly behaving FTP client)
• Proxy, instead, sends EPSV command to backend (because of ProxyDataTransferPolicy passive configuration), which succeeds
• Proxy responds to frontend client's PORT command with 200 response, saying "Yes, that's OK" (and it should not have done this)
• Frontend FTP client sends MLSD command to start the directory listing -- and that is when the proxy complains, since it cannot connect to the frontend client IP address 10.8.0.2.

In the working use case, the one thing that is different is that the frontend client's PORT command contains a public IP address, i.e. 82.144.144.xx, rather than the private IP address 10.8.0.2. Why would the frontend client use a public or private IP addresses in these two cases? The mod_proxy (and backend server) configurations are the same, so there must be something else that is different, for the frontend FTP client. Maybe there's some NAT, firewall, or HAproxy in one case and not the other?

I'll try to confirm the above hypothesis by reproducing the above behaviors locally.

[Castaglia]

I've confirmed that mod_proxy does indeed properly reject PORT, EPRT commands that tell the server to use an IP address that is different than the client's IP address for the control connection.

I'd thus like to close this ticket, and we'll use new tickets for any more issues that arise. Sound good?