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:447:12\nclickElement@chrome://marionette/content/listener.js:1367:5\n"},null]
03:39:43 INFO - 1501065583892 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}]
03:39:43 INFO - TEST-END: test_click.py TestClick.test_clicking_an_element_that_is_not_displayed_raises1501065583895 Marionette TRACE 352 <- [1,5,null,{"value":null}]
03:39:43 INFO - 1501065583896 Marionette TRACE 352 -> [0,6,"deleteSession",{}]
03:39:43 INFO - TEST-PASS | test_click.py TestClick.test_clicking_an_element_that_is_not_displayed_raises | took 174ms
03:39:43 INFO - 1501065583898 Marionette TRACE 352 <- [1,6,null,{}]
03:39:43 INFO - TEST-START | test_click.py TestClick.test_clicking_on_a_multiline_link
03:39:43 INFO - 1501065583900 Marionette DEBUG Closed connection 352
03:39:43 INFO - 1501065583901 Marionette DEBUG Accepted connection 353 from 127.0.0.1:49821
03:39:43 INFO - 1501065583902 Marionette DEBUG Closed connection 353
03:39:43 INFO - 1501065583903 Marionette DEBUG Accepted connection 354 from 127.0.0.1:49822
03:39:43 INFO - 1501065583904 Marionette TRACE 354 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
03:39:43 INFO - 1501065583905 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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}
03:39:43 INFO - 1501065583915 Marionette DEBUG Register listener.js for window 12
03:39:43 INFO - 1501065583918 Marionette TRACE 354 <- [1,1,null,{"sessionId":"ef718cc1-6e22-4546-b27b-f9b80978fc1d","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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}}]
03:39:43 INFO - 1501065583921 Marionette TRACE 354 -> [0,2,"setTimeouts",{"script":30000}]
03:39:43 INFO - 1501065583921 Marionette TRACE 354 <- [1,2,null,{}]
03:39:43 INFO - 1501065583923 Marionette TRACE 354 -> [0,3,"setTimeouts",{"pageLoad":300000}]
03:39:43 INFO - 1501065583923 Marionette TRACE 354 <- [1,3,null,{}]
03:39:43 INFO - 1501065583924 Marionette TRACE 354 -> [0,4,"setTimeouts",{"implicit":0}]
03:39:43 INFO - 1501065583924 Marionette TRACE 354 <- [1,4,null,{}]
03:39:43 INFO - 1501065583926 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}]
03:39:43 INFO - TEST-START: test_click.py TestClick.test_clicking_on_a_multiline_link1501065583930 Marionette TRACE 354 <- [1,5,null,{"value":null}]
03:39:43 INFO - 1501065583930 Marionette TRACE 354 -> [0,6,"deleteSession",{}]
03:39:43 INFO - 1501065583932 Marionette TRACE 354 <- [1,6,null,{}]
03:39:43 INFO - 1501065583936 Marionette DEBUG Closed connection 354
03:39:43 INFO - 1501065583937 Marionette DEBUG Accepted connection 355 from 127.0.0.1:49823
03:39:43 INFO - 1501065583938 Marionette DEBUG Closed connection 355
03:39:43 INFO - 1501065583939 Marionette DEBUG Accepted connection 356 from 127.0.0.1:49824
03:39:43 INFO - 1501065583940 Marionette TRACE 356 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
03:39:43 INFO - 1501065583940 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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}
03:39:43 INFO - 1501065583943 Marionette DEBUG Register listener.js for window 12
03:39:43 INFO - 1501065583946 Marionette TRACE 356 <- [1,1,null,{"sessionId":"d461f1c4-53cf-4181-b98a-9ce89980fb6d","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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}}]
03:39:43 INFO - 1501065583948 Marionette TRACE 356 -> [0,2,"deleteSession",{}]
03:39:43 INFO - 1501065583950 Marionette TRACE 356 <- [1,2,null,{}]
03:39:43 INFO - 1501065583952 Marionette DEBUG Closed connection 356
03:39:43 INFO - 1501065583953 Marionette DEBUG Accepted connection 357 from 127.0.0.1:49825
03:39:43 INFO - 1501065583954 Marionette DEBUG Closed connection 357
03:39:43 INFO - 1501065583954 Marionette DEBUG Accepted connection 358 from 127.0.0.1:49826
03:39:43 INFO - 1501065583955 Marionette TRACE 358 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
03:39:43 INFO - 1501065583956 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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}
03:39:43 INFO - 1501065583958 Marionette DEBUG Register listener.js for window 12
03:39:43 INFO - 1501065583962 Marionette TRACE 358 <- [1,1,null,{"sessionId":"ba282726-be0c-452d-8ff9-30dffd36e35a","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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}}]
03:39:43 INFO - 1501065583964 Marionette TRACE 358 -> [0,2,"get",{"url":"http://127.0.0.1:49383/clicks.html"}]
03:39:43 INFO - 1501065583965 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49383/hidden.html"
03:39:43 INFO - 1501065583972 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49383/hidden.html"
03:39:43 INFO - 1501065583972 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49383/hidden.html"
03:39:44 INFO - 1501065583997 Marionette DEBUG Received DOM event "DOMContentLoaded" for "http://127.0.0.1:49383/clicks.html"
03:39:44 INFO - 1501065583999 Marionette DEBUG Received DOM event "pageshow" for "http://127.0.0.1:49383/clicks.html"
03:39:44 INFO - 1501065584011 Marionette TRACE 358 <- [1,2,null,{}]
03:39:44 INFO - 1501065584013 Marionette TRACE 358 -> [0,3,"findElement",{"using":"id","value":"overflowLink"}]
03:39:44 INFO - 1501065584015 Marionette TRACE 358 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"a095a0ee-25d6-4d23-8fa9-1969e5049b8a","ELEMENT":"a095a0ee-25d6-4d23-8fa9-1969e5049b8a"}}]
03:39:44 INFO - 1501065584016 Marionette TRACE 358 -> [0,4,"clickElement",{"id":"a095a0ee-25d6-4d23-8fa9-1969e5049b8a"}]
03:39:44 INFO - 1501065584061 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49383/clicks.html"
03:39:44 INFO - 1501065584073 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49383/clicks.html"
03:39:44 INFO - 1501065584074 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49383/clicks.html"
03:39:44 INFO - 1501065584111 Marionette DEBUG Received DOM event "DOMContentLoaded" for "http://127.0.0.1:49383/test.html"
03:39:44 INFO - 1501065584115 Marionette DEBUG Received DOM event "pageshow" for "http://127.0.0.1:49383/test.html"
03:39:44 INFO - 1501065584120 Marionette TRACE 358 <- [1,4,null,{}]
03:39:44 INFO - 1501065584129 Marionette TRACE 358 -> [0,5,"findElement",{"using":"id","value":"testDiv"}]
03:39:44 INFO - 1501065584132 Marionette TRACE 358 <- [1,5,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"2bf486bf-a933-462f-9223-7e3ff902582e","ELEMENT":"2bf486bf-a933-462f-9223-7e3ff902582e"}}]
03:39:44 INFO - 1501065584133 Marionette TRACE 358 -> [0,6,"getTitle",{}]
03:39:44 INFO - 1501065584134 Marionette TRACE 358 <- [1,6,null,{"value":"Marionette Test"}]
03:39:44 INFO - 1501065584140 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}]
03:39:44 INFO - TEST-END: test_click.py TestClick.test_clicking_on_a_multiline_link1501065584143 Marionette TRACE 358 <- [1,7,null,{"value":null}]
03:39:44 INFO - 1501065584144 Marionette TRACE 358 -> [0,8,"deleteSession",{}]
03:39:44 INFO - TEST-PASS | test_click.py TestClick.test_clicking_on_a_multiline_link | took 247ms
03:39:44 INFO - TEST-START | test_click.py TestClick.test_container_element
03:39:44 INFO - 1501065584146 Marionette TRACE 358 <- [1,8,null,{}]
03:39:44 INFO - 1501065584148 Marionette DEBUG Closed connection 358
03:39:44 INFO - 1501065584149 Marionette DEBUG Accepted connection 359 from 127.0.0.1:49829
03:39:44 INFO - 1501065584151 Marionette DEBUG Closed connection 359
03:39:44 INFO - 1501065584151 Marionette DEBUG Accepted connection 360 from 127.0.0.1:49830
03:39:44 INFO - 1501065584175 Marionette TRACE 360 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
03:39:44 INFO - 1501065584176 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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}
03:39:44 INFO - 1501065584178 Marionette DEBUG Register listener.js for window 12
03:39:44 INFO - 1501065584182 Marionette TRACE 360 <- [1,1,null,{"sessionId":"c374445a-9835-4296-af7d-3fa00b32ba8f","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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}}]
03:39:44 INFO - 1501065584184 Marionette TRACE 360 -> [0,2,"setTimeouts",{"script":30000}]
03:39:44 INFO - 1501065584185 Marionette TRACE 360 <- [1,2,null,{}]
03:39:44 INFO - 1501065584186 Marionette TRACE 360 -> [0,3,"setTimeouts",{"pageLoad":300000}]
03:39:44 INFO - 1501065584186 Marionette TRACE 360 <- [1,3,null,{}]
03:39:44 INFO - 1501065584187 Marionette TRACE 360 -> [0,4,"setTimeouts",{"implicit":0}]
03:39:44 INFO - 1501065584188 Marionette TRACE 360 <- [1,4,null,{}]
03:39:44 INFO - 1501065584190 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}]
03:39:44 INFO - TEST-START: test_click.py TestClick.test_container_element1501065584193 Marionette TRACE 360 <- [1,5,null,{"value":null}]
03:39:44 INFO - 1501065584194 Marionette TRACE 360 -> [0,6,"deleteSession",{}]
03:39:44 INFO - 1501065584195 Marionette TRACE 360 <- [1,6,null,{}]
03:39:44 INFO - 1501065584197 Marionette DEBUG Closed connection 360
03:39:44 INFO - 1501065584198 Marionette DEBUG Accepted connection 361 from 127.0.0.1:49831
03:39:44 INFO - 1501065584200 Marionette DEBUG Closed connection 361
03:39:44 INFO - 1501065584200 Marionette DEBUG Accepted connection 362 from 127.0.0.1:49832
03:39:44 INFO - 1501065584201 Marionette TRACE 362 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
03:39:44 INFO - 1501065584202 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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}
03:39:44 INFO - 1501065584204 Marionette DEBUG Register listener.js for window 12
03:39:44 INFO - 1501065584208 Marionette TRACE 362 <- [1,1,null,{"sessionId":"723bf6db-e8ff-4768-b400-fd5ac911c630","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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}}]
03:39:44 INFO - 1501065584210 Marionette TRACE 362 -> [0,2,"deleteSession",{}]
03:39:44 INFO - 1501065584211 Marionette TRACE 362 <- [1,2,null,{}]
03:39:44 INFO - 1501065584214 Marionette DEBUG Closed connection 362
03:39:44 INFO - 1501065584214 Marionette DEBUG Accepted connection 363 from 127.0.0.1:49833
03:39:44 INFO - 1501065584215 Marionette DEBUG Closed connection 363
03:39:44 INFO - 1501065584216 Marionette DEBUG Accepted connection 364 from 127.0.0.1:49834
03:39:44 INFO - 1501065584217 Marionette TRACE 364 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
03:39:44 INFO - 1501065584218 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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}
03:39:44 INFO - 1501065584220 Marionette DEBUG Register listener.js for window 12
03:39:44 INFO - 1501065584223 Marionette TRACE 364 <- [1,1,null,{"sessionId":"0bdcc17d-c80c-4538-805b-5793f73d266c","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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}}]
03:39:44 INFO - 1501065584226 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"}]
03:39:44 INFO - 1501065584228 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49383/test.html"
03:39:44 INFO - 1501065584230 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49383/test.html"
03:39:44 INFO - 1501065584231 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49383/test.html"
03:39:44 INFO - 1501065584259 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"
03:39:44 INFO - 1501065584263 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"
03:39:44 INFO - 1501065584267 Marionette TRACE 364 <- [1,2,null,{}]
03:39:44 INFO - 1501065584278 Marionette TRACE 364 -> [0,3,"findElement",{"using":"tag name","value":"option"}]
03:39:44 INFO - 1501065584281 Marionette TRACE 364 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"89cda030-8be5-43be-8906-7fb41cb44efe","ELEMENT":"89cda030-8be5-43be-8906-7fb41cb44efe"}}]
03:39:44 INFO - 1501065584282 Marionette TRACE 364 -> [0,4,"clickElement",{"id":"89cda030-8be5-43be-8906-7fb41cb44efe"}]
03:39:44 INFO - 1501065584527 Marionette DEBUG Canceled page load listener because no navigation has been detected
03:39:44 INFO - 1501065584528 Marionette TRACE 364 <- [1,4,null,{}]
03:39:44 INFO - 1501065584529 Marionette TRACE 364 -> [0,5,"getElementProperty",{"id":"89cda030-8be5-43be-8906-7fb41cb44efe","name":"selected"}]
03:39:44 INFO - 1501065584535 Marionette TRACE 364 <- [1,5,null,{"value":true}]
03:39:44 INFO - 1501065584537 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}]
03:39:44 INFO - TEST-END: test_click.py TestClick.test_container_element1501065584540 Marionette TRACE 364 <- [1,6,null,{"value":null}]
03:39:44 INFO - 1501065584541 Marionette TRACE 364 -> [0,7,"deleteSession",{}]
03:39:44 INFO - TEST-PASS | test_click.py TestClick.test_container_element | took 397ms
03:39:44 INFO - TEST-START | test_click.py TestClick.test_container_element_outside_view
03:39:44 INFO - 1501065584543 Marionette TRACE 364 <- [1,7,null,{}]
03:39:44 INFO - 1501065584552 Marionette DEBUG Closed connection 364
03:39:44 INFO - 1501065584553 Marionette DEBUG Accepted connection 365 from 127.0.0.1:49835
03:39:44 INFO - 1501065584556 Marionette DEBUG Closed connection 365
03:39:44 INFO - 1501065584556 Marionette DEBUG Accepted connection 366 from 127.0.0.1:49836
03:39:44 INFO - 1501065584558 Marionette TRACE 366 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
03:39:44 INFO - 1501065584558 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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}
03:39:44 INFO - 1501065584560 Marionette DEBUG Register listener.js for window 12
03:39:44 INFO - 1501065584571 Marionette TRACE 366 <- [1,1,null,{"sessionId":"7bffb6e4-0be5-4d47-837d-505d1c64892f","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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}}]
03:39:44 INFO - 1501065584573 Marionette TRACE 366 -> [0,2,"setTimeouts",{"script":30000}]
03:39:44 INFO - 1501065584574 Marionette TRACE 366 <- [1,2,null,{}]
03:39:44 INFO - 1501065584575 Marionette TRACE 366 -> [0,3,"setTimeouts",{"pageLoad":300000}]
03:39:44 INFO - 1501065584575 Marionette TRACE 366 <- [1,3,null,{}]
03:39:44 INFO - 1501065584576 Marionette TRACE 366 -> [0,4,"setTimeouts",{"implicit":0}]
03:39:44 INFO - 1501065584577 Marionette TRACE 366 <- [1,4,null,{}]
03:39:44 INFO - 1501065584579 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}]
03:39:44 INFO - TEST-START: test_click.py TestClick.test_container_element_outside_view1501065584582 Marionette TRACE 366 <- [1,5,null,{"value":null}]
03:39:44 INFO - 1501065584583 Marionette TRACE 366 -> [0,6,"deleteSession",{}]
03:39:44 INFO - 1501065584585 Marionette TRACE 366 <- [1,6,null,{}]
03:39:44 INFO - 1501065584587 Marionette DEBUG Closed connection 366
03:39:44 INFO - 1501065584588 Marionette DEBUG Accepted connection 367 from 127.0.0.1:49837
03:39:44 INFO - 1501065584589 Marionette DEBUG Closed connection 367
03:39:44 INFO - 1501065584590 Marionette DEBUG Accepted connection 368 from 127.0.0.1:49838
03:39:44 INFO - 1501065584591 Marionette TRACE 368 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
03:39:44 INFO - 1501065584591 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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}
03:39:44 INFO - 1501065584593 Marionette DEBUG Register listener.js for window 12
03:39:44 INFO - 1501065584597 Marionette TRACE 368 <- [1,1,null,{"sessionId":"2255dd4c-0837-4594-9685-a5058df57ff0","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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}}]
03:39:44 INFO - 1501065584599 Marionette TRACE 368 -> [0,2,"deleteSession",{}]
03:39:44 INFO - 1501065584600 Marionette TRACE 368 <- [1,2,null,{}]
03:39:44 INFO - 1501065584604 Marionette DEBUG Closed connection 368
03:39:44 INFO - 1501065584605 Marionette DEBUG Accepted connection 369 from 127.0.0.1:49839
03:39:44 INFO - 1501065584606 Marionette DEBUG Closed connection 369
03:39:44 INFO - 1501065584607 Marionette DEBUG Accepted connection 370 from 127.0.0.1:49840
03:39:44 INFO - 1501065584608 Marionette TRACE 370 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
03:39:44 INFO - 1501065584609 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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}
03:39:44 INFO - 1501065584611 Marionette DEBUG Register listener.js for window 12
03:39:44 INFO - 1501065584614 Marionette TRACE 370 <- [1,1,null,{"sessionId":"ddd7e0fa-a9fd-4ac8-a121-1bb2cbfcea8b","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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}}]
03:39:44 INFO - 1501065584617 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"}]
03:39:44 INFO - 1501065584619 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"
03:39:44 INFO - 1501065584622 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"
03:39:44 INFO - 1501065584623 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"
03:39:44 INFO - 1501065584644 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"
03:39:44 INFO - 1501065584647 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"
03:39:44 INFO - 1501065584652 Marionette TRACE 370 <- [1,2,null,{}]
03:39:44 INFO - 1501065584659 Marionette TRACE 370 -> [0,3,"findElement",{"using":"tag name","value":"option"}]
03:39:44 INFO - 1501065584662 Marionette TRACE 370 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"746ce7fb-8751-46ae-a7b5-180e7de7bdd9","ELEMENT":"746ce7fb-8751-46ae-a7b5-180e7de7bdd9"}}]
03:39:44 INFO - 1501065584663 Marionette TRACE 370 -> [0,4,"clickElement",{"id":"746ce7fb-8751-46ae-a7b5-180e7de7bdd9"}]
03:39:44 INFO - 1501065584910 Marionette DEBUG Canceled page load listener because no navigation has been detected
03:39:44 INFO - 1501065584911 Marionette TRACE 370 <- [1,4,null,{}]
03:39:44 INFO - 1501065584912 Marionette TRACE 370 -> [0,5,"getElementProperty",{"id":"746ce7fb-8751-46ae-a7b5-180e7de7bdd9","name":"selected"}]
03:39:44 INFO - 1501065584917 Marionette TRACE 370 <- [1,5,null,{"value":true}]
03:39:44 INFO - 1501065584918 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}]
03:39:44 INFO - TEST-END: test_click.py TestClick.test_container_element_outside_view1501065584921 Marionette TRACE 370 <- [1,6,null,{"value":null}]
03:39:44 INFO - 1501065584922 Marionette TRACE 370 -> [0,7,"deleteSession",{}]
03:39:44 INFO - TEST-PASS | test_click.py TestClick.test_container_element_outside_view | took 380ms
03:39:44 INFO - 1501065584924 Marionette TRACE 370 <- [1,7,null,{}]
03:39:44 INFO - TEST-START | test_click.py TestClick.test_css_transforms
03:39:44 INFO - 1501065584926 Marionette DEBUG Closed connection 370
03:39:44 INFO - 1501065584927 Marionette DEBUG Accepted connection 371 from 127.0.0.1:49841
03:39:44 INFO - 1501065584928 Marionette DEBUG Closed connection 371
03:39:44 INFO - 1501065584929 Marionette DEBUG Accepted connection 372 from 127.0.0.1:49842
03:39:44 INFO - 1501065584930 Marionette TRACE 372 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
03:39:44 INFO - 1501065584931 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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}
03:39:44 INFO - 1501065584933 Marionette DEBUG Register listener.js for window 12
03:39:44 INFO - 1501065584937 Marionette TRACE 372 <- [1,1,null,{"sessionId":"823374c3-a9f1-42c4-b565-bbc25836500c","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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}}]
03:39:44 INFO - 1501065584939 Marionette TRACE 372 -> [0,2,"setTimeouts",{"script":30000}]
03:39:44 INFO - 1501065584939 Marionette TRACE 372 <- [1,2,null,{}]
03:39:44 INFO - 1501065584940 Marionette TRACE 372 -> [0,3,"setTimeouts",{"pageLoad":300000}]
03:39:44 INFO - 1501065584941 Marionette TRACE 372 <- [1,3,null,{}]
03:39:44 INFO - 1501065584942 Marionette TRACE 372 -> [0,4,"setTimeouts",{"implicit":0}]
03:39:44 INFO - 1501065584942 Marionette TRACE 372 <- [1,4,null,{}]
03:39:44 INFO - 1501065584944 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}]
03:39:44 INFO - TEST-START: test_click.py TestClick.test_css_transforms1501065584947 Marionette TRACE 372 <- [1,5,null,{"value":null}]
03:39:44 INFO - 1501065584948 Marionette TRACE 372 -> [0,6,"deleteSession",{}]
03:39:44 INFO - 1501065584949 Marionette TRACE 372 <- [1,6,null,{}]
03:39:44 INFO - 1501065584951 Marionette DEBUG Closed connection 372
03:39:44 INFO - 1501065584952 Marionette DEBUG Accepted connection 373 from 127.0.0.1:49843
03:39:44 INFO - 1501065584953 Marionette DEBUG Closed connection 373
03:39:44 INFO - 1501065584954 Marionette DEBUG Accepted connection 374 from 127.0.0.1:49844
03:39:44 INFO - 1501065584955 Marionette TRACE 374 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
03:39:44 INFO - 1501065584955 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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}
03:39:44 INFO - 1501065584958 Marionette DEBUG Register listener.js for window 12
03:39:44 INFO - 1501065584961 Marionette TRACE 374 <- [1,1,null,{"sessionId":"5c9f9293-c325-4ce8-a466-3993b8918650","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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}}]
03:39:44 INFO - 1501065584963 Marionette TRACE 374 -> [0,2,"deleteSession",{}]
03:39:44 INFO - 1501065584965 Marionette TRACE 374 <- [1,2,null,{}]
03:39:44 INFO - 1501065584967 Marionette DEBUG Closed connection 374
03:39:44 INFO - 1501065584968 Marionette DEBUG Accepted connection 375 from 127.0.0.1:49845
03:39:44 INFO - 1501065584969 Marionette DEBUG Closed connection 375
03:39:44 INFO - 1501065584970 Marionette DEBUG Accepted connection 376 from 127.0.0.1:49846
03:39:44 INFO - 1501065584971 Marionette TRACE 376 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
03:39:44 INFO - 1501065584971 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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}
03:39:44 INFO - 1501065584973 Marionette DEBUG Register listener.js for window 12
03:39:44 INFO - 1501065584977 Marionette TRACE 376 <- [1,1,null,{"sessionId":"48525e7d-051e-47d7-b999-37c596100e76","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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}}]
03:39:44 INFO - 1501065584979 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"}]
03:39:44 INFO - 1501065584980 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"
03:39:44 INFO - 1501065584983 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"
03:39:44 INFO - 1501065584983 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"
03:39:45 INFO - 1501065585010 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"
03:39:45 INFO - 1501065585013 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"
03:39:45 INFO - 1501065585017 Marionette TRACE 376 <- [1,2,null,{}]
03:39:45 INFO - 1501065585026 Marionette TRACE 376 -> [0,3,"findElement",{"using":"tag name","value":"div"}]
03:39:45 INFO - 1501065585029 Marionette TRACE 376 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"a71f4dad-5b36-4072-a76f-b93ad6f78ceb","ELEMENT":"a71f4dad-5b36-4072-a76f-b93ad6f78ceb"}}]
03:39:45 INFO - 1501065585030 Marionette TRACE 376 -> [0,4,"clickElement",{"id":"a71f4dad-5b36-4072-a76f-b93ad6f78ceb"}]
03:39:45 INFO - 1501065585272 Marionette DEBUG Canceled page load listener because no navigation has been detected
03:39:45 INFO - 1501065585272 Marionette TRACE 376 <- [1,4,null,{}]
03:39:45 INFO - 1501065585274 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}]
03:39:45 INFO - TEST-END: test_click.py TestClick.test_css_transforms1501065585277 Marionette TRACE 376 <- [1,5,null,{"value":null}]
03:39:45 INFO - 1501065585278 Marionette TRACE 376 -> [0,6,"deleteSession",{}]
03:39:45 INFO - TEST-PASS | test_click.py TestClick.test_css_transforms | took 355ms
03:39:45 INFO - 1501065585280 Marionette TRACE 376 <- [1,6,null,{}]
03:39:45 INFO - TEST-START | test_click.py TestClick.test_inclusive_descendant
03:39:45 INFO - 1501065585283 Marionette DEBUG Closed connection 376
03:39:45 INFO - 1501065585284 Marionette DEBUG Accepted connection 377 from 127.0.0.1:49847
03:39:45 INFO - 1501065585284 Marionette DEBUG Closed connection 377
03:39:45 INFO - 1501065585285 Marionette DEBUG Accepted connection 378 from 127.0.0.1:49848
03:39:45 INFO - 1501065585286 Marionette TRACE 378 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
03:39:45 INFO - 1501065585287 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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}
03:39:45 INFO - 1501065585289 Marionette DEBUG Register listener.js for window 12
03:39:45 INFO - 1501065585293 Marionette TRACE 378 <- [1,1,null,{"sessionId":"29473d9e-e3f4-4332-bcbc-8a8271d10765","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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}}]
03:39:45 INFO - 1501065585295 Marionette TRACE 378 -> [0,2,"setTimeouts",{"script":30000}]
03:39:45 INFO - 1501065585295 Marionette TRACE 378 <- [1,2,null,{}]
03:39:45 INFO - 1501065585296 Marionette TRACE 378 -> [0,3,"setTimeouts",{"pageLoad":300000}]
03:39:45 INFO - 1501065585297 Marionette TRACE 378 <- [1,3,null,{}]
03:39:45 INFO - 1501065585298 Marionette TRACE 378 -> [0,4,"setTimeouts",{"implicit":0}]
03:39:45 INFO - 1501065585298 Marionette TRACE 378 <- [1,4,null,{}]
03:39:45 INFO - 1501065585300 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}]
03:39:45 INFO - TEST-START: test_click.py TestClick.test_inclusive_descendant1501065585303 Marionette TRACE 378 <- [1,5,null,{"value":null}]
03:39:45 INFO - 1501065585304 Marionette TRACE 378 -> [0,6,"deleteSession",{}]
03:39:45 INFO - 1501065585305 Marionette TRACE 378 <- [1,6,null,{}]
03:39:45 INFO - 1501065585308 Marionette DEBUG Closed connection 378
03:39:45 INFO - 1501065585308 Marionette DEBUG Accepted connection 379 from 127.0.0.1:49849
03:39:45 INFO - 1501065585309 Marionette DEBUG Closed connection 379
03:39:45 INFO - 1501065585310 Marionette DEBUG Accepted connection 380 from 127.0.0.1:49850
03:39:45 INFO - 1501065585311 Marionette TRACE 380 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
03:39:45 INFO - 1501065585319 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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}
03:39:45 INFO - 1501065585322 Marionette DEBUG Register listener.js for window 12
03:39:45 INFO - 1501065585325 Marionette TRACE 380 <- [1,1,null,{"sessionId":"7926e42e-d4ca-4a3d-b901-dd85f61f5b3a","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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}}]
03:39:45 INFO - 1501065585327 Marionette TRACE 380 -> [0,2,"deleteSession",{}]
03:39:45 INFO - 1501065585329 Marionette TRACE 380 <- [1,2,null,{}]
03:39:45 INFO - 1501065585331 Marionette DEBUG Closed connection 380
03:39:45 INFO - 1501065585332 Marionette DEBUG Accepted connection 381 from 127.0.0.1:49851
03:39:45 INFO - 1501065585333 Marionette DEBUG Closed connection 381
03:39:45 INFO - 1501065585334 Marionette DEBUG Accepted connection 382 from 127.0.0.1:49852
03:39:45 INFO - 1501065585335 Marionette TRACE 382 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
03:39:45 INFO - 1501065585335 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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}
03:39:45 INFO - 1501065585337 Marionette DEBUG Register listener.js for window 12
03:39:45 INFO - 1501065585341 Marionette TRACE 382 <- [1,1,null,{"sessionId":"76907e8a-50db-47ac-a1fb-5e7effa7eea2","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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}}]
03:39:45 INFO - 1501065585343 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"}]
03:39:45 INFO - 1501065585345 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"
03:39:45 INFO - 1501065585347 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"
03:39:45 INFO - 1501065585347 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"
03:39:45 INFO - 1501065585373 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"
03:39:45 INFO - 1501065585374 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"
03:39:45 INFO - 1501065585378 Marionette TRACE 382 <- [1,2,null,{}]
03:39:45 INFO - 1501065585379 Marionette TRACE 382 -> [0,3,"findElement",{"using":"tag name","value":"select"}]
03:39:45 INFO - 1501065585382 Marionette TRACE 382 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"f5b43b00-cde1-4d59-b18d-abfd56f1250d","ELEMENT":"f5b43b00-cde1-4d59-b18d-abfd56f1250d"}}]
03:39:45 INFO - 1501065585392 Marionette TRACE 382 -> [0,4,"clickElement",{"id":"f5b43b00-cde1-4d59-b18d-abfd56f1250d"}]
03:39:45 INFO - 1501065585638 Marionette DEBUG Canceled page load listener because no navigation has been detected
03:39:45 INFO - 1501065585638 Marionette TRACE 382 <- [1,4,null,{}]
03:39:45 INFO - 1501065585640 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}]
03:39:45 INFO - TEST-END: test_click.py TestClick.test_inclusive_descendant1501065585643 Marionette TRACE 382 <- [1,5,null,{"value":null}]
03:39:45 INFO - 1501065585644 Marionette TRACE 382 -> [0,6,"deleteSession",{}]
03:39:45 INFO - TEST-PASS | test_click.py TestClick.test_inclusive_descendant | took 365ms
03:39:45 INFO - TEST-START | test_click.py TestClick.test_input_file
03:39:45 INFO - 1501065585646 Marionette TRACE 382 <- [1,6,null,{}]
03:39:45 INFO - 1501065585648 Marionette DEBUG Closed connection 382
03:39:45 INFO - 1501065585649 Marionette DEBUG Accepted connection 383 from 127.0.0.1:49853
03:39:45 INFO - 1501065585650 Marionette DEBUG Closed connection 383
03:39:45 INFO - 1501065585651 Marionette DEBUG Accepted connection 384 from 127.0.0.1:49854
03:39:45 INFO - 1501065585652 Marionette TRACE 384 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
03:39:45 INFO - 1501065585653 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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}
03:39:45 INFO - 1501065585655 Marionette DEBUG Register listener.js for window 12
03:39:45 INFO - 1501065585659 Marionette TRACE 384 <- [1,1,null,{"sessionId":"b948440b-9589-4c72-9177-d2ddb9cc2d47","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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}}]
03:39:45 INFO - 1501065585661 Marionette TRACE 384 -> [0,2,"setTimeouts",{"script":30000}]
03:39:45 INFO - 1501065585661 Marionette TRACE 384 <- [1,2,null,{}]
03:39:45 INFO - 1501065585662 Marionette TRACE 384 -> [0,3,"setTimeouts",{"pageLoad":300000}]
03:39:45 INFO - 1501065585663 Marionette TRACE 384 <- [1,3,null,{}]
03:39:45 INFO - 1501065585664 Marionette TRACE 384 -> [0,4,"setTimeouts",{"implicit":0}]
03:39:45 INFO - 1501065585664 Marionette TRACE 384 <- [1,4,null,{}]
03:39:45 INFO - 1501065585666 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}]
03:39:45 INFO - TEST-START: test_click.py TestClick.test_input_file1501065585669 Marionette TRACE 384 <- [1,5,null,{"value":null}]
03:39:45 INFO - 1501065585670 Marionette TRACE 384 -> [0,6,"deleteSession",{}]
03:39:45 INFO - 1501065585672 Marionette TRACE 384 <- [1,6,null,{}]
03:39:45 INFO - 1501065585674 Marionette DEBUG Closed connection 384
03:39:45 INFO - 1501065585675 Marionette DEBUG Accepted connection 385 from 127.0.0.1:49855
03:39:45 INFO - 1501065585675 Marionette DEBUG Closed connection 385
03:39:45 INFO - 1501065585676 Marionette DEBUG Accepted connection 386 from 127.0.0.1:49856
03:39:45 INFO - 1501065585677 Marionette TRACE 386 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
03:39:45 INFO - 1501065585678 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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}
03:39:45 INFO - 1501065585680 Marionette DEBUG Register listener.js for window 12
03:39:45 INFO - 1501065585683 Marionette TRACE 386 <- [1,1,null,{"sessionId":"49439b5b-d3b6-4ed9-83cb-ccf6d8605f41","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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}}]
03:39:45 INFO - 1501065585685 Marionette TRACE 386 -> [0,2,"deleteSession",{}]
03:39:45 INFO - 1501065585687 Marionette TRACE 386 <- [1,2,null,{}]
03:39:45 INFO - 1501065585689 Marionette DEBUG Closed connection 386
03:39:45 INFO - 1501065585690 Marionette DEBUG Accepted connection 387 from 127.0.0.1:49857
03:39:45 INFO - 1501065585691 Marionette DEBUG Closed connection 387
03:39:45 INFO - 1501065585691 Marionette DEBUG Accepted connection 388 from 127.0.0.1:49858
03:39:45 INFO - 1501065585692 Marionette TRACE 388 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
03:39:45 INFO - 1501065585693 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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}
03:39:45 INFO - 1501065585695 Marionette DEBUG Register listener.js for window 12
03:39:45 INFO - 1501065585698 Marionette TRACE 388 <- [1,1,null,{"sessionId":"b99c049d-3f13-4710-812e-6751dfc4fa6e","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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}}]
03:39:45 INFO - 1501065585701 Marionette TRACE 388 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"}]
03:39:45 INFO - 1501065585702 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"
03:39:45 INFO - 1501065585705 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"
03:39:45 INFO - 1501065585706 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"
03:39:45 INFO - 1501065585728 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
03:39:45 INFO - 1501065585731 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
03:39:45 INFO - 1501065585744 Marionette TRACE 388 <- [1,2,null,{}]
03:39:45 INFO - 1501065585745 Marionette TRACE 388 -> [0,3,"findElement",{"using":"tag name","value":"input"}]
03:39:45 INFO - 1501065585748 Marionette TRACE 388 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"e48fbb18-9ca7-4728-bb06-5a4f3b19a7ee","ELEMENT":"e48fbb18-9ca7-4728-bb06-5a4f3b19a7ee"}}]
03:39:45 INFO - 1501065585750 Marionette TRACE 388 -> [0,4,"clickElement",{"id":"e48fbb18-9ca7-4728-bb06-5a4f3b19a7ee"}]
03:39:45 INFO - 1501065585779 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:447:12\nclickElement@chrome://marionette/content/listener.js:1367:5\n"},null]
03:39:45 INFO - 1501065585782 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}]
03:39:45 INFO - TEST-END: test_click.py TestClick.test_input_file1501065585785 Marionette TRACE 388 <- [1,5,null,{"value":null}]
03:39:45 INFO - 1501065585786 Marionette TRACE 388 -> [0,6,"deleteSession",{}]
03:39:45 INFO - TEST-PASS | test_click.py TestClick.test_input_file | took 141ms
03:39:45 INFO - TEST-START | test_click.py TestClick.test_obscured_element
03:39:45 INFO - 1501065585788 Marionette TRACE 388 <- [1,6,null,{}]
03:39:45 INFO - 1501065585790 Marionette DEBUG Closed connection 388
03:39:45 INFO - 1501065585791 Marionette DEBUG Accepted connection 389 from 127.0.0.1:49859
03:39:45 INFO - 1501065585792 Marionette DEBUG Closed connection 389
03:39:45 INFO - 1501065585793 Marionette DEBUG Accepted connection 390 from 127.0.0.1:49860
03:39:45 INFO - 1501065585794 Marionette TRACE 390 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
03:39:45 INFO - 1501065585794 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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}
03:39:45 INFO - 1501065585797 Marionette DEBUG Register listener.js for window 12
03:39:45 INFO - 1501065585800 Marionette TRACE 390 <- [1,1,null,{"sessionId":"b3b41537-0f34-47f9-85cc-b6eb78945474","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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}}]
03:39:45 INFO - 1501065585802 Marionette TRACE 390 -> [0,2,"setTimeouts",{"script":30000}]
03:39:45 INFO - 1501065585803 Marionette TRACE 390 <- [1,2,null,{}]
03:39:45 INFO - 1501065585804 Marionette TRACE 390 -> [0,3,"setTimeouts",{"pageLoad":300000}]
03:39:45 INFO - 1501065585804 Marionette TRACE 390 <- [1,3,null,{}]
03:39:45 INFO - 1501065585805 Marionette TRACE 390 -> [0,4,"setTimeouts",{"implicit":0}]
03:39:45 INFO - 1501065585806 Marionette TRACE 390 <- [1,4,null,{}]
03:39:45 INFO - 1501065585807 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}]
03:39:45 INFO - TEST-START: test_click.py TestClick.test_obscured_element1501065585810 Marionette TRACE 390 <- [1,5,null,{"value":null}]
03:39:45 INFO - 1501065585811 Marionette TRACE 390 -> [0,6,"deleteSession",{}]
03:39:45 INFO - 1501065585813 Marionette TRACE 390 <- [1,6,null,{}]
03:39:45 INFO - 1501065585815 Marionette DEBUG Closed connection 390
03:39:45 INFO - 1501065585816 Marionette DEBUG Accepted connection 391 from 127.0.0.1:49861
03:39:45 INFO - 1501065585817 Marionette DEBUG Closed connection 391
03:39:45 INFO - 1501065585818 Marionette DEBUG Accepted connection 392 from 127.0.0.1:49862
03:39:45 INFO - 1501065585821 Marionette TRACE 392 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
03:39:45 INFO - 1501065585821 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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}
03:39:45 INFO - 1501065585823 Marionette DEBUG Register listener.js for window 12
03:39:45 INFO - 1501065585833 Marionette TRACE 392 <- [1,1,null,{"sessionId":"15d53401-2657-48f8-8f26-fa58bdcf9652","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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}}]
03:39:45 INFO - 1501065585836 Marionette TRACE 392 -> [0,2,"deleteSession",{}]
03:39:45 INFO - 1501065585838 Marionette TRACE 392 <- [1,2,null,{}]
03:39:45 INFO - 1501065585846 Marionette DEBUG Closed connection 392
03:39:45 INFO - 1501065585847 Marionette DEBUG Accepted connection 393 from 127.0.0.1:49863
03:39:45 INFO - 1501065585897 Marionette DEBUG Closed connection 393
03:39:45 INFO - 1501065585898 Marionette DEBUG Accepted connection 394 from 127.0.0.1:49864
03:39:45 INFO - 1501065585948 Marionette TRACE 394 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
03:39:45 INFO - 1501065585949 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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}
03:39:45 INFO - 1501065585952 Marionette DEBUG Register listener.js for window 12
03:39:45 INFO - 1501065585955 Marionette TRACE 394 <- [1,1,null,{"sessionId":"d9d3209e-73bd-485e-b6d9-b15572af248a","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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}}]
03:39:45 INFO - 1501065585971 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"}]
03:39:45 INFO - 1501065585973 Marionette DEBUG Received DOM event "beforeunload" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
03:39:45 INFO - 1501065585976 Marionette DEBUG Received DOM event "pagehide" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
03:39:45 INFO - 1501065585976 Marionette DEBUG Received DOM event "unload" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
03:39:46 INFO - 1501065586003 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"
03:39:46 INFO - 1501065586004 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"
03:39:46 INFO - 1501065586009 Marionette TRACE 394 <- [1,2,null,{}]
03:39:46 INFO - 1501065586010 Marionette TRACE 394 -> [0,3,"findElement",{"using":"id","value":"overlay"}]
03:39:46 INFO - 1501065586013 Marionette TRACE 394 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"ed56b21d-717d-4e9f-a5dd-a814bc2e7f85","ELEMENT":"ed56b21d-717d-4e9f-a5dd-a814bc2e7f85"}}]
03:39:46 INFO - 1501065586014 Marionette TRACE 394 -> [0,4,"findElement",{"using":"id","value":"obscured"}]
03:39:46 INFO - 1501065586024 Marionette TRACE 394 <- [1,4,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"af69cde5-512c-4bcd-b0e9-45edc5ab0ee5","ELEMENT":"af69cde5-512c-4bcd-b0e9-45edc5ab0ee5"}}]
03:39:46 INFO - 1501065586027 Marionette TRACE 394 -> [0,5,"clickElement",{"id":"ed56b21d-717d-4e9f-a5dd-a814bc2e7f85"}]
03:39:46 INFO - 1501065586271 Marionette DEBUG Canceled page load listener because no navigation has been detected
03:39:46 INFO - 1501065586272 Marionette TRACE 394 <- [1,5,null,{}]
03:39:46 INFO - 1501065586273 Marionette TRACE 394 -> [0,6,"clickElement",{"id":"af69cde5-512c-4bcd-b0e9-45edc5ab0ee5"}]
03:39:46 INFO - 1501065586291 Marionette TRACE 394 <- [1,6,{"error":"element click intercepted","message":"Element
is not clickable at point (12.449996948242188,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:447:12\nclickElement@chrome://marionette/content/listener.js:1367:5\n"},null]
03:39:46 INFO - 1501065586293 Marionette TRACE 394 -> [0,7,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"test_click.py","script":"return window.clicked","sandbox":null,"line":257}]
03:39:46 INFO - 1501065586297 Marionette TRACE 394 <- [1,7,null,{"value":false}]
03:39:46 INFO - 1501065586298 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}]
03:39:46 INFO - TEST-END: test_click.py TestClick.test_obscured_element1501065586301 Marionette TRACE 394 <- [1,8,null,{"value":null}]
03:39:46 INFO - 1501065586302 Marionette TRACE 394 -> [0,9,"deleteSession",{}]
03:39:46 INFO - TEST-PASS | test_click.py TestClick.test_obscured_element | took 516ms
03:39:46 INFO - TEST-START | test_click.py TestClick.test_pointer_events_none
03:39:46 INFO - 1501065586304 Marionette TRACE 394 <- [1,9,null,{}]
03:39:46 INFO - 1501065586306 Marionette DEBUG Closed connection 394
03:39:46 INFO - 1501065586307 Marionette DEBUG Accepted connection 395 from 127.0.0.1:49865
03:39:46 INFO - 1501065586308 Marionette DEBUG Closed connection 395
03:39:46 INFO - 1501065586309 Marionette DEBUG Accepted connection 396 from 127.0.0.1:49866
03:39:46 INFO - 1501065586310 Marionette TRACE 396 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
03:39:46 INFO - 1501065586310 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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}
03:39:46 INFO - 1501065586313 Marionette DEBUG Register listener.js for window 12
03:39:46 INFO - 1501065586316 Marionette TRACE 396 <- [1,1,null,{"sessionId":"dc2f2ced-c872-4883-acb0-8d3ac8225c91","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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}}]
03:39:46 INFO - 1501065586318 Marionette TRACE 396 -> [0,2,"setTimeouts",{"script":30000}]
03:39:46 INFO - 1501065586319 Marionette TRACE 396 <- [1,2,null,{}]
03:39:46 INFO - 1501065586320 Marionette TRACE 396 -> [0,3,"setTimeouts",{"pageLoad":300000}]
03:39:46 INFO - 1501065586320 Marionette TRACE 396 <- [1,3,null,{}]
03:39:46 INFO - 1501065586321 Marionette TRACE 396 -> [0,4,"setTimeouts",{"implicit":0}]
03:39:46 INFO - 1501065586322 Marionette TRACE 396 <- [1,4,null,{}]
03:39:46 INFO - 1501065586323 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}]
03:39:46 INFO - TEST-START: test_click.py TestClick.test_pointer_events_none1501065586326 Marionette TRACE 396 <- [1,5,null,{"value":null}]
03:39:46 INFO - 1501065586327 Marionette TRACE 396 -> [0,6,"deleteSession",{}]
03:39:46 INFO - 1501065586329 Marionette TRACE 396 <- [1,6,null,{}]
03:39:46 INFO - 1501065586331 Marionette DEBUG Closed connection 396
03:39:46 INFO - 1501065586332 Marionette DEBUG Accepted connection 397 from 127.0.0.1:49867
03:39:46 INFO - 1501065586333 Marionette DEBUG Closed connection 397
03:39:46 INFO - 1501065586333 Marionette DEBUG Accepted connection 398 from 127.0.0.1:49868
03:39:46 INFO - 1501065586334 Marionette TRACE 398 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
03:39:46 INFO - 1501065586335 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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}
03:39:46 INFO - 1501065586337 Marionette DEBUG Register listener.js for window 12
03:39:46 INFO - 1501065586340 Marionette TRACE 398 <- [1,1,null,{"sessionId":"918f2674-82fb-4244-8809-ad4c467ec6d7","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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}}]
03:39:46 INFO - 1501065586342 Marionette TRACE 398 -> [0,2,"deleteSession",{}]
03:39:46 INFO - 1501065586344 Marionette TRACE 398 <- [1,2,null,{}]
03:39:46 INFO - 1501065586346 Marionette DEBUG Closed connection 398
03:39:46 INFO - 1501065586347 Marionette DEBUG Accepted connection 399 from 127.0.0.1:49869
03:39:46 INFO - 1501065586348 Marionette DEBUG Closed connection 399
03:39:46 INFO - 1501065586348 Marionette DEBUG Accepted connection 400 from 127.0.0.1:49870
03:39:46 INFO - 1501065586349 Marionette TRACE 400 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
03:39:46 INFO - 1501065586350 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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}
03:39:46 INFO - 1501065586352 Marionette DEBUG Register listener.js for window 12
03:39:46 INFO - 1501065586356 Marionette TRACE 400 <- [1,1,null,{"sessionId":"bf381378-d6b0-4c8f-9d00-c166047bc632","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":3612,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp17hixg.mozrunner","moz:accessibilityChecks":false}}]
03:39:46 INFO - 1501065586359 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"}]
03:39:46 INFO - 1501065586361 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"
03:39:46 INFO - 1501065586363 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"
03:39:46 INFO - 1501065586364 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"
03:39:46 INFO - 1501065586387 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"
03:39:46 INFO - 1501065586389 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"
03:39:46 INFO - 1501065586393 Marionette TRACE 400 <- [1,2,null,{}]
03:39:46 INFO - 1501065586394 Marionette TRACE 400 -> [0,3,"findElement",{"using":"tag name","value":"button"}]
03:39:46 INFO - 1501065586397 Marionette TRACE 400 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"ca885055-4589-48ee-a0a2-ad4cbf3c9ae2","ELEMENT":"ca885055-4589-48ee-a0a2-ad4cbf3c9ae2"}}]
03:39:46 INFO - 1501065586398 Marionette TRACE 400 -> [0,4,"getElementValueOfCssProperty",{"propertyName":"pointer-events","id":"ca885055-4589-48ee-a0a2-ad4cbf3c9ae2"}]
03:39:46 INFO - 1501065586428 Marionette TRACE 400 <- [1,4,null,{"value":"none"}]
03:39:46 INFO - 1501065586430 Marionette TRACE 400 -> [0,5,"clickElement",{"id":"ca885055-4589-48ee-a0a2-ad4cbf3c9ae2"}]
03:39:46 INFO - 1501065586452 Marionette TRACE 400 <- [1,5,{"error":"element click intercepted","message":"Element