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:393:12\nclickElement@chrome://marionette/content/listener.js:1330:5\n"},null]
05:02:50 INFO - 1498996970777 Marionette TRACE 352 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-END: test_click.py TestClick.test_clicking_an_element_that_is_not_displayed_raises')","sandbox":"simpletest","line":328}]
05:02:50 INFO - TEST-END: test_click.py TestClick.test_clicking_an_element_that_is_not_displayed_raises1498996970780 Marionette TRACE 352 <- [1,5,null,{"value":null}]
05:02:50 INFO - 1498996970781 Marionette TRACE 352 -> [0,6,"deleteSession",{}]
05:02:50 INFO - 1498996970782 Marionette TRACE 352 <- [1,6,null,{}]
05:02:50 INFO - TEST-PASS | test_click.py TestClick.test_clicking_an_element_that_is_not_displayed_raises | took 140ms
05:02:50 INFO - TEST-START | test_click.py TestClick.test_clicking_on_a_multiline_link
05:02:50 INFO - 1498996970785 Marionette DEBUG Closed connection 352
05:02:50 INFO - 1498996970786 Marionette DEBUG Accepted connection 353 from 127.0.0.1:54325
05:02:50 INFO - 1498996970787 Marionette DEBUG Closed connection 353
05:02:50 INFO - 1498996970787 Marionette DEBUG Accepted connection 354 from 127.0.0.1:54326
05:02:50 INFO - 1498996970788 Marionette TRACE 354 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:02:50 INFO - 1498996970789 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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}
05:02:50 INFO - 1498996970791 Marionette DEBUG Register listener.js for window 12
05:02:50 INFO - 1498996970794 Marionette TRACE 354 <- [1,1,null,{"sessionId":"0f223524-a9fc-4512-8a36-8dac710f30f7","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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}}]
05:02:50 INFO - 1498996970795 Marionette TRACE 354 -> [0,2,"setTimeouts",{"script":30000}]
05:02:50 INFO - 1498996970796 Marionette TRACE 354 <- [1,2,null,{}]
05:02:50 INFO - 1498996970797 Marionette TRACE 354 -> [0,3,"setTimeouts",{"pageLoad":300000}]
05:02:50 INFO - 1498996970797 Marionette TRACE 354 <- [1,3,null,{}]
05:02:50 INFO - 1498996970798 Marionette TRACE 354 -> [0,4,"setTimeouts",{"implicit":0}]
05:02:50 INFO - 1498996970799 Marionette TRACE 354 <- [1,4,null,{}]
05:02:50 INFO - 1498996970801 Marionette TRACE 354 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-START: test_click.py TestClick.test_clicking_on_a_multiline_link')","sandbox":"simpletest","line":316}]
05:02:50 INFO - TEST-START: test_click.py TestClick.test_clicking_on_a_multiline_link1498996970803 Marionette TRACE 354 <- [1,5,null,{"value":null}]
05:02:50 INFO - 1498996970804 Marionette TRACE 354 -> [0,6,"deleteSession",{}]
05:02:50 INFO - 1498996970806 Marionette TRACE 354 <- [1,6,null,{}]
05:02:50 INFO - 1498996970808 Marionette DEBUG Closed connection 354
05:02:50 INFO - 1498996970808 Marionette DEBUG Accepted connection 355 from 127.0.0.1:54327
05:02:50 INFO - 1498996970809 Marionette DEBUG Closed connection 355
05:02:50 INFO - 1498996970810 Marionette DEBUG Accepted connection 356 from 127.0.0.1:54328
05:02:50 INFO - 1498996970811 Marionette TRACE 356 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:02:50 INFO - 1498996970812 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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}
05:02:50 INFO - 1498996970814 Marionette DEBUG Register listener.js for window 12
05:02:50 INFO - 1498996970817 Marionette TRACE 356 <- [1,1,null,{"sessionId":"341056df-dc0f-475f-b686-dab582381699","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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}}]
05:02:50 INFO - 1498996970818 Marionette TRACE 356 -> [0,2,"deleteSession",{}]
05:02:50 INFO - 1498996970819 Marionette TRACE 356 <- [1,2,null,{}]
05:02:50 INFO - 1498996970821 Marionette DEBUG Closed connection 356
05:02:50 INFO - 1498996970822 Marionette DEBUG Accepted connection 357 from 127.0.0.1:54329
05:02:50 INFO - 1498996970822 Marionette DEBUG Closed connection 357
05:02:50 INFO - 1498996970823 Marionette DEBUG Accepted connection 358 from 127.0.0.1:54330
05:02:50 INFO - 1498996970824 Marionette TRACE 358 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
05:02:50 INFO - 1498996970825 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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}
05:02:50 INFO - 1498996970827 Marionette DEBUG Register listener.js for window 12
05:02:50 INFO - 1498996970830 Marionette TRACE 358 <- [1,1,null,{"sessionId":"665f623a-125c-4d9d-b033-b24bf041f1d9","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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}}]
05:02:50 INFO - 1498996970832 Marionette TRACE 358 -> [0,2,"get",{"url":"http://127.0.0.1:53894/clicks.html"}]
05:02:50 INFO - 1498996970833 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:53894/hidden.html"
05:02:50 INFO - 1498996970839 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:53894/hidden.html"
05:02:50 INFO - 1498996970839 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:53894/hidden.html"
05:02:50 INFO - 1498996970858 Marionette DEBUG Received DOM event "DOMContentLoaded" for "http://127.0.0.1:53894/clicks.html"
05:02:50 INFO - 1498996970865 Marionette DEBUG Received DOM event "pageshow" for "http://127.0.0.1:53894/clicks.html"
05:02:50 INFO - 1498996970869 Marionette TRACE 358 <- [1,2,null,{}]
05:02:50 INFO - 1498996970870 Marionette TRACE 358 -> [0,3,"findElement",{"using":"id","value":"overflowLink"}]
05:02:50 INFO - 1498996970873 Marionette TRACE 358 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"4291add6-a600-428c-ab5b-749e595f8708","ELEMENT":"4291add6-a600-428c-ab5b-749e595f8708"}}]
05:02:50 INFO - 1498996970873 Marionette TRACE 358 -> [0,4,"clickElement",{"id":"4291add6-a600-428c-ab5b-749e595f8708"}]
05:02:50 INFO - 1498996970925 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:53894/clicks.html"
05:02:50 INFO - 1498996970939 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:53894/clicks.html"
05:02:50 INFO - 1498996970939 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:53894/clicks.html"
05:02:50 INFO - 1498996970971 Marionette DEBUG Received DOM event "DOMContentLoaded" for "http://127.0.0.1:53894/test.html"
05:02:50 INFO - 1498996970974 Marionette DEBUG Received DOM event "pageshow" for "http://127.0.0.1:53894/test.html"
05:02:50 INFO - 1498996970978 Marionette TRACE 358 <- [1,4,null,{}]
05:02:50 INFO - 1498996970988 Marionette TRACE 358 -> [0,5,"findElement",{"using":"id","value":"testDiv"}]
05:02:50 INFO - 1498996970990 Marionette TRACE 358 <- [1,5,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"302b6986-c8b9-4739-a3c8-7eacf17ae258","ELEMENT":"302b6986-c8b9-4739-a3c8-7eacf17ae258"}}]
05:02:50 INFO - 1498996970991 Marionette TRACE 358 -> [0,6,"getTitle",{}]
05:02:50 INFO - 1498996970992 Marionette TRACE 358 <- [1,6,null,{"value":"Marionette Test"}]
05:02:51 INFO - 1498996970999 Marionette TRACE 358 -> [0,7,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-END: test_click.py TestClick.test_clicking_on_a_multiline_link')","sandbox":"simpletest","line":328}]
05:02:51 INFO - TEST-END: test_click.py TestClick.test_clicking_on_a_multiline_link1498996971001 Marionette TRACE 358 <- [1,7,null,{"value":null}]
05:02:51 INFO - 1498996971003 Marionette TRACE 358 -> [0,8,"deleteSession",{}]
05:02:51 INFO - 1498996971004 Marionette TRACE 358 <- [1,8,null,{}]
05:02:51 INFO - TEST-PASS | test_click.py TestClick.test_clicking_on_a_multiline_link | took 221ms
05:02:51 INFO - TEST-START | test_click.py TestClick.test_container_element
05:02:51 INFO - 1498996971022 Marionette DEBUG Closed connection 358
05:02:51 INFO - 1498996971023 Marionette DEBUG Accepted connection 359 from 127.0.0.1:54333
05:02:51 INFO - 1498996971024 Marionette DEBUG Closed connection 359
05:02:51 INFO - 1498996971025 Marionette DEBUG Accepted connection 360 from 127.0.0.1:54334
05:02:51 INFO - 1498996971026 Marionette TRACE 360 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:02:51 INFO - 1498996971027 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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}
05:02:51 INFO - 1498996971029 Marionette DEBUG Register listener.js for window 12
05:02:51 INFO - 1498996971032 Marionette TRACE 360 <- [1,1,null,{"sessionId":"6d7274e5-d74a-4594-affb-8c15cbbfbb70","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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}}]
05:02:51 INFO - 1498996971033 Marionette TRACE 360 -> [0,2,"setTimeouts",{"script":30000}]
05:02:51 INFO - 1498996971034 Marionette TRACE 360 <- [1,2,null,{}]
05:02:51 INFO - 1498996971035 Marionette TRACE 360 -> [0,3,"setTimeouts",{"pageLoad":300000}]
05:02:51 INFO - 1498996971035 Marionette TRACE 360 <- [1,3,null,{}]
05:02:51 INFO - 1498996971036 Marionette TRACE 360 -> [0,4,"setTimeouts",{"implicit":0}]
05:02:51 INFO - 1498996971037 Marionette TRACE 360 <- [1,4,null,{}]
05:02:51 INFO - 1498996971039 Marionette TRACE 360 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-START: test_click.py TestClick.test_container_element')","sandbox":"simpletest","line":316}]
05:02:51 INFO - TEST-START: test_click.py TestClick.test_container_element1498996971041 Marionette TRACE 360 <- [1,5,null,{"value":null}]
05:02:51 INFO - 1498996971042 Marionette TRACE 360 -> [0,6,"deleteSession",{}]
05:02:51 INFO - 1498996971044 Marionette TRACE 360 <- [1,6,null,{}]
05:02:51 INFO - 1498996971046 Marionette DEBUG Closed connection 360
05:02:51 INFO - 1498996971046 Marionette DEBUG Accepted connection 361 from 127.0.0.1:54335
05:02:51 INFO - 1498996971047 Marionette DEBUG Closed connection 361
05:02:51 INFO - 1498996971048 Marionette DEBUG Accepted connection 362 from 127.0.0.1:54336
05:02:51 INFO - 1498996971049 Marionette TRACE 362 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:02:51 INFO - 1498996971049 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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}
05:02:51 INFO - 1498996971052 Marionette DEBUG Register listener.js for window 12
05:02:51 INFO - 1498996971055 Marionette TRACE 362 <- [1,1,null,{"sessionId":"91f6677d-a732-48a2-9c8e-ebf582fe3fbb","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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}}]
05:02:51 INFO - 1498996971056 Marionette TRACE 362 -> [0,2,"deleteSession",{}]
05:02:51 INFO - 1498996971057 Marionette TRACE 362 <- [1,2,null,{}]
05:02:51 INFO - 1498996971059 Marionette DEBUG Closed connection 362
05:02:51 INFO - 1498996971059 Marionette DEBUG Accepted connection 363 from 127.0.0.1:54337
05:02:51 INFO - 1498996971061 Marionette DEBUG Closed connection 363
05:02:51 INFO - 1498996971062 Marionette DEBUG Accepted connection 364 from 127.0.0.1:54338
05:02:51 INFO - 1498996971063 Marionette TRACE 364 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
05:02:51 INFO - 1498996971064 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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}
05:02:51 INFO - 1498996971066 Marionette DEBUG Register listener.js for window 12
05:02:51 INFO - 1498996971069 Marionette TRACE 364 <- [1,1,null,{"sessionId":"d436f53e-f2c9-4248-aefc-00bbacfe12fc","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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}}]
05:02:51 INFO - 1498996971070 Marionette TRACE 364 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"}]
05:02:51 INFO - 1498996971072 Marionette DEBUG Received DOM event "beforeunload" for "http://127.0.0.1:53894/test.html"
05:02:51 INFO - 1498996971074 Marionette DEBUG Received DOM event "pagehide" for "http://127.0.0.1:53894/test.html"
05:02:51 INFO - 1498996971074 Marionette DEBUG Received DOM event "unload" for "http://127.0.0.1:53894/test.html"
05:02:51 INFO - 1498996971098 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
05:02:51 INFO - 1498996971102 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
05:02:51 INFO - 1498996971106 Marionette TRACE 364 <- [1,2,null,{}]
05:02:51 INFO - 1498996971107 Marionette TRACE 364 -> [0,3,"findElement",{"using":"tag name","value":"option"}]
05:02:51 INFO - 1498996971110 Marionette TRACE 364 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"98e4a556-18a6-4ce6-8a8b-3ce707e9e5ba","ELEMENT":"98e4a556-18a6-4ce6-8a8b-3ce707e9e5ba"}}]
05:02:51 INFO - 1498996971121 Marionette TRACE 364 -> [0,4,"clickElement",{"id":"98e4a556-18a6-4ce6-8a8b-3ce707e9e5ba"}]
05:02:51 INFO - 1498996971362 Marionette DEBUG Canceled page load listener because no navigation has been detected
05:02:51 INFO - 1498996971363 Marionette TRACE 364 <- [1,4,null,{}]
05:02:51 INFO - 1498996971366 Marionette TRACE 364 -> [0,5,"getElementProperty",{"id":"98e4a556-18a6-4ce6-8a8b-3ce707e9e5ba","name":"selected"}]
05:02:51 INFO - 1498996971371 Marionette TRACE 364 <- [1,5,null,{"value":true}]
05:02:51 INFO - 1498996971377 Marionette TRACE 364 -> [0,6,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-END: test_click.py TestClick.test_container_element')","sandbox":"simpletest","line":328}]
05:02:51 INFO - TEST-END: test_click.py TestClick.test_container_element1498996971380 Marionette TRACE 364 <- [1,6,null,{"value":null}]
05:02:51 INFO - 1498996971381 Marionette TRACE 364 -> [0,7,"deleteSession",{}]
05:02:51 INFO - 1498996971382 Marionette TRACE 364 <- [1,7,null,{}]
05:02:51 INFO - TEST-PASS | test_click.py TestClick.test_container_element | took 377ms
05:02:51 INFO - TEST-START | test_click.py TestClick.test_container_element_outside_view
05:02:51 INFO - 1498996971384 Marionette DEBUG Closed connection 364
05:02:51 INFO - 1498996971385 Marionette DEBUG Accepted connection 365 from 127.0.0.1:54339
05:02:51 INFO - 1498996971386 Marionette DEBUG Closed connection 365
05:02:51 INFO - 1498996971387 Marionette DEBUG Accepted connection 366 from 127.0.0.1:54340
05:02:51 INFO - 1498996971388 Marionette TRACE 366 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:02:51 INFO - 1498996971389 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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}
05:02:51 INFO - 1498996971391 Marionette DEBUG Register listener.js for window 12
05:02:51 INFO - 1498996971394 Marionette TRACE 366 <- [1,1,null,{"sessionId":"10570aa9-a66e-428c-b391-9019e42a1e52","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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}}]
05:02:51 INFO - 1498996971396 Marionette TRACE 366 -> [0,2,"setTimeouts",{"script":30000}]
05:02:51 INFO - 1498996971396 Marionette TRACE 366 <- [1,2,null,{}]
05:02:51 INFO - 1498996971397 Marionette TRACE 366 -> [0,3,"setTimeouts",{"pageLoad":300000}]
05:02:51 INFO - 1498996971398 Marionette TRACE 366 <- [1,3,null,{}]
05:02:51 INFO - 1498996971398 Marionette TRACE 366 -> [0,4,"setTimeouts",{"implicit":0}]
05:02:51 INFO - 1498996971399 Marionette TRACE 366 <- [1,4,null,{}]
05:02:51 INFO - 1498996971401 Marionette TRACE 366 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-START: test_click.py TestClick.test_container_element_outside_view')","sandbox":"simpletest","line":316}]
05:02:51 INFO - TEST-START: test_click.py TestClick.test_container_element_outside_view1498996971404 Marionette TRACE 366 <- [1,5,null,{"value":null}]
05:02:51 INFO - 1498996971404 Marionette TRACE 366 -> [0,6,"deleteSession",{}]
05:02:51 INFO - 1498996971406 Marionette TRACE 366 <- [1,6,null,{}]
05:02:51 INFO - 1498996971408 Marionette DEBUG Closed connection 366
05:02:51 INFO - 1498996971409 Marionette DEBUG Accepted connection 367 from 127.0.0.1:54341
05:02:51 INFO - 1498996971409 Marionette DEBUG Closed connection 367
05:02:51 INFO - 1498996971410 Marionette DEBUG Accepted connection 368 from 127.0.0.1:54342
05:02:51 INFO - 1498996971411 Marionette TRACE 368 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:02:51 INFO - 1498996971412 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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}
05:02:51 INFO - 1498996971414 Marionette DEBUG Register listener.js for window 12
05:02:51 INFO - 1498996971417 Marionette TRACE 368 <- [1,1,null,{"sessionId":"bd86b947-88e7-469f-b66d-a54f5b6145bb","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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}}]
05:02:51 INFO - 1498996971418 Marionette TRACE 368 -> [0,2,"deleteSession",{}]
05:02:51 INFO - 1498996971419 Marionette TRACE 368 <- [1,2,null,{}]
05:02:51 INFO - 1498996971421 Marionette DEBUG Closed connection 368
05:02:51 INFO - 1498996971422 Marionette DEBUG Accepted connection 369 from 127.0.0.1:54343
05:02:51 INFO - 1498996971423 Marionette DEBUG Closed connection 369
05:02:51 INFO - 1498996971423 Marionette DEBUG Accepted connection 370 from 127.0.0.1:54344
05:02:51 INFO - 1498996971424 Marionette TRACE 370 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
05:02:51 INFO - 1498996971425 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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}
05:02:51 INFO - 1498996971427 Marionette DEBUG Register listener.js for window 12
05:02:51 INFO - 1498996971431 Marionette TRACE 370 <- [1,1,null,{"sessionId":"6cefb5a0-2fb7-458c-8ea3-a488e01665c5","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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}}]
05:02:51 INFO - 1498996971432 Marionette TRACE 370 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20style%3D%22margin-top%3A%20100vh%22%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"}]
05:02:51 INFO - 1498996971434 Marionette DEBUG Received DOM event "beforeunload" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
05:02:51 INFO - 1498996971437 Marionette DEBUG Received DOM event "pagehide" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
05:02:51 INFO - 1498996971437 Marionette DEBUG Received DOM event "unload" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
05:02:51 INFO - 1498996971459 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20style%3D%22margin-top%3A%20100vh%22%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
05:02:51 INFO - 1498996971468 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20style%3D%22margin-top%3A%20100vh%22%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
05:02:51 INFO - 1498996971471 Marionette TRACE 370 <- [1,2,null,{}]
05:02:51 INFO - 1498996971472 Marionette TRACE 370 -> [0,3,"findElement",{"using":"tag name","value":"option"}]
05:02:51 INFO - 1498996971475 Marionette TRACE 370 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"34d46d16-d6f3-4861-841d-aa0a4cead596","ELEMENT":"34d46d16-d6f3-4861-841d-aa0a4cead596"}}]
05:02:51 INFO - 1498996971481 Marionette TRACE 370 -> [0,4,"clickElement",{"id":"34d46d16-d6f3-4861-841d-aa0a4cead596"}]
05:02:51 INFO - 1498996971729 Marionette DEBUG Canceled page load listener because no navigation has been detected
05:02:51 INFO - 1498996971730 Marionette TRACE 370 <- [1,4,null,{}]
05:02:51 INFO - 1498996971731 Marionette TRACE 370 -> [0,5,"getElementProperty",{"id":"34d46d16-d6f3-4861-841d-aa0a4cead596","name":"selected"}]
05:02:51 INFO - 1498996971736 Marionette TRACE 370 <- [1,5,null,{"value":true}]
05:02:51 INFO - 1498996971737 Marionette TRACE 370 -> [0,6,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-END: test_click.py TestClick.test_container_element_outside_view')","sandbox":"simpletest","line":328}]
05:02:51 INFO - TEST-END: test_click.py TestClick.test_container_element_outside_view1498996971740 Marionette TRACE 370 <- [1,6,null,{"value":null}]
05:02:51 INFO - 1498996971741 Marionette TRACE 370 -> [0,7,"deleteSession",{}]
05:02:51 INFO - 1498996971742 Marionette TRACE 370 <- [1,7,null,{}]
05:02:51 INFO - TEST-PASS | test_click.py TestClick.test_container_element_outside_view | took 360ms
05:02:51 INFO - TEST-START | test_click.py TestClick.test_css_transforms
05:02:51 INFO - 1498996971744 Marionette DEBUG Closed connection 370
05:02:51 INFO - 1498996971746 Marionette DEBUG Accepted connection 371 from 127.0.0.1:54345
05:02:51 INFO - 1498996971746 Marionette DEBUG Closed connection 371
05:02:51 INFO - 1498996971747 Marionette DEBUG Accepted connection 372 from 127.0.0.1:54346
05:02:51 INFO - 1498996971748 Marionette TRACE 372 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:02:51 INFO - 1498996971749 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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}
05:02:51 INFO - 1498996971751 Marionette DEBUG Register listener.js for window 12
05:02:51 INFO - 1498996971754 Marionette TRACE 372 <- [1,1,null,{"sessionId":"8617c63c-0edb-446d-9caa-df558ea239f2","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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}}]
05:02:51 INFO - 1498996971756 Marionette TRACE 372 -> [0,2,"setTimeouts",{"script":30000}]
05:02:51 INFO - 1498996971756 Marionette TRACE 372 <- [1,2,null,{}]
05:02:51 INFO - 1498996971757 Marionette TRACE 372 -> [0,3,"setTimeouts",{"pageLoad":300000}]
05:02:51 INFO - 1498996971758 Marionette TRACE 372 <- [1,3,null,{}]
05:02:51 INFO - 1498996971758 Marionette TRACE 372 -> [0,4,"setTimeouts",{"implicit":0}]
05:02:51 INFO - 1498996971759 Marionette TRACE 372 <- [1,4,null,{}]
05:02:51 INFO - 1498996971761 Marionette TRACE 372 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-START: test_click.py TestClick.test_css_transforms')","sandbox":"simpletest","line":316}]
05:02:51 INFO - TEST-START: test_click.py TestClick.test_css_transforms1498996971764 Marionette TRACE 372 <- [1,5,null,{"value":null}]
05:02:51 INFO - 1498996971765 Marionette TRACE 372 -> [0,6,"deleteSession",{}]
05:02:51 INFO - 1498996971766 Marionette TRACE 372 <- [1,6,null,{}]
05:02:51 INFO - 1498996971768 Marionette DEBUG Closed connection 372
05:02:51 INFO - 1498996971768 Marionette DEBUG Accepted connection 373 from 127.0.0.1:54347
05:02:51 INFO - 1498996971769 Marionette DEBUG Closed connection 373
05:02:51 INFO - 1498996971770 Marionette DEBUG Accepted connection 374 from 127.0.0.1:54348
05:02:51 INFO - 1498996971771 Marionette TRACE 374 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:02:51 INFO - 1498996971772 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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}
05:02:51 INFO - 1498996971774 Marionette DEBUG Register listener.js for window 12
05:02:51 INFO - 1498996971777 Marionette TRACE 374 <- [1,1,null,{"sessionId":"6e637617-4892-47fd-9e75-cd9c0ecc1716","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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}}]
05:02:51 INFO - 1498996971779 Marionette TRACE 374 -> [0,2,"deleteSession",{}]
05:02:51 INFO - 1498996971780 Marionette TRACE 374 <- [1,2,null,{}]
05:02:51 INFO - 1498996971782 Marionette DEBUG Closed connection 374
05:02:51 INFO - 1498996971782 Marionette DEBUG Accepted connection 375 from 127.0.0.1:54349
05:02:51 INFO - 1498996971783 Marionette DEBUG Closed connection 375
05:02:51 INFO - 1498996971784 Marionette DEBUG Accepted connection 376 from 127.0.0.1:54350
05:02:51 INFO - 1498996971785 Marionette TRACE 376 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
05:02:51 INFO - 1498996971786 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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}
05:02:51 INFO - 1498996971788 Marionette DEBUG Register listener.js for window 12
05:02:51 INFO - 1498996971791 Marionette TRACE 376 <- [1,1,null,{"sessionId":"5737ecd6-77e9-4ab7-823a-47047308a453","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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}}]
05:02:51 INFO - 1498996971792 Marionette TRACE 376 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cstyle%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20div%20%7B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20display%3A%20block%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20background-color%3A%20blue%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20width%3A%20200px%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20height%3A%20200px%3B%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%20transform%3A%20translateX%28-105px%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/style%3E%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cdiv%3E%3C/div%3E"}]
05:02:51 INFO - 1498996971794 Marionette DEBUG Received DOM event "beforeunload" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20style%3D%22margin-top%3A%20100vh%22%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
05:02:51 INFO - 1498996971796 Marionette DEBUG Received DOM event "pagehide" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20style%3D%22margin-top%3A%20100vh%22%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
05:02:51 INFO - 1498996971796 Marionette DEBUG Received DOM event "unload" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20style%3D%22margin-top%3A%20100vh%22%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efoo%3C/option%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
05:02:51 INFO - 1498996971810 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cstyle%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20div%20%7B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20display%3A%20block%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20background-color%3A%20blue%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20width%3A%20200px%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20height%3A%20200px%3B%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%20transform%3A%20translateX%28-105px%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/style%3E%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cdiv%3E%3C/div%3E"
05:02:51 INFO - 1498996971815 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cstyle%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20div%20%7B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20display%3A%20block%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20background-color%3A%20blue%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20width%3A%20200px%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20height%3A%20200px%3B%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%20transform%3A%20translateX%28-105px%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/style%3E%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cdiv%3E%3C/div%3E"
05:02:51 INFO - 1498996971825 Marionette TRACE 376 <- [1,2,null,{}]
05:02:51 INFO - 1498996971828 Marionette TRACE 376 -> [0,3,"findElement",{"using":"tag name","value":"div"}]
05:02:51 INFO - 1498996971831 Marionette TRACE 376 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"79a10f0d-7014-4b1b-8802-48299be7f181","ELEMENT":"79a10f0d-7014-4b1b-8802-48299be7f181"}}]
05:02:51 INFO - 1498996971832 Marionette TRACE 376 -> [0,4,"clickElement",{"id":"79a10f0d-7014-4b1b-8802-48299be7f181"}]
05:02:52 INFO - 1498996972069 Marionette DEBUG Canceled page load listener because no navigation has been detected
05:02:52 INFO - 1498996972070 Marionette TRACE 376 <- [1,4,null,{}]
05:02:52 INFO - 1498996972072 Marionette TRACE 376 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-END: test_click.py TestClick.test_css_transforms')","sandbox":"simpletest","line":328}]
05:02:52 INFO - TEST-END: test_click.py TestClick.test_css_transforms1498996972075 Marionette TRACE 376 <- [1,5,null,{"value":null}]
05:02:52 INFO - 1498996972076 Marionette TRACE 376 -> [0,6,"deleteSession",{}]
05:02:52 INFO - TEST-PASS | test_click.py TestClick.test_css_transforms | took 335ms
05:02:52 INFO - TEST-START | test_click.py TestClick.test_inclusive_descendant
05:02:52 INFO - 1498996972077 Marionette TRACE 376 <- [1,6,null,{}]
05:02:52 INFO - 1498996972079 Marionette DEBUG Closed connection 376
05:02:52 INFO - 1498996972081 Marionette DEBUG Accepted connection 377 from 127.0.0.1:54351
05:02:52 INFO - 1498996972082 Marionette DEBUG Closed connection 377
05:02:52 INFO - 1498996972082 Marionette DEBUG Accepted connection 378 from 127.0.0.1:54352
05:02:52 INFO - 1498996972083 Marionette TRACE 378 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:02:52 INFO - 1498996972084 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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}
05:02:52 INFO - 1498996972086 Marionette DEBUG Register listener.js for window 12
05:02:52 INFO - 1498996972089 Marionette TRACE 378 <- [1,1,null,{"sessionId":"34af932e-4598-4143-8759-27633db8746e","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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}}]
05:02:52 INFO - 1498996972090 Marionette TRACE 378 -> [0,2,"setTimeouts",{"script":30000}]
05:02:52 INFO - 1498996972091 Marionette TRACE 378 <- [1,2,null,{}]
05:02:52 INFO - 1498996972092 Marionette TRACE 378 -> [0,3,"setTimeouts",{"pageLoad":300000}]
05:02:52 INFO - 1498996972093 Marionette TRACE 378 <- [1,3,null,{}]
05:02:52 INFO - 1498996972093 Marionette TRACE 378 -> [0,4,"setTimeouts",{"implicit":0}]
05:02:52 INFO - 1498996972094 Marionette TRACE 378 <- [1,4,null,{}]
05:02:52 INFO - 1498996972096 Marionette TRACE 378 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-START: test_click.py TestClick.test_inclusive_descendant')","sandbox":"simpletest","line":316}]
05:02:52 INFO - TEST-START: test_click.py TestClick.test_inclusive_descendant1498996972098 Marionette TRACE 378 <- [1,5,null,{"value":null}]
05:02:52 INFO - 1498996972099 Marionette TRACE 378 -> [0,6,"deleteSession",{}]
05:02:52 INFO - 1498996972100 Marionette TRACE 378 <- [1,6,null,{}]
05:02:52 INFO - 1498996972102 Marionette DEBUG Closed connection 378
05:02:52 INFO - 1498996972103 Marionette DEBUG Accepted connection 379 from 127.0.0.1:54353
05:02:52 INFO - 1498996972104 Marionette DEBUG Closed connection 379
05:02:52 INFO - 1498996972105 Marionette DEBUG Accepted connection 380 from 127.0.0.1:54354
05:02:52 INFO - 1498996972105 Marionette TRACE 380 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:02:52 INFO - 1498996972106 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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}
05:02:52 INFO - 1498996972108 Marionette DEBUG Register listener.js for window 12
05:02:52 INFO - 1498996972111 Marionette TRACE 380 <- [1,1,null,{"sessionId":"039517a5-afea-43ed-8c7d-26fac14f225e","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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}}]
05:02:52 INFO - 1498996972113 Marionette TRACE 380 -> [0,2,"deleteSession",{}]
05:02:52 INFO - 1498996972114 Marionette TRACE 380 <- [1,2,null,{}]
05:02:52 INFO - 1498996972115 Marionette DEBUG Closed connection 380
05:02:52 INFO - 1498996972116 Marionette DEBUG Accepted connection 381 from 127.0.0.1:54355
05:02:52 INFO - 1498996972117 Marionette DEBUG Closed connection 381
05:02:52 INFO - 1498996972118 Marionette DEBUG Accepted connection 382 from 127.0.0.1:54356
05:02:52 INFO - 1498996972119 Marionette TRACE 382 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
05:02:52 INFO - 1498996972119 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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}
05:02:52 INFO - 1498996972121 Marionette DEBUG Register listener.js for window 12
05:02:52 INFO - 1498996972124 Marionette TRACE 382 <- [1,1,null,{"sessionId":"7453ea86-5cd1-4b3a-9cc1-e3e4ff9f9592","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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}}]
05:02:52 INFO - 1498996972125 Marionette TRACE 382 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20multiple%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efirst%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Esecond%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Ethird%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"}]
05:02:52 INFO - 1498996972127 Marionette DEBUG Received DOM event "beforeunload" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cstyle%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20div%20%7B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20display%3A%20block%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20background-color%3A%20blue%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20width%3A%20200px%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20height%3A%20200px%3B%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%20transform%3A%20translateX%28-105px%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/style%3E%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cdiv%3E%3C/div%3E"
05:02:52 INFO - 1498996972129 Marionette DEBUG Received DOM event "pagehide" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cstyle%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20div%20%7B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20display%3A%20block%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20background-color%3A%20blue%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20width%3A%20200px%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20height%3A%20200px%3B%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%20transform%3A%20translateX%28-105px%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/style%3E%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cdiv%3E%3C/div%3E"
05:02:52 INFO - 1498996972129 Marionette DEBUG Received DOM event "unload" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cstyle%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20div%20%7B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20display%3A%20block%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20background-color%3A%20blue%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20width%3A%20200px%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20height%3A%20200px%3B%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%20transform%3A%20translateX%28-105px%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/style%3E%0A%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cdiv%3E%3C/div%3E"
05:02:52 INFO - 1498996972140 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20multiple%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efirst%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Esecond%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Ethird%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
05:02:52 INFO - 1498996972144 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20multiple%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efirst%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Esecond%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Ethird%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
05:02:52 INFO - 1498996972155 Marionette TRACE 382 <- [1,2,null,{}]
05:02:52 INFO - 1498996972159 Marionette TRACE 382 -> [0,3,"findElement",{"using":"tag name","value":"select"}]
05:02:52 INFO - 1498996972162 Marionette TRACE 382 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"a603ef5d-2c6e-4e0e-ac00-71a4860d2624","ELEMENT":"a603ef5d-2c6e-4e0e-ac00-71a4860d2624"}}]
05:02:52 INFO - 1498996972163 Marionette TRACE 382 -> [0,4,"clickElement",{"id":"a603ef5d-2c6e-4e0e-ac00-71a4860d2624"}]
05:02:52 INFO - 1498996972410 Marionette DEBUG Canceled page load listener because no navigation has been detected
05:02:52 INFO - 1498996972411 Marionette TRACE 382 <- [1,4,null,{}]
05:02:52 INFO - 1498996972413 Marionette TRACE 382 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-END: test_click.py TestClick.test_inclusive_descendant')","sandbox":"simpletest","line":328}]
05:02:52 INFO - TEST-END: test_click.py TestClick.test_inclusive_descendant1498996972416 Marionette TRACE 382 <- [1,5,null,{"value":null}]
05:02:52 INFO - 1498996972417 Marionette TRACE 382 -> [0,6,"deleteSession",{}]
05:02:52 INFO - 1498996972418 Marionette TRACE 382 <- [1,6,null,{}]
05:02:52 INFO - TEST-PASS | test_click.py TestClick.test_inclusive_descendant | took 341ms
05:02:52 INFO - TEST-START | test_click.py TestClick.test_input_file
05:02:52 INFO - 1498996972420 Marionette DEBUG Closed connection 382
05:02:52 INFO - 1498996972421 Marionette DEBUG Accepted connection 383 from 127.0.0.1:54357
05:02:52 INFO - 1498996972422 Marionette DEBUG Closed connection 383
05:02:52 INFO - 1498996972423 Marionette DEBUG Accepted connection 384 from 127.0.0.1:54358
05:02:52 INFO - 1498996972424 Marionette TRACE 384 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:02:52 INFO - 1498996972424 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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}
05:02:52 INFO - 1498996972427 Marionette DEBUG Register listener.js for window 12
05:02:52 INFO - 1498996972430 Marionette TRACE 384 <- [1,1,null,{"sessionId":"28ea9373-06f5-4c3f-9196-5b747b708c58","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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}}]
05:02:52 INFO - 1498996972431 Marionette TRACE 384 -> [0,2,"setTimeouts",{"script":30000}]
05:02:52 INFO - 1498996972432 Marionette TRACE 384 <- [1,2,null,{}]
05:02:52 INFO - 1498996972433 Marionette TRACE 384 -> [0,3,"setTimeouts",{"pageLoad":300000}]
05:02:52 INFO - 1498996972433 Marionette TRACE 384 <- [1,3,null,{}]
05:02:52 INFO - 1498996972434 Marionette TRACE 384 -> [0,4,"setTimeouts",{"implicit":0}]
05:02:52 INFO - 1498996972434 Marionette TRACE 384 <- [1,4,null,{}]
05:02:52 INFO - 1498996972436 Marionette TRACE 384 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-START: test_click.py TestClick.test_input_file')","sandbox":"simpletest","line":316}]
05:02:52 INFO - TEST-START: test_click.py TestClick.test_input_file1498996972439 Marionette TRACE 384 <- [1,5,null,{"value":null}]
05:02:52 INFO - 1498996972440 Marionette TRACE 384 -> [0,6,"deleteSession",{}]
05:02:52 INFO - 1498996972441 Marionette TRACE 384 <- [1,6,null,{}]
05:02:52 INFO - 1498996972443 Marionette DEBUG Closed connection 384
05:02:52 INFO - 1498996972444 Marionette DEBUG Accepted connection 385 from 127.0.0.1:54359
05:02:52 INFO - 1498996972445 Marionette DEBUG Closed connection 385
05:02:52 INFO - 1498996972445 Marionette DEBUG Accepted connection 386 from 127.0.0.1:54360
05:02:52 INFO - 1498996972446 Marionette TRACE 386 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:02:52 INFO - 1498996972447 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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}
05:02:52 INFO - 1498996972449 Marionette DEBUG Register listener.js for window 12
05:02:52 INFO - 1498996972452 Marionette TRACE 386 <- [1,1,null,{"sessionId":"c028df0f-005f-430a-9e3d-4400915139ea","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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}}]
05:02:52 INFO - 1498996972453 Marionette TRACE 386 -> [0,2,"deleteSession",{}]
05:02:52 INFO - 1498996972454 Marionette TRACE 386 <- [1,2,null,{}]
05:02:52 INFO - 1498996972456 Marionette DEBUG Closed connection 386
05:02:52 INFO - 1498996972457 Marionette DEBUG Accepted connection 387 from 127.0.0.1:54361
05:02:52 INFO - 1498996972458 Marionette DEBUG Closed connection 387
05:02:52 INFO - 1498996972458 Marionette DEBUG Accepted connection 388 from 127.0.0.1:54362
05:02:52 INFO - 1498996972465 Marionette TRACE 388 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
05:02:52 INFO - 1498996972465 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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}
05:02:52 INFO - 1498996972467 Marionette DEBUG Register listener.js for window 12
05:02:52 INFO - 1498996972470 Marionette TRACE 388 <- [1,1,null,{"sessionId":"453b0b4d-e2ad-48bf-b9f9-a8a1820b75d0","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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}}]
05:02:52 INFO - 1498996972472 Marionette TRACE 388 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"}]
05:02:52 INFO - 1498996972473 Marionette DEBUG Received DOM event "beforeunload" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20multiple%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efirst%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Esecond%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Ethird%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
05:02:52 INFO - 1498996972476 Marionette DEBUG Received DOM event "pagehide" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20multiple%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efirst%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Esecond%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Ethird%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
05:02:52 INFO - 1498996972476 Marionette DEBUG Received DOM event "unload" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cselect%20multiple%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Efirst%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Esecond%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3Coption%3Ethird%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%3C/select%3E"
05:02:52 INFO - 1498996972499 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
05:02:52 INFO - 1498996972500 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
05:02:52 INFO - 1498996972503 Marionette TRACE 388 <- [1,2,null,{}]
05:02:52 INFO - 1498996972506 Marionette TRACE 388 -> [0,3,"findElement",{"using":"tag name","value":"input"}]
05:02:52 INFO - 1498996972509 Marionette TRACE 388 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"977b8f3a-43fc-4884-a087-881d7f1b684c","ELEMENT":"977b8f3a-43fc-4884-a087-881d7f1b684c"}}]
05:02:52 INFO - 1498996972516 Marionette TRACE 388 -> [0,4,"clickElement",{"id":"977b8f3a-43fc-4884-a087-881d7f1b684c"}]
05:02:52 INFO - 1498996972544 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:393:12\nclickElement@chrome://marionette/content/listener.js:1330:5\n"},null]
05:02:52 INFO - 1498996972547 Marionette TRACE 388 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-END: test_click.py TestClick.test_input_file')","sandbox":"simpletest","line":328}]
05:02:52 INFO - TEST-END: test_click.py TestClick.test_input_file1498996972550 Marionette TRACE 388 <- [1,5,null,{"value":null}]
05:02:52 INFO - 1498996972551 Marionette TRACE 388 -> [0,6,"deleteSession",{}]
05:02:52 INFO - 1498996972552 Marionette TRACE 388 <- [1,6,null,{}]
05:02:52 INFO - TEST-PASS | test_click.py TestClick.test_input_file | took 133ms
05:02:52 INFO - TEST-START | test_click.py TestClick.test_obscured_element
05:02:52 INFO - 1498996972555 Marionette DEBUG Closed connection 388
05:02:52 INFO - 1498996972556 Marionette DEBUG Accepted connection 389 from 127.0.0.1:54363
05:02:52 INFO - 1498996972556 Marionette DEBUG Closed connection 389
05:02:52 INFO - 1498996972557 Marionette DEBUG Accepted connection 390 from 127.0.0.1:54364
05:02:52 INFO - 1498996972558 Marionette TRACE 390 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:02:52 INFO - 1498996972559 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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}
05:02:52 INFO - 1498996972561 Marionette DEBUG Register listener.js for window 12
05:02:52 INFO - 1498996972564 Marionette TRACE 390 <- [1,1,null,{"sessionId":"25e9d5e7-e3d8-446a-ab86-5e620db11e2d","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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}}]
05:02:52 INFO - 1498996972565 Marionette TRACE 390 -> [0,2,"setTimeouts",{"script":30000}]
05:02:52 INFO - 1498996972566 Marionette TRACE 390 <- [1,2,null,{}]
05:02:52 INFO - 1498996972567 Marionette TRACE 390 -> [0,3,"setTimeouts",{"pageLoad":300000}]
05:02:52 INFO - 1498996972567 Marionette TRACE 390 <- [1,3,null,{}]
05:02:52 INFO - 1498996972568 Marionette TRACE 390 -> [0,4,"setTimeouts",{"implicit":0}]
05:02:52 INFO - 1498996972568 Marionette TRACE 390 <- [1,4,null,{}]
05:02:52 INFO - 1498996972570 Marionette TRACE 390 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-START: test_click.py TestClick.test_obscured_element')","sandbox":"simpletest","line":316}]
05:02:52 INFO - TEST-START: test_click.py TestClick.test_obscured_element1498996972573 Marionette TRACE 390 <- [1,5,null,{"value":null}]
05:02:52 INFO - 1498996972573 Marionette TRACE 390 -> [0,6,"deleteSession",{}]
05:02:52 INFO - 1498996972575 Marionette TRACE 390 <- [1,6,null,{}]
05:02:52 INFO - 1498996972577 Marionette DEBUG Closed connection 390
05:02:52 INFO - 1498996972577 Marionette DEBUG Accepted connection 391 from 127.0.0.1:54365
05:02:52 INFO - 1498996972578 Marionette DEBUG Closed connection 391
05:02:52 INFO - 1498996972579 Marionette DEBUG Accepted connection 392 from 127.0.0.1:54366
05:02:52 INFO - 1498996972580 Marionette TRACE 392 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:02:52 INFO - 1498996972580 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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}
05:02:52 INFO - 1498996972582 Marionette DEBUG Register listener.js for window 12
05:02:52 INFO - 1498996972586 Marionette TRACE 392 <- [1,1,null,{"sessionId":"b9b6d3cb-a11f-43b3-8f17-abc067cd245b","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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}}]
05:02:52 INFO - 1498996972587 Marionette TRACE 392 -> [0,2,"deleteSession",{}]
05:02:52 INFO - 1498996972588 Marionette TRACE 392 <- [1,2,null,{}]
05:02:52 INFO - 1498996972590 Marionette DEBUG Closed connection 392
05:02:52 INFO - 1498996972590 Marionette DEBUG Accepted connection 393 from 127.0.0.1:54367
05:02:52 INFO - 1498996972591 Marionette DEBUG Closed connection 393
05:02:52 INFO - 1498996972592 Marionette DEBUG Accepted connection 394 from 127.0.0.1:54368
05:02:52 INFO - 1498996972593 Marionette TRACE 394 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
05:02:52 INFO - 1498996972593 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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}
05:02:52 INFO - 1498996972595 Marionette DEBUG Register listener.js for window 12
05:02:52 INFO - 1498996972598 Marionette TRACE 394 <- [1,1,null,{"sessionId":"e81b8875-f266-4a74-907c-432b9b284b9a","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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}}]
05:02:52 INFO - 1498996972600 Marionette TRACE 394 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%0A%3Cstyle%3E%0A%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0Abody%20%7B%20height%3A%20100vh%20%7D%0A%23overlay%20%7B%0A%20%20background-color%3A%20pink%3B%0A%20%20position%3A%20absolute%3B%0A%20%20width%3A%20100%25%3B%0A%20%20height%3A%20100%25%3B%0A%7D%0A%3C/style%3E%0A%0A%3Cdiv%20id%3Doverlay%3E%3C/div%3E%0A%3Ca%20id%3Dobscured%20href%3D%23%3Elink%3C/a%3E%0A%0A%3Cscript%3E%0Awindow.clicked%20%3D%20false%3B%0A%0Alet%20link%20%3D%20document.querySelector%28%22%23obscured%22%29%3B%0Alink.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%3C/script%3E%0A"}]
05:02:52 INFO - 1498996972601 Marionette DEBUG Received DOM event "beforeunload" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
05:02:52 INFO - 1498996972603 Marionette DEBUG Received DOM event "pagehide" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
05:02:52 INFO - 1498996972603 Marionette DEBUG Received DOM event "unload" for "data:text/html;charset=utf-8,%3Cinput%20type%3Dfile%3E"
05:02:52 INFO - 1498996972623 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%0A%3Cstyle%3E%0A%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0Abody%20%7B%20height%3A%20100vh%20%7D%0A%23overlay%20%7B%0A%20%20background-color%3A%20pink%3B%0A%20%20position%3A%20absolute%3B%0A%20%20width%3A%20100%25%3B%0A%20%20height%3A%20100%25%3B%0A%7D%0A%3C/style%3E%0A%0A%3Cdiv%20id%3Doverlay%3E%3C/div%3E%0A%3Ca%20id%3Dobscured%20href%3D%23%3Elink%3C/a%3E%0A%0A%3Cscript%3E%0Awindow.clicked%20%3D%20false%3B%0A%0Alet%20link%20%3D%20document.querySelector%28%22%23obscured%22%29%3B%0Alink.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%3C/script%3E%0A"
05:02:52 INFO - 1498996972625 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%0A%3Cstyle%3E%0A%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0Abody%20%7B%20height%3A%20100vh%20%7D%0A%23overlay%20%7B%0A%20%20background-color%3A%20pink%3B%0A%20%20position%3A%20absolute%3B%0A%20%20width%3A%20100%25%3B%0A%20%20height%3A%20100%25%3B%0A%7D%0A%3C/style%3E%0A%0A%3Cdiv%20id%3Doverlay%3E%3C/div%3E%0A%3Ca%20id%3Dobscured%20href%3D%23%3Elink%3C/a%3E%0A%0A%3Cscript%3E%0Awindow.clicked%20%3D%20false%3B%0A%0Alet%20link%20%3D%20document.querySelector%28%22%23obscured%22%29%3B%0Alink.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%3C/script%3E%0A"
05:02:52 INFO - 1498996972633 Marionette TRACE 394 <- [1,2,null,{}]
05:02:52 INFO - 1498996972635 Marionette TRACE 394 -> [0,3,"findElement",{"using":"id","value":"overlay"}]
05:02:52 INFO - 1498996972638 Marionette TRACE 394 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"5755e109-a13c-4740-a09a-57e465b06f5d","ELEMENT":"5755e109-a13c-4740-a09a-57e465b06f5d"}}]
05:02:52 INFO - 1498996972639 Marionette TRACE 394 -> [0,4,"findElement",{"using":"id","value":"obscured"}]
05:02:52 INFO - 1498996972641 Marionette TRACE 394 <- [1,4,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"5cf503b8-2193-4a4f-a632-9f9eda59ba8a","ELEMENT":"5cf503b8-2193-4a4f-a632-9f9eda59ba8a"}}]
05:02:52 INFO - 1498996972642 Marionette TRACE 394 -> [0,5,"clickElement",{"id":"5755e109-a13c-4740-a09a-57e465b06f5d"}]
05:02:52 INFO - 1498996972880 Marionette DEBUG Canceled page load listener because no navigation has been detected
05:02:52 INFO - 1498996972881 Marionette TRACE 394 <- [1,5,null,{}]
05:02:52 INFO - 1498996972882 Marionette TRACE 394 -> [0,6,"clickElement",{"id":"5cf503b8-2193-4a4f-a632-9f9eda59ba8a"}]
05:02:52 INFO - 1498996972897 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:393:12\nclickElement@chrome://marionette/content/listener.js:1330:5\n"},null]
05:02:52 INFO - 1498996972899 Marionette TRACE 394 -> [0,7,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"test_click.py","script":"return window.clicked","sandbox":null,"line":257}]
05:02:52 INFO - 1498996972902 Marionette TRACE 394 <- [1,7,null,{"value":false}]
05:02:52 INFO - 1498996972903 Marionette TRACE 394 -> [0,8,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-END: test_click.py TestClick.test_obscured_element')","sandbox":"simpletest","line":328}]
05:02:52 INFO - TEST-END: test_click.py TestClick.test_obscured_element1498996972906 Marionette TRACE 394 <- [1,8,null,{"value":null}]
05:02:52 INFO - 1498996972907 Marionette TRACE 394 -> [0,9,"deleteSession",{}]
05:02:52 INFO - TEST-PASS | test_click.py TestClick.test_obscured_element | took 356ms
05:02:52 INFO - TEST-START | test_click.py TestClick.test_pointer_events_none
05:02:52 INFO - 1498996972908 Marionette TRACE 394 <- [1,9,null,{}]
05:02:52 INFO - 1498996972910 Marionette DEBUG Closed connection 394
05:02:52 INFO - 1498996972911 Marionette DEBUG Accepted connection 395 from 127.0.0.1:54369
05:02:52 INFO - 1498996972912 Marionette DEBUG Closed connection 395
05:02:52 INFO - 1498996972913 Marionette DEBUG Accepted connection 396 from 127.0.0.1:54370
05:02:52 INFO - 1498996972914 Marionette TRACE 396 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:02:52 INFO - 1498996972914 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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}
05:02:52 INFO - 1498996972916 Marionette DEBUG Register listener.js for window 12
05:02:52 INFO - 1498996972928 Marionette TRACE 396 <- [1,1,null,{"sessionId":"2978239f-6365-41d5-a693-58555cf609ff","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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}}]
05:02:52 INFO - 1498996972929 Marionette TRACE 396 -> [0,2,"setTimeouts",{"script":30000}]
05:02:52 INFO - 1498996972930 Marionette TRACE 396 <- [1,2,null,{}]
05:02:52 INFO - 1498996972931 Marionette TRACE 396 -> [0,3,"setTimeouts",{"pageLoad":300000}]
05:02:52 INFO - 1498996972931 Marionette TRACE 396 <- [1,3,null,{}]
05:02:52 INFO - 1498996972932 Marionette TRACE 396 -> [0,4,"setTimeouts",{"implicit":0}]
05:02:52 INFO - 1498996972932 Marionette TRACE 396 <- [1,4,null,{}]
05:02:52 INFO - 1498996972934 Marionette TRACE 396 -> [0,5,"executeScript",{"scriptTimeout":null,"newSandbox":true,"args":[],"filename":"testcases.py","script":"dump('TEST-START: test_click.py TestClick.test_pointer_events_none')","sandbox":"simpletest","line":316}]
05:02:52 INFO - TEST-START: test_click.py TestClick.test_pointer_events_none1498996972938 Marionette TRACE 396 <- [1,5,null,{"value":null}]
05:02:52 INFO - 1498996972939 Marionette TRACE 396 -> [0,6,"deleteSession",{}]
05:02:52 INFO - 1498996972940 Marionette TRACE 396 <- [1,6,null,{}]
05:02:52 INFO - 1498996972942 Marionette DEBUG Closed connection 396
05:02:52 INFO - 1498996972942 Marionette DEBUG Accepted connection 397 from 127.0.0.1:54371
05:02:52 INFO - 1498996972943 Marionette DEBUG Closed connection 397
05:02:52 INFO - 1498996972944 Marionette DEBUG Accepted connection 398 from 127.0.0.1:54372
05:02:52 INFO - 1498996972945 Marionette TRACE 398 -> [0,1,"newSession",{"sessionId":null,"capabilities":null}]
05:02:52 INFO - 1498996972945 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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}
05:02:52 INFO - 1498996972947 Marionette DEBUG Register listener.js for window 12
05:02:52 INFO - 1498996972950 Marionette TRACE 398 <- [1,1,null,{"sessionId":"83ecad9e-712b-4ab5-b092-a262d98b1223","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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}}]
05:02:52 INFO - 1498996972951 Marionette TRACE 398 -> [0,2,"deleteSession",{}]
05:02:52 INFO - 1498996972952 Marionette TRACE 398 <- [1,2,null,{}]
05:02:52 INFO - 1498996972959 Marionette DEBUG Closed connection 398
05:02:52 INFO - 1498996972959 Marionette DEBUG Accepted connection 399 from 127.0.0.1:54373
05:02:52 INFO - 1498996972961 Marionette DEBUG Closed connection 399
05:02:52 INFO - 1498996972961 Marionette DEBUG Accepted connection 400 from 127.0.0.1:54374
05:02:52 INFO - 1498996972963 Marionette TRACE 400 -> [0,1,"newSession",{"sessionId":null,"capabilities":{"requiredCapabilities":{"specificationLevel":1}}}]
05:02:52 INFO - 1498996972964 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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}
05:02:52 INFO - 1498996972966 Marionette DEBUG Register listener.js for window 12
05:02:52 INFO - 1498996972969 Marionette TRACE 400 <- [1,1,null,{"sessionId":"b10ca414-2bd4-41a6-aa70-f6d5929ad99e","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":2292,"moz:profile":"C:\\Users\\cltbld\\AppData\\Local\\Temp\\tmp4bj1ce.mozrunner","moz:accessibilityChecks":false}}]
05:02:52 INFO - 1498996972970 Marionette TRACE 400 -> [0,2,"get",{"url":"data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cbutton%20style%3D%22pointer-events%3A%20none%22%3Eclick%20me%3C/button%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cscript%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20window.clicked%20%3D%20false%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20let%20button%20%3D%20document.querySelector%28%22button%22%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20button.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/script%3E%0A%20%20%20%20%20%20%20%20"}]
05:02:52 INFO - 1498996972971 Marionette DEBUG Received DOM event "beforeunload" for "data:text/html;charset=utf-8,%0A%3Cstyle%3E%0A%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0Abody%20%7B%20height%3A%20100vh%20%7D%0A%23overlay%20%7B%0A%20%20background-color%3A%20pink%3B%0A%20%20position%3A%20absolute%3B%0A%20%20width%3A%20100%25%3B%0A%20%20height%3A%20100%25%3B%0A%7D%0A%3C/style%3E%0A%0A%3Cdiv%20id%3Doverlay%3E%3C/div%3E%0A%3Ca%20id%3Dobscured%20href%3D%23%3Elink%3C/a%3E%0A%0A%3Cscript%3E%0Awindow.clicked%20%3D%20false%3B%0A%0Alet%20link%20%3D%20document.querySelector%28%22%23obscured%22%29%3B%0Alink.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%3C/script%3E%0A"
05:02:52 INFO - 1498996972973 Marionette DEBUG Received DOM event "pagehide" for "data:text/html;charset=utf-8,%0A%3Cstyle%3E%0A%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0Abody%20%7B%20height%3A%20100vh%20%7D%0A%23overlay%20%7B%0A%20%20background-color%3A%20pink%3B%0A%20%20position%3A%20absolute%3B%0A%20%20width%3A%20100%25%3B%0A%20%20height%3A%20100%25%3B%0A%7D%0A%3C/style%3E%0A%0A%3Cdiv%20id%3Doverlay%3E%3C/div%3E%0A%3Ca%20id%3Dobscured%20href%3D%23%3Elink%3C/a%3E%0A%0A%3Cscript%3E%0Awindow.clicked%20%3D%20false%3B%0A%0Alet%20link%20%3D%20document.querySelector%28%22%23obscured%22%29%3B%0Alink.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%3C/script%3E%0A"
05:02:52 INFO - 1498996972974 Marionette DEBUG Received DOM event "unload" for "data:text/html;charset=utf-8,%0A%3Cstyle%3E%0A%2A%20%7B%20margin%3A%200%3B%20padding%3A%200%3B%20%7D%0Abody%20%7B%20height%3A%20100vh%20%7D%0A%23overlay%20%7B%0A%20%20background-color%3A%20pink%3B%0A%20%20position%3A%20absolute%3B%0A%20%20width%3A%20100%25%3B%0A%20%20height%3A%20100%25%3B%0A%7D%0A%3C/style%3E%0A%0A%3Cdiv%20id%3Doverlay%3E%3C/div%3E%0A%3Ca%20id%3Dobscured%20href%3D%23%3Elink%3C/a%3E%0A%0A%3Cscript%3E%0Awindow.clicked%20%3D%20false%3B%0A%0Alet%20link%20%3D%20document.querySelector%28%22%23obscured%22%29%3B%0Alink.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%3C/script%3E%0A"
05:02:52 INFO - 1498996972991 Marionette DEBUG Received DOM event "DOMContentLoaded" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cbutton%20style%3D%22pointer-events%3A%20none%22%3Eclick%20me%3C/button%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cscript%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20window.clicked%20%3D%20false%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20let%20button%20%3D%20document.querySelector%28%22button%22%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20button.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/script%3E%0A%20%20%20%20%20%20%20%20"
05:02:52 INFO - 1498996972994 Marionette DEBUG Received DOM event "pageshow" for "data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cbutton%20style%3D%22pointer-events%3A%20none%22%3Eclick%20me%3C/button%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%3Cscript%3E%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20window.clicked%20%3D%20false%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20let%20button%20%3D%20document.querySelector%28%22button%22%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20button.addEventListener%28%22click%22%2C%20%28%29%20%3D%3E%20window.clicked%20%3D%20true%29%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%3C/script%3E%0A%20%20%20%20%20%20%20%20"
05:02:53 INFO - 1498996973003 Marionette TRACE 400 <- [1,2,null,{}]
05:02:53 INFO - 1498996973005 Marionette TRACE 400 -> [0,3,"findElement",{"using":"tag name","value":"button"}]
05:02:53 INFO - 1498996973007 Marionette TRACE 400 <- [1,3,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"0a52ccdb-aca7-4e47-b154-d1e7d702ba4c","ELEMENT":"0a52ccdb-aca7-4e47-b154-d1e7d702ba4c"}}]
05:02:53 INFO - 1498996973008 Marionette TRACE 400 -> [0,4,"getElementValueOfCssProperty",{"propertyName":"pointer-events","id":"0a52ccdb-aca7-4e47-b154-d1e7d702ba4c"}]
05:02:53 INFO - 1498996973030 Marionette TRACE 400 <- [1,4,null,{"value":"none"}]
05:02:53 INFO - 1498996973032 Marionette TRACE 400 -> [0,5,"clickElement",{"id":"0a52ccdb-aca7-4e47-b154-d1e7d702ba4c"}]
05:02:53 INFO - 1498996973051 Marionette TRACE 400 <- [1,5,{"error":"element click intercepted","message":"Element