search

ddvk / rmfakecloud

host your own cloud for the remarkable
GNU Affero General Public License v3.0
788 stars 68 forks source link

sync breaks on 3.5.1.1798 #251

Closed zcy85611 closed 1 year ago

zcy85611 commented 1 year ago

I just updated to 3.5.1.1798, with everything unchanged, the sync on remarkable breaks

reMarkable can be paired with server, but gets a network failure 500 when syncing

On windows client v3.5.0.750, the same thing happens

Would you please help look into it please？ thanks

xochitl log 

Jul 13 06:02:42 reMarkable xochitl[248]: 06:02:42.053 rm.epaperkeyboardhandler No keymap set by QT settings or firmware, defaulting to US.
Jul 13 06:02:42 reMarkable xochitl[248]: 06:02:42.054 rm.epaperkeyboardhandler No keymap set by QT settings or firmware, defaulting to US.
Jul 13 06:02:42 reMarkable xochitl[248]: 06:02:42.143 rm.network.usertoken     Scheduled token update at 2023-07-14 05:57:41, 86098857ms from now (scheduleUpdate /__w/xochitl/xochitl/src/network/src/usertoken.cpp:144)
Jul 13 06:02:42 reMarkable xochitl[248]: 06:02:42.143 rm.network.usertoken     UserToken: setting a new userToken ("eyJhbGciOiJIUzI1NiIs"...) (setUserToken /__w/xochitl/xochitl/src/network/src/usertoken.cpp:76)
Jul 13 06:02:42 reMarkable xochitl[248]: 06:02:42.223 rm.epaperkeyboardhandler No keymap set by QT settings or firmware, defaulting to US.
Jul 13 06:02:42 reMarkable xochitl[248]: 06:02:42.224 rm.epaperkeyboardhandler No keymap set by QT settings or firmware, defaulting to US.
Jul 13 06:02:42 reMarkable xochitl[248]: 06:02:42.239 rm.network.notifications Notifications socket is not OK: UnconnectedState (checkIfShouldConnect /__w/xochitl/xochitl/src/notifications/src/notifications.cpp:186)
Jul 13 06:02:42 reMarkable rm-sync[249]: rm.synchronizer:  - read '/home/root/.local/share/remarkable/xochitl/.tree' in 00.000053615s (failed)
Jul 13 06:03:12 reMarkable xochitl[248]: 06:03:12.890 default                  QIODevice::write (QSslSocket): device not open
Jul 13 06:03:12 reMarkable xochitl[248]: 06:03:12.896 rm.network.notifications Notifications socket is not OK: UnconnectedState (checkIfShouldConnect /__w/xochitl/xochitl/src/notifications/src/notifications.cpp:186)
Jul 13 06:03:43 reMarkable xochitl[248]: 06:03:43.890 default                  QIODevice::write (QSslSocket): device not open
Jul 13 06:03:43 reMarkable xochitl[248]: 06:03:43.895 rm.network.notifications Notifications socket is not OK: UnconnectedState (checkIfShouldConnect /__w/xochitl/xochitl/src/notifications/src/notifications.cpp:186)
Jul 13 06:04:14 reMarkable xochitl[248]: 06:04:14.892 default                  QIODevice::write (QSslSocket): device not open
Jul 13 06:04:14 reMarkable xochitl[248]: 06:04:14.899 rm.network.notifications Notifications socket is not OK: UnconnectedState (checkIfShouldConnect /__w/xochitl/xochitl/src/notifications/src/notifications.cpp:186)
Jul 13 06:04:45 reMarkable xochitl[248]: 06:04:45.892 default                  QIODevice::write (QSslSocket): device not open
Jul 13 06:04:45 reMarkable xochitl[248]: 06:04:45.897 rm.network.notifications Notifications socket is not OK: UnconnectedState (checkIfShouldConnect /__w/xochitl/xochitl/src/notifications/src/notifications.cpp:186)
Jul 13 06:05:16 reMarkable xochitl[248]: 06:05:16.893 default                  QIODevice::write (QSslSocket): device not open
Jul 13 06:05:16 reMarkable xochitl[248]: 06:05:16.898 rm.network.notifications Notifications socket is not OK: UnconnectedState (checkIfShouldConnect /__w/xochitl/xochitl/src/notifications/src/notifications.cpp:186)
Jul 13 06:05:47 reMarkable xochitl[248]: 06:05:47.893 default                  QIODevice::write (QSslSocket): device not open
Jul 13 06:05:47 reMarkable xochitl[248]: 06:05:47.897 rm.network.notifications Notifications socket is not OK: UnconnectedState (checkIfShouldConnect /__w/xochitl/xochitl/src/notifications/src/notifications.cpp:186)
Jul 13 06:06:18 reMarkable xochitl[248]: 06:06:18.890 default                  QIODevice::write (QSslSocket): device not open
Jul 13 06:06:18 reMarkable xochitl[248]: 06:06:18.895 rm.network.notifications Notifications socket is not OK: UnconnectedState (checkIfShouldConnect /__w/xochitl/xochitl/src/notifications/src/notifications.cpp:186)

sync log

Jul 13 05:58:53 reMarkable systemd[1]: rm-sync.service: Succeeded.
Jul 13 05:59:10 reMarkable systemd[1]: rm-sync.service: Service has a D-Bus service name specified, but is not of type dbus. Ignoring.
Jul 13 05:59:15 reMarkable rm-sync[249]: Lock in temp location
Jul 13 05:59:15 reMarkable rm-sync[249]: Installing crash handler
Jul 13 05:59:15 reMarkable rm-sync[249]: installed crash handler
Jul 13 05:59:15 reMarkable rm-sync[249]: Running service...
Jul 13 06:02:42 reMarkable rm-sync[249]: rm.synchronizer:  - read '/home/root/.local/share/remarkable/xochitl/.tree' in 00.000053615s (failed)
Jul 13 06:07:21 reMarkable rm-sync[249]: rm.synchronizer:  -> exceeded retries for "."
Jul 13 06:07:21 reMarkable rm-sync[249]: rm.synchronizer: Communication error when fetching server hash: "root", ""
Jul 13 06:07:21 reMarkable rm-sync[249]: rm.synchronizer:  -> failing SyncDownloadRootHashJob for "." with RequestNetworkError, 500, ""
Jul 13 06:07:21 reMarkable rm-sync[249]: rm.synchronizer: Oh no!!!, Sync failed.. reason="Network failure: 500", detail=""
nemunaire commented 1 year ago

Hi @zcy85611!

I don't encounter any issue on 3.5.1.1798 on my side.

Could you please include the latest rmfakecloud logs, server side. The 500 error should be logged with a message.

zcy85611 commented 1 year ago

I've tried both windows client and remarkable, the errors are the same, on the server side, the error message is msg="not found"

server side

14:25:14 rMcloud[17791]: time="2023-07-13T06:25:14Z" level=warning msg="RM_HTTPS_COOKIE is not set, use only when not using https!"
14:25:14 rMcloud[17791]: time="2023-07-13T06:25:14Z" level=warning msg="smtp not configured, no emails will be sent"
14:25:14 rMcloud[17791]: time="2023-07-13T06:25:14Z" level=info msg="if you want HWR, provide the myScript applicationKey in: RMAPI_HWR_APPLICATIONKEY"
14:25:14 rMcloud[17791]: time="2023-07-13T06:25:14Z" level=info msg="provide the myScript hmac in: RMAPI_HWR_HMAC"
14:25:14 rMcloud[17791]: time="2023-07-13T06:25:14Z" level=info msg="Version: "
14:25:14 rMcloud[17791]: time="2023-07-13T06:25:14Z" level=info msg="STORAGE_URL (Cloud URL): https://local.appspot.com"
14:25:14 rMcloud[17791]: time="2023-07-13T06:25:14Z" level=info msg="Data: /mnt/sda1/cloud"
14:25:14 rMcloud[17791]: time="2023-07-13T06:25:14Z" level=info msg="Listening on port: 3000"
14:25:14 rMcloud[17791]: time="2023-07-13T06:25:14Z" level=info msg="Using plain HTTP"
14:28:21 rMcloud[17791]: time="2023-07-13T06:28:21Z" level=info msg="[auth-middleware] UserId: admin deviceId: RM110-209-xxxxx newSync: true"
14:28:21 rMcloud[17791]: time="2023-07-13T06:28:21Z" level=error msg="not found"
14:28:21 rMcloud[17791]: time="2023-07-13T06:28:21Z" level=info msg="[GIN] 2023/07/13 - 06:28:21 | 500 |    6.122422ms |       127.0.0.1 | GET      \"/sync/v3/root\""
14:28:21 rMcloud[17791]: time="2023-07-13T06:28:21Z" level=info msg="[auth-middleware] UserId: admin deviceId: RM110-209-xxxxx newSync: true"
14:28:21 rMcloud[17791]: time="2023-07-13T06:28:21Z" level=error msg="not found"
14:28:21 rMcloud[17791]: time="2023-07-13T06:28:21Z" level=info msg="[GIN] 2023/07/13 - 06:28:21 | 500 |    4.123743ms |       127.0.0.1 | GET      \"/sync/v3/root\""
14:28:24 rMcloud[17791]: time="2023-07-13T06:28:24Z" level=info msg="[auth-middleware] UserId: admin deviceId: RM110-209-xxxxx newSync: true"
14:28:24 rMcloud[17791]: time="2023-07-13T06:28:24Z" level=error msg="not found"
14:28:24 rMcloud[17791]: time="2023-07-13T06:28:24Z" level=info msg="[GIN] 2023/07/13 - 06:28:24 | 500 |    3.360127ms |       127.0.0.1 | GET      \"/sync/v3/root\""
zcy85611 commented 1 year ago

wired, sync backs to normal now, I've done nothing....

zcy85611 commented 1 year ago

thanks for the help

nemunaire commented 1 year ago

Ok, so the reason of the failure seems to be the absence of the users/admin/sync/root file.

Could you check you don't have that file on your server?

If so, check if you have users/admin/sync/.root.history.

If you have users/admin/sync/.root.history, which is not empty but not users/admin/sync/root, you could recreate it with:

cd users/admin/sync
! [ -s root ] && [ -s .root.history ] && sed '$s/^.\+ //p;d' .root.history | tr -d '\n' > root

Where admin is the name of your user.

nemunaire commented 1 year ago

wired, sync backs to normal now, I've done nothing....

Perhaps there has been a filesystem corruption on your server, leading to the deletion of the root file on recovery? This file is regularly overwritten by the synchronization. Or an unexpected stop, in the middle of a synchronization?

The root file comes with the sync1.5 schema. I see no reason why it could have disappear... Perhaps we can perform an automatic recovery from the history in that case.