Hi,
My backup solution using Syncthing stopped working. It is backing up one folder between two Debian servers. It is all installed using the apt package manager from the stable repo. Screen shots and logs attached:
i have tried multiple configuration, double checked the firewalls, purged everything (database, config file, etc) yet still always stuck at the syncing.
Any help is appreciated.
Regards, Mo
Firewall and config should be all good, the UI and logs show that they are connected. What is not happening is the index exchange (backup global is 0 and only a few bytes were transferred), and that’s nothing you can misconfigure (lets see whether that statement will be coming back to bite me later).
Can you enable the model debug facility? To conveniently get the logs as text, you can use the journal (e.g. journalctl -u syncthing@*yourusername*).
Hi Simon,
Thanks for the reply. True triple checked the firewall and all network related issues.
This is the out put from the main server:
I will follow it up with the log from the backup server in an other reply. the website is blocking me being a new user.
Cheers, Mo
Could you please post that as text, e.g. by redirecting the journal to a file ( journalctl -u syncthing@*yourusername* > log.out.
“New users cannot upload attachment” error message.
Prime server log: https://drive.google.com/open?id=1WuQY_xwi8FzKM2-rbCahFIbuWE9x6dK-
backup server log: https://drive.google.com/open?id=1CDeR8GNgy2g4L12h7UGhSXZIAFLSZLuF
Thanks, Mo
You have something misconfigured connection wise, wether it’s syncthing, firewall or some sort of proxy you are using.
Are you using default settings?
It seems they are both listening on port 22000 yet connection attempts happen on port 24000. Did you tweak something?
I thought from my own observations as a user that the UI shows the title “syncing x%” only if nodes are connected via TCP or similar.
Hi both,
I have no proxy settings on site. Both machines are in the same network as you can see from the log, no firewall rules. I am running ufw as firewall and I have already given permissions for Syncthing to work on both machines:
ufw allow syncthing
ufw allow syncthing-gui
Yes I have fixed the listing port on both machines. I have done that because I have already tried to fix it myself before creating the ticket. I have tried the default, fixed ports, fixed IP, using a different interface.
@Catfriend1, Aren’t they supposed to be connected via TCP? I don’t think UDP is an option to back up important data.
Thanks, Mo
There are indeed non-standard ports (23000) involved, but to me it still looks like there is a connection mixup within Syncthing (at the very least if it’s falsely configured, this isn’t indicated in any meaningful way). The two devices connect on ipv4, then one tries to send a hello message on ipv6 on a connection that isn’t mentioned anywhere else in the log, and then a bit more than 5 min later the ipv4 connection is closed.
prime
[FXOY4] 2018/11/08 13:44:15.442285 service.go:276: INFO: Established secure connection to 7WNN76F-QGLMMBK-I5HMD36-YADCBCJ-ZMOODW2-S6OMT3O-FHFG4BY-CWZGGQX at 10.7.243.68:34711-10.7.243.24:22000/tcp-client (TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305)
[FXOY4] 2018/11/08 13:44:15.442349 model.go:1640: INFO: Device 7WNN76F-QGLMMBK-I5HMD36-YADCBCJ-ZMOODW2-S6OMT3O-FHFG4BY-CWZGGQX client is "syncthing v0.14.52" named "penelopebackup" at 10.7.243.68:34711-10.7.243.24:22000/tcp-client
[FXOY4] 2018/11/08 13:51:45.442629 model.go:1293: INFO: Connection to 7WNN76F-QGLMMBK-I5HMD36-YADCBCJ-ZMOODW2-S6OMT3O-FHFG4BY-CWZGGQX at 10.7.243.68:34711-10.7.243.24:22000/tcp-client closed: read timeout
backup:
[7WNN7] 2018/11/08 13:44:15.441981 service.go:276: INFO: Established secure connection to FXOY4QM-D62YMWF-KSGLJNM-Q7O7UUO-EMA445V-MMARWQN-T2WUQI7-WM3ZLQL at 10.7.243.24:22000-10.7.243.68:34711/tcp-server (TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305)
[7WNN7] 2018/11/08 13:44:15.442037 model.go:1640: INFO: Device FXOY4QM-D62YMWF-KSGLJNM-Q7O7UUO-EMA445V-MMARWQN-T2WUQI7-WM3ZLQL client is "syncthing v0.14.52" named "penelopeprime" at 10.7.243.24:22000-10.7.243.68:34711/tcp-server
[7WNN7] 2018/11/08 13:44:15.477184 service.go:212: INFO: Failed to exchange Hello messages with FXOY4QM-D62YMWF-KSGLJNM-Q7O7UUO-EMA445V-MMARWQN-T2WUQI7-WM3ZLQL at [fe80::250:56ff:fe87:cf4d%ens192]:22000-[fe80::250:56ff:fe87:9bd3%ens192]:38333/tcp-server: EOF
[7WNN7] 2018/11/08 13:51:45.442325 model.go:1293: INFO: Connection to FXOY4QM-D62YMWF-KSGLJNM-Q7O7UUO-EMA445V-MMARWQN-T2WUQI7-WM3ZLQL at 10.7.243.24:22000-10.7.243.68:34711/tcp-server closed: read timeout
Maybe enabling protocol and connections debug facilities can shed some light on what’s going on (@moalibi).
At first I used port 22000 for both machines. And I found out that I should change it. so I have chosen 23000/24000 for one and 22000 for the other. My current configuration screenshot is like this:
Got this from the prime server:
syncthing[119458]: [FXOY4] 2018/11/09 11:40:03.690117 service.go:306: DEBUG: Reconnect loop
syncthing[119458]: [FXOY4] 2018/11/09 11:40:03.690219 service.go:428: DEBUG: sleep until next dial 1m0s
syncthing[119458]: [FXOY4] 2018/11/09 11:40:33.690954 protocol.go:858: DEBUG: 7WNN76F-QGLMMBK-I5HMD36-YADCBCJ-ZMOODW2-S6OMT3O-FHFG4BY-CWZGGQX ping -> after 1m29.99916701s
syncthing[119458]: [FXOY4] 2018/11/09 11:40:33.691085 protocol.go:750: DEBUG: wrote 8 bytes on the wire (2 bytes length, 2 bytes header, 4 bytes message length, 0 bytes message), err=<nil>
syncthing[119458]: [FXOY4] 2018/11/09 11:41:03.690427 service.go:306: DEBUG: Reconnect loop
syncthing[119458]: [FXOY4] 2018/11/09 11:41:03.690545 service.go:428: DEBUG: sleep until next dial 1m0s
syncthing[119458]: [FXOY4] 2018/11/09 11:41:18.690947 protocol.go:854: DEBUG: 7WNN76F-QGLMMBK-I5HMD36-YADCBCJ-ZMOODW2-S6OMT3O-FHFG4BY-CWZGGQX ping skipped after wr 44.999836952s
syncthing[119458]: [FXOY4] 2018/11/09 11:41:18.691142 protocol.go:415: DEBUG: read Ping message
syncthing[119458]: [FXOY4] 2018/11/09 11:41:33.690840 protocol.go:883: DEBUG: 7WNN76F-QGLMMBK-I5HMD36-YADCBCJ-ZMOODW2-S6OMT3O-FHFG4BY-CWZGGQX last read within 14.999650846s
syncthing[119458]: [FXOY4] 2018/11/09 11:42:03.690724 service.go:306: DEBUG: Reconnect loop
syncthing[119458]: [FXOY4] 2018/11/09 11:42:03.690830 service.go:428: DEBUG: sleep until next dial 1m0s
syncthing[119458]: [FXOY4] 2018/11/09 11:42:03.690936 protocol.go:858: DEBUG: 7WNN76F-QGLMMBK-I5HMD36-YADCBCJ-ZMOODW2-S6OMT3O-FHFG4BY-CWZGGQX ping -> after 1m29.99983842s
syncthing[119458]: [FXOY4] 2018/11/09 11:42:03.691005 protocol.go:750: DEBUG: wrote 8 bytes on the wire (2 bytes length, 2 bytes header, 4 bytes message length, 0 bytes message), err=<nil>
syncthing[119458]: [FXOY4] 2018/11/09 11:42:48.690995 protocol.go:854: DEBUG: 7WNN76F-QGLMMBK-I5HMD36-YADCBCJ-ZMOODW2-S6OMT3O-FHFG4BY-CWZGGQX ping skipped after wr 44.999963217s
syncthing[119458]: [FXOY4] 2018/11/09 11:42:48.691085 protocol.go:415: DEBUG: read Ping message
syncthing[119458]: [FXOY4] 2018/11/09 11:43:03.691056 service.go:306: DEBUG: Reconnect loop
syncthing[119458]: [FXOY4] 2018/11/09 11:43:03.691165 service.go:428: DEBUG: sleep until next dial 1m0s
syncthing[119458]: [FXOY4] 2018/11/09 11:43:33.690922 protocol.go:858: DEBUG: 7WNN76F-QGLMMBK-I5HMD36-YADCBCJ-ZMOODW2-S6OMT3O-FHFG4BY-CWZGGQX ping -> after 1m29.999892429s
syncthing[119458]: [FXOY4] 2018/11/09 11:43:33.691593 protocol.go:750: DEBUG: wrote 8 bytes on the wire (2 bytes length, 2 bytes header, 4 bytes message length, 0 bytes message), err=<nil>
syncthing[119458]: [FXOY4] 2018/11/09 11:44:03.690823 protocol.go:883: DEBUG: 7WNN76F-QGLMMBK-I5HMD36-YADCBCJ-ZMOODW2-S6OMT3O-FHFG4BY-CWZGGQX last read within 1m14.999708909s
syncthing[119458]: [FXOY4] 2018/11/09 11:44:03.691287 service.go:306: DEBUG: Reconnect loop
syncthing[119458]: [FXOY4] 2018/11/09 11:44:03.691352 service.go:428: DEBUG: sleep until next dial 1m0s
syncthing[119458]: [FXOY4] 2018/11/09 11:44:18.690972 protocol.go:415: DEBUG: read Ping message
syncthing[119458]: [FXOY4] 2018/11/09 11:44:18.691125 protocol.go:854: DEBUG: 7WNN76F-QGLMMBK-I5HMD36-YADCBCJ-ZMOODW2-S6OMT3O-FHFG4BY-CWZGGQX ping skipped after wr 44.999518411s
syncthing[119458]: [FXOY4] 2018/11/09 11:45:03.690976 protocol.go:858: DEBUG: 7WNN76F-QGLMMBK-I5HMD36-YADCBCJ-ZMOODW2-S6OMT3O-FHFG4BY-CWZGGQX ping -> after 1m29.99935673s
syncthing[119458]: [FXOY4] 2018/11/09 11:45:03.691085 protocol.go:750: DEBUG: wrote 8 bytes on the wire (2 bytes length, 2 bytes header, 4 bytes message length, 0 bytes message), err=<nil>
syncthing[119458]: [FXOY4] 2018/11/09 11:45:03.691474 service.go:306: DEBUG: Reconnect loop
syncthing[119458]: [FXOY4] 2018/11/09 11:45:03.691538 service.go:428: DEBUG: sleep until next dial 1m0s
syncthing[119458]: [FXOY4] 2018/11/09 11:45:48.690991 protocol.go:854: DEBUG: 7WNN76F-QGLMMBK-I5HMD36-YADCBCJ-ZMOODW2-S6OMT3O-FHFG4BY-CWZGGQX ping skipped after wr 44.999873355s
syncthing[119458]: [FXOY4] 2018/11/09 11:45:48.691160 protocol.go:415: DEBUG: read Ping message
From Backup server:
Nov 09 11:39:48 penelopebackup syncthing[20504]: [7WNN7] 2018/11/09 11:39:48.690168 protocol.go:858: DEBUG: FXOY4QM-D62YMWF-KSGLJNM-Q7O7UUO-EMA445V-MMARWQN-T2WUQI7-WM3ZLQL ping -> after 45.00015991s
Nov 09 11:39:48 penelopebackup syncthing[20504]: [7WNN7] 2018/11/09 11:39:48.690234 protocol.go:750: DEBUG: wrote 8 bytes on the wire (2 bytes length, 2 bytes header, 4 bytes message length, 0 bytes message), err=<nil>
Nov 09 11:40:07 penelopebackup syncthing[20504]: [7WNN7] 2018/11/09 11:40:07.886683 service.go:306: DEBUG: Reconnect loop
Nov 09 11:40:07 penelopebackup syncthing[20504]: [7WNN7] 2018/11/09 11:40:07.887038 service.go:428: DEBUG: sleep until next dial 1m0s
Nov 09 11:40:33 penelopebackup syncthing[20504]: [7WNN7] 2018/11/09 11:40:33.690193 protocol.go:854: DEBUG: FXOY4QM-D62YMWF-KSGLJNM-Q7O7UUO-EMA445V-MMARWQN-T2WUQI7-WM3ZLQL ping skipped after wr 44.999933077s
Nov 09 11:41:07 penelopebackup syncthing[20504]: [7WNN7] 2018/11/09 11:41:07.887232 service.go:306: DEBUG: Reconnect loop
Nov 09 11:41:07 penelopebackup syncthing[20504]: [7WNN7] 2018/11/09 11:41:07.887336 service.go:428: DEBUG: sleep until next dial 1m0s
Nov 09 11:41:18 penelopebackup syncthing[20504]: [7WNN7] 2018/11/09 11:41:18.690208 protocol.go:858: DEBUG: FXOY4QM-D62YMWF-KSGLJNM-Q7O7UUO-EMA445V-MMARWQN-T2WUQI7-WM3ZLQL ping -> after 1m29.999946585s
Nov 09 11:41:18 penelopebackup syncthing[20504]: [7WNN7] 2018/11/09 11:41:18.690449 protocol.go:750: DEBUG: wrote 8 bytes on the wire (2 bytes length, 2 bytes header, 4 bytes message length, 0 bytes message), err=<nil>
Nov 09 11:41:33 penelopebackup syncthing[20504]: [7WNN7] 2018/11/09 11:41:33.690043 protocol.go:883: DEBUG: FXOY4QM-D62YMWF-KSGLJNM-Q7O7UUO-EMA445V-MMARWQN-T2WUQI7-WM3ZLQL last read within 2m29.999625368s
Nov 09 11:42:03 penelopebackup syncthing[20504]: [7WNN7] 2018/11/09 11:42:03.690164 protocol.go:854: DEBUG: FXOY4QM-D62YMWF-KSGLJNM-Q7O7UUO-EMA445V-MMARWQN-T2WUQI7-WM3ZLQL ping skipped after wr 44.999707185s
Nov 09 11:42:07 penelopebackup syncthing[20504]: [7WNN7] 2018/11/09 11:42:07.887470 service.go:306: DEBUG: Reconnect loop
Nov 09 11:42:07 penelopebackup syncthing[20504]: [7WNN7] 2018/11/09 11:42:07.887567 service.go:428: DEBUG: sleep until next dial 1m0s
Nov 09 11:42:48 penelopebackup syncthing[20504]: [7WNN7] 2018/11/09 11:42:48.690205 protocol.go:858: DEBUG: FXOY4QM-D62YMWF-KSGLJNM-Q7O7UUO-EMA445V-MMARWQN-T2WUQI7-WM3ZLQL ping -> after 1m29.999733795s
Nov 09 11:42:48 penelopebackup syncthing[20504]: [7WNN7] 2018/11/09 11:42:48.690326 protocol.go:750: DEBUG: wrote 8 bytes on the wire (2 bytes length, 2 bytes header, 4 bytes message length, 0 bytes message), err=<nil>
Nov 09 11:43:07 penelopebackup syncthing[20504]: [7WNN7] 2018/11/09 11:43:07.887704 service.go:306: DEBUG: Reconnect loop
Nov 09 11:43:07 penelopebackup syncthing[20504]: [7WNN7] 2018/11/09 11:43:07.887785 service.go:428: DEBUG: sleep until next dial 1m0s
Nov 09 11:43:33 penelopebackup syncthing[20504]: [7WNN7] 2018/11/09 11:43:33.690186 protocol.go:854: DEBUG: FXOY4QM-D62YMWF-KSGLJNM-Q7O7UUO-EMA445V-MMARWQN-T2WUQI7-WM3ZLQL ping skipped after wr 44.999839843s
Nov 09 11:44:03 penelopebackup syncthing[20504]: [7WNN7] 2018/11/09 11:44:03.690067 protocol.go:883: DEBUG: FXOY4QM-D62YMWF-KSGLJNM-Q7O7UUO-EMA445V-MMARWQN-T2WUQI7-WM3ZLQL last read within 4m59.999663445s
Nov 09 11:44:07 penelopebackup syncthing[20504]: [7WNN7] 2018/11/09 11:44:07.887907 service.go:306: DEBUG: Reconnect loop
Nov 09 11:44:07 penelopebackup syncthing[20504]: [7WNN7] 2018/11/09 11:44:07.888013 service.go:428: DEBUG: sleep until next dial 1m0s
Nov 09 11:44:18 penelopebackup syncthing[20504]: [7WNN7] 2018/11/09 11:44:18.690188 protocol.go:858: DEBUG: FXOY4QM-D62YMWF-KSGLJNM-Q7O7UUO-EMA445V-MMARWQN-T2WUQI7-WM3ZLQL ping -> after 1m29.999842926s
Nov 09 11:44:18 penelopebackup syncthing[20504]: [7WNN7] 2018/11/09 11:44:18.690295 protocol.go:750: DEBUG: wrote 8 bytes on the wire (2 bytes length, 2 bytes header, 4 bytes message length, 0 bytes message), err=<nil>
Nov 09 11:45:03 penelopebackup syncthing[20504]: [7WNN7] 2018/11/09 11:45:03.690199 protocol.go:854: DEBUG: FXOY4QM-D62YMWF-KSGLJNM-Q7O7UUO-EMA445V-MMARWQN-T2WUQI7-WM3ZLQL ping skipped after wr 44.999883303s
Nov 09 11:45:07 penelopebackup syncthing[20504]: [7WNN7] 2018/11/09 11:45:07.888140 service.go:306: DEBUG: Reconnect loop
Nov 09 11:45:07 penelopebackup syncthing[20504]: [7WNN7] 2018/11/09 11:45:07.888231 service.go:428: DEBUG: sleep until next dial 1m0sDid you filter those logs? If yes, please provide all lines for a representative time duration.
The logs are missing lines. Also, I think you should reset to the default config and try again, as it seems you’ve misconfigured something port wise, as the ports don’t line up across the different logs you provide.
@imsodin I have followed your request to select protocol and connections. Should I select everything in the GUI log menu?
@AudriusButkevicius Yes I think that is because I have been trying to do selective logs. When you say reset to default, do mean just put default and dynamic on all address fields?
So I have changed everything to default. and enabled all the log except for http because it is too much. if you want it on I can add it.
The two log files are in the following two links:
https://drive.google.com/open?id=1_t4IM43eQi8NMws8L2-HBooMVtR10yYU
https://drive.google.com/open?id=1dG-hj2j5WvekX9Mb1sCzzge2KWunlk69
Thanks, Mo
I didn’t mean additional facilities (model,connections,protocol is enough), I just want all lines of the log. Now the log is very verbose and it is highly cumbersome to look through it. Please disable everything except those facilities and post the logs again - thanks.
Hi,
Check the links again. I have replaced old files with the new cleaner log.
Regadrs, Mo
This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.