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:393:12\nclickElement@chrome://marionette/content/listener.js:1318:5\n"},null]
12:48:25 INFO - 1499370505931 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}]
12:48:25 INFO - TEST-END: test_click.py TestClick.test_clicking_an_element_that_is_not_displayed_raises1499370505934 Marionette TRACE 352 <- [1,5,null,{"value":null}]
12:48:25 INFO - 1499370505935 Marionette TRACE 352 -> [0,6,"deleteSession",{}]
12:48:25 INFO - TEST-PASS | test_click.py TestClick.test_clicking_an_element_that_is_not_displayed_raises | took 137ms
12:48:25 INFO - TEST-START | test_click.py TestClick.test_clicking_on_a_multiline_link
12:48:25 INFO - 1499370505936 Marionette TRACE 352 <- [1,6,null,{}]
12:48:25 INFO - 1499370505938 Marionette DEBUG Closed connection 352
12:48:25 INFO - 1499370505939 Marionette DEBUG Accepted connection 353 from 127.0.0.1:51377
12:48:25 INFO - 1499370505940 Marionette DEBUG Closed connection 353
12:48:25 INFO - 1499370505941 Marionette DEBUG Accepted connection 354 from 127.0.0.1:51378
12:48:25 INFO - 1499370505942 Marionette TRACE 354 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:25 INFO - 1499370505943 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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}
12:48:25 INFO - 1499370505945 Marionette DEBUG Register listener.js for window 12
12:48:25 INFO - 1499370505948 Marionette TRACE 354 <- [1,1,null,{"sessionId":"1a0c58b9-4e53-40a8-a179-08f149625e73","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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}}]
12:48:25 INFO - 1499370505949 Marionette TRACE 354 -> [0,2,"setTimeouts",{"script":30000}]
12:48:25 INFO - 1499370505950 Marionette TRACE 354 <- [1,2,null,{}]
12:48:25 INFO - 1499370505951 Marionette TRACE 354 -> [0,3,"setTimeouts",{"pageLoad":300000}]
12:48:25 INFO - 1499370505951 Marionette TRACE 354 <- [1,3,null,{}]
12:48:25 INFO - 1499370505952 Marionette TRACE 354 -> [0,4,"setTimeouts",{"implicit":0}]
12:48:25 INFO - 1499370505953 Marionette TRACE 354 <- [1,4,null,{}]
12:48:25 INFO - 1499370505955 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}]
12:48:25 INFO - TEST-START: test_click.py TestClick.test_clicking_on_a_multiline_link1499370505957 Marionette TRACE 354 <- [1,5,null,{"value":null}]
12:48:25 INFO - 1499370505958 Marionette TRACE 354 -> [0,6,"deleteSession",{}]
12:48:25 INFO - 1499370505960 Marionette TRACE 354 <- [1,6,null,{}]
12:48:25 INFO - 1499370505962 Marionette DEBUG Closed connection 354
12:48:25 INFO - 1499370505962 Marionette DEBUG Accepted connection 355 from 127.0.0.1:51379
12:48:25 INFO - 1499370505963 Marionette DEBUG Closed connection 355
12:48:25 INFO - 1499370505964 Marionette DEBUG Accepted connection 356 from 127.0.0.1:51380
12:48:25 INFO - 1499370505965 Marionette TRACE 356 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:25 INFO - 1499370505965 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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}
12:48:25 INFO - 1499370505967 Marionette DEBUG Register listener.js for window 12
12:48:25 INFO - 1499370505971 Marionette TRACE 356 <- [1,1,null,{"sessionId":"7659c116-8fc2-443f-b7e0-06cc8ee231fd","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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}}]
12:48:25 INFO - 1499370505972 Marionette TRACE 356 -> [0,2,"deleteSession",{}]
12:48:25 INFO - 1499370505973 Marionette TRACE 356 <- [1,2,null,{}]
12:48:25 INFO - 1499370505975 Marionette DEBUG Closed connection 356
12:48:25 INFO - 1499370505975 Marionette DEBUG Accepted connection 357 from 127.0.0.1:51381
12:48:25 INFO - 1499370505976 Marionette DEBUG Closed connection 357
12:48:25 INFO - 1499370505977 Marionette DEBUG Accepted connection 358 from 127.0.0.1:51382
12:48:25 INFO - 1499370505978 Marionette TRACE 358 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
12:48:25 INFO - 1499370505979 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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}
12:48:25 INFO - 1499370505981 Marionette DEBUG Register listener.js for window 12
12:48:25 INFO - 1499370505984 Marionette TRACE 358 <- [1,1,null,{"sessionId":"6141d5b3-d8df-4a50-a10f-50ab458bd063","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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}}]
12:48:25 INFO - 1499370505986 Marionette TRACE 358 -> [0,2,"get",{"url":"http://127.0.0.1:50945/clicks.html"}]
12:48:25 INFO - 1499370505988 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:50945/hidden.html"
12:48:25 INFO - 1499370505994 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:50945/hidden.html"
12:48:25 INFO - 1499370505994 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:50945/hidden.html"
12:48:26 INFO - 1499370506012 Marionette DEBUG Received DOM event "DOMContentLoaded" for "http://127.0.0.1:50945/clicks.html"
12:48:26 INFO - 1499370506017 Marionette DEBUG Received DOM event "pageshow" for "http://127.0.0.1:50945/clicks.html"
12:48:26 INFO - 1499370506029 Marionette TRACE 358 <- [1,2,null,{}]
12:48:26 INFO - 1499370506031 Marionette TRACE 358 -> [0,3,"findElement",{"using":"id","value":"overflowLink"}]
12:48:26 INFO - 1499370506034 Marionette TRACE 358 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"2bdc6fb0-1bc8-4053-bc01-7bbf5fb59ddd","ELEMENT":"2bdc6fb0-1bc8-4053-bc01-7bbf5fb59ddd"}}]
12:48:26 INFO - 1499370506036 Marionette TRACE 358 -> [0,4,"clickElement",{"id":"2bdc6fb0-1bc8-4053-bc01-7bbf5fb59ddd"}]
12:48:26 INFO - 1499370506083 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:50945/clicks.html"
12:48:26 INFO - 1499370506091 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:50945/clicks.html"
12:48:26 INFO - 1499370506092 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:50945/clicks.html"
12:48:26 INFO - 1499370506110 Marionette DEBUG Received DOM event "DOMContentLoaded" for "http://127.0.0.1:50945/test.html"
12:48:26 INFO - 1499370506113 Marionette DEBUG Received DOM event "pageshow" for "http://127.0.0.1:50945/test.html"
12:48:26 INFO - 1499370506117 Marionette TRACE 358 <- [1,4,null,{}]
12:48:26 INFO - 1499370506126 Marionette TRACE 358 -> [0,5,"findElement",{"using":"id","value":"testDiv"}]
12:48:26 INFO - 1499370506129 Marionette TRACE 358 <- [1,5,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"b17e72ea-d23d-4653-bf62-79b2a4f70d93","ELEMENT":"b17e72ea-d23d-4653-bf62-79b2a4f70d93"}}]
12:48:26 INFO - 1499370506130 Marionette TRACE 358 -> [0,6,"getTitle",{}]
12:48:26 INFO - 1499370506130 Marionette TRACE 358 <- [1,6,null,{"value":"Marionette Test"}]
12:48:26 INFO - 1499370506132 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}]
12:48:26 INFO - TEST-END: test_click.py TestClick.test_clicking_on_a_multiline_link1499370506135 Marionette TRACE 358 <- [1,7,null,{"value":null}]
12:48:26 INFO - 1499370506137 Marionette TRACE 358 -> [0,8,"deleteSession",{}]
12:48:26 INFO - TEST-PASS | test_click.py TestClick.test_clicking_on_a_multiline_link | took 202ms
12:48:26 INFO - TEST-START | test_click.py TestClick.test_container_element
12:48:26 INFO - 1499370506138 Marionette TRACE 358 <- [1,8,null,{}]
12:48:26 INFO - 1499370506140 Marionette DEBUG Closed connection 358
12:48:26 INFO - 1499370506141 Marionette DEBUG Accepted connection 359 from 127.0.0.1:51385
12:48:26 INFO - 1499370506142 Marionette DEBUG Closed connection 359
12:48:26 INFO - 1499370506143 Marionette DEBUG Accepted connection 360 from 127.0.0.1:51386
12:48:26 INFO - 1499370506144 Marionette TRACE 360 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:26 INFO - 1499370506146 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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}
12:48:26 INFO - 1499370506148 Marionette DEBUG Register listener.js for window 12
12:48:26 INFO - 1499370506151 Marionette TRACE 360 <- [1,1,null,{"sessionId":"17dcc8f2-f5c5-47e9-86c4-1de9a7f990e4","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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}}]
12:48:26 INFO - 1499370506152 Marionette TRACE 360 -> [0,2,"setTimeouts",{"script":30000}]
12:48:26 INFO - 1499370506153 Marionette TRACE 360 <- [1,2,null,{}]
12:48:26 INFO - 1499370506154 Marionette TRACE 360 -> [0,3,"setTimeouts",{"pageLoad":300000}]
12:48:26 INFO - 1499370506154 Marionette TRACE 360 <- [1,3,null,{}]
12:48:26 INFO - 1499370506155 Marionette TRACE 360 -> [0,4,"setTimeouts",{"implicit":0}]
12:48:26 INFO - 1499370506155 Marionette TRACE 360 <- [1,4,null,{}]
12:48:26 INFO - 1499370506157 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}]
12:48:26 INFO - TEST-START: test_click.py TestClick.test_container_element1499370506160 Marionette TRACE 360 <- [1,5,null,{"value":null}]
12:48:26 INFO - 1499370506161 Marionette TRACE 360 -> [0,6,"deleteSession",{}]
12:48:26 INFO - 1499370506162 Marionette TRACE 360 <- [1,6,null,{}]
12:48:26 INFO - 1499370506164 Marionette DEBUG Closed connection 360
12:48:26 INFO - 1499370506164 Marionette DEBUG Accepted connection 361 from 127.0.0.1:51387
12:48:26 INFO - 1499370506165 Marionette DEBUG Closed connection 361
12:48:26 INFO - 1499370506166 Marionette DEBUG Accepted connection 362 from 127.0.0.1:51388
12:48:26 INFO - 1499370506167 Marionette TRACE 362 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:26 INFO - 1499370506168 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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}
12:48:26 INFO - 1499370506170 Marionette DEBUG Register listener.js for window 12
12:48:26 INFO - 1499370506173 Marionette TRACE 362 <- [1,1,null,{"sessionId":"5f73b1c1-982f-4a83-874e-183178ee422f","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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}}]
12:48:26 INFO - 1499370506174 Marionette TRACE 362 -> [0,2,"deleteSession",{}]
12:48:26 INFO - 1499370506175 Marionette TRACE 362 <- [1,2,null,{}]
12:48:26 INFO - 1499370506177 Marionette DEBUG Closed connection 362
12:48:26 INFO - 1499370506178 Marionette DEBUG Accepted connection 363 from 127.0.0.1:51389
12:48:26 INFO - 1499370506179 Marionette DEBUG Closed connection 363
12:48:26 INFO - 1499370506179 Marionette DEBUG Accepted connection 364 from 127.0.0.1:51390
12:48:26 INFO - 1499370506180 Marionette TRACE 364 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
12:48:26 INFO - 1499370506181 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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}
12:48:26 INFO - 1499370506183 Marionette DEBUG Register listener.js for window 12
12:48:26 INFO - 1499370506186 Marionette TRACE 364 <- [1,1,null,{"sessionId":"e688f68e-a87c-429b-86fe-115afbceee8a","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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}}]
12:48:26 INFO - 1499370506187 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"}]
12:48:26 INFO - 1499370506189 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:50945/test.html"
12:48:26 INFO - 1499370506191 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:50945/test.html"
12:48:26 INFO - 1499370506192 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:50945/test.html"
12:48:26 INFO - 1499370506210 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"
12:48:26 INFO - 1499370506215 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"
12:48:26 INFO - 1499370506225 Marionette TRACE 364 <- [1,2,null,{}]
12:48:26 INFO - 1499370506227 Marionette TRACE 364 -> [0,3,"findElement",{"using":"tag name","value":"option"}]
12:48:26 INFO - 1499370506231 Marionette TRACE 364 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"3b6502d8-547a-4a96-bd71-71d60535c75a","ELEMENT":"3b6502d8-547a-4a96-bd71-71d60535c75a"}}]
12:48:26 INFO - 1499370506232 Marionette TRACE 364 -> [0,4,"clickElement",{"id":"3b6502d8-547a-4a96-bd71-71d60535c75a"}]
12:48:26 INFO - 1499370506471 Marionette DEBUG Canceled page load listener because no navigation has been detected
12:48:26 INFO - 1499370506472 Marionette TRACE 364 <- [1,4,null,{}]
12:48:26 INFO - 1499370506473 Marionette TRACE 364 -> [0,5,"getElementProperty",{"id":"3b6502d8-547a-4a96-bd71-71d60535c75a","name":"selected"}]
12:48:26 INFO - 1499370506478 Marionette TRACE 364 <- [1,5,null,{"value":true}]
12:48:26 INFO - 1499370506480 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}]
12:48:26 INFO - TEST-END: test_click.py TestClick.test_container_element1499370506482 Marionette TRACE 364 <- [1,6,null,{"value":null}]
12:48:26 INFO - 1499370506483 Marionette TRACE 364 -> [0,7,"deleteSession",{}]
12:48:26 INFO - 1499370506485 Marionette TRACE 364 <- [1,7,null,{}]
12:48:26 INFO - TEST-PASS | test_click.py TestClick.test_container_element | took 346ms
12:48:26 INFO - TEST-START | test_click.py TestClick.test_container_element_outside_view
12:48:26 INFO - 1499370506487 Marionette DEBUG Closed connection 364
12:48:26 INFO - 1499370506488 Marionette DEBUG Accepted connection 365 from 127.0.0.1:51391
12:48:26 INFO - 1499370506489 Marionette DEBUG Closed connection 365
12:48:26 INFO - 1499370506489 Marionette DEBUG Accepted connection 366 from 127.0.0.1:51392
12:48:26 INFO - 1499370506490 Marionette TRACE 366 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:26 INFO - 1499370506491 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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}
12:48:26 INFO - 1499370506493 Marionette DEBUG Register listener.js for window 12
12:48:26 INFO - 1499370506497 Marionette TRACE 366 <- [1,1,null,{"sessionId":"355b8b55-6771-4e0b-b85f-afb1b603868d","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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}}]
12:48:26 INFO - 1499370506498 Marionette TRACE 366 -> [0,2,"setTimeouts",{"script":30000}]
12:48:26 INFO - 1499370506498 Marionette TRACE 366 <- [1,2,null,{}]
12:48:26 INFO - 1499370506499 Marionette TRACE 366 -> [0,3,"setTimeouts",{"pageLoad":300000}]
12:48:26 INFO - 1499370506500 Marionette TRACE 366 <- [1,3,null,{}]
12:48:26 INFO - 1499370506501 Marionette TRACE 366 -> [0,4,"setTimeouts",{"implicit":0}]
12:48:26 INFO - 1499370506501 Marionette TRACE 366 <- [1,4,null,{}]
12:48:26 INFO - 1499370506503 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}]
12:48:26 INFO - TEST-START: test_click.py TestClick.test_container_element_outside_view1499370506506 Marionette TRACE 366 <- [1,5,null,{"value":null}]
12:48:26 INFO - 1499370506507 Marionette TRACE 366 -> [0,6,"deleteSession",{}]
12:48:26 INFO - 1499370506508 Marionette TRACE 366 <- [1,6,null,{}]
12:48:26 INFO - 1499370506511 Marionette DEBUG Closed connection 366
12:48:26 INFO - 1499370506512 Marionette DEBUG Accepted connection 367 from 127.0.0.1:51393
12:48:26 INFO - 1499370506513 Marionette DEBUG Closed connection 367
12:48:26 INFO - 1499370506514 Marionette DEBUG Accepted connection 368 from 127.0.0.1:51394
12:48:26 INFO - 1499370506515 Marionette TRACE 368 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:26 INFO - 1499370506515 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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}
12:48:26 INFO - 1499370506518 Marionette DEBUG Register listener.js for window 12
12:48:26 INFO - 1499370506522 Marionette TRACE 368 <- [1,1,null,{"sessionId":"bcb80ba3-3612-42c1-b12a-fb6fa3953712","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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}}]
12:48:26 INFO - 1499370506523 Marionette TRACE 368 -> [0,2,"deleteSession",{}]
12:48:26 INFO - 1499370506524 Marionette TRACE 368 <- [1,2,null,{}]
12:48:26 INFO - 1499370506526 Marionette DEBUG Closed connection 368
12:48:26 INFO - 1499370506527 Marionette DEBUG Accepted connection 369 from 127.0.0.1:51395
12:48:26 INFO - 1499370506528 Marionette DEBUG Closed connection 369
12:48:26 INFO - 1499370506528 Marionette DEBUG Accepted connection 370 from 127.0.0.1:51396
12:48:26 INFO - 1499370506529 Marionette TRACE 370 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
12:48:26 INFO - 1499370506530 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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}
12:48:26 INFO - 1499370506532 Marionette DEBUG Register listener.js for window 12
12:48:26 INFO - 1499370506536 Marionette TRACE 370 <- [1,1,null,{"sessionId":"8e66e140-2773-4f70-9ff2-6e3e33b1ad6b","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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}}]
12:48:26 INFO - 1499370506541 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"}]
12:48:26 INFO - 1499370506543 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"
12:48:26 INFO - 1499370506547 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"
12:48:26 INFO - 1499370506547 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"
12:48:26 INFO - 1499370506576 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"
12:48:26 INFO - 1499370506582 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"
12:48:26 INFO - 1499370506593 Marionette TRACE 370 <- [1,2,null,{}]
12:48:26 INFO - 1499370506595 Marionette TRACE 370 -> [0,3,"findElement",{"using":"tag name","value":"option"}]
12:48:26 INFO - 1499370506597 Marionette TRACE 370 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"dbaa5570-9824-4078-9a16-9464e24bfaa4","ELEMENT":"dbaa5570-9824-4078-9a16-9464e24bfaa4"}}]
12:48:26 INFO - 1499370506598 Marionette TRACE 370 -> [0,4,"clickElement",{"id":"dbaa5570-9824-4078-9a16-9464e24bfaa4"}]
12:48:26 INFO - 1499370506847 Marionette DEBUG Canceled page load listener because no navigation has been detected
12:48:26 INFO - 1499370506848 Marionette TRACE 370 <- [1,4,null,{}]
12:48:26 INFO - 1499370506849 Marionette TRACE 370 -> [0,5,"getElementProperty",{"id":"dbaa5570-9824-4078-9a16-9464e24bfaa4","name":"selected"}]
12:48:26 INFO - 1499370506854 Marionette TRACE 370 <- [1,5,null,{"value":true}]
12:48:26 INFO - 1499370506856 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}]
12:48:26 INFO - TEST-END: test_click.py TestClick.test_container_element_outside_view1499370506859 Marionette TRACE 370 <- [1,6,null,{"value":null}]
12:48:26 INFO - 1499370506860 Marionette TRACE 370 -> [0,7,"deleteSession",{}]
12:48:26 INFO - 1499370506861 Marionette TRACE 370 <- [1,7,null,{}]
12:48:26 INFO - TEST-PASS | test_click.py TestClick.test_container_element_outside_view | took 376ms
12:48:26 INFO - TEST-START | test_click.py TestClick.test_css_transforms
12:48:26 INFO - 1499370506863 Marionette DEBUG Closed connection 370
12:48:26 INFO - 1499370506865 Marionette DEBUG Accepted connection 371 from 127.0.0.1:51397
12:48:26 INFO - 1499370506865 Marionette DEBUG Closed connection 371
12:48:26 INFO - 1499370506866 Marionette DEBUG Accepted connection 372 from 127.0.0.1:51398
12:48:26 INFO - 1499370506867 Marionette TRACE 372 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:26 INFO - 1499370506868 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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}
12:48:26 INFO - 1499370506870 Marionette DEBUG Register listener.js for window 12
12:48:26 INFO - 1499370506874 Marionette TRACE 372 <- [1,1,null,{"sessionId":"39c8b770-6a7e-4f6a-8fb5-d073a4a9f8f1","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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}}]
12:48:26 INFO - 1499370506875 Marionette TRACE 372 -> [0,2,"setTimeouts",{"script":30000}]
12:48:26 INFO - 1499370506876 Marionette TRACE 372 <- [1,2,null,{}]
12:48:26 INFO - 1499370506876 Marionette TRACE 372 -> [0,3,"setTimeouts",{"pageLoad":300000}]
12:48:26 INFO - 1499370506877 Marionette TRACE 372 <- [1,3,null,{}]
12:48:26 INFO - 1499370506878 Marionette TRACE 372 -> [0,4,"setTimeouts",{"implicit":0}]
12:48:26 INFO - 1499370506878 Marionette TRACE 372 <- [1,4,null,{}]
12:48:26 INFO - 1499370506880 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}]
12:48:26 INFO - TEST-START: test_click.py TestClick.test_css_transforms1499370506883 Marionette TRACE 372 <- [1,5,null,{"value":null}]
12:48:26 INFO - 1499370506884 Marionette TRACE 372 -> [0,6,"deleteSession",{}]
12:48:26 INFO - 1499370506885 Marionette TRACE 372 <- [1,6,null,{}]
12:48:26 INFO - 1499370506887 Marionette DEBUG Closed connection 372
12:48:26 INFO - 1499370506888 Marionette DEBUG Accepted connection 373 from 127.0.0.1:51399
12:48:26 INFO - 1499370506889 Marionette DEBUG Closed connection 373
12:48:26 INFO - 1499370506890 Marionette DEBUG Accepted connection 374 from 127.0.0.1:51400
12:48:26 INFO - 1499370506891 Marionette TRACE 374 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:26 INFO - 1499370506891 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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}
12:48:26 INFO - 1499370506894 Marionette DEBUG Register listener.js for window 12
12:48:26 INFO - 1499370506897 Marionette TRACE 374 <- [1,1,null,{"sessionId":"db56beb1-b669-46e0-a32e-32e8925ea6d7","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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}}]
12:48:26 INFO - 1499370506898 Marionette TRACE 374 -> [0,2,"deleteSession",{}]
12:48:26 INFO - 1499370506899 Marionette TRACE 374 <- [1,2,null,{}]
12:48:26 INFO - 1499370506901 Marionette DEBUG Closed connection 374
12:48:26 INFO - 1499370506902 Marionette DEBUG Accepted connection 375 from 127.0.0.1:51401
12:48:26 INFO - 1499370506903 Marionette DEBUG Closed connection 375
12:48:26 INFO - 1499370506904 Marionette DEBUG Accepted connection 376 from 127.0.0.1:51402
12:48:26 INFO - 1499370506905 Marionette TRACE 376 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
12:48:26 INFO - 1499370506906 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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}
12:48:26 INFO - 1499370506908 Marionette DEBUG Register listener.js for window 12
12:48:26 INFO - 1499370506911 Marionette TRACE 376 <- [1,1,null,{"sessionId":"f2e50a22-8d4f-48e9-adeb-ec0699ce747d","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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}}]
12:48:26 INFO - 1499370506913 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"}]
12:48:26 INFO - 1499370506914 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"
12:48:26 INFO - 1499370506917 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"
12:48:26 INFO - 1499370506917 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"
12:48:26 INFO - 1499370506930 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"
12:48:26 INFO - 1499370506934 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"
12:48:26 INFO - 1499370506947 Marionette TRACE 376 <- [1,2,null,{}]
12:48:26 INFO - 1499370506950 Marionette TRACE 376 -> [0,3,"findElement",{"using":"tag name","value":"div"}]
12:48:26 INFO - 1499370506953 Marionette TRACE 376 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"f8539e71-f81b-4964-b3df-b33470aa65bf","ELEMENT":"f8539e71-f81b-4964-b3df-b33470aa65bf"}}]
12:48:26 INFO - 1499370506954 Marionette TRACE 376 -> [0,4,"clickElement",{"id":"f8539e71-f81b-4964-b3df-b33470aa65bf"}]
12:48:27 INFO - 1499370507193 Marionette DEBUG Canceled page load listener because no navigation has been detected
12:48:27 INFO - 1499370507194 Marionette TRACE 376 <- [1,4,null,{}]
12:48:27 INFO - 1499370507196 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}]
12:48:27 INFO - TEST-END: test_click.py TestClick.test_css_transforms1499370507199 Marionette TRACE 376 <- [1,5,null,{"value":null}]
12:48:27 INFO - 1499370507200 Marionette TRACE 376 -> [0,6,"deleteSession",{}]
12:48:27 INFO - 1499370507201 Marionette TRACE 376 <- [1,6,null,{}]
12:48:27 INFO - TEST-PASS | test_click.py TestClick.test_css_transforms | took 340ms
12:48:27 INFO - TEST-START | test_click.py TestClick.test_inclusive_descendant
12:48:27 INFO - 1499370507203 Marionette DEBUG Closed connection 376
12:48:27 INFO - 1499370507205 Marionette DEBUG Accepted connection 377 from 127.0.0.1:51403
12:48:27 INFO - 1499370507205 Marionette DEBUG Closed connection 377
12:48:27 INFO - 1499370507206 Marionette DEBUG Accepted connection 378 from 127.0.0.1:51404
12:48:27 INFO - 1499370507207 Marionette TRACE 378 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:27 INFO - 1499370507208 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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}
12:48:27 INFO - 1499370507210 Marionette DEBUG Register listener.js for window 12
12:48:27 INFO - 1499370507213 Marionette TRACE 378 <- [1,1,null,{"sessionId":"40c678c9-b960-48be-9a2d-b3b37b1a2f2d","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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}}]
12:48:27 INFO - 1499370507214 Marionette TRACE 378 -> [0,2,"setTimeouts",{"script":30000}]
12:48:27 INFO - 1499370507214 Marionette TRACE 378 <- [1,2,null,{}]
12:48:27 INFO - 1499370507215 Marionette TRACE 378 -> [0,3,"setTimeouts",{"pageLoad":300000}]
12:48:27 INFO - 1499370507216 Marionette TRACE 378 <- [1,3,null,{}]
12:48:27 INFO - 1499370507217 Marionette TRACE 378 -> [0,4,"setTimeouts",{"implicit":0}]
12:48:27 INFO - 1499370507217 Marionette TRACE 378 <- [1,4,null,{}]
12:48:27 INFO - 1499370507219 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}]
12:48:27 INFO - TEST-START: test_click.py TestClick.test_inclusive_descendant1499370507222 Marionette TRACE 378 <- [1,5,null,{"value":null}]
12:48:27 INFO - 1499370507222 Marionette TRACE 378 -> [0,6,"deleteSession",{}]
12:48:27 INFO - 1499370507224 Marionette TRACE 378 <- [1,6,null,{}]
12:48:27 INFO - 1499370507225 Marionette DEBUG Closed connection 378
12:48:27 INFO - 1499370507226 Marionette DEBUG Accepted connection 379 from 127.0.0.1:51405
12:48:27 INFO - 1499370507227 Marionette DEBUG Closed connection 379
12:48:27 INFO - 1499370507228 Marionette DEBUG Accepted connection 380 from 127.0.0.1:51406
12:48:27 INFO - 1499370507229 Marionette TRACE 380 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:27 INFO - 1499370507229 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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}
12:48:27 INFO - 1499370507231 Marionette DEBUG Register listener.js for window 12
12:48:27 INFO - 1499370507235 Marionette TRACE 380 <- [1,1,null,{"sessionId":"84c29c0e-05ca-4553-87db-6cffe7bb7c76","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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}}]
12:48:27 INFO - 1499370507236 Marionette TRACE 380 -> [0,2,"deleteSession",{}]
12:48:27 INFO - 1499370507237 Marionette TRACE 380 <- [1,2,null,{}]
12:48:27 INFO - 1499370507238 Marionette DEBUG Closed connection 380
12:48:27 INFO - 1499370507239 Marionette DEBUG Accepted connection 381 from 127.0.0.1:51407
12:48:27 INFO - 1499370507240 Marionette DEBUG Closed connection 381
12:48:27 INFO - 1499370507241 Marionette DEBUG Accepted connection 382 from 127.0.0.1:51408
12:48:27 INFO - 1499370507241 Marionette TRACE 382 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
12:48:27 INFO - 1499370507242 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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}
12:48:27 INFO - 1499370507244 Marionette DEBUG Register listener.js for window 12
12:48:27 INFO - 1499370507247 Marionette TRACE 382 <- [1,1,null,{"sessionId":"713accdf-cf53-4188-a86d-7c55140ba8a5","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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}}]
12:48:27 INFO - 1499370507248 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"}]
12:48:27 INFO - 1499370507252 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"
12:48:27 INFO - 1499370507255 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"
12:48:27 INFO - 1499370507256 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"
12:48:27 INFO - 1499370507274 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"
12:48:27 INFO - 1499370507276 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"
12:48:27 INFO - 1499370507279 Marionette TRACE 382 <- [1,2,null,{}]
12:48:27 INFO - 1499370507281 Marionette TRACE 382 -> [0,3,"findElement",{"using":"tag name","value":"select"}]
12:48:27 INFO - 1499370507290 Marionette TRACE 382 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"54eccda4-50bf-4802-a229-7c4240bd3419","ELEMENT":"54eccda4-50bf-4802-a229-7c4240bd3419"}}]
12:48:27 INFO - 1499370507292 Marionette TRACE 382 -> [0,4,"clickElement",{"id":"54eccda4-50bf-4802-a229-7c4240bd3419"}]
12:48:27 INFO - 1499370507533 Marionette DEBUG Canceled page load listener because no navigation has been detected
12:48:27 INFO - 1499370507534 Marionette TRACE 382 <- [1,4,null,{}]
12:48:27 INFO - 1499370507536 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}]
12:48:27 INFO - TEST-END: test_click.py TestClick.test_inclusive_descendant1499370507539 Marionette TRACE 382 <- [1,5,null,{"value":null}]
12:48:27 INFO - 1499370507540 Marionette TRACE 382 -> [0,6,"deleteSession",{}]
12:48:27 INFO - TEST-PASS | test_click.py TestClick.test_inclusive_descendant | took 340ms
12:48:27 INFO - TEST-START | test_click.py TestClick.test_input_file
12:48:27 INFO - 1499370507541 Marionette TRACE 382 <- [1,6,null,{}]
12:48:27 INFO - 1499370507543 Marionette DEBUG Closed connection 382
12:48:27 INFO - 1499370507544 Marionette DEBUG Accepted connection 383 from 127.0.0.1:51409
12:48:27 INFO - 1499370507545 Marionette DEBUG Closed connection 383
12:48:27 INFO - 1499370507546 Marionette DEBUG Accepted connection 384 from 127.0.0.1:51410
12:48:27 INFO - 1499370507547 Marionette TRACE 384 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:27 INFO - 1499370507547 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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}
12:48:27 INFO - 1499370507549 Marionette DEBUG Register listener.js for window 12
12:48:27 INFO - 1499370507560 Marionette TRACE 384 <- [1,1,null,{"sessionId":"d0e3fa35-fff6-4c0c-a002-2e1b55aec136","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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}}]
12:48:27 INFO - 1499370507562 Marionette TRACE 384 -> [0,2,"setTimeouts",{"script":30000}]
12:48:27 INFO - 1499370507562 Marionette TRACE 384 <- [1,2,null,{}]
12:48:27 INFO - 1499370507563 Marionette TRACE 384 -> [0,3,"setTimeouts",{"pageLoad":300000}]
12:48:27 INFO - 1499370507564 Marionette TRACE 384 <- [1,3,null,{}]
12:48:27 INFO - 1499370507564 Marionette TRACE 384 -> [0,4,"setTimeouts",{"implicit":0}]
12:48:27 INFO - 1499370507565 Marionette TRACE 384 <- [1,4,null,{}]
12:48:27 INFO - 1499370507567 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}]
12:48:27 INFO - TEST-START: test_click.py TestClick.test_input_file1499370507570 Marionette TRACE 384 <- [1,5,null,{"value":null}]
12:48:27 INFO - 1499370507570 Marionette TRACE 384 -> [0,6,"deleteSession",{}]
12:48:27 INFO - 1499370507572 Marionette TRACE 384 <- [1,6,null,{}]
12:48:27 INFO - 1499370507573 Marionette DEBUG Closed connection 384
12:48:27 INFO - 1499370507574 Marionette DEBUG Accepted connection 385 from 127.0.0.1:51411
12:48:27 INFO - 1499370507575 Marionette DEBUG Closed connection 385
12:48:27 INFO - 1499370507575 Marionette DEBUG Accepted connection 386 from 127.0.0.1:51412
12:48:27 INFO - 1499370507576 Marionette TRACE 386 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:27 INFO - 1499370507577 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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}
12:48:27 INFO - 1499370507579 Marionette DEBUG Register listener.js for window 12
12:48:27 INFO - 1499370507582 Marionette TRACE 386 <- [1,1,null,{"sessionId":"a6a0814f-7b73-4d6f-a753-82d2a872a3fb","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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}}]
12:48:27 INFO - 1499370507583 Marionette TRACE 386 -> [0,2,"deleteSession",{}]
12:48:27 INFO - 1499370507584 Marionette TRACE 386 <- [1,2,null,{}]
12:48:27 INFO - 1499370507586 Marionette DEBUG Closed connection 386
12:48:27 INFO - 1499370507587 Marionette DEBUG Accepted connection 387 from 127.0.0.1:51413
12:48:27 INFO - 1499370507588 Marionette DEBUG Closed connection 387
12:48:27 INFO - 1499370507588 Marionette DEBUG Accepted connection 388 from 127.0.0.1:51414
12:48:27 INFO - 1499370507589 Marionette TRACE 388 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
12:48:27 INFO - 1499370507590 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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}
12:48:27 INFO - 1499370507592 Marionette DEBUG Register listener.js for window 12
12:48:27 INFO - 1499370507595 Marionette TRACE 388 <- [1,1,null,{"sessionId":"85ee315d-07b5-4249-a077-7eff6f81954a","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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}}]
12:48:27 INFO - 1499370507596 Marionette TRACE 388 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"}]
12:48:27 INFO - 1499370507597 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"
12:48:27 INFO - 1499370507599 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"
12:48:27 INFO - 1499370507600 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"
12:48:27 INFO - 1499370507613 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
12:48:27 INFO - 1499370507618 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
12:48:27 INFO - 1499370507628 Marionette TRACE 388 <- [1,2,null,{}]
12:48:27 INFO - 1499370507630 Marionette TRACE 388 -> [0,3,"findElement",{"using":"tag name","value":"input"}]
12:48:27 INFO - 1499370507633 Marionette TRACE 388 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"04410bfe-f61b-47c6-af43-c834ebd0568c","ELEMENT":"04410bfe-f61b-47c6-af43-c834ebd0568c"}}]
12:48:27 INFO - 1499370507634 Marionette TRACE 388 -> [0,4,"clickElement",{"id":"04410bfe-f61b-47c6-af43-c834ebd0568c"}]
12:48:27 INFO - 1499370507660 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:393:12\nclickElement@chrome://marionette/content/listener.js:1318:5\n"},null]
12:48:27 INFO - 1499370507662 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}]
12:48:27 INFO - TEST-END: test_click.py TestClick.test_input_file1499370507665 Marionette TRACE 388 <- [1,5,null,{"value":null}]
12:48:27 INFO - 1499370507666 Marionette TRACE 388 -> [0,6,"deleteSession",{}]
12:48:27 INFO - TEST-PASS | test_click.py TestClick.test_input_file | took 126ms
12:48:27 INFO - TEST-START | test_click.py TestClick.test_obscured_element
12:48:27 INFO - 1499370507667 Marionette TRACE 388 <- [1,6,null,{}]
12:48:27 INFO - 1499370507669 Marionette DEBUG Closed connection 388
12:48:27 INFO - 1499370507670 Marionette DEBUG Accepted connection 389 from 127.0.0.1:51415
12:48:27 INFO - 1499370507671 Marionette DEBUG Closed connection 389
12:48:27 INFO - 1499370507672 Marionette DEBUG Accepted connection 390 from 127.0.0.1:51416
12:48:27 INFO - 1499370507673 Marionette TRACE 390 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:27 INFO - 1499370507673 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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}
12:48:27 INFO - 1499370507675 Marionette DEBUG Register listener.js for window 12
12:48:27 INFO - 1499370507679 Marionette TRACE 390 <- [1,1,null,{"sessionId":"1a3dbf69-24bb-494a-baf5-190c14a484fa","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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}}]
12:48:27 INFO - 1499370507680 Marionette TRACE 390 -> [0,2,"setTimeouts",{"script":30000}]
12:48:27 INFO - 1499370507680 Marionette TRACE 390 <- [1,2,null,{}]
12:48:27 INFO - 1499370507681 Marionette TRACE 390 -> [0,3,"setTimeouts",{"pageLoad":300000}]
12:48:27 INFO - 1499370507681 Marionette TRACE 390 <- [1,3,null,{}]
12:48:27 INFO - 1499370507682 Marionette TRACE 390 -> [0,4,"setTimeouts",{"implicit":0}]
12:48:27 INFO - 1499370507683 Marionette TRACE 390 <- [1,4,null,{}]
12:48:27 INFO - 1499370507684 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}]
12:48:27 INFO - TEST-START: test_click.py TestClick.test_obscured_element1499370507687 Marionette TRACE 390 <- [1,5,null,{"value":null}]
12:48:27 INFO - 1499370507688 Marionette TRACE 390 -> [0,6,"deleteSession",{}]
12:48:27 INFO - 1499370507689 Marionette TRACE 390 <- [1,6,null,{}]
12:48:27 INFO - 1499370507691 Marionette DEBUG Closed connection 390
12:48:27 INFO - 1499370507692 Marionette DEBUG Accepted connection 391 from 127.0.0.1:51417
12:48:27 INFO - 1499370507692 Marionette DEBUG Closed connection 391
12:48:27 INFO - 1499370507693 Marionette DEBUG Accepted connection 392 from 127.0.0.1:51418
12:48:27 INFO - 1499370507694 Marionette TRACE 392 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:27 INFO - 1499370507695 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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}
12:48:27 INFO - 1499370507697 Marionette DEBUG Register listener.js for window 12
12:48:27 INFO - 1499370507700 Marionette TRACE 392 <- [1,1,null,{"sessionId":"866f1c91-f4b0-46e0-ba8f-b1433943ee20","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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}}]
12:48:27 INFO - 1499370507703 Marionette TRACE 392 -> [0,2,"deleteSession",{}]
12:48:27 INFO - 1499370507704 Marionette TRACE 392 <- [1,2,null,{}]
12:48:27 INFO - 1499370507706 Marionette DEBUG Closed connection 392
12:48:27 INFO - 1499370507707 Marionette DEBUG Accepted connection 393 from 127.0.0.1:51419
12:48:27 INFO - 1499370507707 Marionette DEBUG Closed connection 393
12:48:27 INFO - 1499370507708 Marionette DEBUG Accepted connection 394 from 127.0.0.1:51420
12:48:27 INFO - 1499370507709 Marionette TRACE 394 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
12:48:27 INFO - 1499370507710 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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}
12:48:27 INFO - 1499370507712 Marionette DEBUG Register listener.js for window 12
12:48:27 INFO - 1499370507715 Marionette TRACE 394 <- [1,1,null,{"sessionId":"5923060a-b286-4cad-a415-78d17aa9496a","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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}}]
12:48:27 INFO - 1499370507716 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"}]
12:48:27 INFO - 1499370507717 Marionette DEBUG Received DOM event "beforeunload" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
12:48:27 INFO - 1499370507720 Marionette DEBUG Received DOM event "pagehide" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
12:48:27 INFO - 1499370507720 Marionette DEBUG Received DOM event "unload" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
12:48:27 INFO - 1499370507732 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"
12:48:27 INFO - 1499370507736 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"
12:48:27 INFO - 1499370507746 Marionette TRACE 394 <- [1,2,null,{}]
12:48:27 INFO - 1499370507747 Marionette TRACE 394 -> [0,3,"findElement",{"using":"id","value":"overlay"}]
12:48:27 INFO - 1499370507752 Marionette TRACE 394 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"c1b443b1-9341-4298-ac55-42a9db1cf209","ELEMENT":"c1b443b1-9341-4298-ac55-42a9db1cf209"}}]
12:48:27 INFO - 1499370507754 Marionette TRACE 394 -> [0,4,"findElement",{"using":"id","value":"obscured"}]
12:48:27 INFO - 1499370507756 Marionette TRACE 394 <- [1,4,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"edfa78d5-057e-4ba1-a8fc-486a358d4aff","ELEMENT":"edfa78d5-057e-4ba1-a8fc-486a358d4aff"}}]
12:48:27 INFO - 1499370507757 Marionette TRACE 394 -> [0,5,"clickElement",{"id":"c1b443b1-9341-4298-ac55-42a9db1cf209"}]
12:48:27 INFO - 1499370507993 Marionette DEBUG Canceled page load listener because no navigation has been detected
12:48:27 INFO - 1499370507994 Marionette TRACE 394 <- [1,5,null,{}]
12:48:27 INFO - 1499370507995 Marionette TRACE 394 -> [0,6,"clickElement",{"id":"edfa78d5-057e-4ba1-a8fc-486a358d4aff"}]
12:48:28 INFO - 1499370508010 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:393:12\nclickElement@chrome://marionette/content/listener.js:1318:5\n"},null]
12:48:28 INFO - 1499370508012 Marionette TRACE 394 -> [0,7,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"test_click.py","script":"return window.clicked","sandbox":null,"line":257}]
12:48:28 INFO - 1499370508015 Marionette TRACE 394 <- [1,7,null,{"value":false}]
12:48:28 INFO - 1499370508016 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}]
12:48:28 INFO - TEST-END: test_click.py TestClick.test_obscured_element1499370508019 Marionette TRACE 394 <- [1,8,null,{"value":null}]
12:48:28 INFO - 1499370508020 Marionette TRACE 394 -> [0,9,"deleteSession",{}]
12:48:28 INFO - 1499370508021 Marionette TRACE 394 <- [1,9,null,{}]
12:48:28 INFO - TEST-PASS | test_click.py TestClick.test_obscured_element | took 354ms
12:48:28 INFO - TEST-START | test_click.py TestClick.test_pointer_events_none
12:48:28 INFO - 1499370508023 Marionette DEBUG Closed connection 394
12:48:28 INFO - 1499370508024 Marionette DEBUG Accepted connection 395 from 127.0.0.1:51421
12:48:28 INFO - 1499370508025 Marionette DEBUG Closed connection 395
12:48:28 INFO - 1499370508026 Marionette DEBUG Accepted connection 396 from 127.0.0.1:51422
12:48:28 INFO - 1499370508027 Marionette TRACE 396 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:28 INFO - 1499370508027 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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}
12:48:28 INFO - 1499370508030 Marionette DEBUG Register listener.js for window 12
12:48:28 INFO - 1499370508033 Marionette TRACE 396 <- [1,1,null,{"sessionId":"f41fd623-42e8-4952-b001-46abf1a55453","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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}}]
12:48:28 INFO - 1499370508034 Marionette TRACE 396 -> [0,2,"setTimeouts",{"script":30000}]
12:48:28 INFO - 1499370508035 Marionette TRACE 396 <- [1,2,null,{}]
12:48:28 INFO - 1499370508035 Marionette TRACE 396 -> [0,3,"setTimeouts",{"pageLoad":300000}]
12:48:28 INFO - 1499370508036 Marionette TRACE 396 <- [1,3,null,{}]
12:48:28 INFO - 1499370508037 Marionette TRACE 396 -> [0,4,"setTimeouts",{"implicit":0}]
12:48:28 INFO - 1499370508037 Marionette TRACE 396 <- [1,4,null,{}]
12:48:28 INFO - 1499370508039 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}]
12:48:28 INFO - TEST-START: test_click.py TestClick.test_pointer_events_none1499370508041 Marionette TRACE 396 <- [1,5,null,{"value":null}]
12:48:28 INFO - 1499370508042 Marionette TRACE 396 -> [0,6,"deleteSession",{}]
12:48:28 INFO - 1499370508043 Marionette TRACE 396 <- [1,6,null,{}]
12:48:28 INFO - 1499370508045 Marionette DEBUG Closed connection 396
12:48:28 INFO - 1499370508046 Marionette DEBUG Accepted connection 397 from 127.0.0.1:51423
12:48:28 INFO - 1499370508047 Marionette DEBUG Closed connection 397
12:48:28 INFO - 1499370508048 Marionette DEBUG Accepted connection 398 from 127.0.0.1:51424
12:48:28 INFO - 1499370508049 Marionette TRACE 398 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:28 INFO - 1499370508049 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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}
12:48:28 INFO - 1499370508051 Marionette DEBUG Register listener.js for window 12
12:48:28 INFO - 1499370508054 Marionette TRACE 398 <- [1,1,null,{"sessionId":"6aee0f3b-98bc-4a06-9dbe-e0341e376844","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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}}]
12:48:28 INFO - 1499370508055 Marionette TRACE 398 -> [0,2,"deleteSession",{}]
12:48:28 INFO - 1499370508056 Marionette TRACE 398 <- [1,2,null,{}]
12:48:28 INFO - 1499370508058 Marionette DEBUG Closed connection 398
12:48:28 INFO - 1499370508059 Marionette DEBUG Accepted connection 399 from 127.0.0.1:51425
12:48:28 INFO - 1499370508060 Marionette DEBUG Closed connection 399
12:48:28 INFO - 1499370508060 Marionette DEBUG Accepted connection 400 from 127.0.0.1:51426
12:48:28 INFO - 1499370508061 Marionette TRACE 400 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
12:48:28 INFO - 1499370508062 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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}
12:48:28 INFO - 1499370508072 Marionette DEBUG Register listener.js for window 12
12:48:28 INFO - 1499370508077 Marionette TRACE 400 <- [1,1,null,{"sessionId":"3938e8e6-2d13-4282-8eef-e6e92e1e5b99","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":1568,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4twb61.mozrunner","moz:accessibilityChecks":false}}]
12:48:28 INFO - 1499370508079 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"}]
12:48:28 INFO - 1499370508080 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"
12:48:28 INFO - 1499370508083 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"
12:48:28 INFO - 1499370508083 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"
12:48:28 INFO - 1499370508095 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"
12:48:28 INFO - 1499370508098 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"
12:48:28 INFO - 1499370508108 Marionette TRACE 400 <- [1,2,null,{}]
12:48:28 INFO - 1499370508111 Marionette TRACE 400 -> [0,3,"findElement",{"using":"tag name","value":"button"}]
12:48:28 INFO - 1499370508113 Marionette TRACE 400 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"989f2c97-62fd-47ea-98b4-6f07f84355ad","ELEMENT":"989f2c97-62fd-47ea-98b4-6f07f84355ad"}}]
12:48:28 INFO - 1499370508114 Marionette TRACE 400 -> [0,4,"getElementValueOfCssProperty",{"propertyName":"pointer-events","id":"989f2c97-62fd-47ea-98b4-6f07f84355ad"}]
12:48:28 INFO - 1499370508135 Marionette TRACE 400 <- [1,4,null,{"value":"none"}]
12:48:28 INFO - 1499370508139 Marionette TRACE 400 -> [0,5,"clickElement",{"id":"989f2c97-62fd-47ea-98b4-6f07f84355ad"}]
12:48:28 INFO - 1499370508157 Marionette TRACE 400 <- [1,5,{"error":"element click intercepted","message":"Element