JSONValue is not an object - session uploads via HTTP/2 via curl 7.62.0

[hjrdizwell]

Bug Report Details

Using Manjaro (4.14.79-1-MANJARO #1 SMP PREEMPT Sun Nov 4 16:57:03 UTC 2018 x86_64)
Was uploading ~1TB of files using the manually-issued command:

onedrive --synchronize --upload-only

All had been fine for about a week. I interrupted the upload to apply some O/S updates, rebooted, re-issued the upload command and then got this error:

Initializing the Synchronization Engine ...
Syncing changes from local path only - NOT syncing data changes from OneDrive ...
Uploading file ./classical/G/Gustav Mahler/Vocal/Rückertlieder (Ferrier)/01 - Ich bin der Welt abhanden gekommen.flac ...
Uploading  33% |oooooooooooooo                          |   ETA   --:--:--: done.                                                                                       
JSONValue is not an object

It would try three times and then produced this output after the third attempt:

td.json.JSONException@std/json.d(274): JSONValue is not an object
----------------
/usr/include/dlang/dmd/std/exception.d:515 pure @safe void std.exception.bailOut!(std.json.JSONException).bailOut(immutable(char)[], ulong, scope const(char)[]) [0x618ac9c3]
/usr/include/dlang/dmd/std/exception.d:436 pure @safe bool std.exception.enforce!(std.json.JSONException).enforce!(bool).enforce(bool, lazy const(char)[], immutable(char)[], ulong) [0x618ac93d]
??:? inout pure @property @trusted inout(std.json.JSONValue[immutable(char)[]]) std.json.JSONValue.objectNoRef() [0x61908551]
??:? inout pure ref @safe inout(std.json.JSONValue) std.json.JSONValue.opIndex(immutable(char)[]) [0x61908728]
src/sync.d:1366 void sync.SyncEngine.uploadNewFile(immutable(char)[]) [0x618dae40]
src/sync.d:1147 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x618d9ed2]
src/sync.d:1138 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x618d9dc9]
src/sync.d:1138 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x618d9dc9]
src/sync.d:1138 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x618d9dc9]
src/sync.d:1138 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x618d9dc9]
src/sync.d:1138 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x618d9dc9]
src/sync.d:1138 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x618d9dc9]
src/sync.d:851 void sync.SyncEngine.scanForDifferences(immutable(char)[]) [0x618d8a3d]
src/main.d:432 void main.performSync(sync.SyncEngine, immutable(char)[], bool, bool, bool) [0x618bb430]
src/main.d:312 _Dmain [0x618bad1c]

I have tried onedrive --resync --verbose, but that hasn't resolved the problem. I am at a loss to know what else to try. Got desperate enough to boot up a Win10 VM and use the native client to finish the upload... which made me sad :-(

Application and Operating System Details:
OS: Linux 4.14.79-1-MANJARO #1 SMP PREEMPT Sun Nov 4 16:57:03 UTC 2018 x86_64 GNU/Linux

• Using KDE
• Application version: onedrive v2.1.4-6-geb2cbfd
• OneDrive Account Type -subscriber to Office 365 Home
• DMD or LDC compiler version dmd --version or ldmd2 --version

[hjr@britten ~]$ dmd --version
DMD64 D Compiler v2.083.0
Copyright (C) 1999-2018 by The D Language Foundation, All Rights Reserved written by Walter Bright
[hjr@britten ~]$ ldmd2 --version
bash: ldmd2: command not found

To Reproduce
Steps to reproduce the behavior if not causing an application crash:
Using the command onedrive --synchronize --upload-only, with the source folder described as follows:

[hjr@britten ~]$ cd .config/onedrive/
[hjr@britten onedrive]$ cat config
sync_dir="/multimedia/flac/hjr"

The issue happens regardless of what audio file is being uploaded. After the first error, for example, and thinking that maybe it was file-related, I uploaded the file mentioned in the error via the website. A new synchronisation attempt would then try a different file and would produce the same error as the previous one. This would keep happening, no matter how many files I manually uploaded via the website.

Complete Verbose Log Output
There are about 50,000 files to upload in all, so I won't bore you with the entire log! But after a lot of this sort of thing:

Processing Hymn to St. Cecilia (Best)
The directory has not changed
Processing 01 - Hymn to St. Cecilia.flac
The file has not changed
Processing Hymn to St. Cecilia (Guest)
The directory has not changed

...the output eventually changes to:

Processing 05 - Ich bin der Welt abhanden gekommen.flac
The file has not changed
Processing 04 - Liebst du um Schönheit.flac
The file has not changed
Processing Rückertlieder (Ferrier)
The directory has not changed
Uploading new items of .
Uploading file ./classical/G/Gustav Mahler/Vocal/Rückertlieder (Ferrier)/01 - Ich bin der Welt abhanden gekommen.flac ...
Uploading  33% |oooooooooooooo                          |   ETA   --:--:--: done.                                                                                       
std.json.JSONException@std/json.d(274): JSONValue is not an object
----------------
/usr/include/dlang/dmd/std/exception.d:515 pure @safe void std.exception.bailOut!(std.json.JSONException).bailOut(immutable(char)[], ulong, scope const(char)[]) [0x19fc59c3]
/usr/include/dlang/dmd/std/exception.d:436 pure @safe bool std.exception.enforce!(std.json.JSONException).enforce!(bool).enforce(bool, lazy const(char)[], immutable(char)[], ulong) [0x19fc593d]
??:? inout pure @property @trusted inout(std.json.JSONValue[immutable(char)[]]) std.json.JSONValue.objectNoRef() [0x1a021551]
??:? inout pure ref @safe inout(std.json.JSONValue) std.json.JSONValue.opIndex(immutable(char)[]) [0x1a021728]
src/sync.d:1366 void sync.SyncEngine.uploadNewFile(immutable(char)[]) [0x19ff3e40]
src/sync.d:1147 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x19ff2ed2]
src/sync.d:1138 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x19ff2dc9]
src/sync.d:1138 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x19ff2dc9]
src/sync.d:1138 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x19ff2dc9]
src/sync.d:1138 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x19ff2dc9]
src/sync.d:1138 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x19ff2dc9]
src/sync.d:1138 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x19ff2dc9]
src/sync.d:851 void sync.SyncEngine.scanForDifferences(immutable(char)[]) [0x19ff1a3d]
src/main.d:432 void main.performSync(sync.SyncEngine, immutable(char)[], bool, bool, bool) [0x19fd4430]
src/main.d:312 _Dmain [0x19fd3d1c]

(As I say, I've checked with mutliple different files having been uploaded by hand, so that the onedrive tool attempts to upload various different files, so it's not the presence of the umlaut in the file name that is the problem -it will happen on perfectly plain-English file names, too).

Application Log Output:

This is from the point where the upload had been working fine, there's an interruption to apply O/S updates, and then I try to resume the upload:

2018-Nov-08 11:22:07.2200763 Uploading file ./classical/G/Giuseppe Verdi/Opera/Macbeth (Abbado)/04 - S'allontanarono! N'accozzeremo.flac ... done.
2018-Nov-08 11:40:15.0380592 Initializing the Synchronization Engine ...
2018-Nov-08 11:40:17.5650974 Syncing changes from local path only - NOT syncing data changes from OneDrive ...
2018-Nov-08 11:41:01.8135254 Uploading file ./classical/G/Gioacchino Rossini/Opera/Semiramide (Sutherland)/31 - Su, ti scuoti.flac ... done.
2018-Nov-08 11:41:01.8137363 JSONValue is not an object
2018-Nov-08 11:41:01.8138053 Syncing changes from local path only - NOT syncing data changes from OneDrive ...
2018-Nov-08 11:41:46.1463833 Uploading file ./classical/G/Gioacchino Rossini/Opera/Semiramide (Sutherland)/31 - Su, ti scuoti.flac ... done.

Screenshots
If applicable, add screenshots to help explain your problem.

Additional context
If it helps, OneDrive itself is reporting that I have used 339GB of 1TB, so it's not a matter of running out of disk space.

Bug Report Checklist

• Detailed description
• Reproduction steps (if applicable) -not really applicable. It's just happening every time now.
• Verbose Log Output -hopefully the above is sufficient?

Appreciate any guidance/help: really value this tool and think it's a splendid thing for Linux folk!

[abraunegg]

@hjrdizwell
If this issue is currently 100% repeatable at the moment, can you perform a sync, but using this explicit command line:

onedrive --synchronize --upload-only --debug-https

Need to understand what is being sent by OneDrive when the failure occurs to determine the cause behind 'JSONValue is not an object'

[abraunegg]

Can you also advise what version of curl you are running

[hjrdizwell]

Hello: [hjr@britten onedrive]$ curl --version curl 7.62.0 (x86_64-pc-linux-gnu) libcurl/7.62.0 OpenSSL/1.1.1 zlib/1.2.11 libidn2/2.0.5 libpsl/0.20.2 (+libidn2/2.0.4) libssh2/1.8.0 nghttp2/1.34.0 Release-Date: 2018-10-31 Protocols: dict file ftp ftps gopher http https imap imaps pop3 pop3s rtsp scp sftp smb smbs smtp smtps telnet tftp Features: AsynchDNS IDN IPv6 Largefile GSS-API Kerberos SPNEGO NTLM NTLM_WB SSL libz TLS-SRP HTTP2 UnixSockets HTTPS-proxy PSL Hope that helps... Let me know if I can provide any other information for you. Regards & Thanks again, HJR

…

On 10/11/2018 00:56, abraunegg wrote: Can you also advise what version of curl you are running — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#224 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/Aq0r6dXy6xWHPdBMUqzN2e6c6VmjNWy4ks5utiQogaJpZM4YW3SJ>.

[abraunegg]

As your running with the updated curl version - see #220 - can you please retest using the PR as described in #220.

If this still is causing you an issue, please provide the debug log as requested above with the --debug-https flag

[abraunegg]

@hjrdizwell
PR from #220 has now been merged, please can you rebuild your client from master and retest given you were using curl 7.62.0

[abraunegg]

@hjrdizwell
Do you have an update?

[hjrdizwell]

I've emailed an update twice now, but it would appear not to be getting through. So I'll type it again here directly.

Hello:
I wasn't entirely sure what 'rebuild from master' meant, so I did the following:

[hjr@britten ~]$ rm -rf onedrive
[hjr@britten ~]$ git clone https://github.com/abraunegg/onedrive.git
Cloning into 'onedrive'...
remote: Enumerating objects: 45, done.
remote: Counting objects: 100% (45/45), done.
remote: Compressing objects: 100% (38/38), done.
remote: Total 1708 (delta 23), reused 15 (delta 7), pack-reused 1663
Receiving objects: 100% (1708/1708), 1.05 MiB | 1.02 MiB/s, done.
Resolving deltas: 100% (1147/1147), done.
[hjr@britten ~]$ cd onedrive
[hjr@britten onedrive]$ make
echo v2.1.4-7-g11e477f >version
dmd -g -ofonedrive -O -L-lcurl -L-lsqlite3 -L-ldl -J. src/config.d src/itemdb.d src/log.d src/main.d src/monitor.d src/onedrive.d src/qxor.d src/selective.d src/sqlite.d src/sync.d src/upload.d src/util.d src/progress.d
sed "s|@PREFIX@|/usr/local|g" systemd.units/onedrive.service.in > onedrive.service
sed "s|@PREFIX@|/usr/local|g" systemd.units/onedrive@.service.in > onedrive@.service
[hjr@britten onedrive]$ sudo make install
[sudo] password for hjr:
mkdir -p /var/log/onedrive
chown root.users /var/log/onedrive
chmod 0775 /var/log/onedrive
install -D onedrive /usr/local/bin/onedrive
install -D -m 644 logrotate/onedrive.logrotate /etc/logrotate.d/onedrive
mkdir -p /usr/lib/systemd/user/
chown root.root /usr/lib/systemd/user/
chmod 0755 /usr/lib/systemd/user/
install -D -m 644 onedrive.service /usr/lib/systemd/user/
mkdir -p /usr/lib/systemd/system/
chown root.root /usr/lib/systemd/system/
chmod 0755 /usr/lib/systemd/system/
install -D -m 644 onedrive@.service /usr/lib/systemd/system/
[hjr@britten onedrive]$ onedrive --synchronize --upload-only
Initializing the Synchronization Engine ...
Syncing changes from local path only - NOT syncing data changes from OneDrive ...
Uploading file ./classical/H/Heinrich Ignaz Franz von Biber/Chamber/Rosary Sonatas (Podger)/01 - The Annunciation.flac ...
Uploading 100% |oooooooooooooooooooooooooooooooooooooooo| DONE IN 00:00:33                                                                                             
    done.
Uploading file ./classical/H/Heinrich Ignaz Franz von Biber/Chamber/Rosary Sonatas (Podger)/02 - The Visitation.flac ...

As you can see, file uploads are working fine.
So it all looks good from here: let me know if you need me to do anything else to help.
Regards
HJR

[abraunegg]

Your version seems off

echo v2.1.4-7-g11e477f >version

Would be worth rebuilding again to ensure you get the v2.1.5-* release & version

[hjrdizwell]

OK. Sorry about that. Not sure what happened: possibly didn't delete the original directory created by my initial pull, thus ended up merely re-compiling the patched 2.1.4 version? But in anycase, I should probably not have tried to improve on perfection! See below:

[hjr@britten ~]$ git clone https://github.com/abraunegg/onedrive.git
Cloning into 'onedrive'...
remote: Enumerating objects: 1714, done.
remote: Total 1714 (delta 0), reused 0 (delta 0), pack-reused 1714
Receiving objects: 100% (1714/1714), 1.04 MiB | 1020.00 KiB/s, done.
Resolving deltas: 100% (1156/1156), done.
[hjr@britten ~]$ cd onedrive
[hjr@britten onedrive]$ make
echo v2.1.5-1-g8a98bf3 >version
dmd -g -ofonedrive -O -L-lcurl -L-lsqlite3 -L-ldl -J. src/config.d src/itemdb.d src/log.d src/main.d src/monitor.d src/onedrive.d src/qxor.d src/selective.d src/sqlite.d src/sync.d src/upload.d src/util.d src/progress.d
sed "s|@PREFIX@|/usr/local|g" systemd.units/onedrive.service.in > onedrive.service
sed "s|@PREFIX@|/usr/local|g" systemd.units/onedrive@.service.in > onedrive@.service
[hjr@britten onedrive]$ sudo make install
[sudo] password for hjr: 
mkdir -p /var/log/onedrive
chown root.users /var/log/onedrive
chmod 0775 /var/log/onedrive
install -D onedrive /usr/local/bin/onedrive
install -D -m 644 logrotate/onedrive.logrotate /etc/logrotate.d/onedrive
mkdir -p /usr/lib/systemd/user/
chown root.root /usr/lib/systemd/user/
chmod 0755 /usr/lib/systemd/user/
install -D -m 644 onedrive.service /usr/lib/systemd/user/
mkdir -p /usr/lib/systemd/system/
chown root.root /usr/lib/systemd/system/
chmod 0755 /usr/lib/systemd/system/
install -D -m 644 onedrive@.service /usr/lib/systemd/system/
[hjr@britten onedrive]$ onedrive --version
onedrive v2.1.5-1-g8a98bf3
[hjr@britten onedrive]$ onedrive --synchronize --upload-only
Initializing the Synchronization Engine ...
Syncing changes from local path only - NOT syncing data changes from OneDrive ...
Uploading file ./classical/J/Johann Sebastian Bach/Cantata/BWV 175 - Er rufet seinen Schafen mit Namen (Gardiner)/05 - Sie vernahmen aber nicht.flac ...
Uploading  50% |oooooooooooooooooooo                    |   ETA   --:--:--: done.                                                                                       
JSONValue is not an object
Syncing changes from local path only - NOT syncing data changes from OneDrive ...
Uploading file ./classical/J/Johann Sebastian Bach/Cantata/BWV 175 - Er rufet seinen Schafen mit Namen (Gardiner)/06 - Öffnet euch, ihr beiden Ohren.flac ...
Uploading  33% |oooooooooooooo                          |   ETA   --:--:--: done.                                                                                       
JSONValue is not an object
Syncing changes from local path only - NOT syncing data changes from OneDrive ...
Uploading file ./classical/J/Johann Sebastian Bach/Cantata/BWV 175 - Er rufet seinen Schafen mit Namen (Gardiner)/06 - Öffnet euch, ihr beiden Ohren.flac ...
Uploading  33% |oooooooooooooo                          |   ETA   --:--:--: done.                                                                                       
std.json.JSONException@std/json.d(306): JSONValue is not an object
----------------
/usr/include/dlang/dmd/std/exception.d:515 pure @safe void std.exception.bailOut!(std.json.JSONException).bailOut(immutable(char)[], ulong, scope const(char)[]) [0x99132b27]
/usr/include/dlang/dmd/std/exception.d:436 pure @safe bool std.exception.enforce!(std.json.JSONException).enforce!(bool).enforce(bool, lazy const(char)[], immutable(char)[], ulong) [0x99132aa1]
??:? inout pure @property @trusted inout(std.json.JSONValue[immutable(char)[]]) std.json.JSONValue.objectNoRef() [0x9918e919]
??:? inout pure ref @safe inout(std.json.JSONValue) std.json.JSONValue.opIndex(immutable(char)[]) [0x9918eaf0]
src/sync.d:1384 void sync.SyncEngine.uploadNewFile(immutable(char)[]) [0x9916105c]
src/sync.d:1165 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x991600ee]
src/sync.d:1156 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x9915ffe5]
src/sync.d:1156 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x9915ffe5]
src/sync.d:1156 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x9915ffe5]
src/sync.d:1156 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x9915ffe5]
src/sync.d:1156 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x9915ffe5]
src/sync.d:1156 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x9915ffe5]
src/sync.d:851 void sync.SyncEngine.scanForDifferences(immutable(char)[]) [0x9915ec01]
src/main.d:432 void main.performSync(sync.SyncEngine, immutable(char)[], bool, bool, bool) [0x99141594]
src/main.d:312 _Dmain [0x99140e80]

So that's definitely v2.1.5.* ...and we're back to the three-tries-and-a-bomb-out behaviour from before.

Sorry if I'm doing it wrong.
Regards
HJR

[abraunegg]

No thats perfect ..

Can you now run the exact same command you ran but add '--debug-https' at the end so i can see what is being sent and received by the client as to why it is now failing

[hjrdizwell]

OK. I am now rather confused, because if I issue the command with the --debug-https switch, it does NOT terminate and keeps going fine, apparently managing to upload stuff. If I do it without that switch, it does the three-attempts-and-terminate as you saw above.

Since the "With debug" version doesn't terminate, I can't tell what to upload or what's merely repetition. So I attach the first part of the output and hope that contains clues. Please let me know if the attachment is not legible or is missing stuff you need.
Regards
HJR
debug.txt

[hjrdizwell]

Just by way of follow-up: I terminated the --debug-https version and re-launched the 'ordinary' command:

[hjr@britten ~]$ onedrive --synchronize --upload-only
Initializing the Synchronization Engine ...
Syncing changes from local path only - NOT syncing data changes from OneDrive ...
Uploading file ./classical/J/Johann Sebastian Bach/Cantata/BWV 177 - Ich ruf zu dir, Herr Jesu Christ (Gardiner)/02 - Ich bitt noch mehr, o Herre Gott.flac ...
Uploading  25% |oooooooooo                              |   ETA   --:--:--: done.                                                                                       
JSONValue is not an object
Syncing changes from local path only - NOT syncing data changes from OneDrive ...
Uploading file ./classical/J/Johann Sebastian Bach/Cantata/BWV 177 - Ich ruf zu dir, Herr Jesu Christ (Gardiner)/02 - Ich bitt noch mehr, o Herre Gott.flac ...
Uploading  25% |oooooooooo                              |   ETA   --:--:--: done.                                                                                       
JSONValue is not an object
Syncing changes from local path only - NOT syncing data changes from OneDrive ...
Uploading file ./classical/J/Johann Sebastian Bach/Cantata/BWV 177 - Ich ruf zu dir, Herr Jesu Christ (Gardiner)/02 - Ich bitt noch mehr, o Herre Gott.flac ...
Uploading  25% |oooooooooo                              |   ETA   --:--:--: done.                                                                                       
std.json.JSONException@std/json.d(306): JSONValue is not an object
----------------
/usr/include/dlang/dmd/std/exception.d:515 pure @safe void std.exception.bailOut!(std.json.JSONException).bailOut(immutable(char)[], ulong, scope const(char)[]) [0x7282b27]
/usr/include/dlang/dmd/std/exception.d:436 pure @safe bool std.exception.enforce!(std.json.JSONException).enforce!(bool).enforce(bool, lazy const(char)[], immutable(char)[], ulong) [0x7282aa1]
??:? inout pure @property @trusted inout(std.json.JSONValue[immutable(char)[]]) std.json.JSONValue.objectNoRef() [0x72de919]
??:? inout pure ref @safe inout(std.json.JSONValue) std.json.JSONValue.opIndex(immutable(char)[]) [0x72deaf0]
src/sync.d:1384 void sync.SyncEngine.uploadNewFile(immutable(char)[]) [0x72b105c]
src/sync.d:1165 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x72b00ee]
src/sync.d:1156 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x72affe5]
src/sync.d:1156 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x72affe5]
src/sync.d:1156 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x72affe5]
src/sync.d:1156 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x72affe5]
src/sync.d:1156 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x72affe5]
src/sync.d:1156 void sync.SyncEngine.uploadNewItems(immutable(char)[]) [0x72affe5]
src/sync.d:851 void sync.SyncEngine.scanForDifferences(immutable(char)[]) [0x72aec01]
src/main.d:432 void main.performSync(sync.SyncEngine, immutable(char)[], bool, bool, bool) [0x7291594]
src/main.d:312 _Dmain [0x7290e80]

So, the fact that it is now trying to process BWV177 means the --debug-https switch run did successfully upload some files (because before, we were at BWV 175. So two Bach Canatas got uploaded during the debug run).

Hope that's clear.

[abraunegg]

OK .. I will have to generate a separate PR for you to test.

There is 'zero' reason why, when using --debug-https it works but without it is failing .. as all that flag does is enable the extra curl output you have seen.

[abraunegg]

@hjrdizwell
Can you please test the following PR:

git clone https://github.com/abraunegg/onedrive.git
cd onedrive
git fetch origin pull/233/head:pr233
git checkout pr233
make
make install

When executing the application, please can you use the following:

onedrive --synchronize --upload-only --verbose

This should generate something like the following:

Loading config ...
Using Config Dir: /root/.config/onedrive
No config file found, using defaults
Initializing the OneDrive API ...
Opening the item database ...
All operations will be performed in: /root/OneDrive
Initializing the Synchronization Engine ...
OneDrive HTTP Server Response: 200
OneDrive HTTP Server Response: 200
OneDrive HTTP Server Response: 200
Account Type: personal
Default Drive ID: 66d53be8a5056eca
Default Root ID: 66D53BE8A5056ECA!101
Remaining Free Space: 5368709120
Fetching details for OneDrive Root
OneDrive HTTP Server Response: 200
OneDrive Root exists in the database
Syncing changes from OneDrive ...
Applying changes of Path ID: 66D53BE8A5056ECA!101
OneDrive HTTP Server Response: 200
OneDrive HTTP Server Response: 200
Uploading differences of .
Processing root
The directory has not changed
Uploading new items of .
OneDrive HTTP Server Response: 404
Uploading file ./file.rar ...
OneDrive HTTP Server Response: 200
Uploading  33% |oooooooooooooo                          |   ETA   --:--:--:                                                                                                             
OneDrive HTTP Server Response: 0
Uploading  66% |ooooooooooooooooooooooooooo             |   ETA   00:00:03                                                                                                              
OneDrive HTTP Server Response: 0
OneDrive HTTP Server Response: 0
Uploading 100% |oooooooooooooooooooooooooooooooooooooooo| DONE IN 00:00:11                                                                                                              
 done.
OneDrive HTTP Server Response: 200
Remaining free space: 5352980480
Applying changes of Path ID: 66D53BE8A5056ECA!101
OneDrive HTTP Server Response: 200
OneDrive HTTP Server Response: 200

[hjrdizwell]

Hello again.
Looking good, as follows :

onedrive v2.1.5-4-g4754697
Loading config ...
Using Config Dir: /home/hjr/.config/onedrive
Initializing the OneDrive API ...
Opening the item database ...
All operations will be performed in: /multimedia/flac/hjr
Initializing the Synchronization Engine ...

OneDrive HTTP Server Response: 200

OneDrive HTTP Server Response: 200

OneDrive HTTP Server Response: 200
Account Type: personal
Default Drive ID: 1c73f898dbc646c5
Default Root ID: 1C73F898DBC646C5!101
Remaining Free Space: 557503886999
Fetching details for OneDrive Root

OneDrive HTTP Server Response: 200
OneDrive Root exists in the database
Trying to restore the upload session ...

OneDrive HTTP Server Response: 0
Syncing changes from local path only - NOT syncing data changes from OneDrive ...
Uploading differences of .
Processing root
The directory has not changed
Processing classical
The directory has not changed
Processing J
The directory has not changed
Processing Jacob Obrecht
[etc etc etc... then:]

The file has not changed
Processing 06 - Jagerlied.flac
The file has not changed
Uploading new items of .

OneDrive HTTP Server Response: 404
Uploading file ./classical/J/Johannes Brahms/Chamber/String Quintet No. 2 (Brandis)/01 - Allegro non troppo ma con brio.flac ...

OneDrive HTTP Server Response: 200

                                                                                
Uploading  12% |ooooo                                   |   ETA   --:--:--:
OneDrive HTTP Server Response: 0

                                                                                
Uploading  25% |oooooooooo                              |   ETA   00:00:36 
OneDrive HTTP Server Response: 0

                                                                                
Uploading  37% |ooooooooooooooo                         |   ETA   00:00:38 
OneDrive HTTP Server Response: 0

                                                                                
Uploading  50% |oooooooooooooooooooo                    |   ETA   00:00:34 
OneDrive HTTP Server Response: 0

                                                                                
Uploading  62% |ooooooooooooooooooooooooo               |   ETA   00:00:27 
OneDrive HTTP Server Response: 0

                                                                                
Uploading  75% |oooooooooooooooooooooooooooooo          |   ETA   00:00:18 
OneDrive HTTP Server Response: 0

                                                                                
Uploading  87% |ooooooooooooooooooooooooooooooooooo     |   ETA   00:00:09 
OneDrive HTTP Server Response: 0

OneDrive HTTP Server Response: 0

                                                                                
Uploading 100% |oooooooooooooooooooooooooooooooooooooooo| DONE IN 00:01:15 
 done.

OneDrive HTTP Server Response: 200
Remaining free space: 557433863044

OneDrive HTTP Server Response: 404
Uploading file ./classical/J/Johannes Brahms/Chamber/String Quintet No. 2 (Brandis)/02 - Adagio.flac ...

OneDrive HTTP Server Response: 200

                                                                                
Uploading  25% |oooooooooo                              |   ETA   --:--:--:
OneDrive HTTP Server Response: 0

                                                                                
Uploading  50% |oooooooooooooooooooo                    |   ETA   00:00:11 
OneDrive HTTP Server Response: 0

                                                                                
Uploading  75% |oooooooooooooooooooooooooooooo          |   ETA   00:00:07 
OneDrive HTTP Server Response: 0

                                                                                
Uploading 100% |oooooooooooooooooooooooooooooooooooooooo| DONE IN 00:00:32 
 done.

OneDrive HTTP Server Response: 200
Remaining free space: 557403374416

OneDrive HTTP Server Response: 404
Uploading file ./classical/J/Johannes Brahms/Chamber/String Quintet No. 2 (Brandis)/03 - Un poco allegretto.flac ...

OneDrive HTTP Server Response: 200

                                                                                
Uploading  33% |oooooooooooooo                          |   ETA   --:--:--:
OneDrive HTTP Server Response: 0

                                                                                
Uploading  66% |ooooooooooooooooooooooooooo             |   ETA   00:00:05 
OneDrive HTTP Server Response: 0

                                                                                
Uploading 100% |oooooooooooooooooooooooooooooooooooooooo| DONE IN 00:00:23 
OneDrive HTTP Server Response: 0

OneDrive HTTP Server Response: 0

                                                                                
Uploading 100% |oooooooooooooooooooooooooooooooooooooooo| DONE IN 00:00:26 
 done.

OneDrive HTTP Server Response: 200
Remaining free space: 557379121739

And so on.
Files are uploading successfully once more.
Reagrds
HJR

[hjrdizwell]

And by way of follow-up, here's the command running without the verbose switch:

[hjr@britten onedrive]$ onedrive --synchronize --upload-only
Initializing the Synchronization Engine ...
Syncing changes from local path only - NOT syncing data changes from OneDrive ...
Uploading file ./classical/J/Johannes Brahms/Chamber/String Quintet No. 2 (Melos)/02 - Adagio.flac ...
Uploading 100% |oooooooooooooooooooooooooooooooooooooooo| DONE IN 00:00:34                                                                                              
 done.
Uploading file ./classical/J/Johannes Brahms/Chamber/String Quintet No. 2 (Melos)/03 - Un poco allegretto.flac ...
Uploading 100% |oooooooooooooooooooooooooooooooooooooooo| DONE IN 00:00:27                                                                                              
 done.
Uploading file ./classical/J/Johannes Brahms/Chamber/String Quintet No. 2 (Melos)/04 - Vivace ma non troppo presto.flac ...
Uploading  33% |oooooooooooooo                          |   ETA   --:--:--:                                                                                             

...just in case additional switches alters the code-path at all!
Regards
HJR

[abraunegg]

@hjrdizwell
Thanks - so this PR resolves your issues. Will merge into master.

[abraunegg]

PR #233 merged

[hjrdizwell]

Sorry to re-open this (and if it's not actually related, I'm happy to open another ticket), but a freshly-installed onedrive is now misbehaving as follows.

Versions:

[hjr@britten ~]$ uname -a
Linux britten 4.19.1-1-MANJARO #1 SMP PREEMPT Sun Nov 4 16:05:34 UTC 2018 x86_64 GNU/Linux

[hjr@britten ~]$ onedrive --version
onedrive v2.1.6

[hjr@britten ~]$ curl --version
curl 7.62.0 (x86_64-pc-linux-gnu) libcurl/7.62.0 OpenSSL/1.1.1 zlib/1.2.11 libidn2/2.0.5 libpsl/0.20.2 (+libidn2/2.0.4) libssh2/1.8.0 nghttp2/1.34.0
Release-Date: 2018-10-31
Protocols: dict file ftp ftps gopher http https imap imaps pop3 pop3s rtsp scp sftp smb smbs smtp smtps telnet tftp 
Features: AsynchDNS IDN IPv6 Largefile GSS-API Kerberos SPNEGO NTLM NTLM_WB SSL libz TLS-SRP HTTP2 UnixSockets HTTPS-proxy PSL 

And using the command: onedrive --synchronize --upload-only --verbose

I get...

The file has not changed
Processing 03 - Denk es, o Seele!.flac
The file has not changed
Processing 04 - Heimweh.flac
The file has not changed
Processing 05 - Bei einer Trauung.flac
The file has not changed
Processing 06 - Jagerlied.flac
The file has not changed
Uploading new items of .
Uploading file ./classical/J/Johannes Brahms/Chamber/Viola Sonata No. 1 (Imai)/00 - Allegro appassionato.flac ...
Uploading  25% |oooooooooo                              |   ETA   --:--:--:[hjr@britten ~]$        

Not sure if it's clear from that, but basically it just kills the connection at the 25% of that file and dumps me back at the command line (without putting in a line break, so the terminal prompt ends up displaying at the end of the broken progress indicator). It 'broke' in exactly the same spot multiple times.

So I manually uploaded the Viola Sonata in question, via the OneDrive website in Firefox, and tried again:

...Processing 05 - Bei einer Trauung.flac
The file has not changed
Processing 06 - Jagerlied.flac
The file has not changed
Uploading new items of .
Requested file to upload exists on OneDrive - local database is out of sync for this file: ./classical/J/Johannes Brahms/Chamber/Viola Sonata No. 1 (Imai)/00 - Allegro appassionato.flac
Updating the local database with details for this file: ./classical/J/Johannes Brahms/Chamber/Viola Sonata No. 1 (Imai)/00 - Allegro appassionato.flac
Remaining free space: 556311483666
Requested file to upload exists on OneDrive - local database is out of sync for this file: ./classical/J/Johannes Brahms/Chamber/Viola Sonata No. 1 (Imai)/00 - Andante un poco adagio.flac
Updating the local database with details for this file: ./classical/J/Johannes Brahms/Chamber/Viola Sonata No. 1 (Imai)/00 - Andante un poco adagio.flac
Remaining free space: 556292965350
Requested file to upload exists on OneDrive - local database is out of sync for this file: ./classical/J/Johannes Brahms/Chamber/Viola Sonata No. 1 (Imai)/00 - Vivace.flac
Updating the local database with details for this file: ./classical/J/Johannes Brahms/Chamber/Viola Sonata No. 1 (Imai)/00 - Vivace.flac
Remaining free space: 556272548809
OneDrive Client requested to create remote path: ./classical/J/Johannes Brahms/Chamber/Viola Sonata No. 2 (Imai)
The requested directory to create was not found on OneDrive - creating remote directory: ./classical/J/Johannes Brahms/Chamber/Viola Sonata No. 2 (Imai)
Successfully created the remote directory ./classical/J/Johannes Brahms/Chamber/Viola Sonata No. 2 (Imai) on OneDrive
[hjr@britten ~]$ 

This time, it correctly notes that the Viola Sonata No. 1 is now present in the cloud, so updates the local database to reflect that and goes on to process Viola Sonata No. 2. It also correctly creates the directory... but then just stops, dropping me back to the command line. It never actually starts uploading files there.

A third attempt:

The file has not changed
Processing 06 - Jagerlied.flac
The file has not changed
Uploading new items of .
Uploading file ./classical/J/Johannes Brahms/Chamber/Viola Sonata No. 2 (Imai)/00 - Allegro amabile.flac ...
Uploading  25% |oooooooooo                              |   ETA   --:--:--:[hjr@britten ~]$              

So now it's doing the 'break at 25%' trick again, on a new file. Rinse and repeat, basically.

I therefore did:

[hjr@britten ~]$ onedrive --synchronize --upload-only --debug-https
Initializing the Synchronization Engine ...
*   Trying 40.112.64.18...
* TCP_NODELAY set
* Connected to login.microsoftonline.com (40.112.64.18) port 443 (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* successfully set certificate verify locations:
*   CAfile: /etc/ssl/certs/ca-certificates.crt
  CApath: none
* SSL connection using TLSv1.2 / ECDHE-RSA-AES256-GCM-SHA384
* ALPN, server did not agree to a protocol
* Server certificate:
*  subject: CN=stamp2.login.microsoftonline.com
*  start date: Sep 24 21:35:29 2018 GMT
*  expire date: Sep 24 21:35:29 2020 GMT
*  subjectAltName: host "login.microsoftonline.com" matched cert's "login.microsoftonline.com"
*  issuer: C=US; ST=Washington; L=Redmond; O=Microsoft Corporation; OU=Microsoft IT; CN=Microsoft IT TLS CA 1
*  SSL certificate verify ok.
> POST /common/oauth2/v2.0/token HTTP/1.1
Host: login.microsoftonline.com
User-Agent: Phobos-std.net.curl/2.083 (libcurl/7.62.0)
Accept: */*
Content-Length: 549
Content-Type: application/x-www-form-urlencoded

* We are completely uploaded and fine
< HTTP/1.1 200 OK
< Cache-Control: no-cache, no-store
< Pragma: no-cache
< Content-Type: application/json; charset=utf-8
< Expires: -1
< Server: Microsoft-IIS/10.0
< Strict-Transport-Security: max-age=31536000; includeSubDomains
< X-Content-Type-Options: nosniff
< x-ms-request-id: cc5268b2-1f4f-4ffb-8a5d-181a93825300
< P3P: CP="DSP CUR OTPi IND OTRi ONL FIN"
< Set-Cookie: fpc=AdXK--pOo_JLm8LlesWhgM7UNSDqAQDA463qAkvWCA; expires=Sat, 15-Dec-2018 14:02:02 GMT; path=/; secure; HttpOnly
< Set-Cookie: x-ms-gateway-slice=017; path=/; secure; HttpOnly
< Set-Cookie: stsservicecookie=ests; path=/; secure; HttpOnly
< Date: Thu, 15 Nov 2018 14:02:02 GMT
< Content-Length: 1699
< 
* Connection #0 to host login.microsoftonline.com left intact
*   Trying 20.190.143.49...
* TCP_NODELAY set
* Connected to graph.microsoft.com (20.190.143.49) port 443 (#1)
* ALPN, offering h2
* ALPN, offering http/1.1
* successfully set certificate verify locations:
*   CAfile: /etc/ssl/certs/ca-certificates.crt
  CApath: none
* SSL connection using TLSv1.2 / ECDHE-RSA-AES256-GCM-SHA384
* ALPN, server did not agree to a protocol
* Server certificate:
*  subject: CN=graph.microsoft.com
*  start date: Oct 21 03:32:19 2018 GMT
*  expire date: Oct 21 03:32:19 2020 GMT
*  subjectAltName: host "graph.microsoft.com" matched cert's "graph.microsoft.com"
*  issuer: C=US; ST=Washington; L=Redmond; O=Microsoft Corporation; OU=Microsoft IT; CN=Microsoft IT TLS CA 1
*  SSL certificate verify ok.
> GET /v1.0/me/drive HTTP/1.1
Host: graph.microsoft.com
User-Agent: Phobos-std.net.curl/2.083 (libcurl/7.62.0)
Accept: */*
Authorization: bearer EwBoA8l6BAAURSN/FHlDW5xN74t6GzbtsBBeBUYAAbzJkFIt4QvpLVyCu2GpXlpQ1j/R1WXgzRsVqZP/oudgxAY4Psk/drajNtpUQQaHBrhsiLhqmZQE5/lnKA3fzAfy7kBByjegYzrYuV7vxN5lJZltY6Mit/n8S1BWyk0X6VhCnhquT8V3cbNqhPYBSORr/EziCcV6pa6DN4l3zN6ebDKPVKgejjhTplKmZI1BY26k2XhP1KKSKHFIDF2FOuSkuyXdrDEYLuQBXlc0Hq3pZEmvmPGvyDv6CkderEe5EvCB1wFTDp8A+4IRFrRCzzblbtzInAnLZWAW9ORvVbJgarP9hgckwvW/saKUWnwBT6NNZkxvFD89WEH6/WQI3zcDZgAACH4bX/orNR5COAJzIbuZVPs+0sDRihLNU2g/9akYXdn9rYQgKA7WE8mYXvfE4j8R662/dO3XMC33NbykOU8NZQ5m+EiPTxzW0CbGPhlYNWs+mmPKBOP4HWtCfXvf+CVSU9a7LM/0gEy0WstkCnNl1cSkrLF3drkJEJ4/tLFaKy3SqbfBeF021OTxsMpVl2WvnN/nwWW2D655B7QvoKAb5BVEXpfi6emcuAGc8dsZd6WKLcM9DJFG4WmQRZJYVnQDBJKlLw2fRcUMZciLGf/xXZ3+M+3fvNPZOUONwQ/L8AT67QLkwSi6kNa0dCcW3GEE0cSdpuOy0qgFZJJ8Hnq4tjUeCcxRZCP9mGNTwHeFvmRWomGmeVCOmw51SfAuaYiltTN7nLjoLe+CKcwb1JWwAOLmm6oiwWVUOeZCTC2QlFeyXp4FyvjSDSHN70ABORfpKoP/PvWeJnlad0GRkExjwc2bToLlivjIMl7btxFtmBjg1LbmvQf35AU31CviTkqcQQLX0YJ7eZrRuHpv6wHFUKTld5JAo2MxiIxizBhBtO7LNGknfDiph4cuZdLIokvO2sKqU/22AWk27Q1SiRWClJWjgmM4CI6eJAld2JpMKxwfOzfxRNSJWG++SkUewHKmtPIQjZ2b8Vuc5YF62b9uT/rFAbusH3Vzp6p3B4cCe/J+m93wGYO5biTrQpILF5oN9z28H3Bloh8zreGnh8NIVdvoTRy0vbbYcTpUqt22ohbOOyuyjrK6vCHbsRlcc224978dbwI=

< HTTP/1.1 200 OK
< Cache-Control: private
< Transfer-Encoding: chunked
< Content-Type: application/json;odata.metadata=minimal;odata.streaming=true;IEEE754Compatible=false;charset=utf-8
< request-id: 25f1f88f-213b-407b-90ff-2f4444fdaf82
< client-request-id: 25f1f88f-213b-407b-90ff-2f4444fdaf82
< x-ms-ags-diagnostic: {"ServerInfo":{"DataCenter":"UK South","Slice":"SliceC","Ring":"4","ScaleUnit":"000","Host":"AGSFE_IN_10","ADSiteName":"UKS"}}
< OData-Version: 4.0
< Duration: 121.229
< Strict-Transport-Security: max-age=31536000
< Date: Thu, 15 Nov 2018 14:02:02 GMT
< 
* Connection #1 to host graph.microsoft.com left intact
* Found bundle for host graph.microsoft.com: 0x55c9f0600a10 [can pipeline]
* Could pipeline, but not asked to!
* Re-using existing connection! (#1) with host graph.microsoft.com
* Connected to graph.microsoft.com (20.190.143.49) port 443 (#1)
> GET /v1.0/me/drive/root HTTP/1.1
Host: graph.microsoft.com
User-Agent: Phobos-std.net.curl/2.083 (libcurl/7.62.0)
Accept: */*
Authorization: bearer EwBoA8l6BAAURSN/FHlDW5xN74t6GzbtsBBeBUYAAbzJkFIt4QvpLVyCu2GpXlpQ1j/R1WXgzRsVqZP/oudgxAY4Psk/drajNtpUQQaHBrhsiLhqmZQE5/lnKA3fzAfy7kBByjegYzrYuV7vxN5lJZltY6Mit/n8S1BWyk0X6VhCnhquT8V3cbNqhPYBSORr/EziCcV6pa6DN4l3zN6ebDKPVKgejjhTplKmZI1BY26k2XhP1KKSKHFIDF2FOuSkuyXdrDEYLuQBXlc0Hq3pZEmvmPGvyDv6CkderEe5EvCB1wFTDp8A+4IRFrRCzzblbtzInAnLZWAW9ORvVbJgarP9hgckwvW/saKUWnwBT6NNZkxvFD89WEH6/WQI3zcDZgAACH4bX/orNR5COAJzIbuZVPs+0sDRihLNU2g/9akYXdn9rYQgKA7WE8mYXvfE4j8R662/dO3XMC33NbykOU8NZQ5m+EiPTxzW0CbGPhlYNWs+mmPKBOP4HWtCfXvf+CVSU9a7LM/0gEy0WstkCnNl1cSkrLF3drkJEJ4/tLFaKy3SqbfBeF021OTxsMpVl2WvnN/nwWW2D655B7QvoKAb5BVEXpfi6emcuAGc8dsZd6WKLcM9DJFG4WmQRZJYVnQDBJKlLw2fRcUMZciLGf/xXZ3+M+3fvNPZOUONwQ/L8AT67QLkwSi6kNa0dCcW3GEE0cSdpuOy0qgFZJJ8Hnq4tjUeCcxRZCP9mGNTwHeFvmRWomGmeVCOmw51SfAuaYiltTN7nLjoLe+CKcwb1JWwAOLmm6oiwWVUOeZCTC2QlFeyXp4FyvjSDSHN70ABORfpKoP/PvWeJnlad0GRkExjwc2bToLlivjIMl7btxFtmBjg1LbmvQf35AU31CviTkqcQQLX0YJ7eZrRuHpv6wHFUKTld5JAo2MxiIxizBhBtO7LNGknfDiph4cuZdLIokvO2sKqU/22AWk27Q1SiRWClJWjgmM4CI6eJAld2JpMKxwfOzfxRNSJWG++SkUewHKmtPIQjZ2b8Vuc5YF62b9uT/rFAbusH3Vzp6p3B4cCe/J+m93wGYO5biTrQpILF5oN9z28H3Bloh8zreGnh8NIVdvoTRy0vbbYcTpUqt22ohbOOyuyjrK6vCHbsRlcc224978dbwI=

< HTTP/1.1 200 OK
< Cache-Control: private
< Transfer-Encoding: chunked
< Content-Type: application/json;odata.metadata=minimal;odata.streaming=true;IEEE754Compatible=false;charset=utf-8
< request-id: c023ce9a-b0c6-4f4d-9c62-d01ae198a90f
< client-request-id: c023ce9a-b0c6-4f4d-9c62-d01ae198a90f
< x-ms-ags-diagnostic: {"ServerInfo":{"DataCenter":"UK South","Slice":"SliceC","Ring":"4","ScaleUnit":"000","Host":"AGSFE_IN_10","ADSiteName":"UKS"}}
< OData-Version: 4.0
< Duration: 75.1446
< Strict-Transport-Security: max-age=31536000
< Date: Thu, 15 Nov 2018 14:02:02 GMT
< 
* Connection #1 to host graph.microsoft.com left intact
* Found bundle for host graph.microsoft.com: 0x55c9f0600a10 [can pipeline]
* Could pipeline, but not asked to!
* Re-using existing connection! (#1) with host graph.microsoft.com
* Connected to graph.microsoft.com (20.190.143.49) port 443 (#1)
> GET /v1.0/me/drive/root HTTP/1.1
Host: graph.microsoft.com
User-Agent: Phobos-std.net.curl/2.083 (libcurl/7.62.0)
Accept: */*
Authorization: bearer EwBoA8l6BAAURSN/FHlDW5xN74t6GzbtsBBeBUYAAbzJkFIt4QvpLVyCu2GpXlpQ1j/R1WXgzRsVqZP/oudgxAY4Psk/drajNtpUQQaHBrhsiLhqmZQE5/lnKA3fzAfy7kBByjegYzrYuV7vxN5lJZltY6Mit/n8S1BWyk0X6VhCnhquT8V3cbNqhPYBSORr/EziCcV6pa6DN4l3zN6ebDKPVKgejjhTplKmZI1BY26k2XhP1KKSKHFIDF2FOuSkuyXdrDEYLuQBXlc0Hq3pZEmvmPGvyDv6CkderEe5EvCB1wFTDp8A+4IRFrRCzzblbtzInAnLZWAW9ORvVbJgarP9hgckwvW/saKUWnwBT6NNZkxvFD89WEH6/WQI3zcDZgAACH4bX/orNR5COAJzIbuZVPs+0sDRihLNU2g/9akYXdn9rYQgKA7WE8mYXvfE4j8R662/dO3XMC33NbykOU8NZQ5m+EiPTxzW0CbGPhlYNWs+mmPKBOP4HWtCfXvf+CVSU9a7LM/0gEy0WstkCnNl1cSkrLF3drkJEJ4/tLFaKy3SqbfBeF021OTxsMpVl2WvnN/nwWW2D655B7QvoKAb5BVEXpfi6emcuAGc8dsZd6WKLcM9DJFG4WmQRZJYVnQDBJKlLw2fRcUMZciLGf/xXZ3+M+3fvNPZOUONwQ/L8AT67QLkwSi6kNa0dCcW3GEE0cSdpuOy0qgFZJJ8Hnq4tjUeCcxRZCP9mGNTwHeFvmRWomGmeVCOmw51SfAuaYiltTN7nLjoLe+CKcwb1JWwAOLmm6oiwWVUOeZCTC2QlFeyXp4FyvjSDSHN70ABORfpKoP/PvWeJnlad0GRkExjwc2bToLlivjIMl7btxFtmBjg1LbmvQf35AU31CviTkqcQQLX0YJ7eZrRuHpv6wHFUKTld5JAo2MxiIxizBhBtO7LNGknfDiph4cuZdLIokvO2sKqU/22AWk27Q1SiRWClJWjgmM4CI6eJAld2JpMKxwfOzfxRNSJWG++SkUewHKmtPIQjZ2b8Vuc5YF62b9uT/rFAbusH3Vzp6p3B4cCe/J+m93wGYO5biTrQpILF5oN9z28H3Bloh8zreGnh8NIVdvoTRy0vbbYcTpUqt22ohbOOyuyjrK6vCHbsRlcc224978dbwI=

< HTTP/1.1 200 OK
< Cache-Control: private
< Transfer-Encoding: chunked
< Content-Type: application/json;odata.metadata=minimal;odata.streaming=true;IEEE754Compatible=false;charset=utf-8
< request-id: 7db5f52b-ad41-4d9a-838e-e156f537b8c3
< client-request-id: 7db5f52b-ad41-4d9a-838e-e156f537b8c3
< x-ms-ags-diagnostic: {"ServerInfo":{"DataCenter":"UK South","Slice":"SliceC","Ring":"4","ScaleUnit":"000","Host":"AGSFE_IN_10","ADSiteName":"UKS"}}
< OData-Version: 4.0
< Duration: 79.4925
< Strict-Transport-Security: max-age=31536000
< Date: Thu, 15 Nov 2018 14:02:02 GMT
< 
* Connection #1 to host graph.microsoft.com left intact
*   Trying 204.79.197.213...
* TCP_NODELAY set
* Connected to api.onedrive.com (204.79.197.213) port 443 (#2)
* ALPN, offering h2
* ALPN, offering http/1.1
* successfully set certificate verify locations:
*   CAfile: /etc/ssl/certs/ca-certificates.crt
  CApath: none
* SSL connection using TLSv1.2 / ECDHE-RSA-AES128-GCM-SHA256
* ALPN, server accepted to use h2
* Server certificate:
*  subject: C=US; ST=WA; L=Redmond; O=Microsoft Corporation; OU=Microsoft Corporation; CN=storage.live.com
*  start date: Oct 19 22:20:20 2017 GMT
*  expire date: Oct 19 22:20:20 2019 GMT
*  subjectAltName: host "api.onedrive.com" matched cert's "*.onedrive.com"
*  issuer: C=US; ST=Washington; L=Redmond; O=Microsoft Corporation; OU=Microsoft IT; CN=Microsoft IT TLS CA 5
*  SSL certificate verify ok.
* Using HTTP2, server supports multi-use
* Connection state changed (HTTP/2 confirmed)
* Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0
* Using Stream ID: 1 (easy handle 0x55c9f05ed800)
> GET /rup/1c73f898dbc646c5/eyJSZXNvdXJjZUlEIjoiMUM3M0Y4OThEQkM2NDZDNSExMTE2NDkiLCJSZWxhdGlvbnNoaXBOYW1lIjoiMDAgLSBBbGxlZ3JvIGFtYWJpbGUuZmxhYyJ9/4mTFJ6gMHnbNPRaeq7iFvQDMmQhM5V6uTQVPxvBiWCzMNQuUazvBAtrucLPG12qhggOFl5Ap3dPh9y6WzEw6q18H80hRNhYvNO8b3dO54Jz1Q/eyJAbmFtZS5jb25mbGljdEJlaGF2aW9yIjoicmVwbGFjZSIsIk5hbWUiOiIwMCAtIEFsbGVncm8gYW1hYmlsZS5mbGFjIiwiRmlsZVN5c3RlbUluZm8iOnsiTGFzdE1vZGlmaWVkRGF0ZVRpbWUiOiIyMDE2LTA4LTMxVDA1OjU5OjQ4KzAwOjAwIn19/4wO2496038q7A1wv4OtdZZJ_yVWr29zQH9F4UVWo6RQRTk1qtn_3WoP_gER4O2VtTTV3KP0iMRE2nFpwk10LOQYOaIZON_uRWs9UX7J1fSYFnlrTLx-aAzIpIyFXp7MA5R2qco0-3CdZepT1MIy4X-wCceOKMo6vviz-WhiXN2Xv8035QVLg0hObswpENqBzpOZp8ynwwFZ_3bD2EskMIA2ypnRL_qoTUMfdqZ92bTlzXTwXYkZJgHh7ietaMs98_7bmXQcv1lD04U7-jtx7-FZnjgJukLff330viDNpggz7C0mwKA_-8Utnt4uZRtUapvnVgpeUedarke4P2HX-iAvLysUw8hBv3oBy96IdXKLsOlUFjQYSxZjVVkVlVmEVfjnveXdXN2Zut9akvl6RGQU7n4LLfG5GcjnyKcflMUQk95mhMfEcJMF-H1g-0XkgcxcW5uKcOQfPk3NjwhSQdBwIL4yDGJyGvnHulCrPpyY9d458Bsnm7Xj61T-UAJG5AShaGDaAzbkYVO5EFOcstePc-kqk7kelhfdCULW7cxzAXKKVaHu0ovUGrxiAadzcNB HTTP/2
Host: api.onedrive.com
User-Agent: Phobos-std.net.curl/2.083 (libcurl/7.62.0)
Accept: */*

* Connection state changed (MAX_CONCURRENT_STREAMS == 100)!
< HTTP/2 200 
< content-length: 77
< content-type: application/json; charset=utf-8
< p3p: CP="BUS CUR CONo FIN IVDo ONL OUR PHY SAMo TELo"
< x-msnserver: AM3PPF594573044
< strict-transport-security: max-age=31536000; includeSubDomains
< x-asmversion: UNKNOWN; 19.153.1107.2003
< x-msedge-ref: Ref A: 6FEAB3BCAD7E48A38BE0CB5CAC217CF7 Ref B: LON04EDGE0213 Ref C: 2018-11-15T14:02:03Z
< date: Thu, 15 Nov 2018 14:02:03 GMT
< 
* Connection #2 to host api.onedrive.com left intact
Syncing changes from local path only - NOT syncing data changes from OneDrive ...
* Connection 1 seems to be dead!
* Closing connection 1
* Connection 0 seems to be dead!
* Closing connection 0
* 9 bytes stray data read before trying h2 connection
* Hostname graph.microsoft.com was found in DNS cache
*   Trying 20.190.143.49...
* TCP_NODELAY set
* Connected to graph.microsoft.com (20.190.143.49) port 443 (#3)
* ALPN, offering h2
* ALPN, offering http/1.1
* successfully set certificate verify locations:
*   CAfile: /etc/ssl/certs/ca-certificates.crt
  CApath: none
* SSL re-using session ID
* SSL connection using TLSv1.2 / ECDHE-RSA-AES256-GCM-SHA384
* ALPN, server did not agree to a protocol
* old SSL session ID is stale, removing
* Server certificate:
*  subject: CN=graph.microsoft.com
*  start date: Oct 21 03:32:19 2018 GMT
*  expire date: Oct 21 03:32:19 2020 GMT
*  subjectAltName: host "graph.microsoft.com" matched cert's "graph.microsoft.com"
*  issuer: C=US; ST=Washington; L=Redmond; O=Microsoft Corporation; OU=Microsoft IT; CN=Microsoft IT TLS CA 1
*  SSL certificate verify ok.
> GET /v1.0/me/drive/root:/.%2Fclassical%2FJ%2FJohannes%20Brahms%2FChamber%2FViola%20Sonata%20No.%202%20(Imai)%2F00%20-%20Allegro%20amabile.flac:/?select=id,name,eTag,cTag,deleted,file,folder,root,fileSystemInfo,remoteItem,parentReference HTTP/1.1
Host: graph.microsoft.com
User-Agent: Phobos-std.net.curl/2.083 (libcurl/7.62.0)
Accept: */*
Authorization: bearer EwBoA8l6BAAURSN/FHlDW5xN74t6GzbtsBBeBUYAAbzJkFIt4QvpLVyCu2GpXlpQ1j/R1WXgzRsVqZP/oudgxAY4Psk/drajNtpUQQaHBrhsiLhqmZQE5/lnKA3fzAfy7kBByjegYzrYuV7vxN5lJZltY6Mit/n8S1BWyk0X6VhCnhquT8V3cbNqhPYBSORr/EziCcV6pa6DN4l3zN6ebDKPVKgejjhTplKmZI1BY26k2XhP1KKSKHFIDF2FOuSkuyXdrDEYLuQBXlc0Hq3pZEmvmPGvyDv6CkderEe5EvCB1wFTDp8A+4IRFrRCzzblbtzInAnLZWAW9ORvVbJgarP9hgckwvW/saKUWnwBT6NNZkxvFD89WEH6/WQI3zcDZgAACH4bX/orNR5COAJzIbuZVPs+0sDRihLNU2g/9akYXdn9rYQgKA7WE8mYXvfE4j8R662/dO3XMC33NbykOU8NZQ5m+EiPTxzW0CbGPhlYNWs+mmPKBOP4HWtCfXvf+CVSU9a7LM/0gEy0WstkCnNl1cSkrLF3drkJEJ4/tLFaKy3SqbfBeF021OTxsMpVl2WvnN/nwWW2D655B7QvoKAb5BVEXpfi6emcuAGc8dsZd6WKLcM9DJFG4WmQRZJYVnQDBJKlLw2fRcUMZciLGf/xXZ3+M+3fvNPZOUONwQ/L8AT67QLkwSi6kNa0dCcW3GEE0cSdpuOy0qgFZJJ8Hnq4tjUeCcxRZCP9mGNTwHeFvmRWomGmeVCOmw51SfAuaYiltTN7nLjoLe+CKcwb1JWwAOLmm6oiwWVUOeZCTC2QlFeyXp4FyvjSDSHN70ABORfpKoP/PvWeJnlad0GRkExjwc2bToLlivjIMl7btxFtmBjg1LbmvQf35AU31CviTkqcQQLX0YJ7eZrRuHpv6wHFUKTld5JAo2MxiIxizBhBtO7LNGknfDiph4cuZdLIokvO2sKqU/22AWk27Q1SiRWClJWjgmM4CI6eJAld2JpMKxwfOzfxRNSJWG++SkUewHKmtPIQjZ2b8Vuc5YF62b9uT/rFAbusH3Vzp6p3B4cCe/J+m93wGYO5biTrQpILF5oN9z28H3Bloh8zreGnh8NIVdvoTRy0vbbYcTpUqt22ohbOOyuyjrK6vCHbsRlcc224978dbwI=

< HTTP/1.1 404 Not Found
< Cache-Control: private
< Transfer-Encoding: chunked
< Content-Type: application/json
< request-id: c3c16183-4ac0-41e6-83ad-98b44b02b425
< client-request-id: c3c16183-4ac0-41e6-83ad-98b44b02b425
< x-ms-ags-diagnostic: {"ServerInfo":{"DataCenter":"UK South","Slice":"SliceC","Ring":"4","ScaleUnit":"000","Host":"AGSFE_IN_5","ADSiteName":"UKS"}}
< Duration: 176.6129
< Strict-Transport-Security: max-age=31536000
< Date: Thu, 15 Nov 2018 14:04:28 GMT
< 
* Connection #3 to host graph.microsoft.com left intact
Uploading file ./classical/J/Johannes Brahms/Chamber/Viola Sonata No. 2 (Imai)/00 - Allegro amabile.flac ...
* Found bundle for host graph.microsoft.com: 0x55c9f0a36270 [can pipeline]
* Could pipeline, but not asked to!
* Re-using existing connection! (#3) with host graph.microsoft.com
* Connected to graph.microsoft.com (20.190.143.49) port 443 (#3)
> POST /v1.0/drives/1c73f898dbc646c5/items/1C73F898DBC646C5!111649:/00%20-%20Allegro%20amabile.flac:/createUploadSession HTTP/1.1
Host: graph.microsoft.com
User-Agent: Phobos-std.net.curl/2.083 (libcurl/7.62.0)
Accept: */*
Content-Type: application/json
Authorization: bearer EwBoA8l6BAAURSN/FHlDW5xN74t6GzbtsBBeBUYAAbzJkFIt4QvpLVyCu2GpXlpQ1j/R1WXgzRsVqZP/oudgxAY4Psk/drajNtpUQQaHBrhsiLhqmZQE5/lnKA3fzAfy7kBByjegYzrYuV7vxN5lJZltY6Mit/n8S1BWyk0X6VhCnhquT8V3cbNqhPYBSORr/EziCcV6pa6DN4l3zN6ebDKPVKgejjhTplKmZI1BY26k2XhP1KKSKHFIDF2FOuSkuyXdrDEYLuQBXlc0Hq3pZEmvmPGvyDv6CkderEe5EvCB1wFTDp8A+4IRFrRCzzblbtzInAnLZWAW9ORvVbJgarP9hgckwvW/saKUWnwBT6NNZkxvFD89WEH6/WQI3zcDZgAACH4bX/orNR5COAJzIbuZVPs+0sDRihLNU2g/9akYXdn9rYQgKA7WE8mYXvfE4j8R662/dO3XMC33NbykOU8NZQ5m+EiPTxzW0CbGPhlYNWs+mmPKBOP4HWtCfXvf+CVSU9a7LM/0gEy0WstkCnNl1cSkrLF3drkJEJ4/tLFaKy3SqbfBeF021OTxsMpVl2WvnN/nwWW2D655B7QvoKAb5BVEXpfi6emcuAGc8dsZd6WKLcM9DJFG4WmQRZJYVnQDBJKlLw2fRcUMZciLGf/xXZ3+M+3fvNPZOUONwQ/L8AT67QLkwSi6kNa0dCcW3GEE0cSdpuOy0qgFZJJ8Hnq4tjUeCcxRZCP9mGNTwHeFvmRWomGmeVCOmw51SfAuaYiltTN7nLjoLe+CKcwb1JWwAOLmm6oiwWVUOeZCTC2QlFeyXp4FyvjSDSHN70ABORfpKoP/PvWeJnlad0GRkExjwc2bToLlivjIMl7btxFtmBjg1LbmvQf35AU31CviTkqcQQLX0YJ7eZrRuHpv6wHFUKTld5JAo2MxiIxizBhBtO7LNGknfDiph4cuZdLIokvO2sKqU/22AWk27Q1SiRWClJWjgmM4CI6eJAld2JpMKxwfOzfxRNSJWG++SkUewHKmtPIQjZ2b8Vuc5YF62b9uT/rFAbusH3Vzp6p3B4cCe/J+m93wGYO5biTrQpILF5oN9z28H3Bloh8zreGnh8NIVdvoTRy0vbbYcTpUqt22ohbOOyuyjrK6vCHbsRlcc224978dbwI=
Content-Length: 110

* We are completely uploaded and fine
< HTTP/1.1 200 OK
< Cache-Control: private
< Transfer-Encoding: chunked
< Content-Type: application/json;odata.metadata=minimal;odata.streaming=true;IEEE754Compatible=false;charset=utf-8
< Location: https://graph.microsoft.com
< request-id: 87441a47-0053-4440-8ab0-c23a11c81bef
< client-request-id: 87441a47-0053-4440-8ab0-c23a11c81bef
< x-ms-ags-diagnostic: {"ServerInfo":{"DataCenter":"UK South","Slice":"SliceC","Ring":"4","ScaleUnit":"000","Host":"AGSFE_IN_5","ADSiteName":"UKS"}}
< OData-Version: 4.0
< Duration: 427.8649
< Strict-Transport-Security: max-age=31536000
< Date: Thu, 15 Nov 2018 14:04:28 GMT
< 
* Connection #3 to host graph.microsoft.com left intact
Uploading  25% |oooooooooo                              |   ETA   --:--:--:* Found bundle for host api.onedrive.com: 0x55c9f0761910 [can multiplex]                       
* Connection 2 seems to be dead!
* Closing connection 2

...but I'm afraid I can't see anything in that lot which might give me a clue as to what's going wrong, other than it appearing to think connections are dead (the Internet generally is fine here).

Any chance of taking a look please? It was working fine before you merged the changes back into the main release :-(

Happy to provide further info on request, of course.

Regards
HJR

[abraunegg]

@hjrdizwell
Please open a new case for this - will have to look why the response debugging is not correctly working as well

[abraunegg]

@hjrdizwell
When creating a new case, please provide the logs using the 2 following commands:

Command 1:

onedrive --synchronize --upload-only --verbose

Command 2:

onedrive --synchronize --upload-only --verbose --debug-https

All your other logs above are missing the --verbose flag which means some important details are not being printed out when using --debug-https

[abraunegg]

@hjrdizwell
Can you provide an update? Do you still have this issue? Will you be opening a new case?

[hjrdizwell]

I'm afraid not. With 900GB of files to upload, I can't afford yet more days of no reliable upload. So I've stopped trying to get my Manjaro desktop to upload and have instead installed the software on my CentOS 7.5 file server, where it is uploading happily (though, curiously, whereas on Manjaro files were being uploaded in alphabetical order, on CentOS, the order of upload is entirely random! Never mind: so long as the files get there eventually, I don't care what order they go in!)

Thanks again for all you did to try getting it working on Manjaro, at least.

[Zaporozhec7]

@abraunegg I have same error with version v2.2.4-5-g1fa7e5f

Here is output:

$ onedrive --synchronize --upload-only --no-remote-delete --verbose
Loading config ...
Using Config Dir: /home/stanislav/.config/onedrive
Initializing the OneDrive API ...
Opening the item database ...
All operations will be performed in: /mnt/sdb/stanislav/CLOUD_SYNC_IMPORTANT_FILES
Initializing the Synchronization Engine ...
Account Type: personal
Default Drive ID: 740cd9a1845fc965
Default Root ID: 740CD9A1845FC965!101
Remaining Free Space: 1052596111932
Fetching details for OneDrive Root
OneDrive Root exists in the database
Trying to restore the upload session ...
Continuing the upload session ...
Uploading   0% |o                                       |   ETA   --:--:--:std.json.JSONException@std/json.d(278): JSONValue is not an object                                                                      
----------------
/root/dlang/dmd-2.084.0/linux/bin64/../../src/phobos/std/exception.d:515 pure @safe void std.exception.bailOut!(std.json.JSONException).bailOut(immutable(char)[], ulong, scope const(char)[]) [0x94fb7e67]
/root/dlang/dmd-2.084.0/linux/bin64/../../src/phobos/std/exception.d:436 pure @safe bool std.exception.enforce!(std.json.JSONException).enforce!(bool).enforce(bool, lazy const(char)[], immutable(char)[], ulong) [0x94fb7de1]
??:? inout pure ref @property inout(std.json.JSONValue[immutable(char)[]]) std.json.JSONValue.object() [0x9501968d]
src/sync.d:1703 void sync.SyncEngine.saveItem(std.json.JSONValue) [0x94ff068b]
src/sync.d:262 void sync.SyncEngine.init() [0x94fea323]
src/main.d:583 bool main.initSyncEngine(sync.SyncEngine) [0x94fc88ec]
src/main.d:398 _Dmain [0x94fc7d04]

[abraunegg]

@Zaporozhec7
Please open a new case - do not post on an older issue that has been closed.