could not be scrolled into view","stacktrace":"WebDriverError@chrome://marionette/content/error.js:226:5\nElementNotInteractableError@chrome://marionette/content/error.js:315:5\nwebdriverClickElement@chrome://marionette/content/interaction.js:183:11\nTaskImpl_run@resource://gre/modules/Task.jsm:331:42\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nTaskImpl_handleResultValue@resource://gre/modules/Task.jsm:401:16\nTaskImpl_run@resource://gre/modules/Task.jsm:339:15\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nTaskImpl_handleResultValue@resource://gre/modules/Task.jsm:401:16\nTaskImpl_run@resource://gre/modules/Task.jsm:339:15\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nnavigate@chrome://marionette/content/listener.js:397:12\nclickElement@chrome://marionette/content/listener.js:1317:5\n"},null]
16:00:17 INFO - 1499814017459 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}]
16:00:17 INFO - TEST-END: test_click.py TestClick.test_clicking_an_element_that_is_not_displayed_raises1499814017462 Marionette TRACE 352 <- [1,5,null,{"value":null}]
16:00:17 INFO - 1499814017463 Marionette TRACE 352 -> [0,6,"deleteSession",{}]
16:00:17 INFO - TEST-PASS | test_click.py TestClick.test_clicking_an_element_that_is_not_displayed_raises | took 183ms
16:00:17 INFO - 1499814017464 Marionette TRACE 352 <- [1,6,null,{}]
16:00:17 INFO - TEST-START | test_click.py TestClick.test_clicking_on_a_multiline_link
16:00:17 INFO - 1499814017467 Marionette DEBUG Closed connection 352
16:00:17 INFO - 1499814017468 Marionette DEBUG Accepted connection 353 from 127.0.0.1:49841
16:00:17 INFO - 1499814017469 Marionette DEBUG Closed connection 353
16:00:17 INFO - 1499814017469 Marionette DEBUG Accepted connection 354 from 127.0.0.1:49842
16:00:17 INFO - 1499814017471 Marionette TRACE 354 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
16:00:17 INFO - 1499814017471 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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}
16:00:17 INFO - 1499814017474 Marionette DEBUG Register listener.js for window 12
16:00:17 INFO - 1499814017478 Marionette TRACE 354 <- [1,1,null,{"sessionId":"5738be87-a7c8-447a-8d64-193a7ade159b","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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}}]
16:00:17 INFO - 1499814017480 Marionette TRACE 354 -> [0,2,"setTimeouts",{"script":30000}]
16:00:17 INFO - 1499814017480 Marionette TRACE 354 <- [1,2,null,{}]
16:00:17 INFO - 1499814017481 Marionette TRACE 354 -> [0,3,"setTimeouts",{"pageLoad":300000}]
16:00:17 INFO - 1499814017482 Marionette TRACE 354 <- [1,3,null,{}]
16:00:17 INFO - 1499814017483 Marionette TRACE 354 -> [0,4,"setTimeouts",{"implicit":0}]
16:00:17 INFO - 1499814017483 Marionette TRACE 354 <- [1,4,null,{}]
16:00:17 INFO - 1499814017485 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}]
16:00:17 INFO - TEST-START: test_click.py TestClick.test_clicking_on_a_multiline_link1499814017489 Marionette TRACE 354 <- [1,5,null,{"value":null}]
16:00:17 INFO - 1499814017490 Marionette TRACE 354 -> [0,6,"deleteSession",{}]
16:00:17 INFO - 1499814017492 Marionette TRACE 354 <- [1,6,null,{}]
16:00:17 INFO - 1499814017495 Marionette DEBUG Closed connection 354
16:00:17 INFO - 1499814017495 Marionette DEBUG Accepted connection 355 from 127.0.0.1:49843
16:00:17 INFO - 1499814017496 Marionette DEBUG Closed connection 355
16:00:17 INFO - 1499814017497 Marionette DEBUG Accepted connection 356 from 127.0.0.1:49844
16:00:17 INFO - 1499814017498 Marionette TRACE 356 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
16:00:17 INFO - 1499814017499 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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}
16:00:17 INFO - 1499814017502 Marionette DEBUG Register listener.js for window 12
16:00:17 INFO - 1499814017512 Marionette TRACE 356 <- [1,1,null,{"sessionId":"7caa134d-2e90-4932-b833-9b3649118a03","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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}}]
16:00:17 INFO - 1499814017515 Marionette TRACE 356 -> [0,2,"deleteSession",{}]
16:00:17 INFO - 1499814017516 Marionette TRACE 356 <- [1,2,null,{}]
16:00:17 INFO - 1499814017519 Marionette DEBUG Closed connection 356
16:00:17 INFO - 1499814017520 Marionette DEBUG Accepted connection 357 from 127.0.0.1:49845
16:00:17 INFO - 1499814017521 Marionette DEBUG Closed connection 357
16:00:17 INFO - 1499814017521 Marionette DEBUG Accepted connection 358 from 127.0.0.1:49846
16:00:17 INFO - 1499814017522 Marionette TRACE 358 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
16:00:17 INFO - 1499814017523 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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}
16:00:17 INFO - 1499814017526 Marionette DEBUG Register listener.js for window 12
16:00:17 INFO - 1499814017529 Marionette TRACE 358 <- [1,1,null,{"sessionId":"dade8037-5e92-4769-b9a7-1e8764d87ca8","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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}}]
16:00:17 INFO - 1499814017531 Marionette TRACE 358 -> [0,2,"get",{"url":"http://127.0.0.1:49405/clicks.html"}]
16:00:17 INFO - 1499814017533 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49405/hidden.html"
16:00:17 INFO - 1499814017540 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49405/hidden.html"
16:00:17 INFO - 1499814017540 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49405/hidden.html"
16:00:17 INFO - 1499814017567 Marionette DEBUG Received DOM event "DOMContentLoaded" for "http://127.0.0.1:49405/clicks.html"
16:00:17 INFO - 1499814017569 Marionette DEBUG Received DOM event "pageshow" for "http://127.0.0.1:49405/clicks.html"
16:00:17 INFO - 1499814017574 Marionette TRACE 358 <- [1,2,null,{}]
16:00:17 INFO - 1499814017575 Marionette TRACE 358 -> [0,3,"findElement",{"using":"id","value":"overflowLink"}]
16:00:17 INFO - 1499814017586 Marionette TRACE 358 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"8aef330b-2d50-41b4-9780-8915fb29503a","ELEMENT":"8aef330b-2d50-41b4-9780-8915fb29503a"}}]
16:00:17 INFO - 1499814017589 Marionette TRACE 358 -> [0,4,"clickElement",{"id":"8aef330b-2d50-41b4-9780-8915fb29503a"}]
16:00:17 INFO - 1499814017637 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49405/clicks.html"
16:00:17 INFO - 1499814017649 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49405/clicks.html"
16:00:17 INFO - 1499814017650 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49405/clicks.html"
16:00:17 INFO - 1499814017684 Marionette DEBUG Received DOM event "DOMContentLoaded" for "http://127.0.0.1:49405/test.html"
16:00:17 INFO - 1499814017688 Marionette DEBUG Received DOM event "pageshow" for "http://127.0.0.1:49405/test.html"
16:00:17 INFO - 1499814017693 Marionette TRACE 358 <- [1,4,null,{}]
16:00:17 INFO - 1499814017703 Marionette TRACE 358 -> [0,5,"findElement",{"using":"id","value":"testDiv"}]
16:00:17 INFO - 1499814017706 Marionette TRACE 358 <- [1,5,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"85618787-12fe-4922-828c-2e0efd4d7f70","ELEMENT":"85618787-12fe-4922-828c-2e0efd4d7f70"}}]
16:00:17 INFO - 1499814017707 Marionette TRACE 358 -> [0,6,"getTitle",{}]
16:00:17 INFO - 1499814017708 Marionette TRACE 358 <- [1,6,null,{"value":"Marionette Test"}]
16:00:17 INFO - 1499814017710 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}]
16:00:17 INFO - TEST-END: test_click.py TestClick.test_clicking_on_a_multiline_link1499814017714 Marionette TRACE 358 <- [1,7,null,{"value":null}]
16:00:17 INFO - 1499814017721 Marionette TRACE 358 -> [0,8,"deleteSession",{}]
16:00:17 INFO - 1499814017722 Marionette TRACE 358 <- [1,8,null,{}]
16:00:17 INFO - TEST-PASS | test_click.py TestClick.test_clicking_on_a_multiline_link | took 257ms
16:00:17 INFO - TEST-START | test_click.py TestClick.test_container_element
16:00:17 INFO - 1499814017725 Marionette DEBUG Closed connection 358
16:00:17 INFO - 1499814017726 Marionette DEBUG Accepted connection 359 from 127.0.0.1:49849
16:00:17 INFO - 1499814017727 Marionette DEBUG Closed connection 359
16:00:17 INFO - 1499814017728 Marionette DEBUG Accepted connection 360 from 127.0.0.1:49850
16:00:17 INFO - 1499814017729 Marionette TRACE 360 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
16:00:17 INFO - 1499814017729 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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}
16:00:17 INFO - 1499814017732 Marionette DEBUG Register listener.js for window 12
16:00:17 INFO - 1499814017736 Marionette TRACE 360 <- [1,1,null,{"sessionId":"6d2d3461-a8af-48dc-9143-dcb6f6a1e60a","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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}}]
16:00:17 INFO - 1499814017738 Marionette TRACE 360 -> [0,2,"setTimeouts",{"script":30000}]
16:00:17 INFO - 1499814017738 Marionette TRACE 360 <- [1,2,null,{}]
16:00:17 INFO - 1499814017739 Marionette TRACE 360 -> [0,3,"setTimeouts",{"pageLoad":300000}]
16:00:17 INFO - 1499814017740 Marionette TRACE 360 <- [1,3,null,{}]
16:00:17 INFO - 1499814017741 Marionette TRACE 360 -> [0,4,"setTimeouts",{"implicit":0}]
16:00:17 INFO - 1499814017742 Marionette TRACE 360 <- [1,4,null,{}]
16:00:17 INFO - 1499814017743 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}]
16:00:17 INFO - TEST-START: test_click.py TestClick.test_container_element1499814017746 Marionette TRACE 360 <- [1,5,null,{"value":null}]
16:00:17 INFO - 1499814017747 Marionette TRACE 360 -> [0,6,"deleteSession",{}]
16:00:17 INFO - 1499814017749 Marionette TRACE 360 <- [1,6,null,{}]
16:00:17 INFO - 1499814017751 Marionette DEBUG Closed connection 360
16:00:17 INFO - 1499814017752 Marionette DEBUG Accepted connection 361 from 127.0.0.1:49851
16:00:17 INFO - 1499814017752 Marionette DEBUG Closed connection 361
16:00:17 INFO - 1499814017753 Marionette DEBUG Accepted connection 362 from 127.0.0.1:49852
16:00:17 INFO - 1499814017754 Marionette TRACE 362 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
16:00:17 INFO - 1499814017755 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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}
16:00:17 INFO - 1499814017757 Marionette DEBUG Register listener.js for window 12
16:00:17 INFO - 1499814017761 Marionette TRACE 362 <- [1,1,null,{"sessionId":"530b46df-fb8d-4da0-a590-7cff6bf76818","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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}}]
16:00:17 INFO - 1499814017763 Marionette TRACE 362 -> [0,2,"deleteSession",{}]
16:00:17 INFO - 1499814017765 Marionette TRACE 362 <- [1,2,null,{}]
16:00:17 INFO - 1499814017767 Marionette DEBUG Closed connection 362
16:00:17 INFO - 1499814017768 Marionette DEBUG Accepted connection 363 from 127.0.0.1:49853
16:00:17 INFO - 1499814017769 Marionette DEBUG Closed connection 363
16:00:17 INFO - 1499814017769 Marionette DEBUG Accepted connection 364 from 127.0.0.1:49855
16:00:17 INFO - 1499814017771 Marionette TRACE 364 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
16:00:17 INFO - 1499814017771 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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}
16:00:17 INFO - 1499814017774 Marionette DEBUG Register listener.js for window 12
16:00:17 INFO - 1499814017777 Marionette TRACE 364 <- [1,1,null,{"sessionId":"68f14a42-594a-4e88-919a-b954fa8b7ca6","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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}}]
16:00:17 INFO - 1499814017780 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"}]
16:00:17 INFO - 1499814017781 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:49405/test.html"
16:00:17 INFO - 1499814017784 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:49405/test.html"
16:00:17 INFO - 1499814017784 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:49405/test.html"
16:00:17 INFO - 1499814017814 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"
16:00:17 INFO - 1499814017816 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"
16:00:17 INFO - 1499814017821 Marionette TRACE 364 <- [1,2,null,{}]
16:00:17 INFO - 1499814017822 Marionette TRACE 364 -> [0,3,"findElement",{"using":"tag name","value":"option"}]
16:00:17 INFO - 1499814017825 Marionette TRACE 364 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"d740cba9-7626-496d-88ff-a707102f724b","ELEMENT":"d740cba9-7626-496d-88ff-a707102f724b"}}]
16:00:17 INFO - 1499814017833 Marionette TRACE 364 -> [0,4,"clickElement",{"id":"d740cba9-7626-496d-88ff-a707102f724b"}]
16:00:18 INFO - 1499814018079 Marionette DEBUG Canceled page load listener because no navigation has been detected
16:00:18 INFO - 1499814018080 Marionette TRACE 364 <- [1,4,null,{}]
16:00:18 INFO - 1499814018081 Marionette TRACE 364 -> [0,5,"getElementProperty",{"id":"d740cba9-7626-496d-88ff-a707102f724b","name":"selected"}]
16:00:18 INFO - 1499814018086 Marionette TRACE 364 <- [1,5,null,{"value":true}]
16:00:18 INFO - 1499814018088 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}]
16:00:18 INFO - TEST-END: test_click.py TestClick.test_container_element1499814018091 Marionette TRACE 364 <- [1,6,null,{"value":null}]
16:00:18 INFO - 1499814018092 Marionette TRACE 364 -> [0,7,"deleteSession",{}]
16:00:18 INFO - 1499814018094 Marionette TRACE 364 <- [1,7,null,{}]
16:00:18 INFO - TEST-PASS | test_click.py TestClick.test_container_element | took 371ms
16:00:18 INFO - TEST-START | test_click.py TestClick.test_container_element_outside_view
16:00:18 INFO - 1499814018096 Marionette DEBUG Closed connection 364
16:00:18 INFO - 1499814018097 Marionette DEBUG Accepted connection 365 from 127.0.0.1:49856
16:00:18 INFO - 1499814018099 Marionette DEBUG Closed connection 365
16:00:18 INFO - 1499814018100 Marionette DEBUG Accepted connection 366 from 127.0.0.1:49857
16:00:18 INFO - 1499814018101 Marionette TRACE 366 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
16:00:18 INFO - 1499814018102 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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}
16:00:18 INFO - 1499814018104 Marionette DEBUG Register listener.js for window 12
16:00:18 INFO - 1499814018108 Marionette TRACE 366 <- [1,1,null,{"sessionId":"886c37b5-4040-42cc-9d3f-ace7aeca1d91","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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}}]
16:00:18 INFO - 1499814018111 Marionette TRACE 366 -> [0,2,"setTimeouts",{"script":30000}]
16:00:18 INFO - 1499814018111 Marionette TRACE 366 <- [1,2,null,{}]
16:00:18 INFO - 1499814018112 Marionette TRACE 366 -> [0,3,"setTimeouts",{"pageLoad":300000}]
16:00:18 INFO - 1499814018113 Marionette TRACE 366 <- [1,3,null,{}]
16:00:18 INFO - 1499814018114 Marionette TRACE 366 -> [0,4,"setTimeouts",{"implicit":0}]
16:00:18 INFO - 1499814018114 Marionette TRACE 366 <- [1,4,null,{}]
16:00:18 INFO - 1499814018116 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}]
16:00:18 INFO - TEST-START: test_click.py TestClick.test_container_element_outside_view1499814018119 Marionette TRACE 366 <- [1,5,null,{"value":null}]
16:00:18 INFO - 1499814018120 Marionette TRACE 366 -> [0,6,"deleteSession",{}]
16:00:18 INFO - 1499814018121 Marionette TRACE 366 <- [1,6,null,{}]
16:00:18 INFO - 1499814018124 Marionette DEBUG Closed connection 366
16:00:18 INFO - 1499814018124 Marionette DEBUG Accepted connection 367 from 127.0.0.1:49858
16:00:18 INFO - 1499814018125 Marionette DEBUG Closed connection 367
16:00:18 INFO - 1499814018126 Marionette DEBUG Accepted connection 368 from 127.0.0.1:49859
16:00:18 INFO - 1499814018127 Marionette TRACE 368 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
16:00:18 INFO - 1499814018128 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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}
16:00:18 INFO - 1499814018130 Marionette DEBUG Register listener.js for window 12
16:00:18 INFO - 1499814018134 Marionette TRACE 368 <- [1,1,null,{"sessionId":"91b6bac6-53f5-43ca-b36a-80de6a4a6cd3","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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}}]
16:00:18 INFO - 1499814018144 Marionette TRACE 368 -> [0,2,"deleteSession",{}]
16:00:18 INFO - 1499814018146 Marionette TRACE 368 <- [1,2,null,{}]
16:00:18 INFO - 1499814018148 Marionette DEBUG Closed connection 368
16:00:18 INFO - 1499814018149 Marionette DEBUG Accepted connection 369 from 127.0.0.1:49860
16:00:18 INFO - 1499814018151 Marionette DEBUG Closed connection 369
16:00:18 INFO - 1499814018152 Marionette DEBUG Accepted connection 370 from 127.0.0.1:49861
16:00:18 INFO - 1499814018153 Marionette TRACE 370 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
16:00:18 INFO - 1499814018154 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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}
16:00:18 INFO - 1499814018156 Marionette DEBUG Register listener.js for window 12
16:00:18 INFO - 1499814018160 Marionette TRACE 370 <- [1,1,null,{"sessionId":"7c02d7c7-2943-47f0-93f1-5bdf9417657e","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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}}]
16:00:18 INFO - 1499814018163 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"}]
16:00:18 INFO - 1499814018165 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"
16:00:18 INFO - 1499814018168 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"
16:00:18 INFO - 1499814018169 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"
16:00:18 INFO - 1499814018189 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"
16:00:18 INFO - 1499814018193 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"
16:00:18 INFO - 1499814018202 Marionette TRACE 370 <- [1,2,null,{}]
16:00:18 INFO - 1499814018204 Marionette TRACE 370 -> [0,3,"findElement",{"using":"tag name","value":"option"}]
16:00:18 INFO - 1499814018206 Marionette TRACE 370 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"bfd83e53-9fd3-4d3e-ae5a-42fefd86f47b","ELEMENT":"bfd83e53-9fd3-4d3e-ae5a-42fefd86f47b"}}]
16:00:18 INFO - 1499814018207 Marionette TRACE 370 -> [0,4,"clickElement",{"id":"bfd83e53-9fd3-4d3e-ae5a-42fefd86f47b"}]
16:00:18 INFO - 1499814018454 Marionette DEBUG Canceled page load listener because no navigation has been detected
16:00:18 INFO - 1499814018455 Marionette TRACE 370 <- [1,4,null,{}]
16:00:18 INFO - 1499814018456 Marionette TRACE 370 -> [0,5,"getElementProperty",{"id":"bfd83e53-9fd3-4d3e-ae5a-42fefd86f47b","name":"selected"}]
16:00:18 INFO - 1499814018461 Marionette TRACE 370 <- [1,5,null,{"value":true}]
16:00:18 INFO - 1499814018463 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}]
16:00:18 INFO - TEST-END: test_click.py TestClick.test_container_element_outside_view1499814018466 Marionette TRACE 370 <- [1,6,null,{"value":null}]
16:00:18 INFO - 1499814018467 Marionette TRACE 370 -> [0,7,"deleteSession",{}]
16:00:18 INFO - 1499814018468 Marionette TRACE 370 <- [1,7,null,{}]
16:00:18 INFO - TEST-PASS | test_click.py TestClick.test_container_element_outside_view | took 374ms
16:00:18 INFO - TEST-START | test_click.py TestClick.test_css_transforms
16:00:18 INFO - 1499814018471 Marionette DEBUG Closed connection 370
16:00:18 INFO - 1499814018472 Marionette DEBUG Accepted connection 371 from 127.0.0.1:49862
16:00:18 INFO - 1499814018472 Marionette DEBUG Closed connection 371
16:00:18 INFO - 1499814018473 Marionette DEBUG Accepted connection 372 from 127.0.0.1:49863
16:00:18 INFO - 1499814018474 Marionette TRACE 372 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
16:00:18 INFO - 1499814018475 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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}
16:00:18 INFO - 1499814018478 Marionette DEBUG Register listener.js for window 12
16:00:18 INFO - 1499814018481 Marionette TRACE 372 <- [1,1,null,{"sessionId":"80d7f37f-d639-4986-9b0b-06fed8f09bae","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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}}]
16:00:18 INFO - 1499814018483 Marionette TRACE 372 -> [0,2,"setTimeouts",{"script":30000}]
16:00:18 INFO - 1499814018484 Marionette TRACE 372 <- [1,2,null,{}]
16:00:18 INFO - 1499814018485 Marionette TRACE 372 -> [0,3,"setTimeouts",{"pageLoad":300000}]
16:00:18 INFO - 1499814018485 Marionette TRACE 372 <- [1,3,null,{}]
16:00:18 INFO - 1499814018486 Marionette TRACE 372 -> [0,4,"setTimeouts",{"implicit":0}]
16:00:18 INFO - 1499814018486 Marionette TRACE 372 <- [1,4,null,{}]
16:00:18 INFO - 1499814018488 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}]
16:00:18 INFO - TEST-START: test_click.py TestClick.test_css_transforms1499814018491 Marionette TRACE 372 <- [1,5,null,{"value":null}]
16:00:18 INFO - 1499814018492 Marionette TRACE 372 -> [0,6,"deleteSession",{}]
16:00:18 INFO - 1499814018494 Marionette TRACE 372 <- [1,6,null,{}]
16:00:18 INFO - 1499814018496 Marionette DEBUG Closed connection 372
16:00:18 INFO - 1499814018497 Marionette DEBUG Accepted connection 373 from 127.0.0.1:49864
16:00:18 INFO - 1499814018498 Marionette DEBUG Closed connection 373
16:00:18 INFO - 1499814018498 Marionette DEBUG Accepted connection 374 from 127.0.0.1:49865
16:00:18 INFO - 1499814018500 Marionette TRACE 374 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
16:00:18 INFO - 1499814018500 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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}
16:00:18 INFO - 1499814018503 Marionette DEBUG Register listener.js for window 12
16:00:18 INFO - 1499814018506 Marionette TRACE 374 <- [1,1,null,{"sessionId":"0d9562b7-86cb-493a-bd97-470e49dc0ac5","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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}}]
16:00:18 INFO - 1499814018508 Marionette TRACE 374 -> [0,2,"deleteSession",{}]
16:00:18 INFO - 1499814018510 Marionette TRACE 374 <- [1,2,null,{}]
16:00:18 INFO - 1499814018512 Marionette DEBUG Closed connection 374
16:00:18 INFO - 1499814018513 Marionette DEBUG Accepted connection 375 from 127.0.0.1:49866
16:00:18 INFO - 1499814018514 Marionette DEBUG Closed connection 375
16:00:18 INFO - 1499814018514 Marionette DEBUG Accepted connection 376 from 127.0.0.1:49867
16:00:18 INFO - 1499814018516 Marionette TRACE 376 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
16:00:18 INFO - 1499814018516 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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}
16:00:18 INFO - 1499814018519 Marionette DEBUG Register listener.js for window 12
16:00:18 INFO - 1499814018522 Marionette TRACE 376 <- [1,1,null,{"sessionId":"434df8a6-9437-43bc-b4ef-39254c39c83b","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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}}]
16:00:18 INFO - 1499814018524 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"}]
16:00:18 INFO - 1499814018529 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"
16:00:18 INFO - 1499814018534 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"
16:00:18 INFO - 1499814018534 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"
16:00:18 INFO - 1499814018554 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"
16:00:18 INFO - 1499814018558 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"
16:00:18 INFO - 1499814018568 Marionette TRACE 376 <- [1,2,null,{}]
16:00:18 INFO - 1499814018572 Marionette TRACE 376 -> [0,3,"findElement",{"using":"tag name","value":"div"}]
16:00:18 INFO - 1499814018575 Marionette TRACE 376 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"31529d51-b998-4db5-9b8a-ab299689f4ee","ELEMENT":"31529d51-b998-4db5-9b8a-ab299689f4ee"}}]
16:00:18 INFO - 1499814018576 Marionette TRACE 376 -> [0,4,"clickElement",{"id":"31529d51-b998-4db5-9b8a-ab299689f4ee"}]
16:00:18 INFO - 1499814018819 Marionette DEBUG Canceled page load listener because no navigation has been detected
16:00:18 INFO - 1499814018820 Marionette TRACE 376 <- [1,4,null,{}]
16:00:18 INFO - 1499814018822 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}]
16:00:18 INFO - TEST-END: test_click.py TestClick.test_css_transforms1499814018825 Marionette TRACE 376 <- [1,5,null,{"value":null}]
16:00:18 INFO - 1499814018826 Marionette TRACE 376 -> [0,6,"deleteSession",{}]
16:00:18 INFO - TEST-PASS | test_click.py TestClick.test_css_transforms | took 358ms
16:00:18 INFO - 1499814018827 Marionette TRACE 376 <- [1,6,null,{}]
16:00:18 INFO - TEST-START | test_click.py TestClick.test_inclusive_descendant
16:00:18 INFO - 1499814018830 Marionette DEBUG Closed connection 376
16:00:18 INFO - 1499814018835 Marionette DEBUG Accepted connection 377 from 127.0.0.1:49868
16:00:18 INFO - 1499814018836 Marionette DEBUG Closed connection 377
16:00:18 INFO - 1499814018837 Marionette DEBUG Accepted connection 378 from 127.0.0.1:49869
16:00:18 INFO - 1499814018838 Marionette TRACE 378 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
16:00:18 INFO - 1499814018838 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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}
16:00:18 INFO - 1499814018841 Marionette DEBUG Register listener.js for window 12
16:00:18 INFO - 1499814018845 Marionette TRACE 378 <- [1,1,null,{"sessionId":"3cab632e-dffa-48d1-af3c-5e7a056e0918","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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}}]
16:00:18 INFO - 1499814018847 Marionette TRACE 378 -> [0,2,"setTimeouts",{"script":30000}]
16:00:18 INFO - 1499814018848 Marionette TRACE 378 <- [1,2,null,{}]
16:00:18 INFO - 1499814018849 Marionette TRACE 378 -> [0,3,"setTimeouts",{"pageLoad":300000}]
16:00:18 INFO - 1499814018849 Marionette TRACE 378 <- [1,3,null,{}]
16:00:18 INFO - 1499814018850 Marionette TRACE 378 -> [0,4,"setTimeouts",{"implicit":0}]
16:00:18 INFO - 1499814018851 Marionette TRACE 378 <- [1,4,null,{}]
16:00:18 INFO - 1499814018853 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}]
16:00:18 INFO - TEST-START: test_click.py TestClick.test_inclusive_descendant1499814018856 Marionette TRACE 378 <- [1,5,null,{"value":null}]
16:00:18 INFO - 1499814018857 Marionette TRACE 378 -> [0,6,"deleteSession",{}]
16:00:18 INFO - 1499814018858 Marionette TRACE 378 <- [1,6,null,{}]
16:00:18 INFO - 1499814018860 Marionette DEBUG Closed connection 378
16:00:18 INFO - 1499814018861 Marionette DEBUG Accepted connection 379 from 127.0.0.1:49870
16:00:18 INFO - 1499814018862 Marionette DEBUG Closed connection 379
16:00:18 INFO - 1499814018863 Marionette DEBUG Accepted connection 380 from 127.0.0.1:49871
16:00:18 INFO - 1499814018864 Marionette TRACE 380 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
16:00:18 INFO - 1499814018865 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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}
16:00:18 INFO - 1499814018867 Marionette DEBUG Register listener.js for window 12
16:00:18 INFO - 1499814018871 Marionette TRACE 380 <- [1,1,null,{"sessionId":"49e6a012-c0e9-4f8f-b5c2-c7ab54130114","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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}}]
16:00:18 INFO - 1499814018873 Marionette TRACE 380 -> [0,2,"deleteSession",{}]
16:00:18 INFO - 1499814018874 Marionette TRACE 380 <- [1,2,null,{}]
16:00:18 INFO - 1499814018877 Marionette DEBUG Closed connection 380
16:00:18 INFO - 1499814018877 Marionette DEBUG Accepted connection 381 from 127.0.0.1:49872
16:00:18 INFO - 1499814018878 Marionette DEBUG Closed connection 381
16:00:18 INFO - 1499814018879 Marionette DEBUG Accepted connection 382 from 127.0.0.1:49873
16:00:18 INFO - 1499814018880 Marionette TRACE 382 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
16:00:18 INFO - 1499814018881 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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}
16:00:18 INFO - 1499814018883 Marionette DEBUG Register listener.js for window 12
16:00:18 INFO - 1499814018896 Marionette TRACE 382 <- [1,1,null,{"sessionId":"224468f8-b14f-40e9-a9c3-74695b01501d","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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}}]
16:00:18 INFO - 1499814018899 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"}]
16:00:18 INFO - 1499814018900 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"
16:00:18 INFO - 1499814018903 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"
16:00:18 INFO - 1499814018903 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"
16:00:18 INFO - 1499814018923 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"
16:00:18 INFO - 1499814018927 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"
16:00:18 INFO - 1499814018938 Marionette TRACE 382 <- [1,2,null,{}]
16:00:18 INFO - 1499814018939 Marionette TRACE 382 -> [0,3,"findElement",{"using":"tag name","value":"select"}]
16:00:18 INFO - 1499814018943 Marionette TRACE 382 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"ca008756-f987-4a23-a0e2-bcf5af0803c8","ELEMENT":"ca008756-f987-4a23-a0e2-bcf5af0803c8"}}]
16:00:18 INFO - 1499814018958 Marionette TRACE 382 -> [0,4,"clickElement",{"id":"ca008756-f987-4a23-a0e2-bcf5af0803c8"}]
16:00:19 INFO - 1499814019204 Marionette DEBUG Canceled page load listener because no navigation has been detected
16:00:19 INFO - 1499814019205 Marionette TRACE 382 <- [1,4,null,{}]
16:00:19 INFO - 1499814019207 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}]
16:00:19 INFO - TEST-END: test_click.py TestClick.test_inclusive_descendant1499814019210 Marionette TRACE 382 <- [1,5,null,{"value":null}]
16:00:19 INFO - 1499814019211 Marionette TRACE 382 -> [0,6,"deleteSession",{}]
16:00:19 INFO - 1499814019212 Marionette TRACE 382 <- [1,6,null,{}]
16:00:19 INFO - TEST-PASS | test_click.py TestClick.test_inclusive_descendant | took 385ms
16:00:19 INFO - TEST-START | test_click.py TestClick.test_input_file
16:00:19 INFO - 1499814019215 Marionette DEBUG Closed connection 382
16:00:19 INFO - 1499814019216 Marionette DEBUG Accepted connection 383 from 127.0.0.1:49876
16:00:19 INFO - 1499814019216 Marionette DEBUG Closed connection 383
16:00:19 INFO - 1499814019217 Marionette DEBUG Accepted connection 384 from 127.0.0.1:49877
16:00:19 INFO - 1499814019218 Marionette TRACE 384 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
16:00:19 INFO - 1499814019219 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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}
16:00:19 INFO - 1499814019222 Marionette DEBUG Register listener.js for window 12
16:00:19 INFO - 1499814019225 Marionette TRACE 384 <- [1,1,null,{"sessionId":"b5e27f30-444e-46f9-8f59-633184c2978d","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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}}]
16:00:19 INFO - 1499814019227 Marionette TRACE 384 -> [0,2,"setTimeouts",{"script":30000}]
16:00:19 INFO - 1499814019228 Marionette TRACE 384 <- [1,2,null,{}]
16:00:19 INFO - 1499814019229 Marionette TRACE 384 -> [0,3,"setTimeouts",{"pageLoad":300000}]
16:00:19 INFO - 1499814019229 Marionette TRACE 384 <- [1,3,null,{}]
16:00:19 INFO - 1499814019230 Marionette TRACE 384 -> [0,4,"setTimeouts",{"implicit":0}]
16:00:19 INFO - 1499814019231 Marionette TRACE 384 <- [1,4,null,{}]
16:00:19 INFO - 1499814019233 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}]
16:00:19 INFO - TEST-START: test_click.py TestClick.test_input_file1499814019236 Marionette TRACE 384 <- [1,5,null,{"value":null}]
16:00:19 INFO - 1499814019237 Marionette TRACE 384 -> [0,6,"deleteSession",{}]
16:00:19 INFO - 1499814019238 Marionette TRACE 384 <- [1,6,null,{}]
16:00:19 INFO - 1499814019240 Marionette DEBUG Closed connection 384
16:00:19 INFO - 1499814019241 Marionette DEBUG Accepted connection 385 from 127.0.0.1:49878
16:00:19 INFO - 1499814019242 Marionette DEBUG Closed connection 385
16:00:19 INFO - 1499814019243 Marionette DEBUG Accepted connection 386 from 127.0.0.1:49879
16:00:19 INFO - 1499814019244 Marionette TRACE 386 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
16:00:19 INFO - 1499814019244 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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}
16:00:19 INFO - 1499814019247 Marionette DEBUG Register listener.js for window 12
16:00:19 INFO - 1499814019250 Marionette TRACE 386 <- [1,1,null,{"sessionId":"19a5c799-2df9-499d-97f1-58494a9ad4c9","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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}}]
16:00:19 INFO - 1499814019252 Marionette TRACE 386 -> [0,2,"deleteSession",{}]
16:00:19 INFO - 1499814019254 Marionette TRACE 386 <- [1,2,null,{}]
16:00:19 INFO - 1499814019256 Marionette DEBUG Closed connection 386
16:00:19 INFO - 1499814019257 Marionette DEBUG Accepted connection 387 from 127.0.0.1:49880
16:00:19 INFO - 1499814019258 Marionette DEBUG Closed connection 387
16:00:19 INFO - 1499814019259 Marionette DEBUG Accepted connection 388 from 127.0.0.1:49881
16:00:19 INFO - 1499814019260 Marionette TRACE 388 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
16:00:19 INFO - 1499814019260 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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}
16:00:19 INFO - 1499814019263 Marionette DEBUG Register listener.js for window 12
16:00:19 INFO - 1499814019266 Marionette TRACE 388 <- [1,1,null,{"sessionId":"0ea3ff6b-7b6d-4eff-af4c-1cc5977c61ce","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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}}]
16:00:19 INFO - 1499814019268 Marionette TRACE 388 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"}]
16:00:19 INFO - 1499814019270 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"
16:00:19 INFO - 1499814019273 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"
16:00:19 INFO - 1499814019273 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"
16:00:19 INFO - 1499814019297 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
16:00:19 INFO - 1499814019299 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
16:00:19 INFO - 1499814019303 Marionette TRACE 388 <- [1,2,null,{}]
16:00:19 INFO - 1499814019304 Marionette TRACE 388 -> [0,3,"findElement",{"using":"tag name","value":"input"}]
16:00:19 INFO - 1499814019307 Marionette TRACE 388 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"3e20392e-ee4c-47cc-be7b-bd687c5a5bc0","ELEMENT":"3e20392e-ee4c-47cc-be7b-bd687c5a5bc0"}}]
16:00:19 INFO - 1499814019308 Marionette TRACE 388 -> [0,4,"clickElement",{"id":"3e20392e-ee4c-47cc-be7b-bd687c5a5bc0"}]
16:00:19 INFO - 1499814019346 Marionette TRACE 388 <- [1,4,{"error":"invalid argument","message":"Cannot click
elements","stacktrace":"WebDriverError@chrome://marionette/content/error.js:226:5\nInvalidArgumentError@chrome://marionette/content/error.js:329:5\nwebdriverClickElement@chrome://marionette/content/interaction.js:165:11\nTaskImpl_run@resource://gre/modules/Task.jsm:331:42\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nTaskImpl_handleResultValue@resource://gre/modules/Task.jsm:401:16\nTaskImpl_run@resource://gre/modules/Task.jsm:339:15\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nTaskImpl_handleResultValue@resource://gre/modules/Task.jsm:401:16\nTaskImpl_run@resource://gre/modules/Task.jsm:339:15\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nnavigate@chrome://marionette/content/listener.js:397:12\nclickElement@chrome://marionette/content/listener.js:1317:5\n"},null]
16:00:19 INFO - 1499814019348 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}]
16:00:19 INFO - TEST-END: test_click.py TestClick.test_input_file1499814019351 Marionette TRACE 388 <- [1,5,null,{"value":null}]
16:00:19 INFO - 1499814019352 Marionette TRACE 388 -> [0,6,"deleteSession",{}]
16:00:19 INFO - TEST-PASS | test_click.py TestClick.test_input_file | took 141ms
16:00:19 INFO - TEST-START | test_click.py TestClick.test_obscured_element
16:00:19 INFO - 1499814019354 Marionette TRACE 388 <- [1,6,null,{}]
16:00:19 INFO - 1499814019356 Marionette DEBUG Closed connection 388
16:00:19 INFO - 1499814019357 Marionette DEBUG Accepted connection 389 from 127.0.0.1:49882
16:00:19 INFO - 1499814019358 Marionette DEBUG Closed connection 389
16:00:19 INFO - 1499814019358 Marionette DEBUG Accepted connection 390 from 127.0.0.1:49883
16:00:19 INFO - 1499814019360 Marionette TRACE 390 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
16:00:19 INFO - 1499814019360 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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}
16:00:19 INFO - 1499814019363 Marionette DEBUG Register listener.js for window 12
16:00:19 INFO - 1499814019366 Marionette TRACE 390 <- [1,1,null,{"sessionId":"dae16661-6164-4ed2-8247-05337e6984a6","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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}}]
16:00:19 INFO - 1499814019369 Marionette TRACE 390 -> [0,2,"setTimeouts",{"script":30000}]
16:00:19 INFO - 1499814019369 Marionette TRACE 390 <- [1,2,null,{}]
16:00:19 INFO - 1499814019370 Marionette TRACE 390 -> [0,3,"setTimeouts",{"pageLoad":300000}]
16:00:19 INFO - 1499814019371 Marionette TRACE 390 <- [1,3,null,{}]
16:00:19 INFO - 1499814019371 Marionette TRACE 390 -> [0,4,"setTimeouts",{"implicit":0}]
16:00:19 INFO - 1499814019372 Marionette TRACE 390 <- [1,4,null,{}]
16:00:19 INFO - 1499814019374 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}]
16:00:19 INFO - TEST-START: test_click.py TestClick.test_obscured_element1499814019377 Marionette TRACE 390 <- [1,5,null,{"value":null}]
16:00:19 INFO - 1499814019378 Marionette TRACE 390 -> [0,6,"deleteSession",{}]
16:00:19 INFO - 1499814019379 Marionette TRACE 390 <- [1,6,null,{}]
16:00:19 INFO - 1499814019381 Marionette DEBUG Closed connection 390
16:00:19 INFO - 1499814019382 Marionette DEBUG Accepted connection 391 from 127.0.0.1:49884
16:00:19 INFO - 1499814019383 Marionette DEBUG Closed connection 391
16:00:19 INFO - 1499814019384 Marionette DEBUG Accepted connection 392 from 127.0.0.1:49885
16:00:19 INFO - 1499814019385 Marionette TRACE 392 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
16:00:19 INFO - 1499814019386 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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}
16:00:19 INFO - 1499814019388 Marionette DEBUG Register listener.js for window 12
16:00:19 INFO - 1499814019391 Marionette TRACE 392 <- [1,1,null,{"sessionId":"8865d91e-457d-491c-8b84-3d026df54e91","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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}}]
16:00:19 INFO - 1499814019394 Marionette TRACE 392 -> [0,2,"deleteSession",{}]
16:00:19 INFO - 1499814019395 Marionette TRACE 392 <- [1,2,null,{}]
16:00:19 INFO - 1499814019397 Marionette DEBUG Closed connection 392
16:00:19 INFO - 1499814019398 Marionette DEBUG Accepted connection 393 from 127.0.0.1:49886
16:00:19 INFO - 1499814019399 Marionette DEBUG Closed connection 393
16:00:19 INFO - 1499814019400 Marionette DEBUG Accepted connection 394 from 127.0.0.1:49887
16:00:19 INFO - 1499814019401 Marionette TRACE 394 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
16:00:19 INFO - 1499814019401 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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}
16:00:19 INFO - 1499814019404 Marionette DEBUG Register listener.js for window 12
16:00:19 INFO - 1499814019407 Marionette TRACE 394 <- [1,1,null,{"sessionId":"3a7009b4-12be-42a5-98b9-3433f762e20f","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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}}]
16:00:19 INFO - 1499814019409 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"}]
16:00:19 INFO - 1499814019411 Marionette DEBUG Received DOM event "beforeunload" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
16:00:19 INFO - 1499814019414 Marionette DEBUG Received DOM event "pagehide" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
16:00:19 INFO - 1499814019414 Marionette DEBUG Received DOM event "unload" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
16:00:19 INFO - 1499814019448 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"
16:00:19 INFO - 1499814019451 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"
16:00:19 INFO - 1499814019455 Marionette TRACE 394 <- [1,2,null,{}]
16:00:19 INFO - 1499814019456 Marionette TRACE 394 -> [0,3,"findElement",{"using":"id","value":"overlay"}]
16:00:19 INFO - 1499814019459 Marionette TRACE 394 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"6e7af74a-1210-4ed5-b46f-b13e7e6351f1","ELEMENT":"6e7af74a-1210-4ed5-b46f-b13e7e6351f1"}}]
16:00:19 INFO - 1499814019460 Marionette TRACE 394 -> [0,4,"findElement",{"using":"id","value":"obscured"}]
16:00:19 INFO - 1499814019469 Marionette TRACE 394 <- [1,4,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"f2a5e386-0e00-4fc9-ab8b-8669db43dac0","ELEMENT":"f2a5e386-0e00-4fc9-ab8b-8669db43dac0"}}]
16:00:19 INFO - 1499814019471 Marionette TRACE 394 -> [0,5,"clickElement",{"id":"6e7af74a-1210-4ed5-b46f-b13e7e6351f1"}]
16:00:19 INFO - 1499814019710 Marionette DEBUG Canceled page load listener because no navigation has been detected
16:00:19 INFO - 1499814019711 Marionette TRACE 394 <- [1,5,null,{}]
16:00:19 INFO - 1499814019712 Marionette TRACE 394 -> [0,6,"clickElement",{"id":"f2a5e386-0e00-4fc9-ab8b-8669db43dac0"}]
16:00:19 INFO - 1499814019730 Marionette TRACE 394 <- [1,6,{"error":"element click intercepted","message":"Element
is not clickable at point (10.5,10) because another element obscures it","stacktrace":"WebDriverError@chrome://marionette/content/error.js:226:5\nElementClickInterceptedError@chrome://marionette/content/error.js:308:5\nwebdriverClickElement@chrome://marionette/content/interaction.js:192:11\nTaskImpl_run@resource://gre/modules/Task.jsm:331:42\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nTaskImpl_handleResultValue@resource://gre/modules/Task.jsm:401:16\nTaskImpl_run@resource://gre/modules/Task.jsm:339:15\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nTaskImpl_handleResultValue@resource://gre/modules/Task.jsm:401:16\nTaskImpl_run@resource://gre/modules/Task.jsm:339:15\nTaskImpl@resource://gre/modules/Task.jsm:280:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nnavigate@chrome://marionette/content/listener.js:397:12\nclickElement@chrome://marionette/content/listener.js:1317:5\n"},null]
16:00:19 INFO - 1499814019732 Marionette TRACE 394 -> [0,7,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"test_click.py","script":"return window.clicked","sandbox":null,"line":257}]
16:00:19 INFO - 1499814019735 Marionette TRACE 394 <- [1,7,null,{"value":false}]
16:00:19 INFO - 1499814019737 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}]
16:00:19 INFO - TEST-END: test_click.py TestClick.test_obscured_element1499814019739 Marionette TRACE 394 <- [1,8,null,{"value":null}]
16:00:19 INFO - 1499814019740 Marionette TRACE 394 -> [0,9,"deleteSession",{}]
16:00:19 INFO - TEST-PASS | test_click.py TestClick.test_obscured_element | took 388ms
16:00:19 INFO - TEST-START | test_click.py TestClick.test_pointer_events_none
16:00:19 INFO - 1499814019742 Marionette TRACE 394 <- [1,9,null,{}]
16:00:19 INFO - 1499814019744 Marionette DEBUG Closed connection 394
16:00:19 INFO - 1499814019745 Marionette DEBUG Accepted connection 395 from 127.0.0.1:49888
16:00:19 INFO - 1499814019746 Marionette DEBUG Closed connection 395
16:00:19 INFO - 1499814019747 Marionette DEBUG Accepted connection 396 from 127.0.0.1:49889
16:00:19 INFO - 1499814019748 Marionette TRACE 396 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
16:00:19 INFO - 1499814019749 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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}
16:00:19 INFO - 1499814019751 Marionette DEBUG Register listener.js for window 12
16:00:19 INFO - 1499814019755 Marionette TRACE 396 <- [1,1,null,{"sessionId":"f54b904d-f8a8-4078-9f68-9ad9b43f9bd4","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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}}]
16:00:19 INFO - 1499814019757 Marionette TRACE 396 -> [0,2,"setTimeouts",{"script":30000}]
16:00:19 INFO - 1499814019757 Marionette TRACE 396 <- [1,2,null,{}]
16:00:19 INFO - 1499814019758 Marionette TRACE 396 -> [0,3,"setTimeouts",{"pageLoad":300000}]
16:00:19 INFO - 1499814019759 Marionette TRACE 396 <- [1,3,null,{}]
16:00:19 INFO - 1499814019760 Marionette TRACE 396 -> [0,4,"setTimeouts",{"implicit":0}]
16:00:19 INFO - 1499814019760 Marionette TRACE 396 <- [1,4,null,{}]
16:00:19 INFO - 1499814019762 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}]
16:00:19 INFO - TEST-START: test_click.py TestClick.test_pointer_events_none1499814019765 Marionette TRACE 396 <- [1,5,null,{"value":null}]
16:00:19 INFO - 1499814019766 Marionette TRACE 396 -> [0,6,"deleteSession",{}]
16:00:19 INFO - 1499814019767 Marionette TRACE 396 <- [1,6,null,{}]
16:00:19 INFO - 1499814019770 Marionette DEBUG Closed connection 396
16:00:19 INFO - 1499814019770 Marionette DEBUG Accepted connection 397 from 127.0.0.1:49890
16:00:19 INFO - 1499814019771 Marionette DEBUG Closed connection 397
16:00:19 INFO - 1499814019772 Marionette DEBUG Accepted connection 398 from 127.0.0.1:49891
16:00:19 INFO - 1499814019773 Marionette TRACE 398 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
16:00:19 INFO - 1499814019774 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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}
16:00:19 INFO - 1499814019776 Marionette DEBUG Register listener.js for window 12
16:00:19 INFO - 1499814019781 Marionette TRACE 398 <- [1,1,null,{"sessionId":"4e075ed1-3f42-4287-9e1b-6a5b88819a28","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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}}]
16:00:19 INFO - 1499814019783 Marionette TRACE 398 -> [0,2,"deleteSession",{}]
16:00:19 INFO - 1499814019784 Marionette TRACE 398 <- [1,2,null,{}]
16:00:19 INFO - 1499814019787 Marionette DEBUG Closed connection 398
16:00:19 INFO - 1499814019787 Marionette DEBUG Accepted connection 399 from 127.0.0.1:49892
16:00:19 INFO - 1499814019788 Marionette DEBUG Closed connection 399
16:00:19 INFO - 1499814019789 Marionette DEBUG Accepted connection 400 from 127.0.0.1:49893
16:00:19 INFO - 1499814019790 Marionette TRACE 400 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
16:00:19 INFO - 1499814019791 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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}
16:00:19 INFO - 1499814019793 Marionette DEBUG Register listener.js for window 12
16:00:19 INFO - 1499814019796 Marionette TRACE 400 <- [1,1,null,{"sessionId":"8cdc3621-fd86-4808-a4ec-e42395668420","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":4068,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmpgp6gze.mozrunner","moz:accessibilityChecks":false}}]
16:00:19 INFO - 1499814019799 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"}]
16:00:19 INFO - 1499814019800 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"
16:00:19 INFO - 1499814019803 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"
16:00:19 INFO - 1499814019803 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"
16:00:19 INFO - 1499814019824 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"
16:00:19 INFO - 1499814019828 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"
16:00:19 INFO - 1499814019838 Marionette TRACE 400 <- [1,2,null,{}]
16:00:19 INFO - 1499814019840 Marionette TRACE 400 -> [0,3,"findElement",{"using":"tag name","value":"button"}]
16:00:19 INFO - 1499814019843 Marionette TRACE 400 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"ca148778-df0a-4892-8c19-adb90cea1f45","ELEMENT":"ca148778-df0a-4892-8c19-adb90cea1f45"}}]
16:00:19 INFO - 1499814019845 Marionette TRACE 400 -> [0,4,"getElementValueOfCssProperty",{"propertyName":"pointer-events","id":"ca148778-df0a-4892-8c19-adb90cea1f45"}]
16:00:19 INFO - 1499814019869 Marionette TRACE 400 <- [1,4,null,{"value":"none"}]
16:00:19 INFO - 1499814019870 Marionette TRACE 400 -> [0,5,"clickElement",{"id":"ca148778-df0a-4892-8c19-adb90cea1f45"}]
16:00:19 INFO - 1499814019889 Marionette TRACE 400 <- [1,5,{"error":"element click intercepted","message":"Element