Closed
Bug 1153709
Opened 9 years ago
Closed 9 years ago
[Marionette-webapi] emulator_cmd doesn't get response until sending a `timed out` error to client
Categories
(Firefox OS Graveyard :: Emulator, defect)
Tracking
(tracking-b2g:backlog)
RESOLVED
DUPLICATE
of bug 1207039
tracking-b2g | backlog |
People
(Reporter: edgar, Assigned: edgar)
References
Details
Attachments
(1 file)
Snippet of log: > 04-10 16:21:01.139 I/Gecko ( 44): 1428682861146 Marionette DEBUG conn402 emulator <- ({emulator_cmd:"sensor set orientation 0:-180:0", id:54}) // Sending emulator command, but get no response > 04-10 16:22:52.590 I/Gecko ( 44): 1428682972596 Marionette DEBUG conn402 client <- ({from:"0", status:28, sessionId:"{b45d849c-23b7-4a25-860d-dc8e8168154a}", error:{message:"timed out", stacktrace:null, status:28}}) // Test script is timed out. Sending `timed out` error to client. > 04-10 16:22:52.639 I/Gecko ( 44): 1428682972645 Marionette DEBUG conn402 -> ({result:["OK"], to:"0", name:"emulatorCmdResult", id:54}) // The response of emulator command suddenly back. Some intermittent script time out was caused by this, - https://treeherder.mozilla.org/logviewer.html#?job_id=6300850&repo=try - https://treeherder.mozilla.org/logviewer.html#?job_id=6300858&repo=try
Assignee | ||
Updated•9 years ago
|
Summary: [Marionette-webapi] emulator_cmd doesn't response until send a `timed out` error to client → [Marionette-webapi] emulator_cmd doesn't get response until sending a `timed out` error to client
Assignee | ||
Comment 1•9 years ago
|
||
Try runs with debugging enabled in devtools to see if we can get some clues: https://treeherder.mozilla.org/#/jobs?repo=try&revision=b80d27623c54&exclusion_profile=false
Assignee | ||
Comment 3•9 years ago
|
||
https://treeherder.mozilla.org/logviewer.html#?job_id=6477703&repo=try Snippet of the log with debugging enabled in devtools: > 04-13 15:52:26.090 I/Gecko ( 44): 1428940346095 Marionette DEBUG conn408 emulator <- ({"emulator_cmd":"sensor set orientation 180:0:-90","id":113}) > 04-13 15:52:26.100 I/GeckoDump( 44): DBG-SERVER: Writing JSON packet > 04-13 15:54:00.200 I/Gecko ( 44): 1428940440204 Marionette DEBUG conn408 client <- ({"from":"0","status":28,"sessionId":"{bee27991-ca8a-4281-b7a7-77ce0fbfaf3c}","error":{"message":"timed out","stacktrace":null,"status":28}}) > 04-13 15:54:00.241 I/GeckoDump( 44): DBG-SERVER: Data available: 72 > 04-13 15:54:00.241 I/GeckoDump( 44): DBG-SERVER: Creating a new packet from incoming > 04-13 15:54:00.241 I/GeckoDump( 44): DBG-SERVER: Starting delimited read for : up to 200 bytes > 04-13 15:54:00.249 I/GeckoDump( 44): DBG-SERVER: Header read: 69: > 04-13 15:54:00.249 I/GeckoDump( 44): DBG-SERVER: Found packet header successfully: 69: > 04-13 15:54:00.269 I/GeckoDump( 44): DBG-SERVER: Header matches JSON packet > 04-13 15:54:00.269 I/GeckoDump( 44): DBG-SERVER: Existing packet incomplete, keep reading > 04-13 15:54:00.269 I/GeckoDump( 44): DBG-SERVER: Reading JSON packet > 04-13 15:54:00.279 I/GeckoDump( 44): DBG-SERVER: Reading JSON data: _l: 69 dL: 0 sA: 69 > 04-13 15:54:00.289 I/GeckoDump( 44): DBG-SERVER: Got: { > 04-13 15:54:00.289 I/GeckoDump( 44): "result": [ > 04-13 15:54:00.289 I/GeckoDump( 44): "OK" > 04-13 15:54:00.289 I/GeckoDump( 44): ], > 04-13 15:54:00.289 I/GeckoDump( 44): "to": "0", > 04-13 15:54:00.289 I/GeckoDump( 44): "name": "emulatorCmdResult", > 04-13 15:54:00.289 I/GeckoDump( 44): "id": 113 > 04-13 15:54:00.289 I/GeckoDump( 44): } > 04-13 15:54:00.309 I/GeckoDump( 44): DBG-SERVER: Writing JSON packet > 04-13 15:54:00.339 I/Gecko ( 44): 1428940440342 Marionette DEBUG conn408 -> ({"result":["OK"],"to":"0","name":"emulatorCmdResult","id":113}) > 04-13 15:54:00.350 I/GeckoDump( 44): DBG-SERVER: Data available: 88 > 04-13 15:54:00.350 I/GeckoDump( 44): DBG-SERVER: Creating a new packet from incoming > 04-13 15:54:00.350 I/GeckoDump( 44): DBG-SERVER: Starting delimited read for : up to 200 bytes > 04-13 15:54:00.359 I/GeckoDump( 44): DBG-SERVER: Header read: 85: > 04-13 15:54:00.359 I/GeckoDump( 44): DBG-SERVER: Found packet header successfully: 85: > 04-13 15:54:00.359 I/GeckoDump( 44): DBG-SERVER: Header matches JSON packet > 04-13 15:54:00.359 I/GeckoDump( 44): DBG-SERVER: Existing packet incomplete, keep reading > 04-13 15:54:00.369 I/GeckoDump( 44): DBG-SERVER: Reading JSON packet > 04-13 15:54:00.369 I/GeckoDump( 44): DBG-SERVER: Reading JSON data: _l: 85 dL: 0 sA: 85 > 04-13 15:54:00.379 I/GeckoDump( 44): DBG-SERVER: Got: { > 04-13 15:54:00.379 I/GeckoDump( 44): "to": "0", > 04-13 15:54:00.379 I/GeckoDump( 44): "sessionId": "{bee27991-ca8a-4281-b7a7-77ce0fbfaf3c}", > 04-13 15:54:00.379 I/GeckoDump( 44): "name": "getLogs" > 04-13 15:54:00.379 I/GeckoDump( 44): } > 04-13 15:54:00.399 I/Gecko ( 44): MARIONETTE TEST RESULT:TEST-PASS | test_sensor_orientation.js | Emulator response: ["OK"] - true was true, expected true > 04-13 15:54:00.529 I/Gecko ( 44): 1428940440535 Marionette DEBUG conn408 -> ({"to":"0","sessionId":"{bee27991-ca8a-4281-b7a7-77ce0fbfaf3c}","name":"getLogs"})
Assignee | ||
Comment 4•9 years ago
|
||
I added more log in nsSocketTransport2.cpp trying to debug this, but I cannot reproduce this issue after applying the debug patch (over 130+ retriggers, https://treeherder.mozilla.org/#/jobs?repo=try&revision=74365e5cb51a&exclusion_profile=false). :(
Assignee | ||
Comment 5•9 years ago
|
||
Maybe related to https://android-review.googlesource.com/#/c/169681/? Not sure, but we can give it a shot. (Thanks to Samael finding this)
Assignee | ||
Comment 6•9 years ago
|
||
Try runs with possible fix, cross fingers ... https://treeherder.allizom.org/#/jobs?repo=try&revision=6d36f26b6c91&exclusion_profile=false&group_state=expanded
Assignee | ||
Comment 7•9 years ago
|
||
(In reply to Edgar Chen [:edgar][:echen] from comment #6) > Try runs with possible fix, cross fingers ... > > https://treeherder.allizom.org/#/jobs?repo=try&revision=6d36f26b6c91&exclusion_profile=false&group_state=expanded The result looks pretty good, only 4 failure over 130+ retriggers and none of them are caused by the issue we reported in this bug (comment #0). Comparing with the try runs without the fix: https://treeherder.allizom.org/#/jobs?repo=try&revision=7a080cf8c2ed&exclusion_profile=false&group_state=expanded. I can see 6+ failure with same symptom as comment #0 in 100+ retriggers. It seems the patches in comment #5 works.
Assignee | ||
Comment 8•9 years ago
|
||
Assignee | ||
Comment 9•9 years ago
|
||
I didn't see same issue (comment #0) any more with applying the fix patch of bug 1207039: https://treeherder.mozilla.org/#/jobs?repo=try&revision=8ccd09f7dfa4&exclusion_profile=false&group_state=expanded
Assignee: nobody → echen
Status: NEW → RESOLVED
Closed: 9 years ago
Resolution: --- → DUPLICATE
You need to log in
before you can comment on or make changes to this bug.
Description
•