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]
13:25:18 INFO - 1499718318490 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}]
13:25:18 INFO - TEST-END: test_click.py TestClick.test_clicking_an_element_that_is_not_displayed_raises1499718318495 Marionette TRACE 352 <- [1,5,null,{"value":null}]
13:25:18 INFO - 1499718318496 Marionette TRACE 352 -> [0,6,"deleteSession",{}]
13:25:18 INFO - 1499718318498 Marionette TRACE 352 <- [1,6,null,{}]
13:25:18 INFO - TEST-PASS | test_click.py TestClick.test_clicking_an_element_that_is_not_displayed_raises | took 214ms
13:25:18 INFO - TEST-START | test_click.py TestClick.test_clicking_on_a_multiline_link
13:25:18 INFO - 1499718318502 Marionette DEBUG Closed connection 352
13:25:18 INFO - 1499718318503 Marionette DEBUG Accepted connection 353 from 127.0.0.1:49857
13:25:18 INFO - 1499718318504 Marionette DEBUG Closed connection 353
13:25:18 INFO - 1499718318504 Marionette DEBUG Accepted connection 354 from 127.0.0.1:49858
13:25:18 INFO - 1499718318506 Marionette TRACE 354 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
13:25:18 INFO - 1499718318506 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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}
13:25:18 INFO - 1499718318509 Marionette DEBUG Register listener.js for window 12
13:25:18 INFO - 1499718318513 Marionette TRACE 354 <- [1,1,null,{"sessionId":"837fd22f-ee1e-40e5-80ab-539d6cc6685b","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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}}]
13:25:18 INFO - 1499718318515 Marionette TRACE 354 -> [0,2,"setTimeouts",{"script":30000}]
13:25:18 INFO - 1499718318516 Marionette TRACE 354 <- [1,2,null,{}]
13:25:18 INFO - 1499718318517 Marionette TRACE 354 -> [0,3,"setTimeouts",{"pageLoad":300000}]
13:25:18 INFO - 1499718318517 Marionette TRACE 354 <- [1,3,null,{}]
13:25:18 INFO - 1499718318518 Marionette TRACE 354 -> [0,4,"setTimeouts",{"implicit":0}]
13:25:18 INFO - 1499718318519 Marionette TRACE 354 <- [1,4,null,{}]
13:25:18 INFO - 1499718318521 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}]
13:25:18 INFO - TEST-START: test_click.py TestClick.test_clicking_on_a_multiline_link1499718318524 Marionette TRACE 354 <- [1,5,null,{"value":null}]
13:25:18 INFO - 1499718318525 Marionette TRACE 354 -> [0,6,"deleteSession",{}]
13:25:18 INFO - 1499718318527 Marionette TRACE 354 <- [1,6,null,{}]
13:25:18 INFO - 1499718318529 Marionette DEBUG Closed connection 354
13:25:18 INFO - 1499718318530 Marionette DEBUG Accepted connection 355 from 127.0.0.1:49859
13:25:18 INFO - 1499718318531 Marionette DEBUG Closed connection 355
13:25:18 INFO - 1499718318532 Marionette DEBUG Accepted connection 356 from 127.0.0.1:49860
13:25:18 INFO - 1499718318533 Marionette TRACE 356 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
13:25:18 INFO - 1499718318534 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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}
13:25:18 INFO - 1499718318537 Marionette DEBUG Register listener.js for window 12
13:25:18 INFO - 1499718318540 Marionette TRACE 356 <- [1,1,null,{"sessionId":"d253d73a-c071-4d1e-adfc-a64a57c30c52","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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}}]
13:25:18 INFO - 1499718318543 Marionette TRACE 356 -> [0,2,"deleteSession",{}]
13:25:18 INFO - 1499718318544 Marionette TRACE 356 <- [1,2,null,{}]
13:25:18 INFO - 1499718318548 Marionette DEBUG Closed connection 356
13:25:18 INFO - 1499718318549 Marionette DEBUG Accepted connection 357 from 127.0.0.1:49861
13:25:18 INFO - 1499718318550 Marionette DEBUG Closed connection 357
13:25:18 INFO - 1499718318550 Marionette DEBUG Accepted connection 358 from 127.0.0.1:49862
13:25:18 INFO - 1499718318552 Marionette TRACE 358 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
13:25:18 INFO - 1499718318552 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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}
13:25:18 INFO - 1499718318555 Marionette DEBUG Register listener.js for window 12
13:25:18 INFO - 1499718318559 Marionette TRACE 358 <- [1,1,null,{"sessionId":"f296c872-ff55-40eb-8b0a-0de39254bd3d","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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}}]
13:25:18 INFO - 1499718318561 Marionette TRACE 358 -> [0,2,"get",{"url":"http://127.0.0.1:49427/clicks.html"}]
13:25:18 INFO - 1499718318563 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49427/hidden.html"
13:25:18 INFO - 1499718318570 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49427/hidden.html"
13:25:18 INFO - 1499718318570 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49427/hidden.html"
13:25:18 INFO - 1499718318599 Marionette DEBUG Received DOM event "DOMContentLoaded" for "http://127.0.0.1:49427/clicks.html"
13:25:18 INFO - 1499718318601 Marionette DEBUG Received DOM event "pageshow" for "http://127.0.0.1:49427/clicks.html"
13:25:18 INFO - 1499718318606 Marionette TRACE 358 <- [1,2,null,{}]
13:25:18 INFO - 1499718318618 Marionette TRACE 358 -> [0,3,"findElement",{"using":"id","value":"overflowLink"}]
13:25:18 INFO - 1499718318621 Marionette TRACE 358 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"6a785abc-1b8c-4ce7-a050-13994b2c661f","ELEMENT":"6a785abc-1b8c-4ce7-a050-13994b2c661f"}}]
13:25:18 INFO - 1499718318622 Marionette TRACE 358 -> [0,4,"clickElement",{"id":"6a785abc-1b8c-4ce7-a050-13994b2c661f"}]
13:25:18 INFO - 1499718318668 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49427/clicks.html"
13:25:18 INFO - 1499718318681 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49427/clicks.html"
13:25:18 INFO - 1499718318682 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49427/clicks.html"
13:25:18 INFO - 1499718318717 Marionette DEBUG Received DOM event "DOMContentLoaded" for "http://127.0.0.1:49427/test.html"
13:25:18 INFO - 1499718318722 Marionette DEBUG Received DOM event "pageshow" for "http://127.0.0.1:49427/test.html"
13:25:18 INFO - 1499718318736 Marionette TRACE 358 <- [1,4,null,{}]
13:25:18 INFO - 1499718318737 Marionette TRACE 358 -> [0,5,"findElement",{"using":"id","value":"testDiv"}]
13:25:18 INFO - 1499718318742 Marionette TRACE 358 <- [1,5,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"b2df8b05-0784-4687-a173-2b3e76b1d804","ELEMENT":"b2df8b05-0784-4687-a173-2b3e76b1d804"}}]
13:25:18 INFO - 1499718318743 Marionette TRACE 358 -> [0,6,"getTitle",{}]
13:25:18 INFO - 1499718318744 Marionette TRACE 358 <- [1,6,null,{"value":"Marionette Test"}]
13:25:18 INFO - 1499718318746 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}]
13:25:18 INFO - TEST-END: test_click.py TestClick.test_clicking_on_a_multiline_link1499718318750 Marionette TRACE 358 <- [1,7,null,{"value":null}]
13:25:18 INFO - 1499718318751 Marionette TRACE 358 -> [0,8,"deleteSession",{}]
13:25:18 INFO - TEST-PASS | test_click.py TestClick.test_clicking_on_a_multiline_link | took 254ms
13:25:18 INFO - TEST-START | test_click.py TestClick.test_container_element
13:25:18 INFO - 1499718318752 Marionette TRACE 358 <- [1,8,null,{}]
13:25:18 INFO - 1499718318755 Marionette DEBUG Closed connection 358
13:25:18 INFO - 1499718318756 Marionette DEBUG Accepted connection 359 from 127.0.0.1:49865
13:25:18 INFO - 1499718318757 Marionette DEBUG Closed connection 359
13:25:18 INFO - 1499718318758 Marionette DEBUG Accepted connection 360 from 127.0.0.1:49866
13:25:18 INFO - 1499718318760 Marionette TRACE 360 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
13:25:18 INFO - 1499718318761 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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}
13:25:18 INFO - 1499718318764 Marionette DEBUG Register listener.js for window 12
13:25:18 INFO - 1499718318767 Marionette TRACE 360 <- [1,1,null,{"sessionId":"b5f2a9b3-29c1-4e30-a94f-28d20f8ce910","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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}}]
13:25:18 INFO - 1499718318770 Marionette TRACE 360 -> [0,2,"setTimeouts",{"script":30000}]
13:25:18 INFO - 1499718318770 Marionette TRACE 360 <- [1,2,null,{}]
13:25:18 INFO - 1499718318771 Marionette TRACE 360 -> [0,3,"setTimeouts",{"pageLoad":300000}]
13:25:18 INFO - 1499718318772 Marionette TRACE 360 <- [1,3,null,{}]
13:25:18 INFO - 1499718318773 Marionette TRACE 360 -> [0,4,"setTimeouts",{"implicit":0}]
13:25:18 INFO - 1499718318773 Marionette TRACE 360 <- [1,4,null,{}]
13:25:18 INFO - 1499718318775 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}]
13:25:18 INFO - TEST-START: test_click.py TestClick.test_container_element1499718318778 Marionette TRACE 360 <- [1,5,null,{"value":null}]
13:25:18 INFO - 1499718318779 Marionette TRACE 360 -> [0,6,"deleteSession",{}]
13:25:18 INFO - 1499718318781 Marionette TRACE 360 <- [1,6,null,{}]
13:25:18 INFO - 1499718318784 Marionette DEBUG Closed connection 360
13:25:18 INFO - 1499718318784 Marionette DEBUG Accepted connection 361 from 127.0.0.1:49867
13:25:18 INFO - 1499718318785 Marionette DEBUG Closed connection 361
13:25:18 INFO - 1499718318786 Marionette DEBUG Accepted connection 362 from 127.0.0.1:49868
13:25:18 INFO - 1499718318787 Marionette TRACE 362 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
13:25:18 INFO - 1499718318788 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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}
13:25:18 INFO - 1499718318791 Marionette DEBUG Register listener.js for window 12
13:25:18 INFO - 1499718318795 Marionette TRACE 362 <- [1,1,null,{"sessionId":"e47724bb-9de4-4682-ba96-82e0b6ab8838","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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}}]
13:25:18 INFO - 1499718318797 Marionette TRACE 362 -> [0,2,"deleteSession",{}]
13:25:18 INFO - 1499718318799 Marionette TRACE 362 <- [1,2,null,{}]
13:25:18 INFO - 1499718318801 Marionette DEBUG Closed connection 362
13:25:18 INFO - 1499718318802 Marionette DEBUG Accepted connection 363 from 127.0.0.1:49869
13:25:18 INFO - 1499718318803 Marionette DEBUG Closed connection 363
13:25:18 INFO - 1499718318804 Marionette DEBUG Accepted connection 364 from 127.0.0.1:49870
13:25:18 INFO - 1499718318805 Marionette TRACE 364 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
13:25:18 INFO - 1499718318806 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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}
13:25:18 INFO - 1499718318808 Marionette DEBUG Register listener.js for window 12
13:25:18 INFO - 1499718318812 Marionette TRACE 364 <- [1,1,null,{"sessionId":"8094d056-ed94-418e-956a-26d5f7ff2fb7","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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}}]
13:25:18 INFO - 1499718318814 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"}]
13:25:18 INFO - 1499718318816 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49427/test.html"
13:25:18 INFO - 1499718318819 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49427/test.html"
13:25:18 INFO - 1499718318819 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49427/test.html"
13:25:18 INFO - 1499718318847 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"
13:25:18 INFO - 1499718318853 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"
13:25:18 INFO - 1499718318858 Marionette TRACE 364 <- [1,2,null,{}]
13:25:18 INFO - 1499718318869 Marionette TRACE 364 -> [0,3,"findElement",{"using":"tag name","value":"option"}]
13:25:18 INFO - 1499718318872 Marionette TRACE 364 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"1a9b652d-3648-4200-bfc7-41614fe9c227","ELEMENT":"1a9b652d-3648-4200-bfc7-41614fe9c227"}}]
13:25:18 INFO - 1499718318874 Marionette TRACE 364 -> [0,4,"clickElement",{"id":"1a9b652d-3648-4200-bfc7-41614fe9c227"}]
13:25:19 INFO - 1499718319120 Marionette DEBUG Canceled page load listener because no navigation has been detected
13:25:19 INFO - 1499718319121 Marionette TRACE 364 <- [1,4,null,{}]
13:25:19 INFO - 1499718319122 Marionette TRACE 364 -> [0,5,"getElementProperty",{"id":"1a9b652d-3648-4200-bfc7-41614fe9c227","name":"selected"}]
13:25:19 INFO - 1499718319127 Marionette TRACE 364 <- [1,5,null,{"value":true}]
13:25:19 INFO - 1499718319129 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}]
13:25:19 INFO - TEST-END: test_click.py TestClick.test_container_element1499718319132 Marionette TRACE 364 <- [1,6,null,{"value":null}]
13:25:19 INFO - 1499718319133 Marionette TRACE 364 -> [0,7,"deleteSession",{}]
13:25:19 INFO - TEST-PASS | test_click.py TestClick.test_container_element | took 382ms
13:25:19 INFO - 1499718319135 Marionette TRACE 364 <- [1,7,null,{}]
13:25:19 INFO - TEST-START | test_click.py TestClick.test_container_element_outside_view
13:25:19 INFO - 1499718319137 Marionette DEBUG Closed connection 364
13:25:19 INFO - 1499718319138 Marionette DEBUG Accepted connection 365 from 127.0.0.1:49871
13:25:19 INFO - 1499718319141 Marionette DEBUG Closed connection 365
13:25:19 INFO - 1499718319142 Marionette DEBUG Accepted connection 366 from 127.0.0.1:49872
13:25:19 INFO - 1499718319143 Marionette TRACE 366 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
13:25:19 INFO - 1499718319143 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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}
13:25:19 INFO - 1499718319154 Marionette DEBUG Register listener.js for window 12
13:25:19 INFO - 1499718319158 Marionette TRACE 366 <- [1,1,null,{"sessionId":"3d3f2ce8-998e-4e4b-8051-b4be7455f8c7","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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}}]
13:25:19 INFO - 1499718319162 Marionette TRACE 366 -> [0,2,"setTimeouts",{"script":30000}]
13:25:19 INFO - 1499718319162 Marionette TRACE 366 <- [1,2,null,{}]
13:25:19 INFO - 1499718319164 Marionette TRACE 366 -> [0,3,"setTimeouts",{"pageLoad":300000}]
13:25:19 INFO - 1499718319164 Marionette TRACE 366 <- [1,3,null,{}]
13:25:19 INFO - 1499718319166 Marionette TRACE 366 -> [0,4,"setTimeouts",{"implicit":0}]
13:25:19 INFO - 1499718319166 Marionette TRACE 366 <- [1,4,null,{}]
13:25:19 INFO - 1499718319168 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}]
13:25:19 INFO - TEST-START: test_click.py TestClick.test_container_element_outside_view1499718319173 Marionette TRACE 366 <- [1,5,null,{"value":null}]
13:25:19 INFO - 1499718319174 Marionette TRACE 366 -> [0,6,"deleteSession",{}]
13:25:19 INFO - 1499718319175 Marionette TRACE 366 <- [1,6,null,{}]
13:25:19 INFO - 1499718319178 Marionette DEBUG Closed connection 366
13:25:19 INFO - 1499718319178 Marionette DEBUG Accepted connection 367 from 127.0.0.1:49873
13:25:19 INFO - 1499718319179 Marionette DEBUG Closed connection 367
13:25:19 INFO - 1499718319180 Marionette DEBUG Accepted connection 368 from 127.0.0.1:49874
13:25:19 INFO - 1499718319181 Marionette TRACE 368 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
13:25:19 INFO - 1499718319182 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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}
13:25:19 INFO - 1499718319185 Marionette DEBUG Register listener.js for window 12
13:25:19 INFO - 1499718319188 Marionette TRACE 368 <- [1,1,null,{"sessionId":"b56062e4-2dee-42e3-b23c-46b6bbe86141","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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}}]
13:25:19 INFO - 1499718319191 Marionette TRACE 368 -> [0,2,"deleteSession",{}]
13:25:19 INFO - 1499718319192 Marionette TRACE 368 <- [1,2,null,{}]
13:25:19 INFO - 1499718319194 Marionette DEBUG Closed connection 368
13:25:19 INFO - 1499718319195 Marionette DEBUG Accepted connection 369 from 127.0.0.1:49875
13:25:19 INFO - 1499718319196 Marionette DEBUG Closed connection 369
13:25:19 INFO - 1499718319197 Marionette DEBUG Accepted connection 370 from 127.0.0.1:49876
13:25:19 INFO - 1499718319198 Marionette TRACE 370 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
13:25:19 INFO - 1499718319199 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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}
13:25:19 INFO - 1499718319201 Marionette DEBUG Register listener.js for window 12
13:25:19 INFO - 1499718319205 Marionette TRACE 370 <- [1,1,null,{"sessionId":"b202bd00-ed97-4ae5-9785-29348fa53de8","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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}}]
13:25:19 INFO - 1499718319207 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"}]
13:25:19 INFO - 1499718319209 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"
13:25:19 INFO - 1499718319213 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"
13:25:19 INFO - 1499718319214 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"
13:25:19 INFO - 1499718319234 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"
13:25:19 INFO - 1499718319239 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"
13:25:19 INFO - 1499718319250 Marionette TRACE 370 <- [1,2,null,{}]
13:25:19 INFO - 1499718319252 Marionette TRACE 370 -> [0,3,"findElement",{"using":"tag name","value":"option"}]
13:25:19 INFO - 1499718319255 Marionette TRACE 370 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"af720603-7588-41bc-8838-567f911f6649","ELEMENT":"af720603-7588-41bc-8838-567f911f6649"}}]
13:25:19 INFO - 1499718319256 Marionette TRACE 370 -> [0,4,"clickElement",{"id":"af720603-7588-41bc-8838-567f911f6649"}]
13:25:19 INFO - 1499718319503 Marionette DEBUG Canceled page load listener because no navigation has been detected
13:25:19 INFO - 1499718319504 Marionette TRACE 370 <- [1,4,null,{}]
13:25:19 INFO - 1499718319505 Marionette TRACE 370 -> [0,5,"getElementProperty",{"id":"af720603-7588-41bc-8838-567f911f6649","name":"selected"}]
13:25:19 INFO - 1499718319510 Marionette TRACE 370 <- [1,5,null,{"value":true}]
13:25:19 INFO - 1499718319512 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}]
13:25:19 INFO - TEST-END: test_click.py TestClick.test_container_element_outside_view1499718319515 Marionette TRACE 370 <- [1,6,null,{"value":null}]
13:25:19 INFO - 1499718319516 Marionette TRACE 370 -> [0,7,"deleteSession",{}]
13:25:19 INFO - TEST-PASS | test_click.py TestClick.test_container_element_outside_view | took 382ms
13:25:19 INFO - TEST-START | test_click.py TestClick.test_css_transforms
13:25:19 INFO - 1499718319517 Marionette TRACE 370 <- [1,7,null,{}]
13:25:19 INFO - 1499718319520 Marionette DEBUG Closed connection 370
13:25:19 INFO - 1499718319521 Marionette DEBUG Accepted connection 371 from 127.0.0.1:49877
13:25:19 INFO - 1499718319522 Marionette DEBUG Closed connection 371
13:25:19 INFO - 1499718319523 Marionette DEBUG Accepted connection 372 from 127.0.0.1:49878
13:25:19 INFO - 1499718319524 Marionette TRACE 372 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
13:25:19 INFO - 1499718319524 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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}
13:25:19 INFO - 1499718319527 Marionette DEBUG Register listener.js for window 12
13:25:19 INFO - 1499718319531 Marionette TRACE 372 <- [1,1,null,{"sessionId":"9d1fb5eb-6bde-4dec-9c75-d9d214f0f0ba","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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}}]
13:25:19 INFO - 1499718319533 Marionette TRACE 372 -> [0,2,"setTimeouts",{"script":30000}]
13:25:19 INFO - 1499718319534 Marionette TRACE 372 <- [1,2,null,{}]
13:25:19 INFO - 1499718319535 Marionette TRACE 372 -> [0,3,"setTimeouts",{"pageLoad":300000}]
13:25:19 INFO - 1499718319535 Marionette TRACE 372 <- [1,3,null,{}]
13:25:19 INFO - 1499718319536 Marionette TRACE 372 -> [0,4,"setTimeouts",{"implicit":0}]
13:25:19 INFO - 1499718319537 Marionette TRACE 372 <- [1,4,null,{}]
13:25:19 INFO - 1499718319539 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}]
13:25:19 INFO - TEST-START: test_click.py TestClick.test_css_transforms1499718319542 Marionette TRACE 372 <- [1,5,null,{"value":null}]
13:25:19 INFO - 1499718319543 Marionette TRACE 372 -> [0,6,"deleteSession",{}]
13:25:19 INFO - 1499718319544 Marionette TRACE 372 <- [1,6,null,{}]
13:25:19 INFO - 1499718319547 Marionette DEBUG Closed connection 372
13:25:19 INFO - 1499718319548 Marionette DEBUG Accepted connection 373 from 127.0.0.1:49879
13:25:19 INFO - 1499718319549 Marionette DEBUG Closed connection 373
13:25:19 INFO - 1499718319549 Marionette DEBUG Accepted connection 374 from 127.0.0.1:49880
13:25:19 INFO - 1499718319550 Marionette TRACE 374 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
13:25:19 INFO - 1499718319551 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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}
13:25:19 INFO - 1499718319554 Marionette DEBUG Register listener.js for window 12
13:25:19 INFO - 1499718319558 Marionette TRACE 374 <- [1,1,null,{"sessionId":"91733519-5ed7-4425-9fd2-25231d16eeeb","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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}}]
13:25:19 INFO - 1499718319560 Marionette TRACE 374 -> [0,2,"deleteSession",{}]
13:25:19 INFO - 1499718319561 Marionette TRACE 374 <- [1,2,null,{}]
13:25:19 INFO - 1499718319564 Marionette DEBUG Closed connection 374
13:25:19 INFO - 1499718319565 Marionette DEBUG Accepted connection 375 from 127.0.0.1:49881
13:25:19 INFO - 1499718319566 Marionette DEBUG Closed connection 375
13:25:19 INFO - 1499718319567 Marionette DEBUG Accepted connection 376 from 127.0.0.1:49882
13:25:19 INFO - 1499718319568 Marionette TRACE 376 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
13:25:19 INFO - 1499718319569 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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}
13:25:19 INFO - 1499718319572 Marionette DEBUG Register listener.js for window 12
13:25:19 INFO - 1499718319575 Marionette TRACE 376 <- [1,1,null,{"sessionId":"c8be156b-6bbe-4ba7-b1c8-0d4d9b218f9c","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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}}]
13:25:19 INFO - 1499718319586 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"}]
13:25:19 INFO - 1499718319588 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"
13:25:19 INFO - 1499718319591 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"
13:25:19 INFO - 1499718319591 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"
13:25:19 INFO - 1499718319606 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"
13:25:19 INFO - 1499718319612 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"
13:25:19 INFO - 1499718319625 Marionette TRACE 376 <- [1,2,null,{}]
13:25:19 INFO - 1499718319628 Marionette TRACE 376 -> [0,3,"findElement",{"using":"tag name","value":"div"}]
13:25:19 INFO - 1499718319631 Marionette TRACE 376 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"f7bf39c1-1ff3-4254-bc38-e79e8ef70f77","ELEMENT":"f7bf39c1-1ff3-4254-bc38-e79e8ef70f77"}}]
13:25:19 INFO - 1499718319638 Marionette TRACE 376 -> [0,4,"clickElement",{"id":"f7bf39c1-1ff3-4254-bc38-e79e8ef70f77"}]
13:25:19 INFO - 1499718319887 Marionette DEBUG Canceled page load listener because no navigation has been detected
13:25:19 INFO - 1499718319888 Marionette TRACE 376 <- [1,4,null,{}]
13:25:19 INFO - 1499718319890 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}]
13:25:19 INFO - TEST-END: test_click.py TestClick.test_css_transforms1499718319894 Marionette TRACE 376 <- [1,5,null,{"value":null}]
13:25:19 INFO - 1499718319896 Marionette TRACE 376 -> [0,6,"deleteSession",{}]
13:25:19 INFO - 1499718319897 Marionette TRACE 376 <- [1,6,null,{}]
13:25:19 INFO - TEST-PASS | test_click.py TestClick.test_css_transforms | took 380ms
13:25:19 INFO - TEST-START | test_click.py TestClick.test_inclusive_descendant
13:25:19 INFO - 1499718319900 Marionette DEBUG Closed connection 376
13:25:19 INFO - 1499718319901 Marionette DEBUG Accepted connection 377 from 127.0.0.1:49883
13:25:19 INFO - 1499718319901 Marionette DEBUG Closed connection 377
13:25:19 INFO - 1499718319902 Marionette DEBUG Accepted connection 378 from 127.0.0.1:49884
13:25:19 INFO - 1499718319904 Marionette TRACE 378 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
13:25:19 INFO - 1499718319904 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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}
13:25:19 INFO - 1499718319907 Marionette DEBUG Register listener.js for window 12
13:25:19 INFO - 1499718319919 Marionette TRACE 378 <- [1,1,null,{"sessionId":"62de86c1-4cd6-4676-90b8-5e4ec5ac82e0","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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}}]
13:25:19 INFO - 1499718319922 Marionette TRACE 378 -> [0,2,"setTimeouts",{"script":30000}]
13:25:19 INFO - 1499718319922 Marionette TRACE 378 <- [1,2,null,{}]
13:25:19 INFO - 1499718319923 Marionette TRACE 378 -> [0,3,"setTimeouts",{"pageLoad":300000}]
13:25:19 INFO - 1499718319924 Marionette TRACE 378 <- [1,3,null,{}]
13:25:19 INFO - 1499718319925 Marionette TRACE 378 -> [0,4,"setTimeouts",{"implicit":0}]
13:25:19 INFO - 1499718319925 Marionette TRACE 378 <- [1,4,null,{}]
13:25:19 INFO - 1499718319927 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}]
13:25:19 INFO - TEST-START: test_click.py TestClick.test_inclusive_descendant1499718319930 Marionette TRACE 378 <- [1,5,null,{"value":null}]
13:25:19 INFO - 1499718319931 Marionette TRACE 378 -> [0,6,"deleteSession",{}]
13:25:19 INFO - 1499718319933 Marionette TRACE 378 <- [1,6,null,{}]
13:25:19 INFO - 1499718319935 Marionette DEBUG Closed connection 378
13:25:19 INFO - 1499718319936 Marionette DEBUG Accepted connection 379 from 127.0.0.1:49885
13:25:19 INFO - 1499718319937 Marionette DEBUG Closed connection 379
13:25:19 INFO - 1499718319938 Marionette DEBUG Accepted connection 380 from 127.0.0.1:49886
13:25:19 INFO - 1499718319939 Marionette TRACE 380 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
13:25:19 INFO - 1499718319939 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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}
13:25:19 INFO - 1499718319942 Marionette DEBUG Register listener.js for window 12
13:25:19 INFO - 1499718319946 Marionette TRACE 380 <- [1,1,null,{"sessionId":"1e1cf9c0-48cb-4261-992a-34fdda5570d0","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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}}]
13:25:19 INFO - 1499718319948 Marionette TRACE 380 -> [0,2,"deleteSession",{}]
13:25:19 INFO - 1499718319950 Marionette TRACE 380 <- [1,2,null,{}]
13:25:19 INFO - 1499718319952 Marionette DEBUG Closed connection 380
13:25:19 INFO - 1499718319953 Marionette DEBUG Accepted connection 381 from 127.0.0.1:49887
13:25:19 INFO - 1499718319954 Marionette DEBUG Closed connection 381
13:25:19 INFO - 1499718319954 Marionette DEBUG Accepted connection 382 from 127.0.0.1:49888
13:25:19 INFO - 1499718319957 Marionette TRACE 382 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
13:25:19 INFO - 1499718319958 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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}
13:25:19 INFO - 1499718319960 Marionette DEBUG Register listener.js for window 12
13:25:19 INFO - 1499718319964 Marionette TRACE 382 <- [1,1,null,{"sessionId":"d845e665-fa04-48f6-bb6e-56812543e616","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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}}]
13:25:19 INFO - 1499718319966 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"}]
13:25:19 INFO - 1499718319968 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"
13:25:19 INFO - 1499718319970 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"
13:25:19 INFO - 1499718319971 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"
13:25:20 INFO - 1499718319994 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"
13:25:20 INFO - 1499718319997 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"
13:25:20 INFO - 1499718320001 Marionette TRACE 382 <- [1,2,null,{}]
13:25:20 INFO - 1499718320002 Marionette TRACE 382 -> [0,3,"findElement",{"using":"tag name","value":"select"}]
13:25:20 INFO - 1499718320013 Marionette TRACE 382 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"5ecaac45-f088-43f6-a137-7467151a30f5","ELEMENT":"5ecaac45-f088-43f6-a137-7467151a30f5"}}]
13:25:20 INFO - 1499718320016 Marionette TRACE 382 -> [0,4,"clickElement",{"id":"5ecaac45-f088-43f6-a137-7467151a30f5"}]
13:25:20 INFO - 1499718320261 Marionette DEBUG Canceled page load listener because no navigation has been detected
13:25:20 INFO - 1499718320262 Marionette TRACE 382 <- [1,4,null,{}]
13:25:20 INFO - 1499718320264 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}]
13:25:20 INFO - TEST-END: test_click.py TestClick.test_inclusive_descendant1499718320268 Marionette TRACE 382 <- [1,5,null,{"value":null}]
13:25:20 INFO - 1499718320269 Marionette TRACE 382 -> [0,6,"deleteSession",{}]
13:25:20 INFO - 1499718320270 Marionette TRACE 382 <- [1,6,null,{}]
13:25:20 INFO - TEST-PASS | test_click.py TestClick.test_inclusive_descendant | took 373ms
13:25:20 INFO - TEST-START | test_click.py TestClick.test_input_file
13:25:20 INFO - 1499718320273 Marionette DEBUG Closed connection 382
13:25:20 INFO - 1499718320274 Marionette DEBUG Accepted connection 383 from 127.0.0.1:49889
13:25:20 INFO - 1499718320274 Marionette DEBUG Closed connection 383
13:25:20 INFO - 1499718320275 Marionette DEBUG Accepted connection 384 from 127.0.0.1:49890
13:25:20 INFO - 1499718320276 Marionette TRACE 384 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
13:25:20 INFO - 1499718320277 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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}
13:25:20 INFO - 1499718320280 Marionette DEBUG Register listener.js for window 12
13:25:20 INFO - 1499718320284 Marionette TRACE 384 <- [1,1,null,{"sessionId":"e23d5df5-d57a-4ac4-9e4b-5d5166837b5b","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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}}]
13:25:20 INFO - 1499718320286 Marionette TRACE 384 -> [0,2,"setTimeouts",{"script":30000}]
13:25:20 INFO - 1499718320287 Marionette TRACE 384 <- [1,2,null,{}]
13:25:20 INFO - 1499718320288 Marionette TRACE 384 -> [0,3,"setTimeouts",{"pageLoad":300000}]
13:25:20 INFO - 1499718320288 Marionette TRACE 384 <- [1,3,null,{}]
13:25:20 INFO - 1499718320289 Marionette TRACE 384 -> [0,4,"setTimeouts",{"implicit":0}]
13:25:20 INFO - 1499718320290 Marionette TRACE 384 <- [1,4,null,{}]
13:25:20 INFO - 1499718320292 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}]
13:25:20 INFO - TEST-START: test_click.py TestClick.test_input_file1499718320295 Marionette TRACE 384 <- [1,5,null,{"value":null}]
13:25:20 INFO - 1499718320296 Marionette TRACE 384 -> [0,6,"deleteSession",{}]
13:25:20 INFO - 1499718320298 Marionette TRACE 384 <- [1,6,null,{}]
13:25:20 INFO - 1499718320300 Marionette DEBUG Closed connection 384
13:25:20 INFO - 1499718320301 Marionette DEBUG Accepted connection 385 from 127.0.0.1:49891
13:25:20 INFO - 1499718320302 Marionette DEBUG Closed connection 385
13:25:20 INFO - 1499718320303 Marionette DEBUG Accepted connection 386 from 127.0.0.1:49892
13:25:20 INFO - 1499718320304 Marionette TRACE 386 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
13:25:20 INFO - 1499718320305 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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}
13:25:20 INFO - 1499718320308 Marionette DEBUG Register listener.js for window 12
13:25:20 INFO - 1499718320311 Marionette TRACE 386 <- [1,1,null,{"sessionId":"c6a5cc3a-c6e1-472e-81dc-43acf5e8f291","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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}}]
13:25:20 INFO - 1499718320314 Marionette TRACE 386 -> [0,2,"deleteSession",{}]
13:25:20 INFO - 1499718320315 Marionette TRACE 386 <- [1,2,null,{}]
13:25:20 INFO - 1499718320318 Marionette DEBUG Closed connection 386
13:25:20 INFO - 1499718320319 Marionette DEBUG Accepted connection 387 from 127.0.0.1:49893
13:25:20 INFO - 1499718320319 Marionette DEBUG Closed connection 387
13:25:20 INFO - 1499718320320 Marionette DEBUG Accepted connection 388 from 127.0.0.1:49894
13:25:20 INFO - 1499718320322 Marionette TRACE 388 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
13:25:20 INFO - 1499718320322 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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}
13:25:20 INFO - 1499718320325 Marionette DEBUG Register listener.js for window 12
13:25:20 INFO - 1499718320329 Marionette TRACE 388 <- [1,1,null,{"sessionId":"473bb42a-44bd-45fe-ba32-730971b51c0d","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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}}]
13:25:20 INFO - 1499718320331 Marionette TRACE 388 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"}]
13:25:20 INFO - 1499718320333 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"
13:25:20 INFO - 1499718320336 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"
13:25:20 INFO - 1499718320336 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"
13:25:20 INFO - 1499718320363 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
13:25:20 INFO - 1499718320365 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
13:25:20 INFO - 1499718320369 Marionette TRACE 388 <- [1,2,null,{}]
13:25:20 INFO - 1499718320379 Marionette TRACE 388 -> [0,3,"findElement",{"using":"tag name","value":"input"}]
13:25:20 INFO - 1499718320383 Marionette TRACE 388 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"04f97ee5-7843-4c83-b4cb-c70322366bfb","ELEMENT":"04f97ee5-7843-4c83-b4cb-c70322366bfb"}}]
13:25:20 INFO - 1499718320384 Marionette TRACE 388 -> [0,4,"clickElement",{"id":"04f97ee5-7843-4c83-b4cb-c70322366bfb"}]
13:25:20 INFO - 1499718320414 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]
13:25:20 INFO - 1499718320416 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}]
13:25:20 INFO - TEST-END: test_click.py TestClick.test_input_file1499718320419 Marionette TRACE 388 <- [1,5,null,{"value":null}]
13:25:20 INFO - 1499718320420 Marionette TRACE 388 -> [0,6,"deleteSession",{}]
13:25:20 INFO - 1499718320422 Marionette TRACE 388 <- [1,6,null,{}]
13:25:20 INFO - TEST-PASS | test_click.py TestClick.test_input_file | took 151ms
13:25:20 INFO - TEST-START | test_click.py TestClick.test_obscured_element
13:25:20 INFO - 1499718320424 Marionette DEBUG Closed connection 388
13:25:20 INFO - 1499718320425 Marionette DEBUG Accepted connection 389 from 127.0.0.1:49896
13:25:20 INFO - 1499718320426 Marionette DEBUG Closed connection 389
13:25:20 INFO - 1499718320427 Marionette DEBUG Accepted connection 390 from 127.0.0.1:49897
13:25:20 INFO - 1499718320428 Marionette TRACE 390 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
13:25:20 INFO - 1499718320429 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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}
13:25:20 INFO - 1499718320432 Marionette DEBUG Register listener.js for window 12
13:25:20 INFO - 1499718320435 Marionette TRACE 390 <- [1,1,null,{"sessionId":"19271915-14d4-4957-b40a-6d32f682590d","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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}}]
13:25:20 INFO - 1499718320437 Marionette TRACE 390 -> [0,2,"setTimeouts",{"script":30000}]
13:25:20 INFO - 1499718320438 Marionette TRACE 390 <- [1,2,null,{}]
13:25:20 INFO - 1499718320439 Marionette TRACE 390 -> [0,3,"setTimeouts",{"pageLoad":300000}]
13:25:20 INFO - 1499718320440 Marionette TRACE 390 <- [1,3,null,{}]
13:25:20 INFO - 1499718320441 Marionette TRACE 390 -> [0,4,"setTimeouts",{"implicit":0}]
13:25:20 INFO - 1499718320441 Marionette TRACE 390 <- [1,4,null,{}]
13:25:20 INFO - 1499718320443 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}]
13:25:20 INFO - TEST-START: test_click.py TestClick.test_obscured_element1499718320446 Marionette TRACE 390 <- [1,5,null,{"value":null}]
13:25:20 INFO - 1499718320447 Marionette TRACE 390 -> [0,6,"deleteSession",{}]
13:25:20 INFO - 1499718320449 Marionette TRACE 390 <- [1,6,null,{}]
13:25:20 INFO - 1499718320451 Marionette DEBUG Closed connection 390
13:25:20 INFO - 1499718320452 Marionette DEBUG Accepted connection 391 from 127.0.0.1:49898
13:25:20 INFO - 1499718320453 Marionette DEBUG Closed connection 391
13:25:20 INFO - 1499718320454 Marionette DEBUG Accepted connection 392 from 127.0.0.1:49899
13:25:20 INFO - 1499718320455 Marionette TRACE 392 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
13:25:20 INFO - 1499718320455 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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}
13:25:20 INFO - 1499718320466 Marionette DEBUG Register listener.js for window 12
13:25:20 INFO - 1499718320470 Marionette TRACE 392 <- [1,1,null,{"sessionId":"17cbc85b-26af-48f6-9b9d-ed9d21b2214c","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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}}]
13:25:20 INFO - 1499718320472 Marionette TRACE 392 -> [0,2,"deleteSession",{}]
13:25:20 INFO - 1499718320474 Marionette TRACE 392 <- [1,2,null,{}]
13:25:20 INFO - 1499718320476 Marionette DEBUG Closed connection 392
13:25:20 INFO - 1499718320477 Marionette DEBUG Accepted connection 393 from 127.0.0.1:49900
13:25:20 INFO - 1499718320478 Marionette DEBUG Closed connection 393
13:25:20 INFO - 1499718320479 Marionette DEBUG Accepted connection 394 from 127.0.0.1:49901
13:25:20 INFO - 1499718320480 Marionette TRACE 394 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
13:25:20 INFO - 1499718320481 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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}
13:25:20 INFO - 1499718320484 Marionette DEBUG Register listener.js for window 12
13:25:20 INFO - 1499718320487 Marionette TRACE 394 <- [1,1,null,{"sessionId":"2b347e01-2e15-4871-bee0-62ea49d4e049","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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}}]
13:25:20 INFO - 1499718320490 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"}]
13:25:20 INFO - 1499718320492 Marionette DEBUG Received DOM event "beforeunload" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
13:25:20 INFO - 1499718320494 Marionette DEBUG Received DOM event "pagehide" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
13:25:20 INFO - 1499718320495 Marionette DEBUG Received DOM event "unload" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
13:25:20 INFO - 1499718320519 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"
13:25:20 INFO - 1499718320522 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"
13:25:20 INFO - 1499718320533 Marionette TRACE 394 <- [1,2,null,{}]
13:25:20 INFO - 1499718320535 Marionette TRACE 394 -> [0,3,"findElement",{"using":"id","value":"overlay"}]
13:25:20 INFO - 1499718320538 Marionette TRACE 394 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"3c48ef9f-27c3-4ea5-a9bc-d248371450be","ELEMENT":"3c48ef9f-27c3-4ea5-a9bc-d248371450be"}}]
13:25:20 INFO - 1499718320540 Marionette TRACE 394 -> [0,4,"findElement",{"using":"id","value":"obscured"}]
13:25:20 INFO - 1499718320543 Marionette TRACE 394 <- [1,4,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"d672bca9-0a66-4d5a-a01b-3d400ba0fcfb","ELEMENT":"d672bca9-0a66-4d5a-a01b-3d400ba0fcfb"}}]
13:25:20 INFO - 1499718320544 Marionette TRACE 394 -> [0,5,"clickElement",{"id":"3c48ef9f-27c3-4ea5-a9bc-d248371450be"}]
13:25:20 INFO - 1499718320785 Marionette DEBUG Canceled page load listener because no navigation has been detected
13:25:20 INFO - 1499718320786 Marionette TRACE 394 <- [1,5,null,{}]
13:25:20 INFO - 1499718320787 Marionette TRACE 394 -> [0,6,"clickElement",{"id":"d672bca9-0a66-4d5a-a01b-3d400ba0fcfb"}]
13:25:20 INFO - 1499718320806 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]
13:25:20 INFO - 1499718320808 Marionette TRACE 394 -> [0,7,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"test_click.py","script":"return window.clicked","sandbox":null,"line":257}]
13:25:20 INFO - 1499718320811 Marionette TRACE 394 <- [1,7,null,{"value":false}]
13:25:20 INFO - 1499718320813 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}]
13:25:20 INFO - TEST-END: test_click.py TestClick.test_obscured_element1499718320815 Marionette TRACE 394 <- [1,8,null,{"value":null}]
13:25:20 INFO - 1499718320817 Marionette TRACE 394 -> [0,9,"deleteSession",{}]
13:25:20 INFO - 1499718320818 Marionette TRACE 394 <- [1,9,null,{}]
13:25:20 INFO - TEST-PASS | test_click.py TestClick.test_obscured_element | took 396ms
13:25:20 INFO - TEST-START | test_click.py TestClick.test_pointer_events_none
13:25:20 INFO - 1499718320821 Marionette DEBUG Closed connection 394
13:25:20 INFO - 1499718320822 Marionette DEBUG Accepted connection 395 from 127.0.0.1:49902
13:25:20 INFO - 1499718320822 Marionette DEBUG Closed connection 395
13:25:20 INFO - 1499718320823 Marionette DEBUG Accepted connection 396 from 127.0.0.1:49903
13:25:20 INFO - 1499718320824 Marionette TRACE 396 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
13:25:20 INFO - 1499718320825 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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}
13:25:20 INFO - 1499718320828 Marionette DEBUG Register listener.js for window 12
13:25:20 INFO - 1499718320832 Marionette TRACE 396 <- [1,1,null,{"sessionId":"839657f8-1c36-4ca1-8e3a-03a5601160f4","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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}}]
13:25:20 INFO - 1499718320834 Marionette TRACE 396 -> [0,2,"setTimeouts",{"script":30000}]
13:25:20 INFO - 1499718320835 Marionette TRACE 396 <- [1,2,null,{}]
13:25:20 INFO - 1499718320836 Marionette TRACE 396 -> [0,3,"setTimeouts",{"pageLoad":300000}]
13:25:20 INFO - 1499718320836 Marionette TRACE 396 <- [1,3,null,{}]
13:25:20 INFO - 1499718320837 Marionette TRACE 396 -> [0,4,"setTimeouts",{"implicit":0}]
13:25:20 INFO - 1499718320838 Marionette TRACE 396 <- [1,4,null,{}]
13:25:20 INFO - 1499718320840 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}]
13:25:20 INFO - TEST-START: test_click.py TestClick.test_pointer_events_none1499718320843 Marionette TRACE 396 <- [1,5,null,{"value":null}]
13:25:20 INFO - 1499718320844 Marionette TRACE 396 -> [0,6,"deleteSession",{}]
13:25:20 INFO - 1499718320845 Marionette TRACE 396 <- [1,6,null,{}]
13:25:20 INFO - 1499718320848 Marionette DEBUG Closed connection 396
13:25:20 INFO - 1499718320849 Marionette DEBUG Accepted connection 397 from 127.0.0.1:49904
13:25:20 INFO - 1499718320850 Marionette DEBUG Closed connection 397
13:25:20 INFO - 1499718320850 Marionette DEBUG Accepted connection 398 from 127.0.0.1:49905
13:25:20 INFO - 1499718320851 Marionette TRACE 398 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
13:25:20 INFO - 1499718320852 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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}
13:25:20 INFO - 1499718320855 Marionette DEBUG Register listener.js for window 12
13:25:20 INFO - 1499718320859 Marionette TRACE 398 <- [1,1,null,{"sessionId":"c56faeb7-6ba5-495f-8d26-6b616ab853eb","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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}}]
13:25:20 INFO - 1499718320862 Marionette TRACE 398 -> [0,2,"deleteSession",{}]
13:25:20 INFO - 1499718320863 Marionette TRACE 398 <- [1,2,null,{}]
13:25:20 INFO - 1499718320866 Marionette DEBUG Closed connection 398
13:25:20 INFO - 1499718320867 Marionette DEBUG Accepted connection 399 from 127.0.0.1:49906
13:25:20 INFO - 1499718320867 Marionette DEBUG Closed connection 399
13:25:20 INFO - 1499718320868 Marionette DEBUG Accepted connection 400 from 127.0.0.1:49907
13:25:20 INFO - 1499718320869 Marionette TRACE 400 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
13:25:20 INFO - 1499718320870 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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}
13:25:20 INFO - 1499718320873 Marionette DEBUG Register listener.js for window 12
13:25:20 INFO - 1499718320878 Marionette TRACE 400 <- [1,1,null,{"sessionId":"218a6527-d3a5-4971-b1fc-5f03af9e3dcd","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":2912,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp_hedj8.mozrunner","moz:accessibilityChecks":false}}]
13:25:20 INFO - 1499718320880 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"}]
13:25:20 INFO - 1499718320882 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"
13:25:20 INFO - 1499718320885 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"
13:25:20 INFO - 1499718320885 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"
13:25:20 INFO - 1499718320911 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"
13:25:20 INFO - 1499718320913 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"
13:25:20 INFO - 1499718320917 Marionette TRACE 400 <- [1,2,null,{}]
13:25:20 INFO - 1499718320919 Marionette TRACE 400 -> [0,3,"findElement",{"using":"tag name","value":"button"}]
13:25:20 INFO - 1499718320930 Marionette TRACE 400 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"642b5ec8-b82b-44f7-9aff-a192fd651624","ELEMENT":"642b5ec8-b82b-44f7-9aff-a192fd651624"}}]
13:25:20 INFO - 1499718320932 Marionette TRACE 400 -> [0,4,"getElementValueOfCssProperty",{"propertyName":"pointer-events","id":"642b5ec8-b82b-44f7-9aff-a192fd651624"}]
13:25:20 INFO - 1499718320956 Marionette TRACE 400 <- [1,4,null,{"value":"none"}]
13:25:20 INFO - 1499718320958 Marionette TRACE 400 -> [0,5,"clickElement",{"id":"642b5ec8-b82b-44f7-9aff-a192fd651624"}]
13:25:20 INFO - 1499718320982 Marionette TRACE 400 <- [1,5,{"error":"element click intercepted","message":"Element