Example driver code don't work for me

[andreymeretsky]

I ran the example driver code and got TimeoutError

[9618:9655:0117/170740.834686:ERROR:browser_gpu_channel_host_factory.cc(108)] Failed to launch GPU process.
DEBUG:asyncio:Using selector: EpollSelector
INFO:chromewhip.chrome.ChromeTab:Connected to Chrome tab ws://127.0.0.1:9222/devtools/page/39cff3b7-fed6-43e6-90da-12e1b003f291
DEBUG:chromewhip.chrome.ChromeTab.recv_handler:Waiting for message...
INFO:chromewhip.chrome.ChromeTab:Connected to Chrome tab ws://127.0.0.1:9222/devtools/page/83a74865-c5c1-4453-b5cc-b798becc9c5a
DEBUG:chromewhip.chrome.ChromeTab.recv_handler:Waiting for message...
INFO:chromewhip.chrome.ChromeTab:Connected to Chrome tab ws://127.0.0.1:9222/devtools/page/e70f45a0-793c-4a20-a5ce-2fb2cf45837a
DEBUG:chromewhip.chrome.ChromeTab.recv_handler:Waiting for message...
INFO:chromewhip.chrome.ChromeTab:Connected to Chrome tab ws://127.0.0.1:9222/devtools/page/61dbddaf-a646-4aa3-98d0-7a242f27ec03
DEBUG:chromewhip.chrome.ChromeTab.recv_handler:Waiting for message...
INFO:chromewhip.chrome.ChromeTab:Connected to Chrome tab ws://127.0.0.1:9222/devtools/page/0780b1da-3bdb-42bd-aae9-762ca6fe95e2
DEBUG:chromewhip.chrome.Chrome:Connected to Chrome! Found 5 tabs
DEBUG:chromewhip.chrome.ChromeTab.recv_handler:Waiting for message...
INFO:chromewhip.chrome.ChromeTab.send_handler:Sending command = {"method": "Page.enable", "params": {}, "id": 1}
DEBUG:websockets.protocol:client >> Frame(fin=True, opcode=1, data=b'{"method": "Page.enable", "params": {}, "id": 1}')
DEBUG:chromewhip.chrome.ChromeTab.send_handler:Waiting for ack event set for id=1
DEBUG:websockets.protocol:client << Frame(fin=True, opcode=1, data=b'{"id":1,"result":{}}')
DEBUG:chromewhip.chrome.ChromeTab.recv_handler:Received message, processing...
DEBUG:chromewhip.chrome.ChromeTab.recv_handler:Notifying ack event with id=1
DEBUG:chromewhip.chrome.ChromeTab.recv_handler:Waiting for message...
DEBUG:chromewhip.chrome.ChromeTab.send_handler:Received ack event set for id=1
INFO:chromewhip.chrome.ChromeTab.send_handler:Successfully sent command = {"method": "Page.enable", "params": {}, "id": 1}
INFO:chromewhip.chrome.ChromeTab.send_handler:Sending command = {"method": "Page.navigate", "params": {"url": "http://myip.dnsomatic.com/"}, "id": 2}
DEBUG:websockets.protocol:client >> Frame(fin=True, opcode=1, data=b'{"method": "Page.navigate", "params": {"url": "http://myip.dnsomatic.com/"}, "id": 2}')
DEBUG:chromewhip.chrome.ChromeTab.send_handler:Waiting for ack event set for id=2
DEBUG:websockets.protocol:client << Frame(fin=True, opcode=1, data=b'{"method":"Page.frameStartedLoading","params":{"frameId":"9704.1"}}')
DEBUG:chromewhip.chrome.ChromeTab.recv_handler:Received message, processing...
DEBUG:chromewhip.chrome.ChromeTab.recv_handler:Received event message!
DEBUG:chromewhip.chrome.ChromeTab.recv_handler:Received a "Page.frameStartedLoading" event , storing against hash and name...
DEBUG:chromewhip.helpers:generated hash = Page.frameStartedLoading:frameId=9704.1
DEBUG:chromewhip.chrome.ChromeTab.recv_handler:Waiting for message...
DEBUG:websockets.protocol:client << Frame(fin=True, opcode=1, data=b'{"method":"Page.lifecycleEvent","params":{"name":"commit","timestamp":197780.337573}}')
DEBUG:websockets.protocol:client << Frame(fin=True, opcode=1, data=b'{"method":"Page.frameNavigated","params":{"frame":{"id":"9704.1","loaderId":"9704.1","url":"http://myip.dnsomatic.com/","securityOrigin":"http://myip.dnsomatic.com","mimeType":"text/html"}}}')
DEBUG:chromewhip.chrome.ChromeTab.recv_handler:Received message, processing...
DEBUG:chromewhip.chrome.ChromeTab.recv_handler:Received event message!
DEBUG:websockets.protocol:client << Frame(fin=True, opcode=1, data=b'{"method":"Page.loadEventFired","params":{"timestamp":197780.340161}}')
DEBUG:websockets.protocol:client << Frame(fin=True, opcode=1, data=b'{"method":"Page.lifecycleEvent","params":{"name":"load","timestamp":197780.340161}}')
DEBUG:websockets.protocol:client << Frame(fin=True, opcode=1, data=b'{"method":"Page.frameStoppedLoading","params":{"frameId":"9704.1"}}')
DEBUG:websockets.protocol:client << Frame(fin=True, opcode=1, data=b'{"method":"Page.domContentEventFired","params":{"timestamp":197780.348346}}')
DEBUG:websockets.protocol:client << Frame(fin=True, opcode=1, data=b'{"method":"Page.lifecycleEvent","params":{"name":"DOMContentLoaded","timestamp":197780.348346}}')
DEBUG:websockets.protocol:client << Frame(fin=True, opcode=1, data=b'{"id":2,"result":{"frameId":"9704.1"}}')
DEBUG:websockets.protocol:client << Frame(fin=True, opcode=1, data=b'{"method":"Page.lifecycleEvent","params":{"name":"firstPaint","timestamp":197780.39997}}')
DEBUG:websockets.protocol:client << Frame(fin=True, opcode=1, data=b'{"method":"Page.lifecycleEvent","params":{"name":"firstContentfulPaint","timestamp":197780.399986}}')
DEBUG:websockets.protocol:client << Frame(fin=True, opcode=1, data=b'{"method":"Page.lifecycleEvent","params":{"name":"firstTextPaint","timestamp":197780.399987}}')
DEBUG:websockets.protocol:client << Frame(fin=True, opcode=1, data=b'{"method":"Page.lifecycleEvent","params":{"name":"firstMeaningfulPaintCandidate","timestamp":197780.399988}}')
DEBUG:websockets.protocol:client << Frame(fin=True, opcode=1, data=b'{"method":"Page.lifecycleEvent","params":{"name":"networkAlmostIdle","timestamp":197780.880721}}')
DEBUG:websockets.protocol:client << Frame(fin=True, opcode=1, data=b'{"method":"Page.lifecycleEvent","params":{"name":"networkIdle","timestamp":197781.097418}}')
ERROR:chromewhip.chrome.ChromeTab.send_handler:{"method": "Page.navigate", "params": {"url": "http://myip.dnsomatic.com/"}, "id": 2}
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/chromewhip/chrome.py", line 167, in _send
    await asyncio.wait_for(ack_event.wait(), timeout=TIMEOUT_S)  # recv
  File "/usr/lib/python3.6/asyncio/tasks.py", line 362, in wait_for
    raise futures.TimeoutError()
concurrent.futures._base.TimeoutError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/mouse/.PyCharmCE2017.1/config/scratches/scratch_25.py", line 32, in <module>
    result = loop.run_until_complete(tab.send_command(cmd, await_on_event_type=await_on_event_type))
  File "/usr/lib/python3.6/asyncio/base_events.py", line 467, in run_until_complete
    return future.result()
  File "/usr/local/lib/python3.6/dist-packages/chromewhip/chrome.py", line 264, in send_command
    return await self._send(*command, input_event_cls=input_event_type, trigger_event_cls=await_on_event_type)
  File "/usr/local/lib/python3.6/dist-packages/chromewhip/chrome.py", line 241, in _send
    raise TimeoutError('Unknown cause for timeout to occurs for "%s" with id=%s' % (method, id_))
chromewhip.chrome.TimeoutError: Unknown cause for timeout to occurs for "Page.navigate" with id=2
ERROR:asyncio:Task exception was never retrieved
future: <Task finished coro=<ChromeTab.recv_handler() done, defined at /usr/local/lib/python3.6/dist-packages/chromewhip/chrome.py:71> exception=TypeError("LifecycleEventEvent unable to deserialise: __init__() missing 2 required positional arguments: 'frameId' and 'loaderId'",)>
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/chromewhip/helpers.py", line 91, in json_to_event
    result = event_cls(**payload['params'])
TypeError: __init__() missing 2 required positional arguments: 'frameId' and 'loaderId'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/chromewhip/chrome.py", line 97, in recv_handler
    event = helpers.json_to_event(result)
  File "/usr/local/lib/python3.6/dist-packages/chromewhip/helpers.py", line 93, in json_to_event
    raise TypeError('%s unable to deserialise: %s' % (event_cls.__name__, e))
TypeError: LifecycleEventEvent unable to deserialise: __init__() missing 2 required positional arguments: 'frameId' and 'loaderId'

Process finished with exit code 1

/usr/local/lib/python3.6/dist-packages/chromewhip/helpers.py As you can see in debugger there is no frameId and loaderId in params and LifecycleEventEvent constructor needs it!

Is that an error in chromewhip or i understand something wrong? This error also arrised when using docker and http api.

[chazkii]

Thanks for the bug report @andreymeretsky, I've regenerated the protocol modules and added in the README of how that works, and fixed a few bugs, and got the example script working locally. Once you get it going, I'll close this issue.

[chazkii]

Since there is no response, I'm assuming this is now working.

[andreymeretsky]

Sorry, I couldn't test it earlier. Explain please do you have the same problem with timeouts? I ran docker from your repo and made screenshot. Or you test it in another way? I've regenerated the protocol modules with your script but the behavior of test script is the same

I added script which i ran for test. I start Chrome in it also. https://github.com/andreymeretsky/chromewhip/blob/master/scripts/test_script_from_readme.py As you see in screenshot I got the response in browser but after several seconds an error dropped in the console. ( I ran it without docker on my machine)

As i saw from error trace script fails by timeout :(

If you want to ask more questions you can contact with me by telegram http://t.me/mouse_meretsky

[chazkii]

@andreymeretsky I've been able to recreate error in my Docker container (works fine locally under MacOS), will let you know how I go.

[Tylerlhess]

I think the Docker Error might be that you never start Chrome. This causes it to time out while connecting to the remote debug port. This is fixed by you having Chrome running locally with --remote-debug-port=9222 as per the readme.