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]
01:54:45 INFO - 1499676885270 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}]
01:54:45 INFO - TEST-END: test_click.py TestClick.test_clicking_an_element_that_is_not_displayed_raises1499676885274 Marionette TRACE 352 <- [1,5,null,{"value":null}]
01:54:45 INFO - 1499676885276 Marionette TRACE 352 -> [0,6,"deleteSession",{}]
01:54:45 INFO - 1499676885278 Marionette TRACE 352 <- [1,6,null,{}]
01:54:45 INFO - TEST-PASS | test_click.py TestClick.test_clicking_an_element_that_is_not_displayed_raises | took 234ms
01:54:45 INFO - TEST-START | test_click.py TestClick.test_clicking_on_a_multiline_link
01:54:45 INFO - 1499676885281 Marionette DEBUG Closed connection 352
01:54:45 INFO - 1499676885282 Marionette DEBUG Accepted connection 353 from 127.0.0.1:49811
01:54:45 INFO - 1499676885283 Marionette DEBUG Closed connection 353
01:54:45 INFO - 1499676885285 Marionette DEBUG Accepted connection 354 from 127.0.0.1:49812
01:54:45 INFO - 1499676885286 Marionette TRACE 354 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
01:54:45 INFO - 1499676885287 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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}
01:54:45 INFO - 1499676885291 Marionette DEBUG Register listener.js for window 12
01:54:45 INFO - 1499676885295 Marionette TRACE 354 <- [1,1,null,{"sessionId":"7e6aaf0a-1957-420c-85c4-7c90088a22cb","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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}}]
01:54:45 INFO - 1499676885298 Marionette TRACE 354 -> [0,2,"setTimeouts",{"script":30000}]
01:54:45 INFO - 1499676885299 Marionette TRACE 354 <- [1,2,null,{}]
01:54:45 INFO - 1499676885300 Marionette TRACE 354 -> [0,3,"setTimeouts",{"pageLoad":300000}]
01:54:45 INFO - 1499676885301 Marionette TRACE 354 <- [1,3,null,{}]
01:54:45 INFO - 1499676885302 Marionette TRACE 354 -> [0,4,"setTimeouts",{"implicit":0}]
01:54:45 INFO - 1499676885303 Marionette TRACE 354 <- [1,4,null,{}]
01:54:45 INFO - 1499676885305 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}]
01:54:45 INFO - TEST-START: test_click.py TestClick.test_clicking_on_a_multiline_link1499676885309 Marionette TRACE 354 <- [1,5,null,{"value":null}]
01:54:45 INFO - 1499676885311 Marionette TRACE 354 -> [0,6,"deleteSession",{}]
01:54:45 INFO - 1499676885313 Marionette TRACE 354 <- [1,6,null,{}]
01:54:45 INFO - 1499676885316 Marionette DEBUG Closed connection 354
01:54:45 INFO - 1499676885317 Marionette DEBUG Accepted connection 355 from 127.0.0.1:49813
01:54:45 INFO - 1499676885318 Marionette DEBUG Closed connection 355
01:54:45 INFO - 1499676885319 Marionette DEBUG Accepted connection 356 from 127.0.0.1:49814
01:54:45 INFO - 1499676885320 Marionette TRACE 356 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
01:54:45 INFO - 1499676885321 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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}
01:54:45 INFO - 1499676885325 Marionette DEBUG Register listener.js for window 12
01:54:45 INFO - 1499676885329 Marionette TRACE 356 <- [1,1,null,{"sessionId":"c43d1ca1-8c0e-4073-970a-fd72e6fa5d3f","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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}}]
01:54:45 INFO - 1499676885332 Marionette TRACE 356 -> [0,2,"deleteSession",{}]
01:54:45 INFO - 1499676885334 Marionette TRACE 356 <- [1,2,null,{}]
01:54:45 INFO - 1499676885337 Marionette DEBUG Closed connection 356
01:54:45 INFO - 1499676885338 Marionette DEBUG Accepted connection 357 from 127.0.0.1:49815
01:54:45 INFO - 1499676885339 Marionette DEBUG Closed connection 357
01:54:45 INFO - 1499676885340 Marionette DEBUG Accepted connection 358 from 127.0.0.1:49816
01:54:45 INFO - 1499676885342 Marionette TRACE 358 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
01:54:45 INFO - 1499676885343 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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}
01:54:45 INFO - 1499676885346 Marionette DEBUG Register listener.js for window 12
01:54:45 INFO - 1499676885359 Marionette TRACE 358 <- [1,1,null,{"sessionId":"9ec20b73-d259-427b-8b99-a4c73d56cee8","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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}}]
01:54:45 INFO - 1499676885362 Marionette TRACE 358 -> [0,2,"get",{"url":"http://127.0.0.1:49378/clicks.html"}]
01:54:45 INFO - 1499676885364 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49378/hidden.html"
01:54:45 INFO - 1499676885377 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49378/hidden.html"
01:54:45 INFO - 1499676885377 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49378/hidden.html"
01:54:45 INFO - 1499676885400 Marionette DEBUG Received DOM event "DOMContentLoaded" for "http://127.0.0.1:49378/clicks.html"
01:54:45 INFO - 1499676885420 Marionette DEBUG Received DOM event "pageshow" for "http://127.0.0.1:49378/clicks.html"
01:54:45 INFO - 1499676885431 Marionette TRACE 358 <- [1,2,null,{}]
01:54:45 INFO - 1499676885434 Marionette TRACE 358 -> [0,3,"findElement",{"using":"id","value":"overflowLink"}]
01:54:45 INFO - 1499676885438 Marionette TRACE 358 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"ae820068-3658-4fb4-bf04-1444dfa04eae","ELEMENT":"ae820068-3658-4fb4-bf04-1444dfa04eae"}}]
01:54:45 INFO - 1499676885440 Marionette TRACE 358 -> [0,4,"clickElement",{"id":"ae820068-3658-4fb4-bf04-1444dfa04eae"}]
01:54:45 INFO - 1499676885492 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49378/clicks.html"
01:54:45 INFO - 1499676885498 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49378/clicks.html"
01:54:45 INFO - 1499676885499 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49378/clicks.html"
01:54:45 INFO - 1499676885532 Marionette DEBUG Received DOM event "DOMContentLoaded" for "http://127.0.0.1:49378/test.html"
01:54:45 INFO - 1499676885535 Marionette DEBUG Received DOM event "pageshow" for "http://127.0.0.1:49378/test.html"
01:54:45 INFO - 1499676885538 Marionette TRACE 358 <- [1,4,null,{}]
01:54:45 INFO - 1499676885551 Marionette TRACE 358 -> [0,5,"findElement",{"using":"id","value":"testDiv"}]
01:54:45 INFO - 1499676885555 Marionette TRACE 358 <- [1,5,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"91a4a93d-7d2b-4969-8645-d5e0ddbc7c89","ELEMENT":"91a4a93d-7d2b-4969-8645-d5e0ddbc7c89"}}]
01:54:45 INFO - 1499676885557 Marionette TRACE 358 -> [0,6,"getTitle",{}]
01:54:45 INFO - 1499676885558 Marionette TRACE 358 <- [1,6,null,{"value":"Marionette Test"}]
01:54:45 INFO - 1499676885561 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}]
01:54:45 INFO - TEST-END: test_click.py TestClick.test_clicking_on_a_multiline_link1499676885565 Marionette TRACE 358 <- [1,7,null,{"value":null}]
01:54:45 INFO - 1499676885566 Marionette TRACE 358 -> [0,8,"deleteSession",{}]
01:54:45 INFO - 1499676885568 Marionette TRACE 358 <- [1,8,null,{}]
01:54:45 INFO - TEST-PASS | test_click.py TestClick.test_clicking_on_a_multiline_link | took 290ms
01:54:45 INFO - TEST-START | test_click.py TestClick.test_container_element
01:54:45 INFO - 1499676885571 Marionette DEBUG Closed connection 358
01:54:45 INFO - 1499676885572 Marionette DEBUG Accepted connection 359 from 127.0.0.1:49819
01:54:45 INFO - 1499676885573 Marionette DEBUG Closed connection 359
01:54:45 INFO - 1499676885575 Marionette DEBUG Accepted connection 360 from 127.0.0.1:49820
01:54:45 INFO - 1499676885576 Marionette TRACE 360 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
01:54:45 INFO - 1499676885577 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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}
01:54:45 INFO - 1499676885580 Marionette DEBUG Register listener.js for window 12
01:54:45 INFO - 1499676885585 Marionette TRACE 360 <- [1,1,null,{"sessionId":"8cd5dedd-debc-4c27-b95b-97147a20b54a","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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}}]
01:54:45 INFO - 1499676885588 Marionette TRACE 360 -> [0,2,"setTimeouts",{"script":30000}]
01:54:45 INFO - 1499676885588 Marionette TRACE 360 <- [1,2,null,{}]
01:54:45 INFO - 1499676885589 Marionette TRACE 360 -> [0,3,"setTimeouts",{"pageLoad":300000}]
01:54:45 INFO - 1499676885590 Marionette TRACE 360 <- [1,3,null,{}]
01:54:45 INFO - 1499676885592 Marionette TRACE 360 -> [0,4,"setTimeouts",{"implicit":0}]
01:54:45 INFO - 1499676885592 Marionette TRACE 360 <- [1,4,null,{}]
01:54:45 INFO - 1499676885595 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}]
01:54:45 INFO - TEST-START: test_click.py TestClick.test_container_element1499676885599 Marionette TRACE 360 <- [1,5,null,{"value":null}]
01:54:45 INFO - 1499676885600 Marionette TRACE 360 -> [0,6,"deleteSession",{}]
01:54:45 INFO - 1499676885602 Marionette TRACE 360 <- [1,6,null,{}]
01:54:45 INFO - 1499676885606 Marionette DEBUG Closed connection 360
01:54:45 INFO - 1499676885606 Marionette DEBUG Accepted connection 361 from 127.0.0.1:49821
01:54:45 INFO - 1499676885608 Marionette DEBUG Closed connection 361
01:54:45 INFO - 1499676885609 Marionette DEBUG Accepted connection 362 from 127.0.0.1:49822
01:54:45 INFO - 1499676885610 Marionette TRACE 362 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
01:54:45 INFO - 1499676885611 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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}
01:54:45 INFO - 1499676885614 Marionette DEBUG Register listener.js for window 12
01:54:45 INFO - 1499676885619 Marionette TRACE 362 <- [1,1,null,{"sessionId":"3f426fb3-26bb-4395-b9af-f28a3fc443e0","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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}}]
01:54:45 INFO - 1499676885621 Marionette TRACE 362 -> [0,2,"deleteSession",{}]
01:54:45 INFO - 1499676885623 Marionette TRACE 362 <- [1,2,null,{}]
01:54:45 INFO - 1499676885627 Marionette DEBUG Closed connection 362
01:54:45 INFO - 1499676885628 Marionette DEBUG Accepted connection 363 from 127.0.0.1:49823
01:54:45 INFO - 1499676885629 Marionette DEBUG Closed connection 363
01:54:45 INFO - 1499676885630 Marionette DEBUG Accepted connection 364 from 127.0.0.1:49824
01:54:45 INFO - 1499676885632 Marionette TRACE 364 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
01:54:45 INFO - 1499676885633 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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}
01:54:45 INFO - 1499676885636 Marionette DEBUG Register listener.js for window 12
01:54:45 INFO - 1499676885641 Marionette TRACE 364 <- [1,1,null,{"sessionId":"de4462b3-b52a-42ed-ba5f-6ef7afa4ed63","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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}}]
01:54:45 INFO - 1499676885644 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"}]
01:54:45 INFO - 1499676885646 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49378/test.html"
01:54:45 INFO - 1499676885649 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49378/test.html"
01:54:45 INFO - 1499676885650 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49378/test.html"
01:54:45 INFO - 1499676885682 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"
01:54:45 INFO - 1499676885690 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"
01:54:45 INFO - 1499676885705 Marionette TRACE 364 <- [1,2,null,{}]
01:54:45 INFO - 1499676885708 Marionette TRACE 364 -> [0,3,"findElement",{"using":"tag name","value":"option"}]
01:54:45 INFO - 1499676885712 Marionette TRACE 364 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"37f6a8ad-f951-4572-a170-0946b848e9cc","ELEMENT":"37f6a8ad-f951-4572-a170-0946b848e9cc"}}]
01:54:45 INFO - 1499676885713 Marionette TRACE 364 -> [0,4,"clickElement",{"id":"37f6a8ad-f951-4572-a170-0946b848e9cc"}]
01:54:45 INFO - 1499676885969 Marionette DEBUG Canceled page load listener because no navigation has been detected
01:54:45 INFO - 1499676885970 Marionette TRACE 364 <- [1,4,null,{}]
01:54:45 INFO - 1499676885972 Marionette TRACE 364 -> [0,5,"getElementProperty",{"id":"37f6a8ad-f951-4572-a170-0946b848e9cc","name":"selected"}]
01:54:45 INFO - 1499676885978 Marionette TRACE 364 <- [1,5,null,{"value":true}]
01:54:45 INFO - 1499676885981 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}]
01:54:45 INFO - TEST-END: test_click.py TestClick.test_container_element1499676885985 Marionette TRACE 364 <- [1,6,null,{"value":null}]
01:54:45 INFO - 1499676885986 Marionette TRACE 364 -> [0,7,"deleteSession",{}]
01:54:45 INFO - 1499676885988 Marionette TRACE 364 <- [1,7,null,{}]
01:54:45 INFO - TEST-PASS | test_click.py TestClick.test_container_element | took 420ms
01:54:45 INFO - TEST-START | test_click.py TestClick.test_container_element_outside_view
01:54:45 INFO - 1499676885992 Marionette DEBUG Closed connection 364
01:54:45 INFO - 1499676885993 Marionette DEBUG Accepted connection 365 from 127.0.0.1:49825
01:54:45 INFO - 1499676885994 Marionette DEBUG Closed connection 365
01:54:45 INFO - 1499676885995 Marionette DEBUG Accepted connection 366 from 127.0.0.1:49826
01:54:45 INFO - 1499676885996 Marionette TRACE 366 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
01:54:45 INFO - 1499676885997 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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}
01:54:46 INFO - 1499676886000 Marionette DEBUG Register listener.js for window 12
01:54:46 INFO - 1499676886005 Marionette TRACE 366 <- [1,1,null,{"sessionId":"80f0a85f-a8f9-4ee3-8a61-4eda5dbc3bed","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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}}]
01:54:46 INFO - 1499676886009 Marionette TRACE 366 -> [0,2,"setTimeouts",{"script":30000}]
01:54:46 INFO - 1499676886010 Marionette TRACE 366 <- [1,2,null,{}]
01:54:46 INFO - 1499676886011 Marionette TRACE 366 -> [0,3,"setTimeouts",{"pageLoad":300000}]
01:54:46 INFO - 1499676886012 Marionette TRACE 366 <- [1,3,null,{}]
01:54:46 INFO - 1499676886013 Marionette TRACE 366 -> [0,4,"setTimeouts",{"implicit":0}]
01:54:46 INFO - 1499676886014 Marionette TRACE 366 <- [1,4,null,{}]
01:54:46 INFO - 1499676886033 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}]
01:54:46 INFO - TEST-START: test_click.py TestClick.test_container_element_outside_view1499676886038 Marionette TRACE 366 <- [1,5,null,{"value":null}]
01:54:46 INFO - 1499676886041 Marionette TRACE 366 -> [0,6,"deleteSession",{}]
01:54:46 INFO - 1499676886044 Marionette TRACE 366 <- [1,6,null,{}]
01:54:46 INFO - 1499676886058 Marionette DEBUG Closed connection 366
01:54:46 INFO - 1499676886059 Marionette DEBUG Accepted connection 367 from 127.0.0.1:49827
01:54:46 INFO - 1499676886061 Marionette DEBUG Closed connection 367
01:54:46 INFO - 1499676886063 Marionette DEBUG Accepted connection 368 from 127.0.0.1:49828
01:54:46 INFO - 1499676886065 Marionette TRACE 368 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
01:54:46 INFO - 1499676886069 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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}
01:54:46 INFO - 1499676886073 Marionette DEBUG Register listener.js for window 12
01:54:46 INFO - 1499676886081 Marionette TRACE 368 <- [1,1,null,{"sessionId":"7e9819a5-9c36-40a1-b37c-76b7f3aac830","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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}}]
01:54:46 INFO - 1499676886087 Marionette TRACE 368 -> [0,2,"deleteSession",{}]
01:54:46 INFO - 1499676886090 Marionette TRACE 368 <- [1,2,null,{}]
01:54:46 INFO - 1499676886095 Marionette DEBUG Closed connection 368
01:54:46 INFO - 1499676886096 Marionette DEBUG Accepted connection 369 from 127.0.0.1:49829
01:54:46 INFO - 1499676886098 Marionette DEBUG Closed connection 369
01:54:46 INFO - 1499676886100 Marionette DEBUG Accepted connection 370 from 127.0.0.1:49830
01:54:46 INFO - 1499676886101 Marionette TRACE 370 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
01:54:46 INFO - 1499676886103 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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}
01:54:46 INFO - 1499676886107 Marionette DEBUG Register listener.js for window 12
01:54:46 INFO - 1499676886114 Marionette TRACE 370 <- [1,1,null,{"sessionId":"188a4761-bd68-4105-add2-f37ac434547c","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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}}]
01:54:46 INFO - 1499676886118 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"}]
01:54:46 INFO - 1499676886122 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"
01:54:46 INFO - 1499676886127 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"
01:54:46 INFO - 1499676886127 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"
01:54:46 INFO - 1499676886161 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"
01:54:46 INFO - 1499676886165 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"
01:54:46 INFO - 1499676886183 Marionette TRACE 370 <- [1,2,null,{}]
01:54:46 INFO - 1499676886194 Marionette TRACE 370 -> [0,3,"findElement",{"using":"tag name","value":"option"}]
01:54:46 INFO - 1499676886199 Marionette TRACE 370 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"4c8b7693-b60c-4eeb-91c4-78b28de80710","ELEMENT":"4c8b7693-b60c-4eeb-91c4-78b28de80710"}}]
01:54:46 INFO - 1499676886201 Marionette TRACE 370 -> [0,4,"clickElement",{"id":"4c8b7693-b60c-4eeb-91c4-78b28de80710"}]
01:54:46 INFO - 1499676886466 Marionette DEBUG Canceled page load listener because no navigation has been detected
01:54:46 INFO - 1499676886467 Marionette TRACE 370 <- [1,4,null,{}]
01:54:46 INFO - 1499676886469 Marionette TRACE 370 -> [0,5,"getElementProperty",{"id":"4c8b7693-b60c-4eeb-91c4-78b28de80710","name":"selected"}]
01:54:46 INFO - 1499676886477 Marionette TRACE 370 <- [1,5,null,{"value":true}]
01:54:46 INFO - 1499676886480 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}]
01:54:46 INFO - TEST-END: test_click.py TestClick.test_container_element_outside_view1499676886485 Marionette TRACE 370 <- [1,6,null,{"value":null}]
01:54:46 INFO - 1499676886488 Marionette TRACE 370 -> [0,7,"deleteSession",{}]
01:54:46 INFO - TEST-PASS | test_click.py TestClick.test_container_element_outside_view | took 503ms
01:54:46 INFO - TEST-START | test_click.py TestClick.test_css_transforms
01:54:46 INFO - 1499676886492 Marionette TRACE 370 <- [1,7,null,{}]
01:54:46 INFO - 1499676886495 Marionette DEBUG Closed connection 370
01:54:46 INFO - 1499676886497 Marionette DEBUG Accepted connection 371 from 127.0.0.1:49831
01:54:46 INFO - 1499676886499 Marionette DEBUG Closed connection 371
01:54:46 INFO - 1499676886500 Marionette DEBUG Accepted connection 372 from 127.0.0.1:49832
01:54:46 INFO - 1499676886501 Marionette TRACE 372 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
01:54:46 INFO - 1499676886503 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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}
01:54:46 INFO - 1499676886506 Marionette DEBUG Register listener.js for window 12
01:54:46 INFO - 1499676886523 Marionette TRACE 372 <- [1,1,null,{"sessionId":"f92c7df1-335f-4dd3-bd4a-7cbf324763a4","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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}}]
01:54:46 INFO - 1499676886527 Marionette TRACE 372 -> [0,2,"setTimeouts",{"script":30000}]
01:54:46 INFO - 1499676886528 Marionette TRACE 372 <- [1,2,null,{}]
01:54:46 INFO - 1499676886529 Marionette TRACE 372 -> [0,3,"setTimeouts",{"pageLoad":300000}]
01:54:46 INFO - 1499676886530 Marionette TRACE 372 <- [1,3,null,{}]
01:54:46 INFO - 1499676886532 Marionette TRACE 372 -> [0,4,"setTimeouts",{"implicit":0}]
01:54:46 INFO - 1499676886533 Marionette TRACE 372 <- [1,4,null,{}]
01:54:46 INFO - 1499676886535 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}]
01:54:46 INFO - TEST-START: test_click.py TestClick.test_css_transforms1499676886540 Marionette TRACE 372 <- [1,5,null,{"value":null}]
01:54:46 INFO - 1499676886571 Marionette TRACE 372 -> [0,6,"deleteSession",{}]
01:54:46 INFO - 1499676886574 Marionette TRACE 372 <- [1,6,null,{}]
01:54:46 INFO - 1499676886577 Marionette DEBUG Closed connection 372
01:54:46 INFO - 1499676886579 Marionette DEBUG Accepted connection 373 from 127.0.0.1:49833
01:54:46 INFO - 1499676886580 Marionette DEBUG Closed connection 373
01:54:46 INFO - 1499676886581 Marionette DEBUG Accepted connection 374 from 127.0.0.1:49834
01:54:46 INFO - 1499676886583 Marionette TRACE 374 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
01:54:46 INFO - 1499676886584 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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}
01:54:46 INFO - 1499676886588 Marionette DEBUG Register listener.js for window 12
01:54:46 INFO - 1499676886599 Marionette TRACE 374 <- [1,1,null,{"sessionId":"848acee2-13db-4c6a-aba9-66d66c265211","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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}}]
01:54:46 INFO - 1499676886603 Marionette TRACE 374 -> [0,2,"deleteSession",{}]
01:54:46 INFO - 1499676886605 Marionette TRACE 374 <- [1,2,null,{}]
01:54:46 INFO - 1499676886692 Marionette DEBUG Closed connection 374
01:54:46 INFO - 1499676886693 Marionette DEBUG Accepted connection 375 from 127.0.0.1:49835
01:54:46 INFO - 1499676886696 Marionette DEBUG Closed connection 375
01:54:46 INFO - 1499676886697 Marionette DEBUG Accepted connection 376 from 127.0.0.1:49836
01:54:46 INFO - 1499676886699 Marionette TRACE 376 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
01:54:46 INFO - 1499676886703 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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}
01:54:46 INFO - 1499676886707 Marionette DEBUG Register listener.js for window 12
01:54:46 INFO - 1499676886714 Marionette TRACE 376 <- [1,1,null,{"sessionId":"5de6d03c-05e3-405d-a699-e0293a60cbf5","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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}}]
01:54:46 INFO - 1499676886766 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"}]
01:54:46 INFO - 1499676886769 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"
01:54:46 INFO - 1499676886775 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"
01:54:46 INFO - 1499676886777 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"
01:54:46 INFO - 1499676886810 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"
01:54:46 INFO - 1499676886815 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"
01:54:46 INFO - 1499676886822 Marionette TRACE 376 <- [1,2,null,{}]
01:54:46 INFO - 1499676886835 Marionette TRACE 376 -> [0,3,"findElement",{"using":"tag name","value":"div"}]
01:54:46 INFO - 1499676886842 Marionette TRACE 376 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"42dda5b4-645d-4af1-b33e-c9f3ae5b1bcd","ELEMENT":"42dda5b4-645d-4af1-b33e-c9f3ae5b1bcd"}}]
01:54:46 INFO - 1499676886850 Marionette TRACE 376 -> [0,4,"clickElement",{"id":"42dda5b4-645d-4af1-b33e-c9f3ae5b1bcd"}]
01:54:47 INFO - 1499676887106 Marionette DEBUG Canceled page load listener because no navigation has been detected
01:54:47 INFO - 1499676887107 Marionette TRACE 376 <- [1,4,null,{}]
01:54:47 INFO - 1499676887110 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}]
01:54:47 INFO - TEST-END: test_click.py TestClick.test_css_transforms1499676887116 Marionette TRACE 376 <- [1,5,null,{"value":null}]
01:54:47 INFO - 1499676887118 Marionette TRACE 376 -> [0,6,"deleteSession",{}]
01:54:47 INFO - 1499676887121 Marionette TRACE 376 <- [1,6,null,{}]
01:54:47 INFO - TEST-PASS | test_click.py TestClick.test_css_transforms | took 628ms
01:54:47 INFO - TEST-START | test_click.py TestClick.test_inclusive_descendant
01:54:47 INFO - 1499676887124 Marionette DEBUG Closed connection 376
01:54:47 INFO - 1499676887136 Marionette DEBUG Accepted connection 377 from 127.0.0.1:49837
01:54:47 INFO - 1499676887139 Marionette DEBUG Closed connection 377
01:54:47 INFO - 1499676887140 Marionette DEBUG Accepted connection 378 from 127.0.0.1:49838
01:54:47 INFO - 1499676887142 Marionette TRACE 378 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
01:54:47 INFO - 1499676887143 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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}
01:54:47 INFO - 1499676887147 Marionette DEBUG Register listener.js for window 12
01:54:47 INFO - 1499676887153 Marionette TRACE 378 <- [1,1,null,{"sessionId":"b022893e-2acd-401b-8598-40f75fdda56c","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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}}]
01:54:47 INFO - 1499676887158 Marionette TRACE 378 -> [0,2,"setTimeouts",{"script":30000}]
01:54:47 INFO - 1499676887159 Marionette TRACE 378 <- [1,2,null,{}]
01:54:47 INFO - 1499676887160 Marionette TRACE 378 -> [0,3,"setTimeouts",{"pageLoad":300000}]
01:54:47 INFO - 1499676887161 Marionette TRACE 378 <- [1,3,null,{}]
01:54:47 INFO - 1499676887163 Marionette TRACE 378 -> [0,4,"setTimeouts",{"implicit":0}]
01:54:47 INFO - 1499676887164 Marionette TRACE 378 <- [1,4,null,{}]
01:54:47 INFO - 1499676887168 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}]
01:54:47 INFO - TEST-START: test_click.py TestClick.test_inclusive_descendant1499676887174 Marionette TRACE 378 <- [1,5,null,{"value":null}]
01:54:47 INFO - 1499676887176 Marionette TRACE 378 -> [0,6,"deleteSession",{}]
01:54:47 INFO - 1499676887179 Marionette TRACE 378 <- [1,6,null,{}]
01:54:47 INFO - 1499676887199 Marionette DEBUG Closed connection 378
01:54:47 INFO - 1499676887201 Marionette DEBUG Accepted connection 379 from 127.0.0.1:49839
01:54:47 INFO - 1499676887206 Marionette DEBUG Closed connection 379
01:54:47 INFO - 1499676887208 Marionette DEBUG Accepted connection 380 from 127.0.0.1:49840
01:54:47 INFO - 1499676887209 Marionette TRACE 380 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
01:54:47 INFO - 1499676887211 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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}
01:54:47 INFO - 1499676887214 Marionette DEBUG Register listener.js for window 12
01:54:47 INFO - 1499676887221 Marionette TRACE 380 <- [1,1,null,{"sessionId":"751e6601-2bdd-4128-bb30-f2128480b641","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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}}]
01:54:47 INFO - 1499676887226 Marionette TRACE 380 -> [0,2,"deleteSession",{}]
01:54:47 INFO - 1499676887229 Marionette TRACE 380 <- [1,2,null,{}]
01:54:47 INFO - 1499676887232 Marionette DEBUG Closed connection 380
01:54:47 INFO - 1499676887233 Marionette DEBUG Accepted connection 381 from 127.0.0.1:49841
01:54:47 INFO - 1499676887235 Marionette DEBUG Closed connection 381
01:54:47 INFO - 1499676887236 Marionette DEBUG Accepted connection 382 from 127.0.0.1:49842
01:54:47 INFO - 1499676887238 Marionette TRACE 382 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
01:54:47 INFO - 1499676887239 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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}
01:54:47 INFO - 1499676887243 Marionette DEBUG Register listener.js for window 12
01:54:47 INFO - 1499676887248 Marionette TRACE 382 <- [1,1,null,{"sessionId":"c3d10f59-b01f-492e-9ce2-3b1afb926f1a","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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}}]
01:54:47 INFO - 1499676887253 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"}]
01:54:47 INFO - 1499676887255 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"
01:54:47 INFO - 1499676887260 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"
01:54:47 INFO - 1499676887261 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"
01:54:47 INFO - 1499676887295 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"
01:54:47 INFO - 1499676887298 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"
01:54:47 INFO - 1499676887305 Marionette TRACE 382 <- [1,2,null,{}]
01:54:47 INFO - 1499676887317 Marionette TRACE 382 -> [0,3,"findElement",{"using":"tag name","value":"select"}]
01:54:47 INFO - 1499676887322 Marionette TRACE 382 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"af3f1025-89b2-4212-ac06-b2f56b00dbe5","ELEMENT":"af3f1025-89b2-4212-ac06-b2f56b00dbe5"}}]
01:54:47 INFO - 1499676887359 Marionette TRACE 382 -> [0,4,"clickElement",{"id":"af3f1025-89b2-4212-ac06-b2f56b00dbe5"}]
01:54:47 INFO - 1499676887616 Marionette DEBUG Canceled page load listener because no navigation has been detected
01:54:47 INFO - 1499676887617 Marionette TRACE 382 <- [1,4,null,{}]
01:54:47 INFO - 1499676887620 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}]
01:54:47 INFO - TEST-END: test_click.py TestClick.test_inclusive_descendant1499676887625 Marionette TRACE 382 <- [1,5,null,{"value":null}]
01:54:47 INFO - 1499676887626 Marionette TRACE 382 -> [0,6,"deleteSession",{}]
01:54:47 INFO - 1499676887628 Marionette TRACE 382 <- [1,6,null,{}]
01:54:47 INFO - TEST-PASS | test_click.py TestClick.test_inclusive_descendant | took 507ms
01:54:47 INFO - TEST-START | test_click.py TestClick.test_input_file
01:54:47 INFO - 1499676887632 Marionette DEBUG Closed connection 382
01:54:47 INFO - 1499676887633 Marionette DEBUG Accepted connection 383 from 127.0.0.1:49843
01:54:47 INFO - 1499676887634 Marionette DEBUG Closed connection 383
01:54:47 INFO - 1499676887635 Marionette DEBUG Accepted connection 384 from 127.0.0.1:49844
01:54:47 INFO - 1499676887637 Marionette TRACE 384 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
01:54:47 INFO - 1499676887639 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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}
01:54:47 INFO - 1499676887643 Marionette DEBUG Register listener.js for window 12
01:54:47 INFO - 1499676887649 Marionette TRACE 384 <- [1,1,null,{"sessionId":"95e055f1-e845-4543-be72-8d6b268a309d","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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}}]
01:54:47 INFO - 1499676887652 Marionette TRACE 384 -> [0,2,"setTimeouts",{"script":30000}]
01:54:47 INFO - 1499676887653 Marionette TRACE 384 <- [1,2,null,{}]
01:54:47 INFO - 1499676887654 Marionette TRACE 384 -> [0,3,"setTimeouts",{"pageLoad":300000}]
01:54:47 INFO - 1499676887655 Marionette TRACE 384 <- [1,3,null,{}]
01:54:47 INFO - 1499676887657 Marionette TRACE 384 -> [0,4,"setTimeouts",{"implicit":0}]
01:54:47 INFO - 1499676887657 Marionette TRACE 384 <- [1,4,null,{}]
01:54:47 INFO - 1499676887660 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}]
01:54:47 INFO - TEST-START: test_click.py TestClick.test_input_file1499676887664 Marionette TRACE 384 <- [1,5,null,{"value":null}]
01:54:47 INFO - 1499676887666 Marionette TRACE 384 -> [0,6,"deleteSession",{}]
01:54:47 INFO - 1499676887668 Marionette TRACE 384 <- [1,6,null,{}]
01:54:47 INFO - 1499676887673 Marionette DEBUG Closed connection 384
01:54:47 INFO - 1499676887675 Marionette DEBUG Accepted connection 385 from 127.0.0.1:49845
01:54:47 INFO - 1499676887677 Marionette DEBUG Closed connection 385
01:54:47 INFO - 1499676887678 Marionette DEBUG Accepted connection 386 from 127.0.0.1:49846
01:54:47 INFO - 1499676887680 Marionette TRACE 386 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
01:54:47 INFO - 1499676887681 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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}
01:54:47 INFO - 1499676887684 Marionette DEBUG Register listener.js for window 12
01:54:47 INFO - 1499676887690 Marionette TRACE 386 <- [1,1,null,{"sessionId":"e41a079c-a320-4181-890d-ce9b79e4579a","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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}}]
01:54:47 INFO - 1499676887693 Marionette TRACE 386 -> [0,2,"deleteSession",{}]
01:54:47 INFO - 1499676887696 Marionette TRACE 386 <- [1,2,null,{}]
01:54:47 INFO - 1499676887754 Marionette DEBUG Closed connection 386
01:54:47 INFO - 1499676887755 Marionette DEBUG Accepted connection 387 from 127.0.0.1:49847
01:54:47 INFO - 1499676887773 Marionette DEBUG Closed connection 387
01:54:47 INFO - 1499676887774 Marionette DEBUG Accepted connection 388 from 127.0.0.1:49848
01:54:47 INFO - 1499676887787 Marionette TRACE 388 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
01:54:47 INFO - 1499676887788 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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}
01:54:47 INFO - 1499676887792 Marionette DEBUG Register listener.js for window 12
01:54:47 INFO - 1499676887796 Marionette TRACE 388 <- [1,1,null,{"sessionId":"05802b6d-ebe6-4777-8dc6-9244dba79f73","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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}}]
01:54:47 INFO - 1499676887799 Marionette TRACE 388 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"}]
01:54:47 INFO - 1499676887803 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"
01:54:47 INFO - 1499676887807 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"
01:54:47 INFO - 1499676887808 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"
01:54:47 INFO - 1499676887837 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
01:54:47 INFO - 1499676887848 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
01:54:47 INFO - 1499676887855 Marionette TRACE 388 <- [1,2,null,{}]
01:54:47 INFO - 1499676887877 Marionette TRACE 388 -> [0,3,"findElement",{"using":"tag name","value":"input"}]
01:54:47 INFO - 1499676887882 Marionette TRACE 388 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"7b76dc54-c1a7-49b6-8509-021548037d91","ELEMENT":"7b76dc54-c1a7-49b6-8509-021548037d91"}}]
01:54:47 INFO - 1499676887883 Marionette TRACE 388 -> [0,4,"clickElement",{"id":"7b76dc54-c1a7-49b6-8509-021548037d91"}]
01:54:47 INFO - 1499676887918 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]
01:54:47 INFO - 1499676887933 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}]
01:54:47 INFO - TEST-END: test_click.py TestClick.test_input_file1499676887938 Marionette TRACE 388 <- [1,5,null,{"value":null}]
01:54:47 INFO - TEST-PASS | test_click.py TestClick.test_input_file | took 361ms
01:54:47 INFO - TEST-START | test_click.py TestClick.test_obscured_element
01:54:47 INFO - 1499676887988 Marionette TRACE 388 -> [0,6,"deleteSession",{}]
01:54:47 INFO - 1499676887990 Marionette TRACE 388 <- [1,6,null,{}]
01:54:48 INFO - 1499676888043 Marionette DEBUG Closed connection 388
01:54:48 INFO - 1499676888044 Marionette DEBUG Accepted connection 389 from 127.0.0.1:49849
01:54:48 INFO - 1499676888051 Marionette DEBUG Closed connection 389
01:54:48 INFO - 1499676888052 Marionette DEBUG Accepted connection 390 from 127.0.0.1:49850
01:54:48 INFO - 1499676888075 Marionette TRACE 390 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
01:54:48 INFO - 1499676888077 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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}
01:54:48 INFO - 1499676888080 Marionette DEBUG Register listener.js for window 12
01:54:48 INFO - 1499676888095 Marionette TRACE 390 <- [1,1,null,{"sessionId":"f56c98cc-e4eb-4427-ab52-c14c843ef0e8","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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}}]
01:54:48 INFO - 1499676888098 Marionette TRACE 390 -> [0,2,"setTimeouts",{"script":30000}]
01:54:48 INFO - 1499676888099 Marionette TRACE 390 <- [1,2,null,{}]
01:54:48 INFO - 1499676888102 Marionette TRACE 390 -> [0,3,"setTimeouts",{"pageLoad":300000}]
01:54:48 INFO - 1499676888103 Marionette TRACE 390 <- [1,3,null,{}]
01:54:48 INFO - 1499676888105 Marionette TRACE 390 -> [0,4,"setTimeouts",{"implicit":0}]
01:54:48 INFO - 1499676888106 Marionette TRACE 390 <- [1,4,null,{}]
01:54:48 INFO - 1499676888108 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}]
01:54:48 INFO - TEST-START: test_click.py TestClick.test_obscured_element1499676888113 Marionette TRACE 390 <- [1,5,null,{"value":null}]
01:54:48 INFO - 1499676888115 Marionette TRACE 390 -> [0,6,"deleteSession",{}]
01:54:48 INFO - 1499676888117 Marionette TRACE 390 <- [1,6,null,{}]
01:54:48 INFO - 1499676888120 Marionette DEBUG Closed connection 390
01:54:48 INFO - 1499676888121 Marionette DEBUG Accepted connection 391 from 127.0.0.1:49851
01:54:48 INFO - 1499676888122 Marionette DEBUG Closed connection 391
01:54:48 INFO - 1499676888124 Marionette DEBUG Accepted connection 392 from 127.0.0.1:49852
01:54:48 INFO - 1499676888126 Marionette TRACE 392 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
01:54:48 INFO - 1499676888127 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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}
01:54:48 INFO - 1499676888130 Marionette DEBUG Register listener.js for window 12
01:54:48 INFO - 1499676888135 Marionette TRACE 392 <- [1,1,null,{"sessionId":"1bf6c29d-0cc8-4d33-a02e-590b483ba35d","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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}}]
01:54:48 INFO - 1499676888138 Marionette TRACE 392 -> [0,2,"deleteSession",{}]
01:54:48 INFO - 1499676888140 Marionette TRACE 392 <- [1,2,null,{}]
01:54:48 INFO - 1499676888144 Marionette DEBUG Closed connection 392
01:54:48 INFO - 1499676888145 Marionette DEBUG Accepted connection 393 from 127.0.0.1:49853
01:54:48 INFO - 1499676888146 Marionette DEBUG Closed connection 393
01:54:48 INFO - 1499676888147 Marionette DEBUG Accepted connection 394 from 127.0.0.1:49854
01:54:48 INFO - 1499676888149 Marionette TRACE 394 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
01:54:48 INFO - 1499676888150 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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}
01:54:48 INFO - 1499676888153 Marionette DEBUG Register listener.js for window 12
01:54:48 INFO - 1499676888158 Marionette TRACE 394 <- [1,1,null,{"sessionId":"5ac86d1e-e9f1-4434-a5ed-80c7a6a00848","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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}}]
01:54:48 INFO - 1499676888161 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"}]
01:54:48 INFO - 1499676888164 Marionette DEBUG Received DOM event "beforeunload" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
01:54:48 INFO - 1499676888169 Marionette DEBUG Received DOM event "pagehide" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
01:54:48 INFO - 1499676888169 Marionette DEBUG Received DOM event "unload" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
01:54:48 INFO - 1499676888212 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"
01:54:48 INFO - 1499676888216 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"
01:54:48 INFO - 1499676888222 Marionette TRACE 394 <- [1,2,null,{}]
01:54:48 INFO - 1499676888233 Marionette TRACE 394 -> [0,3,"findElement",{"using":"id","value":"overlay"}]
01:54:48 INFO - 1499676888237 Marionette TRACE 394 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"79063a94-f647-4e5d-9878-d180aba2c124","ELEMENT":"79063a94-f647-4e5d-9878-d180aba2c124"}}]
01:54:48 INFO - 1499676888239 Marionette TRACE 394 -> [0,4,"findElement",{"using":"id","value":"obscured"}]
01:54:48 INFO - 1499676888243 Marionette TRACE 394 <- [1,4,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"81511d1d-4575-4179-b6d3-763af35979d1","ELEMENT":"81511d1d-4575-4179-b6d3-763af35979d1"}}]
01:54:48 INFO - 1499676888245 Marionette TRACE 394 -> [0,5,"clickElement",{"id":"79063a94-f647-4e5d-9878-d180aba2c124"}]
01:54:48 INFO - 1499676888503 Marionette DEBUG Canceled page load listener because no navigation has been detected
01:54:48 INFO - 1499676888504 Marionette TRACE 394 <- [1,5,null,{}]
01:54:48 INFO - 1499676888505 Marionette TRACE 394 -> [0,6,"clickElement",{"id":"81511d1d-4575-4179-b6d3-763af35979d1"}]
01:54:48 INFO - 1499676888529 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]
01:54:48 INFO - 1499676888532 Marionette TRACE 394 -> [0,7,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"test_click.py","script":"return window.clicked","sandbox":null,"line":257}]
01:54:48 INFO - 1499676888536 Marionette TRACE 394 <- [1,7,null,{"value":false}]
01:54:48 INFO - 1499676888539 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}]
01:54:48 INFO - TEST-END: test_click.py TestClick.test_obscured_element1499676888543 Marionette TRACE 394 <- [1,8,null,{"value":null}]
01:54:48 INFO - 1499676888544 Marionette TRACE 394 -> [0,9,"deleteSession",{}]
01:54:48 INFO - 1499676888546 Marionette TRACE 394 <- [1,9,null,{}]
01:54:48 INFO - TEST-PASS | test_click.py TestClick.test_obscured_element | took 555ms
01:54:48 INFO - TEST-START | test_click.py TestClick.test_pointer_events_none
01:54:48 INFO - 1499676888549 Marionette DEBUG Closed connection 394
01:54:48 INFO - 1499676888550 Marionette DEBUG Accepted connection 395 from 127.0.0.1:49855
01:54:48 INFO - 1499676888551 Marionette DEBUG Closed connection 395
01:54:48 INFO - 1499676888554 Marionette DEBUG Accepted connection 396 from 127.0.0.1:49856
01:54:48 INFO - 1499676888557 Marionette TRACE 396 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
01:54:48 INFO - 1499676888558 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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}
01:54:48 INFO - 1499676888563 Marionette DEBUG Register listener.js for window 12
01:54:48 INFO - 1499676888569 Marionette TRACE 396 <- [1,1,null,{"sessionId":"7f477dcf-2b60-451f-bc95-bfae2b461de5","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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}}]
01:54:48 INFO - 1499676888573 Marionette TRACE 396 -> [0,2,"setTimeouts",{"script":30000}]
01:54:48 INFO - 1499676888574 Marionette TRACE 396 <- [1,2,null,{}]
01:54:48 INFO - 1499676888575 Marionette TRACE 396 -> [0,3,"setTimeouts",{"pageLoad":300000}]
01:54:48 INFO - 1499676888577 Marionette TRACE 396 <- [1,3,null,{}]
01:54:48 INFO - 1499676888578 Marionette TRACE 396 -> [0,4,"setTimeouts",{"implicit":0}]
01:54:48 INFO - 1499676888579 Marionette TRACE 396 <- [1,4,null,{}]
01:54:48 INFO - 1499676888581 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}]
01:54:48 INFO - TEST-START: test_click.py TestClick.test_pointer_events_none1499676888586 Marionette TRACE 396 <- [1,5,null,{"value":null}]
01:54:48 INFO - 1499676888587 Marionette TRACE 396 -> [0,6,"deleteSession",{}]
01:54:48 INFO - 1499676888589 Marionette TRACE 396 <- [1,6,null,{}]
01:54:48 INFO - 1499676888593 Marionette DEBUG Closed connection 396
01:54:48 INFO - 1499676888594 Marionette DEBUG Accepted connection 397 from 127.0.0.1:49857
01:54:48 INFO - 1499676888595 Marionette DEBUG Closed connection 397
01:54:48 INFO - 1499676888596 Marionette DEBUG Accepted connection 398 from 127.0.0.1:49858
01:54:48 INFO - 1499676888597 Marionette TRACE 398 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
01:54:48 INFO - 1499676888598 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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}
01:54:48 INFO - 1499676888602 Marionette DEBUG Register listener.js for window 12
01:54:48 INFO - 1499676888607 Marionette TRACE 398 <- [1,1,null,{"sessionId":"68bb7ece-358d-4bad-86e1-d8285f9ac3e4","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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}}]
01:54:48 INFO - 1499676888610 Marionette TRACE 398 -> [0,2,"deleteSession",{}]
01:54:48 INFO - 1499676888612 Marionette TRACE 398 <- [1,2,null,{}]
01:54:48 INFO - 1499676888615 Marionette DEBUG Closed connection 398
01:54:48 INFO - 1499676888616 Marionette DEBUG Accepted connection 399 from 127.0.0.1:49859
01:54:48 INFO - 1499676888618 Marionette DEBUG Closed connection 399
01:54:48 INFO - 1499676888619 Marionette DEBUG Accepted connection 400 from 127.0.0.1:49860
01:54:48 INFO - 1499676888620 Marionette TRACE 400 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
01:54:48 INFO - 1499676888621 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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}
01:54:48 INFO - 1499676888625 Marionette DEBUG Register listener.js for window 12
01:54:48 INFO - 1499676888629 Marionette TRACE 400 <- [1,1,null,{"sessionId":"14e8e765-7ed1-4efe-9a27-c521f49f7cda","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":1764,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpir6lp8.mozrunner","moz:accessibilityChecks":false}}]
01:54:48 INFO - 1499676888632 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"}]
01:54:48 INFO - 1499676888634 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"
01:54:48 INFO - 1499676888639 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"
01:54:48 INFO - 1499676888639 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"
01:54:48 INFO - 1499676888669 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"
01:54:48 INFO - 1499676888673 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"
01:54:48 INFO - 1499676888688 Marionette TRACE 400 <- [1,2,null,{}]
01:54:48 INFO - 1499676888691 Marionette TRACE 400 -> [0,3,"findElement",{"using":"tag name","value":"button"}]
01:54:48 INFO - 1499676888695 Marionette TRACE 400 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"2a032e40-1435-4e99-a874-405d4172fe11","ELEMENT":"2a032e40-1435-4e99-a874-405d4172fe11"}}]
01:54:48 INFO - 1499676888697 Marionette TRACE 400 -> [0,4,"getElementValueOfCssProperty",{"propertyName":"pointer-events","id":"2a032e40-1435-4e99-a874-405d4172fe11"}]
01:54:48 INFO - 1499676888725 Marionette TRACE 400 <- [1,4,null,{"value":"none"}]
01:54:48 INFO - 1499676888727 Marionette TRACE 400 -> [0,5,"clickElement",{"id":"2a032e40-1435-4e99-a874-405d4172fe11"}]
01:54:48 INFO - 1499676888752 Marionette TRACE 400 <- [1,5,{"error":"element click intercepted","message":"Element