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

Deflake the joining test #4579

Merged
merged 1 commit into from Jul 14, 2017

Conversation

@richvdh
Copy link
Member

richvdh commented Jul 14, 2017

Just give the client longer to get started (it seems to be taking a long time
to get started talking to indexeddb)

Just give the client longer to get started (it seems to be taking a long time
to get started talking to indexeddb)
@dbkr
dbkr approved these changes Jul 14, 2017
Copy link
Member

dbkr left a comment

fair enough :/

@dbkr dbkr merged commit 1690f87 into develop Jul 14, 2017
2 checks passed
2 checks passed
continuous-integration/travis-ci/pr The Travis CI build passed
Details
continuous-integration/travis-ci/push The Travis CI build passed
Details
@richvdh richvdh deleted the rav/wait_longer_for_client branch Jul 17, 2017
@richvdh

This comment has been minimized.

Copy link
Member Author

richvdh commented Jul 17, 2017

This still hasn't deflaked the test, ftr. https://travis-ci.org/vector-im/riot-web/jobs/253689873 shows the following:

LOG: 'joining a room over federation should not get stuck at a spinner'
LOG: '================================================================'
LOG: 'waiting for /sync'
LOG: '1500052266294 flush[]: HTTP backend flushing... (path=undefined numToFlush=undefined waitTime=1000)'
LOG: 'Restoring session for @me:localhost'
LOG: 'setLoggedIn: mxid: @me:localhost deviceId: null guest: false hs: http://localhost'
LOG: 'Session persisted for @me:localhost'
LOG: 'Lifecycle: Starting MatrixClient'
LOG: '1500052266459 HTTP backend received request: PUT http://localhost/_matrix/client/r0/presence/%40me%3Alocalhost/status'
LOG: 'MatrixClientPeg: waiting for MatrixClient store to initialise'
LOG: '1500052266469 flush[]:   trying to flush => reqs=[PUT http://localhost/_matrix/client/r0/presence/%40me%3Alocalhost/status] expected=[GET /pushrules,POST /filter,GET /sync]'
LOG: '1500052266469 flush[]:   nothing to flush yet; waiting for requests.'
...
LOG: '1500052266880 flush[]:   trying to flush => reqs=[PUT http://localhost/_matrix/client/r0/presence/%40me%3Alocalhost/status] expected=[GET /pushrules,POST /filter,GET /sync]'
LOG: '1500052266880 flush[]:   nothing to flush yet; waiting for requests.'
LOG: 'MatrixClientPeg: really starting MatrixClient'
LOG: '1500052266881 HTTP backend received request: GET http://localhost/_matrix/client/r0/voip/turnServer'
LOG: '1500052266882 HTTP backend received request: GET http://localhost/_matrix/client/r0/pushrules/'
LOG: 'MatrixClientPeg: MatrixClient started'
LOG: '1500052266886 flush[]:   trying to flush => reqs=[PUT http://localhost/_matrix/client/r0/presence/%40me%3Alocalhost/status,GET http://localhost/_matrix/client/r0/voip/turnServer,GET http://localhost/_matrix/client/r0/pushrules/] expected=[GET /pushrules,POST /filter,GET /sync]'
LOG: '1500052266886    responding to /pushrules'
LOG: '1500052266886 flush[]:   flushed. Trying for more.'
LOG: 'Got push rules'
LOG: '1500052266888 HTTP backend received request: POST http://localhost/_matrix/client/r0/user/%40me%3Alocalhost/filter'
LOG: '1500052266891 flush[]:   trying to flush => reqs=[PUT http://localhost/_matrix/client/r0/presence/%40me%3Alocalhost/status,GET http://localhost/_matrix/client/r0/voip/turnServer,POST http://localhost/_matrix/client/r0/user/%40me%3Alocalhost/filter] expected=[POST /filter,GET /sync]'
LOG: '1500052266891    responding to /filter'
LOG: '1500052266891 flush[]:   flushed. Trying for more.'
LOG: '1500052266895 HTTP backend received request: GET http://localhost/_matrix/client/r0/sync'
LOG: '1500052266896 flush[]:   trying to flush => reqs=[PUT http://localhost/_matrix/client/r0/presence/%40me%3Alocalhost/status,GET http://localhost/_matrix/client/r0/voip/turnServer,GET http://localhost/_matrix/client/r0/sync] expected=[GET /sync]'
LOG: '1500052266896    responding to /sync'
LOG: '1500052266896 flush[]:   flushed. Trying for more.'
LOG: 'MatrixClient sync state => %s', 'PREPARED'
LOG: '1500052266969 HTTP backend received request: GET http://localhost/_matrix/client/unstable/thirdparty/protocols'
LOG: 'MatrixClient sync state => %s', 'SYNCING'
LOG: 'Persisting sync data up to ', undefined
LOG: '1500052267008 HTTP backend received request: GET http://localhost/_matrix/client/r0/sync'
LOG: '1500052267013 flush[]:   trying to flush => reqs=[PUT http://localhost/_matrix/client/r0/presence/%40me%3Alocalhost/status,GET http://localhost/_matrix/client/r0/voip/turnServer,GET http://localhost/_matrix/client/unstable/thirdparty/protocols,GET http://localhost/_matrix/client/r0/sync] expected=[]'
LOG: '1500052267013 flush[]: no more flushes after flushing 3 requests'
LOG: '1500052267014 flush[]: HTTP backend flushing... (path=undefined numToFlush=undefined waitTime=100)'
LOG: '1500052267018 flush[]:   trying to flush => reqs=[PUT http://localhost/_matrix/client/r0/presence/%40me%3Alocalhost/status,GET http://localhost/_matrix/client/r0/voip/turnServer,GET http://localhost/_matrix/client/unstable/thirdparty/protocols,GET http://localhost/_matrix/client/r0/sync] expected=[POST /publicRooms,GET /thirdparty/protocols]'
LOG: '1500052267019    responding to /thirdparty/protocols'
LOG: '1500052267019 flush[]:   flushed. Trying for more.'
LOG: '1500052267040 HTTP backend received request: POST http://localhost/_matrix/client/r0/publicRooms'
LOG: '1500052267045 flush[]:   trying to flush => reqs=[PUT http://localhost/_matrix/client/r0/presence/%40me%3Alocalhost/status,GET http://localhost/_matrix/client/r0/voip/turnServer,GET http://localhost/_matrix/client/r0/sync,POST http://localhost/_matrix/client/r0/publicRooms] expected=[POST /publicRooms]'
LOG: '1500052267045    responding to /publicRooms'
LOG: '1500052267045 flush[]:   flushed. Trying for more.'
LOG: '1500052267053 flush[]:   trying to flush => reqs=[PUT http://localhost/_matrix/client/r0/presence/%40me%3Alocalhost/status,GET http://localhost/_matrix/client/r0/voip/turnServer,GET http://localhost/_matrix/client/r0/sync] expected=[]'
LOG: '1500052267053 flush[]: no more flushes after flushing 2 requests'
LOG: '1500052267053 App made requests for directory view; switching to a room.'
LOG: '1500052267061 flush[]: HTTP backend flushing... (path=undefined numToFlush=undefined waitTime=100)'
LOG: '1500052267101 HTTP backend received request: GET http://localhost/_matrix/client/r0/directory/room/%23alias%3Alocalhost'
LOG: 'Switching to room alias #alias:localhost at event undefined'
LOG: 'RVS update:', null, '#alias:localhost', 'loading?', true, 'joining?', false, 'initial?', true, 'waiting?', undefined, 'shouldPeek?', undefined
LOG: '1500052267156 flush[]:   trying to flush => reqs=[PUT http://localhost/_matrix/client/r0/presence/%40me%3Alocalhost/status,GET http://localhost/_matrix/client/r0/voip/turnServer,GET http://localhost/_matrix/client/r0/sync,GET http://localhost/_matrix/client/r0/directory/room/%23alias%3Alocalhost] expected=[GET /directory/room/%23alias%3Alocalhost,GET /rooms/!id%3Alocalhost/initialSync]'
LOG: '1500052267156    responding to /directory/room/%23alias%3Alocalhost'
LOG: '1500052267156 flush[]:   flushed. Trying for more.'
LOG: '1500052267161 flush[]:   trying to flush => reqs=[PUT http://localhost/_matrix/client/r0/presence/%40me%3Alocalhost/status,GET http://localhost/_matrix/client/r0/voip/turnServer,GET http://localhost/_matrix/client/r0/sync] expected=[GET /rooms/!id%3Alocalhost/initialSync]'
LOG: '1500052267161 flush[]: no more flushes after flushing 1 requests'
HeadlessChrome 0.0.0 (Ubuntu 0.0.0) joining a room over federation should not get stuck at a spinner FAILED
	Error: Timed out after flushing 1 requests; 1 remaining
	    at iterate (/home/travis/build/vector-im/riot-web/test/all-tests.js:240244:24)
	    at /home/travis/build/vector-im/riot-web/test/all-tests.js:240255:25
	    at tryCatcher (/home/travis/build/vector-im/riot-web/test/all-tests.js:7649:24)
	    at Promise._settlePromiseFromHandler (/home/travis/build/vector-im/riot-web/test/all-tests.js:7173:32)
	    at Promise._settlePromise (/home/travis/build/vector-im/riot-web/test/all-tests.js:7230:19)
	    at Promise._settlePromise0 (/home/travis/build/vector-im/riot-web/test/all-tests.js:7275:11)
	    at Promise._settlePromises (/home/travis/build/vector-im/riot-web/test/all-tests.js:7354:19)
	    at Async._drainQueue (/home/travis/build/vector-im/riot-web/test/all-tests.js:8238:17)
	    at Async._drainQueues (/home/travis/build/vector-im/riot-web/test/all-tests.js:8248:11)
	    at Async.drainQueues (/home/travis/build/vector-im/riot-web/test/all-tests.js:8122:15)
	    at <anonymous>

So although we've now fixed the problem with waiting for the client to start (it took 600ms here), we're now timing out on a later flush (

return httpBackend.flushAllExpected();
), which seems to take 100ms to do... not much. I'm inclined to simply bump up the timeout on flushAllExpected to 1000ms.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
2 participants
You can’t perform that action at this time.