search

abraunegg / onedrive

OneDrive Client for Linux
https://abraunegg.github.io
GNU General Public License v3.0
10.17k stars 865 forks source link

Bug: Crash after synchronizing with core.time.TimeException: Invalid ISO Extended String #2810

Closed dploeger closed 1 month ago

dploeger commented 2 months ago

Describe the bug

After synchronizing the data with --sync and vacuuming the database, the process crashes with this stack:

[Step 2/8] Performing a database consistency and integrity check on locally stored data ...Attempting to perform a database vacuum to optimise database^M
[Step 2/8] Database vacuum is complete^M
[Step 2/8] core.time.TimeException@/usr/lib/ldc/x86_64-linux-gnu/include/d/std/datetime/systime.d(9101): Invalid ISO Extended String: 2024-Sep-17 06:00:27^M
[Step 2/8] ----------------^M
[Step 2/8] ??:? [0x55ed92234da5]^M
[Step 2/8] ??:? [0x55ed92231a31]^M
[Step 2/8] ??:? [0x55ed92231692]^M
[Step 2/8] ??:? [0x55ed92259adc]^M
[Step 2/8] ??:? [0x55ed9225814f]^M
[Step 2/8] ??:? [0x55ed92259b2c]^M
[Step 2/8] ??:? [0x55ed9225814f]^M
[Step 2/8] ??:? [0x55ed92259b2c]^M
[Step 2/8] ??:? [0x55ed9225814f]^M
[Step 2/8] ??:? [0x55ed92259b2c]^M
[Step 2/8] ??:? [0x55ed9225814f]^M
[Step 2/8] ??:? [0x55ed92257ada]^M
[Step 2/8] ??:? [0x55ed922cee66]^M
[Step 2/8] ??:? [0x55ed922cb5e1]^M
[Step 2/8] ??:? void rt.dmain2._d_run_main2(char[][], ulong, extern (C) int function(char[][])*).runAll() [0x7f19050d6b7b]^M
[Step 2/8] ??:? _d_run_main2 [0x7f19050d6995]^M
[Step 2/8] ??:? _d_run_main [0x7f19050d67ed]^M
[Step 2/8] ??:? [0x7f1904d33249]^M
[Step 2/8] ??:? __libc_start_main [0x7f1904d33304]^M
[Step 2/8] ??:? [0x55ed92213100]^M
[Step 2/8] Process exited with code 1^M

Operating System Details

We're using https://hub.docker.com/r/driveone/onedrive with tag 2.5 running on 

Docker engine 

Docker version 27.2.1, build 9e34c9b

on this host:

Linux dtm-devops-p-build-06 5.15.0-122-generic #132-Ubuntu SMP Thu Aug 29 13:45:52 UTC 2024 x86_64 x86_64 x86_64 GNU/Linux
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 22.04.5 LTS
Release:    22.04
Codename:   jammy

Client Installation Method

From Distribution Package

OneDrive Account Type

Business | Office365

What is your OneDrive Application Version

onedrive v2.5.0

What is your OneDrive Application Configuration

# Running container as user: onedrive
# Base Args: --monitor
# Changing ownership permissions on /onedrive/data and /onedrive/conf to onedrive:onedrive
# Launching 'onedrive' as onedrive via gosu
Reading configuration file: /onedrive/conf/config
Configuration file successfully loaded
Application version                          = onedrive v2.5.0
Compiled with                                = LDC 2100
User Application Config path                 = /onedrive/conf
System Application Config path               = /etc/onedrive
Applicable Application 'config' location     = /onedrive/conf/config
Configuration file found in config location  = true - using 'config' file values to override application defaults
Applicable 'sync_list' location              = /onedrive/conf/sync_list
Applicable 'items.sqlite3' location          = /onedrive/conf/items.sqlite3
Config option 'drive_id'                     =
Config option 'sync_dir'                     = /onedrive/data
Config option 'enable_logging'               = false
Config option 'log_dir'                      = /var/log/onedrive
Config option 'disable_notifications'        = false
Config option 'skip_dir'                     =
Config option 'skip_dir_strict_match'        = false
Config option 'skip_file'                    = ~*|.~*|*.tmp|*.swp|*.partial
Config option 'skip_dotfiles'                = false
Config option 'skip_symlinks'                = false
Config option 'monitor_interval'             = 300
Config option 'monitor_log_frequency'        = 12
Config option 'monitor_fullscan_frequency'   = 12
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 'disable_download_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'               = <redacted>
Config option 'azure_ad_endpoint'            =
Config option 'azure_tenant_id'              =
Config option 'user_agent'                   = ISV|abraunegg|OneDrive Client for Linux/v2.5.0
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'                 = 60
Config option 'ip_protocol_version'          = 0
Config option 'threads'                      = 8
Compile time option --enable-notifications   = false

Selective sync 'sync_list' configured        = false

Config option 'sync_business_shared_items'   = true
Config option 'Shared Files Directory'       = /onedrive/data/Files Shared With Me

Config option 'webhook_enabled'              = false

### What is your 'curl' version

```shell
There is no curl command in the container image apparently...

Where is your 'sync_dir' located

Local

What are all your system 'mount points'

overlay on / type overlay (rw,relatime,lowerdir=/var/lib/docker/overlay2/l/5JLF3RFFTJY6X5IMN37WUS5NNJ:/var/lib/docker/overlay2/l/7HTAGFZKEB5LWHIE67R4FEAPSI:/var/lib/docker/overlay2/l/62Q34FAOUU43G6FQKLZDZ747XZ:/var/lib/docker/overlay2/l/XQFOILHEZ4XYFNK72GN4RN3G3S:/var/lib/docker/overlay2/l/FXFGMUASRTB76F3TORUONTTSIU:/var/lib/docker/overlay2/l/EBQLC3ZMYKSMTOP3JETN4UW6WV,upperdir=/var/lib/docker/overlay2/cae42f9677a7fb8fd2fc5538d3799244e85944026795a7f0fb987d89569fef90/diff,workdir=/var/lib/docker/overlay2/cae42f9677a7fb8fd2fc5538d3799244e85944026795a7f0fb987d89569fef90/work)
proc on /proc type proc (rw,nosuid,nodev,noexec,relatime)
tmpfs on /dev type tmpfs (rw,nosuid,size=65536k,mode=755,inode64)
devpts on /dev/pts type devpts (rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=666)
sysfs on /sys type sysfs (ro,nosuid,nodev,noexec,relatime)
cgroup on /sys/fs/cgroup type cgroup2 (ro,nosuid,nodev,noexec,relatime,nsdelegate,memory_recursiveprot)
mqueue on /dev/mqueue type mqueue (rw,nosuid,nodev,noexec,relatime)
shm on /dev/shm type tmpfs (rw,nosuid,nodev,noexec,relatime,size=65536k,inode64)
/dev/mapper/ubuntuvg-root on /onedrive/data type ext4 (rw,relatime)
/dev/mapper/ubuntuvg-root on /onedrive/conf type ext4 (rw,relatime)
/dev/mapper/ubuntuvg-root on /etc/resolv.conf type ext4 (rw,relatime)
/dev/mapper/ubuntuvg-root on /etc/hostname type ext4 (rw,relatime)
/dev/mapper/ubuntuvg-root on /etc/hosts type ext4 (rw,relatime)
devpts on /dev/console type devpts (rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=666)
proc on /proc/bus type proc (ro,nosuid,nodev,noexec,relatime)
proc on /proc/fs type proc (ro,nosuid,nodev,noexec,relatime)
proc on /proc/irq type proc (ro,nosuid,nodev,noexec,relatime)
proc on /proc/sys type proc (ro,nosuid,nodev,noexec,relatime)
proc on /proc/sysrq-trigger type proc (ro,nosuid,nodev,noexec,relatime)
tmpfs on /proc/acpi type tmpfs (ro,relatime,inode64)
tmpfs on /proc/kcore type tmpfs (rw,nosuid,size=65536k,mode=755,inode64)
tmpfs on /proc/keys type tmpfs (rw,nosuid,size=65536k,mode=755,inode64)
tmpfs on /proc/timer_list type tmpfs (rw,nosuid,size=65536k,mode=755,inode64)
tmpfs on /proc/scsi type tmpfs (ro,relatime,inode64)
tmpfs on /sys/firmware type tmpfs (ro,relatime,inode64)
tmpfs on /sys/devices/virtual/powercap type tmpfs (ro,relatime,inode64)

What are all your local file system partition types

NAME   FSTYPE FSVER LABEL UUID FSAVAIL FSUSE% MOUNTPOINTS
loop0
loop1
loop2
loop3
loop4
loop5
loop6
loop7
loop8
loop9
loop10
loop11
sda
|-sda1
|-sda2
`-sda3
sdb

How do you use 'onedrive'

The onedrive sync folder is used for storing export data from one system and synced to a shared business folder.

Steps to reproduce the behaviour

Complete Verbose Log Output

Will generate it and send the debug log to the mail adress because of possible sensitive data.

Screenshots

No response

Other Log Information or Details

No response

Additional context

No response

abraunegg commented 2 months ago

@dploeger Please build from 'source' - using 'master' and reproduce without using Docker please.

When building from source, please enable debugging:

./configure --enable-debug make clean; make;

To create a debug log output, please follow:

onedrive --sync --resync --resync-auth --verbose --verbose > debug_output.log 2>&1

Thanks.

abraunegg commented 1 month ago

@dploeger If you are able to 'self build' Docker containers, I have created PR #2811 that adds the --enable-debug option to the Docker builds.

This is critically important to resolve this:

[Step 2/8] core.time.TimeException@/usr/lib/ldc/x86_64-linux-gnu/include/d/std/datetime/systime.d(9101): Invalid ISO Extended String: 2024-Sep-17 06:00:27^M
[Step 2/8] ----------------^M
[Step 2/8] ??:? [0x55ed92234da5]^M
[Step 2/8] ??:? [0x55ed92231a31]^M
[Step 2/8] ??:? [0x55ed92231692]^M
[Step 2/8] ??:? [0x55ed92259adc]^M
[Step 2/8] ??:? [0x55ed9225814f]^M
[Step 2/8] ??:? [0x55ed92259b2c]^M
[Step 2/8] ??:? [0x55ed9225814f]^M
[Step 2/8] ??:? [0x55ed92259b2c]^M
[Step 2/8] ??:? [0x55ed9225814f]^M
[Step 2/8] ??:? [0x55ed92259b2c]^M
[Step 2/8] ??:? [0x55ed9225814f]^M
[Step 2/8] ??:? [0x55ed92257ada]^M
[Step 2/8] ??:? [0x55ed922cee66]^M
[Step 2/8] ??:? [0x55ed922cb5e1]^M
[Step 2/8] ??:? void rt.dmain2._d_run_main2(char[][], ulong, extern (C) int function(char[][])*).runAll() [0x7f19050d6b7b]^M
[Step 2/8] ??:? _d_run_main2 [0x7f19050d6995]^M
[Step 2/8] ??:? _d_run_main [0x7f19050d67ed]^M
[Step 2/8] ??:? [0x7f1904d33249]^M
[Step 2/8] ??:? __libc_start_main [0x7f1904d33304]^M
[Step 2/8] ??:? [0x55ed92213100]^M

Once this is resolved, the reason for the crash can be understood and then fixed.

Without this resolution, it is next to impossible to pinpoint the cause & fix.

abraunegg commented 1 month ago

@dploeger Please use the following instructions to clone this PR:

git clone https://github.com/abraunegg/onedrive.git
cd onedrive
git fetch origin pull/2811/head:pr2811
git checkout pr2811

Augment the above with the instructions here on building your own Docker container:

https://github.com/abraunegg/onedrive/blob/master/docs/docker.md#building-a-custom-docker-image

dploeger commented 1 month ago

Meh. On a second run it works without a problem. I'll keep this in mind though. Thanks!

abraunegg commented 1 month ago

No problem .. it would have been good to know what broke and where and why ....

dploeger commented 1 month ago

But now I see other problems in another run. I'll create the docker image and will use that internally. If another problem occurs, I can give you better information.

dploeger commented 1 month ago

@abraunegg Hm. --enable-debug still doesn't seem to work in the container:

grafik

Or did I misunderstand you there?

(I've build the image on the PR branch and pushed that to our internal registry to use it in the CI build)

abraunegg commented 1 month ago

@abraunegg Hm. --enable-debug still doesn't seem to work in the container:

grafik

Or did I misunderstand you there?

(I've build the image on the PR branch and pushed that to our internal registry to use it in the CI build)

You need to recompile the actual 'client' .. by either building the entire client from scratch, or using the PR and build your own Docker container from the PR, which will do this step.

When using the 'self built' container, the 'onedrive' binary will be built with --enable-debug to then give the right details.

dploeger commented 1 month ago

I've checked out the PR and ran docker build.

Isn't that what you mean with "self-built container"?

abraunegg commented 1 month ago

I've checked out the PR and ran docker build.

Isn't that what you mean with "self-built container"?

Correct ... so now, if the client crashes, the internally built 'onedrive' binary will have the correct debugging enabled to capture what is going on.

dploeger commented 1 month ago

Ohhh. It's not a parameter to the entrypoint of the container?

abraunegg commented 1 month ago

Ohhh. It's not a parameter to the entrypoint of the container?

No it is not .. which is why you have to either:

dploeger commented 1 month ago

Yeah, yeah. I got that. But I added --enable-debug to the parameter list and saw the error because I misunderstood you. Will remove it tomorrow and report any stack traces. Thanks for the support!

abraunegg commented 1 month ago

@dploeger FYI - what I have also done in the meantime is I have added the required change into 'master' , so if you use any of the 'edge' Docker tags, this 'change' should be there by default - this may assist you with this issue.

abraunegg commented 1 month ago

@dploeger I have been looking at this issue today more deeply, and I am still trying to deduce where the issue is being introduced, however, given that there are 2 issues of the same type that has been raised, I have worked on a more generic fix.

Please can you pull this PR, and build a new Docker container from this PR:

git clone https://github.com/abraunegg/onedrive.git
cd onedrive
git fetch origin pull/2816/head:pr2816
git checkout pr2816

When running the PR, your version should be: onedrive v2.5.0-3-gf06e816 or greater within your Docker container.

dploeger commented 1 month ago

I've compiled the PR and will use that image from now on. Our pipeline runs for 4 hours though (one initial onedrive sync, generating the export and rsyncing it locally, second onedrive sync) so I can't provide faster insights I'm afraid.

abraunegg commented 1 month ago

I've compiled the PR and will use that image from now on. Our pipeline runs for 4 hours though (one initial onedrive sync, generating the export and rsyncing it locally, second onedrive sync) so I can't provide faster insights I'm afraid.

No problem - thanks for letting me know

dploeger commented 1 month ago

It now failed with this on the second sync:

  std.json.JSONException@std/json.d(315): JSONValue is not an object
  ----------------
  /usr/lib/ldc/x86_64-redhat-linux-gnu/include/d/std/exception.d:519 pure @safe noreturn std.exception.bailOut!(std.json.JSONException).bailOut(immutable(char)[], ulong, scope const(char)[]) [0x68b1e3]
  ??:? inout pure ref @safe inout(std.json.JSONValue) std.json.JSONValue.opIndex(return scope immutable(char)[]) [0x7fe4485c5a93]
  src/sync.d:6027 [0x4d3cac]
  src/sync.d:4417 [0x4d261c]
  src/sync.d:4161 [0x4d1208]
  src/sync.d:4060 [0x4d0c79]
  /usr/lib/ldc/x86_64-redhat-linux-gnu/include/d/std/parallelism.d-mixin-4114:4156 [0x68e3db]
  ??:? void std.parallelism.TaskPool.executeWorkLoop() [0x7fe4485a378d]
  ??:? thread_entryPoint [0x7fe4482da467]
  ??:? [0x7fe447f936d6]
  ??:? __clone [0x7fe448017413]
dploeger commented 1 month ago

Hope that helps

abraunegg commented 1 month ago

Hope that helps

That little part shows a 100% potentially different issue .......

dploeger commented 1 month ago

Yes. The original TimeException doesn't seem to pop up again.

dploeger commented 1 month ago

We can update this issue to better reflect it or I can open another one

abraunegg commented 1 month ago

Please raise a new bug report for tracking purposes

dploeger commented 1 month ago

This is in #2822 then. I'll close this bug then.

abraunegg commented 1 month ago

Keep this one open for the moment until 2813 is also solved.

abraunegg commented 1 month ago

This issue has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.