could not be scrolled into view","stacktrace":"WebDriverError@chrome://marionette/content/error.js:226:5\nElementNotInteractableError@chrome://marionette/content/error.js:315:5\nwebdriverClickElement@chrome://marionette/content/interaction.js:183:11\nTaskImpl_run@resource://gre/modules/Task.jsm:331:42\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nTaskImpl_handleResultValue@resource://gre/modules/Task.jsm:401:16\nTaskImpl_run@resource://gre/modules/Task.jsm:339:15\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nTaskImpl_handleResultValue@resource://gre/modules/Task.jsm:401:16\nTaskImpl_run@resource://gre/modules/Task.jsm:339:15\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nnavigate@chrome://marionette/content/listener.js:392:12\nclickElement@chrome://marionette/content/listener.js:1312:5\n"},null]
12:48:07 INFO - 1499543287633 Marionette TRACE 352 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-END: test_click.py TestClick.test_clicking_an_element_that_is_not_displayed_raises')","sandbox":"simpletest","line":328}]
12:48:07 INFO - TEST-END: test_click.py TestClick.test_clicking_an_element_that_is_not_displayed_raises1499543287635 Marionette TRACE 352 <- [1,5,null,{"value":null}]
12:48:07 INFO - TEST-PASS | test_click.py TestClick.test_clicking_an_element_that_is_not_displayed_raises | took 143ms
12:48:07 INFO - TEST-START | test_click.py TestClick.test_clicking_on_a_multiline_link
12:48:07 INFO - 1499543287639 Marionette TRACE 352 -> [0,6,"deleteSession",{}]
12:48:07 INFO - 1499543287641 Marionette TRACE 352 <- [1,6,null,{}]
12:48:07 INFO - 1499543287643 Marionette DEBUG Closed connection 352
12:48:07 INFO - 1499543287644 Marionette DEBUG Accepted connection 353 from 127.0.0.1:50108
12:48:07 INFO - 1499543287645 Marionette DEBUG Closed connection 353
12:48:07 INFO - 1499543287645 Marionette DEBUG Accepted connection 354 from 127.0.0.1:50109
12:48:07 INFO - 1499543287646 Marionette TRACE 354 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:07 INFO - 1499543287647 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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}
12:48:07 INFO - 1499543287649 Marionette DEBUG Register listener.js for window 12
12:48:07 INFO - 1499543287652 Marionette TRACE 354 <- [1,1,null,{"sessionId":"40eed804-4003-4614-b19f-a55de8acc8de","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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}}]
12:48:07 INFO - 1499543287655 Marionette TRACE 354 -> [0,2,"setTimeouts",{"script":30000}]
12:48:07 INFO - 1499543287655 Marionette TRACE 354 <- [1,2,null,{}]
12:48:07 INFO - 1499543287656 Marionette TRACE 354 -> [0,3,"setTimeouts",{"pageLoad":300000}]
12:48:07 INFO - 1499543287656 Marionette TRACE 354 <- [1,3,null,{}]
12:48:07 INFO - 1499543287657 Marionette TRACE 354 -> [0,4,"setTimeouts",{"implicit":0}]
12:48:07 INFO - 1499543287658 Marionette TRACE 354 <- [1,4,null,{}]
12:48:07 INFO - 1499543287659 Marionette TRACE 354 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-START: test_click.py TestClick.test_clicking_on_a_multiline_link')","sandbox":"simpletest","line":316}]
12:48:07 INFO - TEST-START: test_click.py TestClick.test_clicking_on_a_multiline_link1499543287662 Marionette TRACE 354 <- [1,5,null,{"value":null}]
12:48:07 INFO - 1499543287663 Marionette TRACE 354 -> [0,6,"deleteSession",{}]
12:48:07 INFO - 1499543287665 Marionette TRACE 354 <- [1,6,null,{}]
12:48:07 INFO - 1499543287668 Marionette DEBUG Closed connection 354
12:48:07 INFO - 1499543287668 Marionette DEBUG Accepted connection 355 from 127.0.0.1:50110
12:48:07 INFO - 1499543287669 Marionette DEBUG Closed connection 355
12:48:07 INFO - 1499543287670 Marionette DEBUG Accepted connection 356 from 127.0.0.1:50111
12:48:07 INFO - 1499543287671 Marionette TRACE 356 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:07 INFO - 1499543287671 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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}
12:48:07 INFO - 1499543287674 Marionette DEBUG Register listener.js for window 12
12:48:07 INFO - 1499543287686 Marionette TRACE 356 <- [1,1,null,{"sessionId":"b0f89d4e-989a-4061-a62f-725afb63cd80","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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}}]
12:48:07 INFO - 1499543287688 Marionette TRACE 356 -> [0,2,"deleteSession",{}]
12:48:07 INFO - 1499543287690 Marionette TRACE 356 <- [1,2,null,{}]
12:48:07 INFO - 1499543287692 Marionette DEBUG Closed connection 356
12:48:07 INFO - 1499543287692 Marionette DEBUG Accepted connection 357 from 127.0.0.1:50112
12:48:07 INFO - 1499543287693 Marionette DEBUG Closed connection 357
12:48:07 INFO - 1499543287694 Marionette DEBUG Accepted connection 358 from 127.0.0.1:50113
12:48:07 INFO - 1499543287695 Marionette TRACE 358 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
12:48:07 INFO - 1499543287695 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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}
12:48:07 INFO - 1499543287698 Marionette DEBUG Register listener.js for window 12
12:48:07 INFO - 1499543287700 Marionette TRACE 358 <- [1,1,null,{"sessionId":"30dc02d0-b551-4eb0-925f-232e1dbe6549","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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}}]
12:48:07 INFO - 1499543287702 Marionette TRACE 358 -> [0,2,"get",{"url":"http://127.0.0.1:49679/clicks.html"}]
12:48:07 INFO - 1499543287704 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49679/hidden.html"
12:48:07 INFO - 1499543287709 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49679/hidden.html"
12:48:07 INFO - 1499543287709 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49679/hidden.html"
12:48:07 INFO - 1499543287731 Marionette DEBUG Received DOM event "DOMContentLoaded" for "http://127.0.0.1:49679/clicks.html"
12:48:07 INFO - 1499543287732 Marionette DEBUG Received DOM event "pageshow" for "http://127.0.0.1:49679/clicks.html"
12:48:07 INFO - 1499543287736 Marionette TRACE 358 <- [1,2,null,{}]
12:48:07 INFO - 1499543287744 Marionette TRACE 358 -> [0,3,"findElement",{"using":"id","value":"overflowLink"}]
12:48:07 INFO - 1499543287747 Marionette TRACE 358 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"68423c0c-1bc5-4fa7-91e1-f54069304d21","ELEMENT":"68423c0c-1bc5-4fa7-91e1-f54069304d21"}}]
12:48:07 INFO - 1499543287748 Marionette TRACE 358 -> [0,4,"clickElement",{"id":"68423c0c-1bc5-4fa7-91e1-f54069304d21"}]
12:48:07 INFO - 1499543287789 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49679/clicks.html"
12:48:07 INFO - 1499543287799 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49679/clicks.html"
12:48:07 INFO - 1499543287800 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49679/clicks.html"
12:48:07 INFO - 1499543287829 Marionette DEBUG Received DOM event "DOMContentLoaded" for "http://127.0.0.1:49679/test.html"
12:48:07 INFO - 1499543287832 Marionette DEBUG Received DOM event "pageshow" for "http://127.0.0.1:49679/test.html"
12:48:07 INFO - 1499543287836 Marionette TRACE 358 <- [1,4,null,{}]
12:48:07 INFO - 1499543287845 Marionette TRACE 358 -> [0,5,"findElement",{"using":"id","value":"testDiv"}]
12:48:07 INFO - 1499543287848 Marionette TRACE 358 <- [1,5,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"a422857c-916d-4bd5-bde1-d2f7319e047b","ELEMENT":"a422857c-916d-4bd5-bde1-d2f7319e047b"}}]
12:48:07 INFO - 1499543287849 Marionette TRACE 358 -> [0,6,"getTitle",{}]
12:48:07 INFO - 1499543287849 Marionette TRACE 358 <- [1,6,null,{"value":"Marionette Test"}]
12:48:07 INFO - 1499543287851 Marionette TRACE 358 -> [0,7,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-END: test_click.py TestClick.test_clicking_on_a_multiline_link')","sandbox":"simpletest","line":328}]
12:48:07 INFO - TEST-END: test_click.py TestClick.test_clicking_on_a_multiline_link1499543287854 Marionette TRACE 358 <- [1,7,null,{"value":null}]
12:48:07 INFO - 1499543287872 Marionette TRACE 358 -> [0,8,"deleteSession",{}]
12:48:07 INFO - 1499543287873 Marionette TRACE 358 <- [1,8,null,{}]
12:48:07 INFO - TEST-PASS | test_click.py TestClick.test_clicking_on_a_multiline_link | took 232ms
12:48:07 INFO - TEST-START | test_click.py TestClick.test_container_element
12:48:07 INFO - 1499543287876 Marionette DEBUG Closed connection 358
12:48:07 INFO - 1499543287878 Marionette DEBUG Accepted connection 359 from 127.0.0.1:50116
12:48:07 INFO - 1499543287879 Marionette DEBUG Closed connection 359
12:48:07 INFO - 1499543287879 Marionette DEBUG Accepted connection 360 from 127.0.0.1:50117
12:48:07 INFO - 1499543287880 Marionette TRACE 360 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:07 INFO - 1499543287881 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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}
12:48:07 INFO - 1499543287883 Marionette DEBUG Register listener.js for window 12
12:48:07 INFO - 1499543287886 Marionette TRACE 360 <- [1,1,null,{"sessionId":"ad924ab9-6305-444b-9e64-d5da946e8edc","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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}}]
12:48:07 INFO - 1499543287888 Marionette TRACE 360 -> [0,2,"setTimeouts",{"script":30000}]
12:48:07 INFO - 1499543287889 Marionette TRACE 360 <- [1,2,null,{}]
12:48:07 INFO - 1499543287890 Marionette TRACE 360 -> [0,3,"setTimeouts",{"pageLoad":300000}]
12:48:07 INFO - 1499543287890 Marionette TRACE 360 <- [1,3,null,{}]
12:48:07 INFO - 1499543287891 Marionette TRACE 360 -> [0,4,"setTimeouts",{"implicit":0}]
12:48:07 INFO - 1499543287891 Marionette TRACE 360 <- [1,4,null,{}]
12:48:07 INFO - 1499543287893 Marionette TRACE 360 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-START: test_click.py TestClick.test_container_element')","sandbox":"simpletest","line":316}]
12:48:07 INFO - TEST-START: test_click.py TestClick.test_container_element1499543287896 Marionette TRACE 360 <- [1,5,null,{"value":null}]
12:48:07 INFO - 1499543287897 Marionette TRACE 360 -> [0,6,"deleteSession",{}]
12:48:07 INFO - 1499543287898 Marionette TRACE 360 <- [1,6,null,{}]
12:48:07 INFO - 1499543287900 Marionette DEBUG Closed connection 360
12:48:07 INFO - 1499543287901 Marionette DEBUG Accepted connection 361 from 127.0.0.1:50118
12:48:07 INFO - 1499543287902 Marionette DEBUG Closed connection 361
12:48:07 INFO - 1499543287902 Marionette DEBUG Accepted connection 362 from 127.0.0.1:50119
12:48:07 INFO - 1499543287903 Marionette TRACE 362 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:07 INFO - 1499543287904 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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}
12:48:07 INFO - 1499543287906 Marionette DEBUG Register listener.js for window 12
12:48:07 INFO - 1499543287909 Marionette TRACE 362 <- [1,1,null,{"sessionId":"cd7d1d4a-577c-4434-954d-d604fd44b892","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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}}]
12:48:07 INFO - 1499543287911 Marionette TRACE 362 -> [0,2,"deleteSession",{}]
12:48:07 INFO - 1499543287912 Marionette TRACE 362 <- [1,2,null,{}]
12:48:07 INFO - 1499543287914 Marionette DEBUG Closed connection 362
12:48:07 INFO - 1499543287915 Marionette DEBUG Accepted connection 363 from 127.0.0.1:50120
12:48:07 INFO - 1499543287915 Marionette DEBUG Closed connection 363
12:48:07 INFO - 1499543287916 Marionette DEBUG Accepted connection 364 from 127.0.0.1:50123
12:48:07 INFO - 1499543287917 Marionette TRACE 364 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
12:48:07 INFO - 1499543287918 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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}
12:48:07 INFO - 1499543287921 Marionette DEBUG Register listener.js for window 12
12:48:07 INFO - 1499543287923 Marionette TRACE 364 <- [1,1,null,{"sessionId":"1be00854-4c68-40e9-a403-b766dc4ffebb","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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}}]
12:48:07 INFO - 1499543287926 Marionette TRACE 364 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"}]
12:48:07 INFO - 1499543287927 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49679/test.html"
12:48:07 INFO - 1499543287929 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49679/test.html"
12:48:07 INFO - 1499543287930 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49679/test.html"
12:48:07 INFO - 1499543287953 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
12:48:07 INFO - 1499543287960 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
12:48:07 INFO - 1499543287964 Marionette TRACE 364 <- [1,2,null,{}]
12:48:07 INFO - 1499543287965 Marionette TRACE 364 -> [0,3,"findElement",{"using":"tag name","value":"option"}]
12:48:07 INFO - 1499543287968 Marionette TRACE 364 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"f3ead862-137c-42de-8532-94f4e339f65a","ELEMENT":"f3ead862-137c-42de-8532-94f4e339f65a"}}]
12:48:07 INFO - 1499543287975 Marionette TRACE 364 -> [0,4,"clickElement",{"id":"f3ead862-137c-42de-8532-94f4e339f65a"}]
12:48:08 INFO - 1499543288215 Marionette DEBUG Canceled page load listener because no navigation has been detected
12:48:08 INFO - 1499543288216 Marionette TRACE 364 <- [1,4,null,{}]
12:48:08 INFO - 1499543288218 Marionette TRACE 364 -> [0,5,"getElementProperty",{"id":"f3ead862-137c-42de-8532-94f4e339f65a","name":"selected"}]
12:48:08 INFO - 1499543288223 Marionette TRACE 364 <- [1,5,null,{"value":true}]
12:48:08 INFO - 1499543288226 Marionette TRACE 364 -> [0,6,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-END: test_click.py TestClick.test_container_element')","sandbox":"simpletest","line":328}]
12:48:08 INFO - TEST-END: test_click.py TestClick.test_container_element1499543288229 Marionette TRACE 364 <- [1,6,null,{"value":null}]
12:48:08 INFO - 1499543288235 Marionette TRACE 364 -> [0,7,"deleteSession",{}]
12:48:08 INFO - 1499543288236 Marionette TRACE 364 <- [1,7,null,{}]
12:48:08 INFO - TEST-PASS | test_click.py TestClick.test_container_element | took 361ms
12:48:08 INFO - TEST-START | test_click.py TestClick.test_container_element_outside_view
12:48:08 INFO - 1499543288238 Marionette DEBUG Closed connection 364
12:48:08 INFO - 1499543288239 Marionette DEBUG Accepted connection 365 from 127.0.0.1:50124
12:48:08 INFO - 1499543288240 Marionette DEBUG Closed connection 365
12:48:08 INFO - 1499543288240 Marionette DEBUG Accepted connection 366 from 127.0.0.1:50125
12:48:08 INFO - 1499543288241 Marionette TRACE 366 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:08 INFO - 1499543288242 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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}
12:48:08 INFO - 1499543288244 Marionette DEBUG Register listener.js for window 12
12:48:08 INFO - 1499543288247 Marionette TRACE 366 <- [1,1,null,{"sessionId":"bf3d4584-e74f-424e-9960-c3ae75da9310","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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}}]
12:48:08 INFO - 1499543288249 Marionette TRACE 366 -> [0,2,"setTimeouts",{"script":30000}]
12:48:08 INFO - 1499543288250 Marionette TRACE 366 <- [1,2,null,{}]
12:48:08 INFO - 1499543288250 Marionette TRACE 366 -> [0,3,"setTimeouts",{"pageLoad":300000}]
12:48:08 INFO - 1499543288251 Marionette TRACE 366 <- [1,3,null,{}]
12:48:08 INFO - 1499543288252 Marionette TRACE 366 -> [0,4,"setTimeouts",{"implicit":0}]
12:48:08 INFO - 1499543288252 Marionette TRACE 366 <- [1,4,null,{}]
12:48:08 INFO - 1499543288254 Marionette TRACE 366 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-START: test_click.py TestClick.test_container_element_outside_view')","sandbox":"simpletest","line":316}]
12:48:08 INFO - TEST-START: test_click.py TestClick.test_container_element_outside_view1499543288257 Marionette TRACE 366 <- [1,5,null,{"value":null}]
12:48:08 INFO - 1499543288258 Marionette TRACE 366 -> [0,6,"deleteSession",{}]
12:48:08 INFO - 1499543288259 Marionette TRACE 366 <- [1,6,null,{}]
12:48:08 INFO - 1499543288261 Marionette DEBUG Closed connection 366
12:48:08 INFO - 1499543288261 Marionette DEBUG Accepted connection 367 from 127.0.0.1:50126
12:48:08 INFO - 1499543288262 Marionette DEBUG Closed connection 367
12:48:08 INFO - 1499543288263 Marionette DEBUG Accepted connection 368 from 127.0.0.1:50127
12:48:08 INFO - 1499543288264 Marionette TRACE 368 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:08 INFO - 1499543288264 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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}
12:48:08 INFO - 1499543288267 Marionette DEBUG Register listener.js for window 12
12:48:08 INFO - 1499543288269 Marionette TRACE 368 <- [1,1,null,{"sessionId":"1d5e6795-4f37-4418-acb4-cb4d3f316c58","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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}}]
12:48:08 INFO - 1499543288271 Marionette TRACE 368 -> [0,2,"deleteSession",{}]
12:48:08 INFO - 1499543288272 Marionette TRACE 368 <- [1,2,null,{}]
12:48:08 INFO - 1499543288274 Marionette DEBUG Closed connection 368
12:48:08 INFO - 1499543288275 Marionette DEBUG Accepted connection 369 from 127.0.0.1:50128
12:48:08 INFO - 1499543288276 Marionette DEBUG Closed connection 369
12:48:08 INFO - 1499543288276 Marionette DEBUG Accepted connection 370 from 127.0.0.1:50129
12:48:08 INFO - 1499543288277 Marionette TRACE 370 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
12:48:08 INFO - 1499543288287 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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}
12:48:08 INFO - 1499543288290 Marionette DEBUG Register listener.js for window 12
12:48:08 INFO - 1499543288293 Marionette TRACE 370 <- [1,1,null,{"sessionId":"3d76a93a-28d7-4d39-8b1d-01423342c54b","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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}}]
12:48:08 INFO - 1499543288295 Marionette TRACE 370 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20style%3D%22margin-top%3A%20100vh%22%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"}]
12:48:08 INFO - 1499543288297 Marionette DEBUG Received DOM event "beforeunload" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
12:48:08 INFO - 1499543288299 Marionette DEBUG Received DOM event "pagehide" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
12:48:08 INFO - 1499543288300 Marionette DEBUG Received DOM event "unload" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
12:48:08 INFO - 1499543288316 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20style%3D%22margin-top%3A%20100vh%22%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
12:48:08 INFO - 1499543288323 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20style%3D%22margin-top%3A%20100vh%22%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
12:48:08 INFO - 1499543288326 Marionette TRACE 370 <- [1,2,null,{}]
12:48:08 INFO - 1499543288329 Marionette TRACE 370 -> [0,3,"findElement",{"using":"tag name","value":"option"}]
12:48:08 INFO - 1499543288343 Marionette TRACE 370 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"7afd49bf-be1b-44a9-831b-c9c5294ee74b","ELEMENT":"7afd49bf-be1b-44a9-831b-c9c5294ee74b"}}]
12:48:08 INFO - 1499543288345 Marionette TRACE 370 -> [0,4,"clickElement",{"id":"7afd49bf-be1b-44a9-831b-c9c5294ee74b"}]
12:48:08 INFO - 1499543288585 Marionette DEBUG Canceled page load listener because no navigation has been detected
12:48:08 INFO - 1499543288586 Marionette TRACE 370 <- [1,4,null,{}]
12:48:08 INFO - 1499543288587 Marionette TRACE 370 -> [0,5,"getElementProperty",{"id":"7afd49bf-be1b-44a9-831b-c9c5294ee74b","name":"selected"}]
12:48:08 INFO - 1499543288592 Marionette TRACE 370 <- [1,5,null,{"value":true}]
12:48:08 INFO - 1499543288594 Marionette TRACE 370 -> [0,6,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-END: test_click.py TestClick.test_container_element_outside_view')","sandbox":"simpletest","line":328}]
12:48:08 INFO - TEST-END: test_click.py TestClick.test_container_element_outside_view1499543288597 Marionette TRACE 370 <- [1,6,null,{"value":null}]
12:48:08 INFO - 1499543288597 Marionette TRACE 370 -> [0,7,"deleteSession",{}]
12:48:08 INFO - 1499543288599 Marionette TRACE 370 <- [1,7,null,{}]
12:48:08 INFO - TEST-PASS | test_click.py TestClick.test_container_element_outside_view | took 362ms
12:48:08 INFO - TEST-START | test_click.py TestClick.test_css_transforms
12:48:08 INFO - 1499543288600 Marionette DEBUG Closed connection 370
12:48:08 INFO - 1499543288602 Marionette DEBUG Accepted connection 371 from 127.0.0.1:50130
12:48:08 INFO - 1499543288603 Marionette DEBUG Closed connection 371
12:48:08 INFO - 1499543288603 Marionette DEBUG Accepted connection 372 from 127.0.0.1:50131
12:48:08 INFO - 1499543288604 Marionette TRACE 372 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:08 INFO - 1499543288605 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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}
12:48:08 INFO - 1499543288607 Marionette DEBUG Register listener.js for window 12
12:48:08 INFO - 1499543288610 Marionette TRACE 372 <- [1,1,null,{"sessionId":"5812d311-15f9-49eb-9a85-c2c6b0057534","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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}}]
12:48:08 INFO - 1499543288612 Marionette TRACE 372 -> [0,2,"setTimeouts",{"script":30000}]
12:48:08 INFO - 1499543288613 Marionette TRACE 372 <- [1,2,null,{}]
12:48:08 INFO - 1499543288614 Marionette TRACE 372 -> [0,3,"setTimeouts",{"pageLoad":300000}]
12:48:08 INFO - 1499543288614 Marionette TRACE 372 <- [1,3,null,{}]
12:48:08 INFO - 1499543288615 Marionette TRACE 372 -> [0,4,"setTimeouts",{"implicit":0}]
12:48:08 INFO - 1499543288615 Marionette TRACE 372 <- [1,4,null,{}]
12:48:08 INFO - 1499543288617 Marionette TRACE 372 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-START: test_click.py TestClick.test_css_transforms')","sandbox":"simpletest","line":316}]
12:48:08 INFO - TEST-START: test_click.py TestClick.test_css_transforms1499543288620 Marionette TRACE 372 <- [1,5,null,{"value":null}]
12:48:08 INFO - 1499543288621 Marionette TRACE 372 -> [0,6,"deleteSession",{}]
12:48:08 INFO - 1499543288622 Marionette TRACE 372 <- [1,6,null,{}]
12:48:08 INFO - 1499543288624 Marionette DEBUG Closed connection 372
12:48:08 INFO - 1499543288624 Marionette DEBUG Accepted connection 373 from 127.0.0.1:50132
12:48:08 INFO - 1499543288625 Marionette DEBUG Closed connection 373
12:48:08 INFO - 1499543288626 Marionette DEBUG Accepted connection 374 from 127.0.0.1:50133
12:48:08 INFO - 1499543288627 Marionette TRACE 374 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:08 INFO - 1499543288627 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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}
12:48:08 INFO - 1499543288630 Marionette DEBUG Register listener.js for window 12
12:48:08 INFO - 1499543288632 Marionette TRACE 374 <- [1,1,null,{"sessionId":"532f7ab2-0cc8-479c-a367-1b59c8f2bf60","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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}}]
12:48:08 INFO - 1499543288634 Marionette TRACE 374 -> [0,2,"deleteSession",{}]
12:48:08 INFO - 1499543288635 Marionette TRACE 374 <- [1,2,null,{}]
12:48:08 INFO - 1499543288637 Marionette DEBUG Closed connection 374
12:48:08 INFO - 1499543288638 Marionette DEBUG Accepted connection 375 from 127.0.0.1:50134
12:48:08 INFO - 1499543288639 Marionette DEBUG Closed connection 375
12:48:08 INFO - 1499543288639 Marionette DEBUG Accepted connection 376 from 127.0.0.1:50135
12:48:08 INFO - 1499543288640 Marionette TRACE 376 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
12:48:08 INFO - 1499543288641 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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}
12:48:08 INFO - 1499543288643 Marionette DEBUG Register listener.js for window 12
12:48:08 INFO - 1499543288646 Marionette TRACE 376 <- [1,1,null,{"sessionId":"d7baea24-6053-4f07-a240-8b89159ecee5","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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}}]
12:48:08 INFO - 1499543288648 Marionette TRACE 376 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cstyle%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20div%20%7B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20display%3A%20block%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20background-color%3A%20blue%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20width%3A%20200px%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20height%3A%20200px%3B%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%20transform%3A%20translateX%28-105px%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/style%3E%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cdiv%3E%3C/div%3E"}]
12:48:08 INFO - 1499543288649 Marionette DEBUG Received DOM event "beforeunload" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20style%3D%22margin-top%3A%20100vh%22%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
12:48:08 INFO - 1499543288652 Marionette DEBUG Received DOM event "pagehide" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20style%3D%22margin-top%3A%20100vh%22%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
12:48:08 INFO - 1499543288652 Marionette DEBUG Received DOM event "unload" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20style%3D%22margin-top%3A%20100vh%22%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
12:48:08 INFO - 1499543288674 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cstyle%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20div%20%7B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20display%3A%20block%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20background-color%3A%20blue%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20width%3A%20200px%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20height%3A%20200px%3B%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%20transform%3A%20translateX%28-105px%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/style%3E%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cdiv%3E%3C/div%3E"
12:48:08 INFO - 1499543288678 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cstyle%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20div%20%7B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20display%3A%20block%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20background-color%3A%20blue%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20width%3A%20200px%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20height%3A%20200px%3B%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%20transform%3A%20translateX%28-105px%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/style%3E%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cdiv%3E%3C/div%3E"
12:48:08 INFO - 1499543288681 Marionette TRACE 376 <- [1,2,null,{}]
12:48:08 INFO - 1499543288682 Marionette TRACE 376 -> [0,3,"findElement",{"using":"tag name","value":"div"}]
12:48:08 INFO - 1499543288692 Marionette TRACE 376 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"bf4420f2-6933-4283-8ba2-23d55ad8114c","ELEMENT":"bf4420f2-6933-4283-8ba2-23d55ad8114c"}}]
12:48:08 INFO - 1499543288695 Marionette TRACE 376 -> [0,4,"clickElement",{"id":"bf4420f2-6933-4283-8ba2-23d55ad8114c"}]
12:48:08 INFO - 1499543288935 Marionette DEBUG Canceled page load listener because no navigation has been detected
12:48:08 INFO - 1499543288936 Marionette TRACE 376 <- [1,4,null,{}]
12:48:08 INFO - 1499543288938 Marionette TRACE 376 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-END: test_click.py TestClick.test_css_transforms')","sandbox":"simpletest","line":328}]
12:48:08 INFO - TEST-END: test_click.py TestClick.test_css_transforms1499543288940 Marionette TRACE 376 <- [1,5,null,{"value":null}]
12:48:08 INFO - 1499543288941 Marionette TRACE 376 -> [0,6,"deleteSession",{}]
12:48:08 INFO - 1499543288943 Marionette TRACE 376 <- [1,6,null,{}]
12:48:08 INFO - TEST-PASS | test_click.py TestClick.test_css_transforms | took 343ms
12:48:08 INFO - TEST-START | test_click.py TestClick.test_inclusive_descendant
12:48:08 INFO - 1499543288944 Marionette DEBUG Closed connection 376
12:48:08 INFO - 1499543288946 Marionette DEBUG Accepted connection 377 from 127.0.0.1:50136
12:48:08 INFO - 1499543288947 Marionette DEBUG Closed connection 377
12:48:08 INFO - 1499543288947 Marionette DEBUG Accepted connection 378 from 127.0.0.1:50137
12:48:08 INFO - 1499543288948 Marionette TRACE 378 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:08 INFO - 1499543288949 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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}
12:48:08 INFO - 1499543288951 Marionette DEBUG Register listener.js for window 12
12:48:08 INFO - 1499543288954 Marionette TRACE 378 <- [1,1,null,{"sessionId":"7ffed8dd-f1bc-4563-8daa-2c0f904da924","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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}}]
12:48:08 INFO - 1499543288956 Marionette TRACE 378 -> [0,2,"setTimeouts",{"script":30000}]
12:48:08 INFO - 1499543288957 Marionette TRACE 378 <- [1,2,null,{}]
12:48:08 INFO - 1499543288958 Marionette TRACE 378 -> [0,3,"setTimeouts",{"pageLoad":300000}]
12:48:08 INFO - 1499543288959 Marionette TRACE 378 <- [1,3,null,{}]
12:48:08 INFO - 1499543288959 Marionette TRACE 378 -> [0,4,"setTimeouts",{"implicit":0}]
12:48:08 INFO - 1499543288960 Marionette TRACE 378 <- [1,4,null,{}]
12:48:08 INFO - 1499543288962 Marionette TRACE 378 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-START: test_click.py TestClick.test_inclusive_descendant')","sandbox":"simpletest","line":316}]
12:48:08 INFO - TEST-START: test_click.py TestClick.test_inclusive_descendant1499543288965 Marionette TRACE 378 <- [1,5,null,{"value":null}]
12:48:08 INFO - 1499543288965 Marionette TRACE 378 -> [0,6,"deleteSession",{}]
12:48:08 INFO - 1499543288967 Marionette TRACE 378 <- [1,6,null,{}]
12:48:08 INFO - 1499543288969 Marionette DEBUG Closed connection 378
12:48:08 INFO - 1499543288969 Marionette DEBUG Accepted connection 379 from 127.0.0.1:50138
12:48:08 INFO - 1499543288970 Marionette DEBUG Closed connection 379
12:48:08 INFO - 1499543288971 Marionette DEBUG Accepted connection 380 from 127.0.0.1:50139
12:48:08 INFO - 1499543288972 Marionette TRACE 380 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:08 INFO - 1499543288972 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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}
12:48:09 INFO - 1499543288975 Marionette DEBUG Register listener.js for window 12
12:48:09 INFO - 1499543288977 Marionette TRACE 380 <- [1,1,null,{"sessionId":"09831530-a82c-4aa5-82f9-23ef79fd7a53","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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}}]
12:48:09 INFO - 1499543288979 Marionette TRACE 380 -> [0,2,"deleteSession",{}]
12:48:09 INFO - 1499543288980 Marionette TRACE 380 <- [1,2,null,{}]
12:48:09 INFO - 1499543288982 Marionette DEBUG Closed connection 380
12:48:09 INFO - 1499543288983 Marionette DEBUG Accepted connection 381 from 127.0.0.1:50140
12:48:09 INFO - 1499543288984 Marionette DEBUG Closed connection 381
12:48:09 INFO - 1499543288985 Marionette DEBUG Accepted connection 382 from 127.0.0.1:50141
12:48:09 INFO - 1499543288986 Marionette TRACE 382 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
12:48:09 INFO - 1499543288986 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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}
12:48:09 INFO - 1499543288988 Marionette DEBUG Register listener.js for window 12
12:48:09 INFO - 1499543289001 Marionette TRACE 382 <- [1,1,null,{"sessionId":"80fee413-5260-4446-a749-b78b86a81aac","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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}}]
12:48:09 INFO - 1499543289003 Marionette TRACE 382 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20multiple%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efirst%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Esecond%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Ethird%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"}]
12:48:09 INFO - 1499543289007 Marionette DEBUG Received DOM event "beforeunload" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cstyle%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20div%20%7B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20display%3A%20block%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20background-color%3A%20blue%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20width%3A%20200px%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20height%3A%20200px%3B%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%20transform%3A%20translateX%28-105px%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/style%3E%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cdiv%3E%3C/div%3E"
12:48:09 INFO - 1499543289009 Marionette DEBUG Received DOM event "pagehide" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cstyle%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20div%20%7B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20display%3A%20block%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20background-color%3A%20blue%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20width%3A%20200px%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20height%3A%20200px%3B%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%20transform%3A%20translateX%28-105px%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/style%3E%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cdiv%3E%3C/div%3E"
12:48:09 INFO - 1499543289009 Marionette DEBUG Received DOM event "unload" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cstyle%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20div%20%7B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20display%3A%20block%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20background-color%3A%20blue%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20width%3A%20200px%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20height%3A%20200px%3B%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%20transform%3A%20translateX%28-105px%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/style%3E%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cdiv%3E%3C/div%3E"
12:48:09 INFO - 1499543289027 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20multiple%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efirst%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Esecond%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Ethird%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
12:48:09 INFO - 1499543289029 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20multiple%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efirst%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Esecond%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Ethird%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
12:48:09 INFO - 1499543289032 Marionette TRACE 382 <- [1,2,null,{}]
12:48:09 INFO - 1499543289033 Marionette TRACE 382 -> [0,3,"findElement",{"using":"tag name","value":"select"}]
12:48:09 INFO - 1499543289043 Marionette TRACE 382 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"51d382d6-46bd-4cb7-a74c-c7de5fbf15bb","ELEMENT":"51d382d6-46bd-4cb7-a74c-c7de5fbf15bb"}}]
12:48:09 INFO - 1499543289045 Marionette TRACE 382 -> [0,4,"clickElement",{"id":"51d382d6-46bd-4cb7-a74c-c7de5fbf15bb"}]
12:48:09 INFO - 1499543289285 Marionette DEBUG Canceled page load listener because no navigation has been detected
12:48:09 INFO - 1499543289286 Marionette TRACE 382 <- [1,4,null,{}]
12:48:09 INFO - 1499543289288 Marionette TRACE 382 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-END: test_click.py TestClick.test_inclusive_descendant')","sandbox":"simpletest","line":328}]
12:48:09 INFO - TEST-END: test_click.py TestClick.test_inclusive_descendant1499543289291 Marionette TRACE 382 <- [1,5,null,{"value":null}]
12:48:09 INFO - 1499543289292 Marionette TRACE 382 -> [0,6,"deleteSession",{}]
12:48:09 INFO - TEST-PASS | test_click.py TestClick.test_inclusive_descendant | took 350ms
12:48:09 INFO - TEST-START | test_click.py TestClick.test_input_file
12:48:09 INFO - 1499543289293 Marionette TRACE 382 <- [1,6,null,{}]
12:48:09 INFO - 1499543289295 Marionette DEBUG Closed connection 382
12:48:09 INFO - 1499543289296 Marionette DEBUG Accepted connection 383 from 127.0.0.1:50142
12:48:09 INFO - 1499543289297 Marionette DEBUG Closed connection 383
12:48:09 INFO - 1499543289298 Marionette DEBUG Accepted connection 384 from 127.0.0.1:50143
12:48:09 INFO - 1499543289299 Marionette TRACE 384 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:09 INFO - 1499543289300 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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}
12:48:09 INFO - 1499543289302 Marionette DEBUG Register listener.js for window 12
12:48:09 INFO - 1499543289305 Marionette TRACE 384 <- [1,1,null,{"sessionId":"c9ec00fd-2687-4906-ba36-a1995c9c46ff","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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}}]
12:48:09 INFO - 1499543289307 Marionette TRACE 384 -> [0,2,"setTimeouts",{"script":30000}]
12:48:09 INFO - 1499543289308 Marionette TRACE 384 <- [1,2,null,{}]
12:48:09 INFO - 1499543289308 Marionette TRACE 384 -> [0,3,"setTimeouts",{"pageLoad":300000}]
12:48:09 INFO - 1499543289309 Marionette TRACE 384 <- [1,3,null,{}]
12:48:09 INFO - 1499543289310 Marionette TRACE 384 -> [0,4,"setTimeouts",{"implicit":0}]
12:48:09 INFO - 1499543289310 Marionette TRACE 384 <- [1,4,null,{}]
12:48:09 INFO - 1499543289312 Marionette TRACE 384 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-START: test_click.py TestClick.test_input_file')","sandbox":"simpletest","line":316}]
12:48:09 INFO - TEST-START: test_click.py TestClick.test_input_file1499543289314 Marionette TRACE 384 <- [1,5,null,{"value":null}]
12:48:09 INFO - 1499543289315 Marionette TRACE 384 -> [0,6,"deleteSession",{}]
12:48:09 INFO - 1499543289316 Marionette TRACE 384 <- [1,6,null,{}]
12:48:09 INFO - 1499543289318 Marionette DEBUG Closed connection 384
12:48:09 INFO - 1499543289319 Marionette DEBUG Accepted connection 385 from 127.0.0.1:50144
12:48:09 INFO - 1499543289320 Marionette DEBUG Closed connection 385
12:48:09 INFO - 1499543289320 Marionette DEBUG Accepted connection 386 from 127.0.0.1:50145
12:48:09 INFO - 1499543289321 Marionette TRACE 386 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:09 INFO - 1499543289322 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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}
12:48:09 INFO - 1499543289324 Marionette DEBUG Register listener.js for window 12
12:48:09 INFO - 1499543289327 Marionette TRACE 386 <- [1,1,null,{"sessionId":"607c498c-ecca-4e61-ac30-79f886e1983e","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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}}]
12:48:09 INFO - 1499543289328 Marionette TRACE 386 -> [0,2,"deleteSession",{}]
12:48:09 INFO - 1499543289329 Marionette TRACE 386 <- [1,2,null,{}]
12:48:09 INFO - 1499543289331 Marionette DEBUG Closed connection 386
12:48:09 INFO - 1499543289332 Marionette DEBUG Accepted connection 387 from 127.0.0.1:50146
12:48:09 INFO - 1499543289333 Marionette DEBUG Closed connection 387
12:48:09 INFO - 1499543289333 Marionette DEBUG Accepted connection 388 from 127.0.0.1:50147
12:48:09 INFO - 1499543289334 Marionette TRACE 388 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
12:48:09 INFO - 1499543289335 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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}
12:48:09 INFO - 1499543289337 Marionette DEBUG Register listener.js for window 12
12:48:09 INFO - 1499543289340 Marionette TRACE 388 <- [1,1,null,{"sessionId":"1693ee37-3e78-4e98-a0be-11d5c0d3a2e3","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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}}]
12:48:09 INFO - 1499543289342 Marionette TRACE 388 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"}]
12:48:09 INFO - 1499543289344 Marionette DEBUG Received DOM event "beforeunload" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20multiple%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efirst%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Esecond%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Ethird%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
12:48:09 INFO - 1499543289346 Marionette DEBUG Received DOM event "pagehide" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20multiple%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efirst%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Esecond%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Ethird%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
12:48:09 INFO - 1499543289347 Marionette DEBUG Received DOM event "unload" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20multiple%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efirst%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Esecond%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Ethird%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
12:48:09 INFO - 1499543289365 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
12:48:09 INFO - 1499543289369 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
12:48:09 INFO - 1499543289379 Marionette TRACE 388 <- [1,2,null,{}]
12:48:09 INFO - 1499543289385 Marionette TRACE 388 -> [0,3,"findElement",{"using":"tag name","value":"input"}]
12:48:09 INFO - 1499543289388 Marionette TRACE 388 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"9630fcfc-5dee-49bc-a977-9103f4822c7e","ELEMENT":"9630fcfc-5dee-49bc-a977-9103f4822c7e"}}]
12:48:09 INFO - 1499543289390 Marionette TRACE 388 -> [0,4,"clickElement",{"id":"9630fcfc-5dee-49bc-a977-9103f4822c7e"}]
12:48:09 INFO - 1499543289416 Marionette TRACE 388 <- [1,4,{"error":"invalid argument","message":"Cannot click
elements","stacktrace":"WebDriverError@chrome://marionette/content/error.js:226:5\nInvalidArgumentError@chrome://marionette/content/error.js:329:5\nwebdriverClickElement@chrome://marionette/content/interaction.js:165:11\nTaskImpl_run@resource://gre/modules/Task.jsm:331:42\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nTaskImpl_handleResultValue@resource://gre/modules/Task.jsm:401:16\nTaskImpl_run@resource://gre/modules/Task.jsm:339:15\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nTaskImpl_handleResultValue@resource://gre/modules/Task.jsm:401:16\nTaskImpl_run@resource://gre/modules/Task.jsm:339:15\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nnavigate@chrome://marionette/content/listener.js:392:12\nclickElement@chrome://marionette/content/listener.js:1312:5\n"},null]
12:48:09 INFO - 1499543289418 Marionette TRACE 388 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-END: test_click.py TestClick.test_input_file')","sandbox":"simpletest","line":328}]
12:48:09 INFO - TEST-END: test_click.py TestClick.test_input_file1499543289421 Marionette TRACE 388 <- [1,5,null,{"value":null}]
12:48:09 INFO - 1499543289422 Marionette TRACE 388 -> [0,6,"deleteSession",{}]
12:48:09 INFO - 1499543289423 Marionette TRACE 388 <- [1,6,null,{}]
12:48:09 INFO - TEST-PASS | test_click.py TestClick.test_input_file | took 129ms
12:48:09 INFO - TEST-START | test_click.py TestClick.test_obscured_element
12:48:09 INFO - 1499543289425 Marionette DEBUG Closed connection 388
12:48:09 INFO - 1499543289426 Marionette DEBUG Accepted connection 389 from 127.0.0.1:50148
12:48:09 INFO - 1499543289427 Marionette DEBUG Closed connection 389
12:48:09 INFO - 1499543289428 Marionette DEBUG Accepted connection 390 from 127.0.0.1:50149
12:48:09 INFO - 1499543289428 Marionette TRACE 390 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:09 INFO - 1499543289429 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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}
12:48:09 INFO - 1499543289431 Marionette DEBUG Register listener.js for window 12
12:48:09 INFO - 1499543289434 Marionette TRACE 390 <- [1,1,null,{"sessionId":"7ff71cdd-abd3-4f30-b063-38a9b2c0ce32","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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}}]
12:48:09 INFO - 1499543289436 Marionette TRACE 390 -> [0,2,"setTimeouts",{"script":30000}]
12:48:09 INFO - 1499543289437 Marionette TRACE 390 <- [1,2,null,{}]
12:48:09 INFO - 1499543289438 Marionette TRACE 390 -> [0,3,"setTimeouts",{"pageLoad":300000}]
12:48:09 INFO - 1499543289438 Marionette TRACE 390 <- [1,3,null,{}]
12:48:09 INFO - 1499543289439 Marionette TRACE 390 -> [0,4,"setTimeouts",{"implicit":0}]
12:48:09 INFO - 1499543289439 Marionette TRACE 390 <- [1,4,null,{}]
12:48:09 INFO - 1499543289441 Marionette TRACE 390 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-START: test_click.py TestClick.test_obscured_element')","sandbox":"simpletest","line":316}]
12:48:09 INFO - TEST-START: test_click.py TestClick.test_obscured_element1499543289444 Marionette TRACE 390 <- [1,5,null,{"value":null}]
12:48:09 INFO - 1499543289445 Marionette TRACE 390 -> [0,6,"deleteSession",{}]
12:48:09 INFO - 1499543289446 Marionette TRACE 390 <- [1,6,null,{}]
12:48:09 INFO - 1499543289448 Marionette DEBUG Closed connection 390
12:48:09 INFO - 1499543289448 Marionette DEBUG Accepted connection 391 from 127.0.0.1:50150
12:48:09 INFO - 1499543289449 Marionette DEBUG Closed connection 391
12:48:09 INFO - 1499543289450 Marionette DEBUG Accepted connection 392 from 127.0.0.1:50151
12:48:09 INFO - 1499543289451 Marionette TRACE 392 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:09 INFO - 1499543289451 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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}
12:48:09 INFO - 1499543289454 Marionette DEBUG Register listener.js for window 12
12:48:09 INFO - 1499543289456 Marionette TRACE 392 <- [1,1,null,{"sessionId":"01128da1-7be3-40f1-b5c4-5f86a00ee7d2","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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}}]
12:48:09 INFO - 1499543289460 Marionette TRACE 392 -> [0,2,"deleteSession",{}]
12:48:09 INFO - 1499543289461 Marionette TRACE 392 <- [1,2,null,{}]
12:48:09 INFO - 1499543289463 Marionette DEBUG Closed connection 392
12:48:09 INFO - 1499543289464 Marionette DEBUG Accepted connection 393 from 127.0.0.1:50152
12:48:09 INFO - 1499543289465 Marionette DEBUG Closed connection 393
12:48:09 INFO - 1499543289465 Marionette DEBUG Accepted connection 394 from 127.0.0.1:50153
12:48:09 INFO - 1499543289466 Marionette TRACE 394 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
12:48:09 INFO - 1499543289467 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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}
12:48:09 INFO - 1499543289469 Marionette DEBUG Register listener.js for window 12
12:48:09 INFO - 1499543289472 Marionette TRACE 394 <- [1,1,null,{"sessionId":"4550aa61-5746-4673-8926-4fae58eb6746","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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}}]
12:48:09 INFO - 1499543289474 Marionette TRACE 394 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%0A%3Cstyle%3E%0A%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0Abody%20%7B%20height%3A%20100vh%20%7D%0A%23overlay%20%7B%0A%20%20background-color%3A%20pink%3B%0A%20%20position%3A%20absolute%3B%0A%20%20width%3A%20100%25%3B%0A%20%20height%3A%20100%25%3B%0A%7D%0A%3C/style%3E%0A%0A%3Cdiv%20id%3Doverlay%3E%3C/div%3E%0A%3Ca%20id%3Dobscured%20href%3D%23%3Elink%3C/a%3E%0A%0A%3Cscript%3E%0Awindow.clicked%20%3D%20false%3B%0A%0Alet%20link%20%3D%20document.querySelector%28%22%23obscured%22%29%3B%0Alink.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%3C/script%3E%0A"}]
12:48:09 INFO - 1499543289476 Marionette DEBUG Received DOM event "beforeunload" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
12:48:09 INFO - 1499543289478 Marionette DEBUG Received DOM event "pagehide" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
12:48:09 INFO - 1499543289478 Marionette DEBUG Received DOM event "unload" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
12:48:09 INFO - 1499543289499 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%0A%3Cstyle%3E%0A%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0Abody%20%7B%20height%3A%20100vh%20%7D%0A%23overlay%20%7B%0A%20%20background-color%3A%20pink%3B%0A%20%20position%3A%20absolute%3B%0A%20%20width%3A%20100%25%3B%0A%20%20height%3A%20100%25%3B%0A%7D%0A%3C/style%3E%0A%0A%3Cdiv%20id%3Doverlay%3E%3C/div%3E%0A%3Ca%20id%3Dobscured%20href%3D%23%3Elink%3C/a%3E%0A%0A%3Cscript%3E%0Awindow.clicked%20%3D%20false%3B%0A%0Alet%20link%20%3D%20document.querySelector%28%22%23obscured%22%29%3B%0Alink.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%3C/script%3E%0A"
12:48:09 INFO - 1499543289501 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%0A%3Cstyle%3E%0A%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0Abody%20%7B%20height%3A%20100vh%20%7D%0A%23overlay%20%7B%0A%20%20background-color%3A%20pink%3B%0A%20%20position%3A%20absolute%3B%0A%20%20width%3A%20100%25%3B%0A%20%20height%3A%20100%25%3B%0A%7D%0A%3C/style%3E%0A%0A%3Cdiv%20id%3Doverlay%3E%3C/div%3E%0A%3Ca%20id%3Dobscured%20href%3D%23%3Elink%3C/a%3E%0A%0A%3Cscript%3E%0Awindow.clicked%20%3D%20false%3B%0A%0Alet%20link%20%3D%20document.querySelector%28%22%23obscured%22%29%3B%0Alink.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%3C/script%3E%0A"
12:48:09 INFO - 1499543289503 Marionette TRACE 394 <- [1,2,null,{}]
12:48:09 INFO - 1499543289511 Marionette TRACE 394 -> [0,3,"findElement",{"using":"id","value":"overlay"}]
12:48:09 INFO - 1499543289524 Marionette TRACE 394 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"66956f6f-0fe0-4605-8d1d-cfdcf8bb54b6","ELEMENT":"66956f6f-0fe0-4605-8d1d-cfdcf8bb54b6"}}]
12:48:09 INFO - 1499543289528 Marionette TRACE 394 -> [0,4,"findElement",{"using":"id","value":"obscured"}]
12:48:09 INFO - 1499543289530 Marionette TRACE 394 <- [1,4,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"e72a73e0-4967-41e6-a933-23343390e81f","ELEMENT":"e72a73e0-4967-41e6-a933-23343390e81f"}}]
12:48:09 INFO - 1499543289531 Marionette TRACE 394 -> [0,5,"clickElement",{"id":"66956f6f-0fe0-4605-8d1d-cfdcf8bb54b6"}]
12:48:09 INFO - 1499543289774 Marionette DEBUG Canceled page load listener because no navigation has been detected
12:48:09 INFO - 1499543289775 Marionette TRACE 394 <- [1,5,null,{}]
12:48:09 INFO - 1499543289776 Marionette TRACE 394 -> [0,6,"clickElement",{"id":"e72a73e0-4967-41e6-a933-23343390e81f"}]
12:48:09 INFO - 1499543289791 Marionette TRACE 394 <- [1,6,{"error":"element click intercepted","message":"Element
is not clickable at point (10.5,10) because another element obscures it","stacktrace":"WebDriverError@chrome://marionette/content/error.js:226:5\nElementClickInterceptedError@chrome://marionette/content/error.js:308:5\nwebdriverClickElement@chrome://marionette/content/interaction.js:192:11\nTaskImpl_run@resource://gre/modules/Task.jsm:331:42\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nTaskImpl_handleResultValue@resource://gre/modules/Task.jsm:401:16\nTaskImpl_run@resource://gre/modules/Task.jsm:339:15\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nTaskImpl_handleResultValue@resource://gre/modules/Task.jsm:401:16\nTaskImpl_run@resource://gre/modules/Task.jsm:339:15\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nnavigate@chrome://marionette/content/listener.js:392:12\nclickElement@chrome://marionette/content/listener.js:1312:5\n"},null]
12:48:09 INFO - 1499543289794 Marionette TRACE 394 -> [0,7,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"test_click.py","script":"return window.clicked","sandbox":null,"line":257}]
12:48:09 INFO - 1499543289796 Marionette TRACE 394 <- [1,7,null,{"value":false}]
12:48:09 INFO - 1499543289801 Marionette TRACE 394 -> [0,8,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-END: test_click.py TestClick.test_obscured_element')","sandbox":"simpletest","line":328}]
12:48:09 INFO - TEST-END: test_click.py TestClick.test_obscured_element1499543289804 Marionette TRACE 394 <- [1,8,null,{"value":null}]
12:48:09 INFO - 1499543289805 Marionette TRACE 394 -> [0,9,"deleteSession",{}]
12:48:09 INFO - TEST-PASS | test_click.py TestClick.test_obscured_element | took 383ms
12:48:09 INFO - 1499543289806 Marionette TRACE 394 <- [1,9,null,{}]
12:48:09 INFO - TEST-START | test_click.py TestClick.test_pointer_events_none
12:48:09 INFO - 1499543289809 Marionette DEBUG Closed connection 394
12:48:09 INFO - 1499543289810 Marionette DEBUG Accepted connection 395 from 127.0.0.1:50154
12:48:09 INFO - 1499543289811 Marionette DEBUG Closed connection 395
12:48:09 INFO - 1499543289812 Marionette DEBUG Accepted connection 396 from 127.0.0.1:50155
12:48:09 INFO - 1499543289813 Marionette TRACE 396 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:09 INFO - 1499543289813 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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}
12:48:09 INFO - 1499543289816 Marionette DEBUG Register listener.js for window 12
12:48:09 INFO - 1499543289818 Marionette TRACE 396 <- [1,1,null,{"sessionId":"2b64dcef-8d63-4bd6-a92e-19f71244c02d","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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}}]
12:48:09 INFO - 1499543289820 Marionette TRACE 396 -> [0,2,"setTimeouts",{"script":30000}]
12:48:09 INFO - 1499543289821 Marionette TRACE 396 <- [1,2,null,{}]
12:48:09 INFO - 1499543289822 Marionette TRACE 396 -> [0,3,"setTimeouts",{"pageLoad":300000}]
12:48:09 INFO - 1499543289823 Marionette TRACE 396 <- [1,3,null,{}]
12:48:09 INFO - 1499543289823 Marionette TRACE 396 -> [0,4,"setTimeouts",{"implicit":0}]
12:48:09 INFO - 1499543289824 Marionette TRACE 396 <- [1,4,null,{}]
12:48:09 INFO - 1499543289826 Marionette TRACE 396 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-START: test_click.py TestClick.test_pointer_events_none')","sandbox":"simpletest","line":316}]
12:48:09 INFO - TEST-START: test_click.py TestClick.test_pointer_events_none1499543289828 Marionette TRACE 396 <- [1,5,null,{"value":null}]
12:48:09 INFO - 1499543289829 Marionette TRACE 396 -> [0,6,"deleteSession",{}]
12:48:09 INFO - 1499543289830 Marionette TRACE 396 <- [1,6,null,{}]
12:48:09 INFO - 1499543289832 Marionette DEBUG Closed connection 396
12:48:09 INFO - 1499543289833 Marionette DEBUG Accepted connection 397 from 127.0.0.1:50156
12:48:09 INFO - 1499543289834 Marionette DEBUG Closed connection 397
12:48:09 INFO - 1499543289834 Marionette DEBUG Accepted connection 398 from 127.0.0.1:50157
12:48:09 INFO - 1499543289835 Marionette TRACE 398 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
12:48:09 INFO - 1499543289836 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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}
12:48:09 INFO - 1499543289838 Marionette DEBUG Register listener.js for window 12
12:48:09 INFO - 1499543289842 Marionette TRACE 398 <- [1,1,null,{"sessionId":"ee2406a9-3088-4166-b770-2f5efe08ce11","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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}}]
12:48:09 INFO - 1499543289843 Marionette TRACE 398 -> [0,2,"deleteSession",{}]
12:48:09 INFO - 1499543289845 Marionette TRACE 398 <- [1,2,null,{}]
12:48:09 INFO - 1499543289846 Marionette DEBUG Closed connection 398
12:48:09 INFO - 1499543289847 Marionette DEBUG Accepted connection 399 from 127.0.0.1:50158
12:48:09 INFO - 1499543289848 Marionette DEBUG Closed connection 399
12:48:09 INFO - 1499543289848 Marionette DEBUG Accepted connection 400 from 127.0.0.1:50159
12:48:09 INFO - 1499543289849 Marionette TRACE 400 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
12:48:09 INFO - 1499543289850 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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}
12:48:09 INFO - 1499543289852 Marionette DEBUG Register listener.js for window 12
12:48:09 INFO - 1499543289856 Marionette TRACE 400 <- [1,1,null,{"sessionId":"698efb0d-0ad9-4d22-a528-201d0097b598","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":1428,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpl3g3it.mozrunner","moz:accessibilityChecks":false}}]
12:48:09 INFO - 1499543289858 Marionette TRACE 400 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cbutton%20style%3D%22pointer-events%3A%20none%22%3Eclick%20me%3C/button%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cscript%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20window.clicked%20%3D%20false%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20let%20button%20%3D%20document.querySelector%28%22button%22%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20button.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/script%3E%0A%20%20%20%20%20%20%20%20"}]
12:48:09 INFO - 1499543289860 Marionette DEBUG Received DOM event "beforeunload" for "data:text/html;charset=utf-8,%0A%3Cstyle%3E%0A%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0Abody%20%7B%20height%3A%20100vh%20%7D%0A%23overlay%20%7B%0A%20%20background-color%3A%20pink%3B%0A%20%20position%3A%20absolute%3B%0A%20%20width%3A%20100%25%3B%0A%20%20height%3A%20100%25%3B%0A%7D%0A%3C/style%3E%0A%0A%3Cdiv%20id%3Doverlay%3E%3C/div%3E%0A%3Ca%20id%3Dobscured%20href%3D%23%3Elink%3C/a%3E%0A%0A%3Cscript%3E%0Awindow.clicked%20%3D%20false%3B%0A%0Alet%20link%20%3D%20document.querySelector%28%22%23obscured%22%29%3B%0Alink.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%3C/script%3E%0A"
12:48:09 INFO - 1499543289862 Marionette DEBUG Received DOM event "pagehide" for "data:text/html;charset=utf-8,%0A%3Cstyle%3E%0A%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0Abody%20%7B%20height%3A%20100vh%20%7D%0A%23overlay%20%7B%0A%20%20background-color%3A%20pink%3B%0A%20%20position%3A%20absolute%3B%0A%20%20width%3A%20100%25%3B%0A%20%20height%3A%20100%25%3B%0A%7D%0A%3C/style%3E%0A%0A%3Cdiv%20id%3Doverlay%3E%3C/div%3E%0A%3Ca%20id%3Dobscured%20href%3D%23%3Elink%3C/a%3E%0A%0A%3Cscript%3E%0Awindow.clicked%20%3D%20false%3B%0A%0Alet%20link%20%3D%20document.querySelector%28%22%23obscured%22%29%3B%0Alink.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%3C/script%3E%0A"
12:48:09 INFO - 1499543289862 Marionette DEBUG Received DOM event "unload" for "data:text/html;charset=utf-8,%0A%3Cstyle%3E%0A%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0Abody%20%7B%20height%3A%20100vh%20%7D%0A%23overlay%20%7B%0A%20%20background-color%3A%20pink%3B%0A%20%20position%3A%20absolute%3B%0A%20%20width%3A%20100%25%3B%0A%20%20height%3A%20100%25%3B%0A%7D%0A%3C/style%3E%0A%0A%3Cdiv%20id%3Doverlay%3E%3C/div%3E%0A%3Ca%20id%3Dobscured%20href%3D%23%3Elink%3C/a%3E%0A%0A%3Cscript%3E%0Awindow.clicked%20%3D%20false%3B%0A%0Alet%20link%20%3D%20document.querySelector%28%22%23obscured%22%29%3B%0Alink.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%3C/script%3E%0A"
12:48:09 INFO - 1499543289880 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cbutton%20style%3D%22pointer-events%3A%20none%22%3Eclick%20me%3C/button%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cscript%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20window.clicked%20%3D%20false%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20let%20button%20%3D%20document.querySelector%28%22button%22%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20button.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/script%3E%0A%20%20%20%20%20%20%20%20"
12:48:09 INFO - 1499543289883 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cbutton%20style%3D%22pointer-events%3A%20none%22%3Eclick%20me%3C/button%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cscript%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20window.clicked%20%3D%20false%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20let%20button%20%3D%20document.querySelector%28%22button%22%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20button.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/script%3E%0A%20%20%20%20%20%20%20%20"
12:48:09 INFO - 1499543289886 Marionette TRACE 400 <- [1,2,null,{}]
12:48:09 INFO - 1499543289894 Marionette TRACE 400 -> [0,3,"findElement",{"using":"tag name","value":"button"}]
12:48:09 INFO - 1499543289897 Marionette TRACE 400 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"171de172-6db4-4af8-a183-df8e6d9d851f","ELEMENT":"171de172-6db4-4af8-a183-df8e6d9d851f"}}]
12:48:09 INFO - 1499543289898 Marionette TRACE 400 -> [0,4,"getElementValueOfCssProperty",{"propertyName":"pointer-events","id":"171de172-6db4-4af8-a183-df8e6d9d851f"}]
12:48:09 INFO - 1499543289921 Marionette TRACE 400 <- [1,4,null,{"value":"none"}]
12:48:09 INFO - 1499543289922 Marionette TRACE 400 -> [0,5,"clickElement",{"id":"171de172-6db4-4af8-a183-df8e6d9d851f"}]
12:48:09 INFO - 1499543289942 Marionette TRACE 400 <- [1,5,{"error":"element click intercepted","message":"Element