[SOLVED] FreePBX 16 - SSH Filestore can't log in - because it uses SFTP!

FreePBX System Administration
1

Hi folks, I’m deeply puzzled.

I’ve set up a new FreePBX 16 server, patched up to date, and I’m unable to backup using the SSH file store (but I can use S3 thank goodness).

I’ve copied the public key data from the source /home/asterisk/.ssh/id_rsa.pub to the destination and inserted the contents in the remote /home/freepbx/.ssh/authorized_keys file.

I’ve verified that for the asterisk user on the source, the required destination server is in the known_hosts file, by doing a repeated manual ssh, which thereafter works perfectly fine with no extra confirmations or passwords required (please accept my [*REDACTIONS*] in the excerpts below)

[asterisk@freepbx ~]$ ssh -i ~/.ssh/id_rsa freepbx@[*HOSTNAME*] -p [*PORT*]
freepbx@[*HOSTNAME*]:~$ logout
Connection to [*HOSTNAME*] closed.

I’ve checked that the public key is an RSA key and nothing “funky” as per this thread by looking at the start of the key (ssh-rsa AAAA....) and adding the debug to the ssh command so it says:

debug1: Offering RSA public key: /home/asterisk/.ssh/id_rsa
debug1: Server accepts key: pkalg ssh-rsa blen 535
debug1: Authentication succeeded (publickey).

However, when I run the backup it fails with nothing more helpful than:

Finished created backup file: 20230121-215250-1674337970-16.0.30-486126098.tar.gz
Performing Local Maintenance
Finished Local Maintenance
Performing Remote Maintenance
Could not login with username: freepbx, host: [*HOSTNAME*]
Finished Remote Maintenance
Saving to selected Filestore locations
Could not login with username: freepbx, host: [*HOSTNAME*]
Finished Saving to selected Filestore locations
There were errors during the backup process
	Could not login with username: freepbx, host: [*HOSTNAME*]
	Could not login with username: freepbx, host: [*HOSTNAME*]

While the backup is running I can see a successful TCP connection (three in fact, by repeatedly running netstat -an | fgrep [*PORT*]:

tcp        0      0 [*SOURCEIP*]:43122     [*DESTIP*]:[*PORT*]     ESTABLISHED
tcp        0      0 [*SOURCEIP*]:43122     [*DESTIP*]:[*PORT*]     TIME_WAIT

tcp        0      0 [*SOURCEIP*]:43138     [*DESTIP*]:[*PORT*]     ESTABLISHED

tcp        0     64 [*SOURCEIP*]:43140     [*DESTIP*]:[*PORT*]     ESTABLISHED

Does anyone have insight as to why the connection from the fwconsole backup is failing, but from ssh at the console it’s perfectly happy?

Cheers
Mike

2

Are you using fqdn in the ssh test and the backup? If so have you tried with just IP? Maybe it’s a name lookup problem.

You could also look through /var/log/sshd on the destination server to see if there are any relevant logs:

cat /var/log/secure | grep sshd

Or you could even monitor it in real time while performing the backup.

tail -f /var/log/secure
3

Thanks Igor. All connections are using FQDN and the DNS resolution is fine, as I showed above the TCP connections are opened properly to the expected IP addresses.

The target is a Synology NAS, so there’s no /var/log/secure - I’ll see if there’s an equivalent, but my immediate Googling doesn’t fill me with confidence.

But since I can login from the CLI, and I’m (supposed to be!) offering the same credentials with the file store, I’m baffled by why the destination would act differently? So I’m presuming something in the file store configuration or the way the connection is opened is different to doing it from the command line.

Filestore parameters:

Type:     SSH (duh!)
Enabled:  Yes
Hostname: [*HOSTNAME*] (same as in my post above)
Port:     [*PORT*] (same as in my post above)
Username: freepbx
Key:      /home/asterisk/.ssh/id_rsa
Path:     /var/services/homes/freepbx/newserver/
4

If you are confident that your PBX configuration doesn’t have any problems then I don’t think you’ll get very far without getting the sshd logs from the Synology to be able to tell why those specific connections from the backup application are not being allowed through.

It could be that the Synology is not allowing file transfer over SSH. Maybe you could test with SCP or something else and send a file manually to the Synology to see what happens?

5

Yeah, I’m in full agreement. The problem is that same Synology box is already hosting SSH backups from my earlier FreePBX14 installation! Thus my deep puzzlement:

  • FreePBX14 SSH backup → Synology (works fine, has for years)

  • FreePBX16 SSH login → Synology (works exactly as expected)

  • FreePBX16 SSH backup → Synology (fails to login).

The only odd thing I’ve spotted this morning is that the root volume on the FreePBX16 box has filled up - I’m not sure if that’s as a result of lots of failed backups, so I’ll address that in case it’s contributing to the issue.

[Later] It wasn’t the backups - fail2ban seems to have gone insane and has filled the disk with 10GB of logs. I’m going to resolve that problem first as it likely confounds this one. I will report back!

6

Hmm. Something odd is still going on. I’ve cleared the filesystem blockage (and will investigate that separately).

I am able to copy a test file from FreePBX to the Synology with scp using the private/public key pair:

[asterisk@pharos-pbx-3 ~]$ scp -v -i /home/asterisk/.ssh/id_rsa -P [*PORT*] ./testfile freepbx@[**HOSTNAME]:/var/services/homes/freepbx/newserver/testfile
Executing: program /usr/bin/ssh host [*HOSTNAME*], user freepbx, command scp -v -t /var/services/homes/freepbx/newserver/testfile
OpenSSH_7.4p1, OpenSSL 1.0.2k-fips  26 Jan 2017
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: /etc/ssh/ssh_config line 58: Applying options for *
debug1: Connecting to [*HOSTNAME*] [*DESTIP*] port [*PORT*].
debug1: Connection established.
debug1: identity file /home/asterisk/.ssh/id_rsa type 1
debug1: key_load_public: No such file or directory
debug1: identity file /home/asterisk/.ssh/id_rsa-cert type -1
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_7.4
debug1: Remote protocol version 2.0, remote software version OpenSSH_7.4
debug1: match: OpenSSH_7.4 pat OpenSSH* compat 0x04000000
debug1: Authenticating to [*HOSTNAME*]:[*PORT*] as 'freepbx'
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug1: kex: algorithm: curve25519-sha256
debug1: kex: host key algorithm: ecdsa-sha2-nistp256
debug1: kex: server->client cipher: [email protected] MAC: <implicit> compression: none
debug1: kex: client->server cipher: [email protected] MAC: <implicit> compression: none
debug1: kex: curve25519-sha256 need=64 dh_need=64
debug1: kex: curve25519-sha256 need=64 dh_need=64
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
debug1: Server host key: ecdsa-sha2-nistp256 SHA256:qx0s6ud89h5SGbbCgK6K84Z7VhpON3on7WSZlzN0pSo
debug1: Host '[*HOSTNAME*]:[*PORT*]' is known and matches the ECDSA host key.
debug1: Found key in /home/asterisk/.ssh/known_hosts:1
debug1: rekey after 134217728 blocks
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug1: SSH2_MSG_NEWKEYS received
debug1: rekey after 134217728 blocks
debug1: SSH2_MSG_EXT_INFO received
debug1: kex_input_ext_info: server-sig-algs=<ssh-ed25519,ssh-rsa,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521>
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug1: Authentications that can continue: publickey,password
debug1: Next authentication method: publickey
debug1: Offering RSA public key: /home/asterisk/.ssh/id_rsa
debug1: Server accepts key: pkalg ssh-rsa blen 535
debug1: Authentication succeeded (publickey).
Authenticated to [*HOSTNAME*] ([*DESTIP*]:[*PORT*]).
debug1: channel 0: new [client-session]
debug1: Requesting [email protected]
debug1: Entering interactive session.
debug1: pledge: network
debug1: client_input_global_request: rtype [email protected] want_reply 0
debug1: Sending environment.
debug1: Sending env LANG = en_GB.UTF-8
debug1: Sending command: scp -v -t /var/services/homes/freepbx/newserver/testfile
Sending file modes: C0644 47 testfile
Sink: C0644 47 testfile
testfile                                      100%   47     4.7KB/s   00:00    
debug1: client_input_channel_req: channel 0 rtype exit-status reply 0
debug1: channel 0: free: client-session, nchannels 1
debug1: fd 0 clearing O_NONBLOCK
debug1: fd 1 clearing O_NONBLOCK
Transferred: sent 3788, received 3304 bytes, in 0.2 seconds
Bytes per second: sent 19288.2, received 16823.7
debug1: Exit status 0

And it arrived as expected:

freepbx@moneta-pharos:~/newserver$ cat /var/services/homes/freepbx/newserver/testfile
Hello Synology - Nice to be here
Regards, FreePBX

But the backup jobs are still failing with the same error:

Performing Remote Maintenance
Could not login with username: freepbx, host: [*HOSTNAME*]
7

So enable logging in sshd_config on the Synology – it’s running the same version you have on the PBX.

8

Hi @Stewart1 - unfortunately I’ve not discovered how to do that on the Synology itself, the link I mentioned above suggests it’s far from trivial either.

9

I know nothing about Synology, but maybe try running sshd in the foreground with -d switch(es), or find out what client FreePBX backup is using and try logging there.

If both of those fail, you can’t see much with a packet capture, because everything after the key exchange is encrypted. However, you can tell if it does complete the key exchange, and get a rough idea where it’s failing by seeing how many packets go in each direction after that.

10

Another thought: Instead of the Synology, test by doing an SSH file store backup to a ‘regular’ computer (cloud server, local VM, whatever you’ve got). If it fails the same way, you can easily enable logging. If it works, it’s a good bet that a difference in the sshd_config files is the culprit, which with luck should be easy to spot.

11

Thanks @Stewart1 - but as per updates above, the key exchange for a regular SSH connection to the same box with the same key works fine.

The puzzle is - what’s different with the FreePBX backup? Like you say that’s going to be shown in the payload (inside the encrypted tunnel that we can’t see). Unfortunately the Synology box is remote (which makes restarting sshd somewhat risky if I stuff something up) and behind a firewall I don’t control, so I can’t start a second sshd on another port.

As I said in the intro - I’m able to backup to AWS S3 buckets no problem at all, and this exact same Synology NAS has been acting as the backup for my FreePBX14 installation, and continues to do so.

Therefore I believe something has changed between FreePBX14 and 16, which offends the delicate sensibilities of the Synology NAS, but only when doing backups…

Thus, my deep puzzlement.

12

But does the key exchange from your FreePBX 16 backup to a ‘regular’ computer work fine?

If not, that’s something you can easily troubleshoot.

If yes, just compare sshd_config files between that computer and the Synology. You could test a hypothesis by changing sshd_config on the test computer to see if that breaks it and if so try to design a fix.

Yes, but that’s using a different protocol unrelated to SSH.

13

I misread your post, I’m aware S3 is very different, and won’t help troubleshoot this issue. I only meant I’m not in dire circumstances as I can back this installation up elsewhere if needed.

It’s bugging me that this particular Synology is also the SSH backup for a FreePBX14 installation, which is working fine! Therefore I’m pretty sure there’s something different at the FreePBX end (no great surprise as 16 >> 14!).

I just wish I understood more of the differences in the FreePBX 16 tools:

  • ssh login works and
  • scp file works but
  • fwconsole backup fails.

I can be pretty confident that SSH backup to a “regular” machine will work (though I’ll try to set something up to test) otherwise there would have been a lot of noise made already. This feels like a particular combination of:

  • FreePBX14.0.16.11 → Synology NAS DSM 6.2.4-25556 Update 6 is OK, but
  • FreePBX16.0.30 → Synology NAS DSM 6.2.4-25556 Update 6 is not.

Given the age and end of software support for the Synology box (DS215j) this particular issue may be insoluble, and I have to redirect backups elsewhere than the Synology. It’s had a good innings.

One test I hadn’t thought of, prompted by your replies (thanks again btw!) would be to backup to a newer Synology that I also have access to… hmmm. I’ll carry on experimenting, will report back.

14

So this still doesn’t work to a more recent Synology NAS either (DSM 7.1.1-42962 Update 3 on DS918+).

I have the same symptoms, I can faultlessly perform ssh login to the target account, and scp files to the target folder, from the FreePBX node. But I can’t complete an “SSH” backup.

I’m putting air quotes on “SSH” because I can reproduce one failure mode from the command line - connecting using SFTP immediately fails, just as with the backup job.

[asterisk@pharos-pbx-3 ~]$ ssh -i /home/asterisk/.ssh/id_rsa michthom@[*HOSTNAME*] -p [*PORT*]
michthom@NAS-Maven:~$ exit
logout
Connection to [*HOSTNAME*] closed.

[asterisk@pharos-pbx-3 ~]$ scp -i /home/asterisk/.ssh/id_rsa -P [*PORT*] /tmp/mike michthom@[*HOSTNAME*]:/var/services/homes/michthom/mike
mike      100% 5279   235.4KB/s   00:00

[asterisk@pharos-pbx-3 ~]$ sftp -i /home/asterisk/.ssh/id_rsa -P 59421 [email protected]
subsystem request failed on channel 0
Couldn't read packet: Connection reset by peer

Does FreePBX (Always? Only on FreePBX15+??) use SFTP under the covers to accomplish the “SSH” backup?

It seems to be the case: configuring access to the SFTP port has fixed my problem!!

Finished created backup file: 20230122-223433-1674426873-16.0.30-1291127048.tar.gz
Performing Local Maintenance
Finished Local Maintenance
Performing Remote Maintenance
Finished Remote Maintenance
Saving to selected Filestore locations
	Saving to: SSH:'Nas-SFTP' instance ,File location: /homes/michthom/20230122-223433-1674426873-16.0.30-1291127048.tar.gz 
Finished Saving to selected Filestore locations
15

This topic was automatically closed 7 days after the last reply. New replies are no longer allowed.