22.01 - problem with ssh host key permissions after restore from backup, sshd fails to start

[oddussiben-3161]

did Reset Log Files yesterday. since then syslogd service is not starting :(

[luckman212]

I'm running out of ideas, but this sure seems like a bigger issue than just permissions on the ssh keys. You really need to hook up a console cable to see what's happening during boot, you'd probably spot the error pretty quickly.

I'd start thinking about backing up and reinstalling. Unless Netgate support has any other ideas.

[oddussiben-3161]

@luckman212 upgraded 2.5 to 2.6RC now syslogd started working :d

sshd is still down, here is the log

grep ssh /var/log/system.log

Jan 14 17:25:00 the sshguard[80932]: Exiting on signal.
Jan 14 17:25:00 the sshguard[26945]: Now monitoring attacks.
Jan 14 17:26:00 the sshguard[26945]: Exiting on signal.
Jan 14 17:26:00 the sshguard[95288]: Now monitoring attacks.
Jan 14 17:27:00 the sshguard[95288]: Exiting on signal.
Jan 14 17:27:00 the sshguard[92574]: Now monitoring attacks.
Jan 14 17:28:00 the sshguard[92574]: Exiting on signal.
Jan 14 17:28:00 the sshguard[32703]: Now monitoring attacks.
Jan 14 17:28:27 the check_reload_status[418]: starting sshd
Jan 14 17:29:00 the sshguard[32703]: Exiting on signal.
Jan 14 17:29:00 the sshguard[31906]: Now monitoring attacks.
Jan 14 17:30:00 the sshguard[31906]: Exiting on signal.
Jan 14 17:30:00 the sshguard[3832]: Now monitoring attacks.

[luckman212]

@oddussiben-3161 Still not clear what could be causing that. There's no way to turn off sshguard that I know of. Can you try showing some more context:

grep -B1 -A3 ssh /var/log/system.log

[oddussiben-3161]

grep -B1 -A3 ssh /var/log/system.log

Jan 15 09:41:00 the newsyslog[24752]: logfile turned over due to size>97K
Jan 15 09:41:00 the sshguard[39770]: Exiting on signal.
Jan 15 09:41:00 the sshguard[25944]: Now monitoring attacks.
Jan 15 09:42:00 the sshguard[25944]: Exiting on signal.
Jan 15 09:42:00 the sshguard[33294]: Now monitoring attacks.
Jan 15 09:43:00 the sshguard[33294]: Exiting on signal.
Jan 15 09:43:00 the sshguard[9172]: Now monitoring attacks.
Jan 15 09:44:00 the sshguard[9172]: Exiting on signal.
Jan 15 09:44:00 the sshguard[76252]: Now monitoring attacks.
Jan 15 09:44:03 the php[75348]: pfSsh.php: OpenVPN ID client01 PID 57590 still running, killing.
Jan 15 09:44:03 the kernel: ovpnc01: link state changed to DOWN
Jan 15 09:44:04 the check_reload_status[418]: Reloading filter
--
Jan 15 09:44:07 the php-fpm[61923]: /rc.newwanip: Removing static route for monitor 94.x.x.x and adding a new route through 10.x.x.x
Jan 15 09:44:07 the check_reload_status[418]: starting sshd
Jan 15 09:44:08 the php-fpm[61923]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.x.x.x.
Jan 15 09:44:11 the php-fpm[61923]: /rc.newwanip: Creating rrd update script
Jan 15 09:44:13 the php-fpm[61923]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - 10.x.x.x ->  10.x.x.x - Restarting packages.
--
Jan 15 09:44:59 the check_reload_status[418]: starting sshd
Jan 15 09:45:00 the sshguard[76252]: Exiting on signal.
Jan 15 09:45:00 the sshguard[17392]: Now monitoring attacks.
Jan 15 09:45:03 the php[15086]: /usr/local/sbin/acbupload.php: End of configuration backup to https://acb.netgate.com/save (success).
Jan 15 09:47:00 the sshguard[17392]: Exiting on signal.
Jan 15 09:47:00 the sshguard[78519]: Now monitoring attacks.
Jan 15 09:47:32 the php-fpm[35829]: /index.php: Successful login for user 'admin' from: 192.168.1.x (Local Database)

[luckman212]

@oddussiben-3161 Amazingly that still doesn't reveal much detail, I assume sshguard is failing or stuck in a loop because sshd isn't starting properly. And your logfile is too small and is rotating out the important part(s) before we get a chance to see them.

Try increasing your logfile size limit to 5000000 (5MB) and reboot, then run this command to look for sshd only:

grep -B2 -A5 sshd /var/log/system.log

[oddussiben-3161]

increased log size, after reboot

Jan 15 12:23:43 the kernel: coretemp0: <CPU On-Die Thermal Sensors> on cpu0
Jan 15 12:23:43 the kernel: lo0: link state changed to UP
Jan 15 12:23:44 the php-fpm[346]: /sshd: New alert found: pfSense has started creating missing SSH keys.  SSH Startup will be delayed.  Please note that reloading the filter rules and changes will be delayed until this operation is completed.
Jan 15 12:23:44 the check_reload_status[418]: Linkup starting igb0
Jan 15 12:23:44 the kernel:
Jan 15 12:23:44 the kernel: igb0: link state changed to UP
Jan 15 12:23:44 the kernel: igb0: link state changed to DOWN
Jan 15 12:23:44 the check_reload_status[418]: Linkup starting igb0
--
Jan 15 12:24:20 the kernel: done.
Jan 15 12:24:21 the root[84238]: /etc/rc.d/hostid: WARNING: hostid: unable to figure out a UUID from DMI data, generating a new one
Jan 15 12:24:21 the php-fpm[346]: /sshd: API to Telegram did not return data in expected format!
Jan 15 12:24:22 the php-fpm[32372]: /index.php: Successful login for user 'admin' from: 192.168.1.x (Local Database)
Jan 15 12:24:22 the sshguard[93066]: Now monitoring attacks.
Jan 15 12:24:23 the syslogd: exiting on signal 15
Jan 15 12:24:23 the syslogd: kernel boot file is /boot/kernel/kernel
Jan 15 12:24:23 the kernel: ovpnc1: link state changed to UP

[luckman212]

Not 100% sure, but it looks like the system is failing to generate the host keys during boot.

Can you try going to Diagnostics → Command Prompt and executing this command:

for t in rsa ed25519; do rm -f /etc/ssh/ssh_host_${t}_key; ssh-keygen -t $t -b 4096 -N '' -f /etc/ssh/ssh_host_${t}_key; done

You should see output like this after a few seconds:

Try rebooting after that & see if sshd is working.

[oddussiben-3161]

@luckman212 you are awesome!!!!.
that worked. thank you

[luckman212]

@oddussiben-3161 Glad to help.