could not be scrolled into view","stacktrace":"WebDriverError@chrome://marionette/content/error.js:226:5\nElementNotInteractableError@chrome://marionette/content/error.js:315:5\nwebdriverClickElement@chrome://marionette/content/interaction.js:183:11\nTaskImpl_run@resource://gre/modules/Task.jsm:331:42\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nTaskImpl_handleResultValue@resource://gre/modules/Task.jsm:401:16\nTaskImpl_run@resource://gre/modules/Task.jsm:339:15\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nTaskImpl_handleResultValue@resource://gre/modules/Task.jsm:401:16\nTaskImpl_run@resource://gre/modules/Task.jsm:339:15\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nnavigate@chrome://marionette/content/listener.js:447:12\nclickElement@chrome://marionette/content/listener.js:1367:5\n"},null]
05:38:29 INFO - 1500899909533 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}]
05:38:29 INFO - TEST-END: test_click.py TestClick.test_clicking_an_element_that_is_not_displayed_raises1500899909537 Marionette TRACE 352 <- [1,5,null,{"value":null}]
05:38:29 INFO - 1500899909538 Marionette TRACE 352 -> [0,6,"deleteSession",{}]
05:38:29 INFO - 1500899909540 Marionette TRACE 352 <- [1,6,null,{}]
05:38:29 INFO - TEST-PASS | test_click.py TestClick.test_clicking_an_element_that_is_not_displayed_raises | took 162ms
05:38:29 INFO - TEST-START | test_click.py TestClick.test_clicking_on_a_multiline_link
05:38:29 INFO - 1500899909543 Marionette DEBUG Closed connection 352
05:38:29 INFO - 1500899909544 Marionette DEBUG Accepted connection 353 from 127.0.0.1:49782
05:38:29 INFO - 1500899909545 Marionette DEBUG Closed connection 353
05:38:29 INFO - 1500899909546 Marionette DEBUG Accepted connection 354 from 127.0.0.1:49783
05:38:29 INFO - 1500899909547 Marionette TRACE 354 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:38:29 INFO - 1500899909555 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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}
05:38:29 INFO - 1500899909559 Marionette DEBUG Register listener.js for window 12
05:38:29 INFO - 1500899909562 Marionette TRACE 354 <- [1,1,null,{"sessionId":"6c51259a-0a50-41b2-90df-ad906c782713","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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}}]
05:38:29 INFO - 1500899909564 Marionette TRACE 354 -> [0,2,"setTimeouts",{"script":30000}]
05:38:29 INFO - 1500899909565 Marionette TRACE 354 <- [1,2,null,{}]
05:38:29 INFO - 1500899909566 Marionette TRACE 354 -> [0,3,"setTimeouts",{"pageLoad":300000}]
05:38:29 INFO - 1500899909567 Marionette TRACE 354 <- [1,3,null,{}]
05:38:29 INFO - 1500899909568 Marionette TRACE 354 -> [0,4,"setTimeouts",{"implicit":0}]
05:38:29 INFO - 1500899909568 Marionette TRACE 354 <- [1,4,null,{}]
05:38:29 INFO - 1500899909570 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}]
05:38:29 INFO - TEST-START: test_click.py TestClick.test_clicking_on_a_multiline_link1500899909574 Marionette TRACE 354 <- [1,5,null,{"value":null}]
05:38:29 INFO - 1500899909575 Marionette TRACE 354 -> [0,6,"deleteSession",{}]
05:38:29 INFO - 1500899909577 Marionette TRACE 354 <- [1,6,null,{}]
05:38:29 INFO - 1500899909579 Marionette DEBUG Closed connection 354
05:38:29 INFO - 1500899909580 Marionette DEBUG Accepted connection 355 from 127.0.0.1:49784
05:38:29 INFO - 1500899909581 Marionette DEBUG Closed connection 355
05:38:29 INFO - 1500899909581 Marionette DEBUG Accepted connection 356 from 127.0.0.1:49785
05:38:29 INFO - 1500899909582 Marionette TRACE 356 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:38:29 INFO - 1500899909583 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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}
05:38:29 INFO - 1500899909586 Marionette DEBUG Register listener.js for window 12
05:38:29 INFO - 1500899909589 Marionette TRACE 356 <- [1,1,null,{"sessionId":"562366e2-75d3-414f-90e8-1287b2c1cb0c","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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}}]
05:38:29 INFO - 1500899909591 Marionette TRACE 356 -> [0,2,"deleteSession",{}]
05:38:29 INFO - 1500899909593 Marionette TRACE 356 <- [1,2,null,{}]
05:38:29 INFO - 1500899909596 Marionette DEBUG Closed connection 356
05:38:29 INFO - 1500899909597 Marionette DEBUG Accepted connection 357 from 127.0.0.1:49786
05:38:29 INFO - 1500899909598 Marionette DEBUG Closed connection 357
05:38:29 INFO - 1500899909598 Marionette DEBUG Accepted connection 358 from 127.0.0.1:49787
05:38:29 INFO - 1500899909600 Marionette TRACE 358 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
05:38:29 INFO - 1500899909600 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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}
05:38:29 INFO - 1500899909603 Marionette DEBUG Register listener.js for window 12
05:38:29 INFO - 1500899909606 Marionette TRACE 358 <- [1,1,null,{"sessionId":"09d3b99c-2115-4280-a02e-dd1b1cc111a2","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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}}]
05:38:29 INFO - 1500899909608 Marionette TRACE 358 -> [0,2,"get",{"url":"http://127.0.0.1:49347/clicks.html"}]
05:38:29 INFO - 1500899909610 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49347/hidden.html"
05:38:29 INFO - 1500899909616 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49347/hidden.html"
05:38:29 INFO - 1500899909617 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49347/hidden.html"
05:38:29 INFO - 1500899909638 Marionette DEBUG Received DOM event "DOMContentLoaded" for "http://127.0.0.1:49347/clicks.html"
05:38:29 INFO - 1500899909644 Marionette DEBUG Received DOM event "pageshow" for "http://127.0.0.1:49347/clicks.html"
05:38:29 INFO - 1500899909656 Marionette TRACE 358 <- [1,2,null,{}]
05:38:29 INFO - 1500899909658 Marionette TRACE 358 -> [0,3,"findElement",{"using":"id","value":"overflowLink"}]
05:38:29 INFO - 1500899909662 Marionette TRACE 358 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"1f1a1546-299c-4390-857a-52b8fec2d506","ELEMENT":"1f1a1546-299c-4390-857a-52b8fec2d506"}}]
05:38:29 INFO - 1500899909664 Marionette TRACE 358 -> [0,4,"clickElement",{"id":"1f1a1546-299c-4390-857a-52b8fec2d506"}]
05:38:29 INFO - 1500899909708 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49347/clicks.html"
05:38:29 INFO - 1500899909720 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49347/clicks.html"
05:38:29 INFO - 1500899909721 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49347/clicks.html"
05:38:29 INFO - 1500899909752 Marionette DEBUG Received DOM event "DOMContentLoaded" for "http://127.0.0.1:49347/test.html"
05:38:29 INFO - 1500899909759 Marionette DEBUG Received DOM event "pageshow" for "http://127.0.0.1:49347/test.html"
05:38:29 INFO - 1500899909772 Marionette TRACE 358 <- [1,4,null,{}]
05:38:29 INFO - 1500899909775 Marionette TRACE 358 -> [0,5,"findElement",{"using":"id","value":"testDiv"}]
05:38:29 INFO - 1500899909779 Marionette TRACE 358 <- [1,5,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"94be4342-3032-4e16-b451-004547447321","ELEMENT":"94be4342-3032-4e16-b451-004547447321"}}]
05:38:29 INFO - 1500899909780 Marionette TRACE 358 -> [0,6,"getTitle",{}]
05:38:29 INFO - 1500899909780 Marionette TRACE 358 <- [1,6,null,{"value":"Marionette Test"}]
05:38:29 INFO - 1500899909783 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}]
05:38:29 INFO - TEST-END: test_click.py TestClick.test_clicking_on_a_multiline_link1500899909786 Marionette TRACE 358 <- [1,7,null,{"value":null}]
05:38:29 INFO - 1500899909787 Marionette TRACE 358 -> [0,8,"deleteSession",{}]
05:38:29 INFO - 1500899909789 Marionette TRACE 358 <- [1,8,null,{}]
05:38:29 INFO - TEST-PASS | test_click.py TestClick.test_clicking_on_a_multiline_link | took 249ms
05:38:29 INFO - TEST-START | test_click.py TestClick.test_container_element
05:38:29 INFO - 1500899909792 Marionette DEBUG Closed connection 358
05:38:29 INFO - 1500899909793 Marionette DEBUG Accepted connection 359 from 127.0.0.1:49790
05:38:29 INFO - 1500899909794 Marionette DEBUG Closed connection 359
05:38:29 INFO - 1500899909794 Marionette DEBUG Accepted connection 360 from 127.0.0.1:49791
05:38:29 INFO - 1500899909796 Marionette TRACE 360 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:38:29 INFO - 1500899909797 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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}
05:38:29 INFO - 1500899909800 Marionette DEBUG Register listener.js for window 12
05:38:29 INFO - 1500899909803 Marionette TRACE 360 <- [1,1,null,{"sessionId":"78e7d893-0254-45a9-a99c-141c92cf12f2","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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}}]
05:38:29 INFO - 1500899909805 Marionette TRACE 360 -> [0,2,"setTimeouts",{"script":30000}]
05:38:29 INFO - 1500899909806 Marionette TRACE 360 <- [1,2,null,{}]
05:38:29 INFO - 1500899909807 Marionette TRACE 360 -> [0,3,"setTimeouts",{"pageLoad":300000}]
05:38:29 INFO - 1500899909808 Marionette TRACE 360 <- [1,3,null,{}]
05:38:29 INFO - 1500899909809 Marionette TRACE 360 -> [0,4,"setTimeouts",{"implicit":0}]
05:38:29 INFO - 1500899909809 Marionette TRACE 360 <- [1,4,null,{}]
05:38:29 INFO - 1500899909811 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}]
05:38:29 INFO - TEST-START: test_click.py TestClick.test_container_element1500899909814 Marionette TRACE 360 <- [1,5,null,{"value":null}]
05:38:29 INFO - 1500899909815 Marionette TRACE 360 -> [0,6,"deleteSession",{}]
05:38:29 INFO - 1500899909816 Marionette TRACE 360 <- [1,6,null,{}]
05:38:29 INFO - 1500899909819 Marionette DEBUG Closed connection 360
05:38:29 INFO - 1500899909820 Marionette DEBUG Accepted connection 361 from 127.0.0.1:49792
05:38:29 INFO - 1500899909820 Marionette DEBUG Closed connection 361
05:38:29 INFO - 1500899909821 Marionette DEBUG Accepted connection 362 from 127.0.0.1:49793
05:38:29 INFO - 1500899909822 Marionette TRACE 362 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:38:29 INFO - 1500899909823 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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}
05:38:29 INFO - 1500899909826 Marionette DEBUG Register listener.js for window 12
05:38:29 INFO - 1500899909829 Marionette TRACE 362 <- [1,1,null,{"sessionId":"8559233b-8267-421c-8bfd-6816e17c55f8","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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}}]
05:38:29 INFO - 1500899909831 Marionette TRACE 362 -> [0,2,"deleteSession",{}]
05:38:29 INFO - 1500899909833 Marionette TRACE 362 <- [1,2,null,{}]
05:38:29 INFO - 1500899909835 Marionette DEBUG Closed connection 362
05:38:29 INFO - 1500899909836 Marionette DEBUG Accepted connection 363 from 127.0.0.1:49794
05:38:29 INFO - 1500899909837 Marionette DEBUG Closed connection 363
05:38:29 INFO - 1500899909838 Marionette DEBUG Accepted connection 364 from 127.0.0.1:49795
05:38:29 INFO - 1500899909839 Marionette TRACE 364 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
05:38:29 INFO - 1500899909839 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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}
05:38:29 INFO - 1500899909842 Marionette DEBUG Register listener.js for window 12
05:38:29 INFO - 1500899909846 Marionette TRACE 364 <- [1,1,null,{"sessionId":"a0065555-944c-4d76-a714-1030b72c3eaf","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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}}]
05:38:29 INFO - 1500899909848 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"}]
05:38:29 INFO - 1500899909850 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49347/test.html"
05:38:29 INFO - 1500899909852 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49347/test.html"
05:38:29 INFO - 1500899909852 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49347/test.html"
05:38:29 INFO - 1500899909881 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"
05:38:29 INFO - 1500899909885 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"
05:38:29 INFO - 1500899909889 Marionette TRACE 364 <- [1,2,null,{}]
05:38:29 INFO - 1500899909897 Marionette TRACE 364 -> [0,3,"findElement",{"using":"tag name","value":"option"}]
05:38:29 INFO - 1500899909901 Marionette TRACE 364 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"e0cf6567-24ae-495f-83f3-5464455dcaad","ELEMENT":"e0cf6567-24ae-495f-83f3-5464455dcaad"}}]
05:38:29 INFO - 1500899909906 Marionette TRACE 364 -> [0,4,"clickElement",{"id":"e0cf6567-24ae-495f-83f3-5464455dcaad"}]
05:38:30 INFO - 1500899910153 Marionette DEBUG Canceled page load listener because no navigation has been detected
05:38:30 INFO - 1500899910154 Marionette TRACE 364 <- [1,4,null,{}]
05:38:30 INFO - 1500899910155 Marionette TRACE 364 -> [0,5,"getElementProperty",{"id":"e0cf6567-24ae-495f-83f3-5464455dcaad","name":"selected"}]
05:38:30 INFO - 1500899910160 Marionette TRACE 364 <- [1,5,null,{"value":true}]
05:38:30 INFO - 1500899910162 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}]
05:38:30 INFO - TEST-END: test_click.py TestClick.test_container_element1500899910165 Marionette TRACE 364 <- [1,6,null,{"value":null}]
05:38:30 INFO - 1500899910166 Marionette TRACE 364 -> [0,7,"deleteSession",{}]
05:38:30 INFO - TEST-PASS | test_click.py TestClick.test_container_element | took 378ms
05:38:30 INFO - TEST-START | test_click.py TestClick.test_container_element_outside_view
05:38:30 INFO - 1500899910168 Marionette TRACE 364 <- [1,7,null,{}]
05:38:30 INFO - 1500899910170 Marionette DEBUG Closed connection 364
05:38:30 INFO - 1500899910171 Marionette DEBUG Accepted connection 365 from 127.0.0.1:49796
05:38:30 INFO - 1500899910172 Marionette DEBUG Closed connection 365
05:38:30 INFO - 1500899910173 Marionette DEBUG Accepted connection 366 from 127.0.0.1:49797
05:38:30 INFO - 1500899910174 Marionette TRACE 366 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:38:30 INFO - 1500899910174 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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}
05:38:30 INFO - 1500899910177 Marionette DEBUG Register listener.js for window 12
05:38:30 INFO - 1500899910188 Marionette TRACE 366 <- [1,1,null,{"sessionId":"4fb0127c-8b31-4aac-be15-7303c30bd96c","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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}}]
05:38:30 INFO - 1500899910190 Marionette TRACE 366 -> [0,2,"setTimeouts",{"script":30000}]
05:38:30 INFO - 1500899910191 Marionette TRACE 366 <- [1,2,null,{}]
05:38:30 INFO - 1500899910199 Marionette TRACE 366 -> [0,3,"setTimeouts",{"pageLoad":300000}]
05:38:30 INFO - 1500899910200 Marionette TRACE 366 <- [1,3,null,{}]
05:38:30 INFO - 1500899910202 Marionette TRACE 366 -> [0,4,"setTimeouts",{"implicit":0}]
05:38:30 INFO - 1500899910202 Marionette TRACE 366 <- [1,4,null,{}]
05:38:30 INFO - 1500899910204 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}]
05:38:30 INFO - TEST-START: test_click.py TestClick.test_container_element_outside_view1500899910207 Marionette TRACE 366 <- [1,5,null,{"value":null}]
05:38:30 INFO - 1500899910209 Marionette TRACE 366 -> [0,6,"deleteSession",{}]
05:38:30 INFO - 1500899910211 Marionette TRACE 366 <- [1,6,null,{}]
05:38:30 INFO - 1500899910213 Marionette DEBUG Closed connection 366
05:38:30 INFO - 1500899910214 Marionette DEBUG Accepted connection 367 from 127.0.0.1:49798
05:38:30 INFO - 1500899910215 Marionette DEBUG Closed connection 367
05:38:30 INFO - 1500899910216 Marionette DEBUG Accepted connection 368 from 127.0.0.1:49799
05:38:30 INFO - 1500899910217 Marionette TRACE 368 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:38:30 INFO - 1500899910217 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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}
05:38:30 INFO - 1500899910220 Marionette DEBUG Register listener.js for window 12
05:38:30 INFO - 1500899910224 Marionette TRACE 368 <- [1,1,null,{"sessionId":"a71e7e69-29e4-46ea-88fe-29164ce2bcdf","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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}}]
05:38:30 INFO - 1500899910226 Marionette TRACE 368 -> [0,2,"deleteSession",{}]
05:38:30 INFO - 1500899910227 Marionette TRACE 368 <- [1,2,null,{}]
05:38:30 INFO - 1500899910230 Marionette DEBUG Closed connection 368
05:38:30 INFO - 1500899910230 Marionette DEBUG Accepted connection 369 from 127.0.0.1:49800
05:38:30 INFO - 1500899910231 Marionette DEBUG Closed connection 369
05:38:30 INFO - 1500899910232 Marionette DEBUG Accepted connection 370 from 127.0.0.1:49801
05:38:30 INFO - 1500899910233 Marionette TRACE 370 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
05:38:30 INFO - 1500899910234 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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}
05:38:30 INFO - 1500899910237 Marionette DEBUG Register listener.js for window 12
05:38:30 INFO - 1500899910240 Marionette TRACE 370 <- [1,1,null,{"sessionId":"56e8494a-5a52-4395-a473-05765d715a7b","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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}}]
05:38:30 INFO - 1500899910243 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"}]
05:38:30 INFO - 1500899910245 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"
05:38:30 INFO - 1500899910248 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"
05:38:30 INFO - 1500899910249 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"
05:38:30 INFO - 1500899910269 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"
05:38:30 INFO - 1500899910272 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"
05:38:30 INFO - 1500899910277 Marionette TRACE 370 <- [1,2,null,{}]
05:38:30 INFO - 1500899910284 Marionette TRACE 370 -> [0,3,"findElement",{"using":"tag name","value":"option"}]
05:38:30 INFO - 1500899910287 Marionette TRACE 370 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"246f2baa-3a7c-4c03-8b84-e18d194c3bfa","ELEMENT":"246f2baa-3a7c-4c03-8b84-e18d194c3bfa"}}]
05:38:30 INFO - 1500899910288 Marionette TRACE 370 -> [0,4,"clickElement",{"id":"246f2baa-3a7c-4c03-8b84-e18d194c3bfa"}]
05:38:30 INFO - 1500899910533 Marionette DEBUG Canceled page load listener because no navigation has been detected
05:38:30 INFO - 1500899910533 Marionette TRACE 370 <- [1,4,null,{}]
05:38:30 INFO - 1500899910535 Marionette TRACE 370 -> [0,5,"getElementProperty",{"id":"246f2baa-3a7c-4c03-8b84-e18d194c3bfa","name":"selected"}]
05:38:30 INFO - 1500899910540 Marionette TRACE 370 <- [1,5,null,{"value":true}]
05:38:30 INFO - 1500899910541 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}]
05:38:30 INFO - TEST-END: test_click.py TestClick.test_container_element_outside_view1500899910544 Marionette TRACE 370 <- [1,6,null,{"value":null}]
05:38:30 INFO - 1500899910545 Marionette TRACE 370 -> [0,7,"deleteSession",{}]
05:38:30 INFO - TEST-PASS | test_click.py TestClick.test_container_element_outside_view | took 379ms
05:38:30 INFO - TEST-START | test_click.py TestClick.test_css_transforms
05:38:30 INFO - 1500899910547 Marionette TRACE 370 <- [1,7,null,{}]
05:38:30 INFO - 1500899910549 Marionette DEBUG Closed connection 370
05:38:30 INFO - 1500899910550 Marionette DEBUG Accepted connection 371 from 127.0.0.1:49802
05:38:30 INFO - 1500899910551 Marionette DEBUG Closed connection 371
05:38:30 INFO - 1500899910552 Marionette DEBUG Accepted connection 372 from 127.0.0.1:49803
05:38:30 INFO - 1500899910553 Marionette TRACE 372 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:38:30 INFO - 1500899910553 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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}
05:38:30 INFO - 1500899910556 Marionette DEBUG Register listener.js for window 12
05:38:30 INFO - 1500899910559 Marionette TRACE 372 <- [1,1,null,{"sessionId":"f8ad3044-467d-4794-ac62-892a96032579","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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}}]
05:38:30 INFO - 1500899910562 Marionette TRACE 372 -> [0,2,"setTimeouts",{"script":30000}]
05:38:30 INFO - 1500899910562 Marionette TRACE 372 <- [1,2,null,{}]
05:38:30 INFO - 1500899910563 Marionette TRACE 372 -> [0,3,"setTimeouts",{"pageLoad":300000}]
05:38:30 INFO - 1500899910564 Marionette TRACE 372 <- [1,3,null,{}]
05:38:30 INFO - 1500899910565 Marionette TRACE 372 -> [0,4,"setTimeouts",{"implicit":0}]
05:38:30 INFO - 1500899910565 Marionette TRACE 372 <- [1,4,null,{}]
05:38:30 INFO - 1500899910567 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}]
05:38:30 INFO - TEST-START: test_click.py TestClick.test_css_transforms1500899910570 Marionette TRACE 372 <- [1,5,null,{"value":null}]
05:38:30 INFO - 1500899910571 Marionette TRACE 372 -> [0,6,"deleteSession",{}]
05:38:30 INFO - 1500899910572 Marionette TRACE 372 <- [1,6,null,{}]
05:38:30 INFO - 1500899910575 Marionette DEBUG Closed connection 372
05:38:30 INFO - 1500899910575 Marionette DEBUG Accepted connection 373 from 127.0.0.1:49804
05:38:30 INFO - 1500899910576 Marionette DEBUG Closed connection 373
05:38:30 INFO - 1500899910577 Marionette DEBUG Accepted connection 374 from 127.0.0.1:49805
05:38:30 INFO - 1500899910578 Marionette TRACE 374 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:38:30 INFO - 1500899910579 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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}
05:38:30 INFO - 1500899910581 Marionette DEBUG Register listener.js for window 12
05:38:30 INFO - 1500899910585 Marionette TRACE 374 <- [1,1,null,{"sessionId":"62b2bcf8-4566-43f9-a25c-a414c592faf7","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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}}]
05:38:30 INFO - 1500899910587 Marionette TRACE 374 -> [0,2,"deleteSession",{}]
05:38:30 INFO - 1500899910588 Marionette TRACE 374 <- [1,2,null,{}]
05:38:30 INFO - 1500899910591 Marionette DEBUG Closed connection 374
05:38:30 INFO - 1500899910591 Marionette DEBUG Accepted connection 375 from 127.0.0.1:49806
05:38:30 INFO - 1500899910592 Marionette DEBUG Closed connection 375
05:38:30 INFO - 1500899910593 Marionette DEBUG Accepted connection 376 from 127.0.0.1:49807
05:38:30 INFO - 1500899910594 Marionette TRACE 376 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
05:38:30 INFO - 1500899910595 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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}
05:38:30 INFO - 1500899910597 Marionette DEBUG Register listener.js for window 12
05:38:30 INFO - 1500899910600 Marionette TRACE 376 <- [1,1,null,{"sessionId":"6660e66e-618b-4f01-b128-ca96b9d3dc43","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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}}]
05:38:30 INFO - 1500899910603 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"}]
05:38:30 INFO - 1500899910604 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"
05:38:30 INFO - 1500899910607 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"
05:38:30 INFO - 1500899910607 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"
05:38:30 INFO - 1500899910632 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"
05:38:30 INFO - 1500899910634 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"
05:38:30 INFO - 1500899910639 Marionette TRACE 376 <- [1,2,null,{}]
05:38:30 INFO - 1500899910647 Marionette TRACE 376 -> [0,3,"findElement",{"using":"tag name","value":"div"}]
05:38:30 INFO - 1500899910651 Marionette TRACE 376 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"cac62bc5-69f3-4121-bf44-5509e3ba2d3e","ELEMENT":"cac62bc5-69f3-4121-bf44-5509e3ba2d3e"}}]
05:38:30 INFO - 1500899910652 Marionette TRACE 376 -> [0,4,"clickElement",{"id":"cac62bc5-69f3-4121-bf44-5509e3ba2d3e"}]
05:38:30 INFO - 1500899910895 Marionette DEBUG Canceled page load listener because no navigation has been detected
05:38:30 INFO - 1500899910895 Marionette TRACE 376 <- [1,4,null,{}]
05:38:30 INFO - 1500899910897 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}]
05:38:30 INFO - TEST-END: test_click.py TestClick.test_css_transforms1500899910901 Marionette TRACE 376 <- [1,5,null,{"value":null}]
05:38:30 INFO - 1500899910902 Marionette TRACE 376 -> [0,6,"deleteSession",{}]
05:38:30 INFO - 1500899910903 Marionette TRACE 376 <- [1,6,null,{}]
05:38:30 INFO - TEST-PASS | test_click.py TestClick.test_css_transforms | took 357ms
05:38:30 INFO - TEST-START | test_click.py TestClick.test_inclusive_descendant
05:38:30 INFO - 1500899910906 Marionette DEBUG Closed connection 376
05:38:30 INFO - 1500899910906 Marionette DEBUG Accepted connection 377 from 127.0.0.1:49808
05:38:30 INFO - 1500899910907 Marionette DEBUG Closed connection 377
05:38:30 INFO - 1500899910908 Marionette DEBUG Accepted connection 378 from 127.0.0.1:49809
05:38:30 INFO - 1500899910910 Marionette TRACE 378 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:38:30 INFO - 1500899910910 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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}
05:38:30 INFO - 1500899910913 Marionette DEBUG Register listener.js for window 12
05:38:30 INFO - 1500899910924 Marionette TRACE 378 <- [1,1,null,{"sessionId":"74e2cb5e-a756-45b3-b3d9-cc38d19a93ee","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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}}]
05:38:30 INFO - 1500899910926 Marionette TRACE 378 -> [0,2,"setTimeouts",{"script":30000}]
05:38:30 INFO - 1500899910927 Marionette TRACE 378 <- [1,2,null,{}]
05:38:30 INFO - 1500899910928 Marionette TRACE 378 -> [0,3,"setTimeouts",{"pageLoad":300000}]
05:38:30 INFO - 1500899910928 Marionette TRACE 378 <- [1,3,null,{}]
05:38:30 INFO - 1500899910929 Marionette TRACE 378 -> [0,4,"setTimeouts",{"implicit":0}]
05:38:30 INFO - 1500899910930 Marionette TRACE 378 <- [1,4,null,{}]
05:38:30 INFO - 1500899910932 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}]
05:38:30 INFO - TEST-START: test_click.py TestClick.test_inclusive_descendant1500899910935 Marionette TRACE 378 <- [1,5,null,{"value":null}]
05:38:30 INFO - 1500899910936 Marionette TRACE 378 -> [0,6,"deleteSession",{}]
05:38:30 INFO - 1500899910937 Marionette TRACE 378 <- [1,6,null,{}]
05:38:30 INFO - 1500899910940 Marionette DEBUG Closed connection 378
05:38:30 INFO - 1500899910941 Marionette DEBUG Accepted connection 379 from 127.0.0.1:49810
05:38:30 INFO - 1500899910942 Marionette DEBUG Closed connection 379
05:38:30 INFO - 1500899910942 Marionette DEBUG Accepted connection 380 from 127.0.0.1:49811
05:38:30 INFO - 1500899910943 Marionette TRACE 380 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:38:30 INFO - 1500899910944 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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}
05:38:30 INFO - 1500899910947 Marionette DEBUG Register listener.js for window 12
05:38:30 INFO - 1500899910950 Marionette TRACE 380 <- [1,1,null,{"sessionId":"e3079764-fb4c-4a1f-a734-32399fb87e77","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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}}]
05:38:30 INFO - 1500899910952 Marionette TRACE 380 -> [0,2,"deleteSession",{}]
05:38:30 INFO - 1500899910954 Marionette TRACE 380 <- [1,2,null,{}]
05:38:30 INFO - 1500899910956 Marionette DEBUG Closed connection 380
05:38:30 INFO - 1500899910957 Marionette DEBUG Accepted connection 381 from 127.0.0.1:49812
05:38:30 INFO - 1500899910958 Marionette DEBUG Closed connection 381
05:38:30 INFO - 1500899910958 Marionette DEBUG Accepted connection 382 from 127.0.0.1:49813
05:38:30 INFO - 1500899910959 Marionette TRACE 382 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
05:38:30 INFO - 1500899910960 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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}
05:38:30 INFO - 1500899910963 Marionette DEBUG Register listener.js for window 12
05:38:30 INFO - 1500899910966 Marionette TRACE 382 <- [1,1,null,{"sessionId":"2e908b5e-6955-4de8-acfc-7ad1478ad2fa","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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}}]
05:38:30 INFO - 1500899910968 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"}]
05:38:30 INFO - 1500899910970 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"
05:38:30 INFO - 1500899910972 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"
05:38:30 INFO - 1500899910973 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"
05:38:30 INFO - 1500899910994 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"
05:38:31 INFO - 1500899910997 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"
05:38:31 INFO - 1500899911001 Marionette TRACE 382 <- [1,2,null,{}]
05:38:31 INFO - 1500899911003 Marionette TRACE 382 -> [0,3,"findElement",{"using":"tag name","value":"select"}]
05:38:31 INFO - 1500899911006 Marionette TRACE 382 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"3f0effe0-ddc7-4d62-8431-0d951f884b4c","ELEMENT":"3f0effe0-ddc7-4d62-8431-0d951f884b4c"}}]
05:38:31 INFO - 1500899911007 Marionette TRACE 382 -> [0,4,"clickElement",{"id":"3f0effe0-ddc7-4d62-8431-0d951f884b4c"}]
05:38:31 INFO - 1500899911260 Marionette DEBUG Canceled page load listener because no navigation has been detected
05:38:31 INFO - 1500899911260 Marionette TRACE 382 <- [1,4,null,{}]
05:38:31 INFO - 1500899911262 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}]
05:38:31 INFO - TEST-PASS | test_click.py TestClick.test_inclusive_descendant | took 364ms
05:38:31 INFO - TEST-END: test_click.py TestClick.test_inclusive_descendant1500899911265 Marionette TRACE 382 <- [1,5,null,{"value":null}]
05:38:31 INFO - 1500899911266 Marionette TRACE 382 -> [0,6,"deleteSession",{}]
05:38:31 INFO - 1500899911268 Marionette TRACE 382 <- [1,6,null,{}]
05:38:31 INFO - TEST-START | test_click.py TestClick.test_input_file
05:38:31 INFO - 1500899911270 Marionette DEBUG Closed connection 382
05:38:31 INFO - 1500899911272 Marionette DEBUG Accepted connection 383 from 127.0.0.1:49814
05:38:31 INFO - 1500899911272 Marionette DEBUG Closed connection 383
05:38:31 INFO - 1500899911273 Marionette DEBUG Accepted connection 384 from 127.0.0.1:49815
05:38:31 INFO - 1500899911274 Marionette TRACE 384 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:38:31 INFO - 1500899911275 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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}
05:38:31 INFO - 1500899911278 Marionette DEBUG Register listener.js for window 12
05:38:31 INFO - 1500899911281 Marionette TRACE 384 <- [1,1,null,{"sessionId":"e188e796-9578-4ebf-94ef-3f1460f5c5f0","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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}}]
05:38:31 INFO - 1500899911283 Marionette TRACE 384 -> [0,2,"setTimeouts",{"script":30000}]
05:38:31 INFO - 1500899911284 Marionette TRACE 384 <- [1,2,null,{}]
05:38:31 INFO - 1500899911285 Marionette TRACE 384 -> [0,3,"setTimeouts",{"pageLoad":300000}]
05:38:31 INFO - 1500899911285 Marionette TRACE 384 <- [1,3,null,{}]
05:38:31 INFO - 1500899911286 Marionette TRACE 384 -> [0,4,"setTimeouts",{"implicit":0}]
05:38:31 INFO - 1500899911287 Marionette TRACE 384 <- [1,4,null,{}]
05:38:31 INFO - 1500899911289 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}]
05:38:31 INFO - TEST-START: test_click.py TestClick.test_input_file1500899911291 Marionette TRACE 384 <- [1,5,null,{"value":null}]
05:38:31 INFO - 1500899911292 Marionette TRACE 384 -> [0,6,"deleteSession",{}]
05:38:31 INFO - 1500899911294 Marionette TRACE 384 <- [1,6,null,{}]
05:38:31 INFO - 1500899911296 Marionette DEBUG Closed connection 384
05:38:31 INFO - 1500899911297 Marionette DEBUG Accepted connection 385 from 127.0.0.1:49816
05:38:31 INFO - 1500899911298 Marionette DEBUG Closed connection 385
05:38:31 INFO - 1500899911298 Marionette DEBUG Accepted connection 386 from 127.0.0.1:49817
05:38:31 INFO - 1500899911299 Marionette TRACE 386 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:38:31 INFO - 1500899911300 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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}
05:38:31 INFO - 1500899911303 Marionette DEBUG Register listener.js for window 12
05:38:31 INFO - 1500899911306 Marionette TRACE 386 <- [1,1,null,{"sessionId":"2a4d2cfd-803d-406a-a382-fbf9590da418","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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}}]
05:38:31 INFO - 1500899911308 Marionette TRACE 386 -> [0,2,"deleteSession",{}]
05:38:31 INFO - 1500899911309 Marionette TRACE 386 <- [1,2,null,{}]
05:38:31 INFO - 1500899911312 Marionette DEBUG Closed connection 386
05:38:31 INFO - 1500899911313 Marionette DEBUG Accepted connection 387 from 127.0.0.1:49818
05:38:31 INFO - 1500899911314 Marionette DEBUG Closed connection 387
05:38:31 INFO - 1500899911314 Marionette DEBUG Accepted connection 388 from 127.0.0.1:49819
05:38:31 INFO - 1500899911316 Marionette TRACE 388 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
05:38:31 INFO - 1500899911316 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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}
05:38:31 INFO - 1500899911319 Marionette DEBUG Register listener.js for window 12
05:38:31 INFO - 1500899911322 Marionette TRACE 388 <- [1,1,null,{"sessionId":"40435ebe-ef7d-46b0-bc96-300edcbe7078","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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}}]
05:38:31 INFO - 1500899911324 Marionette TRACE 388 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"}]
05:38:31 INFO - 1500899911326 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"
05:38:31 INFO - 1500899911329 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"
05:38:31 INFO - 1500899911329 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"
05:38:31 INFO - 1500899911352 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
05:38:31 INFO - 1500899911354 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
05:38:31 INFO - 1500899911358 Marionette TRACE 388 <- [1,2,null,{}]
05:38:31 INFO - 1500899911366 Marionette TRACE 388 -> [0,3,"findElement",{"using":"tag name","value":"input"}]
05:38:31 INFO - 1500899911370 Marionette TRACE 388 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"3b535e8c-a4ad-4a71-93a6-e4a5aa6dc719","ELEMENT":"3b535e8c-a4ad-4a71-93a6-e4a5aa6dc719"}}]
05:38:31 INFO - 1500899911371 Marionette TRACE 388 -> [0,4,"clickElement",{"id":"3b535e8c-a4ad-4a71-93a6-e4a5aa6dc719"}]
05:38:31 INFO - 1500899911401 Marionette TRACE 388 <- [1,4,{"error":"invalid argument","message":"Cannot click
elements","stacktrace":"WebDriverError@chrome://marionette/content/error.js:226:5\nInvalidArgumentError@chrome://marionette/content/error.js:329:5\nwebdriverClickElement@chrome://marionette/content/interaction.js:165:11\nTaskImpl_run@resource://gre/modules/Task.jsm:331:42\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nTaskImpl_handleResultValue@resource://gre/modules/Task.jsm:401:16\nTaskImpl_run@resource://gre/modules/Task.jsm:339:15\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nTaskImpl_handleResultValue@resource://gre/modules/Task.jsm:401:16\nTaskImpl_run@resource://gre/modules/Task.jsm:339:15\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nnavigate@chrome://marionette/content/listener.js:447:12\nclickElement@chrome://marionette/content/listener.js:1367:5\n"},null]
05:38:31 INFO - 1500899911403 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}]
05:38:31 INFO - TEST-END: test_click.py TestClick.test_input_file1500899911406 Marionette TRACE 388 <- [1,5,null,{"value":null}]
05:38:31 INFO - 1500899911407 Marionette TRACE 388 -> [0,6,"deleteSession",{}]
05:38:31 INFO - TEST-PASS | test_click.py TestClick.test_input_file | took 141ms
05:38:31 INFO - 1500899911409 Marionette TRACE 388 <- [1,6,null,{}]
05:38:31 INFO - TEST-START | test_click.py TestClick.test_obscured_element
05:38:31 INFO - 1500899911412 Marionette DEBUG Closed connection 388
05:38:31 INFO - 1500899911413 Marionette DEBUG Accepted connection 389 from 127.0.0.1:49820
05:38:31 INFO - 1500899911414 Marionette DEBUG Closed connection 389
05:38:31 INFO - 1500899911414 Marionette DEBUG Accepted connection 390 from 127.0.0.1:49821
05:38:31 INFO - 1500899911415 Marionette TRACE 390 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:38:31 INFO - 1500899911416 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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}
05:38:31 INFO - 1500899911419 Marionette DEBUG Register listener.js for window 12
05:38:31 INFO - 1500899911422 Marionette TRACE 390 <- [1,1,null,{"sessionId":"320ab21b-cd3e-4764-973f-ad810758adc9","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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}}]
05:38:31 INFO - 1500899911424 Marionette TRACE 390 -> [0,2,"setTimeouts",{"script":30000}]
05:38:31 INFO - 1500899911425 Marionette TRACE 390 <- [1,2,null,{}]
05:38:31 INFO - 1500899911426 Marionette TRACE 390 -> [0,3,"setTimeouts",{"pageLoad":300000}]
05:38:31 INFO - 1500899911427 Marionette TRACE 390 <- [1,3,null,{}]
05:38:31 INFO - 1500899911428 Marionette TRACE 390 -> [0,4,"setTimeouts",{"implicit":0}]
05:38:31 INFO - 1500899911428 Marionette TRACE 390 <- [1,4,null,{}]
05:38:31 INFO - 1500899911430 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}]
05:38:31 INFO - TEST-START: test_click.py TestClick.test_obscured_element1500899911433 Marionette TRACE 390 <- [1,5,null,{"value":null}]
05:38:31 INFO - 1500899911434 Marionette TRACE 390 -> [0,6,"deleteSession",{}]
05:38:31 INFO - 1500899911435 Marionette TRACE 390 <- [1,6,null,{}]
05:38:31 INFO - 1500899911438 Marionette DEBUG Closed connection 390
05:38:31 INFO - 1500899911439 Marionette DEBUG Accepted connection 391 from 127.0.0.1:49822
05:38:31 INFO - 1500899911439 Marionette DEBUG Closed connection 391
05:38:31 INFO - 1500899911440 Marionette DEBUG Accepted connection 392 from 127.0.0.1:49823
05:38:31 INFO - 1500899911442 Marionette TRACE 392 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:38:31 INFO - 1500899911443 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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}
05:38:31 INFO - 1500899911445 Marionette DEBUG Register listener.js for window 12
05:38:31 INFO - 1500899911456 Marionette TRACE 392 <- [1,1,null,{"sessionId":"5035c9e4-7a0c-4f91-bd20-668cacda340e","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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}}]
05:38:31 INFO - 1500899911459 Marionette TRACE 392 -> [0,2,"deleteSession",{}]
05:38:31 INFO - 1500899911461 Marionette TRACE 392 <- [1,2,null,{}]
05:38:31 INFO - 1500899911464 Marionette DEBUG Closed connection 392
05:38:31 INFO - 1500899911464 Marionette DEBUG Accepted connection 393 from 127.0.0.1:49824
05:38:31 INFO - 1500899911465 Marionette DEBUG Closed connection 393
05:38:31 INFO - 1500899911466 Marionette DEBUG Accepted connection 394 from 127.0.0.1:49825
05:38:31 INFO - 1500899911467 Marionette TRACE 394 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
05:38:31 INFO - 1500899911468 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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}
05:38:31 INFO - 1500899911471 Marionette DEBUG Register listener.js for window 12
05:38:31 INFO - 1500899911474 Marionette TRACE 394 <- [1,1,null,{"sessionId":"4705f837-2c1f-49f6-bbce-aabf6993d419","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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}}]
05:38:31 INFO - 1500899911476 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"}]
05:38:31 INFO - 1500899911478 Marionette DEBUG Received DOM event "beforeunload" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
05:38:31 INFO - 1500899911480 Marionette DEBUG Received DOM event "pagehide" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
05:38:31 INFO - 1500899911481 Marionette DEBUG Received DOM event "unload" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
05:38:31 INFO - 1500899911506 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"
05:38:31 INFO - 1500899911508 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"
05:38:31 INFO - 1500899911518 Marionette TRACE 394 <- [1,2,null,{}]
05:38:31 INFO - 1500899911520 Marionette TRACE 394 -> [0,3,"findElement",{"using":"id","value":"overlay"}]
05:38:31 INFO - 1500899911522 Marionette TRACE 394 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"8ec0ea4e-25a9-41db-a23c-2a086c4ff693","ELEMENT":"8ec0ea4e-25a9-41db-a23c-2a086c4ff693"}}]
05:38:31 INFO - 1500899911523 Marionette TRACE 394 -> [0,4,"findElement",{"using":"id","value":"obscured"}]
05:38:31 INFO - 1500899911526 Marionette TRACE 394 <- [1,4,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"09d1b91a-069a-473f-b431-4dd2f5261e24","ELEMENT":"09d1b91a-069a-473f-b431-4dd2f5261e24"}}]
05:38:31 INFO - 1500899911528 Marionette TRACE 394 -> [0,5,"clickElement",{"id":"8ec0ea4e-25a9-41db-a23c-2a086c4ff693"}]
05:38:31 INFO - 1500899911770 Marionette DEBUG Canceled page load listener because no navigation has been detected
05:38:31 INFO - 1500899911771 Marionette TRACE 394 <- [1,5,null,{}]
05:38:31 INFO - 1500899911772 Marionette TRACE 394 -> [0,6,"clickElement",{"id":"09d1b91a-069a-473f-b431-4dd2f5261e24"}]
05:38:31 INFO - 1500899911790 Marionette TRACE 394 <- [1,6,{"error":"element click intercepted","message":"Element
is not clickable at point (12.449996948242188,10) because another element obscures it","stacktrace":"WebDriverError@chrome://marionette/content/error.js:226:5\nElementClickInterceptedError@chrome://marionette/content/error.js:308:5\nwebdriverClickElement@chrome://marionette/content/interaction.js:192:11\nTaskImpl_run@resource://gre/modules/Task.jsm:331:42\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nTaskImpl_handleResultValue@resource://gre/modules/Task.jsm:401:16\nTaskImpl_run@resource://gre/modules/Task.jsm:339:15\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nTaskImpl_handleResultValue@resource://gre/modules/Task.jsm:401:16\nTaskImpl_run@resource://gre/modules/Task.jsm:339:15\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nnavigate@chrome://marionette/content/listener.js:447:12\nclickElement@chrome://marionette/content/listener.js:1367:5\n"},null]
05:38:31 INFO - 1500899911792 Marionette TRACE 394 -> [0,7,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"test_click.py","script":"return window.clicked","sandbox":null,"line":257}]
05:38:31 INFO - 1500899911795 Marionette TRACE 394 <- [1,7,null,{"value":false}]
05:38:31 INFO - 1500899911797 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}]
05:38:31 INFO - TEST-END: test_click.py TestClick.test_obscured_element1500899911799 Marionette TRACE 394 <- [1,8,null,{"value":null}]
05:38:31 INFO - 1500899911800 Marionette TRACE 394 -> [0,9,"deleteSession",{}]
05:38:31 INFO - TEST-PASS | test_click.py TestClick.test_obscured_element | took 392ms
05:38:31 INFO - 1500899911802 Marionette TRACE 394 <- [1,9,null,{}]
05:38:31 INFO - TEST-START | test_click.py TestClick.test_pointer_events_none
05:38:31 INFO - 1500899911804 Marionette DEBUG Closed connection 394
05:38:31 INFO - 1500899911805 Marionette DEBUG Accepted connection 395 from 127.0.0.1:49826
05:38:31 INFO - 1500899911806 Marionette DEBUG Closed connection 395
05:38:31 INFO - 1500899911807 Marionette DEBUG Accepted connection 396 from 127.0.0.1:49827
05:38:31 INFO - 1500899911809 Marionette TRACE 396 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:38:31 INFO - 1500899911809 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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}
05:38:31 INFO - 1500899911812 Marionette DEBUG Register listener.js for window 12
05:38:31 INFO - 1500899911816 Marionette TRACE 396 <- [1,1,null,{"sessionId":"1e6ca41a-60bd-40c0-a121-7074641e528d","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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}}]
05:38:31 INFO - 1500899911818 Marionette TRACE 396 -> [0,2,"setTimeouts",{"script":30000}]
05:38:31 INFO - 1500899911819 Marionette TRACE 396 <- [1,2,null,{}]
05:38:31 INFO - 1500899911819 Marionette TRACE 396 -> [0,3,"setTimeouts",{"pageLoad":300000}]
05:38:31 INFO - 1500899911820 Marionette TRACE 396 <- [1,3,null,{}]
05:38:31 INFO - 1500899911821 Marionette TRACE 396 -> [0,4,"setTimeouts",{"implicit":0}]
05:38:31 INFO - 1500899911821 Marionette TRACE 396 <- [1,4,null,{}]
05:38:31 INFO - 1500899911823 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}]
05:38:31 INFO - TEST-START: test_click.py TestClick.test_pointer_events_none1500899911826 Marionette TRACE 396 <- [1,5,null,{"value":null}]
05:38:31 INFO - 1500899911827 Marionette TRACE 396 -> [0,6,"deleteSession",{}]
05:38:31 INFO - 1500899911829 Marionette TRACE 396 <- [1,6,null,{}]
05:38:31 INFO - 1500899911831 Marionette DEBUG Closed connection 396
05:38:31 INFO - 1500899911832 Marionette DEBUG Accepted connection 397 from 127.0.0.1:49828
05:38:31 INFO - 1500899911832 Marionette DEBUG Closed connection 397
05:38:31 INFO - 1500899911833 Marionette DEBUG Accepted connection 398 from 127.0.0.1:49829
05:38:31 INFO - 1500899911834 Marionette TRACE 398 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:38:31 INFO - 1500899911835 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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}
05:38:31 INFO - 1500899911838 Marionette DEBUG Register listener.js for window 12
05:38:31 INFO - 1500899911841 Marionette TRACE 398 <- [1,1,null,{"sessionId":"72968c9d-ca1b-49f6-8cf0-53aca24ffb7b","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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}}]
05:38:31 INFO - 1500899911843 Marionette TRACE 398 -> [0,2,"deleteSession",{}]
05:38:31 INFO - 1500899911845 Marionette TRACE 398 <- [1,2,null,{}]
05:38:31 INFO - 1500899911847 Marionette DEBUG Closed connection 398
05:38:31 INFO - 1500899911848 Marionette DEBUG Accepted connection 399 from 127.0.0.1:49830
05:38:31 INFO - 1500899911849 Marionette DEBUG Closed connection 399
05:38:31 INFO - 1500899911849 Marionette DEBUG Accepted connection 400 from 127.0.0.1:49831
05:38:31 INFO - 1500899911850 Marionette TRACE 400 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
05:38:31 INFO - 1500899911851 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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}
05:38:31 INFO - 1500899911854 Marionette DEBUG Register listener.js for window 12
05:38:31 INFO - 1500899911857 Marionette TRACE 400 <- [1,1,null,{"sessionId":"23df6a4d-dfaa-42fe-8a41-754fd5dbb3e5","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":2772,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpo__f4p.mozrunner","moz:accessibilityChecks":false}}]
05:38:31 INFO - 1500899911860 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"}]
05:38:31 INFO - 1500899911862 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"
05:38:31 INFO - 1500899911864 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"
05:38:31 INFO - 1500899911864 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"
05:38:31 INFO - 1500899911888 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"
05:38:31 INFO - 1500899911890 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"
05:38:31 INFO - 1500899911900 Marionette TRACE 400 <- [1,2,null,{}]
05:38:31 INFO - 1500899911901 Marionette TRACE 400 -> [0,3,"findElement",{"using":"tag name","value":"button"}]
05:38:31 INFO - 1500899911904 Marionette TRACE 400 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"19ad28ae-78e6-49b4-80a4-f774ddaef193","ELEMENT":"19ad28ae-78e6-49b4-80a4-f774ddaef193"}}]
05:38:31 INFO - 1500899911905 Marionette TRACE 400 -> [0,4,"getElementValueOfCssProperty",{"propertyName":"pointer-events","id":"19ad28ae-78e6-49b4-80a4-f774ddaef193"}]
05:38:31 INFO - 1500899911930 Marionette TRACE 400 <- [1,4,null,{"value":"none"}]
05:38:31 INFO - 1500899911931 Marionette TRACE 400 -> [0,5,"clickElement",{"id":"19ad28ae-78e6-49b4-80a4-f774ddaef193"}]
05:38:31 INFO - 1500899911954 Marionette TRACE 400 <- [1,5,{"error":"element click intercepted","message":"Element