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:397:12\nclickElement@chrome://marionette/content/listener.js:1317:5\n"},null]
22:02:01 INFO - 1499835721681 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}]
22:02:01 INFO - TEST-END: test_click.py TestClick.test_clicking_an_element_that_is_not_displayed_raises1499835721684 Marionette TRACE 352 <- [1,5,null,{"value":null}]
22:02:01 INFO - 1499835721685 Marionette TRACE 352 -> [0,6,"deleteSession",{}]
22:02:01 INFO - TEST-PASS | test_click.py TestClick.test_clicking_an_element_that_is_not_displayed_raises | took 189ms
22:02:01 INFO - TEST-START | test_click.py TestClick.test_clicking_on_a_multiline_link
22:02:01 INFO - 1499835721687 Marionette TRACE 352 <- [1,6,null,{}]
22:02:01 INFO - 1499835721690 Marionette DEBUG Closed connection 352
22:02:01 INFO - 1499835721691 Marionette DEBUG Accepted connection 353 from 127.0.0.1:50113
22:02:01 INFO - 1499835721693 Marionette DEBUG Closed connection 353
22:02:01 INFO - 1499835721693 Marionette DEBUG Accepted connection 354 from 127.0.0.1:50114
22:02:01 INFO - 1499835721694 Marionette TRACE 354 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
22:02:01 INFO - 1499835721695 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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}
22:02:01 INFO - 1499835721698 Marionette DEBUG Register listener.js for window 12
22:02:01 INFO - 1499835721702 Marionette TRACE 354 <- [1,1,null,{"sessionId":"5664f882-3201-4043-9188-3360bb47a845","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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}}]
22:02:01 INFO - 1499835721704 Marionette TRACE 354 -> [0,2,"setTimeouts",{"script":30000}]
22:02:01 INFO - 1499835721705 Marionette TRACE 354 <- [1,2,null,{}]
22:02:01 INFO - 1499835721706 Marionette TRACE 354 -> [0,3,"setTimeouts",{"pageLoad":300000}]
22:02:01 INFO - 1499835721706 Marionette TRACE 354 <- [1,3,null,{}]
22:02:01 INFO - 1499835721707 Marionette TRACE 354 -> [0,4,"setTimeouts",{"implicit":0}]
22:02:01 INFO - 1499835721708 Marionette TRACE 354 <- [1,4,null,{}]
22:02:01 INFO - 1499835721710 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}]
22:02:01 INFO - TEST-START: test_click.py TestClick.test_clicking_on_a_multiline_link1499835721713 Marionette TRACE 354 <- [1,5,null,{"value":null}]
22:02:01 INFO - 1499835721714 Marionette TRACE 354 -> [0,6,"deleteSession",{}]
22:02:01 INFO - 1499835721715 Marionette TRACE 354 <- [1,6,null,{}]
22:02:01 INFO - 1499835721718 Marionette DEBUG Closed connection 354
22:02:01 INFO - 1499835721719 Marionette DEBUG Accepted connection 355 from 127.0.0.1:50115
22:02:01 INFO - 1499835721719 Marionette DEBUG Closed connection 355
22:02:01 INFO - 1499835721720 Marionette DEBUG Accepted connection 356 from 127.0.0.1:50116
22:02:01 INFO - 1499835721721 Marionette TRACE 356 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
22:02:01 INFO - 1499835721722 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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}
22:02:01 INFO - 1499835721725 Marionette DEBUG Register listener.js for window 12
22:02:01 INFO - 1499835721736 Marionette TRACE 356 <- [1,1,null,{"sessionId":"4cc21640-6114-46fb-a7a5-fb34780f9eaa","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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}}]
22:02:01 INFO - 1499835721738 Marionette TRACE 356 -> [0,2,"deleteSession",{}]
22:02:01 INFO - 1499835721740 Marionette TRACE 356 <- [1,2,null,{}]
22:02:01 INFO - 1499835721742 Marionette DEBUG Closed connection 356
22:02:01 INFO - 1499835721743 Marionette DEBUG Accepted connection 357 from 127.0.0.1:50117
22:02:01 INFO - 1499835721744 Marionette DEBUG Closed connection 357
22:02:01 INFO - 1499835721745 Marionette DEBUG Accepted connection 358 from 127.0.0.1:50118
22:02:01 INFO - 1499835721746 Marionette TRACE 358 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
22:02:01 INFO - 1499835721746 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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}
22:02:01 INFO - 1499835721749 Marionette DEBUG Register listener.js for window 12
22:02:01 INFO - 1499835721752 Marionette TRACE 358 <- [1,1,null,{"sessionId":"19068a2a-a84f-4c9f-8ad5-00dd8ba38042","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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}}]
22:02:01 INFO - 1499835721755 Marionette TRACE 358 -> [0,2,"get",{"url":"http://127.0.0.1:49674/clicks.html"}]
22:02:01 INFO - 1499835721756 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49674/hidden.html"
22:02:01 INFO - 1499835721763 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49674/hidden.html"
22:02:01 INFO - 1499835721763 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49674/hidden.html"
22:02:01 INFO - 1499835721788 Marionette DEBUG Received DOM event "DOMContentLoaded" for "http://127.0.0.1:49674/clicks.html"
22:02:01 INFO - 1499835721790 Marionette DEBUG Received DOM event "pageshow" for "http://127.0.0.1:49674/clicks.html"
22:02:01 INFO - 1499835721802 Marionette TRACE 358 <- [1,2,null,{}]
22:02:01 INFO - 1499835721803 Marionette TRACE 358 -> [0,3,"findElement",{"using":"id","value":"overflowLink"}]
22:02:01 INFO - 1499835721806 Marionette TRACE 358 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"a83aa64d-e077-40c4-9b19-e1320f3fb6c6","ELEMENT":"a83aa64d-e077-40c4-9b19-e1320f3fb6c6"}}]
22:02:01 INFO - 1499835721807 Marionette TRACE 358 -> [0,4,"clickElement",{"id":"a83aa64d-e077-40c4-9b19-e1320f3fb6c6"}]
22:02:01 INFO - 1499835721853 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49674/clicks.html"
22:02:01 INFO - 1499835721866 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49674/clicks.html"
22:02:01 INFO - 1499835721866 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49674/clicks.html"
22:02:01 INFO - 1499835721899 Marionette DEBUG Received DOM event "DOMContentLoaded" for "http://127.0.0.1:49674/test.html"
22:02:01 INFO - 1499835721904 Marionette DEBUG Received DOM event "pageshow" for "http://127.0.0.1:49674/test.html"
22:02:01 INFO - 1499835721908 Marionette TRACE 358 <- [1,4,null,{}]
22:02:01 INFO - 1499835721918 Marionette TRACE 358 -> [0,5,"findElement",{"using":"id","value":"testDiv"}]
22:02:01 INFO - 1499835721921 Marionette TRACE 358 <- [1,5,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"f8136788-5f80-44d8-9c1c-e15fed0865ad","ELEMENT":"f8136788-5f80-44d8-9c1c-e15fed0865ad"}}]
22:02:01 INFO - 1499835721922 Marionette TRACE 358 -> [0,6,"getTitle",{}]
22:02:01 INFO - 1499835721922 Marionette TRACE 358 <- [1,6,null,{"value":"Marionette Test"}]
22:02:01 INFO - 1499835721927 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}]
22:02:01 INFO - TEST-END: test_click.py TestClick.test_clicking_on_a_multiline_link1499835721930 Marionette TRACE 358 <- [1,7,null,{"value":null}]
22:02:01 INFO - 1499835721931 Marionette TRACE 358 -> [0,8,"deleteSession",{}]
22:02:01 INFO - 1499835721933 Marionette TRACE 358 <- [1,8,null,{}]
22:02:01 INFO - TEST-PASS | test_click.py TestClick.test_clicking_on_a_multiline_link | took 245ms
22:02:01 INFO - TEST-START | test_click.py TestClick.test_container_element
22:02:01 INFO - 1499835721936 Marionette DEBUG Closed connection 358
22:02:01 INFO - 1499835721936 Marionette DEBUG Accepted connection 359 from 127.0.0.1:50121
22:02:01 INFO - 1499835721937 Marionette DEBUG Closed connection 359
22:02:01 INFO - 1499835721938 Marionette DEBUG Accepted connection 360 from 127.0.0.1:50122
22:02:01 INFO - 1499835721939 Marionette TRACE 360 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
22:02:01 INFO - 1499835721940 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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}
22:02:01 INFO - 1499835721943 Marionette DEBUG Register listener.js for window 12
22:02:01 INFO - 1499835721946 Marionette TRACE 360 <- [1,1,null,{"sessionId":"b3ebc7bf-8354-4689-8e22-f7ce69323a6a","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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}}]
22:02:01 INFO - 1499835721954 Marionette TRACE 360 -> [0,2,"setTimeouts",{"script":30000}]
22:02:01 INFO - 1499835721954 Marionette TRACE 360 <- [1,2,null,{}]
22:02:01 INFO - 1499835721955 Marionette TRACE 360 -> [0,3,"setTimeouts",{"pageLoad":300000}]
22:02:01 INFO - 1499835721956 Marionette TRACE 360 <- [1,3,null,{}]
22:02:01 INFO - 1499835721957 Marionette TRACE 360 -> [0,4,"setTimeouts",{"implicit":0}]
22:02:01 INFO - 1499835721957 Marionette TRACE 360 <- [1,4,null,{}]
22:02:01 INFO - 1499835721959 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}]
22:02:01 INFO - TEST-START: test_click.py TestClick.test_container_element1499835721962 Marionette TRACE 360 <- [1,5,null,{"value":null}]
22:02:01 INFO - 1499835721963 Marionette TRACE 360 -> [0,6,"deleteSession",{}]
22:02:01 INFO - 1499835721964 Marionette TRACE 360 <- [1,6,null,{}]
22:02:01 INFO - 1499835721967 Marionette DEBUG Closed connection 360
22:02:01 INFO - 1499835721967 Marionette DEBUG Accepted connection 361 from 127.0.0.1:50123
22:02:01 INFO - 1499835721968 Marionette DEBUG Closed connection 361
22:02:01 INFO - 1499835721969 Marionette DEBUG Accepted connection 362 from 127.0.0.1:50124
22:02:01 INFO - 1499835721970 Marionette TRACE 362 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
22:02:01 INFO - 1499835721971 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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}
22:02:01 INFO - 1499835721973 Marionette DEBUG Register listener.js for window 12
22:02:01 INFO - 1499835721977 Marionette TRACE 362 <- [1,1,null,{"sessionId":"dd1af81b-e7f8-4f7d-8059-ada26d2186d4","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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}}]
22:02:01 INFO - 1499835721979 Marionette TRACE 362 -> [0,2,"deleteSession",{}]
22:02:01 INFO - 1499835721980 Marionette TRACE 362 <- [1,2,null,{}]
22:02:01 INFO - 1499835721983 Marionette DEBUG Closed connection 362
22:02:01 INFO - 1499835721984 Marionette DEBUG Accepted connection 363 from 127.0.0.1:50125
22:02:01 INFO - 1499835721985 Marionette DEBUG Closed connection 363
22:02:01 INFO - 1499835721986 Marionette DEBUG Accepted connection 364 from 127.0.0.1:50126
22:02:01 INFO - 1499835721987 Marionette TRACE 364 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
22:02:01 INFO - 1499835721988 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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}
22:02:01 INFO - 1499835721991 Marionette DEBUG Register listener.js for window 12
22:02:01 INFO - 1499835721994 Marionette TRACE 364 <- [1,1,null,{"sessionId":"ac20384b-c0ff-457c-8eb9-aa577733d5d0","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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}}]
22:02:01 INFO - 1499835721997 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"}]
22:02:02 INFO - 1499835721998 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49674/test.html"
22:02:02 INFO - 1499835722001 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49674/test.html"
22:02:02 INFO - 1499835722001 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49674/test.html"
22:02:02 INFO - 1499835722028 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"
22:02:02 INFO - 1499835722033 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"
22:02:02 INFO - 1499835722037 Marionette TRACE 364 <- [1,2,null,{}]
22:02:02 INFO - 1499835722038 Marionette TRACE 364 -> [0,3,"findElement",{"using":"tag name","value":"option"}]
22:02:02 INFO - 1499835722049 Marionette TRACE 364 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"57a06afb-bba1-4b06-98d6-d0c1a5ee3aae","ELEMENT":"57a06afb-bba1-4b06-98d6-d0c1a5ee3aae"}}]
22:02:02 INFO - 1499835722051 Marionette TRACE 364 -> [0,4,"clickElement",{"id":"57a06afb-bba1-4b06-98d6-d0c1a5ee3aae"}]
22:02:02 INFO - 1499835722297 Marionette DEBUG Canceled page load listener because no navigation has been detected
22:02:02 INFO - 1499835722298 Marionette TRACE 364 <- [1,4,null,{}]
22:02:02 INFO - 1499835722299 Marionette TRACE 364 -> [0,5,"getElementProperty",{"id":"57a06afb-bba1-4b06-98d6-d0c1a5ee3aae","name":"selected"}]
22:02:02 INFO - 1499835722304 Marionette TRACE 364 <- [1,5,null,{"value":true}]
22:02:02 INFO - 1499835722306 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}]
22:02:02 INFO - TEST-END: test_click.py TestClick.test_container_element1499835722309 Marionette TRACE 364 <- [1,6,null,{"value":null}]
22:02:02 INFO - 1499835722310 Marionette TRACE 364 -> [0,7,"deleteSession",{}]
22:02:02 INFO - TEST-PASS | test_click.py TestClick.test_container_element | took 379ms
22:02:02 INFO - TEST-START | test_click.py TestClick.test_container_element_outside_view
22:02:02 INFO - 1499835722312 Marionette TRACE 364 <- [1,7,null,{}]
22:02:02 INFO - 1499835722314 Marionette DEBUG Closed connection 364
22:02:02 INFO - 1499835722315 Marionette DEBUG Accepted connection 365 from 127.0.0.1:50127
22:02:02 INFO - 1499835722316 Marionette DEBUG Closed connection 365
22:02:02 INFO - 1499835722317 Marionette DEBUG Accepted connection 366 from 127.0.0.1:50128
22:02:02 INFO - 1499835722318 Marionette TRACE 366 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
22:02:02 INFO - 1499835722318 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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}
22:02:02 INFO - 1499835722321 Marionette DEBUG Register listener.js for window 12
22:02:02 INFO - 1499835722325 Marionette TRACE 366 <- [1,1,null,{"sessionId":"b1f124fe-8339-49ad-a6a4-88c7ade54794","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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}}]
22:02:02 INFO - 1499835722327 Marionette TRACE 366 -> [0,2,"setTimeouts",{"script":30000}]
22:02:02 INFO - 1499835722328 Marionette TRACE 366 <- [1,2,null,{}]
22:02:02 INFO - 1499835722329 Marionette TRACE 366 -> [0,3,"setTimeouts",{"pageLoad":300000}]
22:02:02 INFO - 1499835722329 Marionette TRACE 366 <- [1,3,null,{}]
22:02:02 INFO - 1499835722330 Marionette TRACE 366 -> [0,4,"setTimeouts",{"implicit":0}]
22:02:02 INFO - 1499835722331 Marionette TRACE 366 <- [1,4,null,{}]
22:02:02 INFO - 1499835722333 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}]
22:02:02 INFO - TEST-START: test_click.py TestClick.test_container_element_outside_view1499835722336 Marionette TRACE 366 <- [1,5,null,{"value":null}]
22:02:02 INFO - 1499835722337 Marionette TRACE 366 -> [0,6,"deleteSession",{}]
22:02:02 INFO - 1499835722338 Marionette TRACE 366 <- [1,6,null,{}]
22:02:02 INFO - 1499835722342 Marionette DEBUG Closed connection 366
22:02:02 INFO - 1499835722342 Marionette DEBUG Accepted connection 367 from 127.0.0.1:50129
22:02:02 INFO - 1499835722343 Marionette DEBUG Closed connection 367
22:02:02 INFO - 1499835722344 Marionette DEBUG Accepted connection 368 from 127.0.0.1:50130
22:02:02 INFO - 1499835722345 Marionette TRACE 368 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
22:02:02 INFO - 1499835722346 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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}
22:02:02 INFO - 1499835722349 Marionette DEBUG Register listener.js for window 12
22:02:02 INFO - 1499835722360 Marionette TRACE 368 <- [1,1,null,{"sessionId":"4761fdae-1945-48a7-bb4f-704a5c405c8e","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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}}]
22:02:02 INFO - 1499835722364 Marionette TRACE 368 -> [0,2,"deleteSession",{}]
22:02:02 INFO - 1499835722366 Marionette TRACE 368 <- [1,2,null,{}]
22:02:02 INFO - 1499835722368 Marionette DEBUG Closed connection 368
22:02:02 INFO - 1499835722369 Marionette DEBUG Accepted connection 369 from 127.0.0.1:50131
22:02:02 INFO - 1499835722370 Marionette DEBUG Closed connection 369
22:02:02 INFO - 1499835722370 Marionette DEBUG Accepted connection 370 from 127.0.0.1:50132
22:02:02 INFO - 1499835722372 Marionette TRACE 370 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
22:02:02 INFO - 1499835722372 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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}
22:02:02 INFO - 1499835722375 Marionette DEBUG Register listener.js for window 12
22:02:02 INFO - 1499835722379 Marionette TRACE 370 <- [1,1,null,{"sessionId":"d44d2b4c-f37b-4a60-9b46-65cb86d6bf79","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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}}]
22:02:02 INFO - 1499835722381 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"}]
22:02:02 INFO - 1499835722383 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"
22:02:02 INFO - 1499835722387 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"
22:02:02 INFO - 1499835722387 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"
22:02:02 INFO - 1499835722407 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"
22:02:02 INFO - 1499835722413 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"
22:02:02 INFO - 1499835722417 Marionette TRACE 370 <- [1,2,null,{}]
22:02:02 INFO - 1499835722420 Marionette TRACE 370 -> [0,3,"findElement",{"using":"tag name","value":"option"}]
22:02:02 INFO - 1499835722428 Marionette TRACE 370 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"40dad854-e16d-43b8-bc44-2962dd925af8","ELEMENT":"40dad854-e16d-43b8-bc44-2962dd925af8"}}]
22:02:02 INFO - 1499835722430 Marionette TRACE 370 -> [0,4,"clickElement",{"id":"40dad854-e16d-43b8-bc44-2962dd925af8"}]
22:02:02 INFO - 1499835722675 Marionette DEBUG Canceled page load listener because no navigation has been detected
22:02:02 INFO - 1499835722676 Marionette TRACE 370 <- [1,4,null,{}]
22:02:02 INFO - 1499835722677 Marionette TRACE 370 -> [0,5,"getElementProperty",{"id":"40dad854-e16d-43b8-bc44-2962dd925af8","name":"selected"}]
22:02:02 INFO - 1499835722682 Marionette TRACE 370 <- [1,5,null,{"value":true}]
22:02:02 INFO - 1499835722684 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}]
22:02:02 INFO - TEST-END: test_click.py TestClick.test_container_element_outside_view1499835722687 Marionette TRACE 370 <- [1,6,null,{"value":null}]
22:02:02 INFO - 1499835722688 Marionette TRACE 370 -> [0,7,"deleteSession",{}]
22:02:02 INFO - TEST-PASS | test_click.py TestClick.test_container_element_outside_view | took 378ms
22:02:02 INFO - TEST-START | test_click.py TestClick.test_css_transforms
22:02:02 INFO - 1499835722690 Marionette TRACE 370 <- [1,7,null,{}]
22:02:02 INFO - 1499835722692 Marionette DEBUG Closed connection 370
22:02:02 INFO - 1499835722693 Marionette DEBUG Accepted connection 371 from 127.0.0.1:50133
22:02:02 INFO - 1499835722694 Marionette DEBUG Closed connection 371
22:02:02 INFO - 1499835722694 Marionette DEBUG Accepted connection 372 from 127.0.0.1:50134
22:02:02 INFO - 1499835722695 Marionette TRACE 372 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
22:02:02 INFO - 1499835722696 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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}
22:02:02 INFO - 1499835722699 Marionette DEBUG Register listener.js for window 12
22:02:02 INFO - 1499835722702 Marionette TRACE 372 <- [1,1,null,{"sessionId":"f97e8103-de36-486c-8b2a-939b8119756d","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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}}]
22:02:02 INFO - 1499835722705 Marionette TRACE 372 -> [0,2,"setTimeouts",{"script":30000}]
22:02:02 INFO - 1499835722705 Marionette TRACE 372 <- [1,2,null,{}]
22:02:02 INFO - 1499835722706 Marionette TRACE 372 -> [0,3,"setTimeouts",{"pageLoad":300000}]
22:02:02 INFO - 1499835722707 Marionette TRACE 372 <- [1,3,null,{}]
22:02:02 INFO - 1499835722708 Marionette TRACE 372 -> [0,4,"setTimeouts",{"implicit":0}]
22:02:02 INFO - 1499835722708 Marionette TRACE 372 <- [1,4,null,{}]
22:02:02 INFO - 1499835722710 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}]
22:02:02 INFO - TEST-START: test_click.py TestClick.test_css_transforms1499835722713 Marionette TRACE 372 <- [1,5,null,{"value":null}]
22:02:02 INFO - 1499835722714 Marionette TRACE 372 -> [0,6,"deleteSession",{}]
22:02:02 INFO - 1499835722715 Marionette TRACE 372 <- [1,6,null,{}]
22:02:02 INFO - 1499835722718 Marionette DEBUG Closed connection 372
22:02:02 INFO - 1499835722718 Marionette DEBUG Accepted connection 373 from 127.0.0.1:50135
22:02:02 INFO - 1499835722719 Marionette DEBUG Closed connection 373
22:02:02 INFO - 1499835722720 Marionette DEBUG Accepted connection 374 from 127.0.0.1:50136
22:02:02 INFO - 1499835722721 Marionette TRACE 374 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
22:02:02 INFO - 1499835722722 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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}
22:02:02 INFO - 1499835722724 Marionette DEBUG Register listener.js for window 12
22:02:02 INFO - 1499835722728 Marionette TRACE 374 <- [1,1,null,{"sessionId":"9640735a-e045-41c0-b82e-43cb8232f64a","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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}}]
22:02:02 INFO - 1499835722730 Marionette TRACE 374 -> [0,2,"deleteSession",{}]
22:02:02 INFO - 1499835722731 Marionette TRACE 374 <- [1,2,null,{}]
22:02:02 INFO - 1499835722733 Marionette DEBUG Closed connection 374
22:02:02 INFO - 1499835722734 Marionette DEBUG Accepted connection 375 from 127.0.0.1:50137
22:02:02 INFO - 1499835722735 Marionette DEBUG Closed connection 375
22:02:02 INFO - 1499835722736 Marionette DEBUG Accepted connection 376 from 127.0.0.1:50138
22:02:02 INFO - 1499835722737 Marionette TRACE 376 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
22:02:02 INFO - 1499835722738 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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}
22:02:02 INFO - 1499835722740 Marionette DEBUG Register listener.js for window 12
22:02:02 INFO - 1499835722747 Marionette TRACE 376 <- [1,1,null,{"sessionId":"4de9d9e1-a7a4-4486-9319-b306876671e2","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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}}]
22:02:02 INFO - 1499835722751 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"}]
22:02:02 INFO - 1499835722753 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"
22:02:02 INFO - 1499835722755 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"
22:02:02 INFO - 1499835722756 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"
22:02:02 INFO - 1499835722777 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"
22:02:02 INFO - 1499835722780 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"
22:02:02 INFO - 1499835722784 Marionette TRACE 376 <- [1,2,null,{}]
22:02:02 INFO - 1499835722786 Marionette TRACE 376 -> [0,3,"findElement",{"using":"tag name","value":"div"}]
22:02:02 INFO - 1499835722789 Marionette TRACE 376 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"f9946be1-b1a3-4605-936e-d98f19bd02b5","ELEMENT":"f9946be1-b1a3-4605-936e-d98f19bd02b5"}}]
22:02:02 INFO - 1499835722797 Marionette TRACE 376 -> [0,4,"clickElement",{"id":"f9946be1-b1a3-4605-936e-d98f19bd02b5"}]
22:02:03 INFO - 1499835723040 Marionette DEBUG Canceled page load listener because no navigation has been detected
22:02:03 INFO - 1499835723041 Marionette TRACE 376 <- [1,4,null,{}]
22:02:03 INFO - 1499835723042 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}]
22:02:03 INFO - TEST-END: test_click.py TestClick.test_css_transforms1499835723046 Marionette TRACE 376 <- [1,5,null,{"value":null}]
22:02:03 INFO - TEST-PASS | test_click.py TestClick.test_css_transforms | took 359ms
22:02:03 INFO - 1499835723047 Marionette TRACE 376 -> [0,6,"deleteSession",{}]
22:02:03 INFO - 1499835723048 Marionette TRACE 376 <- [1,6,null,{}]
22:02:03 INFO - TEST-START | test_click.py TestClick.test_inclusive_descendant
22:02:03 INFO - 1499835723051 Marionette DEBUG Closed connection 376
22:02:03 INFO - 1499835723052 Marionette DEBUG Accepted connection 377 from 127.0.0.1:50139
22:02:03 INFO - 1499835723053 Marionette DEBUG Closed connection 377
22:02:03 INFO - 1499835723054 Marionette DEBUG Accepted connection 378 from 127.0.0.1:50140
22:02:03 INFO - 1499835723055 Marionette TRACE 378 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
22:02:03 INFO - 1499835723056 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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}
22:02:03 INFO - 1499835723059 Marionette DEBUG Register listener.js for window 12
22:02:03 INFO - 1499835723063 Marionette TRACE 378 <- [1,1,null,{"sessionId":"dbf537fa-d606-40c0-a7ed-d68757206385","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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}}]
22:02:03 INFO - 1499835723065 Marionette TRACE 378 -> [0,2,"setTimeouts",{"script":30000}]
22:02:03 INFO - 1499835723066 Marionette TRACE 378 <- [1,2,null,{}]
22:02:03 INFO - 1499835723067 Marionette TRACE 378 -> [0,3,"setTimeouts",{"pageLoad":300000}]
22:02:03 INFO - 1499835723067 Marionette TRACE 378 <- [1,3,null,{}]
22:02:03 INFO - 1499835723068 Marionette TRACE 378 -> [0,4,"setTimeouts",{"implicit":0}]
22:02:03 INFO - 1499835723069 Marionette TRACE 378 <- [1,4,null,{}]
22:02:03 INFO - 1499835723071 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}]
22:02:03 INFO - TEST-START: test_click.py TestClick.test_inclusive_descendant1499835723074 Marionette TRACE 378 <- [1,5,null,{"value":null}]
22:02:03 INFO - 1499835723075 Marionette TRACE 378 -> [0,6,"deleteSession",{}]
22:02:03 INFO - 1499835723077 Marionette TRACE 378 <- [1,6,null,{}]
22:02:03 INFO - 1499835723079 Marionette DEBUG Closed connection 378
22:02:03 INFO - 1499835723080 Marionette DEBUG Accepted connection 379 from 127.0.0.1:50141
22:02:03 INFO - 1499835723081 Marionette DEBUG Closed connection 379
22:02:03 INFO - 1499835723081 Marionette DEBUG Accepted connection 380 from 127.0.0.1:50142
22:02:03 INFO - 1499835723083 Marionette TRACE 380 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
22:02:03 INFO - 1499835723083 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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}
22:02:03 INFO - 1499835723086 Marionette DEBUG Register listener.js for window 12
22:02:03 INFO - 1499835723094 Marionette TRACE 380 <- [1,1,null,{"sessionId":"4da400ef-ef9b-4a76-83da-7b7a766b649d","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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}}]
22:02:03 INFO - 1499835723096 Marionette TRACE 380 -> [0,2,"deleteSession",{}]
22:02:03 INFO - 1499835723097 Marionette TRACE 380 <- [1,2,null,{}]
22:02:03 INFO - 1499835723101 Marionette DEBUG Closed connection 380
22:02:03 INFO - 1499835723101 Marionette DEBUG Accepted connection 381 from 127.0.0.1:50143
22:02:03 INFO - 1499835723102 Marionette DEBUG Closed connection 381
22:02:03 INFO - 1499835723103 Marionette DEBUG Accepted connection 382 from 127.0.0.1:50144
22:02:03 INFO - 1499835723104 Marionette TRACE 382 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
22:02:03 INFO - 1499835723105 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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}
22:02:03 INFO - 1499835723107 Marionette DEBUG Register listener.js for window 12
22:02:03 INFO - 1499835723120 Marionette TRACE 382 <- [1,1,null,{"sessionId":"a7e6ac3c-6605-4c8b-9563-acdd8d72ab02","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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}}]
22:02:03 INFO - 1499835723123 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"}]
22:02:03 INFO - 1499835723125 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"
22:02:03 INFO - 1499835723127 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"
22:02:03 INFO - 1499835723128 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"
22:02:03 INFO - 1499835723148 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"
22:02:03 INFO - 1499835723151 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"
22:02:03 INFO - 1499835723155 Marionette TRACE 382 <- [1,2,null,{}]
22:02:03 INFO - 1499835723163 Marionette TRACE 382 -> [0,3,"findElement",{"using":"tag name","value":"select"}]
22:02:03 INFO - 1499835723167 Marionette TRACE 382 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"aa4212b4-9e21-4c91-ba92-6cc9345ab632","ELEMENT":"aa4212b4-9e21-4c91-ba92-6cc9345ab632"}}]
22:02:03 INFO - 1499835723168 Marionette TRACE 382 -> [0,4,"clickElement",{"id":"aa4212b4-9e21-4c91-ba92-6cc9345ab632"}]
22:02:03 INFO - 1499835723413 Marionette DEBUG Canceled page load listener because no navigation has been detected
22:02:03 INFO - 1499835723414 Marionette TRACE 382 <- [1,4,null,{}]
22:02:03 INFO - 1499835723416 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}]
22:02:03 INFO - TEST-END: test_click.py TestClick.test_inclusive_descendant1499835723419 Marionette TRACE 382 <- [1,5,null,{"value":null}]
22:02:03 INFO - 1499835723420 Marionette TRACE 382 -> [0,6,"deleteSession",{}]
22:02:03 INFO - 1499835723421 Marionette TRACE 382 <- [1,6,null,{}]
22:02:03 INFO - TEST-PASS | test_click.py TestClick.test_inclusive_descendant | took 372ms
22:02:03 INFO - TEST-START | test_click.py TestClick.test_input_file
22:02:03 INFO - 1499835723424 Marionette DEBUG Closed connection 382
22:02:03 INFO - 1499835723425 Marionette DEBUG Accepted connection 383 from 127.0.0.1:50145
22:02:03 INFO - 1499835723426 Marionette DEBUG Closed connection 383
22:02:03 INFO - 1499835723427 Marionette DEBUG Accepted connection 384 from 127.0.0.1:50146
22:02:03 INFO - 1499835723428 Marionette TRACE 384 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
22:02:03 INFO - 1499835723428 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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}
22:02:03 INFO - 1499835723431 Marionette DEBUG Register listener.js for window 12
22:02:03 INFO - 1499835723434 Marionette TRACE 384 <- [1,1,null,{"sessionId":"e7943df5-cbe0-493c-854d-9b9a3bfc0f6b","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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}}]
22:02:03 INFO - 1499835723437 Marionette TRACE 384 -> [0,2,"setTimeouts",{"script":30000}]
22:02:03 INFO - 1499835723437 Marionette TRACE 384 <- [1,2,null,{}]
22:02:03 INFO - 1499835723438 Marionette TRACE 384 -> [0,3,"setTimeouts",{"pageLoad":300000}]
22:02:03 INFO - 1499835723439 Marionette TRACE 384 <- [1,3,null,{}]
22:02:03 INFO - 1499835723440 Marionette TRACE 384 -> [0,4,"setTimeouts",{"implicit":0}]
22:02:03 INFO - 1499835723440 Marionette TRACE 384 <- [1,4,null,{}]
22:02:03 INFO - 1499835723442 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}]
22:02:03 INFO - TEST-START: test_click.py TestClick.test_input_file1499835723445 Marionette TRACE 384 <- [1,5,null,{"value":null}]
22:02:03 INFO - 1499835723446 Marionette TRACE 384 -> [0,6,"deleteSession",{}]
22:02:03 INFO - 1499835723448 Marionette TRACE 384 <- [1,6,null,{}]
22:02:03 INFO - 1499835723450 Marionette DEBUG Closed connection 384
22:02:03 INFO - 1499835723451 Marionette DEBUG Accepted connection 385 from 127.0.0.1:50147
22:02:03 INFO - 1499835723452 Marionette DEBUG Closed connection 385
22:02:03 INFO - 1499835723452 Marionette DEBUG Accepted connection 386 from 127.0.0.1:50148
22:02:03 INFO - 1499835723454 Marionette TRACE 386 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
22:02:03 INFO - 1499835723454 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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}
22:02:03 INFO - 1499835723457 Marionette DEBUG Register listener.js for window 12
22:02:03 INFO - 1499835723460 Marionette TRACE 386 <- [1,1,null,{"sessionId":"cfce4a95-c14a-4221-9814-887938a4a89b","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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}}]
22:02:03 INFO - 1499835723462 Marionette TRACE 386 -> [0,2,"deleteSession",{}]
22:02:03 INFO - 1499835723464 Marionette TRACE 386 <- [1,2,null,{}]
22:02:03 INFO - 1499835723466 Marionette DEBUG Closed connection 386
22:02:03 INFO - 1499835723467 Marionette DEBUG Accepted connection 387 from 127.0.0.1:50149
22:02:03 INFO - 1499835723468 Marionette DEBUG Closed connection 387
22:02:03 INFO - 1499835723469 Marionette DEBUG Accepted connection 388 from 127.0.0.1:50150
22:02:03 INFO - 1499835723470 Marionette TRACE 388 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
22:02:03 INFO - 1499835723471 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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}
22:02:03 INFO - 1499835723473 Marionette DEBUG Register listener.js for window 12
22:02:03 INFO - 1499835723477 Marionette TRACE 388 <- [1,1,null,{"sessionId":"76ddb124-8af8-4747-ae06-0dd87cd17cee","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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}}]
22:02:03 INFO - 1499835723479 Marionette TRACE 388 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"}]
22:02:03 INFO - 1499835723480 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"
22:02:03 INFO - 1499835723483 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"
22:02:03 INFO - 1499835723484 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"
22:02:03 INFO - 1499835723504 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
22:02:03 INFO - 1499835723508 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
22:02:03 INFO - 1499835723519 Marionette TRACE 388 <- [1,2,null,{}]
22:02:03 INFO - 1499835723521 Marionette TRACE 388 -> [0,3,"findElement",{"using":"tag name","value":"input"}]
22:02:03 INFO - 1499835723524 Marionette TRACE 388 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"d09fd3cb-1bbe-43d1-9af6-8de5f064991b","ELEMENT":"d09fd3cb-1bbe-43d1-9af6-8de5f064991b"}}]
22:02:03 INFO - 1499835723526 Marionette TRACE 388 -> [0,4,"clickElement",{"id":"d09fd3cb-1bbe-43d1-9af6-8de5f064991b"}]
22:02:03 INFO - 1499835723554 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:397:12\nclickElement@chrome://marionette/content/listener.js:1317:5\n"},null]
22:02:03 INFO - 1499835723556 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}]
22:02:03 INFO - TEST-END: test_click.py TestClick.test_input_file1499835723559 Marionette TRACE 388 <- [1,5,null,{"value":null}]
22:02:03 INFO - 1499835723560 Marionette TRACE 388 -> [0,6,"deleteSession",{}]
22:02:03 INFO - 1499835723562 Marionette TRACE 388 <- [1,6,null,{}]
22:02:03 INFO - TEST-PASS | test_click.py TestClick.test_input_file | took 140ms
22:02:03 INFO - TEST-START | test_click.py TestClick.test_obscured_element
22:02:03 INFO - 1499835723564 Marionette DEBUG Closed connection 388
22:02:03 INFO - 1499835723565 Marionette DEBUG Accepted connection 389 from 127.0.0.1:50151
22:02:03 INFO - 1499835723566 Marionette DEBUG Closed connection 389
22:02:03 INFO - 1499835723566 Marionette DEBUG Accepted connection 390 from 127.0.0.1:50152
22:02:03 INFO - 1499835723568 Marionette TRACE 390 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
22:02:03 INFO - 1499835723568 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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}
22:02:03 INFO - 1499835723571 Marionette DEBUG Register listener.js for window 12
22:02:03 INFO - 1499835723575 Marionette TRACE 390 <- [1,1,null,{"sessionId":"73cf1898-586d-42d8-adc1-25f27b97396d","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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}}]
22:02:03 INFO - 1499835723577 Marionette TRACE 390 -> [0,2,"setTimeouts",{"script":30000}]
22:02:03 INFO - 1499835723577 Marionette TRACE 390 <- [1,2,null,{}]
22:02:03 INFO - 1499835723578 Marionette TRACE 390 -> [0,3,"setTimeouts",{"pageLoad":300000}]
22:02:03 INFO - 1499835723579 Marionette TRACE 390 <- [1,3,null,{}]
22:02:03 INFO - 1499835723580 Marionette TRACE 390 -> [0,4,"setTimeouts",{"implicit":0}]
22:02:03 INFO - 1499835723580 Marionette TRACE 390 <- [1,4,null,{}]
22:02:03 INFO - 1499835723582 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}]
22:02:03 INFO - TEST-START: test_click.py TestClick.test_obscured_element1499835723585 Marionette TRACE 390 <- [1,5,null,{"value":null}]
22:02:03 INFO - 1499835723586 Marionette TRACE 390 -> [0,6,"deleteSession",{}]
22:02:03 INFO - 1499835723588 Marionette TRACE 390 <- [1,6,null,{}]
22:02:03 INFO - 1499835723591 Marionette DEBUG Closed connection 390
22:02:03 INFO - 1499835723592 Marionette DEBUG Accepted connection 391 from 127.0.0.1:50153
22:02:03 INFO - 1499835723592 Marionette DEBUG Closed connection 391
22:02:03 INFO - 1499835723593 Marionette DEBUG Accepted connection 392 from 127.0.0.1:50154
22:02:03 INFO - 1499835723595 Marionette TRACE 392 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
22:02:03 INFO - 1499835723595 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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}
22:02:03 INFO - 1499835723598 Marionette DEBUG Register listener.js for window 12
22:02:03 INFO - 1499835723601 Marionette TRACE 392 <- [1,1,null,{"sessionId":"903d9654-9533-41c2-92af-c907d740947c","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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}}]
22:02:03 INFO - 1499835723603 Marionette TRACE 392 -> [0,2,"deleteSession",{}]
22:02:03 INFO - 1499835723605 Marionette TRACE 392 <- [1,2,null,{}]
22:02:03 INFO - 1499835723607 Marionette DEBUG Closed connection 392
22:02:03 INFO - 1499835723608 Marionette DEBUG Accepted connection 393 from 127.0.0.1:50155
22:02:03 INFO - 1499835723609 Marionette DEBUG Closed connection 393
22:02:03 INFO - 1499835723610 Marionette DEBUG Accepted connection 394 from 127.0.0.1:50156
22:02:03 INFO - 1499835723611 Marionette TRACE 394 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
22:02:03 INFO - 1499835723612 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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}
22:02:03 INFO - 1499835723615 Marionette DEBUG Register listener.js for window 12
22:02:03 INFO - 1499835723618 Marionette TRACE 394 <- [1,1,null,{"sessionId":"9e249d90-fdcc-48d8-91a6-6c3e127747c2","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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}}]
22:02:03 INFO - 1499835723628 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"}]
22:02:03 INFO - 1499835723630 Marionette DEBUG Received DOM event "beforeunload" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
22:02:03 INFO - 1499835723633 Marionette DEBUG Received DOM event "pagehide" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
22:02:03 INFO - 1499835723633 Marionette DEBUG Received DOM event "unload" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
22:02:03 INFO - 1499835723656 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"
22:02:03 INFO - 1499835723659 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"
22:02:03 INFO - 1499835723671 Marionette TRACE 394 <- [1,2,null,{}]
22:02:03 INFO - 1499835723672 Marionette TRACE 394 -> [0,3,"findElement",{"using":"id","value":"overlay"}]
22:02:03 INFO - 1499835723676 Marionette TRACE 394 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"fb603abf-a1a4-4e0e-a483-3a46a1e8e66f","ELEMENT":"fb603abf-a1a4-4e0e-a483-3a46a1e8e66f"}}]
22:02:03 INFO - 1499835723677 Marionette TRACE 394 -> [0,4,"findElement",{"using":"id","value":"obscured"}]
22:02:03 INFO - 1499835723680 Marionette TRACE 394 <- [1,4,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"1322333c-08ed-437d-95ef-57ff024f1c96","ELEMENT":"1322333c-08ed-437d-95ef-57ff024f1c96"}}]
22:02:03 INFO - 1499835723681 Marionette TRACE 394 -> [0,5,"clickElement",{"id":"fb603abf-a1a4-4e0e-a483-3a46a1e8e66f"}]
22:02:03 INFO - 1499835723924 Marionette DEBUG Canceled page load listener because no navigation has been detected
22:02:03 INFO - 1499835723925 Marionette TRACE 394 <- [1,5,null,{}]
22:02:03 INFO - 1499835723926 Marionette TRACE 394 -> [0,6,"clickElement",{"id":"1322333c-08ed-437d-95ef-57ff024f1c96"}]
22:02:03 INFO - 1499835723944 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:397:12\nclickElement@chrome://marionette/content/listener.js:1317:5\n"},null]
22:02:03 INFO - 1499835723946 Marionette TRACE 394 -> [0,7,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"test_click.py","script":"return window.clicked","sandbox":null,"line":257}]
22:02:03 INFO - 1499835723949 Marionette TRACE 394 <- [1,7,null,{"value":false}]
22:02:03 INFO - 1499835723951 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}]
22:02:03 INFO - TEST-END: test_click.py TestClick.test_obscured_element1499835723954 Marionette TRACE 394 <- [1,8,null,{"value":null}]
22:02:03 INFO - 1499835723955 Marionette TRACE 394 -> [0,9,"deleteSession",{}]
22:02:03 INFO - 1499835723956 Marionette TRACE 394 <- [1,9,null,{}]
22:02:03 INFO - TEST-PASS | test_click.py TestClick.test_obscured_element | took 394ms
22:02:03 INFO - TEST-START | test_click.py TestClick.test_pointer_events_none
22:02:03 INFO - 1499835723959 Marionette DEBUG Closed connection 394
22:02:03 INFO - 1499835723960 Marionette DEBUG Accepted connection 395 from 127.0.0.1:50157
22:02:03 INFO - 1499835723960 Marionette DEBUG Closed connection 395
22:02:03 INFO - 1499835723961 Marionette DEBUG Accepted connection 396 from 127.0.0.1:50158
22:02:03 INFO - 1499835723962 Marionette TRACE 396 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
22:02:03 INFO - 1499835723963 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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}
22:02:03 INFO - 1499835723966 Marionette DEBUG Register listener.js for window 12
22:02:03 INFO - 1499835723970 Marionette TRACE 396 <- [1,1,null,{"sessionId":"c52266f3-956a-4d4e-a185-e7e977c1bea4","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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}}]
22:02:03 INFO - 1499835723972 Marionette TRACE 396 -> [0,2,"setTimeouts",{"script":30000}]
22:02:03 INFO - 1499835723973 Marionette TRACE 396 <- [1,2,null,{}]
22:02:03 INFO - 1499835723974 Marionette TRACE 396 -> [0,3,"setTimeouts",{"pageLoad":300000}]
22:02:03 INFO - 1499835723974 Marionette TRACE 396 <- [1,3,null,{}]
22:02:03 INFO - 1499835723975 Marionette TRACE 396 -> [0,4,"setTimeouts",{"implicit":0}]
22:02:03 INFO - 1499835723976 Marionette TRACE 396 <- [1,4,null,{}]
22:02:03 INFO - 1499835723978 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}]
22:02:03 INFO - TEST-START: test_click.py TestClick.test_pointer_events_none1499835723981 Marionette TRACE 396 <- [1,5,null,{"value":null}]
22:02:03 INFO - 1499835723982 Marionette TRACE 396 -> [0,6,"deleteSession",{}]
22:02:03 INFO - 1499835723983 Marionette TRACE 396 <- [1,6,null,{}]
22:02:03 INFO - 1499835723986 Marionette DEBUG Closed connection 396
22:02:03 INFO - 1499835723986 Marionette DEBUG Accepted connection 397 from 127.0.0.1:50159
22:02:03 INFO - 1499835723987 Marionette DEBUG Closed connection 397
22:02:03 INFO - 1499835723988 Marionette DEBUG Accepted connection 398 from 127.0.0.1:50160
22:02:03 INFO - 1499835723989 Marionette TRACE 398 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
22:02:03 INFO - 1499835723990 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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}
22:02:03 INFO - 1499835723992 Marionette DEBUG Register listener.js for window 12
22:02:04 INFO - 1499835723997 Marionette TRACE 398 <- [1,1,null,{"sessionId":"1be028ca-afe6-47e9-98e9-2fba5bc301e3","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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}}]
22:02:04 INFO - 1499835723999 Marionette TRACE 398 -> [0,2,"deleteSession",{}]
22:02:04 INFO - 1499835724000 Marionette TRACE 398 <- [1,2,null,{}]
22:02:04 INFO - 1499835724002 Marionette DEBUG Closed connection 398
22:02:04 INFO - 1499835724003 Marionette DEBUG Accepted connection 399 from 127.0.0.1:50161
22:02:04 INFO - 1499835724004 Marionette DEBUG Closed connection 399
22:02:04 INFO - 1499835724005 Marionette DEBUG Accepted connection 400 from 127.0.0.1:50162
22:02:04 INFO - 1499835724006 Marionette TRACE 400 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
22:02:04 INFO - 1499835724007 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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}
22:02:04 INFO - 1499835724009 Marionette DEBUG Register listener.js for window 12
22:02:04 INFO - 1499835724013 Marionette TRACE 400 <- [1,1,null,{"sessionId":"17e2db44-df77-4a7d-a012-1924866f3965","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":2036,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp9ct3w1.mozrunner","moz:accessibilityChecks":false}}]
22:02:04 INFO - 1499835724015 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"}]
22:02:04 INFO - 1499835724017 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"
22:02:04 INFO - 1499835724019 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"
22:02:04 INFO - 1499835724020 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"
22:02:04 INFO - 1499835724043 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"
22:02:04 INFO - 1499835724045 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"
22:02:04 INFO - 1499835724049 Marionette TRACE 400 <- [1,2,null,{}]
22:02:04 INFO - 1499835724050 Marionette TRACE 400 -> [0,3,"findElement",{"using":"tag name","value":"button"}]
22:02:04 INFO - 1499835724053 Marionette TRACE 400 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"81b5b6e5-d486-46f5-829b-e81648302462","ELEMENT":"81b5b6e5-d486-46f5-829b-e81648302462"}}]
22:02:04 INFO - 1499835724054 Marionette TRACE 400 -> [0,4,"getElementValueOfCssProperty",{"propertyName":"pointer-events","id":"81b5b6e5-d486-46f5-829b-e81648302462"}]
22:02:04 INFO - 1499835724084 Marionette TRACE 400 <- [1,4,null,{"value":"none"}]
22:02:04 INFO - 1499835724085 Marionette TRACE 400 -> [0,5,"clickElement",{"id":"81b5b6e5-d486-46f5-829b-e81648302462"}]
22:02:04 INFO - 1499835724109 Marionette TRACE 400 <- [1,5,{"error":"element click intercepted","message":"Element