Bug: HTTPS access timeout after reboot the router

efirlus commented 1 week ago

Describe the bug

Literally, I have my connected router set to reboot at 4:05am, and from that time until I reboot my PC, no matter what I do, onedrive will not connect and will repeat the error below ad infinitum.

2024-Sep-10 04:44:21.5314886    ERROR: There was a timeout in accessing the Microsoft OneDrive service - Internet connectivity issue?
2024-Sep-10 04:44:21.5317502      - Check HTTPS access or Firewall Rules
2024-Sep-10 04:50:22.5348264    ERROR: There was a timeout in accessing the Microsoft OneDrive service - Internet connectivity issue?
2024-Sep-10 04:50:22.5350628      - Check HTTPS access or Firewall Rules
2024-Sep-10 04:57:02.5381378    ERROR: There was a timeout in accessing the Microsoft OneDrive service - Internet connectivity issue?
2024-Sep-10 04:57:02.5383779      - Check HTTPS access or Firewall Rules
2024-Sep-10 05:04:23.5414394    ERROR: There was a timeout in accessing the Microsoft OneDrive service - Internet connectivity issue?
2024-Sep-10 05:04:23.5416715      - Check HTTPS access or Firewall Rules

Operating System Details

`$ uname -a`
Linux Efirlus-NAS 6.8.0-41-generic #41-Ubuntu SMP PREEMPT_DYNAMIC Fri Aug  2 20:41:06 UTC 2024 x86_64 x86_64 x86_64 GNU/Linux

`$ lsb_release -a`
Distributor ID: Ubuntu
Description:    Ubuntu 24.04.1 LTS
Release:        24.04
Codename:       noble

Client Installation Method

From 3rd Party Source (PPA, OpenSuSE Build Service etc)

OneDrive Account Type

Business | Office365

What is your OneDrive Application Version

onedrive v2.4.25-1+np3+5.1

What is your OneDrive Application Configuration

Configuration file successfully loaded
onedrive version                             = v2.4.25-1+np3+5.1
Config path                                  = /home/efirlus/.config/onedrive
Config file found in config path             = true
Config option 'sync_dir'                     = /home/efirlus/OneDrive
Config option 'enable_logging'               = true
Config option 'log_dir'                      = /var/log/onedrive/
Config option 'disable_notifications'        = false
Config option 'min_notify_changes'           = 5
Config option 'skip_dir'                     =
Config option 'skip_dir_strict_match'        = false
Config option 'skip_file'                    = ~*|.~*|*.tmp
Config option 'skip_dotfiles'                = false
Config option 'skip_symlinks'                = false
Config option 'monitor_interval'             = 3600
Config option 'monitor_log_frequency'        = 6
Config option 'monitor_fullscan_frequency'   = 24
Config option 'read_only_auth_scope'         = false
Config option 'dry_run'                      = false
Config option 'upload_only'                  = false
Config option 'download_only'                = false
Config option 'local_first'                  = false
Config option 'check_nosync'                 = false
Config option 'check_nomount'                = false
Config option 'resync'                       = false
Config option 'resync_auth'                  = false
Config option 'cleanup_local_files'          = false
Config option 'classify_as_big_delete'       = 1000
Config option 'disable_upload_validation'    = false
Config option 'bypass_data_preservation'     = false
Config option 'no_remote_delete'             = false
Config option 'remove_source_files'          = false
Config option 'sync_dir_permissions'         = 700
Config option 'sync_file_permissions'        = 600
Config option 'space_reservation'            = 52428800
Config option 'application_id'               =
Config option 'azure_ad_endpoint'            =
Config option 'azure_tenant_id'              = common
Config option 'user_agent'                   =
Config option 'force_http_11'                = false
Config option 'debug_https'                  = false
Config option 'rate_limit'                   = 0
Config option 'operation_timeout'            = 3600
Config option 'dns_timeout'                  = 60
Config option 'connect_timeout'              = 10
Config option 'data_timeout'                 = 600
Config option 'ip_protocol_version'          = 0
Config option 'sync_root_files'              = false
Selective sync 'sync_list' configured        = true
sync_list contents:
# Exclude Everythings
!/Documents
# Include Only
/Creative Cloud Files
Config option 'sync_business_shared_folders' = false
Business Shared Folders configured           = false
Config option 'webhook_enabled'              = false

What is your 'curl' version

curl 8.5.0 (x86_64-pc-linux-gnu) 
libcurl/8.5.0 
OpenSSL/3.0.13 
zlib/1.3 
brotli/1.1.0 
zstd/1.5.5 
libidn2/2.3.7 
libpsl/0.21.2 (+libidn2/2.3.7) 
libssh/0.10.6/openssl/zlib 
nghttp2/1.59.0 
librtmp/2.3 
OpenLDAP/2.6.7
Release-Date: 2023-12-06, 
security patched: 8.5.0-2ubuntu10.3
Protocols: dict file ftp ftps gopher gophers http https imap imaps ldap ldaps mqtt pop3 pop3s rtmp rtsp scp sftp smb smbs smtp smtps telnet tftp
Features: alt-svc AsynchDNS brotli GSS-API HSTS HTTP2 HTTPS-proxy IDN IPv6 Kerberos Largefile libz NTLM PSL SPNEGO SSL threadsafe TLS-SRP UnixSockets zstd

Where is your 'sync_dir' located

Local

What are all your system 'mount points'

sysfs on /sys type sysfs (rw,nosuid,nodev,noexec,relatime)
proc on /proc type proc (rw,nosuid,nodev,noexec,relatime)
udev on /dev type devtmpfs (rw,nosuid,relatime,size=3938484k,nr_inodes=984621,mode=755,inode64)
devpts on /dev/pts type devpts (rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000)
tmpfs on /run type tmpfs (rw,nosuid,nodev,noexec,relatime,size=794956k,mode=755,inode64)
efivarfs on /sys/firmware/efi/efivars type efivarfs (rw,nosuid,nodev,noexec,relatime)
/dev/sda2 on / type ext4 (rw,relatime,errors=remount-ro)
securityfs on /sys/kernel/security type securityfs (rw,nosuid,nodev,noexec,relatime)
tmpfs on /dev/shm type tmpfs (rw,nosuid,nodev,inode64)
tmpfs on /run/lock type tmpfs (rw,nosuid,nodev,noexec,relatime,size=5120k,inode64)
cgroup2 on /sys/fs/cgroup type cgroup2 (rw,nosuid,nodev,noexec,relatime)
pstore on /sys/fs/pstore type pstore (rw,nosuid,nodev,noexec,relatime)
bpf on /sys/fs/bpf type bpf (rw,nosuid,nodev,noexec,relatime,mode=700)
systemd-1 on /proc/sys/fs/binfmt_misc type autofs (rw,relatime,fd=32,pgrp=1,timeout=0,minproto=5,maxproto=5,direct,pipe_ino=680)
mqueue on /dev/mqueue type mqueue (rw,nosuid,nodev,noexec,relatime)
debugfs on /sys/kernel/debug type debugfs (rw,nosuid,nodev,noexec,relatime)
hugetlbfs on /dev/hugepages type hugetlbfs (rw,nosuid,nodev,relatime,pagesize=2M)
tracefs on /sys/kernel/tracing type tracefs (rw,nosuid,nodev,noexec,relatime)
fusectl on /sys/fs/fuse/connections type fusectl (rw,nosuid,nodev,noexec,relatime)
configfs on /sys/kernel/config type configfs (rw,nosuid,nodev,noexec,relatime)
/var/lib/snapd/snaps/core_16928.snap on /snap/core/16928 type squashfs (ro,nodev,relatime,errors=continue,threads=single,x-gdu.hide,x-gvfs-hide)
/var/lib/snapd/snaps/core_17200.snap on /snap/core/17200 type squashfs (ro,nodev,relatime,errors=continue,threads=single,x-gdu.hide,x-gvfs-hide)
/var/lib/snapd/snaps/core20_2264.snap on /snap/core20/2264 type squashfs (ro,nodev,relatime,errors=continue,threads=single,x-gdu.hide,x-gvfs-hide)
/var/lib/snapd/snaps/core20_2318.snap on /snap/core20/2318 type squashfs (ro,nodev,relatime,errors=continue,threads=single,x-gdu.hide,x-gvfs-hide)
/var/lib/snapd/snaps/lxd_24061.snap on /snap/lxd/24061 type squashfs (ro,nodev,relatime,errors=continue,threads=single,x-gdu.hide,x-gvfs-hide)
/var/lib/snapd/snaps/node_5857.snap on /snap/node/5857 type squashfs (ro,nodev,relatime,errors=continue,threads=single,x-gdu.hide,x-gvfs-hide)
/var/lib/snapd/snaps/node_6195.snap on /snap/node/6195 type squashfs (ro,nodev,relatime,errors=continue,threads=single,x-gdu.hide,x-gvfs-hide)
/var/lib/snapd/snaps/lxd_29619.snap on /snap/lxd/29619 type squashfs (ro,nodev,relatime,errors=continue,threads=single,x-gdu.hide,x-gvfs-hide)
/dev/mmcblk0p1 on /boot/efi type vfat (rw,relatime,fmask=0077,dmask=0077,codepage=437,iocharset=iso8859-1,shortname=mixed,errors=remount-ro)
binfmt_misc on /proc/sys/fs/binfmt_misc type binfmt_misc (rw,nosuid,nodev,noexec,relatime)
lxcfs on /var/lib/lxcfs type fuse.lxcfs (rw,nosuid,nodev,relatime,user_id=0,group_id=0,allow_other)
tmpfs on /run/snapd/ns type tmpfs (rw,nosuid,nodev,noexec,relatime,size=794956k,mode=755,inode64)
nsfs on /run/snapd/ns/lxd.mnt type nsfs (rw)
tmpfs on /run/user/1000 type tmpfs (rw,nosuid,nodev,relatime,size=794952k,nr_inodes=198738,mode=700,uid=1000,gid=1000,inode64)

What are all your local file system partition types

NAME FSTYPE FSVER LABEL    UUID                                 FSAVAIL FSUSE% MOUNTPOINTS
loop0
     squash 4.0                                                       0   100% /snap/core/16928
loop1
     squash 4.0                                                       0   100% /snap/core/17200
loop2
     squash 4.0                                                       0   100% /snap/core20/2264
loop3
     squash 4.0                                                       0   100% /snap/core20/2318
loop4
     squash 4.0                                                       0   100% /snap/lxd/24061
loop5
     squash 4.0                                                       0   100% /snap/node/5857
loop6
     squash 4.0                                                       0   100% /snap/node/6195
loop7
     squash 4.0                                                       0   100% /snap/lxd/29619
sda
└─sda2
     ext4   1.0            be549ebc-ec76-4bab-8c29-cadfc9f1d724     90G    18% /
mmcblk0
└─mmcblk0p1
     vfat   FAT32          ECD6-17C7                              14.7G     0% /boot/efi
mmcblk0boot0

mmcblk0boot1

How do you use 'onedrive'

For Windows 11

As with all other normal situations, the OneDrive signed in to my office 365 account is always up and running.
Windows machines are turned off during the night hours, so they're not directly hit by the problems caused by router reboots. However, I've never experienced any issues with onedrive when I turn the router off and on during the day.

For Android Devices

I connected to two Android devices via the onesync app.
I only have one folder linked, I haven't looked at it closely and it's the free version, it seems to sync about once every 2-3 hours.

For Ubuntu Server

I set the synchronizing a same folder as oneSync.
This PC is always turned on.

Steps to reproduce the behaviour

leave the computer with ubuntu server installed simply turned on.
leave onedrive running in monitor mode.
reboot the router.
watch the errors spew out.

Complete Verbose Log Output

This issue occurs when I'm running monitor mode, so I don't know how to gather verbose.

For now, try `onedrive --synchronize --verbose` in the situation where I am experiencing the problem

    Using 'user' Config Dir: /home/efirlus/.config/onedrive
    Using 'system' Config Dir: /etc/onedrive
    Configuration file successfully loaded
    Using logfile dir: /var/log/onedrive/

      Calling Function: testNetwork()

    Cannot connect to Microsoft OneDrive Service - Network Connection Issue
    ERROR: Microsoft OneDrive API returned an error with the following message:
      Error Message:    Timeout was reached on handle 57394D1ED0C0
    Unable to reach Microsoft OneDrive API service, unable to initialize application

This is a verbose after rebooting the PC, with no problems.

Using 'user' Config Dir: /home/efirlus/.config/onedrive
Using 'system' Config Dir: /etc/onedrive
Configuration file successfully loaded
Using logfile dir: /var/log/onedrive/
Checking Application Version ...
Initializing the OneDrive API ...
Configuring Global Azure AD Endpoints
Using Curl defaults for all HTTP operations
Opening the item database ...
All operations will be performed in: /home/efirlus/OneDrive
Application version: v2.4.25-1+np3+5.1
Account Type: personal
Default Drive ID: 5C94D065642EBE63
Default Root ID: 5C94D065642EBE63!sea8cc6beffdb43d7976fbc7da445c639
Remaining Free Space: 784475776614
Fetching details for OneDrive Root
OneDrive Root exists in the database
Initializing the Synchronization Engine ...
Syncing changes and items from OneDrive ...
Applying changes of Path ID: 5C94D065642EBE63!sea8cc6beffdb43d7976fbc7da445c639
Updated Remaining Free Space: 784475776614
Performing a database consistency and integrity check on locally stored data ... 
Uploading differences of ~/OneDrive
Processing .
The directory has not changed
======= Cropped file not changed log =======
The file has not changed
Uploading new items of ~/OneDrive
Applying changes of Path ID: 5C94D065642EBE63!sea8cc6beffdb43d7976fbc7da445c639
Updated Remaining Free Space: 784475776614
Processing 234 OneDrive items to ensure consistent local state due to sync_list being used
======= Cropped skipping item log =======
Sync with OneDrive is complete

This is when I forcibly disconnected the router while running verbose.

Using 'user' Config Dir: /home/efirlus/.config/onedrive
Using 'system' Config Dir: /etc/onedrive
Configuration file successfully loaded
Using logfile dir: /var/log/onedrive/
Checking Application Version ...
Initializing the OneDrive API ...
Configuring Global Azure AD Endpoints
Using Curl defaults for all HTTP operations
Opening the item database ...
All operations will be performed in: /home/efirlus/OneDrive
Application version: v2.4.25-1+np3+5.1
Account Type: personal
Default Drive ID: 5C94D065642EBE63
Default Root ID: 5C94D065642EBE63!sea8cc6beffdb43d7976fbc7da445c639
Remaining Free Space: 784475776614
Fetching details for OneDrive Root
OneDrive Root exists in the database
Initializing the Synchronization Engine ...
Syncing changes and items from OneDrive ...
Applying changes of Path ID: 5C94D065642EBE63!sea8cc6beffdb43d7976fbc7da445c639
Updated Remaining Free Space: 784475776614
Performing a database consistency and integrity check on locally stored data ... 
Uploading differences of ~/OneDrive
Processing .
The directory has not changed
======= Cropped file not changed log =======
The file has not changed
Uploading new items of ~/OneDrive
Applying changes of Path ID: 5C94D065642EBE63!sea8cc6beffdb43d7976fbc7da445c639
Updated Remaining Free Space: 784475776614
Processing 234 OneDrive items to ensure consistent local state due to sync_list being used
Skipping item - excluded by sync_list config: ./Documents

(Yes. It just cut here. same in /var/log/onedrive)

This is after rebooting the router that was forcibly cut, and then verbose.

Using 'user' Config Dir: /home/efirlus/.config/onedrive
Using 'system' Config Dir: /etc/onedrive
Configuration file successfully loaded
Using logfile dir: /var/log/onedrive/
Checking Application Version ...
Initializing the OneDrive API ...
Configuring Global Azure AD Endpoints
Using Curl defaults for all HTTP operations
Opening the item database ...
All operations will be performed in: /home/efirlus/OneDrive
Application version: v2.4.25-1+np3+5.1
Account Type: personal
Default Drive ID: 5C94D065642EBE63
Default Root ID: 5C94D065642EBE63!sea8cc6beffdb43d7976fbc7da445c639
Remaining Free Space: 784475776614
Fetching details for OneDrive Root
OneDrive Root exists in the database
Initializing the Synchronization Engine ...
Syncing changes and items from OneDrive ...
Applying changes of Path ID: 5C94D065642EBE63!sea8cc6beffdb43d7976fbc7da445c639
Updated Remaining Free Space: 784475776614
Processing 297 OneDrive items to ensure consistent local state due to sync_list being used
Skipping item - excluded by sync_list config: ./Desktop

(Yup, surprisingly, it picks up where it left off.)

Screenshots

No response

Other Log Information or Details

No response

Additional context

Well, it occurred to me while taking logs that if you stop the service, rebooting the router doesn't seem to matter. I'll have to work on a way to automatically stop the service just before 4:05am.

abraunegg commented 1 week ago

@efirlus This issue relates to the single threading of v2.4.x and will not be fixed.

Please manually compile v2.5.0 RC3 and test that application version regarding your scenario.

There is a 'short' window here that if this is still an issue in v2.5.0 RC3 this can be fixed before it is released on 16th September.

Please URGENTLY test v2.5.0 RC3 in your environment.

abraunegg commented 1 week ago

@efirlus

I'll have to work on a way to automatically stop the service just before 4:05am.

Use 'crontab' .. a cron job to restart the service after your router reboot .. say 4.10am

abraunegg commented 6 days ago

@efirlus FYI I have tested v2.5.0 RC3 against this scenario:

leave the computer with ubuntu server installed simply turned on.

leave onedrive running in monitor mode.

reboot the router.

watch the errors spew out.

No such error occurs post rebooting the router.

Please can you test v2.5.0 RC3 in your environment URGENTLY as if there is an issue, I would rather have this fixed before next Monday.

abraunegg commented 6 days ago

@efirlus Please can you respond

efirlus commented 5 days ago

@abraunegg

@efirlus Please can you respond

I apologize for taking so long to respond.

I've spent the last 3 days researching how to erase the existing packages and install 2.5.0 RC3, but I've been unable to figure it out at all. I'm unfortunately not a professional ubuntu user, just a guy who uses commands on the fly as gpt tells me to... Sorry.

Current status

Without thinking, I deleted the current onedrive and unpredictibly the contents of /home/user/OneDrive/* were deleted, but it wasn't worth it since I didn't have anything important in there.

Next, I tried to install RC, but it wasn't as easy as just typing in a few opensuse package keywords.

Building via dmd, or ldc, is something I've never done before, so I was pretty intimidated, but I went ahead and pasted in the curl - fsS blah blah bash -s dmd from the guide anyway, and got an error

I can't scrape the logs at the time because I'd already turned the SSH window off and on a few times, but it was basically saying that the OneDrive version was crashing.

After typing in a few keywords from GPT's advice that I couldn't understand, the crash went away, but the next thing I knew it was talking about permissions.

Well, I let go after that....

About crontab

Luckily, crontabs are something I've always used, so it was relatively easy to adapt. Making systemctl passwordless was a bit of a challenge, but I eventually succeeded in restricting it to onedrive@user.

Unfortunately, this wasn't a very good approach, because when I first reported the bug and forced the router to shut down, it was obviously just a matter of stopping it, turning it off, turning it back on, and then starting the service.

But then I woke up last night and realized that the same problem was still happening. Crontab timer was set to stop at 4 o'clock and start at 5 o'clock, and timer was working, but onedrive was giving me same errors from 5 o'clock.

So I came back to read this thread and saw that you had already written the RC story and the crontab story, and I tried to implement them, and it's been this long... Sorry again.

abraunegg commented 4 days ago

@efirlus Sorry that you could not work out how to uninstall your package and install RC3.

No matter, I have tested this scenario, evidence below:

Performing a sync, downloading data & then performing a reboot of the router

Screenshot from 2024-09-13 12-20-31

Client attempts to reconnect, reties in background

Screenshot from 2024-09-13 12-21-36

Router is back online, WiFi Operational, laptop reconnects, application reconnects

Screenshot from 2024-09-13 12-22-17

Further Use Case: Switch WiFi Networks to whole different SSID / Network / DNS Servers etc

Client retries for a while , DNS times out, gets a fresh connection and restarts connection with Microsoft OneDrive to continue downloading data

Screenshot from 2024-09-13 12-38-15

Based on all of this evidence I am closing this issue.

efirlus commented 3 days ago

@abraunegg

I don't know if you're being called out for tagging an ID in a closed thread, but I'm curious if I understand it correctly, that's why I comment here.

In short, if v2.5 comes out (or if I succeed in installing RC3), the problem will be solved?

Of course, I haven't solved the installation issue yet.... I'm looking forward to it being released as a package, even if it's not a homebrew or something more convenient.

abraunegg commented 3 days ago

@efirlus

In short, if v2.5 comes out (or if I succeed in installing RC3), the problem will be solved?

It should be ... but .. only doing some testing in your environment will validate. I am fairly confident that it should be fixed.

Of course, I haven't solved the installation issue yet....

Backtrack / back out everything you have done.

Given you are using Ubuntu, follow these instructions: https://github.com/abraunegg/onedrive/blob/onedrive-v2.5.0-release-candidate-3/docs/ubuntu-package-install.md

Once you do that, you will get the current client version installed.

When the release is done on Monday, and the packages are updated, you should be able to update your Ubuntu package without an issue.

efirlus commented 2 hours ago

@abraunegg

Hi! I'm here to tell you that I'm over the hump thanks to v2.5.

And I would definitely recommend adding one thing to the usage. Add a warning that the 1-thread issue is only fixed by creating a new systemservice or running daemon-reload.

If you just sudo apt update && upgrade and leave the v2.4-service alone, you still have the problem the next morning lol.

This morning I saw a bunch of timeout errors again, so I tried to error report again, and in the process gpt told me to try reload-daemon.

So I did it, and the onedrive connection was fine, even though I turned it off and on several times. I may come back in a few days, but thanks for making v2.5 so awesome. Being able to use the --verbose option even in monitor mode has allowed gpt to be more proactive in helping me.

abraunegg commented 59 minutes ago

@efirlus Thanks for the feedback that v2.5.0 is working without issue in your scenario

abraunegg / onedrive