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]
08:53:35 INFO - 1500911615850 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}]
08:53:35 INFO - TEST-END: test_click.py TestClick.test_clicking_an_element_that_is_not_displayed_raises1500911615853 Marionette TRACE 352 <- [1,5,null,{"value":null}]
08:53:35 INFO - 1500911615854 Marionette TRACE 352 -> [0,6,"deleteSession",{}]
08:53:35 INFO - 1500911615855 Marionette TRACE 352 <- [1,6,null,{}]
08:53:35 INFO - TEST-PASS | test_click.py TestClick.test_clicking_an_element_that_is_not_displayed_raises | took 132ms
08:53:35 INFO - TEST-START | test_click.py TestClick.test_clicking_on_a_multiline_link
08:53:35 INFO - 1500911615858 Marionette DEBUG Closed connection 352
08:53:35 INFO - 1500911615859 Marionette DEBUG Accepted connection 353 from 127.0.0.1:49864
08:53:35 INFO - 1500911615859 Marionette DEBUG Closed connection 353
08:53:35 INFO - 1500911615860 Marionette DEBUG Accepted connection 354 from 127.0.0.1:49865
08:53:35 INFO - 1500911615861 Marionette TRACE 354 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
08:53:35 INFO - 1500911615862 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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}
08:53:35 INFO - 1500911615865 Marionette DEBUG Register listener.js for window 12
08:53:35 INFO - 1500911615868 Marionette TRACE 354 <- [1,1,null,{"sessionId":"f41d02a9-967e-471c-9181-e4e6179866db","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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}}]
08:53:35 INFO - 1500911615869 Marionette TRACE 354 -> [0,2,"setTimeouts",{"script":30000}]
08:53:35 INFO - 1500911615870 Marionette TRACE 354 <- [1,2,null,{}]
08:53:35 INFO - 1500911615871 Marionette TRACE 354 -> [0,3,"setTimeouts",{"pageLoad":300000}]
08:53:35 INFO - 1500911615871 Marionette TRACE 354 <- [1,3,null,{}]
08:53:35 INFO - 1500911615872 Marionette TRACE 354 -> [0,4,"setTimeouts",{"implicit":0}]
08:53:35 INFO - 1500911615872 Marionette TRACE 354 <- [1,4,null,{}]
08:53:35 INFO - 1500911615874 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}]
08:53:35 INFO - TEST-START: test_click.py TestClick.test_clicking_on_a_multiline_link1500911615876 Marionette TRACE 354 <- [1,5,null,{"value":null}]
08:53:35 INFO - 1500911615877 Marionette TRACE 354 -> [0,6,"deleteSession",{}]
08:53:35 INFO - 1500911615879 Marionette TRACE 354 <- [1,6,null,{}]
08:53:35 INFO - 1500911615880 Marionette DEBUG Closed connection 354
08:53:35 INFO - 1500911615881 Marionette DEBUG Accepted connection 355 from 127.0.0.1:49866
08:53:35 INFO - 1500911615883 Marionette DEBUG Closed connection 355
08:53:35 INFO - 1500911615885 Marionette DEBUG Accepted connection 356 from 127.0.0.1:49867
08:53:35 INFO - 1500911615886 Marionette TRACE 356 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
08:53:35 INFO - 1500911615886 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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}
08:53:35 INFO - 1500911615889 Marionette DEBUG Register listener.js for window 12
08:53:35 INFO - 1500911615892 Marionette TRACE 356 <- [1,1,null,{"sessionId":"3b5bdfdc-aaf1-42d8-814a-6f0aaa30b88e","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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}}]
08:53:35 INFO - 1500911615894 Marionette TRACE 356 -> [0,2,"deleteSession",{}]
08:53:35 INFO - 1500911615895 Marionette TRACE 356 <- [1,2,null,{}]
08:53:35 INFO - 1500911615897 Marionette DEBUG Closed connection 356
08:53:35 INFO - 1500911615897 Marionette DEBUG Accepted connection 357 from 127.0.0.1:49868
08:53:35 INFO - 1500911615898 Marionette DEBUG Closed connection 357
08:53:35 INFO - 1500911615899 Marionette DEBUG Accepted connection 358 from 127.0.0.1:49869
08:53:35 INFO - 1500911615900 Marionette TRACE 358 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
08:53:35 INFO - 1500911615900 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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}
08:53:35 INFO - 1500911615903 Marionette DEBUG Register listener.js for window 12
08:53:35 INFO - 1500911615905 Marionette TRACE 358 <- [1,1,null,{"sessionId":"d76d8292-1685-436d-a462-1b99df6119cd","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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}}]
08:53:35 INFO - 1500911615907 Marionette TRACE 358 -> [0,2,"get",{"url":"http://127.0.0.1:49428/clicks.html"}]
08:53:35 INFO - 1500911615909 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49428/hidden.html"
08:53:35 INFO - 1500911615914 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49428/hidden.html"
08:53:35 INFO - 1500911615915 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49428/hidden.html"
08:53:35 INFO - 1500911615931 Marionette DEBUG Received DOM event "DOMContentLoaded" for "http://127.0.0.1:49428/clicks.html"
08:53:35 INFO - 1500911615937 Marionette DEBUG Received DOM event "pageshow" for "http://127.0.0.1:49428/clicks.html"
08:53:35 INFO - 1500911615940 Marionette TRACE 358 <- [1,2,null,{}]
08:53:35 INFO - 1500911615942 Marionette TRACE 358 -> [0,3,"findElement",{"using":"id","value":"overflowLink"}]
08:53:35 INFO - 1500911615944 Marionette TRACE 358 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"3a5dd0db-da20-4aa8-8838-a43a4857fcc1","ELEMENT":"3a5dd0db-da20-4aa8-8838-a43a4857fcc1"}}]
08:53:35 INFO - 1500911615945 Marionette TRACE 358 -> [0,4,"clickElement",{"id":"3a5dd0db-da20-4aa8-8838-a43a4857fcc1"}]
08:53:35 INFO - 1500911615986 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49428/clicks.html"
08:53:36 INFO - 1500911615994 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49428/clicks.html"
08:53:36 INFO - 1500911615995 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49428/clicks.html"
08:53:36 INFO - 1500911616010 Marionette DEBUG Received DOM event "DOMContentLoaded" for "http://127.0.0.1:49428/test.html"
08:53:36 INFO - 1500911616013 Marionette DEBUG Received DOM event "pageshow" for "http://127.0.0.1:49428/test.html"
08:53:36 INFO - 1500911616016 Marionette TRACE 358 <- [1,4,null,{}]
08:53:36 INFO - 1500911616024 Marionette TRACE 358 -> [0,5,"findElement",{"using":"id","value":"testDiv"}]
08:53:36 INFO - 1500911616027 Marionette TRACE 358 <- [1,5,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"7c7783ec-0b36-49f7-8dcf-d1a4c20dd745","ELEMENT":"7c7783ec-0b36-49f7-8dcf-d1a4c20dd745"}}]
08:53:36 INFO - 1500911616028 Marionette TRACE 358 -> [0,6,"getTitle",{}]
08:53:36 INFO - 1500911616029 Marionette TRACE 358 <- [1,6,null,{"value":"Marionette Test"}]
08:53:36 INFO - 1500911616031 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}]
08:53:36 INFO - TEST-END: test_click.py TestClick.test_clicking_on_a_multiline_link1500911616034 Marionette TRACE 358 <- [1,7,null,{"value":null}]
08:53:36 INFO - 1500911616035 Marionette TRACE 358 -> [0,8,"deleteSession",{}]
08:53:36 INFO - 1500911616036 Marionette TRACE 358 <- [1,8,null,{}]
08:53:36 INFO - TEST-PASS | test_click.py TestClick.test_clicking_on_a_multiline_link | took 180ms
08:53:36 INFO - TEST-START | test_click.py TestClick.test_container_element
08:53:36 INFO - 1500911616038 Marionette DEBUG Closed connection 358
08:53:36 INFO - 1500911616039 Marionette DEBUG Accepted connection 359 from 127.0.0.1:49872
08:53:36 INFO - 1500911616040 Marionette DEBUG Closed connection 359
08:53:36 INFO - 1500911616041 Marionette DEBUG Accepted connection 360 from 127.0.0.1:49873
08:53:36 INFO - 1500911616042 Marionette TRACE 360 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
08:53:36 INFO - 1500911616042 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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}
08:53:36 INFO - 1500911616051 Marionette DEBUG Register listener.js for window 12
08:53:36 INFO - 1500911616054 Marionette TRACE 360 <- [1,1,null,{"sessionId":"9006067b-23d6-417e-b776-fa1915a357be","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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}}]
08:53:36 INFO - 1500911616056 Marionette TRACE 360 -> [0,2,"setTimeouts",{"script":30000}]
08:53:36 INFO - 1500911616056 Marionette TRACE 360 <- [1,2,null,{}]
08:53:36 INFO - 1500911616057 Marionette TRACE 360 -> [0,3,"setTimeouts",{"pageLoad":300000}]
08:53:36 INFO - 1500911616057 Marionette TRACE 360 <- [1,3,null,{}]
08:53:36 INFO - 1500911616058 Marionette TRACE 360 -> [0,4,"setTimeouts",{"implicit":0}]
08:53:36 INFO - 1500911616059 Marionette TRACE 360 <- [1,4,null,{}]
08:53:36 INFO - 1500911616060 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}]
08:53:36 INFO - TEST-START: test_click.py TestClick.test_container_element1500911616063 Marionette TRACE 360 <- [1,5,null,{"value":null}]
08:53:36 INFO - 1500911616064 Marionette TRACE 360 -> [0,6,"deleteSession",{}]
08:53:36 INFO - 1500911616065 Marionette TRACE 360 <- [1,6,null,{}]
08:53:36 INFO - 1500911616067 Marionette DEBUG Closed connection 360
08:53:36 INFO - 1500911616067 Marionette DEBUG Accepted connection 361 from 127.0.0.1:49874
08:53:36 INFO - 1500911616068 Marionette DEBUG Closed connection 361
08:53:36 INFO - 1500911616069 Marionette DEBUG Accepted connection 362 from 127.0.0.1:49875
08:53:36 INFO - 1500911616070 Marionette TRACE 362 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
08:53:36 INFO - 1500911616070 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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}
08:53:36 INFO - 1500911616072 Marionette DEBUG Register listener.js for window 12
08:53:36 INFO - 1500911616075 Marionette TRACE 362 <- [1,1,null,{"sessionId":"863114db-9f56-40ce-b3fa-a00e94a874d0","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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}}]
08:53:36 INFO - 1500911616077 Marionette TRACE 362 -> [0,2,"deleteSession",{}]
08:53:36 INFO - 1500911616078 Marionette TRACE 362 <- [1,2,null,{}]
08:53:36 INFO - 1500911616080 Marionette DEBUG Closed connection 362
08:53:36 INFO - 1500911616080 Marionette DEBUG Accepted connection 363 from 127.0.0.1:49876
08:53:36 INFO - 1500911616081 Marionette DEBUG Closed connection 363
08:53:36 INFO - 1500911616082 Marionette DEBUG Accepted connection 364 from 127.0.0.1:49877
08:53:36 INFO - 1500911616083 Marionette TRACE 364 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
08:53:36 INFO - 1500911616083 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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}
08:53:36 INFO - 1500911616085 Marionette DEBUG Register listener.js for window 12
08:53:36 INFO - 1500911616088 Marionette TRACE 364 <- [1,1,null,{"sessionId":"55145a25-95ec-4737-a3de-c3e583f33557","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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}}]
08:53:36 INFO - 1500911616090 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"}]
08:53:36 INFO - 1500911616091 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49428/test.html"
08:53:36 INFO - 1500911616093 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49428/test.html"
08:53:36 INFO - 1500911616094 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49428/test.html"
08:53:36 INFO - 1500911616111 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"
08:53:36 INFO - 1500911616115 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"
08:53:36 INFO - 1500911616124 Marionette TRACE 364 <- [1,2,null,{}]
08:53:36 INFO - 1500911616126 Marionette TRACE 364 -> [0,3,"findElement",{"using":"tag name","value":"option"}]
08:53:36 INFO - 1500911616129 Marionette TRACE 364 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"807521da-be9d-4d40-b498-ef15268faae5","ELEMENT":"807521da-be9d-4d40-b498-ef15268faae5"}}]
08:53:36 INFO - 1500911616130 Marionette TRACE 364 -> [0,4,"clickElement",{"id":"807521da-be9d-4d40-b498-ef15268faae5"}]
08:53:36 INFO - 1500911616370 Marionette DEBUG Canceled page load listener because no navigation has been detected
08:53:36 INFO - 1500911616371 Marionette TRACE 364 <- [1,4,null,{}]
08:53:36 INFO - 1500911616372 Marionette TRACE 364 -> [0,5,"getElementProperty",{"id":"807521da-be9d-4d40-b498-ef15268faae5","name":"selected"}]
08:53:36 INFO - 1500911616376 Marionette TRACE 364 <- [1,5,null,{"value":true}]
08:53:36 INFO - 1500911616377 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}]
08:53:36 INFO - TEST-END: test_click.py TestClick.test_container_element1500911616380 Marionette TRACE 364 <- [1,6,null,{"value":null}]
08:53:36 INFO - 1500911616381 Marionette TRACE 364 -> [0,7,"deleteSession",{}]
08:53:36 INFO - 1500911616382 Marionette TRACE 364 <- [1,7,null,{}]
08:53:36 INFO - TEST-PASS | test_click.py TestClick.test_container_element | took 345ms
08:53:36 INFO - TEST-START | test_click.py TestClick.test_container_element_outside_view
08:53:36 INFO - 1500911616384 Marionette DEBUG Closed connection 364
08:53:36 INFO - 1500911616385 Marionette DEBUG Accepted connection 365 from 127.0.0.1:49878
08:53:36 INFO - 1500911616386 Marionette DEBUG Closed connection 365
08:53:36 INFO - 1500911616386 Marionette DEBUG Accepted connection 366 from 127.0.0.1:49879
08:53:36 INFO - 1500911616388 Marionette TRACE 366 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
08:53:36 INFO - 1500911616388 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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}
08:53:36 INFO - 1500911616390 Marionette DEBUG Register listener.js for window 12
08:53:36 INFO - 1500911616393 Marionette TRACE 366 <- [1,1,null,{"sessionId":"70086e38-d3f0-4e27-9542-28008982b92b","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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}}]
08:53:36 INFO - 1500911616395 Marionette TRACE 366 -> [0,2,"setTimeouts",{"script":30000}]
08:53:36 INFO - 1500911616395 Marionette TRACE 366 <- [1,2,null,{}]
08:53:36 INFO - 1500911616396 Marionette TRACE 366 -> [0,3,"setTimeouts",{"pageLoad":300000}]
08:53:36 INFO - 1500911616396 Marionette TRACE 366 <- [1,3,null,{}]
08:53:36 INFO - 1500911616397 Marionette TRACE 366 -> [0,4,"setTimeouts",{"implicit":0}]
08:53:36 INFO - 1500911616397 Marionette TRACE 366 <- [1,4,null,{}]
08:53:36 INFO - 1500911616417 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}]
08:53:36 INFO - TEST-START: test_click.py TestClick.test_container_element_outside_view1500911616419 Marionette TRACE 366 <- [1,5,null,{"value":null}]
08:53:36 INFO - 1500911616420 Marionette TRACE 366 -> [0,6,"deleteSession",{}]
08:53:36 INFO - 1500911616421 Marionette TRACE 366 <- [1,6,null,{}]
08:53:36 INFO - 1500911616424 Marionette DEBUG Closed connection 366
08:53:36 INFO - 1500911616425 Marionette DEBUG Accepted connection 367 from 127.0.0.1:49880
08:53:36 INFO - 1500911616426 Marionette DEBUG Closed connection 367
08:53:36 INFO - 1500911616426 Marionette DEBUG Accepted connection 368 from 127.0.0.1:49881
08:53:36 INFO - 1500911616427 Marionette TRACE 368 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
08:53:36 INFO - 1500911616428 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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}
08:53:36 INFO - 1500911616430 Marionette DEBUG Register listener.js for window 12
08:53:36 INFO - 1500911616433 Marionette TRACE 368 <- [1,1,null,{"sessionId":"7c37bc8e-84af-487c-8fed-29988ae7b6a0","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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}}]
08:53:36 INFO - 1500911616435 Marionette TRACE 368 -> [0,2,"deleteSession",{}]
08:53:36 INFO - 1500911616436 Marionette TRACE 368 <- [1,2,null,{}]
08:53:36 INFO - 1500911616439 Marionette DEBUG Closed connection 368
08:53:36 INFO - 1500911616440 Marionette DEBUG Accepted connection 369 from 127.0.0.1:49882
08:53:36 INFO - 1500911616440 Marionette DEBUG Closed connection 369
08:53:36 INFO - 1500911616441 Marionette DEBUG Accepted connection 370 from 127.0.0.1:49883
08:53:36 INFO - 1500911616442 Marionette TRACE 370 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
08:53:36 INFO - 1500911616442 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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}
08:53:36 INFO - 1500911616444 Marionette DEBUG Register listener.js for window 12
08:53:36 INFO - 1500911616447 Marionette TRACE 370 <- [1,1,null,{"sessionId":"92eba35f-6fe1-4af3-a1d6-05699148ef98","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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}}]
08:53:36 INFO - 1500911616449 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"}]
08:53:36 INFO - 1500911616450 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"
08:53:36 INFO - 1500911616453 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"
08:53:36 INFO - 1500911616454 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"
08:53:36 INFO - 1500911616480 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"
08:53:36 INFO - 1500911616486 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"
08:53:36 INFO - 1500911616491 Marionette TRACE 370 <- [1,2,null,{}]
08:53:36 INFO - 1500911616520 Marionette TRACE 370 -> [0,3,"findElement",{"using":"tag name","value":"option"}]
08:53:36 INFO - 1500911616523 Marionette TRACE 370 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"60ee18a9-e455-4ad4-95d4-e0c98e189147","ELEMENT":"60ee18a9-e455-4ad4-95d4-e0c98e189147"}}]
08:53:36 INFO - 1500911616524 Marionette TRACE 370 -> [0,4,"clickElement",{"id":"60ee18a9-e455-4ad4-95d4-e0c98e189147"}]
08:53:36 INFO - 1500911616763 Marionette DEBUG Canceled page load listener because no navigation has been detected
08:53:36 INFO - 1500911616764 Marionette TRACE 370 <- [1,4,null,{}]
08:53:36 INFO - 1500911616765 Marionette TRACE 370 -> [0,5,"getElementProperty",{"id":"60ee18a9-e455-4ad4-95d4-e0c98e189147","name":"selected"}]
08:53:36 INFO - 1500911616769 Marionette TRACE 370 <- [1,5,null,{"value":true}]
08:53:36 INFO - 1500911616770 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}]
08:53:36 INFO - TEST-END: test_click.py TestClick.test_container_element_outside_view1500911616773 Marionette TRACE 370 <- [1,6,null,{"value":null}]
08:53:36 INFO - 1500911616774 Marionette TRACE 370 -> [0,7,"deleteSession",{}]
08:53:36 INFO - TEST-PASS | test_click.py TestClick.test_container_element_outside_view | took 393ms
08:53:36 INFO - TEST-START | test_click.py TestClick.test_css_transforms
08:53:36 INFO - 1500911616775 Marionette TRACE 370 <- [1,7,null,{}]
08:53:36 INFO - 1500911616777 Marionette DEBUG Closed connection 370
08:53:36 INFO - 1500911616778 Marionette DEBUG Accepted connection 371 from 127.0.0.1:49884
08:53:36 INFO - 1500911616778 Marionette DEBUG Closed connection 371
08:53:36 INFO - 1500911616779 Marionette DEBUG Accepted connection 372 from 127.0.0.1:49885
08:53:36 INFO - 1500911616780 Marionette TRACE 372 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
08:53:36 INFO - 1500911616781 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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}
08:53:36 INFO - 1500911616783 Marionette DEBUG Register listener.js for window 12
08:53:36 INFO - 1500911616791 Marionette TRACE 372 <- [1,1,null,{"sessionId":"55acfea7-0d35-41d0-b9d4-5e3c583a6700","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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}}]
08:53:36 INFO - 1500911616793 Marionette TRACE 372 -> [0,2,"setTimeouts",{"script":30000}]
08:53:36 INFO - 1500911616794 Marionette TRACE 372 <- [1,2,null,{}]
08:53:36 INFO - 1500911616795 Marionette TRACE 372 -> [0,3,"setTimeouts",{"pageLoad":300000}]
08:53:36 INFO - 1500911616795 Marionette TRACE 372 <- [1,3,null,{}]
08:53:36 INFO - 1500911616796 Marionette TRACE 372 -> [0,4,"setTimeouts",{"implicit":0}]
08:53:36 INFO - 1500911616796 Marionette TRACE 372 <- [1,4,null,{}]
08:53:36 INFO - 1500911616798 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}]
08:53:36 INFO - TEST-START: test_click.py TestClick.test_css_transforms1500911616801 Marionette TRACE 372 <- [1,5,null,{"value":null}]
08:53:36 INFO - 1500911616801 Marionette TRACE 372 -> [0,6,"deleteSession",{}]
08:53:36 INFO - 1500911616803 Marionette TRACE 372 <- [1,6,null,{}]
08:53:36 INFO - 1500911616804 Marionette DEBUG Closed connection 372
08:53:36 INFO - 1500911616805 Marionette DEBUG Accepted connection 373 from 127.0.0.1:49886
08:53:36 INFO - 1500911616806 Marionette DEBUG Closed connection 373
08:53:36 INFO - 1500911616807 Marionette DEBUG Accepted connection 374 from 127.0.0.1:49887
08:53:36 INFO - 1500911616807 Marionette TRACE 374 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
08:53:36 INFO - 1500911616808 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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}
08:53:36 INFO - 1500911616810 Marionette DEBUG Register listener.js for window 12
08:53:36 INFO - 1500911616813 Marionette TRACE 374 <- [1,1,null,{"sessionId":"abfe84ac-3d0b-40f1-99a0-734f4b2f850c","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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}}]
08:53:36 INFO - 1500911616814 Marionette TRACE 374 -> [0,2,"deleteSession",{}]
08:53:36 INFO - 1500911616816 Marionette TRACE 374 <- [1,2,null,{}]
08:53:36 INFO - 1500911616817 Marionette DEBUG Closed connection 374
08:53:36 INFO - 1500911616818 Marionette DEBUG Accepted connection 375 from 127.0.0.1:49888
08:53:36 INFO - 1500911616819 Marionette DEBUG Closed connection 375
08:53:36 INFO - 1500911616819 Marionette DEBUG Accepted connection 376 from 127.0.0.1:49889
08:53:36 INFO - 1500911616820 Marionette TRACE 376 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
08:53:36 INFO - 1500911616821 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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}
08:53:36 INFO - 1500911616823 Marionette DEBUG Register listener.js for window 12
08:53:36 INFO - 1500911616826 Marionette TRACE 376 <- [1,1,null,{"sessionId":"0ca1e851-1c9d-4748-ac77-ea485e197642","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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}}]
08:53:36 INFO - 1500911616827 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"}]
08:53:36 INFO - 1500911616829 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"
08:53:36 INFO - 1500911616831 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"
08:53:36 INFO - 1500911616831 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"
08:53:36 INFO - 1500911616850 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"
08:53:36 INFO - 1500911616853 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"
08:53:36 INFO - 1500911616856 Marionette TRACE 376 <- [1,2,null,{}]
08:53:36 INFO - 1500911616857 Marionette TRACE 376 -> [0,3,"findElement",{"using":"tag name","value":"div"}]
08:53:36 INFO - 1500911616859 Marionette TRACE 376 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"897cf6a6-cadb-4084-a2b9-3ed703690a67","ELEMENT":"897cf6a6-cadb-4084-a2b9-3ed703690a67"}}]
08:53:36 INFO - 1500911616860 Marionette TRACE 376 -> [0,4,"clickElement",{"id":"897cf6a6-cadb-4084-a2b9-3ed703690a67"}]
08:53:37 INFO - 1500911617099 Marionette DEBUG Canceled page load listener because no navigation has been detected
08:53:37 INFO - 1500911617100 Marionette TRACE 376 <- [1,4,null,{}]
08:53:37 INFO - 1500911617102 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}]
08:53:37 INFO - TEST-END: test_click.py TestClick.test_css_transforms1500911617104 Marionette TRACE 376 <- [1,5,null,{"value":null}]
08:53:37 INFO - 1500911617105 Marionette TRACE 376 -> [0,6,"deleteSession",{}]
08:53:37 INFO - 1500911617106 Marionette TRACE 376 <- [1,6,null,{}]
08:53:37 INFO - TEST-PASS | test_click.py TestClick.test_css_transforms | took 331ms
08:53:37 INFO - TEST-START | test_click.py TestClick.test_inclusive_descendant
08:53:37 INFO - 1500911617108 Marionette DEBUG Closed connection 376
08:53:37 INFO - 1500911617109 Marionette DEBUG Accepted connection 377 from 127.0.0.1:49890
08:53:37 INFO - 1500911617110 Marionette DEBUG Closed connection 377
08:53:37 INFO - 1500911617111 Marionette DEBUG Accepted connection 378 from 127.0.0.1:49891
08:53:37 INFO - 1500911617112 Marionette TRACE 378 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
08:53:37 INFO - 1500911617112 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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}
08:53:37 INFO - 1500911617114 Marionette DEBUG Register listener.js for window 12
08:53:37 INFO - 1500911617117 Marionette TRACE 378 <- [1,1,null,{"sessionId":"b8e44e01-01dd-42f0-a33c-0a35211e37d9","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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}}]
08:53:37 INFO - 1500911617119 Marionette TRACE 378 -> [0,2,"setTimeouts",{"script":30000}]
08:53:37 INFO - 1500911617119 Marionette TRACE 378 <- [1,2,null,{}]
08:53:37 INFO - 1500911617120 Marionette TRACE 378 -> [0,3,"setTimeouts",{"pageLoad":300000}]
08:53:37 INFO - 1500911617121 Marionette TRACE 378 <- [1,3,null,{}]
08:53:37 INFO - 1500911617122 Marionette TRACE 378 -> [0,4,"setTimeouts",{"implicit":0}]
08:53:37 INFO - 1500911617122 Marionette TRACE 378 <- [1,4,null,{}]
08:53:37 INFO - 1500911617124 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}]
08:53:37 INFO - TEST-START: test_click.py TestClick.test_inclusive_descendant1500911617126 Marionette TRACE 378 <- [1,5,null,{"value":null}]
08:53:37 INFO - 1500911617127 Marionette TRACE 378 -> [0,6,"deleteSession",{}]
08:53:37 INFO - 1500911617128 Marionette TRACE 378 <- [1,6,null,{}]
08:53:37 INFO - 1500911617130 Marionette DEBUG Closed connection 378
08:53:37 INFO - 1500911617131 Marionette DEBUG Accepted connection 379 from 127.0.0.1:49892
08:53:37 INFO - 1500911617131 Marionette DEBUG Closed connection 379
08:53:37 INFO - 1500911617132 Marionette DEBUG Accepted connection 380 from 127.0.0.1:49893
08:53:37 INFO - 1500911617133 Marionette TRACE 380 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
08:53:37 INFO - 1500911617133 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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}
08:53:37 INFO - 1500911617135 Marionette DEBUG Register listener.js for window 12
08:53:37 INFO - 1500911617138 Marionette TRACE 380 <- [1,1,null,{"sessionId":"37ae5029-44f1-4135-bcd4-840623836c37","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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}}]
08:53:37 INFO - 1500911617140 Marionette TRACE 380 -> [0,2,"deleteSession",{}]
08:53:37 INFO - 1500911617141 Marionette TRACE 380 <- [1,2,null,{}]
08:53:37 INFO - 1500911617142 Marionette DEBUG Closed connection 380
08:53:37 INFO - 1500911617143 Marionette DEBUG Accepted connection 381 from 127.0.0.1:49894
08:53:37 INFO - 1500911617144 Marionette DEBUG Closed connection 381
08:53:37 INFO - 1500911617144 Marionette DEBUG Accepted connection 382 from 127.0.0.1:49895
08:53:37 INFO - 1500911617145 Marionette TRACE 382 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
08:53:37 INFO - 1500911617146 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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}
08:53:37 INFO - 1500911617148 Marionette DEBUG Register listener.js for window 12
08:53:37 INFO - 1500911617150 Marionette TRACE 382 <- [1,1,null,{"sessionId":"c7de3082-5337-40ce-a92a-22f9b6928069","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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}}]
08:53:37 INFO - 1500911617152 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"}]
08:53:37 INFO - 1500911617154 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"
08:53:37 INFO - 1500911617156 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"
08:53:37 INFO - 1500911617157 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"
08:53:37 INFO - 1500911617174 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"
08:53:37 INFO - 1500911617177 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"
08:53:37 INFO - 1500911617180 Marionette TRACE 382 <- [1,2,null,{}]
08:53:37 INFO - 1500911617188 Marionette TRACE 382 -> [0,3,"findElement",{"using":"tag name","value":"select"}]
08:53:37 INFO - 1500911617191 Marionette TRACE 382 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"f4533c37-80ba-4b43-89d0-460f1edbea6d","ELEMENT":"f4533c37-80ba-4b43-89d0-460f1edbea6d"}}]
08:53:37 INFO - 1500911617192 Marionette TRACE 382 -> [0,4,"clickElement",{"id":"f4533c37-80ba-4b43-89d0-460f1edbea6d"}]
08:53:37 INFO - 1500911617429 Marionette DEBUG Canceled page load listener because no navigation has been detected
08:53:37 INFO - 1500911617430 Marionette TRACE 382 <- [1,4,null,{}]
08:53:37 INFO - 1500911617432 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}]
08:53:37 INFO - TEST-END: test_click.py TestClick.test_inclusive_descendant1500911617434 Marionette TRACE 382 <- [1,5,null,{"value":null}]
08:53:37 INFO - 1500911617435 Marionette TRACE 382 -> [0,6,"deleteSession",{}]
08:53:37 INFO - 1500911617436 Marionette TRACE 382 <- [1,6,null,{}]
08:53:37 INFO - TEST-PASS | test_click.py TestClick.test_inclusive_descendant | took 329ms
08:53:37 INFO - TEST-START | test_click.py TestClick.test_input_file
08:53:37 INFO - 1500911617438 Marionette DEBUG Closed connection 382
08:53:37 INFO - 1500911617439 Marionette DEBUG Accepted connection 383 from 127.0.0.1:49896
08:53:37 INFO - 1500911617440 Marionette DEBUG Closed connection 383
08:53:37 INFO - 1500911617441 Marionette DEBUG Accepted connection 384 from 127.0.0.1:49897
08:53:37 INFO - 1500911617442 Marionette TRACE 384 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
08:53:37 INFO - 1500911617442 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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}
08:53:37 INFO - 1500911617444 Marionette DEBUG Register listener.js for window 12
08:53:37 INFO - 1500911617447 Marionette TRACE 384 <- [1,1,null,{"sessionId":"4233e582-6407-4365-95fc-90040d6c47b3","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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}}]
08:53:37 INFO - 1500911617449 Marionette TRACE 384 -> [0,2,"setTimeouts",{"script":30000}]
08:53:37 INFO - 1500911617449 Marionette TRACE 384 <- [1,2,null,{}]
08:53:37 INFO - 1500911617450 Marionette TRACE 384 -> [0,3,"setTimeouts",{"pageLoad":300000}]
08:53:37 INFO - 1500911617450 Marionette TRACE 384 <- [1,3,null,{}]
08:53:37 INFO - 1500911617451 Marionette TRACE 384 -> [0,4,"setTimeouts",{"implicit":0}]
08:53:37 INFO - 1500911617451 Marionette TRACE 384 <- [1,4,null,{}]
08:53:37 INFO - 1500911617453 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}]
08:53:37 INFO - TEST-START: test_click.py TestClick.test_input_file1500911617455 Marionette TRACE 384 <- [1,5,null,{"value":null}]
08:53:37 INFO - 1500911617456 Marionette TRACE 384 -> [0,6,"deleteSession",{}]
08:53:37 INFO - 1500911617457 Marionette TRACE 384 <- [1,6,null,{}]
08:53:37 INFO - 1500911617459 Marionette DEBUG Closed connection 384
08:53:37 INFO - 1500911617459 Marionette DEBUG Accepted connection 385 from 127.0.0.1:49898
08:53:37 INFO - 1500911617460 Marionette DEBUG Closed connection 385
08:53:37 INFO - 1500911617461 Marionette DEBUG Accepted connection 386 from 127.0.0.1:49899
08:53:37 INFO - 1500911617462 Marionette TRACE 386 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
08:53:37 INFO - 1500911617462 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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}
08:53:37 INFO - 1500911617470 Marionette DEBUG Register listener.js for window 12
08:53:37 INFO - 1500911617473 Marionette TRACE 386 <- [1,1,null,{"sessionId":"3d3dc696-b60d-442b-9f67-29b195aa45f1","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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}}]
08:53:37 INFO - 1500911617474 Marionette TRACE 386 -> [0,2,"deleteSession",{}]
08:53:37 INFO - 1500911617476 Marionette TRACE 386 <- [1,2,null,{}]
08:53:37 INFO - 1500911617477 Marionette DEBUG Closed connection 386
08:53:37 INFO - 1500911617478 Marionette DEBUG Accepted connection 387 from 127.0.0.1:49900
08:53:37 INFO - 1500911617479 Marionette DEBUG Closed connection 387
08:53:37 INFO - 1500911617480 Marionette DEBUG Accepted connection 388 from 127.0.0.1:49901
08:53:37 INFO - 1500911617480 Marionette TRACE 388 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
08:53:37 INFO - 1500911617481 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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}
08:53:37 INFO - 1500911617483 Marionette DEBUG Register listener.js for window 12
08:53:37 INFO - 1500911617485 Marionette TRACE 388 <- [1,1,null,{"sessionId":"6c4d4271-1959-4872-82d1-0857b3131b9f","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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}}]
08:53:37 INFO - 1500911617487 Marionette TRACE 388 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"}]
08:53:37 INFO - 1500911617489 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"
08:53:37 INFO - 1500911617490 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"
08:53:37 INFO - 1500911617491 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"
08:53:37 INFO - 1500911617507 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
08:53:37 INFO - 1500911617510 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
08:53:37 INFO - 1500911617513 Marionette TRACE 388 <- [1,2,null,{}]
08:53:37 INFO - 1500911617514 Marionette TRACE 388 -> [0,3,"findElement",{"using":"tag name","value":"input"}]
08:53:37 INFO - 1500911617522 Marionette TRACE 388 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"0bb13817-8f5e-403c-a7df-56c27a2642a1","ELEMENT":"0bb13817-8f5e-403c-a7df-56c27a2642a1"}}]
08:53:37 INFO - 1500911617523 Marionette TRACE 388 -> [0,4,"clickElement",{"id":"0bb13817-8f5e-403c-a7df-56c27a2642a1"}]
08:53:37 INFO - 1500911617548 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]
08:53:37 INFO - 1500911617550 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}]
08:53:37 INFO - TEST-END: test_click.py TestClick.test_input_file1500911617553 Marionette TRACE 388 <- [1,5,null,{"value":null}]
08:53:37 INFO - 1500911617554 Marionette TRACE 388 -> [0,6,"deleteSession",{}]
08:53:37 INFO - 1500911617555 Marionette TRACE 388 <- [1,6,null,{}]
08:53:37 INFO - TEST-PASS | test_click.py TestClick.test_input_file | took 119ms
08:53:37 INFO - TEST-START | test_click.py TestClick.test_obscured_element
08:53:37 INFO - 1500911617557 Marionette DEBUG Closed connection 388
08:53:37 INFO - 1500911617558 Marionette DEBUG Accepted connection 389 from 127.0.0.1:49902
08:53:37 INFO - 1500911617559 Marionette DEBUG Closed connection 389
08:53:37 INFO - 1500911617559 Marionette DEBUG Accepted connection 390 from 127.0.0.1:49903
08:53:37 INFO - 1500911617560 Marionette TRACE 390 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
08:53:37 INFO - 1500911617561 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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}
08:53:37 INFO - 1500911617563 Marionette DEBUG Register listener.js for window 12
08:53:37 INFO - 1500911617565 Marionette TRACE 390 <- [1,1,null,{"sessionId":"0c938bd4-3188-489f-95fb-70440ca99ee8","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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}}]
08:53:37 INFO - 1500911617567 Marionette TRACE 390 -> [0,2,"setTimeouts",{"script":30000}]
08:53:37 INFO - 1500911617568 Marionette TRACE 390 <- [1,2,null,{}]
08:53:37 INFO - 1500911617569 Marionette TRACE 390 -> [0,3,"setTimeouts",{"pageLoad":300000}]
08:53:37 INFO - 1500911617569 Marionette TRACE 390 <- [1,3,null,{}]
08:53:37 INFO - 1500911617570 Marionette TRACE 390 -> [0,4,"setTimeouts",{"implicit":0}]
08:53:37 INFO - 1500911617570 Marionette TRACE 390 <- [1,4,null,{}]
08:53:37 INFO - 1500911617572 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}]
08:53:37 INFO - TEST-START: test_click.py TestClick.test_obscured_element1500911617574 Marionette TRACE 390 <- [1,5,null,{"value":null}]
08:53:37 INFO - 1500911617575 Marionette TRACE 390 -> [0,6,"deleteSession",{}]
08:53:37 INFO - 1500911617576 Marionette TRACE 390 <- [1,6,null,{}]
08:53:37 INFO - 1500911617578 Marionette DEBUG Closed connection 390
08:53:37 INFO - 1500911617579 Marionette DEBUG Accepted connection 391 from 127.0.0.1:49904
08:53:37 INFO - 1500911617579 Marionette DEBUG Closed connection 391
08:53:37 INFO - 1500911617580 Marionette DEBUG Accepted connection 392 from 127.0.0.1:49905
08:53:37 INFO - 1500911617581 Marionette TRACE 392 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
08:53:37 INFO - 1500911617581 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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}
08:53:37 INFO - 1500911617583 Marionette DEBUG Register listener.js for window 12
08:53:37 INFO - 1500911617586 Marionette TRACE 392 <- [1,1,null,{"sessionId":"5d136816-e8cc-4ab5-91ac-413aac87010d","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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}}]
08:53:37 INFO - 1500911617588 Marionette TRACE 392 -> [0,2,"deleteSession",{}]
08:53:37 INFO - 1500911617589 Marionette TRACE 392 <- [1,2,null,{}]
08:53:37 INFO - 1500911617590 Marionette DEBUG Closed connection 392
08:53:37 INFO - 1500911617591 Marionette DEBUG Accepted connection 393 from 127.0.0.1:49906
08:53:37 INFO - 1500911617592 Marionette DEBUG Closed connection 393
08:53:37 INFO - 1500911617592 Marionette DEBUG Accepted connection 394 from 127.0.0.1:49907
08:53:37 INFO - 1500911617593 Marionette TRACE 394 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
08:53:37 INFO - 1500911617594 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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}
08:53:37 INFO - 1500911617596 Marionette DEBUG Register listener.js for window 12
08:53:37 INFO - 1500911617598 Marionette TRACE 394 <- [1,1,null,{"sessionId":"10bc5370-1f4d-42d6-9641-977b1a460aa3","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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}}]
08:53:37 INFO - 1500911617600 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"}]
08:53:37 INFO - 1500911617601 Marionette DEBUG Received DOM event "beforeunload" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
08:53:37 INFO - 1500911617603 Marionette DEBUG Received DOM event "pagehide" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
08:53:37 INFO - 1500911617604 Marionette DEBUG Received DOM event "unload" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
08:53:37 INFO - 1500911617614 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"
08:53:37 INFO - 1500911617617 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"
08:53:37 INFO - 1500911617626 Marionette TRACE 394 <- [1,2,null,{}]
08:53:37 INFO - 1500911617627 Marionette TRACE 394 -> [0,3,"findElement",{"using":"id","value":"overlay"}]
08:53:37 INFO - 1500911617630 Marionette TRACE 394 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"7f23d06f-21e3-43f1-80b2-55fc1f029453","ELEMENT":"7f23d06f-21e3-43f1-80b2-55fc1f029453"}}]
08:53:37 INFO - 1500911617633 Marionette TRACE 394 -> [0,4,"findElement",{"using":"id","value":"obscured"}]
08:53:37 INFO - 1500911617635 Marionette TRACE 394 <- [1,4,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"0f9fbc3f-f316-4ffd-a6b0-cc7b71fa66e8","ELEMENT":"0f9fbc3f-f316-4ffd-a6b0-cc7b71fa66e8"}}]
08:53:37 INFO - 1500911617636 Marionette TRACE 394 -> [0,5,"clickElement",{"id":"7f23d06f-21e3-43f1-80b2-55fc1f029453"}]
08:53:37 INFO - 1500911617871 Marionette DEBUG Canceled page load listener because no navigation has been detected
08:53:37 INFO - 1500911617872 Marionette TRACE 394 <- [1,5,null,{}]
08:53:37 INFO - 1500911617873 Marionette TRACE 394 -> [0,6,"clickElement",{"id":"0f9fbc3f-f316-4ffd-a6b0-cc7b71fa66e8"}]
08:53:37 INFO - 1500911617886 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]
08:53:37 INFO - 1500911617888 Marionette TRACE 394 -> [0,7,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"test_click.py","script":"return window.clicked","sandbox":null,"line":257}]
08:53:37 INFO - 1500911617891 Marionette TRACE 394 <- [1,7,null,{"value":false}]
08:53:37 INFO - 1500911617892 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}]
08:53:37 INFO - TEST-END: test_click.py TestClick.test_obscured_element1500911617895 Marionette TRACE 394 <- [1,8,null,{"value":null}]
08:53:37 INFO - 1500911617895 Marionette TRACE 394 -> [0,9,"deleteSession",{}]
08:53:37 INFO - 1500911617897 Marionette TRACE 394 <- [1,9,null,{}]
08:53:37 INFO - TEST-PASS | test_click.py TestClick.test_obscured_element | took 341ms
08:53:37 INFO - TEST-START | test_click.py TestClick.test_pointer_events_none
08:53:37 INFO - 1500911617898 Marionette DEBUG Closed connection 394
08:53:37 INFO - 1500911617899 Marionette DEBUG Accepted connection 395 from 127.0.0.1:49908
08:53:37 INFO - 1500911617900 Marionette DEBUG Closed connection 395
08:53:37 INFO - 1500911617901 Marionette DEBUG Accepted connection 396 from 127.0.0.1:49909
08:53:37 INFO - 1500911617902 Marionette TRACE 396 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
08:53:37 INFO - 1500911617902 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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}
08:53:37 INFO - 1500911617904 Marionette DEBUG Register listener.js for window 12
08:53:37 INFO - 1500911617907 Marionette TRACE 396 <- [1,1,null,{"sessionId":"d7ae848b-4452-476c-afe7-21a6cf73dad1","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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}}]
08:53:37 INFO - 1500911617909 Marionette TRACE 396 -> [0,2,"setTimeouts",{"script":30000}]
08:53:37 INFO - 1500911617909 Marionette TRACE 396 <- [1,2,null,{}]
08:53:37 INFO - 1500911617910 Marionette TRACE 396 -> [0,3,"setTimeouts",{"pageLoad":300000}]
08:53:37 INFO - 1500911617911 Marionette TRACE 396 <- [1,3,null,{}]
08:53:37 INFO - 1500911617912 Marionette TRACE 396 -> [0,4,"setTimeouts",{"implicit":0}]
08:53:37 INFO - 1500911617912 Marionette TRACE 396 <- [1,4,null,{}]
08:53:37 INFO - 1500911617914 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}]
08:53:37 INFO - TEST-START: test_click.py TestClick.test_pointer_events_none1500911617916 Marionette TRACE 396 <- [1,5,null,{"value":null}]
08:53:37 INFO - 1500911617917 Marionette TRACE 396 -> [0,6,"deleteSession",{}]
08:53:37 INFO - 1500911617918 Marionette TRACE 396 <- [1,6,null,{}]
08:53:37 INFO - 1500911617920 Marionette DEBUG Closed connection 396
08:53:37 INFO - 1500911617921 Marionette DEBUG Accepted connection 397 from 127.0.0.1:49910
08:53:37 INFO - 1500911617921 Marionette DEBUG Closed connection 397
08:53:37 INFO - 1500911617922 Marionette DEBUG Accepted connection 398 from 127.0.0.1:49911
08:53:37 INFO - 1500911617923 Marionette TRACE 398 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
08:53:37 INFO - 1500911617923 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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}
08:53:37 INFO - 1500911617925 Marionette DEBUG Register listener.js for window 12
08:53:37 INFO - 1500911617934 Marionette TRACE 398 <- [1,1,null,{"sessionId":"2bd55a24-bafb-4ba7-88bb-a66145ea1908","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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}}]
08:53:37 INFO - 1500911617936 Marionette TRACE 398 -> [0,2,"deleteSession",{}]
08:53:37 INFO - 1500911617937 Marionette TRACE 398 <- [1,2,null,{}]
08:53:37 INFO - 1500911617939 Marionette DEBUG Closed connection 398
08:53:37 INFO - 1500911617940 Marionette DEBUG Accepted connection 399 from 127.0.0.1:49912
08:53:37 INFO - 1500911617941 Marionette DEBUG Closed connection 399
08:53:37 INFO - 1500911617941 Marionette DEBUG Accepted connection 400 from 127.0.0.1:49913
08:53:37 INFO - 1500911617943 Marionette TRACE 400 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
08:53:37 INFO - 1500911617943 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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}
08:53:37 INFO - 1500911617945 Marionette DEBUG Register listener.js for window 12
08:53:37 INFO - 1500911617948 Marionette TRACE 400 <- [1,1,null,{"sessionId":"8a00edd0-a86d-45c9-a0a5-2d9036dce7a8","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":2916,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmppyrn2n.mozrunner","moz:accessibilityChecks":false}}]
08:53:37 INFO - 1500911617950 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"}]
08:53:37 INFO - 1500911617951 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"
08:53:37 INFO - 1500911617953 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"
08:53:37 INFO - 1500911617954 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"
08:53:37 INFO - 1500911617964 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"
08:53:37 INFO - 1500911617967 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"
08:53:37 INFO - 1500911617976 Marionette TRACE 400 <- [1,2,null,{}]
08:53:37 INFO - 1500911617978 Marionette TRACE 400 -> [0,3,"findElement",{"using":"tag name","value":"button"}]
08:53:37 INFO - 1500911617981 Marionette TRACE 400 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"b332e19f-76af-46c6-aba0-d5771bf674f4","ELEMENT":"b332e19f-76af-46c6-aba0-d5771bf674f4"}}]
08:53:37 INFO - 1500911617982 Marionette TRACE 400 -> [0,4,"getElementValueOfCssProperty",{"propertyName":"pointer-events","id":"b332e19f-76af-46c6-aba0-d5771bf674f4"}]
08:53:38 INFO - 1500911618002 Marionette TRACE 400 <- [1,4,null,{"value":"none"}]
08:53:38 INFO - 1500911618003 Marionette TRACE 400 -> [0,5,"clickElement",{"id":"b332e19f-76af-46c6-aba0-d5771bf674f4"}]
08:53:38 INFO - 1500911618020 Marionette TRACE 400 <- [1,5,{"error":"element click intercepted","message":"Element