could not be scrolled into view","stacktrace":"WebDriverError@chrome://marionette/content/error.js:226:5\nElementNotInteractableError@chrome://marionette/content/error.js:315:5\nwebdriverClickElement@chrome://marionette/content/interaction.js:183:11\nTaskImpl_run@resource://gre/modules/Task.jsm:331:42\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nTaskImpl_handleResultValue@resource://gre/modules/Task.jsm:401:16\nTaskImpl_run@resource://gre/modules/Task.jsm:339:15\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nTaskImpl_handleResultValue@resource://gre/modules/Task.jsm:401:16\nTaskImpl_run@resource://gre/modules/Task.jsm:339:15\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nnavigate@chrome://marionette/content/listener.js:392:12\nclickElement@chrome://marionette/content/listener.js:1312:5\n"},null]
04:09:27 INFO - 1499598567208 Marionette TRACE 352 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-END: test_click.py TestClick.test_clicking_an_element_that_is_not_displayed_raises')","sandbox":"simpletest","line":328}]
04:09:27 INFO - TEST-END: test_click.py TestClick.test_clicking_an_element_that_is_not_displayed_raises1499598567211 Marionette TRACE 352 <- [1,5,null,{"value":null}]
04:09:27 INFO - 1499598567212 Marionette TRACE 352 -> [0,6,"deleteSession",{}]
04:09:27 INFO - TEST-PASS | test_click.py TestClick.test_clicking_an_element_that_is_not_displayed_raises | took 158ms
04:09:27 INFO - 1499598567214 Marionette TRACE 352 <- [1,6,null,{}]
04:09:27 INFO - TEST-START | test_click.py TestClick.test_clicking_on_a_multiline_link
04:09:27 INFO - 1499598567216 Marionette DEBUG Closed connection 352
04:09:27 INFO - 1499598567217 Marionette DEBUG Accepted connection 353 from 127.0.0.1:49778
04:09:27 INFO - 1499598567218 Marionette DEBUG Closed connection 353
04:09:27 INFO - 1499598567219 Marionette DEBUG Accepted connection 354 from 127.0.0.1:49779
04:09:27 INFO - 1499598567220 Marionette TRACE 354 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
04:09:27 INFO - 1499598567228 Marionette CONFIG Matched capabilities: {"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}
04:09:27 INFO - 1499598567231 Marionette DEBUG Register listener.js for window 12
04:09:27 INFO - 1499598567235 Marionette TRACE 354 <- [1,1,null,{"sessionId":"8f4296c4-b962-44b1-96c6-e1246f2bb9b5","capabilities":{"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}}]
04:09:27 INFO - 1499598567237 Marionette TRACE 354 -> [0,2,"setTimeouts",{"script":30000}]
04:09:27 INFO - 1499598567238 Marionette TRACE 354 <- [1,2,null,{}]
04:09:27 INFO - 1499598567239 Marionette TRACE 354 -> [0,3,"setTimeouts",{"pageLoad":300000}]
04:09:27 INFO - 1499598567240 Marionette TRACE 354 <- [1,3,null,{}]
04:09:27 INFO - 1499598567241 Marionette TRACE 354 -> [0,4,"setTimeouts",{"implicit":0}]
04:09:27 INFO - 1499598567241 Marionette TRACE 354 <- [1,4,null,{}]
04:09:27 INFO - 1499598567243 Marionette TRACE 354 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-START: test_click.py TestClick.test_clicking_on_a_multiline_link')","sandbox":"simpletest","line":316}]
04:09:27 INFO - TEST-START: test_click.py TestClick.test_clicking_on_a_multiline_link1499598567246 Marionette TRACE 354 <- [1,5,null,{"value":null}]
04:09:27 INFO - 1499598567247 Marionette TRACE 354 -> [0,6,"deleteSession",{}]
04:09:27 INFO - 1499598567249 Marionette TRACE 354 <- [1,6,null,{}]
04:09:27 INFO - 1499598567251 Marionette DEBUG Closed connection 354
04:09:27 INFO - 1499598567252 Marionette DEBUG Accepted connection 355 from 127.0.0.1:49780
04:09:27 INFO - 1499598567253 Marionette DEBUG Closed connection 355
04:09:27 INFO - 1499598567253 Marionette DEBUG Accepted connection 356 from 127.0.0.1:49781
04:09:27 INFO - 1499598567254 Marionette TRACE 356 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
04:09:27 INFO - 1499598567255 Marionette CONFIG Matched capabilities: {"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}
04:09:27 INFO - 1499598567258 Marionette DEBUG Register listener.js for window 12
04:09:27 INFO - 1499598567261 Marionette TRACE 356 <- [1,1,null,{"sessionId":"7acf9246-426d-4769-af6f-19408fbe362a","capabilities":{"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}}]
04:09:27 INFO - 1499598567263 Marionette TRACE 356 -> [0,2,"deleteSession",{}]
04:09:27 INFO - 1499598567265 Marionette TRACE 356 <- [1,2,null,{}]
04:09:27 INFO - 1499598567267 Marionette DEBUG Closed connection 356
04:09:27 INFO - 1499598567268 Marionette DEBUG Accepted connection 357 from 127.0.0.1:49782
04:09:27 INFO - 1499598567269 Marionette DEBUG Closed connection 357
04:09:27 INFO - 1499598567269 Marionette DEBUG Accepted connection 358 from 127.0.0.1:49783
04:09:27 INFO - 1499598567270 Marionette TRACE 358 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
04:09:27 INFO - 1499598567271 Marionette CONFIG Matched capabilities: {"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":1,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}
04:09:27 INFO - 1499598567274 Marionette DEBUG Register listener.js for window 12
04:09:27 INFO - 1499598567277 Marionette TRACE 358 <- [1,1,null,{"sessionId":"c2c00a4b-dbac-420f-9f6b-297febd33a83","capabilities":{"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":1,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}}]
04:09:27 INFO - 1499598567279 Marionette TRACE 358 -> [0,2,"get",{"url":"http://127.0.0.1:49349/clicks.html"}]
04:09:27 INFO - 1499598567281 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49349/hidden.html"
04:09:27 INFO - 1499598567291 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49349/hidden.html"
04:09:27 INFO - 1499598567292 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49349/hidden.html"
04:09:27 INFO - 1499598567315 Marionette DEBUG Received DOM event "DOMContentLoaded" for "http://127.0.0.1:49349/clicks.html"
04:09:27 INFO - 1499598567317 Marionette DEBUG Received DOM event "pageshow" for "http://127.0.0.1:49349/clicks.html"
04:09:27 INFO - 1499598567322 Marionette TRACE 358 <- [1,2,null,{}]
04:09:27 INFO - 1499598567332 Marionette TRACE 358 -> [0,3,"findElement",{"using":"id","value":"overflowLink"}]
04:09:27 INFO - 1499598567335 Marionette TRACE 358 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"4a650c3a-ef85-48b2-a0d8-92ab90d61072","ELEMENT":"4a650c3a-ef85-48b2-a0d8-92ab90d61072"}}]
04:09:27 INFO - 1499598567336 Marionette TRACE 358 -> [0,4,"clickElement",{"id":"4a650c3a-ef85-48b2-a0d8-92ab90d61072"}]
04:09:27 INFO - 1499598567381 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49349/clicks.html"
04:09:27 INFO - 1499598567393 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49349/clicks.html"
04:09:27 INFO - 1499598567394 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49349/clicks.html"
04:09:27 INFO - 1499598567429 Marionette DEBUG Received DOM event "DOMContentLoaded" for "http://127.0.0.1:49349/test.html"
04:09:27 INFO - 1499598567433 Marionette DEBUG Received DOM event "pageshow" for "http://127.0.0.1:49349/test.html"
04:09:27 INFO - 1499598567437 Marionette TRACE 358 <- [1,4,null,{}]
04:09:27 INFO - 1499598567447 Marionette TRACE 358 -> [0,5,"findElement",{"using":"id","value":"testDiv"}]
04:09:27 INFO - 1499598567450 Marionette TRACE 358 <- [1,5,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"78eeeafe-9db9-4e94-9a60-5db8b825a202","ELEMENT":"78eeeafe-9db9-4e94-9a60-5db8b825a202"}}]
04:09:27 INFO - 1499598567451 Marionette TRACE 358 -> [0,6,"getTitle",{}]
04:09:27 INFO - 1499598567452 Marionette TRACE 358 <- [1,6,null,{"value":"Marionette Test"}]
04:09:27 INFO - 1499598567456 Marionette TRACE 358 -> [0,7,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-END: test_click.py TestClick.test_clicking_on_a_multiline_link')","sandbox":"simpletest","line":328}]
04:09:27 INFO - TEST-END: test_click.py TestClick.test_clicking_on_a_multiline_link1499598567459 Marionette TRACE 358 <- [1,7,null,{"value":null}]
04:09:27 INFO - 1499598567460 Marionette TRACE 358 -> [0,8,"deleteSession",{}]
04:09:27 INFO - TEST-PASS | test_click.py TestClick.test_clicking_on_a_multiline_link | took 247ms
04:09:27 INFO - TEST-START | test_click.py TestClick.test_container_element
04:09:27 INFO - 1499598567461 Marionette TRACE 358 <- [1,8,null,{}]
04:09:27 INFO - 1499598567464 Marionette DEBUG Closed connection 358
04:09:27 INFO - 1499598567465 Marionette DEBUG Accepted connection 359 from 127.0.0.1:49786
04:09:27 INFO - 1499598567465 Marionette DEBUG Closed connection 359
04:09:27 INFO - 1499598567466 Marionette DEBUG Accepted connection 360 from 127.0.0.1:49787
04:09:27 INFO - 1499598567467 Marionette TRACE 360 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
04:09:27 INFO - 1499598567468 Marionette CONFIG Matched capabilities: {"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}
04:09:27 INFO - 1499598567471 Marionette DEBUG Register listener.js for window 12
04:09:27 INFO - 1499598567474 Marionette TRACE 360 <- [1,1,null,{"sessionId":"ddabf139-1c27-4233-85c1-210ae52abb06","capabilities":{"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}}]
04:09:27 INFO - 1499598567477 Marionette TRACE 360 -> [0,2,"setTimeouts",{"script":30000}]
04:09:27 INFO - 1499598567477 Marionette TRACE 360 <- [1,2,null,{}]
04:09:27 INFO - 1499598567478 Marionette TRACE 360 -> [0,3,"setTimeouts",{"pageLoad":300000}]
04:09:27 INFO - 1499598567479 Marionette TRACE 360 <- [1,3,null,{}]
04:09:27 INFO - 1499598567480 Marionette TRACE 360 -> [0,4,"setTimeouts",{"implicit":0}]
04:09:27 INFO - 1499598567480 Marionette TRACE 360 <- [1,4,null,{}]
04:09:27 INFO - 1499598567482 Marionette TRACE 360 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-START: test_click.py TestClick.test_container_element')","sandbox":"simpletest","line":316}]
04:09:27 INFO - TEST-START: test_click.py TestClick.test_container_element1499598567485 Marionette TRACE 360 <- [1,5,null,{"value":null}]
04:09:27 INFO - 1499598567486 Marionette TRACE 360 -> [0,6,"deleteSession",{}]
04:09:27 INFO - 1499598567488 Marionette TRACE 360 <- [1,6,null,{}]
04:09:27 INFO - 1499598567490 Marionette DEBUG Closed connection 360
04:09:27 INFO - 1499598567491 Marionette DEBUG Accepted connection 361 from 127.0.0.1:49788
04:09:27 INFO - 1499598567492 Marionette DEBUG Closed connection 361
04:09:27 INFO - 1499598567492 Marionette DEBUG Accepted connection 362 from 127.0.0.1:49789
04:09:27 INFO - 1499598567494 Marionette TRACE 362 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
04:09:27 INFO - 1499598567494 Marionette CONFIG Matched capabilities: {"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}
04:09:27 INFO - 1499598567497 Marionette DEBUG Register listener.js for window 12
04:09:27 INFO - 1499598567500 Marionette TRACE 362 <- [1,1,null,{"sessionId":"027ec0e2-b60a-45d1-a29e-3062666f610a","capabilities":{"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}}]
04:09:27 INFO - 1499598567503 Marionette TRACE 362 -> [0,2,"deleteSession",{}]
04:09:27 INFO - 1499598567504 Marionette TRACE 362 <- [1,2,null,{}]
04:09:27 INFO - 1499598567506 Marionette DEBUG Closed connection 362
04:09:27 INFO - 1499598567507 Marionette DEBUG Accepted connection 363 from 127.0.0.1:49790
04:09:27 INFO - 1499598567508 Marionette DEBUG Closed connection 363
04:09:27 INFO - 1499598567509 Marionette DEBUG Accepted connection 364 from 127.0.0.1:49791
04:09:27 INFO - 1499598567510 Marionette TRACE 364 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
04:09:27 INFO - 1499598567511 Marionette CONFIG Matched capabilities: {"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":1,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}
04:09:27 INFO - 1499598567513 Marionette DEBUG Register listener.js for window 12
04:09:27 INFO - 1499598567516 Marionette TRACE 364 <- [1,1,null,{"sessionId":"9f5b78f3-ce71-490b-970f-b3fc34345041","capabilities":{"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":1,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}}]
04:09:27 INFO - 1499598567519 Marionette TRACE 364 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"}]
04:09:27 INFO - 1499598567520 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49349/test.html"
04:09:27 INFO - 1499598567523 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49349/test.html"
04:09:27 INFO - 1499598567523 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49349/test.html"
04:09:27 INFO - 1499598567550 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
04:09:27 INFO - 1499598567556 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
04:09:27 INFO - 1499598567568 Marionette TRACE 364 <- [1,2,null,{}]
04:09:27 INFO - 1499598567571 Marionette TRACE 364 -> [0,3,"findElement",{"using":"tag name","value":"option"}]
04:09:27 INFO - 1499598567574 Marionette TRACE 364 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"7640437d-9958-4601-b86c-0ccb878371f2","ELEMENT":"7640437d-9958-4601-b86c-0ccb878371f2"}}]
04:09:27 INFO - 1499598567575 Marionette TRACE 364 -> [0,4,"clickElement",{"id":"7640437d-9958-4601-b86c-0ccb878371f2"}]
04:09:27 INFO - 1499598567819 Marionette DEBUG Canceled page load listener because no navigation has been detected
04:09:27 INFO - 1499598567821 Marionette TRACE 364 <- [1,4,null,{}]
04:09:27 INFO - 1499598567822 Marionette TRACE 364 -> [0,5,"getElementProperty",{"id":"7640437d-9958-4601-b86c-0ccb878371f2","name":"selected"}]
04:09:27 INFO - 1499598567827 Marionette TRACE 364 <- [1,5,null,{"value":true}]
04:09:27 INFO - 1499598567829 Marionette TRACE 364 -> [0,6,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-END: test_click.py TestClick.test_container_element')","sandbox":"simpletest","line":328}]
04:09:27 INFO - TEST-END: test_click.py TestClick.test_container_element1499598567832 Marionette TRACE 364 <- [1,6,null,{"value":null}]
04:09:27 INFO - 1499598567833 Marionette TRACE 364 -> [0,7,"deleteSession",{}]
04:09:27 INFO - 1499598567834 Marionette TRACE 364 <- [1,7,null,{}]
04:09:27 INFO - TEST-PASS | test_click.py TestClick.test_container_element | took 374ms
04:09:27 INFO - TEST-START | test_click.py TestClick.test_container_element_outside_view
04:09:27 INFO - 1499598567838 Marionette DEBUG Closed connection 364
04:09:27 INFO - 1499598567839 Marionette DEBUG Accepted connection 365 from 127.0.0.1:49792
04:09:27 INFO - 1499598567840 Marionette DEBUG Closed connection 365
04:09:27 INFO - 1499598567841 Marionette DEBUG Accepted connection 366 from 127.0.0.1:49793
04:09:27 INFO - 1499598567842 Marionette TRACE 366 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
04:09:27 INFO - 1499598567843 Marionette CONFIG Matched capabilities: {"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}
04:09:27 INFO - 1499598567846 Marionette DEBUG Register listener.js for window 12
04:09:27 INFO - 1499598567857 Marionette TRACE 366 <- [1,1,null,{"sessionId":"100ee619-77fb-406c-b450-c71fd18c3cbf","capabilities":{"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}}]
04:09:27 INFO - 1499598567860 Marionette TRACE 366 -> [0,2,"setTimeouts",{"script":30000}]
04:09:27 INFO - 1499598567861 Marionette TRACE 366 <- [1,2,null,{}]
04:09:27 INFO - 1499598567862 Marionette TRACE 366 -> [0,3,"setTimeouts",{"pageLoad":300000}]
04:09:27 INFO - 1499598567862 Marionette TRACE 366 <- [1,3,null,{}]
04:09:27 INFO - 1499598567871 Marionette TRACE 366 -> [0,4,"setTimeouts",{"implicit":0}]
04:09:27 INFO - 1499598567871 Marionette TRACE 366 <- [1,4,null,{}]
04:09:27 INFO - 1499598567873 Marionette TRACE 366 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-START: test_click.py TestClick.test_container_element_outside_view')","sandbox":"simpletest","line":316}]
04:09:27 INFO - TEST-START: test_click.py TestClick.test_container_element_outside_view1499598567876 Marionette TRACE 366 <- [1,5,null,{"value":null}]
04:09:27 INFO - 1499598567877 Marionette TRACE 366 -> [0,6,"deleteSession",{}]
04:09:27 INFO - 1499598567879 Marionette TRACE 366 <- [1,6,null,{}]
04:09:27 INFO - 1499598567881 Marionette DEBUG Closed connection 366
04:09:27 INFO - 1499598567882 Marionette DEBUG Accepted connection 367 from 127.0.0.1:49794
04:09:27 INFO - 1499598567883 Marionette DEBUG Closed connection 367
04:09:27 INFO - 1499598567884 Marionette DEBUG Accepted connection 368 from 127.0.0.1:49795
04:09:27 INFO - 1499598567885 Marionette TRACE 368 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
04:09:27 INFO - 1499598567885 Marionette CONFIG Matched capabilities: {"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}
04:09:27 INFO - 1499598567888 Marionette DEBUG Register listener.js for window 12
04:09:27 INFO - 1499598567892 Marionette TRACE 368 <- [1,1,null,{"sessionId":"cb2bb28d-79e1-4e06-9c18-c2644c8bfe9c","capabilities":{"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}}]
04:09:27 INFO - 1499598567894 Marionette TRACE 368 -> [0,2,"deleteSession",{}]
04:09:27 INFO - 1499598567895 Marionette TRACE 368 <- [1,2,null,{}]
04:09:27 INFO - 1499598567898 Marionette DEBUG Closed connection 368
04:09:27 INFO - 1499598567899 Marionette DEBUG Accepted connection 369 from 127.0.0.1:49796
04:09:27 INFO - 1499598567899 Marionette DEBUG Closed connection 369
04:09:27 INFO - 1499598567900 Marionette DEBUG Accepted connection 370 from 127.0.0.1:49797
04:09:27 INFO - 1499598567901 Marionette TRACE 370 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
04:09:27 INFO - 1499598567902 Marionette CONFIG Matched capabilities: {"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":1,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}
04:09:27 INFO - 1499598567905 Marionette DEBUG Register listener.js for window 12
04:09:27 INFO - 1499598567908 Marionette TRACE 370 <- [1,1,null,{"sessionId":"c1291c08-3bad-4dbc-8681-a56de504c78d","capabilities":{"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":1,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}}]
04:09:27 INFO - 1499598567910 Marionette TRACE 370 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20style%3D%22margin-top%3A%20100vh%22%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"}]
04:09:27 INFO - 1499598567912 Marionette DEBUG Received DOM event "beforeunload" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
04:09:27 INFO - 1499598567916 Marionette DEBUG Received DOM event "pagehide" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
04:09:27 INFO - 1499598567917 Marionette DEBUG Received DOM event "unload" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
04:09:27 INFO - 1499598567940 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20style%3D%22margin-top%3A%20100vh%22%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
04:09:27 INFO - 1499598567942 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20style%3D%22margin-top%3A%20100vh%22%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
04:09:27 INFO - 1499598567946 Marionette TRACE 370 <- [1,2,null,{}]
04:09:27 INFO - 1499598567948 Marionette TRACE 370 -> [0,3,"findElement",{"using":"tag name","value":"option"}]
04:09:27 INFO - 1499598567951 Marionette TRACE 370 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"e84e5e75-75fa-4147-bb5f-c024c71c227d","ELEMENT":"e84e5e75-75fa-4147-bb5f-c024c71c227d"}}]
04:09:27 INFO - 1499598567952 Marionette TRACE 370 -> [0,4,"clickElement",{"id":"e84e5e75-75fa-4147-bb5f-c024c71c227d"}]
04:09:28 INFO - 1499598568215 Marionette DEBUG Canceled page load listener because no navigation has been detected
04:09:28 INFO - 1499598568216 Marionette TRACE 370 <- [1,4,null,{}]
04:09:28 INFO - 1499598568224 Marionette TRACE 370 -> [0,5,"getElementProperty",{"id":"e84e5e75-75fa-4147-bb5f-c024c71c227d","name":"selected"}]
04:09:28 INFO - 1499598568229 Marionette TRACE 370 <- [1,5,null,{"value":true}]
04:09:28 INFO - 1499598568231 Marionette TRACE 370 -> [0,6,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-END: test_click.py TestClick.test_container_element_outside_view')","sandbox":"simpletest","line":328}]
04:09:28 INFO - TEST-END: test_click.py TestClick.test_container_element_outside_view1499598568234 Marionette TRACE 370 <- [1,6,null,{"value":null}]
04:09:28 INFO - 1499598568235 Marionette TRACE 370 -> [0,7,"deleteSession",{}]
04:09:28 INFO - 1499598568237 Marionette TRACE 370 <- [1,7,null,{}]
04:09:28 INFO - TEST-PASS | test_click.py TestClick.test_container_element_outside_view | took 400ms
04:09:28 INFO - TEST-START | test_click.py TestClick.test_css_transforms
04:09:28 INFO - 1499598568239 Marionette DEBUG Closed connection 370
04:09:28 INFO - 1499598568240 Marionette DEBUG Accepted connection 371 from 127.0.0.1:49800
04:09:28 INFO - 1499598568241 Marionette DEBUG Closed connection 371
04:09:28 INFO - 1499598568242 Marionette DEBUG Accepted connection 372 from 127.0.0.1:49801
04:09:28 INFO - 1499598568243 Marionette TRACE 372 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
04:09:28 INFO - 1499598568244 Marionette CONFIG Matched capabilities: {"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}
04:09:28 INFO - 1499598568247 Marionette DEBUG Register listener.js for window 12
04:09:28 INFO - 1499598568250 Marionette TRACE 372 <- [1,1,null,{"sessionId":"aac5e6b6-a41d-4066-9cb1-ae0667389de6","capabilities":{"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}}]
04:09:28 INFO - 1499598568252 Marionette TRACE 372 -> [0,2,"setTimeouts",{"script":30000}]
04:09:28 INFO - 1499598568253 Marionette TRACE 372 <- [1,2,null,{}]
04:09:28 INFO - 1499598568254 Marionette TRACE 372 -> [0,3,"setTimeouts",{"pageLoad":300000}]
04:09:28 INFO - 1499598568255 Marionette TRACE 372 <- [1,3,null,{}]
04:09:28 INFO - 1499598568256 Marionette TRACE 372 -> [0,4,"setTimeouts",{"implicit":0}]
04:09:28 INFO - 1499598568256 Marionette TRACE 372 <- [1,4,null,{}]
04:09:28 INFO - 1499598568258 Marionette TRACE 372 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-START: test_click.py TestClick.test_css_transforms')","sandbox":"simpletest","line":316}]
04:09:28 INFO - TEST-START: test_click.py TestClick.test_css_transforms1499598568261 Marionette TRACE 372 <- [1,5,null,{"value":null}]
04:09:28 INFO - 1499598568262 Marionette TRACE 372 -> [0,6,"deleteSession",{}]
04:09:28 INFO - 1499598568264 Marionette TRACE 372 <- [1,6,null,{}]
04:09:28 INFO - 1499598568266 Marionette DEBUG Closed connection 372
04:09:28 INFO - 1499598568267 Marionette DEBUG Accepted connection 373 from 127.0.0.1:49802
04:09:28 INFO - 1499598568268 Marionette DEBUG Closed connection 373
04:09:28 INFO - 1499598568269 Marionette DEBUG Accepted connection 374 from 127.0.0.1:49803
04:09:28 INFO - 1499598568270 Marionette TRACE 374 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
04:09:28 INFO - 1499598568271 Marionette CONFIG Matched capabilities: {"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}
04:09:28 INFO - 1499598568273 Marionette DEBUG Register listener.js for window 12
04:09:28 INFO - 1499598568277 Marionette TRACE 374 <- [1,1,null,{"sessionId":"d81464db-1dc7-405d-89f7-8b9ea82b15dc","capabilities":{"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}}]
04:09:28 INFO - 1499598568279 Marionette TRACE 374 -> [0,2,"deleteSession",{}]
04:09:28 INFO - 1499598568281 Marionette TRACE 374 <- [1,2,null,{}]
04:09:28 INFO - 1499598568283 Marionette DEBUG Closed connection 374
04:09:28 INFO - 1499598568284 Marionette DEBUG Accepted connection 375 from 127.0.0.1:49804
04:09:28 INFO - 1499598568285 Marionette DEBUG Closed connection 375
04:09:28 INFO - 1499598568286 Marionette DEBUG Accepted connection 376 from 127.0.0.1:49805
04:09:28 INFO - 1499598568287 Marionette TRACE 376 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
04:09:28 INFO - 1499598568288 Marionette CONFIG Matched capabilities: {"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":1,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}
04:09:28 INFO - 1499598568291 Marionette DEBUG Register listener.js for window 12
04:09:28 INFO - 1499598568294 Marionette TRACE 376 <- [1,1,null,{"sessionId":"b84934a5-9963-4914-9396-6ccb761d8fd5","capabilities":{"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":1,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}}]
04:09:28 INFO - 1499598568296 Marionette TRACE 376 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cstyle%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20div%20%7B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20display%3A%20block%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20background-color%3A%20blue%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20width%3A%20200px%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20height%3A%20200px%3B%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%20transform%3A%20translateX%28-105px%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/style%3E%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cdiv%3E%3C/div%3E"}]
04:09:28 INFO - 1499598568298 Marionette DEBUG Received DOM event "beforeunload" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20style%3D%22margin-top%3A%20100vh%22%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
04:09:28 INFO - 1499598568301 Marionette DEBUG Received DOM event "pagehide" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20style%3D%22margin-top%3A%20100vh%22%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
04:09:28 INFO - 1499598568301 Marionette DEBUG Received DOM event "unload" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20style%3D%22margin-top%3A%20100vh%22%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
04:09:28 INFO - 1499598568325 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cstyle%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20div%20%7B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20display%3A%20block%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20background-color%3A%20blue%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20width%3A%20200px%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20height%3A%20200px%3B%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%20transform%3A%20translateX%28-105px%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/style%3E%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cdiv%3E%3C/div%3E"
04:09:28 INFO - 1499598568328 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cstyle%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20div%20%7B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20display%3A%20block%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20background-color%3A%20blue%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20width%3A%20200px%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20height%3A%20200px%3B%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%20transform%3A%20translateX%28-105px%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/style%3E%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cdiv%3E%3C/div%3E"
04:09:28 INFO - 1499598568333 Marionette TRACE 376 <- [1,2,null,{}]
04:09:28 INFO - 1499598568334 Marionette TRACE 376 -> [0,3,"findElement",{"using":"tag name","value":"div"}]
04:09:28 INFO - 1499598568345 Marionette TRACE 376 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"5c050eee-a595-4d51-b84e-db46950d5491","ELEMENT":"5c050eee-a595-4d51-b84e-db46950d5491"}}]
04:09:28 INFO - 1499598568346 Marionette TRACE 376 -> [0,4,"clickElement",{"id":"5c050eee-a595-4d51-b84e-db46950d5491"}]
04:09:28 INFO - 1499598568588 Marionette DEBUG Canceled page load listener because no navigation has been detected
04:09:28 INFO - 1499598568590 Marionette TRACE 376 <- [1,4,null,{}]
04:09:28 INFO - 1499598568592 Marionette TRACE 376 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-END: test_click.py TestClick.test_css_transforms')","sandbox":"simpletest","line":328}]
04:09:28 INFO - TEST-END: test_click.py TestClick.test_css_transforms1499598568595 Marionette TRACE 376 <- [1,5,null,{"value":null}]
04:09:28 INFO - 1499598568596 Marionette TRACE 376 -> [0,6,"deleteSession",{}]
04:09:28 INFO - TEST-PASS | test_click.py TestClick.test_css_transforms | took 360ms
04:09:28 INFO - TEST-START | test_click.py TestClick.test_inclusive_descendant
04:09:28 INFO - 1499598568598 Marionette TRACE 376 <- [1,6,null,{}]
04:09:28 INFO - 1499598568600 Marionette DEBUG Closed connection 376
04:09:28 INFO - 1499598568601 Marionette DEBUG Accepted connection 377 from 127.0.0.1:49806
04:09:28 INFO - 1499598568602 Marionette DEBUG Closed connection 377
04:09:28 INFO - 1499598568602 Marionette DEBUG Accepted connection 378 from 127.0.0.1:49807
04:09:28 INFO - 1499598568603 Marionette TRACE 378 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
04:09:28 INFO - 1499598568604 Marionette CONFIG Matched capabilities: {"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}
04:09:28 INFO - 1499598568607 Marionette DEBUG Register listener.js for window 12
04:09:28 INFO - 1499598568610 Marionette TRACE 378 <- [1,1,null,{"sessionId":"733dc86a-131e-437c-884d-bf6012100c2b","capabilities":{"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}}]
04:09:28 INFO - 1499598568620 Marionette TRACE 378 -> [0,2,"setTimeouts",{"script":30000}]
04:09:28 INFO - 1499598568621 Marionette TRACE 378 <- [1,2,null,{}]
04:09:28 INFO - 1499598568622 Marionette TRACE 378 -> [0,3,"setTimeouts",{"pageLoad":300000}]
04:09:28 INFO - 1499598568622 Marionette TRACE 378 <- [1,3,null,{}]
04:09:28 INFO - 1499598568623 Marionette TRACE 378 -> [0,4,"setTimeouts",{"implicit":0}]
04:09:28 INFO - 1499598568624 Marionette TRACE 378 <- [1,4,null,{}]
04:09:28 INFO - 1499598568625 Marionette TRACE 378 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-START: test_click.py TestClick.test_inclusive_descendant')","sandbox":"simpletest","line":316}]
04:09:28 INFO - TEST-START: test_click.py TestClick.test_inclusive_descendant1499598568629 Marionette TRACE 378 <- [1,5,null,{"value":null}]
04:09:28 INFO - 1499598568630 Marionette TRACE 378 -> [0,6,"deleteSession",{}]
04:09:28 INFO - 1499598568631 Marionette TRACE 378 <- [1,6,null,{}]
04:09:28 INFO - 1499598568633 Marionette DEBUG Closed connection 378
04:09:28 INFO - 1499598568634 Marionette DEBUG Accepted connection 379 from 127.0.0.1:49808
04:09:28 INFO - 1499598568635 Marionette DEBUG Closed connection 379
04:09:28 INFO - 1499598568636 Marionette DEBUG Accepted connection 380 from 127.0.0.1:49809
04:09:28 INFO - 1499598568637 Marionette TRACE 380 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
04:09:28 INFO - 1499598568638 Marionette CONFIG Matched capabilities: {"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}
04:09:28 INFO - 1499598568641 Marionette DEBUG Register listener.js for window 12
04:09:28 INFO - 1499598568644 Marionette TRACE 380 <- [1,1,null,{"sessionId":"767f4ca7-ad07-4139-beb1-8f2f725acfcb","capabilities":{"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}}]
04:09:28 INFO - 1499598568646 Marionette TRACE 380 -> [0,2,"deleteSession",{}]
04:09:28 INFO - 1499598568647 Marionette TRACE 380 <- [1,2,null,{}]
04:09:28 INFO - 1499598568650 Marionette DEBUG Closed connection 380
04:09:28 INFO - 1499598568650 Marionette DEBUG Accepted connection 381 from 127.0.0.1:49810
04:09:28 INFO - 1499598568651 Marionette DEBUG Closed connection 381
04:09:28 INFO - 1499598568652 Marionette DEBUG Accepted connection 382 from 127.0.0.1:49811
04:09:28 INFO - 1499598568654 Marionette TRACE 382 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
04:09:28 INFO - 1499598568655 Marionette CONFIG Matched capabilities: {"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":1,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}
04:09:28 INFO - 1499598568658 Marionette DEBUG Register listener.js for window 12
04:09:28 INFO - 1499598568662 Marionette TRACE 382 <- [1,1,null,{"sessionId":"fbd00dd4-bc8e-447e-a361-e77410f48611","capabilities":{"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":1,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}}]
04:09:28 INFO - 1499598568664 Marionette TRACE 382 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20multiple%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efirst%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Esecond%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Ethird%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"}]
04:09:28 INFO - 1499598568666 Marionette DEBUG Received DOM event "beforeunload" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cstyle%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20div%20%7B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20display%3A%20block%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20background-color%3A%20blue%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20width%3A%20200px%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20height%3A%20200px%3B%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%20transform%3A%20translateX%28-105px%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/style%3E%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cdiv%3E%3C/div%3E"
04:09:28 INFO - 1499598568668 Marionette DEBUG Received DOM event "pagehide" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cstyle%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20div%20%7B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20display%3A%20block%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20background-color%3A%20blue%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20width%3A%20200px%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20height%3A%20200px%3B%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%20transform%3A%20translateX%28-105px%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/style%3E%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cdiv%3E%3C/div%3E"
04:09:28 INFO - 1499598568669 Marionette DEBUG Received DOM event "unload" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cstyle%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20div%20%7B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20display%3A%20block%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20background-color%3A%20blue%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20width%3A%20200px%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20height%3A%20200px%3B%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%20transform%3A%20translateX%28-105px%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/style%3E%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cdiv%3E%3C/div%3E"
04:09:28 INFO - 1499598568692 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20multiple%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efirst%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Esecond%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Ethird%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
04:09:28 INFO - 1499598568694 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20multiple%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efirst%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Esecond%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Ethird%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
04:09:28 INFO - 1499598568697 Marionette TRACE 382 <- [1,2,null,{}]
04:09:28 INFO - 1499598568699 Marionette TRACE 382 -> [0,3,"findElement",{"using":"tag name","value":"select"}]
04:09:28 INFO - 1499598568702 Marionette TRACE 382 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"1e0c1649-ef39-46e8-b421-d9e43e112e05","ELEMENT":"1e0c1649-ef39-46e8-b421-d9e43e112e05"}}]
04:09:28 INFO - 1499598568711 Marionette TRACE 382 -> [0,4,"clickElement",{"id":"1e0c1649-ef39-46e8-b421-d9e43e112e05"}]
04:09:28 INFO - 1499598568957 Marionette DEBUG Canceled page load listener because no navigation has been detected
04:09:28 INFO - 1499598568958 Marionette TRACE 382 <- [1,4,null,{}]
04:09:29 INFO - 1499598569009 Marionette TRACE 382 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-END: test_click.py TestClick.test_inclusive_descendant')","sandbox":"simpletest","line":328}]
04:09:29 INFO - TEST-END: test_click.py TestClick.test_inclusive_descendant1499598569012 Marionette TRACE 382 <- [1,5,null,{"value":null}]
04:09:29 INFO - TEST-PASS | test_click.py TestClick.test_inclusive_descendant | took 421ms
04:09:29 INFO - TEST-START | test_click.py TestClick.test_input_file
04:09:29 INFO - 1499598569017 Marionette TRACE 382 -> [0,6,"deleteSession",{}]
04:09:29 INFO - 1499598569018 Marionette TRACE 382 <- [1,6,null,{}]
04:09:29 INFO - 1499598569028 Marionette DEBUG Closed connection 382
04:09:29 INFO - 1499598569029 Marionette DEBUG Accepted connection 383 from 127.0.0.1:49812
04:09:29 INFO - 1499598569030 Marionette DEBUG Closed connection 383
04:09:29 INFO - 1499598569031 Marionette DEBUG Accepted connection 384 from 127.0.0.1:49813
04:09:29 INFO - 1499598569032 Marionette TRACE 384 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
04:09:29 INFO - 1499598569033 Marionette CONFIG Matched capabilities: {"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}
04:09:29 INFO - 1499598569036 Marionette DEBUG Register listener.js for window 12
04:09:29 INFO - 1499598569039 Marionette TRACE 384 <- [1,1,null,{"sessionId":"41e2be67-2e10-4060-8a24-8e3ea921c139","capabilities":{"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}}]
04:09:29 INFO - 1499598569041 Marionette TRACE 384 -> [0,2,"setTimeouts",{"script":30000}]
04:09:29 INFO - 1499598569042 Marionette TRACE 384 <- [1,2,null,{}]
04:09:29 INFO - 1499598569043 Marionette TRACE 384 -> [0,3,"setTimeouts",{"pageLoad":300000}]
04:09:29 INFO - 1499598569044 Marionette TRACE 384 <- [1,3,null,{}]
04:09:29 INFO - 1499598569045 Marionette TRACE 384 -> [0,4,"setTimeouts",{"implicit":0}]
04:09:29 INFO - 1499598569045 Marionette TRACE 384 <- [1,4,null,{}]
04:09:29 INFO - 1499598569047 Marionette TRACE 384 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-START: test_click.py TestClick.test_input_file')","sandbox":"simpletest","line":316}]
04:09:29 INFO - TEST-START: test_click.py TestClick.test_input_file1499598569050 Marionette TRACE 384 <- [1,5,null,{"value":null}]
04:09:29 INFO - 1499598569051 Marionette TRACE 384 -> [0,6,"deleteSession",{}]
04:09:29 INFO - 1499598569052 Marionette TRACE 384 <- [1,6,null,{}]
04:09:29 INFO - 1499598569055 Marionette DEBUG Closed connection 384
04:09:29 INFO - 1499598569056 Marionette DEBUG Accepted connection 385 from 127.0.0.1:49814
04:09:29 INFO - 1499598569056 Marionette DEBUG Closed connection 385
04:09:29 INFO - 1499598569057 Marionette DEBUG Accepted connection 386 from 127.0.0.1:49815
04:09:29 INFO - 1499598569058 Marionette TRACE 386 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
04:09:29 INFO - 1499598569059 Marionette CONFIG Matched capabilities: {"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}
04:09:29 INFO - 1499598569062 Marionette DEBUG Register listener.js for window 12
04:09:29 INFO - 1499598569065 Marionette TRACE 386 <- [1,1,null,{"sessionId":"cfff53f9-0f5b-422b-8603-264fe060527a","capabilities":{"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}}]
04:09:29 INFO - 1499598569068 Marionette TRACE 386 -> [0,2,"deleteSession",{}]
04:09:29 INFO - 1499598569069 Marionette TRACE 386 <- [1,2,null,{}]
04:09:29 INFO - 1499598569071 Marionette DEBUG Closed connection 386
04:09:29 INFO - 1499598569072 Marionette DEBUG Accepted connection 387 from 127.0.0.1:49816
04:09:29 INFO - 1499598569073 Marionette DEBUG Closed connection 387
04:09:29 INFO - 1499598569124 Marionette DEBUG Accepted connection 388 from 127.0.0.1:49817
04:09:29 INFO - 1499598569126 Marionette TRACE 388 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
04:09:29 INFO - 1499598569129 Marionette CONFIG Matched capabilities: {"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":1,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}
04:09:29 INFO - 1499598569132 Marionette DEBUG Register listener.js for window 12
04:09:29 INFO - 1499598569140 Marionette TRACE 388 <- [1,1,null,{"sessionId":"d9352f19-a46c-4f07-a4ae-d8ad099f04b9","capabilities":{"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":1,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}}]
04:09:29 INFO - 1499598569153 Marionette TRACE 388 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"}]
04:09:29 INFO - 1499598569155 Marionette DEBUG Received DOM event "beforeunload" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20multiple%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efirst%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Esecond%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Ethird%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
04:09:29 INFO - 1499598569159 Marionette DEBUG Received DOM event "pagehide" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20multiple%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efirst%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Esecond%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Ethird%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
04:09:29 INFO - 1499598569160 Marionette DEBUG Received DOM event "unload" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20multiple%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efirst%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Esecond%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Ethird%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
04:09:29 INFO - 1499598569184 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
04:09:29 INFO - 1499598569192 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
04:09:29 INFO - 1499598569199 Marionette TRACE 388 <- [1,2,null,{}]
04:09:29 INFO - 1499598569201 Marionette TRACE 388 -> [0,3,"findElement",{"using":"tag name","value":"input"}]
04:09:29 INFO - 1499598569214 Marionette TRACE 388 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"18fdfbbb-c44e-4e39-bba1-6c72162e9f6f","ELEMENT":"18fdfbbb-c44e-4e39-bba1-6c72162e9f6f"}}]
04:09:29 INFO - 1499598569215 Marionette TRACE 388 -> [0,4,"clickElement",{"id":"18fdfbbb-c44e-4e39-bba1-6c72162e9f6f"}]
04:09:29 INFO - 1499598569251 Marionette TRACE 388 <- [1,4,{"error":"invalid argument","message":"Cannot click
elements","stacktrace":"WebDriverError@chrome://marionette/content/error.js:226:5\nInvalidArgumentError@chrome://marionette/content/error.js:329:5\nwebdriverClickElement@chrome://marionette/content/interaction.js:165:11\nTaskImpl_run@resource://gre/modules/Task.jsm:331:42\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nTaskImpl_handleResultValue@resource://gre/modules/Task.jsm:401:16\nTaskImpl_run@resource://gre/modules/Task.jsm:339:15\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nTaskImpl_handleResultValue@resource://gre/modules/Task.jsm:401:16\nTaskImpl_run@resource://gre/modules/Task.jsm:339:15\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nnavigate@chrome://marionette/content/listener.js:392:12\nclickElement@chrome://marionette/content/listener.js:1312:5\n"},null]
04:09:29 INFO - 1499598569317 Marionette TRACE 388 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-END: test_click.py TestClick.test_input_file')","sandbox":"simpletest","line":328}]
04:09:29 INFO - TEST-END: test_click.py TestClick.test_input_file1499598569321 Marionette TRACE 388 <- [1,5,null,{"value":null}]
04:09:29 INFO - 1499598569323 Marionette TRACE 388 -> [0,6,"deleteSession",{}]
04:09:29 INFO - 1499598569327 Marionette TRACE 388 <- [1,6,null,{}]
04:09:29 INFO - TEST-PASS | test_click.py TestClick.test_input_file | took 308ms
04:09:29 INFO - TEST-START | test_click.py TestClick.test_obscured_element
04:09:29 INFO - 1499598569330 Marionette DEBUG Closed connection 388
04:09:29 INFO - 1499598569331 Marionette DEBUG Accepted connection 389 from 127.0.0.1:49818
04:09:29 INFO - 1499598569333 Marionette DEBUG Closed connection 389
04:09:29 INFO - 1499598569334 Marionette DEBUG Accepted connection 390 from 127.0.0.1:49819
04:09:29 INFO - 1499598569377 Marionette TRACE 390 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
04:09:29 INFO - 1499598569380 Marionette CONFIG Matched capabilities: {"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}
04:09:29 INFO - 1499598569385 Marionette DEBUG Register listener.js for window 12
04:09:29 INFO - 1499598569392 Marionette TRACE 390 <- [1,1,null,{"sessionId":"2c4b2dde-2def-4619-89e5-55936ca4c0be","capabilities":{"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}}]
04:09:29 INFO - 1499598569401 Marionette TRACE 390 -> [0,2,"setTimeouts",{"script":30000}]
04:09:29 INFO - 1499598569402 Marionette TRACE 390 <- [1,2,null,{}]
04:09:29 INFO - 1499598569420 Marionette TRACE 390 -> [0,3,"setTimeouts",{"pageLoad":300000}]
04:09:29 INFO - 1499598569421 Marionette TRACE 390 <- [1,3,null,{}]
04:09:29 INFO - 1499598569423 Marionette TRACE 390 -> [0,4,"setTimeouts",{"implicit":0}]
04:09:29 INFO - 1499598569424 Marionette TRACE 390 <- [1,4,null,{}]
04:09:29 INFO - 1499598569433 Marionette TRACE 390 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-START: test_click.py TestClick.test_obscured_element')","sandbox":"simpletest","line":316}]
04:09:29 INFO - TEST-START: test_click.py TestClick.test_obscured_element1499598569439 Marionette TRACE 390 <- [1,5,null,{"value":null}]
04:09:29 INFO - 1499598569441 Marionette TRACE 390 -> [0,6,"deleteSession",{}]
04:09:29 INFO - 1499598569443 Marionette TRACE 390 <- [1,6,null,{}]
04:09:29 INFO - 1499598569464 Marionette DEBUG Closed connection 390
04:09:29 INFO - 1499598569465 Marionette DEBUG Accepted connection 391 from 127.0.0.1:49820
04:09:29 INFO - 1499598569467 Marionette DEBUG Closed connection 391
04:09:29 INFO - 1499598569468 Marionette DEBUG Accepted connection 392 from 127.0.0.1:49821
04:09:29 INFO - 1499598569470 Marionette TRACE 392 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
04:09:29 INFO - 1499598569471 Marionette CONFIG Matched capabilities: {"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}
04:09:29 INFO - 1499598569474 Marionette DEBUG Register listener.js for window 12
04:09:29 INFO - 1499598569479 Marionette TRACE 392 <- [1,1,null,{"sessionId":"83172f89-ecb4-4233-9806-418d6fc1d7e8","capabilities":{"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}}]
04:09:29 INFO - 1499598569483 Marionette TRACE 392 -> [0,2,"deleteSession",{}]
04:09:29 INFO - 1499598569485 Marionette TRACE 392 <- [1,2,null,{}]
04:09:29 INFO - 1499598569488 Marionette DEBUG Closed connection 392
04:09:29 INFO - 1499598569489 Marionette DEBUG Accepted connection 393 from 127.0.0.1:49822
04:09:29 INFO - 1499598569525 Marionette DEBUG Closed connection 393
04:09:29 INFO - 1499598569526 Marionette DEBUG Accepted connection 394 from 127.0.0.1:49823
04:09:29 INFO - 1499598569529 Marionette TRACE 394 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
04:09:29 INFO - 1499598569531 Marionette CONFIG Matched capabilities: {"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":1,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}
04:09:29 INFO - 1499598569534 Marionette DEBUG Register listener.js for window 12
04:09:29 INFO - 1499598569539 Marionette TRACE 394 <- [1,1,null,{"sessionId":"230a198e-67eb-42c1-b160-85ea9a5b753a","capabilities":{"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":1,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}}]
04:09:29 INFO - 1499598569543 Marionette TRACE 394 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%0A%3Cstyle%3E%0A%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0Abody%20%7B%20height%3A%20100vh%20%7D%0A%23overlay%20%7B%0A%20%20background-color%3A%20pink%3B%0A%20%20position%3A%20absolute%3B%0A%20%20width%3A%20100%25%3B%0A%20%20height%3A%20100%25%3B%0A%7D%0A%3C/style%3E%0A%0A%3Cdiv%20id%3Doverlay%3E%3C/div%3E%0A%3Ca%20id%3Dobscured%20href%3D%23%3Elink%3C/a%3E%0A%0A%3Cscript%3E%0Awindow.clicked%20%3D%20false%3B%0A%0Alet%20link%20%3D%20document.querySelector%28%22%23obscured%22%29%3B%0Alink.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%3C/script%3E%0A"}]
04:09:29 INFO - 1499598569545 Marionette DEBUG Received DOM event "beforeunload" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
04:09:29 INFO - 1499598569549 Marionette DEBUG Received DOM event "pagehide" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
04:09:29 INFO - 1499598569549 Marionette DEBUG Received DOM event "unload" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
04:09:29 INFO - 1499598569578 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%0A%3Cstyle%3E%0A%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0Abody%20%7B%20height%3A%20100vh%20%7D%0A%23overlay%20%7B%0A%20%20background-color%3A%20pink%3B%0A%20%20position%3A%20absolute%3B%0A%20%20width%3A%20100%25%3B%0A%20%20height%3A%20100%25%3B%0A%7D%0A%3C/style%3E%0A%0A%3Cdiv%20id%3Doverlay%3E%3C/div%3E%0A%3Ca%20id%3Dobscured%20href%3D%23%3Elink%3C/a%3E%0A%0A%3Cscript%3E%0Awindow.clicked%20%3D%20false%3B%0A%0Alet%20link%20%3D%20document.querySelector%28%22%23obscured%22%29%3B%0Alink.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%3C/script%3E%0A"
04:09:29 INFO - 1499598569581 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%0A%3Cstyle%3E%0A%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0Abody%20%7B%20height%3A%20100vh%20%7D%0A%23overlay%20%7B%0A%20%20background-color%3A%20pink%3B%0A%20%20position%3A%20absolute%3B%0A%20%20width%3A%20100%25%3B%0A%20%20height%3A%20100%25%3B%0A%7D%0A%3C/style%3E%0A%0A%3Cdiv%20id%3Doverlay%3E%3C/div%3E%0A%3Ca%20id%3Dobscured%20href%3D%23%3Elink%3C/a%3E%0A%0A%3Cscript%3E%0Awindow.clicked%20%3D%20false%3B%0A%0Alet%20link%20%3D%20document.querySelector%28%22%23obscured%22%29%3B%0Alink.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%3C/script%3E%0A"
04:09:29 INFO - 1499598569587 Marionette TRACE 394 <- [1,2,null,{}]
04:09:29 INFO - 1499598569596 Marionette TRACE 394 -> [0,3,"findElement",{"using":"id","value":"overlay"}]
04:09:29 INFO - 1499598569600 Marionette TRACE 394 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"6e2b7d25-e14f-49a9-acec-f3dd89cddfbd","ELEMENT":"6e2b7d25-e14f-49a9-acec-f3dd89cddfbd"}}]
04:09:29 INFO - 1499598569601 Marionette TRACE 394 -> [0,4,"findElement",{"using":"id","value":"obscured"}]
04:09:29 INFO - 1499598569605 Marionette TRACE 394 <- [1,4,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"c1297480-7def-4550-af43-4453379fdecb","ELEMENT":"c1297480-7def-4550-af43-4453379fdecb"}}]
04:09:29 INFO - 1499598569611 Marionette TRACE 394 -> [0,5,"clickElement",{"id":"6e2b7d25-e14f-49a9-acec-f3dd89cddfbd"}]
04:09:29 INFO - 1499598569857 Marionette DEBUG Canceled page load listener because no navigation has been detected
04:09:29 INFO - 1499598569858 Marionette TRACE 394 <- [1,5,null,{}]
04:09:29 INFO - 1499598569860 Marionette TRACE 394 -> [0,6,"clickElement",{"id":"c1297480-7def-4550-af43-4453379fdecb"}]
04:09:29 INFO - 1499598569880 Marionette TRACE 394 <- [1,6,{"error":"element click intercepted","message":"Element
is not clickable at point (10.5,10) because another element obscures it","stacktrace":"WebDriverError@chrome://marionette/content/error.js:226:5\nElementClickInterceptedError@chrome://marionette/content/error.js:308:5\nwebdriverClickElement@chrome://marionette/content/interaction.js:192:11\nTaskImpl_run@resource://gre/modules/Task.jsm:331:42\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nTaskImpl_handleResultValue@resource://gre/modules/Task.jsm:401:16\nTaskImpl_run@resource://gre/modules/Task.jsm:339:15\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nTaskImpl_handleResultValue@resource://gre/modules/Task.jsm:401:16\nTaskImpl_run@resource://gre/modules/Task.jsm:339:15\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nnavigate@chrome://marionette/content/listener.js:392:12\nclickElement@chrome://marionette/content/listener.js:1312:5\n"},null]
04:09:29 INFO - 1499598569882 Marionette TRACE 394 -> [0,7,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"test_click.py","script":"return window.clicked","sandbox":null,"line":257}]
04:09:29 INFO - 1499598569887 Marionette TRACE 394 <- [1,7,null,{"value":false}]
04:09:29 INFO - 1499598569889 Marionette TRACE 394 -> [0,8,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-END: test_click.py TestClick.test_obscured_element')","sandbox":"simpletest","line":328}]
04:09:29 INFO - TEST-END: test_click.py TestClick.test_obscured_element1499598569892 Marionette TRACE 394 <- [1,8,null,{"value":null}]
04:09:29 INFO - 1499598569893 Marionette TRACE 394 -> [0,9,"deleteSession",{}]
04:09:29 INFO - 1499598569895 Marionette TRACE 394 <- [1,9,null,{}]
04:09:29 INFO - TEST-PASS | test_click.py TestClick.test_obscured_element | took 568ms
04:09:29 INFO - TEST-START | test_click.py TestClick.test_pointer_events_none
04:09:29 INFO - 1499598569898 Marionette DEBUG Closed connection 394
04:09:29 INFO - 1499598569899 Marionette DEBUG Accepted connection 395 from 127.0.0.1:49824
04:09:29 INFO - 1499598569900 Marionette DEBUG Closed connection 395
04:09:29 INFO - 1499598569901 Marionette DEBUG Accepted connection 396 from 127.0.0.1:49825
04:09:29 INFO - 1499598569903 Marionette TRACE 396 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
04:09:29 INFO - 1499598569904 Marionette CONFIG Matched capabilities: {"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}
04:09:29 INFO - 1499598569907 Marionette DEBUG Register listener.js for window 12
04:09:29 INFO - 1499598569911 Marionette TRACE 396 <- [1,1,null,{"sessionId":"7a9ca6a9-4d91-40d6-9e90-7441b93a049e","capabilities":{"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}}]
04:09:29 INFO - 1499598569914 Marionette TRACE 396 -> [0,2,"setTimeouts",{"script":30000}]
04:09:29 INFO - 1499598569914 Marionette TRACE 396 <- [1,2,null,{}]
04:09:29 INFO - 1499598569915 Marionette TRACE 396 -> [0,3,"setTimeouts",{"pageLoad":300000}]
04:09:29 INFO - 1499598569916 Marionette TRACE 396 <- [1,3,null,{}]
04:09:29 INFO - 1499598569917 Marionette TRACE 396 -> [0,4,"setTimeouts",{"implicit":0}]
04:09:29 INFO - 1499598569918 Marionette TRACE 396 <- [1,4,null,{}]
04:09:29 INFO - 1499598569920 Marionette TRACE 396 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-START: test_click.py TestClick.test_pointer_events_none')","sandbox":"simpletest","line":316}]
04:09:29 INFO - TEST-START: test_click.py TestClick.test_pointer_events_none1499598569923 Marionette TRACE 396 <- [1,5,null,{"value":null}]
04:09:29 INFO - 1499598569924 Marionette TRACE 396 -> [0,6,"deleteSession",{}]
04:09:29 INFO - 1499598569926 Marionette TRACE 396 <- [1,6,null,{}]
04:09:29 INFO - 1499598569928 Marionette DEBUG Closed connection 396
04:09:29 INFO - 1499598569929 Marionette DEBUG Accepted connection 397 from 127.0.0.1:49826
04:09:29 INFO - 1499598569930 Marionette DEBUG Closed connection 397
04:09:29 INFO - 1499598569931 Marionette DEBUG Accepted connection 398 from 127.0.0.1:49827
04:09:29 INFO - 1499598569932 Marionette TRACE 398 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
04:09:29 INFO - 1499598569934 Marionette CONFIG Matched capabilities: {"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}
04:09:29 INFO - 1499598569937 Marionette DEBUG Register listener.js for window 12
04:09:29 INFO - 1499598569942 Marionette TRACE 398 <- [1,1,null,{"sessionId":"f1577ccf-ef52-4653-87c7-20f05e96b22c","capabilities":{"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}}]
04:09:29 INFO - 1499598569944 Marionette TRACE 398 -> [0,2,"deleteSession",{}]
04:09:29 INFO - 1499598569946 Marionette TRACE 398 <- [1,2,null,{}]
04:09:29 INFO - 1499598569949 Marionette DEBUG Closed connection 398
04:09:29 INFO - 1499598569951 Marionette DEBUG Accepted connection 399 from 127.0.0.1:49828
04:09:29 INFO - 1499598569953 Marionette DEBUG Closed connection 399
04:09:29 INFO - 1499598569954 Marionette DEBUG Accepted connection 400 from 127.0.0.1:49829
04:09:29 INFO - 1499598569955 Marionette TRACE 400 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
04:09:29 INFO - 1499598569956 Marionette CONFIG Matched capabilities: {"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":1,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}
04:09:29 INFO - 1499598569959 Marionette DEBUG Register listener.js for window 12
04:09:29 INFO - 1499598569963 Marionette TRACE 400 <- [1,1,null,{"sessionId":"7d2dfe6a-083c-4163-a721-03716495ae2a","capabilities":{"browserName":"firefox","browserVersion":"56.0a1","platformName":"windows_nt","platformVersion":"6.1","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":1,"moz:processID":3464,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp94h64h.mozrunner","moz:accessibilityChecks":false}}]
04:09:29 INFO - 1499598569966 Marionette TRACE 400 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cbutton%20style%3D%22pointer-events%3A%20none%22%3Eclick%20me%3C/button%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cscript%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20window.clicked%20%3D%20false%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20let%20button%20%3D%20document.querySelector%28%22button%22%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20button.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/script%3E%0A%20%20%20%20%20%20%20%20"}]
04:09:29 INFO - 1499598569970 Marionette DEBUG Received DOM event "beforeunload" for "data:text/html;charset=utf-8,%0A%3Cstyle%3E%0A%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0Abody%20%7B%20height%3A%20100vh%20%7D%0A%23overlay%20%7B%0A%20%20background-color%3A%20pink%3B%0A%20%20position%3A%20absolute%3B%0A%20%20width%3A%20100%25%3B%0A%20%20height%3A%20100%25%3B%0A%7D%0A%3C/style%3E%0A%0A%3Cdiv%20id%3Doverlay%3E%3C/div%3E%0A%3Ca%20id%3Dobscured%20href%3D%23%3Elink%3C/a%3E%0A%0A%3Cscript%3E%0Awindow.clicked%20%3D%20false%3B%0A%0Alet%20link%20%3D%20document.querySelector%28%22%23obscured%22%29%3B%0Alink.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%3C/script%3E%0A"
04:09:29 INFO - 1499598569974 Marionette DEBUG Received DOM event "pagehide" for "data:text/html;charset=utf-8,%0A%3Cstyle%3E%0A%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0Abody%20%7B%20height%3A%20100vh%20%7D%0A%23overlay%20%7B%0A%20%20background-color%3A%20pink%3B%0A%20%20position%3A%20absolute%3B%0A%20%20width%3A%20100%25%3B%0A%20%20height%3A%20100%25%3B%0A%7D%0A%3C/style%3E%0A%0A%3Cdiv%20id%3Doverlay%3E%3C/div%3E%0A%3Ca%20id%3Dobscured%20href%3D%23%3Elink%3C/a%3E%0A%0A%3Cscript%3E%0Awindow.clicked%20%3D%20false%3B%0A%0Alet%20link%20%3D%20document.querySelector%28%22%23obscured%22%29%3B%0Alink.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%3C/script%3E%0A"
04:09:29 INFO - 1499598569974 Marionette DEBUG Received DOM event "unload" for "data:text/html;charset=utf-8,%0A%3Cstyle%3E%0A%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0Abody%20%7B%20height%3A%20100vh%20%7D%0A%23overlay%20%7B%0A%20%20background-color%3A%20pink%3B%0A%20%20position%3A%20absolute%3B%0A%20%20width%3A%20100%25%3B%0A%20%20height%3A%20100%25%3B%0A%7D%0A%3C/style%3E%0A%0A%3Cdiv%20id%3Doverlay%3E%3C/div%3E%0A%3Ca%20id%3Dobscured%20href%3D%23%3Elink%3C/a%3E%0A%0A%3Cscript%3E%0Awindow.clicked%20%3D%20false%3B%0A%0Alet%20link%20%3D%20document.querySelector%28%22%23obscured%22%29%3B%0Alink.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%3C/script%3E%0A"
04:09:30 INFO - 1499598570000 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cbutton%20style%3D%22pointer-events%3A%20none%22%3Eclick%20me%3C/button%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cscript%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20window.clicked%20%3D%20false%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20let%20button%20%3D%20document.querySelector%28%22button%22%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20button.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/script%3E%0A%20%20%20%20%20%20%20%20"
04:09:30 INFO - 1499598570003 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cbutton%20style%3D%22pointer-events%3A%20none%22%3Eclick%20me%3C/button%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cscript%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20window.clicked%20%3D%20false%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20let%20button%20%3D%20document.querySelector%28%22button%22%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20button.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/script%3E%0A%20%20%20%20%20%20%20%20"
04:09:30 INFO - 1499598570016 Marionette TRACE 400 <- [1,2,null,{}]
04:09:30 INFO - 1499598570018 Marionette TRACE 400 -> [0,3,"findElement",{"using":"tag name","value":"button"}]
04:09:30 INFO - 1499598570022 Marionette TRACE 400 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"997a01f1-0d7e-46d2-a148-f652994e13de","ELEMENT":"997a01f1-0d7e-46d2-a148-f652994e13de"}}]
04:09:30 INFO - 1499598570023 Marionette TRACE 400 -> [0,4,"getElementValueOfCssProperty",{"propertyName":"pointer-events","id":"997a01f1-0d7e-46d2-a148-f652994e13de"}]
04:09:30 INFO - 1499598570047 Marionette TRACE 400 <- [1,4,null,{"value":"none"}]
04:09:30 INFO - 1499598570048 Marionette TRACE 400 -> [0,5,"clickElement",{"id":"997a01f1-0d7e-46d2-a148-f652994e13de"}]
04:09:30 INFO - 1499598570067 Marionette TRACE 400 <- [1,5,{"error":"element click intercepted","message":"Element