[SOLVED] Issue with sync

[itobin]

Hi,

ive upgraded to v7 from 6. Upgrade went ok however both nodes are stuck syncing.

The error from the log

Aug 8 23:15:55 host1 pmgmirror[712]: database sync 'host2' failed - DBD:g::st execute failed: ERROR: duplicate key value violates unique constraint "cmailstore_pkey"#012DETAIL: Key (cid, rid)=(2, 106658) already exists. at /usr/share/perl5/PMG/DBTools.pm line 1095.
Aug 8 23:15:55 host1 pmgmirror[712]: cluster synchronization finished (1 errors, 0.21 seconds (files 0.00, database 0.21, config 0.00))

ive tried recreating the cluster but makes no difference.

Any ideas?

thanks

 

[Stoiko Ivanov]

Aug 8 23:15:55 host1 pmgmirror[712]: database sync 'host2' failed - DBD:g::st execute failed: ERROR: duplicate key value violates unique constraint "cmailstore_pkey"#012DETAIL: Key (cid, rid)=(2, 106658) already exists. at /usr/share/perl5/PMG/DBTools.pm line 1095.
Aug 8 23:15:55 host1 pmgmirror[712]: cluster synchronization finished (1 errors, 0.21 seconds (files 0.00, database 0.21, config 0.00))

The error message happens if you "remove" a node from the cluster by removing it's cluster.conf (without running `pmgcm delete` on the master ) and afterwards add it again with pmgcm join

I'd suggest to:
* setup your node freshly and add it to the cluster (after running pmgcm delete for the current node) - simple and clean
or a bit more involved (but if you have much customized config on your node:
* remove cluster.conf on the node
* edit /etc/pmg/cluster.conf on the master-node and increase the maxcid value in the master definition to the maximal number shown when you run `ls /var/spool/pmg/cluster`.
* join the node again
* restart all cluster-services (pmgmirror pmgtunnel) on both nodes

I hope this helps!

 

[itobin]

Hi,

thanks for the advice.

I will try doing both, with the fresh node first.

Just to point out, ive not removed any nodes, these were 2 nodes running V6, all i did was upgrade both to V7 and thats when the problem started.

thanks!

 

[Stoiko Ivanov]

Just to point out, ive not removed any nodes, these were 2 nodes running V6, all i did was upgrade both to V7 and thats when the problem started.

That does sound odd - could I ask you to check the journal/syslog from before the upgrade?
When did those messages start appearing?

 

[itobin]

so i had to revert back to a backup so both nodes are back to version 6 and are running fine. I intend to run the upgrade process again so if there is anything you would like me to do before and after then let me know

 

[Stoiko Ivanov]

so i had to revert back to a backup so both nodes are back to version 6 and are running fine. I intend to run the upgrade process again so if there is anything you would like me to do before and after then let me know

Thanks for the opportunity!

outputs of:
* `pmgcm status`
* `journalctl -u pmgmirror -u pmgtunnel --since '2021-08-09'

would be of interest (remove sensitive information please!)

 

[itobin]

is that before or after upgrade?

 

[Stoiko Ivanov]

is that before or after upgrade?

before

 

[itobin]

NAME(CID)--------------IPADDRESS----ROLE-STATE---------UPTIME---LOAD----MEM---DISK
host01(1) x.x.x.x master A 03:27 10.29 28% 2%
host02(2) x.x.x.x node A 03:27 10.43 26% 2%


root@host01:~# journalctl -u pmgmirror -u pmgtunnel --since '2021-08-09'
-- Logs begin at Mon 2021-08-09 13:22:19 BST, end at Mon 2021-08-09 16:50:22 BST. --
Aug 09 13:22:22 host01 systemd[1]: Starting Proxmox Mail Gateway Cluster Tunnel Daemon...
Aug 09 13:22:24 host01 pmgtunnel[342]: starting server
Aug 09 13:22:24 host01 pmgtunnel[342]: starting tunnel 343 x.x.x.x
Aug 09 13:22:24 host01 systemd[1]: Started Proxmox Mail Gateway Cluster Tunnel Daemon.
Aug 09 13:22:34 host01 systemd[1]: Starting Proxmox Mail Gateway Database Mirror Daemon...
Aug 09 13:22:37 host01 pmgmirror[622]: starting server
Aug 09 13:22:37 host01 systemd[1]: Started Proxmox Mail Gateway Database Mirror Daemon.
Aug 09 13:24:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 13:24:38 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.92 seconds (files 0.19, database 0.73, config 0.00))
Aug 09 13:26:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 13:26:37 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.43 seconds (files 0.23, database 0.21, config 0.00))
Aug 09 13:28:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 13:28:38 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.42 seconds (files 0.23, database 0.19, config 0.00))
Aug 09 13:30:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 13:30:37 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.34 seconds (files 0.22, database 0.12, config 0.00))
Aug 09 13:32:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 13:32:37 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.41 seconds (files 0.23, database 0.18, config 0.00))
Aug 09 13:34:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 13:34:38 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.36 seconds (files 0.23, database 0.13, config 0.00))
Aug 09 13:36:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 13:36:37 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.35 seconds (files 0.20, database 0.14, config 0.00))
Aug 09 13:38:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 13:38:38 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.42 seconds (files 0.23, database 0.19, config 0.00))
Aug 09 13:40:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 13:40:37 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.38 seconds (files 0.22, database 0.15, config 0.00))
Aug 09 13:42:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 13:42:38 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.53 seconds (files 0.20, database 0.32, config 0.00))
Aug 09 13:44:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 13:44:37 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.38 seconds (files 0.23, database 0.15, config 0.00))
Aug 09 13:46:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 13:46:37 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.40 seconds (files 0.22, database 0.18, config 0.00))
Aug 09 13:48:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 13:48:38 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.40 seconds (files 0.27, database 0.13, config 0.00))
Aug 09 13:50:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 13:50:37 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.50 seconds (files 0.23, database 0.28, config 0.00))
Aug 09 13:52:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 13:52:38 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.38 seconds (files 0.23, database 0.15, config 0.00))
Aug 09 13:54:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 13:54:37 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.38 seconds (files 0.22, database 0.15, config 0.00))
Aug 09 13:56:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 13:56:38 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.35 seconds (files 0.23, database 0.13, config 0.00))
Aug 09 13:58:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 13:58:37 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.43 seconds (files 0.26, database 0.18, config 0.00))
Aug 09 14:00:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 14:00:37 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.42 seconds (files 0.23, database 0.19, config 0.00))
Aug 09 14:02:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 14:02:38 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.38 seconds (files 0.23, database 0.15, config 0.00))
Aug 09 14:04:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 14:04:37 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.42 seconds (files 0.24, database 0.18, config 0.00))
Aug 09 14:06:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 14:06:38 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.41 seconds (files 0.23, database 0.18, config 0.00))
Aug 09 14:08:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 14:08:37 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.37 seconds (files 0.23, database 0.13, config 0.00))
Aug 09 14:10:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 14:10:38 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.41 seconds (files 0.23, database 0.18, config 0.00))
Aug 09 14:12:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 14:12:37 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.36 seconds (files 0.23, database 0.13, config 0.00))
Aug 09 14:14:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 14:14:37 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.39 seconds (files 0.23, database 0.15, config 0.00))
Aug 09 14:16:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 14:16:38 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.42 seconds (files 0.23, database 0.19, config 0.00))
Aug 09 14:18:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 14:18:37 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.39 seconds (files 0.23, database 0.16, config 0.00))
Aug 09 14:20:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 14:20:38 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.37 seconds (files 0.22, database 0.15, config 0.00))
Aug 09 14:22:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 14:22:37 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.65 seconds (files 0.23, database 0.42, config 0.00))
Aug 09 14:24:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 14:24:38 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.46 seconds (files 0.24, database 0.22, config 0.00))
Aug 09 14:26:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 14:26:37 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.38 seconds (files 0.23, database 0.15, config 0.00))
Aug 09 14:28:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 14:28:38 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.38 seconds (files 0.23, database 0.15, config 0.00))
Aug 09 14:30:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 14:30:37 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.40 seconds (files 0.23, database 0.17, config 0.00))
Aug 09 14:32:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 14:32:37 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.36 seconds (files 0.23, database 0.12, config 0.00))
Aug 09 14:34:37 host01 pmgmirror[622]: starting cluster synchronization
Aug 09 14:34:38 host01 pmgmirror[622]: cluster synchronization finished (0 errors, 0.35 seconds (files 0.23, database 0.12, config 0.00))
Aug 09 14:36:37 host01 pmgmirror[622]: starting cluster synchronization

 

[itobin]

i couldnt post all of it due to size but its all the same

 

[Stoiko Ivanov]

couldnt post all of it due to size but its all the same

Thanks - that looks fine!

did you follow the upgrade guide?:
https://pmg.proxmox.com/wiki/index.php/Upgrade_from_6.x_to_7.0

(In any case - I think the issue should not occur after the upgrade)

 

[itobin]

yes i followed it twice, same issue.

So once i run the upgrade shall i post the same commands?

 

[itobin]

ok upgrade complete, ive done nothing else after, from host01;

NAME(CID)--------------IPADDRESS----ROLE-STATE---------UPTIME---LOAD----MEM---DISK
host2(2) x.x.x.2 node S 00:03 11.30 37% 3%
host1(1) x.x.x.1 master S 00:03 11.30 38% 3%

root@host01:~# journalctl -u pmgmirror -u pmgtunnel --since '2021-08-09'
-- Journal begins at Mon 2021-08-09 21:19:20 BST, ends at Mon 2021-08-09 22:00:29 BST. --
Aug 09 21:19:23 host01 systemd[1]: Starting Proxmox Mail Gateway Cluster Tunnel Daemon...
Aug 09 21:19:24 host01 pmgtunnel[341]: starting server
Aug 09 21:19:24 host01 systemd[1]: Started Proxmox Mail Gateway Cluster Tunnel Daemon.
Aug 09 21:19:24 host01 pmgtunnel[341]: starting tunnel 342 x.x.x.x
Aug 09 21:19:33 host01 systemd[1]: Starting Proxmox Mail Gateway Database Mirror Daemon...
Aug 09 21:19:34 host01 systemd[1]: pmgmirror.service: Can't open PID file /run/pmgmirror.pid (yet?) after start: No such file or directory
Aug 09 21:19:34 host01 pmgmirror[567]: starting server
Aug 09 21:19:34 host01 systemd[1]: Started Proxmox Mail Gateway Database Mirror Daemon.
Aug 09 21:21:34 host01 pmgmirror[567]: starting cluster synchronization
Aug 09 21:21:35 host01 pmgmirror[567]: cluster synchronization finished (0 errors, 0.64 seconds (files 0.25, database 0.39, config 0.00))
Aug 09 21:23:34 host01 pmgmirror[567]: starting cluster synchronization
Aug 09 21:23:34 host01 pmgmirror[567]: cluster synchronization finished (0 errors, 0.38 seconds (files 0.24, database 0.14, config 0.00))
Aug 09 21:24:34 host01 systemd[1]: Stopping Proxmox Mail Gateway Cluster Tunnel Daemon...
Aug 09 21:24:34 host01 systemd[1]: Stopping Proxmox Mail Gateway Database Mirror Daemon...
Aug 09 21:24:35 host01 pmgmirror[567]: received signal TERM
Aug 09 21:24:35 host01 pmgmirror[567]: server closing
Aug 09 21:24:35 host01 pmgmirror[567]: server stopped
Aug 09 21:24:35 host01 pmgtunnel[341]: received signal TERM
Aug 09 21:24:35 host01 pmgtunnel[341]: server closing
Aug 09 21:24:35 host01 pmgtunnel[341]: successfully deleted tunnel 342 x.x.x.x
Aug 09 21:24:35 host01 pmgtunnel[341]: server stopped
Aug 09 21:24:36 host01 systemd[1]: pmgtunnel.service: Succeeded.
Aug 09 21:24:36 host01 systemd[1]: Stopped Proxmox Mail Gateway Cluster Tunnel Daemon.
Aug 09 21:24:36 host01 systemd[1]: pmgmirror.service: Succeeded.
Aug 09 21:24:36 host01 systemd[1]: Stopped Proxmox Mail Gateway Database Mirror Daemon.
-- Boot 7fb780071ae54b0dba0cdc32ccebd722 --
Aug 09 21:55:59 host01 systemd[1]: Starting Proxmox Mail Gateway Database Mirror Daemon...
Aug 09 21:55:59 host01 systemd[1]: Starting Proxmox Mail Gateway Cluster Tunnel Daemon...
Aug 09 21:56:00 host01 pmgtunnel[900]: starting server
Aug 09 21:56:00 host01 systemd[1]: Started Proxmox Mail Gateway Cluster Tunnel Daemon.
Aug 09 21:56:00 host01 pmgtunnel[900]: starting tunnel 901 x.x.x.x
Aug 09 21:56:01 host01 pmgmirror[904]: starting server
Aug 09 21:56:01 host01 systemd[1]: Started Proxmox Mail Gateway Database Mirror Daemon.
Aug 09 21:58:01 host01 pmgmirror[904]: starting cluster synchronization
Aug 09 21:58:16 host01 pmgmirror[904]: database sync 'host02' failed - command 'rsync '--rsh=ssh -l root -o BatchMode=yes -o HostKeyAlias=lepmg02' -q --tim>
Aug 09 21:58:16 host01 pmgmirror[904]: cluster synchronization finished (1 errors, 15.13 seconds (files 0.00, database 15.13, config 0.00))
Aug 09 22:00:01 host01 pmgmirror[904]: starting cluster synchronization
Aug 09 22:00:16 host01 pmgmirror[904]: database sync 'host02' failed - command 'rsync '--rsh=ssh -l root -o BatchMode=yes -o HostKeyAlias=lepmg02' -q --tim>
Aug 09 22:00:16 host01 pmgmirror[904]: cluster synchronization finished (1 errors, 15.08 seconds (files 0.00, database 15.07, config 0.00))

 

[itobin]

from host02;

-- Journal begins at Mon 2021-08-09 21:13:29 BST, ends at Mon 2021-08-09 22:02:14 BST. --
Aug 09 21:13:32 host02 systemd[1]: Starting Proxmox Mail Gateway Cluster Tunnel Daemon...
Aug 09 21:13:33 host02 pmgtunnel[332]: starting server
Aug 09 21:13:33 host02 systemd[1]: Started Proxmox Mail Gateway Cluster Tunnel Daemon.
Aug 09 21:13:33 host02 pmgtunnel[332]: starting tunnel 333 x.x.x.x
Aug 09 21:13:35 host02 pmgtunnel[332]: tunnel finished 333 x.x.x.x
Aug 09 21:13:41 host02 systemd[1]: Starting Proxmox Mail Gateway Database Mirror Daemon...
Aug 09 21:13:44 host02 pmgmirror[614]: starting server
Aug 09 21:13:44 host02 systemd[1]: Started Proxmox Mail Gateway Database Mirror Daemon.
Aug 09 21:13:52 host02 pmgtunnel[332]: restarting crashed tunnel 726 x.x.x.x
Aug 09 21:14:11 host02 pmgtunnel[332]: tunnel finished 726 x.x.x.x
Aug 09 21:14:22 host02 pmgtunnel[332]: restarting crashed tunnel 744 x.x.x.x
Aug 09 21:14:25 host02 pmgtunnel[332]: tunnel finished 744 x.x.x.x
Aug 09 21:14:41 host02 pmgtunnel[332]: restarting crashed tunnel 755 x.x.x.x
Aug 09 21:14:44 host02 pmgtunnel[332]: tunnel finished 755 x.x.x.x
Aug 09 21:15:00 host02 pmgtunnel[332]: restarting crashed tunnel 767 x.x.x.x
Aug 09 21:15:03 host02 pmgtunnel[332]: tunnel finished 767 x.x.x.x
Aug 09 21:15:19 host02 pmgtunnel[332]: restarting crashed tunnel 782 x.x.x.x
Aug 09 21:15:22 host02 pmgtunnel[332]: tunnel finished 782 x.x.x.x
Aug 09 21:15:44 host02 pmgmirror[614]: starting cluster synchronization
Aug 09 21:15:47 host02 pmgmirror[614]: sync error: syncing master configuration from 'x.x.x.x' failed: rsync error: unexplained error (code 255) at io.>
Aug 09 21:16:28 host02 pmgtunnel[332]: restarting crashed tunnel 819 x.x.x.x
Aug 09 21:16:31 host02 pmgtunnel[332]: tunnel finished 819 x.x.x.x
Aug 09 21:17:37 host02 pmgtunnel[332]: restarting crashed tunnel 858 x.x.x.x
Aug 09 21:17:40 host02 pmgtunnel[332]: tunnel finished 858 x.x.x.x
Aug 09 21:17:44 host02 pmgmirror[614]: starting cluster synchronization
Aug 09 21:17:47 host02 pmgmirror[614]: sync error: syncing master configuration from 'x.x.x.x' failed: rsync error: unexplained error (code 255) at io.>
Aug 09 21:18:46 host02 pmgtunnel[332]: restarting crashed tunnel 895 x.x.x.x
Aug 09 21:18:50 host02 pmgtunnel[332]: tunnel finished 895 x.x.x.x
Aug 09 21:19:44 host02 pmgmirror[614]: starting cluster synchronization
Aug 09 21:19:45 host02 pmgmirror[614]: database sync 'host01' failed - DBI connect('dbname=Proxmox_ruledb;host=/run/pmgtunnel;port=1;','root',...) failed: >
Is the server running locally and accepting
connections on Unix domain socket "/run/pmgtunnel/.s.PGSQL.1"? at /usr/share/perl5/PMG/DBTools.pm line 68.
Aug 09 21:19:47 host02 pmgmirror[614]: cluster synchronization finished (1 errors, 3.26 seconds (files 0.00, database 2.25, config 1.01))
Aug 09 21:19:56 host02 pmgtunnel[332]: restarting crashed tunnel 1072 x.x.x.x
Aug 09 21:21:44 host02 pmgmirror[614]: starting cluster synchronization
Aug 09 21:21:45 host02 pmgmirror[614]: detected rule database changes - starting sync from 'x.x.x.x'
Aug 09 21:21:45 host02 pmgmirror[614]: finished rule database sync from host 'x.x.x.x'
Aug 09 21:21:48 host02 pmgmirror[614]: cluster synchronization finished (0 errors, 3.44 seconds (files 0.23, database 2.90, config 0.31))
Aug 09 21:23:44 host02 pmgmirror[614]: starting cluster synchronization
Aug 09 21:23:47 host02 pmgmirror[614]: cluster synchronization finished (0 errors, 2.90 seconds (files 0.22, database 2.38, config 0.30))
Aug 09 21:24:35 host02 systemd[1]: Stopping Proxmox Mail Gateway Database Mirror Daemon...
Aug 09 21:24:35 host02 systemd[1]: Stopping Proxmox Mail Gateway Cluster Tunnel Daemon...
Aug 09 21:24:37 host02 pmgtunnel[332]: received signal TERM
Aug 09 21:24:37 host02 pmgtunnel[332]: server closing
Aug 09 21:24:37 host02 pmgtunnel[332]: successfully deleted tunnel 1072 x.x.x.x
Aug 09 21:24:37 host02 pmgtunnel[332]: server stopped
Aug 09 21:24:37 host02 pmgmirror[614]: received signal TERM
Aug 09 21:24:37 host02 pmgmirror[614]: server closing
Aug 09 21:24:37 host02 pmgmirror[614]: server stopped
Aug 09 21:24:38 host02 systemd[1]: pmgtunnel.service: Succeeded.
Aug 09 21:24:38 host02 systemd[1]: Stopped Proxmox Mail Gateway Cluster Tunnel Daemon.
Aug 09 21:24:38 host02 systemd[1]: pmgmirror.service: Succeeded.
Aug 09 21:24:38 host02 systemd[1]: Stopped Proxmox Mail Gateway Database Mirror Daemon.
-- Boot 6c26ef309e154371a38813ba2d360b3c --
Aug 09 21:56:01 host02 systemd[1]: Starting Proxmox Mail Gateway Database Mirror Daemon...
Aug 09 21:56:01 host02 systemd[1]: Starting Proxmox Mail Gateway Cluster Tunnel Daemon...
Aug 09 21:56:03 host02 pmgmirror[922]: starting server
Aug 09 21:56:03 host02 systemd[1]: Started Proxmox Mail Gateway Database Mirror Daemon.
Aug 09 21:56:03 host02 pmgtunnel[926]: starting server
Aug 09 21:56:03 host02 pmgtunnel[926]: starting tunnel 927 x.x.x.x
Aug 09 21:56:03 host02 systemd[1]: Started Proxmox Mail Gateway Cluster Tunnel Daemon.
Aug 09 21:58:03 host02 pmgmirror[922]: starting cluster synchronization
Aug 09 21:58:43 host02 pmgmirror[922]: database sync 'host01' failed - command 'rsync '--rsh=ssh -l root -o BatchMode=yes -o HostKeyAlias=host01' -q --tim>
Aug 09 21:58:45 host02 pmgmirror[922]: cluster synchronization finished (1 errors, 42.64 seconds (files 0.00, database 17.21, config 25.44))
Aug 09 22:00:03 host02 pmgmirror[922]: starting cluster synchronization
Aug 09 22:00:44 host02 pmgmirror[922]: database sync 'host01' failed - command 'rsync '--rsh=ssh -l root -o BatchMode=yes -o HostKeyAlias=host01' -q --tim>
Aug 09 22:00:46 host02 pmgmirror[922]: cluster synchronization finished (1 errors, 42.41 seconds (files 0.00, database 16.98, config 25.43))

 

[Stoiko Ivanov]

ok upgrade complete, ive done nothing else after, from host01;

did you upgrade both host01 and host02?
(if not please upgrade both before starting the cluster services)

database sync 'host01' failed - command 'rsync '--rsh=ssh -l root -o BatchMode=yes -o HostKeyAlias=host01' -q --tim>

and

Aug 09 21:15:22 host02 pmgtunnel[332]: tunnel finished 782 x.x.x.x

would indicate a problem with ssh between the nodes
can you
* `ssh root@host01` from host02
* `ssh root@host02` from host01

without providing a password?

 

[itobin]

did you upgrade both host01 and host02?
(if not please upgrade both before starting the cluster services)


and

would indicate a problem with ssh between the nodes
can you
* `ssh root@host01` from host02
* `ssh root@host02` from host01

without providing a password?

yes both nodes are upgraded and i can login to both consoles ok.

I can SSH both ways, little slow but it does login

 

[Stoiko Ivanov]

I can SSH both ways, little slow but it does login

hm - is DNS working correctly on the nodes?

else could you provide the output of `ssh -vvv root@host01` ?

EDIT: does anything show in the journal while you try to login?
On what platform is PMG running? (bare-metal, VM, container? - If it's a container on PVE - please enable nesting for them (and make sure they are unprivileged))

 

[itobin]

i have listed all services, unbound DNS seem to not be started on both nodes

UNIT LOAD ACTIVE SUB DESCRIPTION
clamav-daemon.service loaded active running Clam AntiVirus userspace daemon
clamav-freshclam.service loaded active running ClamAV virus database updater
console-getty.service loaded active running Console Getty
container-getty@1.service loaded active running Container Getty on /dev/tty1
container-getty@2.service loaded active running Container Getty on /dev/tty2
cron.service loaded active running Regular background program processing daemon
dbus.service loaded active running D-Bus System Message Bus
fetchmail.service loaded active exited LSB: init-Script for system wide fetchmail daemon
ifupdown-pre.service loaded active exited Helper to synchronize boot up for ifupdown
● logrotate.service loaded failed failed Rotate log files
● modprobe@drm.service loaded failed failed Load Kernel Module drm
named.service loaded active running BIND Domain Name Server
networking.service loaded active exited Raise network interfaces
pmg-smtp-filter.service loaded active running Proxmox SMTP Filter Daemon
pmgbanner.service loaded active exited Proxmox Mail Gateway Login Banner
pmgdaemon.service loaded active running Proxmox Mail Gateway API Daemon
pmgmirror.service loaded active running Proxmox Mail Gateway Database Mirror Daemon
pmgnetcommit.service loaded active exited Commit Proxmox network changes
pmgpolicy.service loaded active running Proxmox Mail Gateway Policy Daemon
pmgproxy.service loaded active running Proxmox Mail Gateway API
pmgsync.service loaded active exited Sync Proxmox Configuration
pmgtunnel.service loaded active running Proxmox Mail Gateway Cluster Tunnel Daemon
postfix.service loaded active exited Postfix Mail Transport Agent
postfix@-.service loaded active running Postfix Mail Transport Agent (instance -)
postgresql.service loaded active exited PostgreSQL RDBMS
postgresql@13-main.service loaded active running PostgreSQL Cluster 13-main
rrdcached.service loaded active running LSB: start or stop rrdcached
rsyslog.service loaded active running System Logging Service
ssh.service loaded active running OpenBSD Secure Shell server
systemd-journal-flush.service loaded active exited Flush Journal to Persistent Storage
systemd-journald.service loaded active running Journal Service
● systemd-logind.service loaded failed failed User Login Management
systemd-modules-load.service loaded active exited Load Kernel Modules
systemd-remount-fs.service loaded active exited Remount Root and Kernel File Systems
systemd-sysctl.service loaded active exited Apply Kernel Variables
systemd-sysusers.service loaded active exited Create System Users
systemd-tmpfiles-setup-dev.service loaded active exited Create Static Device Nodes in /dev
systemd-tmpfiles-setup.service loaded active exited Create Volatile Files and Directories
systemd-update-utmp.service loaded active exited Update UTMP about System Boot/Shutdown
systemd-user-sessions.service loaded active exited Permit User Sessions
● unbound.service loaded failed failed Unbound DNS server

 

[itobin]

root@host02:~# ssh -vvv root@host01
OpenSSH_8.4p1 Debian-5, OpenSSL 1.1.1k 25 Mar 2021
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: /etc/ssh/ssh_config line 19: include /etc/ssh/ssh_config.d/*.conf matched no files
debug1: /etc/ssh/ssh_config line 21: Applying options for *
debug3: expanded UserKnownHostsFile '~/.ssh/known_hosts' -> '/root/.ssh/known_hosts'
debug3: expanded UserKnownHostsFile '~/.ssh/known_hosts2' -> '/root/.ssh/known_hosts2'
debug2: resolving "host01" port 22
debug2: ssh_connect_direct
debug1: Connecting to host01 [0000:0000:2000:01] port 22.
debug1: Connection established.
debug1: identity file /root/.ssh/id_rsa type 0
debug1: identity file /root/.ssh/id_rsa-cert type -1
debug1: identity file /root/.ssh/id_dsa type -1
debug1: identity file /root/.ssh/id_dsa-cert type -1
debug1: identity file /root/.ssh/id_ecdsa type -1
debug1: identity file /root/.ssh/id_ecdsa-cert type -1
debug1: identity file /root/.ssh/id_ecdsa_sk type -1
debug1: identity file /root/.ssh/id_ecdsa_sk-cert type -1
debug1: identity file /root/.ssh/id_ed25519 type -1
debug1: identity file /root/.ssh/id_ed25519-cert type -1
debug1: identity file /root/.ssh/id_ed25519_sk type -1
debug1: identity file /root/.ssh/id_ed25519_sk-cert type -1
debug1: identity file /root/.ssh/id_xmss type -1
debug1: identity file /root/.ssh/id_xmss-cert type -1
debug1: Local version string SSH-2.0-OpenSSH_8.4p1 Debian-5
debug1: Remote protocol version 2.0, remote software version OpenSSH_8.4p1 Debian-5
debug1: match: OpenSSH_8.4p1 Debian-5 pat OpenSSH* compat 0x04000000
debug2: fd 3 setting O_NONBLOCK
debug1: Authenticating to host01:22 as 'root'
debug3: hostkeys_foreach: reading file "/root/.ssh/known_hosts"
debug3: hostkeys_foreach: reading file "/etc/ssh/ssh_known_hosts2"
debug3: record_hostkey: found key type RSA in file /etc/ssh/ssh_known_hosts2:4
debug3: load_hostkeys: loaded 1 keys from host01
debug3: order_hostkeyalgs: prefer hostkeyalgs: rsa-sha2-512-cert-v01@openssh.com,rsa-sha2-256-cert-v01@openssh.com,ssh-rsa-cert-v01@openssh.com,rsa-sha2-512,rsa-sha2-256,ssh-rsa
debug3: send packet: type 20
debug1: SSH2_MSG_KEXINIT sent
debug3: receive packet: type 20
debug1: SSH2_MSG_KEXINIT received
debug2: local client KEXINIT proposal
debug2: KEX algorithms: curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group14-sha256,ext-info-c
debug2: host key algorithms: rsa-sha2-512-cert-v01@openssh.com,rsa-sha2-256-cert-v01@openssh.com,ssh-rsa-cert-v01@openssh.com,rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nistp521-cert-v01@openssh.com,sk-ecdsa-sha2-nistp256-cert-v01@openssh.com,ssh-ed25519-cert-v01@openssh.com,sk-ssh-ed25519-cert-v01@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,sk-ecdsa-sha2-nistp256@openssh.com,ssh-ed25519,sk-ssh-ed25519@openssh.com
debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com
debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com
debug2: MACs ctos: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
debug2: MACs stoc: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
debug2: compression ctos: none,zlib@openssh.com,zlib
debug2: compression stoc: none,zlib@openssh.com,zlib
debug2: languages ctos:
debug2: languages stoc:
debug2: first_kex_follows 0
debug2: reserved 0
debug2: peer server KEXINIT proposal
debug2: KEX algorithms: curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group14-sha256
debug2: host key algorithms: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519
debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com
debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com
debug2: MACs ctos: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
debug2: MACs stoc: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
debug2: compression ctos: none,zlib@openssh.com
debug2: compression stoc: none,zlib@openssh.com
debug2: languages ctos:
debug2: languages stoc:
debug2: first_kex_follows 0
debug2: reserved 0
debug1: kex: algorithm: curve25519-sha256
debug1: kex: host key algorithm: rsa-sha2-512
debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none
debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none
debug3: send packet: type 30
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
debug3: receive packet: type 31
debug1: Server host key: ssh-rsa SHA256:NDkjMLYAeoco5B5vd78U/x8f9/FJZC/6bJCYLj8hufI
debug3: hostkeys_foreach: reading file "/root/.ssh/known_hosts"
debug3: hostkeys_foreach: reading file "/etc/ssh/ssh_known_hosts2"
debug3: record_hostkey: found key type RSA in file /etc/ssh/ssh_known_hosts2:4
debug3: load_hostkeys: loaded 1 keys from host01
debug3: hostkeys_foreach: reading file "/root/.ssh/known_hosts"
debug3: record_hostkey: found key type RSA in file /root/.ssh/known_hosts:1
debug3: load_hostkeys: loaded 1 keys from 0000:0000:2000:01
debug3: hostkeys_foreach: reading file "/etc/ssh/ssh_known_hosts2"
debug1: Host 'host01' is known and matches the RSA host key.
debug1: Found key in /etc/ssh/ssh_known_hosts2:4
debug3: send packet: type 21
debug2: set_newkeys: mode 1
debug1: rekey out after 134217728 blocks
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug3: receive packet: type 21
debug1: SSH2_MSG_NEWKEYS received
debug2: set_newkeys: mode 0
debug1: rekey in after 134217728 blocks
debug1: Will attempt key: /root/.ssh/id_rsa RSA SHA256:r5JtJiPjo1s9pfykErWi+AzMmLkAbjb/CS8yMHIRhoM
debug1: Will attempt key: /root/.ssh/id_dsa
debug1: Will attempt key: /root/.ssh/id_ecdsa
debug1: Will attempt key: /root/.ssh/id_ecdsa_sk
debug1: Will attempt key: /root/.ssh/id_ed25519
debug1: Will attempt key: /root/.ssh/id_ed25519_sk
debug1: Will attempt key: /root/.ssh/id_xmss
debug2: pubkey_prepare: done
debug3: send packet: type 5
debug3: receive packet: type 7
debug1: SSH2_MSG_EXT_INFO received
debug1: kex_input_ext_info: server-sig-algs=<ssh-ed25519,sk-ssh-ed25519@openssh.com,ssh-rsa,rsa-sha2-256,rsa-sha2-512,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,sk-ecdsa-sha2-nistp256@openssh.com,webauthn-sk-ecdsa-sha2-nistp256@openssh.com>
debug3: receive packet: type 6
debug2: service_accept: ssh-userauth
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug3: send packet: type 50
debug3: receive packet: type 51
debug1: Authentications that can continue: publickey,password
debug3: start over, passed a different list publickey,password
debug3: preferred gssapi-with-mic,publickey,keyboard-interactive,password
debug3: authmethod_lookup publickey
debug3: remaining preferred: keyboard-interactive,password
debug3: authmethod_is_enabled publickey
debug1: Next authentication method: publickey
debug1: Offering public key: /root/.ssh/id_rsa RSA SHA256:r5JtJiPjo1s9pfykErWi+AzMmLkAbjb/CS8yMHIRhoM
debug3: send packet: type 50
debug2: we sent a publickey packet, wait for reply
debug3: receive packet: type 60
debug1: Server accepts key: /root/.ssh/id_rsa RSA SHA256:r5JtJiPjo1s9pfykErWi+AzMmLkAbjb/CS8yMHIRhoM
debug3: sign_and_send_pubkey: RSA SHA256:r5JtJiPjo1s9pfykErWi+AzMmLkAbjb/CS8yMHIRhoM
debug3: sign_and_send_pubkey: signing using rsa-sha2-512 SHA256:r5JtJiPjo1s9pfykErWi+AzMmLkAbjb/CS8yMHIRhoM
debug3: send packet: type 50
debug3: receive packet: type 52
debug1: Authentication succeeded (publickey).
Authenticated to host01 ([0000:0000:2000:01]:22).
debug1: channel 0: new [client-session]
debug3: ssh_session2_open: channel_new: 0
debug2: channel 0: send open
debug3: send packet: type 90
debug1: Requesting no-more-sessions@openssh.com
debug3: send packet: type 80
debug1: Entering interactive session.
debug1: pledge: network
debug3: receive packet: type 80
debug1: client_input_global_request: rtype hostkeys-00@openssh.com want_reply 0
debug3: receive packet: type 4
debug1: Remote: /root/.ssh/authorized_keys:2: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
debug3: receive packet: type 4
debug1: Remote: /root/.ssh/authorized_keys:2: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
debug3: receive packet: type 91
debug2: channel_input_open_confirmation: channel 0: callback start
debug2: fd 3 setting TCP_NODELAY
debug3: ssh_packet_set_tos: set IPV6_TCLASS 0x10
debug2: client_session2_setup: id 0
debug2: channel 0: request pty-req confirm 1
debug3: send packet: type 98
debug1: Sending environment.
debug3: Ignored env SHELL
debug3: Ignored env PWD
debug3: Ignored env LOGNAME
debug3: Ignored env MOTD_SHOWN
debug3: Ignored env HOME
debug3: Ignored env SSH_CONNECTION
debug3: Ignored env TERM
debug3: Ignored env USER
debug3: Ignored env SHLVL
debug3: Ignored env SSH_CLIENT
debug3: Ignored env PATH
debug3: Ignored env SSH_TTY
debug3: Ignored env _
debug2: channel 0: request shell confirm 1
debug3: send packet: type 98
debug2: channel_input_open_confirmation: channel 0: callback done
debug2: channel 0: open confirm rwindow 0 rmax 32768
debug3: receive packet: type 99
debug2: channel_input_status_confirm: type 99 id 0
debug2: PTY allocation request accepted on channel 0
debug2: channel 0: rcvd adjust 2097152
debug3: receive packet: type 99
debug2: channel_input_status_confirm: type 99 id 0
debug2: shell request accepted on channel 0
Linux host01 5.4.119-1-pve #1 SMP PVE 5.4.119-1 (Tue, 01 Jun 2021 15:32:00 +0200) x86_64

The programs included with the Debian GNU/Linux system are free software;
the exact distribution terms for each program are described in the
individual files in /usr/share/doc/*/copyright.

Debian GNU/Linux comes with ABSOLUTELY NO WARRANTY, to the extent
permitted by applicable law.
Last login: Tue Aug 10 09:26:50 2021 from 0000:0000:2000:02
root@host01:~#

 

[itobin]

I think unbounddns is a red herring as bind is running.