Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Regression in resync speed after being asleep #2425

Closed
ara4n opened this issue Oct 6, 2016 · 5 comments
Closed

Regression in resync speed after being asleep #2425

ara4n opened this issue Oct 6, 2016 · 5 comments
Labels
P1 S-Major Severely degrades major functionality or product features, with no satisfactory workaround T-Defect X-Release-Blocker

Comments

@ara4n
Copy link
Member

ara4n commented Oct 6, 2016

Today and yesterday, it took my vector-web about 95 seconds to wake up after unsleeping my laptop from overnight (Chrome 53.0.2785.116 on OSX 10.11.4). Unsure what has changed, but i'm very surprised we're not seeing 'sync state' console log lines from js-sdk any more saying whether we're in state ERROR or SYNCING etc.

2016-10-06 08:22:02.813 sync.js:545 /sync error MatrixError(anonymous function) @ sync.js:545
2016-10-06 08:22:02.813 sync.js:546 MatrixError(anonymous function) @ sync.js:546

<comp wakes up>

2016-10-06 09:23:00.255 https://matrix.org/_matrix/client/r0/rooms/!zOmsiVucpWbRRDjSwe%3Amatrix.org… Failed to load resource: net::ERR_INTERNET_DISCONNECTED
2016-10-06 09:23:00.370 https://matrix.org/_matrix/client/r0/presence/%40matthew%3Amatrix.org/statu… Failed to load resource: net::ERR_INTERNET_DISCONNECTED
2016-10-06 09:23:00.372 q.js:161 Uncaught Error: CORS request rejected: https://matrix.org/_matrix/client/r0/rooms/!zOmsiVucpWbRRDjSwe%3Amatrix.org…
2016-10-06 09:23:00.372 Presence.js:85 Failed to set presence: Error: CORS request rejected: https://matrix.org/_matrix/client/r0/presence/%40matthew%3Amatrix.org/statu…
    at on_response (https://vector.im/develop/bundle.js:20038:23)
    at XMLHttpRequest.on_state_change (https://vector.im/develop/bundle.js:20021:8)(anonymous function) @ Presence.js:85
2016-10-06 09:23:00.627 https://matrix.org/_matrix/client/r0/presence/%40matthew%3Amatrix.org/statu… Failed to load resource: net::ERR_INTERNET_DISCONNECTED
2016-10-06 09:23:00.628 Presence.js:85 Failed to set presence: Error: CORS request rejected: https://matrix.org/_matrix/client/r0/presence/%40matthew%3Amatrix.org/statu…
    at on_response (https://vector.im/develop/bundle.js:20038:23)
    at XMLHttpRequest.on_state_change (https://vector.im/develop/bundle.js:20021:8)(anonymous function) @ Presence.js:85
2016-10-06 09:23:01.157 https://matrix.org/_matrix/client/r0/presence/%40matthew%3Amatrix.org/statu… Failed to load resource: net::ERR_INTERNET_DISCONNECTED
2016-10-06 09:23:01.158 Presence.js:85 Failed to set presence: Error: CORS request rejected: https://matrix.org/_matrix/client/r0/presence/%40matthew%3Amatrix.org/statu…
    at on_response (https://vector.im/develop/bundle.js:20038:23)
    at XMLHttpRequest.on_state_change (https://vector.im/develop/bundle.js:20021:8)(anonymous function) @ Presence.js:85
2016-10-06 09:23:01.984 https://matrix.org/_matrix/client/r0/presence/%40matthew%3Amatrix.org/statu… Failed to load resource: net::ERR_INTERNET_DISCONNECTED
2016-10-06 09:23:01.987 Presence.js:85 Failed to set presence: Error: CORS request rejected: https://matrix.org/_matrix/client/r0/presence/%40matthew%3Amatrix.org/statu…
    at on_response (https://vector.im/develop/bundle.js:20038:23)
    at XMLHttpRequest.on_state_change (https://vector.im/develop/bundle.js:20021:8)(anonymous function) @ Presence.js:85
2016-10-06 09:23:02.241 https://matrix.org/_matrix/client/r0/presence/%40matthew%3Amatrix.org/statu… Failed to load resource: net::ERR_INTERNET_DISCONNECTED
2016-10-06 09:23:02.242 Presence.js:85 Failed to set presence: Error: CORS request rejected: https://matrix.org/_matrix/client/r0/presence/%40matthew%3Amatrix.org/statu…
    at on_response (https://vector.im/develop/bundle.js:20038:23)
    at XMLHttpRequest.on_state_change (https://vector.im/develop/bundle.js:20021:8)(anonymous function) @ Presence.js:85
2016-10-06 09:23:02.871 https://matrix.org/_matrix/client/r0/presence/%40matthew%3Amatrix.org/statu… Failed to load resource: net::ERR_INTERNET_DISCONNECTED
2016-10-06 09:23:02.871 Presence.js:85Failed to set presence: Error: CORS request rejected: https://matrix.org/_matrix/client/r0/presence/%40matthew%3Amatrix.org/statu…
    at on_response (https://vector.im/develop/bundle.js:20038:23)
    at XMLHttpRequest.on_state_change (https://vector.im/develop/bundle.js:20021:8)(anonymous function) @ Presence.js:85
2016-10-06 09:23:03.041 https://matrix.org/_matrix/client/r0/rooms/!zOmsiVucpWbRRDjSwe%3Amatrix.org… Failed to load resource: net::ERR_INTERNET_DISCONNECTED
2016-10-06 09:23:03.049 https://matrix.org/_matrix/client/r0/presence/%40matthew%3Amatrix.org/statu… Failed to load resource: net::ERR_INTERNET_DISCONNECTED
2016-10-06 09:23:03.050 q.js:161Uncaught Error: CORS request rejected: https://matrix.org/_matrix/client/r0/rooms/!zOmsiVucpWbRRDjSwe%3Amatrix.org…
2016-10-06 09:23:03.051 index.js:116newscreen room/!lFdHwFlnCHQWDBxEjs:matrix.org
2016-10-06 09:23:03.298 RoomView.js:1338updateTint from RoomView._gatherTimelinePanelRef
2016-10-06 09:23:03.298 RoomView.js:469Tinter.tint from updateTint
2016-10-06 09:23:03.378 Presence.js:85Failed to set presence: Error: CORS request rejected: https://matrix.org/_matrix/client/r0/presence/%40matthew%3Amatrix.org/statu…
    at on_response (https://vector.im/develop/bundle.js:20038:23)
    at XMLHttpRequest.on_state_change (https://vector.im/develop/bundle.js:20021:8)(anonymous function) @ Presence.js:85
2016-10-06 09:23:03.601 https://matrix.org/_matrix/media/v1/thumbnail/matrix.org/rwCHdrTnCqZjyajPFKEXkJOX?width=100&height=100 Failed to load resource: the server responded with a status of 404 (Not Found)
2016-10-06 09:23:04.148 Presence.js:83Presence: online
2016-10-06 09:23:04.468 index.js:116newscreen room/#irc_#matrix:openmarket.com
2016-10-06 09:23:04.779 RoomView.js:1338updateTint from RoomView._gatherTimelinePanelRef
2016-10-06 09:23:04.779 RoomView.js:469Tinter.tint from updateTint
2016-10-06 09:23:05.032 https://matrix.org/_matrix/media/v1/thumbnail/matrix.org/HMFeLzEGlsHsSRZrarybMWBu?width=100&height=100 Failed to load resource: the server responded with a status of 404 (Not Found)
2016-10-06 09:23:05.275 https://matrix.org/_matrix/media/r0/preview_url?url=https%3A%2F%2Fgithub.co… Failed to load resource: the server responded with a status of 500 (Internal Server Error)
2016-10-06 09:23:05.277 LinkPreviewWidget.js:58Failed to get preview for https://github.com/erikjohnston/matrix-ircd/blob/master/src/irc/protocol.rs#L257-L298 M_UNKNOWN: Failed to download content: 502: Got error 404(anonymous function) @ LinkPreviewWidget.js:58
2016-10-06 09:23:16.846 3103 console messages are not shown.
2016-10-06 09:24:41.901 sync.js:545 /sync error Error: ETIMEDOUT
    at too_late (https://vector.im/develop/bundle.js:19982:15)(anonymous function) @ sync.js:545
    _rejected @ q.js:844(anonymous function) @ q.js:870
    when @ q.js:1122
    Promise.promise.promiseDispatch @ q.js:788
    (anonymous function) @ q.js:604
    runSingle @ q.js:137
    flush @ q.js:125
    onNextTick @ main.js:64
    Item.run @ browser.js:133
    drainQueue @ browser.js:103
2016-10-06 09:24:41.905 sync.js:546 Error: ETIMEDOUT(…)(anonymous function) @ sync.js:546
    _rejected @ q.js:844
    (anonymous function) @ q.js:870
    when @ q.js:1122
    Promise.promise.promiseDispatch @ q.js:788
    (anonymous function) @ q.js:604
    runSingle @ q.js:137
    flush @ q.js:125
    onNextTick @ main.js:64
    Item.run @ browser.js:133
    drainQueue @ browser.js:103

...and then app comes back, without any further console logging?!

@ara4n ara4n added T-Defect P1 S-Critical Prevents work, causes data loss and/or has no workaround X-Release-Blocker S-Major Severely degrades major functionality or product features, with no satisfactory workaround and removed S-Critical Prevents work, causes data loss and/or has no workaround labels Oct 6, 2016
@ara4n
Copy link
Member Author

ara4n commented Oct 6, 2016

(this was on /develop)

@dbkr
Copy link
Member

dbkr commented Oct 6, 2016

I'm going to accuse matrix-org/matrix-js-sdk#216 of causing this, based on timing and the fact that this will immediately cause it to try & sync again which will take however long a sync takes to time out to time out.

@ara4n
Copy link
Member Author

ara4n commented Oct 9, 2016

I just had this again - worse still, it didn't give me any warning I was unconnected; just behaved normally with 24h-stale history until it suddenly popped back into life about 2 minutes after unsleeping my laptop >:(

This on current /develop - so vector-web version: vector-f827a2963e82-react-79011886a85e-js-74d6cb802fbe

2016-10-09 00:39:13.633 sync.js:545 /sync error Error: CORS request rejected: https://matrix.org/_matrix/client/r0/sync?filter=66&timeout=30000&since=s46…
    at on_response (https://vector.im/develop/bundle.js:20038:23)
    at XMLHttpRequest.on_state_change (https://vector.im/develop/bundle.js:20021:8)(anonymous function) @ sync.js:545
2016-10-09 00:39:13.633 sync.js:546 Error: CORS request rejected: https://matrix.org/_matrix/client/r0/sync?filter=66&timeout=30000&since=s46…(…)(anonymous function) @ sync.js:546
2016-10-09 00:39:13.633 sync.js:49 Starting keep-alive
2016-10-09 00:39:13.635 MatrixChat.js:646 MatrixClient sync state => RECONNECTING
2016-10-09 00:39:21.590 MatrixChat.js:646 MatrixClient sync state => SYNCING
2016-10-09 02:39:29.333 sync.js:545 /sync error MatrixError(anonymous function) @ sync.js:545
2016-10-09 02:39:29.333 sync.js:546 MatrixError(anonymous function) @ sync.js:546
2016-10-09 02:39:29.333 sync.js:49 Starting keep-alive
2016-10-09 02:39:29.334 MatrixChat.js:646 MatrixClient sync state => RECONNECTING
2016-10-09 05:40:21.076 MatrixChat.js:646 MatrixClient sync state => SYNCING
2016-10-10 00:00:41.145 https://matrix.org/_matrix/media/v1/thumbnail/writequit.org/wVORSejMHYAczGKFrowXvvRo?width=24&height=24&method=crop Failed to load resource: net::ERR_NETWORK_CHANGED
2016-10-10 00:00:42.665 https://matrix.org/_matrix/client/r0/rooms/!zOmsiVucpWbRRDjSwe%3Amatrix.org… Failed to load resource: net::ERR_INTERNET_DISCONNECTED
2016-10-10 00:00:42.830 q.js:161 Uncaught Error: CORS request rejected: https://matrix.org/_matrix/client/r0/rooms/!zOmsiVucpWbRRDjSwe%3Amatrix.org…
2016-10-10 00:00:44.138 index.js:116 newscreen room/#matrix:matrix.org
2016-10-10 00:00:44.810 RoomView.js:1338 updateTint from RoomView._gatherTimelinePanelRef
2016-10-10 00:00:44.811 RoomView.js:469 Tinter.tint from updateTint
2016-10-10 00:00:46.786 https://matrix.org/_matrix/client/r0/rooms/!cURbafjkfsMDVwdRDQ%3Amatrix.org… Failed to load resource: net::ERR_INTERNET_DISCONNECTED
...
2016-10-10 00:00:55.439 q.js:161 Uncaught Error: CORS request rejected: https://matrix.org/_matrix/client/r0/rooms/!cURbafjkfsMDVwdRDQ%3Amatrix.org…
2016-10-10 00:00:55.579 https://matrix.org/_matrix/client/r0/rooms/!cURbafjkfsMDVwdRDQ%3Amatrix.org… Failed to load resource: net::ERR_INTERNET_DISCONNECTED
2016-10-10 00:01:19.885 index.js:116 newscreen room/#irc:matrix.org
2016-10-10 00:01:20.437 RoomView.js:1338 updateTint from RoomView._gatherTimelinePanelRef
2016-10-10 00:01:20.437 RoomView.js:469 Tinter.tint from updateTint
2016-10-10 00:01:21.008 event-timeline-set.js:395 Already have timeline for $1475953335159uQFhI:sw1v.org - joining timeline !SudviOJlimDvrGdFCY:matrix.org:2016-10-08T22:30:32.106Z to !SudviOJlimDvrGdFCY:matrix.org:2016-10-07T23:39:34.787Z
2016-10-10 00:01:21.008 event-timeline-set.js:368 Event $14759510541304IVtYm:kolm.io already in timeline !SudviOJlimDvrGdFCY:matrix.org:2016-10-07T23:39:34.787Z
2016-10-10 00:01:21.008 event-timeline-set.js:368 Event $1475950897751288wrnfD:matrix.org already in timeline !SudviOJlimDvrGdFCY:matrix.org:2016-10-07T23:39:34.787Z
2016-10-10 00:01:21.103 https://matrix.org/_matrix/media/r0/preview_url?url=http%3A%2F%2Flocalhost%… Failed to load resource: the server responded with a status of 500 (Internal Server Error)
2016-10-10 00:01:21.164 LinkPreviewWidget.js:58 Failed to get preview for http://localhost:8090 M_UNKNOWN: Failed to download content: An error occurred while connecting: Refusing to spider blacklisted IP address 127.0.0.1.(anonymous function) @ LinkPreviewWidget.js:58
2016-10-10 00:01:21.260 https://matrix.org/_matrix/media/r0/preview_url?url=http%3A%2F%2Fsomehost%3… Failed to load resource: the server responded with a status of 500 (Internal Server Error)
2016-10-10 00:01:21.293 LinkPreviewWidget.js:58 Failed to get preview for http://somehost:someport M_UNKNOWN: Failed to download content: DNS lookup failed: address 'somehost' not found: [Errno -2] Name or service not known.(anonymous function) @ LinkPreviewWidget.js:58
2016-10-10 00:01:21.427 https://matrix.org/_matrix/media/v1/thumbnail/matrix.org/zwtaGhJhxzUkEaQSlroCsYll?width=100&height=100 Failed to load resource: the server responded with a status of 404 (Not Found)
2016-10-10 00:01:21.447 https://matrix.org/_matrix/media/v1/thumbnail/matrix.org/RGXSQYmIPvYlGWHKwjLDycSr?width=100&height=100 Failed to load resource: the server responded with a status of 404 (Not Found)
2016-10-10 00:01:21.606 https://matrix.org/_matrix/media/v1/thumbnail/matrix.org/OfILUePwuImCoOfylfqnQyOP?width=100&height=100 Failed to load resource: the server responded with a status of 404 (Not Found)
2016-10-10 00:01:33.625 981console messages are not shown.
2016-10-10 00:02:03.122 index.js:116 newscreen room/#irc_#matrix:openmarket.com
2016-10-10 00:02:03.600 RoomView.js:1338 updateTint from RoomView._gatherTimelinePanelRef
2016-10-10 00:02:03.600 RoomView.js:469 Tinter.tint from updateTint
2016-10-10 00:02:16.848 https://matrix.org/_matrix/client/r0/sync?filter=66&timeout=30000&since=s46… Failed to load resource: net::ERR_TIMED_OUT
2016-10-10 00:02:16.850 sync.js:545 /sync error Error: CORS request rejected: https://matrix.org/_matrix/client/r0/sync?filter=66&timeout=30000&since=s46…
    at on_response (https://vector.im/develop/bundle.js:20038:23)
    at XMLHttpRequest.on_state_change (https://vector.im/develop/bundle.js:20021:8)(anonymous function) @ sync.js:545_rejected @ q.js:844(anonymous function) @ q.js:870when @ q.js:1122Promise.promise.promiseDispatch @ q.js:788(anonymous function) @ q.js:604runSingle @ q.js:137flush @ q.js:125onNextTick @ main.js:64Item.run @ browser.js:133drainQueue @ browser.js:103
2016-10-10 00:02:16.856 sync.js:546 Error: CORS request rejected: https://matrix.org/_matrix/client/r0/sync?filter=66&timeout=30000&since=s46…(…)(anonymous function) @ sync.js:546_rejected @ q.js:844(anonymous function) @ q.js:870when @ q.js:1122Promise.promise.promiseDispatch @ q.js:788(anonymous function) @ q.js:604runSingle @ q.js:137flush @ q.js:125onNextTick @ main.js:64Item.run @ browser.js:133drainQueue @ browser.js:103
2016-10-10 00:02:16.857 sync.js:49 Starting keep-alive
2016-10-10 00:02:16.860 MatrixChat.js:646 MatrixClient sync state => RECONNECTING
2016-10-10 00:02:39.509 index.js:1139 m.new_device event from @jon:terracrypt.net:SGNKXOKMHT for rooms !UCnwUWwIKhcpaPTHtR:sw1v.org
2016-10-10 00:02:39.902 event-timeline-set.js:450 EventTimelineSet.addLiveEvent: ignoring duplicate event $1476031097948368nWcUl:matrix.org
2016-10-10 00:02:48.597 MatrixChat.js:646 MatrixClient sync state => SYNCING

Whilst we're at it, worth noting this is by far our most regressing bug: #540, #1702 etc.

@ara4n ara4n reopened this Oct 9, 2016
@ara4n
Copy link
Member Author

ara4n commented Oct 15, 2016

haven't seen this since

@ara4n ara4n closed this as completed Oct 15, 2016
@mahmoud
Copy link

mahmoud commented Feb 16, 2017

I've been getting this for the past hour :/

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
P1 S-Major Severely degrades major functionality or product features, with no satisfactory workaround T-Defect X-Release-Blocker
Projects
None yet
Development

No branches or pull requests

3 participants