Big files do not sync - chunks do not sum up #7020

kerlerm · 2019-02-08T14:37:48Z

Expected behaviour

Big files should sync.

Actual behaviour

Bigger files do not sync when using the sync client 2.5.3
Upload is possible by Webbrowser & GUI. No changes where made on the server since 10/2018 and I synced files sized about 320 MB in 12/2018. No quota is applied to the user.

Steps to reproduce

Take file "test" with about 100-150 MB and initiate sync. Error "Chunks on server do not sum up to ..." is thrown after upload of chunks is complete.

Server configuration

Operating system:
Linux

Web server:
Apache

Database:
MySQL 5.7

PHP version:
7.2 FPM

ownCloud version:
10.0.10.4

Storage backend (external storage):

Client configuration

Client version:
2.5.3 build 342

Operating system:
Linux 64

OS language:
German

Qt version used by client package (Linux only, see also Settings dialog):
Qt 5.10.1

Client package (From ownCloud or distro) (Linux only):
GIT-Revision 80478b auf Feb 7 2019, 17:25:04 verwendet Qt 5.10.1, OpenSSL 1.0.2n 7 Dec 2017

Installation path of client:
/usr/bin/owncloud

Logs

Client logfile: Output of owncloud --logwindow or owncloud --logfile log.txt
https://gist.githubusercontent.com/kerlerm/bb259a92d63e4b926b7ad3fe30ab0f62/raw/fd2740e5ffebfbef2d608ce28613317c3e76ee68/client_log.txt
Web server error log:
https://gist.githubusercontent.com/kerlerm/9bc1dfcc073be59966b2c2d70592f29a/raw/4b60d3d6744c623c8ce43587bdea8bd3784d3989/gistfile1.txt
Server logfile: ownCloud log (data/owncloud.log):
https://gist.githubusercontent.com/kerlerm/99f1ae603170e8ce0669987cc54cf055/raw/0711f8b296e7a68a902125dd0216ce98fa9d487b/server_log.txt

The text was updated successfully, but these errors were encountered:

michaelstingl · 2019-02-08T17:43:55Z

@kerlerm Do you know the version that worked? 2.5.1? 2.4.3?

kerlerm · 2019-02-08T18:16:48Z

Unfortunately, I did not follow installed versions on my machine. I assume 2.4.3 still worked, 2.5.2 and 2.5.3 certainly do not. Should I try downgrading to verify?

ckamm · 2019-02-14T11:08:56Z

@kerlerm Thanks for the report and for including client logs!

@guruz The log contains warnings like this:

[ warning qt.network.http2 ]:	stream 15 finished with error: ""

Is there a way to disable http2 for testing?

From what I can see the client attempts to upload chunks and sees successes even though the server log shows a 400. For example there's a from-scratch upload that logs like this:

02-08 10:36:36:430 [ info sync.networkjob.put ]:	PUT of "https://xxxFQDNxx/remote.php/dav/uploads/xxUSERxx/1711918512/00000000" FINISHED WITH STATUS "OK" QVariant(Invalid) QVariant(Invalid)
02-08 10:36:36:430 [ warning qt.network.http2 ]:	stream 15 finished with error: ""
02-08 10:36:36:434 [ info sync.propagator.upload ]:	Chunked upload of 10000000 bytes took ...

02-08 10:38:42:556 [ info sync.networkjob.put ]:	PUT of "https://xxxFQDNxx/remote.php/dav/uploads/xxUSERxx/1711918512/00000001" FINISHED WITH STATUS "OK" QVariant(Invalid) QVariant(Invalid)
02-08 10:38:42:561 [ info sync.propagator.upload ]:	Chunked upload of 92645760 bytes took ...

10000000 + 92645760 = 102645760

02-08 10:38:43:099 [ warning sync.propagator ]:	Could not complete propagation of "Software/Android/test" by OCC::PropagateUploadFileNG(0x558a8d9c4520) with status 2 and error: "Error transferring https://xxxFQDNxx/remote.php/dav/uploads/xxUSERxx/1711918512/.file - server replied:  
(Chunks on server do not sum up to 102645760 but to 75726848)"

and the server says

xxIPxx - - [08/Feb/2019:10:36:34 +0100] "PUT /remote.php/dav/uploads/xxUSERxx/1711918512/00000000 HTTP/2.0" 400 23 "-" "Mozilla/5.0 (Linux) mirall/2.5.3 (build 342)" xxxFQDNxx

ckamm · 2019-02-14T11:20:40Z

It looks like we end up in QHttp2ProtocolHandler::finishStreamWithError but error is NoError. If I read the Qt code correctly that can only happen when a GOAWAY or RST_STREAM frame has errorCode 0.

Should we check for putFileJob->device()->atEnd() after a successful job, just to make sure? Could be though that the data was sent successfully, just the reply didn't end up being processed correctly somehow.

ckamm · 2019-02-15T07:30:16Z

@kerlerm Do you think you might be able to capture the network traffic that happens while failing to sync this file with a tool like wireshark and upload the data? (shared privately with mail at ckamm de preferably, it might contain auth cookies) This could be your server speaking HTTP2 improperly, but could also be a bug in Qt.

You should definitely be able to work around the problem by disabling HTTP2 server side.

kerlerm · 2019-02-16T15:18:44Z

@ckamm Sent you a notice. PCAP is available on my owncloud for download.

kerlerm · 2019-02-16T15:19:46Z

Disabling HTTP/2 is bit of a hassle because this is not running on a root server but shared hosting...

kerlerm · 2019-02-19T07:50:58Z

@ckamm I tried mitmproxy of ubuntu, but the package is damaged (newer libs). Then I fetched the linux binaries of mitmproxy 4.0, but those froze at 6MB transfer while testing. So I'm a bit lost...

Should I provide a test account on my owncloud for you?

ckamm · 2019-02-19T09:00:01Z

@kerlerm Mitmproxy freezing mid-transfer might be an indication that something is indeed going wrong with the http2 stream. Yes, if you could give me a test account I'd try to reproduce and check it out.

ckamm · 2019-02-20T13:42:55Z

I think this is a bug in the Qt http2 stack.

Test setup: client <-> mitmproxy <-> server with mitmproxy dumping ssl secrets and wireshark listening to the comunication between mitmproxy and the server. That means I'm seeing how mitmproxy reacts to the server messages, but the data is sufficient to see what's going on.

Client opens HTTP2 connection
Requests data on streams 1, 3, 5, 7, 9
Stream 1, 9 finish; Stream 3, 5, 7 are still streaming DATA frames and are not finished
There's a GOAWAY 2^31-1 no-error frame
mitmproxy closes the connection with a tls close_notify
there are more DATA frames from the server on streams 3, 7 that aren't ACKed by the client
finally a GOAWAY 9 no-error frame, and the server's close_notify

The GOAWAY processing seems to be the problem for mitmproxy, and also for Qt. Looking at https://code.woboq.org/qt5/qtbase/src/network/access/qhttp2protocolhandler.cpp.html#815 it seems that a GOAWAY with lastStreamId of 2^31-1 will close all active streams. If I read the spec correctly, it shouldn't do that (https://http2.github.io/http2-spec/#GOAWAY).

ckamm · 2019-02-20T14:02:33Z

Created upstream ticket: https://bugreports.qt.io/browse/QTBUG-73947

ckamm · 2019-02-22T07:42:27Z

@michaelstingl @guruz @ogoffart I'm working on the upstream issue but am strongly recommending to disable HTTP2 support until we have upgraded to a Qt version containing the fix.

michaelstingl · 2019-02-22T07:47:22Z

@ckamm Is there a config switch to disable HTTP2?

ckamm · 2019-02-22T07:48:09Z

No, not yet :/ I'd disable it for 2.5.4 and add a env variable to reenable it if desired.

Due to QTBUG-73947 and #7020. Use OWNCLOUD_HTTP2_ENABLED=1 to enable anyway.

ckamm · 2019-02-22T10:31:54Z

https://codereview.qt-project.org/#/c/254111/

guruz · 2019-02-22T13:43:09Z

@ckamm Wow. And meh!

ckamm · 2019-02-27T09:43:47Z

Note: PR doesn't solve the issue, just disables HTTP2. We'll need to update Qt once the patch is released.

Due to QTBUG-73947 and #7020. Use OWNCLOUD_HTTP2_ENABLED=1 to enable anyway.

guruz · 2019-03-04T06:07:54Z

@kerlerm Can you try a recent daily build?
https://download.owncloud.com/desktop/daily/owncloud-client-2.5.4.11579.451daily20190304.linux-repo.html

kerlerm · 2019-03-05T20:16:53Z

Sorry for the late reply: Version 2.5.4daily20190305 (build 453) syncs big files without problems.

@ckamm: Should I delete your account on my owncloud or will you do further testing once Qt is fixed?

ckamm · 2019-03-06T09:15:57Z

@kerlerm Thanks for testing! You can delete it now, I found a way to reproduce a very similar problem locally.

jnweiger · 2019-03-14T16:22:59Z

Tested on ubuntu 18.10 with 2.5.4rc1

allow haproxy to use HTTP/2.0
2.5.4rc1 connects per default with HTTP/1.1
export OWNCLOUD_HTTP2_ENABLED=1
2.5.4rc1 connects then with HTTP/2.0
OK

ckamm added this to the 2.5.4 milestone Feb 14, 2019

ckamm self-assigned this Feb 14, 2019

ckamm added the type:bug label Feb 14, 2019

ckamm added the Upstream issue label Feb 22, 2019

ckamm added a commit that referenced this issue Feb 22, 2019

Disable HTTP2 by default

a58e439

Due to QTBUG-73947 and #7020. Use OWNCLOUD_HTTP2_ENABLED=1 to enable anyway.

ckamm mentioned this issue Feb 22, 2019

Disable HTTP2 by default #7053

Merged

ckamm added the PR available label Feb 27, 2019

guruz pushed a commit that referenced this issue Feb 28, 2019

Disable HTTP2 by default

9e66347

Due to QTBUG-73947 and #7020. Use OWNCLOUD_HTTP2_ENABLED=1 to enable anyway.

ckamm added ReadyToTest QA, please validate the fix/enhancement and removed PR available labels Feb 28, 2019

ckamm closed this as completed Mar 6, 2019

jnweiger removed the ReadyToTest QA, please validate the fix/enhancement label Mar 14, 2019

tribut mentioned this issue Mar 27, 2019

Big files do not upload ("chunks on server do not sum up") due to QT bug nextcloud/desktop#1171

Closed

ghost mentioned this issue Jun 17, 2019

HTTP/2 protocol error nextcloud/desktop#1072

Closed

papjul mentioned this issue Oct 1, 2019

Error when uploading changes on files with umlauts nextcloud/desktop#1182

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Big files do not sync - chunks do not sum up #7020

Big files do not sync - chunks do not sum up #7020

kerlerm commented Feb 8, 2019 •

edited

Loading

michaelstingl commented Feb 8, 2019

kerlerm commented Feb 8, 2019

ckamm commented Feb 14, 2019

ckamm commented Feb 14, 2019 •

edited

Loading

ckamm commented Feb 15, 2019 •

edited

Loading

kerlerm commented Feb 16, 2019

kerlerm commented Feb 16, 2019

kerlerm commented Feb 19, 2019

ckamm commented Feb 19, 2019

ckamm commented Feb 20, 2019 •

edited

Loading

ckamm commented Feb 20, 2019

ckamm commented Feb 22, 2019

michaelstingl commented Feb 22, 2019

ckamm commented Feb 22, 2019 •

edited

Loading

ckamm commented Feb 22, 2019

guruz commented Feb 22, 2019

ckamm commented Feb 27, 2019

guruz commented Mar 4, 2019

kerlerm commented Mar 5, 2019

ckamm commented Mar 6, 2019

jnweiger commented Mar 14, 2019

Big files do not sync - chunks do not sum up #7020

Big files do not sync - chunks do not sum up #7020

Comments

kerlerm commented Feb 8, 2019 • edited Loading

Expected behaviour

Actual behaviour

Steps to reproduce

Server configuration

Client configuration

Logs

michaelstingl commented Feb 8, 2019

kerlerm commented Feb 8, 2019

ckamm commented Feb 14, 2019

ckamm commented Feb 14, 2019 • edited Loading

ckamm commented Feb 15, 2019 • edited Loading

kerlerm commented Feb 16, 2019

kerlerm commented Feb 16, 2019

kerlerm commented Feb 19, 2019

ckamm commented Feb 19, 2019

ckamm commented Feb 20, 2019 • edited Loading

ckamm commented Feb 20, 2019

ckamm commented Feb 22, 2019

michaelstingl commented Feb 22, 2019

ckamm commented Feb 22, 2019 • edited Loading

ckamm commented Feb 22, 2019

guruz commented Feb 22, 2019

ckamm commented Feb 27, 2019

guruz commented Mar 4, 2019

kerlerm commented Mar 5, 2019

ckamm commented Mar 6, 2019

jnweiger commented Mar 14, 2019

Tested on ubuntu 18.10 with 2.5.4rc1

kerlerm commented Feb 8, 2019 •

edited

Loading

ckamm commented Feb 14, 2019 •

edited

Loading

ckamm commented Feb 15, 2019 •

edited

Loading

ckamm commented Feb 20, 2019 •

edited

Loading

ckamm commented Feb 22, 2019 •

edited

Loading