search

openai / universe

Universe: a software platform for measuring and training an AI's general intelligence across the world's supply of games, websites and other applications.
https://universe.openai.com
MIT License
7.45k stars 956 forks source link

Cannot run DuskDrive example on AWS t2.micro #159

Closed j8lp closed 7 years ago

j8lp commented 7 years ago

(First, please check https://github.com/openai/universe/wiki/Solutions-to-common-problems for solutions to many common problems)

Expected behavior

I am running an Ubuntu 16.04 machine on AWS. I installed OpenAI Universe successfully. I tried to run the starter code. I expected to able to go to http://{my-IP-address}/flashgames.DuskDrive-v0 and see the game running.

Actual behavior

The code seems to run and launch the environment, but I couldn't connect to the docker container from my browser. I also see connection errors in the console. Eventually, the code terminates after 5 failed attempts to start environment.

Console output. (Sorry that it's so big)

`>>> env = gym.make('flashgames.DuskDrive-v0') [2017-03-02 06:15:39,696] Making new env: flashgames.DuskDrive-v0

env.configure(remotes=1) # automatically creates a local docker container [2017-03-02 06:15:39,719] Writing logs to file: /tmp/universe-1892.log [2017-03-02 06:15:39,765] Ports used: dict_keys([]) [2017-03-02 06:15:39,765] [0] Creating container: image=quay.io/openai/universe.flashgames:0.20.28. Run the same thing by hand as: docker run -p 5900:5900 -p 15900:15900 --cap-add SYS_ADMIN --privileged --ipc host quay.io/openai/universe.flashgames:0.20.28 [2017-03-02 06:15:40,144] Remote closed: address=localhost:15900 [2017-03-02 06:15:40,145] Remote closed: address=localhost:5900 [2017-03-02 06:15:40,145] At least one sockets was closed by the remote. Sleeping 1s... universe-98PmJS-0 | Setting VNC and rewarder password: openai universe-98PmJS-0 | [Thu Mar 2 06:15:40 UTC 2017] Waiting for /tmp/.X11-unix/X0 to be created (try 1/10) universe-98PmJS-0 | [Thu Mar 2 06:15:40 UTC 2017] [/usr/local/bin/sudoable-env-setup] Disabling outbound network traffic for none universe-98PmJS-0 | [tigervnc] universe-98PmJS-0 | [tigervnc] Xvnc TigerVNC 1.7.0 - built Sep 8 2016 10:39:22 universe-98PmJS-0 | [tigervnc] Copyright (C) 1999-2016 TigerVNC Team and many others (see README.txt) universe-98PmJS-0 | [tigervnc] See http://www.tigervnc.org for information on TigerVNC. universe-98PmJS-0 | [tigervnc] Underlying X server release 11400000, The X.Org Foundation universe-98PmJS-0 | [tigervnc] universe-98PmJS-0 | [tigervnc] Initializing built-in extension VNC-EXTENSION universe-98PmJS-0 | [tigervnc] Initializing built-in extension Generic Event Extension universe-98PmJS-0 | [tigervnc] Initializing built-in extension SHAPE universe-98PmJS-0 | [tigervnc] Initializing built-in extension MIT-SHM universe-98PmJS-0 | [tigervnc] Initializing built-in extension XInputExtension universe-98PmJS-0 | [tigervnc] Initializing built-in extension XTEST universe-98PmJS-0 | [tigervnc] Initializing built-in extension BIG-REQUESTS universe-98PmJS-0 | [tigervnc] Initializing built-in extension SYNC universe-98PmJS-0 | [tigervnc] Initializing built-in extension XKEYBOARD universe-98PmJS-0 | [tigervnc] Initializing built-in extension XC-MISC universe-98PmJS-0 | [tigervnc] Initializing built-in extension XINERAMA universe-98PmJS-0 | [tigervnc] Initializing built-in extension XFIXES universe-98PmJS-0 | [tigervnc] Initializing built-in extension RENDER universe-98PmJS-0 | [tigervnc] Initializing built-in extension RANDR universe-98PmJS-0 | [tigervnc] Initializing built-in extension COMPOSITE universe-98PmJS-0 | [tigervnc] Initializing built-in extension DAMAGE universe-98PmJS-0 | [tigervnc] Initializing built-in extension MIT-SCREEN-SAVER universe-98PmJS-0 | [tigervnc] Initializing built-in extension DOUBLE-BUFFER universe-98PmJS-0 | [tigervnc] Initializing built-in extension RECORD universe-98PmJS-0 | [tigervnc] Initializing built-in extension DPMS universe-98PmJS-0 | [tigervnc] Initializing built-in extension X-Resource universe-98PmJS-0 | [tigervnc] Initializing built-in extension XVideo universe-98PmJS-0 | [tigervnc] Initializing built-in extension XVideo-MotionCompensation universe-98PmJS-0 | [tigervnc] Initializing built-in extension GLX universe-98PmJS-0 | [init] [2017-03-02 06:15:40,788] Launching system_diagnostics_logger.py, recorder_logdir=/tmp/demo universe-98PmJS-0 | [tigervnc] universe-98PmJS-0 | [tigervnc] Thu Mar 2 06:15:40 2017 universe-98PmJS-0 | [tigervnc] vncext: VNC extension running! universe-98PmJS-0 | [tigervnc] vncext: Listening for VNC connections on all interface(s), port 5900 universe-98PmJS-0 | [tigervnc] vncext: created VNC server for screen 0 universe-98PmJS-0 | [init] [2017-03-02 06:15:40,797] Launching reward_recorder.py, recorder_logdir=/tmp/demo universe-98PmJS-0 | [init] [2017-03-02 06:15:40,804] Launching vnc_recorder.py, recorder_logdir=/tmp/demo universe-98PmJS-0 | [tigervnc] [dix] Could not init font path element /usr/share/fonts/X11/Type1/, removing from list! universe-98PmJS-0 | [tigervnc] [dix] Could not init font path element /usr/share/fonts/X11/75dpi/, removing from list! universe-98PmJS-0 | [tigervnc] [dix] Could not init font path element /usr/share/fonts/X11/100dpi/, removing from list! universe-98PmJS-0 | [init] [2017-03-02 06:15:40,836] PID 51 launched with command ['sudo', '-H', '-u', 'nobody', 'DISPLAY=:0', 'DBUS_SESSION_BUS_ADDRESS=/dev/null', '/app/universe-envs/controlplane/bin/controlplane.py', '--rewarder-port=15901'] universe-98PmJS-0 | [init] [2017-03-02 06:15:40,992] init detected end of child process 54 with exit code 0, not killed by signal [2017-03-02 06:15:41,146] Remote closed: address=localhost:15900 [2017-03-02 06:15:41,147] Remote closed: address=localhost:5900 [2017-03-02 06:15:41,148] At least one sockets was closed by the remote. Sleeping 1s... universe-98PmJS-0 | [nginx] 2017/03/02 06:15:41 [error] 60#60: 1 connect() failed (111: Connection refused) while connecting to upstream, client: 172.17.0.1, server: , request: "GET / HTTP/1.1", upstream: "http://127.0.0.1:15901/", host: "127.0.0.1:10003" universe-98PmJS-0 | [nginx] 172.17.0.1 - openai [02/Mar/2017:06:15:41 +0000] "GET / HTTP/1.1" 502 182 "-" "-" universe-98PmJS-0 | [tigervnc] universe-98PmJS-0 | [tigervnc] Thu Mar 2 06:15:41 2017 universe-98PmJS-0 | [tigervnc] Connections: accepted: 172.17.0.1::34808 universe-98PmJS-0 | WebSocket server settings: universe-98PmJS-0 | - Listen on :5898 universe-98PmJS-0 | - Flash security policy server universe-98PmJS-0 | - No SSL/TLS support (no cert file) universe-98PmJS-0 | - proxying from :5898 to localhost:5900 universe-98PmJS-0 | [init] [2017-03-02 06:15:41,681] init detected end of child process 15 with exit code 0, not killed by signal [2017-03-02 06:15:42,149] Using the golang VNC implementation [2017-03-02 06:15:42,149] Using VNCSession arguments: {'encoding': 'tight', 'subsample_level': 2, 'fine_quality_level': 50, 'start_timeout': 7}. (Customize by running "env.configure(vnc_kwargs={...})" universe-98PmJS-0 | [nginx] 2017/03/02 06:15:42 [info] 60#60: 1 client 172.17.0.1 closed keepalive connection universe-98PmJS-0 | [tigervnc] universe-98PmJS-0 | [tigervnc] Thu Mar 2 06:15:42 2017 universe-98PmJS-0 | [tigervnc] Connections: closed: 172.17.0.1::34808 (Clean disconnection) universe-98PmJS-0 | [tigervnc] EncodeManager: Framebuffer updates: 0 universe-98PmJS-0 | [tigervnc] EncodeManager: Total: 0 rects, 0 pixels universe-98PmJS-0 | [tigervnc] EncodeManager: 0 B (1:-nan ratio) [2017-03-02 06:15:42,155] [0] Connecting to environment: vnc://localhost:5900 password=openai. If desired, you can manually connect a VNC viewer, such as TurboVNC. Most environments provide a convenient in-browser VNC client: http://localhost:15900/viewer/?password=openai 2017/03/02 06:15:42 I0302 06:15:42.156701 1892 gymvnc.go:417] [0:localhost:5900] opening connection to VNC server observation_n = env.reset() universe-98PmJS-0 | [tigervnc] Connections: accepted: 172.17.0.1::34814 universe-98PmJS-0 | [tigervnc] SConnection: Client needs protocol version 3.8 universe-98PmJS-0 | [tigervnc] SConnection: Client requests security type VncAuth(2)

while True: ... action_n = [[('KeyEven2017/03/02 06:15:42 I0302 06:15:42.167446 1892 gymvnc.go:550] [0:localhost:5900] connection established t', 'ArrowUp', True)universe-98PmJS-0 | [tigervnc] VNCSConnST: Server default pixel format depth 24 (32bpp) little-endian rgb888 universe-98PmJS-0 | [tigervnc] VNCSConnST: Client pixel format depth 24 (32bpp) little-endian bgr888 ur agent herebservation_n] # yo ... observation_n, reward_n, done_n, info = env.step(action_n) ... env.render() ... universe-98PmJS-0 | [nginx] 2017/03/02 06:15:42 [error] 60#60: 3 connect() failed (111: Connection refused) while connecting to upstream, client: 172.17.0.1, server: , request: "GET / HTTP/1.1", upstream: "http://127.0.0.1:15901/", host: "localhost:15900" universe-98PmJS-0 | [nginx] 172.17.0.1 - openai [02/Mar/2017:06:15:42 +0000] "GET / HTTP/1.1" 502 182 "-" "AutobahnPython/0.17.2" [2017-03-02 06:15:42,204] [0:localhost:5900] Waiting on rewarder: failed to complete WebSocket handshake. Retry in 1s (slept 0s/7s): connection was closed uncleanly (WebSocket connection upgrade failed (502 - BadGateway)) universe-98PmJS-0 | [nginx] 2017/03/02 06:15:42 [info] 60#60: 3 client 172.17.0.1 closed keepalive connection universe-98PmJS-0 | [reward_recorder] [2017-03-02 06:15:42,677] Listening on 0.0.0.0:15898 universe-98PmJS-0 | [vnc_recorder] [2017-03-02 06:15:42,681] Listening on 0.0.0.0:5899 universe-98PmJS-0 | [2017-03-02 06:15:42,931] [INFO:root] Starting play_controlplane.py with the following: command=['/app/universe-envs/controlplane/bin/controlplane.py', '--rewarder-port=15901'] args=Namespace(bot_demonstration=False, demonstration=False, env_id=None, idle_timeout=None, integrator_mode=False, no_env=False, no_rewarder=False, no_scorer=False, no_vexpect=False, remotes='vnc://127.0.0.1:5900', rewarder_fps=60, rewarder_port=15901, verbosity=0) env=environ({'DISPLAY': ':0', 'HOSTNAME': '379dd5cfca43', 'SUDO_GID': '0', 'TERM': 'xterm', 'USERNAME': 'nobody', 'HOME': '/nonexistent', 'SHELL': '/usr/sbin/nologin', 'SUDO_USER': 'root', 'USER': 'nobody', 'SUDO_COMMAND': '/app/universe-envs/controlplane/bin/controlplane.py --rewarder-port=15901', 'SUDO_UID': '0', 'DBUS_SESSION_BUS_ADDRESS': '/dev/null', 'MAIL': '/var/mail/nobody', 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin', 'LOGNAME': 'nobody'}) universe-98PmJS-0 | [2017-03-02 06:15:42,931] [INFO:root] [EnvStatus] Changing env_state: None (env_id=None) -> None (env_id=None) (episode_id: 0->0, fps=60) universe-98PmJS-0 | [2017-03-02 06:15:42,931] [INFO:universe.rewarder.remote] Starting Rewarder on port=15901 universe-98PmJS-0 | [2017-03-02 06:15:42,935] [INFO:universe.extra.universe.wrappers.logger] Running VNC environments with Logger set to print_frequency=5. To change this, pass "print_frequency=k" or "print_frequency=None" to "env.configure". universe-98PmJS-0 | [2017-03-02 06:15:42,937] [INFO:universe.remotes.hardcoded_addresses] No rewarder addresses were provided, so this env cannot connect to the remote's rewarder channel, and cannot send control messages (e.g. reset) universe-98PmJS-0 | [2017-03-02 06:15:42,937] [INFO:universe.envs.vnc_env] Using the golang VNC implementation universe-98PmJS-0 | [2017-03-02 06:15:42,937] [INFO:universe.envs.vnc_env] Using VNCSession arguments: {'encoding': 'zrle', 'start_timeout': 7, 'compress_level': 9, 'subsample_level': 2, 'fine_quality_level': 50}. (Customize by running "env.configure(vnc_kwargs={...})" universe-98PmJS-0 | [2017-03-02 06:15:42,937] [INFO:universe.envs.vnc_env] Printed stats will ignore clock skew. (This usually makes sense only when the environment and agent are on the same machine.) universe-98PmJS-0 | [2017-03-02 06:15:42,943] [INFO:universe.envs.vnc_env] [0] Connecting to environment: vnc://127.0.0.1:5900 password=openai. If desired, you can manually connect a VNC viewer, such as TurboVNC. Most environments provide a convenient in-browser VNC client: http://None/viewer/?password=openai universe-98PmJS-0 | [2017-03-02 06:15:42,943] [INFO:universe.extra.universe.envs.vnc_env] [0] Connecting to environment details: vnc_address=127.0.0.1:5900 vnc_password=openai rewarder_address=None rewarder_password=openai universe-98PmJS-0 | 2017/03/02 06:15:42 I0302 06:15:42.944196 58 gymvnc.go:417] [0:127.0.0.1:5900] opening connection to VNC server universe-98PmJS-0 | [tigervnc] Connections: accepted: 127.0.0.1::38406 universe-98PmJS-0 | [tigervnc] SConnection: Client needs protocol version 3.8 universe-98PmJS-0 | [2017-03-02 06:15:42,944] [INFO:root] [EnvStatus] Changing env_state: None (env_id=None) -> resetting (env_id=None) (episode_id: 0->1, fps=60) universe-98PmJS-0 | [2017-03-02 06:15:42,946] [INFO:root] [MainThread] Env state: env_id=None episode_id=1 universe-98PmJS-0 | [tigervnc] SConnection: Client requests security type VncAuth(2) universe-98PmJS-0 | [tigervnc] VNCSConnST: Server default pixel format depth 24 (32bpp) little-endian rgb888 universe-98PmJS-0 | 2017/03/02 06:15:42 I0302 06:15:42.948394 58 gymvnc.go:550] [0:127.0.0.1:5900] connection established universe-98PmJS-0 | [tigervnc] VNCSConnST: Client pixel format depth 24 (32bpp) little-endian bgr888 universe-98PmJS-0 | [2017-03-02 06:15:42,948] [INFO:root] [MainThread] Writing None to /tmp/demo/env_id.txt universe-98PmJS-0 | [Thu Mar 2 06:15:42 UTC 2017] [/usr/local/bin/sudoable-env-setup] Disabling outbound network traffic for none universe-98PmJS-0 | [2017-03-02 06:15:42,971] [INFO:gym_flashgames.launcher] [MainThread] Launching new Chrome process (attempt 0/10) universe-98PmJS-0 | [2017-03-02 06:15:42,971] [INFO:root] Replacing selenium_wrapper_server since we currently do it at every episode boundary universe-98PmJS-0 | [2017-03-02 06:15:43,157] [selenium_wrapper_server] Calling webdriver.Chrome() universe-98PmJS-0 | [2017-03-02 06:15:43,210] [INFO:universe.rewarder.remote] Client connecting: peer=tcp4:127.0.0.1:59330 observer=False universe-98PmJS-0 | [2017-03-02 06:15:43,210] [INFO:universe.rewarder.remote] WebSocket connection established universe-98PmJS-0 | [nginx] 2017/03/02 06:15:45 [info] 60#60: 7 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1" universe-98PmJS-0 | [nginx] 2017/03/02 06:15:45 [info] 60#60: 8 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1" universe-98PmJS-0 | [nginx] 2017/03/02 06:15:45 [info] 60#60: 9 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1" universe-98PmJS-0 | [nginx] 2017/03/02 06:15:46 [info] 60#60: 10 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1" universe-98PmJS-0 | [2017-03-02 06:15:46,218] [selenium_wrapper_server] Call to webdriver.Chrome() completed: 3.06s universe-98PmJS-0 | [2017-03-02 06:15:46,219] [INFO:gym_flashgames.launcher] [MainThread] Navigating browser to url=http://localhost universe-98PmJS-0 | [2017-03-02 06:15:46,358] [INFO:root] [EnvStatus] Changing env_state: resetting (env_id=None) -> running (env_id=None) (episode_id: 1->1, fps=60) universe-98PmJS-0 | [2017-03-02 06:15:46,383] [INFO:root] [MainThread] Writing None to /tmp/demo/env_id.txt universe-98PmJS-0 | [2017-03-02 06:15:46,537] [INFO:root] [Rewarder] Rewarder fell behind by 0.10671138763427734s from target; losing 6 frames universe-98PmJS-0 | Manhole[1488435346.5398]: Patched and . universe-98PmJS-0 | Manhole[1488435346.5402]: Manhole UDS path: /tmp/manhole-58 universe-98PmJS-0 | Manhole[1488435346.5402]: Waiting for new connection (in pid:58) ... universe-98PmJS-0 | [2017-03-02 06:15:47,955] [INFO:universe.wrappers.logger] Stats for the past 5.01s: vnc_updates_ps=3.6 n=1 reaction_time=None observation_lag=None action_lag=None reward_ps=0.0 reward_total=0.0 vnc_bytes_ps[total]=355942.2 vnc_pixels_ps[total]=533064.3 reward_lag=None rewarder_message_lag=None fps=17.56 universe-98PmJS-0 | [2017-03-02 06:15:51,404] [INFO:universe.pyprofile] [pyprofile] period=5.01s timers={"rewarder.frame": {"std": "9.28ms", "mean": "17.59ms", "calls": 294}, "vnc_env.VNCEnv.vnc_session.step": {"std": "453.77us", "mean": "104.97us", "calls": 295}, "rewarder.sleep": {"std": "452.67us", "mean": "16.28ms", "calls": 293}, "rewarder.sleep.missed": {"std": "0.00us", "mean": "106.71ms", "calls": 1}, "rewarder.compute_reward": {"std": "483.92us", "mean": "205.38us", "calls": 295}} counters={"reward.vnc.updates.n": {"std": 0.6621488799111056, "mean": 0.06101694915254243, "calls": 295}} gauges={} (export_time=111.10us) universe-98PmJS-0 | [2017-03-02 06:15:51,405] [INFO:universe.rewarder.remote] [Rewarder] Over past 5.01s, sent 1 reward messages to agent: reward=0 reward_min=0 reward_max=0 done=False info={'rewarder.vnc.updates.n': 0, 'rewarder.vnc.updates.bytes': 0, 'rewarder.vnc.updates.pixels': 0, 'rewarder.profile': '<858 bytes>'} universe-98PmJS-0 | [2017-03-02 06:15:52,972] [INFO:universe.wrappers.logger] Stats for the past 5.02s: vnc_updates_ps=0.0 n=1 reaction_time=None observation_lag=None action_lag=None reward_ps=0.0 reward_total=0.0 vnc_bytes_ps[total]=0.0 vnc_pixels_ps[total]=0.0 reward_lag=None rewarder_message_lag=None fps=60.01 universe-98PmJS-0 | [2017-03-02 06:15:56,421] [INFO:universe.pyprofile] [pyprofile] period=5.02s timers={"rewarder.frame": {"std": "147.91us", "mean": "16.84ms", "calls": 301}, "vnc_env.VNCEnv.vnc_session.step": {"std": "8.59us", "mean": "63.55us", "calls": 301}, "rewarder.sleep": {"std": "233.73us", "mean": "16.26ms", "calls": 301}, "rewarder.compute_reward": {"std": "57.51us", "mean": "175.82us", "calls": 301}} counters={"agent_conn.reward": {"std": 0, "mean": 0.0, "calls": 1}, "reward.vnc.updates.n": {"std": 0.0, "mean": 0.0, "calls": 301}} gauges={} (export_time=106.81us) universe-98PmJS-0 | [2017-03-02 06:15:56,422] [INFO:universe.rewarder.remote] [Rewarder] Over past 5.02s, sent 1 reward messages to agent: reward=0 reward_min=0 reward_max=0 done=False info={'rewarder.vnc.updates.n': 0, 'rewarder.vnc.updates.bytes': 0, 'rewarder.vnc.updates.pixels': 0, 'rewarder.profile': '<801 bytes>'} universe-98PmJS-0 | [2017-03-02 06:15:57,988] [INFO:universe.wrappers.logger] Stats for the past 5.02s: vnc_updates_ps=0.0 n=1 reaction_time=None observation_lag=None action_lag=None reward_ps=0.0 reward_total=0.0 vnc_bytes_ps[total]=0.0 vnc_pixels_ps[total]=0.0 reward_lag=None rewarder_message_lag=None fps=60.01 universe-98PmJS-0 | [2017-03-02 06:16:01,438] [INFO:universe.pyprofile] [pyprofile] period=5.02s timers={"rewarder.frame": {"std": "46.17us", "mean": "16.83ms", "calls": 301}, "vnc_env.VNCEnv.vnc_session.step": {"std": "10.24us", "mean": "55.64us", "calls": 301}, "rewarder.sleep": {"std": "198.25us", "mean": "16.30ms", "calls": 301}, "rewarder.compute_reward": {"std": "91.58us", "mean": "152.72us", "calls": 301}} counters={"agent_conn.reward": {"std": 0, "mean": 0.0, "calls": 1}, "reward.vnc.updates.n": {"std": 0.0, "mean": 0.0, "calls": 301}} gauges={} (export_time=119.21us) universe-98PmJS-0 | [2017-03-02 06:16:01,439] [INFO:universe.rewarder.remote] [Rewarder] Over past 5.02s, sent 1 reward messages to agent: reward=0 reward_min=0 reward_max=0 done=False info={'rewarder.vnc.updates.n': 0, 'rewarder.vnc.updates.bytes': 0, 'rewarder.vnc.updates.pixels': 0, 'rewarder.profile': '<804 bytes>'} universe-98PmJS-0 | [2017-03-02 06:16:03,005] [INFO:universe.wrappers.logger] Stats for the past 5.02s: vnc_updates_ps=0.0 n=1 reaction_time=None observation_lag=None action_lag=None reward_ps=0.0 reward_total=0.0 vnc_bytes_ps[total]=0.0 vnc_pixels_ps[total]=0.0 reward_lag=None rewarder_message_lag=None fps=60.01 [2017-03-02 06:16:03,216] [0:localhost:5900] ntpdate -q -p 8 localhost call timed out after 20.0s; killing the subprocess. This is ok, but you could have more accurate timings by enabling UDP port 123 traffic to your env. (Alternatively, you can try increasing the timeout by setting environment variable UNIVERSE_NTPDATE_TIMEOUT=10.) universe-98PmJS-0 | [nginx] 2017/03/02 06:16:03 [info] 60#60: 13 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900 universe-98PmJS-0 | [nginx] 2017/03/02 06:16:03 [info] 60#60: 14 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900 universe-98PmJS-0 | [nginx] 2017/03/02 06:16:03 [info] 60#60: 15 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900 universe-98PmJS-0 | [nginx] 2017/03/02 06:16:03 [info] 60#60: 16 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900 universe-98PmJS-0 | [nginx] 2017/03/02 06:16:03 [info] 60#60: 17 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900 universe-98PmJS-0 | [nginx] 2017/03/02 06:16:03 [info] 60#60: 18 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900 universe-98PmJS-0 | [nginx] 2017/03/02 06:16:03 [info] 60#60: 19 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900 universe-98PmJS-0 | [nginx] 2017/03/02 06:16:03 [info] 60#60: 20 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900 universe-98PmJS-0 | [nginx] 2017/03/02 06:16:03 [info] 60#60: 21 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900 universe-98PmJS-0 | [2017-03-02 06:16:03,234] [INFO:universe.rewarder.remote] CONNECTION STATUS: Marking connection as active: observer=False peer=tcp4:127.0.0.1:59330 total_conns=1 universe-98PmJS-0 | [nginx] 2017/03/02 06:16:03 [info] 60#60: 22 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900 [2017-03-02 06:16:03,245] [0:localhost:5900] Sending reset for env_id=flashgames.DuskDrive-v0 fps=60 episode_id=0 universe-98PmJS-0 | [2017-03-02 06:16:03,246] [INFO:universe.rewarder.remote] Received reset message: {'method': 'v0.env.reset', 'headers': {'sent_at': 1488435363.2461307, 'message_id': 10, 'episode_id': '0'}, 'body': {'seed': None, 'fps': 60, 'env_id': 'flashgames.DuskDrive-v0'}} universe-98PmJS-0 | [2017-03-02 06:16:03,258] [INFO:root] [EnvStatus] Changing env_state: running (env_id=None) -> resetting (env_id=flashgames.DuskDrive-v0) (episode_id: 1->2, fps=60) universe-98PmJS-0 | [2017-03-02 06:16:03,258] [ERROR:root] Closing server (via subprocess.close()) and all chromes (via pkill chromedriver || :; pkill chrome || :) universe-98PmJS-0 | [2017-03-02 06:16:03,271] [INFO:root] [Rewarder] Blocking until env finishes resetting universe-98PmJS-0 | [init] [2017-03-02 06:16:03,286] init detected end of child process 106 with exit code 0, killed by SIGTERM: 15 universe-98PmJS-0 | [2017-03-02 06:16:03,305] [INFO:root] [EnvController] RESET CAUSE: changing out environments due to v0.env.reset (with episode_id=0): flashgames.DuskDrive-v0 -> flashgames.DuskDrive-v0 (new episode_id=2 fps=60) universe-98PmJS-0 | [init] [2017-03-02 06:16:03,306] init detected end of child process 121 with exit code 0, not killed by signal universe-98PmJS-0 | [2017-03-02 06:16:03,306] [INFO:root] [EnvController] Env state: env_id=flashgames.DuskDrive-v0 episode_id=2 universe-98PmJS-0 | [2017-03-02 06:16:03,307] [INFO:root] [EnvController] Writing flashgames.DuskDrive-v0 to /tmp/demo/env_id.txt universe-98PmJS-0 | [nginx] 2017/03/02 06:16:03 [info] 60#60: 12 client closed connection while waiting for request, client: 127.0.0.1, server: 0.0.0.0:80 universe-98PmJS-0 | [nginx] 2017/03/02 06:16:03 [info] 60#60: 11 client 127.0.0.1 closed keepalive connection universe-98PmJS-0 | [init] [2017-03-02 06:16:03,381] init detected end of child process 117 with exit code 0, not killed by signal universe-98PmJS-0 | [init] [2017-03-02 06:16:03,382] init detected end of child process 118 with exit code 0, not killed by signal universe-98PmJS-0 | [init] [2017-03-02 06:16:03,382] init detected end of child process 120 with exit code 0, killed by SIGTERM: 15 universe-98PmJS-0 | [init] [2017-03-02 06:16:03,382] init detected end of child process 109 with exit code 0, not killed by signal universe-98PmJS-0 | [Thu Mar 2 06:16:03 UTC 2017] [/usr/local/bin/sudoable-env-setup] Allowing outbound network traffic to non-private IPs for git-lfs. (Going to fetch files via git lfs.) universe-98PmJS-0 | [unpack-lfs] [2017-03-02 06:16:03,568] Unpacking files for flashgames.DuskDrive-v0 universe-98PmJS-0 | [unpack-lfs] [2017-03-02 06:16:03,707] Merged 5 files from /tmp/flashgames.DuskDrive-v0/public -> /app/universe-envs/flashgames/build/public/flashgames.DuskDrive-v0 universe-98PmJS-0 | [unpack-lfs] [2017-03-02 06:16:03,711] Merged 20 files from /tmp/flashgames.DuskDrive-v0/private -> /app/universe-envs/flashgames/build/private/flashgames.DuskDrive-v0 universe-98PmJS-0 | [unpack-lfs] [2017-03-02 06:16:03,712] Completed unpack for flashgames.DuskDrive-v0 in 0.150s universe-98PmJS-0 | [Thu Mar 2 06:16:03 UTC 2017] [/usr/local/bin/sudoable-env-setup] [debug] unpack-lfs completed with status code: 0. Created completion file: /usr/local/openai/git-lfs/flashgames.DuskDrive-v0 universe-98PmJS-0 | [Thu Mar 2 06:16:03 UTC 2017] [/usr/local/bin/sudoable-env-setup] Disabling outbound network traffic for flashgames.DuskDrive-v0 universe-98PmJS-0 | [2017-03-02 06:16:03,802] [INFO:gym_flashgames.launcher] [EnvController] Launching new Chrome process (attempt 0/10) universe-98PmJS-0 | [2017-03-02 06:16:03,802] [INFO:root] Replacing selenium_wrapper_server since we currently do it at every episode boundary universe-98PmJS-0 | [2017-03-02 06:16:03,987] [selenium_wrapper_server] Calling webdriver.Chrome() universe-98PmJS-0 | [nginx] 2017/03/02 06:16:05 [info] 60#60: 23 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1" universe-98PmJS-0 | [nginx] 2017/03/02 06:16:05 [info] 60#60: 24 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1" universe-98PmJS-0 | [nginx] 2017/03/02 06:16:05 [info] 60#60: 25 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1" universe-98PmJS-0 | [nginx] 2017/03/02 06:16:05 [info] 60#60: 26 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1" universe-98PmJS-0 | [2017-03-02 06:16:05,612] [selenium_wrapper_server] Call to webdriver.Chrome() completed: 1.63s universe-98PmJS-0 | [2017-03-02 06:16:05,614] [INFO:gym_flashgames.launcher] [EnvController] Navigating browser to url=http://localhost/flashgames.DuskDrive-v0 universe-98PmJS-0 | [2017-03-02 06:16:05,656] [INFO:root] [EnvController] Running command: /app/universe-envs/controlplane/bin/play_vexpect -e flashgames.DuskDrive-v0 -r vnc://127.0.0.1:5900 -d universe-98PmJS-0 | [nginx] 2017/03/02 06:16:06 [info] 60#60: 30 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google-analytics.com:443 HTTP/1.1" universe-98PmJS-0 | [2017-03-02 06:16:07,319] [play_vexpect] No rewarder addresses were provided, so this env cannot connect to the remote's rewarder channel, and cannot send control messages (e.g. reset) universe-98PmJS-0 | [2017-03-02 06:16:07,319] [play_vexpect] Using the golang VNC implementation universe-98PmJS-0 | [2017-03-02 06:16:07,320] [play_vexpect] Using VNCSession arguments: {'encoding': 'zrle', 'fine_quality_level': 50, 'compress_level': 0, 'subsample_level': 2, 'start_timeout': 7}. (Customize by running "env.configure(vnc_kwargs={...})" universe-98PmJS-0 | [2017-03-02 06:16:07,321] [play_vexpect] Printed stats will ignore clock skew. (This usually makes sense only when the environment and agent are on the same machine.) universe-98PmJS-0 | [2017-03-02 06:16:07,325] [play_vexpect] [0] Connecting to environment: vnc://127.0.0.1:5900 password=openai. If desired, you can manually connect a VNC viewer, such as TurboVNC. Most environments provide a convenient in-browser VNC client: http://None/viewer/?password=openai universe-98PmJS-0 | [2017-03-02 06:16:07,325] [play_vexpect] [0] Connecting to environment details: vnc_address=127.0.0.1:5900 vnc_password=openai rewarder_address=None rewarder_password=openai universe-98PmJS-0 | 2017/03/02 06:16:07 I0302 06:16:07.326426 647 gymvnc.go:417] [0:127.0.0.1:5900] opening connection to VNC server universe-98PmJS-0 | [tigervnc] universe-98PmJS-0 | [tigervnc] Thu Mar 2 06:16:07 2017 universe-98PmJS-0 | [tigervnc] Connections: accepted: 127.0.0.1::38740 universe-98PmJS-0 | [tigervnc] SConnection: Client needs protocol version 3.8 universe-98PmJS-0 | [tigervnc] SConnection: Client requests security type VncAuth(2) universe-98PmJS-0 | [tigervnc] VNCSConnST: Server default pixel format depth 24 (32bpp) little-endian rgb888 universe-98PmJS-0 | 2017/03/02 06:16:07 I0302 06:16:07.330175 647 gymvnc.go:550] [0:127.0.0.1:5900] connection established universe-98PmJS-0 | [tigervnc] VNCSConnST: Client pixel format depth 24 (32bpp) little-endian bgr888 universe-98PmJS-0 | [2017-03-02 06:16:08,066] [play_vexpect] Waiting for any of [MaskState] to activate 2017/03/02 06:16:08 I0302 06:16:08.914706 1892 gymvnc.go:374] [0:localhost:5900] update queue max of 60 reached; pausing further updates universe-98PmJS-0 | 2017/03/02 06:16:12 I0302 06:16:12.146866 58 gymvnc.go:374] [0:127.0.0.1:5900] update queue max of 60 reached; pausing further updates universe-98PmJS-0 | [2017-03-02 06:16:15,150] [play_vexpect] Applying transition: ClickTransition['initializing1'] x=429 y=539 buttonmask=1> for active state MaskState. (Summary: plausible_states=MaskState distance_m=0.048 match_time_m=217us) universe-98PmJS-0 | [2017-03-02 06:16:15,167] [play_vexpect] Waiting for any of [MaskState] to activate (or whether any of [MaskState] are still active) universe-98PmJS-0 | [2017-03-02 06:16:19,202] [play_vexpect] Advancing to the next hopeful state (2/2): MaskState universe-98PmJS-0 | [2017-03-02 06:16:25,029] [play_vexpect] Advancing to the next hopeful state (1/2): MaskState universe-98PmJS-0 | [2017-03-02 06:16:30,888] [play_vexpect] Fell behind by 10.178326845169067s from target; losing 610 frames universe-98PmJS-0 | [2017-03-02 06:16:36,329] [play_vexpect] Fell behind by 3.953403949737549s from target; losing 237 frames universe-98PmJS-0 | [2017-03-02 06:16:41,105] [play_vexpect] Fell behind by 2.2975549697875977s from target; losing 137 frames universe-98PmJS-0 | [2017-03-02 06:16:41,921] [play_vexpect] Fell behind by 0.37058210372924805s from target; losing 22 frames universe-98PmJS-0 | [2017-03-02 06:16:43,046] [play_vexpect] Fell behind by 0.4473896026611328s from target; losing 26 frames universe-98PmJS-0 | [2017-03-02 06:16:44,043] [play_vexpect] Fell behind by 0.4378662109375s from target; losing 26 frames universe-98PmJS-0 | [2017-03-02 06:16:45,380] [play_vexpect] Advancing to the next hopeful state (2/2): MaskState universe-98PmJS-0 | [2017-03-02 06:16:46,686] [play_vexpect] Fell behind by 1.982759952545166s from target; losing 118 frames universe-98PmJS-0 | [2017-03-02 06:16:48,947] [play_vexpect] Fell behind by 1.3610031604766846s from target; losing 81 frames universe-98PmJS-0 | [2017-03-02 06:16:50,504] [play_vexpect] Fell behind by 0.50917649269104s from target; losing 30 frames universe-98PmJS-0 | [2017-03-02 06:16:51,925] [play_vexpect] Fell behind by 0.5472750663757324s from target; losing 32 frames universe-98PmJS-0 | [2017-03-02 06:16:54,964] [play_vexpect] Fell behind by 2.4267780780792236s from target; losing 145 frames universe-98PmJS-0 | [2017-03-02 06:16:57,178] [play_vexpect] Fell behind by 1.778724193572998s from target; losing 106 frames universe-98PmJS-0 | [2017-03-02 06:16:58,312] [play_vexpect] Advancing to the next hopeful state (1/2): MaskState universe-98PmJS-0 | [2017-03-02 06:17:00,372] [play_vexpect] Fell behind by 2.4682815074920654s from target; losing 148 frames universe-98PmJS-0 | [nginx] 2017/03/02 06:17:03 [info] 60#60: 5 upstream timed out (110: Connection timed out) while proxying upgraded connection, client: 172.17.0.1, server: , request: "GET / HTTP/1.1", upstream: "http://127.0.0.1:15901/", host: "localhost:15900" universe-98PmJS-0 | [2017-03-02 06:17:03,118] [play_vexpect] Fell behind by 1.7743258476257324s from target; losing 106 frames universe-98PmJS-0 | [nginx] 172.17.0.1 - openai [02/Mar/2017:06:17:03 +0000] "GET / HTTP/1.1" 101 4535 "-" "AutobahnPython/0.17.2" universe-98PmJS-0 | [2017-03-02 06:17:03,857] [INFO:universe.rewarder.remote] WebSocket connection closed: connection was closed uncleanly (peer dropped the TCP connection without previous WebSocket closing handshake) universe-98PmJS-0 | [2017-03-02 06:17:05,060] [play_vexpect] Fell behind by 1.299440860748291s from target; losing 77 frames universe-98PmJS-0 | [2017-03-02 06:17:04,961] [INFO:universe.rewarder.remote] [Twisted] Active client disconnected (sent 11 messages). Still have 0 active clients left universe-98PmJS-0 | [2017-03-02 06:17:07,907] [play_vexpect] Fell behind by 1.564291000366211s from target; losing 93 frames universe-98PmJS-0 | [2017-03-02 06:17:09,311] [play_vexpect] Fell behind by 0.6579861640930176s from target; losing 39 frames universe-98PmJS-0 | [2017-03-02 06:17:12,719] [play_vexpect] Fell behind by 2.2593607902526855s from target; losing 135 frames universe-98PmJS-0 | [2017-03-02 06:17:13,977] [play_vexpect] Advancing to the next hopeful state (2/2): MaskState universe-98PmJS-0 | [2017-03-02 06:17:15,105] [play_vexpect] Fell behind by 1.237210988998413s from target; losing 74 frames universe-98PmJS-0 | [2017-03-02 06:17:15,540] [play_vexpect] Handled error.VExpectTimeout: Error: vexpect has been looking for the same states for 60s: [MaskState] (old plausible states: [MaskState]) (runtime: 68.132591s) universe-98PmJS-0 | [tigervnc] universe-98PmJS-0 | [tigervnc] Thu Mar 2 06:17:16 2017 universe-98PmJS-0 | [tigervnc] Connections: closed: 127.0.0.1::38740 (Clean disconnection) universe-98PmJS-0 | [tigervnc] EncodeManager: Framebuffer updates: 202 universe-98PmJS-0 | [tigervnc] EncodeManager: ZRLE: universe-98PmJS-0 | [tigervnc] EncodeManager: Solid: 15 rects, 423.872 kpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 1.0293 KiB (1:1608.79 ratio) universe-98PmJS-0 | [tigervnc] EncodeManager: Bitmap RLE: 65 rects, 732.165 kpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 97.3604 KiB (1:29.3834 ratio) universe-98PmJS-0 | [tigervnc] EncodeManager: Indexed RLE: 127 rects, 474.997 kpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 116.199 KiB (1:15.9807 ratio) universe-98PmJS-0 | [tigervnc] EncodeManager: Full Colour: 120 rects, 3.44456 Mpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 9.86009 MiB (1:1.33278 ratio) universe-98PmJS-0 | [tigervnc] EncodeManager: Total: 327 rects, 5.07559 Mpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 10.0696 MiB (1:1.92317 ratio) universe-98PmJS-0 | [2017-03-02 06:17:17,519] [INFO:root] [EnvController] RESET CAUSE: VExpect failed with returncode 10, which means it timed out internally. Going to trigger a reset. universe-98PmJS-0 | [2017-03-02 06:17:17,523] [INFO:root] [EnvController] Triggering a reset on EnvController universe-98PmJS-0 | [2017-03-02 06:17:17,523] [INFO:root] [EnvStatus] Changing env_state: resetting (env_id=flashgames.DuskDrive-v0) -> resetting (env_id=flashgames.DuskDrive-v0) (episode_id: 2->3, fps=60) universe-98PmJS-0 | [Thu Mar 2 06:17:17 UTC 2017] [/usr/local/bin/sudoable-env-setup] Allowing outbound network traffic to non-private IPs for git-lfs. (Going to fetch files via git lfs.) universe-98PmJS-0 | [Thu Mar 2 06:17:17 UTC 2017] [/usr/local/bin/sudoable-env-setup] Completion file /usr/local/openai/git-lfs/flashgames.DuskDrive-v0 exists; not git-lfs pulling universe-98PmJS-0 | [Thu Mar 2 06:17:17 UTC 2017] [/usr/local/bin/sudoable-env-setup] Disabling outbound network traffic for flashgames.DuskDrive-v0 universe-98PmJS-0 | [2017-03-02 06:17:17,881] [INFO:gym_flashgames.launcher] [EnvController] Launching new Chrome process (attempt 0/10) universe-98PmJS-0 | [2017-03-02 06:17:17,881] [INFO:root] Replacing selenium_wrapper_server since we currently do it at every episode boundary universe-98PmJS-0 | [2017-03-02 06:17:17,882] [ERROR:root] Closing server (via subprocess.close()) and all chromes (via pkill chromedriver || :; pkill chrome || :) universe-98PmJS-0 | [init] [2017-03-02 06:17:17,895] init detected end of child process 409 with exit code 0, killed by SIGTERM: 15 universe-98PmJS-0 | [init] [2017-03-02 06:17:17,899] init detected end of child process 631 with exit code 0, killed by SIGTERM: 15 universe-98PmJS-0 | [init] [2017-03-02 06:17:17,903] init detected end of child process 646 with exit code 0, killed by SIGTERM: 15 universe-98PmJS-0 | [init] [2017-03-02 06:17:17,928] init detected end of child process 656 with exit code 0, killed by SIGTERM: 15 universe-98PmJS-0 | [init] [2017-03-02 06:17:17,971] init detected end of child process 424 with exit code 0, not killed by signal universe-98PmJS-0 | [init] [2017-03-02 06:17:18,408] init detected end of child process 420 with exit code 0, not killed by signal universe-98PmJS-0 | [init] [2017-03-02 06:17:18,408] init detected end of child process 421 with exit code 0, not killed by signal universe-98PmJS-0 | [init] [2017-03-02 06:17:18,408] init detected end of child process 423 with exit code 0, killed by SIGTERM: 15 universe-98PmJS-0 | [init] [2017-03-02 06:17:18,408] init detected end of child process 412 with exit code 0, not killed by signal universe-98PmJS-0 | [2017-03-02 06:17:18,509] [selenium_wrapper_server] Calling webdriver.Chrome() universe-98PmJS-0 | [nginx] 2017/03/02 06:17:20 [info] 60#60: 32 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1" universe-98PmJS-0 | [nginx] 2017/03/02 06:17:20 [info] 60#60: 33 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1" universe-98PmJS-0 | [nginx] 2017/03/02 06:17:20 [info] 60#60: 34 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1" universe-98PmJS-0 | [2017-03-02 06:17:20,365] [selenium_wrapper_server] Call to webdriver.Chrome() completed: 1.86s universe-98PmJS-0 | [2017-03-02 06:17:20,366] [INFO:gym_flashgames.launcher] [EnvController] Navigating browser to url=http://localhost/flashgames.DuskDrive-v0 universe-98PmJS-0 | [2017-03-02 06:17:20,492] [INFO:root] [EnvController] Running command: /app/universe-envs/controlplane/bin/play_vexpect -e flashgames.DuskDrive-v0 -r vnc://127.0.0.1:5900 -d universe-98PmJS-0 | [nginx] 2017/03/02 06:17:21 [info] 60#60: 40 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google-analytics.com:443 HTTP/1.1" universe-98PmJS-0 | [2017-03-02 06:17:22,109] [play_vexpect] No rewarder addresses were provided, so this env cannot connect to the remote's rewarder channel, and cannot send control messages (e.g. reset) universe-98PmJS-0 | [2017-03-02 06:17:22,110] [play_vexpect] Using the golang VNC implementation universe-98PmJS-0 | [2017-03-02 06:17:22,110] [play_vexpect] Using VNCSession arguments: {'fine_quality_level': 50, 'compress_level': 0, 'start_timeout': 7, 'subsample_level': 2, 'encoding': 'zrle'}. (Customize by running "env.configure(vnc_kwargs={...})" universe-98PmJS-0 | [2017-03-02 06:17:22,110] [play_vexpect] Printed stats will ignore clock skew. (This usually makes sense only when the environment and agent are on the same machine.) universe-98PmJS-0 | [2017-03-02 06:17:22,115] [play_vexpect] [0] Connecting to environment: vnc://127.0.0.1:5900 password=openai. If desired, you can manually connect a VNC viewer, such as TurboVNC. Most environments provide a convenient in-browser VNC client: http://None/viewer/?password=openai universe-98PmJS-0 | [2017-03-02 06:17:22,115] [play_vexpect] [0] Connecting to environment details: vnc_address=127.0.0.1:5900 vnc_password=openai rewarder_address=None rewarder_password=openai universe-98PmJS-0 | 2017/03/02 06:17:22 I0302 06:17:22.116656 1137 gymvnc.go:417] [0:127.0.0.1:5900] opening connection to VNC server universe-98PmJS-0 | [tigervnc] universe-98PmJS-0 | [tigervnc] Thu Mar 2 06:17:22 2017 universe-98PmJS-0 | [tigervnc] Connections: accepted: 127.0.0.1::38850 universe-98PmJS-0 | [tigervnc] SConnection: Client needs protocol version 3.8 universe-98PmJS-0 | [tigervnc] SConnection: Client requests security type VncAuth(2) universe-98PmJS-0 | [tigervnc] VNCSConnST: Server default pixel format depth 24 (32bpp) little-endian rgb888 universe-98PmJS-0 | 2017/03/02 06:17:22 I0302 06:17:22.126206 1137 gymvnc.go:550] [0:127.0.0.1:5900] connection established universe-98PmJS-0 | [tigervnc] VNCSConnST: Client pixel format depth 24 (32bpp) little-endian bgr888 universe-98PmJS-0 | [2017-03-02 06:17:22,773] [play_vexpect] Waiting for any of [MaskState] to activate universe-98PmJS-0 | [2017-03-02 06:17:29,876] [play_vexpect] Applying transition: ClickTransition['initializing1'] x=429 y=539 buttonmask=1> for active state MaskState. (Summary: plausible_states=MaskState distance_m=0.0489 match_time_m=221us) universe-98PmJS-0 | [2017-03-02 06:17:29,890] [play_vexpect] Waiting for any of [MaskState] to activate (or whether any of [MaskState] are still active) universe-98PmJS-0 | [2017-03-02 06:17:33,957] [play_vexpect] Advancing to the next hopeful state (2/2): MaskState universe-98PmJS-0 | [2017-03-02 06:17:38,461] [play_vexpect] Advancing to the next hopeful state (1/2): MaskState universe-98PmJS-0 | [2017-03-02 06:17:40,285] [play_vexpect] Fell behind by 4.196403741836548s from target; losing 251 frames universe-98PmJS-0 | [2017-03-02 06:17:42,422] [play_vexpect] Fell behind by 1.4747495651245117s from target; losing 88 frames universe-98PmJS-0 | [2017-03-02 06:17:44,075] [play_vexpect] Fell behind by 1.011826753616333s from target; losing 60 frames universe-98PmJS-0 | [2017-03-02 06:17:45,242] [play_vexpect] Fell behind by 0.563737154006958s from target; losing 33 frames universe-98PmJS-0 | [2017-03-02 06:17:46,459] [play_vexpect] Fell behind by 0.6118791103363037s from target; losing 36 frames universe-98PmJS-0 | [2017-03-02 06:17:47,795] [play_vexpect] Fell behind by 0.48017120361328125s from target; losing 28 frames universe-98PmJS-0 | [2017-03-02 06:17:48,815] [play_vexpect] Advancing to the next hopeful state (2/2): MaskState universe-98PmJS-0 | [2017-03-02 06:17:50,920] [play_vexpect] Fell behind by 2.361299753189087s from target; losing 141 frames universe-98PmJS-0 | [2017-03-02 06:17:54,449] [play_vexpect] Fell behind by 2.577153205871582s from target; losing 154 frames universe-98PmJS-0 | [2017-03-02 06:17:57,420] [play_vexpect] Fell behind by 2.075864315032959s from target; losing 124 frames universe-98PmJS-0 | [2017-03-02 06:18:00,666] [play_vexpect] Fell behind by 2.106170892715454s from target; losing 126 frames universe-98PmJS-0 | [2017-03-02 06:18:03,517] [play_vexpect] Fell behind by 1.971766471862793s from target; losing 118 frames universe-98PmJS-0 | [2017-03-02 06:18:06,760] [play_vexpect] Fell behind by 2.213761329650879s from target; losing 132 frames universe-98PmJS-0 | [2017-03-02 06:18:08,353] [play_vexpect] Advancing to the next hopeful state (1/2): MaskState universe-98PmJS-0 | [2017-03-02 06:18:10,191] [play_vexpect] Fell behind by 2.5700507164001465s from target; losing 154 frames universe-98PmJS-0 | [2017-03-02 06:18:14,610] [play_vexpect] Fell behind by 3.1608996391296387s from target; losing 189 frames universe-98PmJS-0 | [2017-03-02 06:18:17,644] [play_vexpect] Fell behind by 1.8173108100891113s from target; losing 109 frames universe-98PmJS-0 | [nginx] 2017/03/02 06:18:20 [info] 60#60: 36 client timed out (110: Connection timed out) while waiting for request, client: 127.0.0.1, server: 0.0.0.0:80 universe-98PmJS-0 | [nginx] 2017/03/02 06:18:20 [info] 60#60: 37 client timed out (110: Connection timed out) while waiting for request, client: 127.0.0.1, server: 0.0.0.0:80 universe-98PmJS-0 | [nginx] 2017/03/02 06:18:20 [info] 60#60: 38 client timed out (110: Connection timed out) while waiting for request, client: 127.0.0.1, server: 0.0.0.0:80 universe-98PmJS-0 | [nginx] 2017/03/02 06:18:20 [info] 60#60: 39 client timed out (110: Connection timed out) while waiting for request, client: 127.0.0.1, server: 0.0.0.0:80 universe-98PmJS-0 | [2017-03-02 06:18:21,070] [play_vexpect] Fell behind by 2.036191463470459s from target; losing 122 frames universe-98PmJS-0 | [2017-03-02 06:18:24,896] [play_vexpect] Fell behind by 2.5178515911102295s from target; losing 151 frames universe-98PmJS-0 | [2017-03-02 06:18:28,628] [play_vexpect] Fell behind by 2.191056251525879s from target; losing 131 frames universe-98PmJS-0 | [2017-03-02 06:18:30,483] [play_vexpect] Advancing to the next hopeful state (2/2): MaskState universe-98PmJS-0 | [2017-03-02 06:18:32,566] [play_vexpect] Fell behind by 2.962843418121338s from target; losing 177 frames universe-98PmJS-0 | [2017-03-02 06:18:33,556] [play_vexpect] Handled error.VExpectTimeout: Error: vexpect has been looking for the same states for 60s: [MaskState] (old plausible states: [MaskState]) (runtime: 71.389089s) universe-98PmJS-0 | [tigervnc] universe-98PmJS-0 | [tigervnc] Thu Mar 2 06:18:35 2017 universe-98PmJS-0 | [tigervnc] Connections: closed: 127.0.0.1::38850 (Clean disconnection) universe-98PmJS-0 | [tigervnc] EncodeManager: Framebuffer updates: 194 universe-98PmJS-0 | [tigervnc] EncodeManager: ZRLE: universe-98PmJS-0 | [tigervnc] EncodeManager: Solid: 14 rects, 423.712 kpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 1 KiB (1:1655.29 ratio) universe-98PmJS-0 | [tigervnc] EncodeManager: Bitmap RLE: 70 rects, 701.95 kpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 93.4482 KiB (1:29.3511 ratio) universe-98PmJS-0 | [tigervnc] EncodeManager: Indexed RLE: 129 rects, 483.072 kpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 120.717 KiB (1:15.6442 ratio) universe-98PmJS-0 | [tigervnc] EncodeManager: Full Colour: 118 rects, 3.37936 Mpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 9.67346 MiB (1:1.33278 ratio) universe-98PmJS-0 | [tigervnc] EncodeManager: Total: 331 rects, 4.98809 Mpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 9.88359 MiB (1:1.9256 ratio) universe-98PmJS-0 | [2017-03-02 06:18:35,908] [INFO:root] [EnvController] RESET CAUSE: VExpect failed with returncode 10, which means it timed out internally. Going to trigger a reset. universe-98PmJS-0 | [2017-03-02 06:18:35,918] [INFO:root] [EnvController] Triggering a reset on EnvController universe-98PmJS-0 | [2017-03-02 06:18:35,918] [INFO:root] [EnvStatus] Changing env_state: resetting (env_id=flashgames.DuskDrive-v0) -> resetting (env_id=flashgames.DuskDrive-v0) (episode_id: 3->4, fps=60) universe-98PmJS-0 | [Thu Mar 2 06:18:36 UTC 2017] [/usr/local/bin/sudoable-env-setup] Allowing outbound network traffic to non-private IPs for git-lfs. (Going to fetch files via git lfs.) universe-98PmJS-0 | [Thu Mar 2 06:18:36 UTC 2017] [/usr/local/bin/sudoable-env-setup] Completion file /usr/local/openai/git-lfs/flashgames.DuskDrive-v0 exists; not git-lfs pulling universe-98PmJS-0 | [Thu Mar 2 06:18:36 UTC 2017] [/usr/local/bin/sudoable-env-setup] Disabling outbound network traffic for flashgames.DuskDrive-v0 universe-98PmJS-0 | [2017-03-02 06:18:36,273] [INFO:gym_flashgames.launcher] [EnvController] Launching new Chrome process (attempt 0/10) universe-98PmJS-0 | [2017-03-02 06:18:36,273] [INFO:root] Replacing selenium_wrapper_server since we currently do it at every episode boundary universe-98PmJS-0 | [2017-03-02 06:18:36,273] [ERROR:root] Closing server (via subprocess.close()) and all chromes (via pkill chromedriver || :; pkill chrome || :) universe-98PmJS-0 | [init] [2017-03-02 06:18:36,292] init detected end of child process 899 with exit code 0, killed by SIGTERM: 15 universe-98PmJS-0 | [init] [2017-03-02 06:18:36,297] init detected end of child process 1120 with exit code 0, killed by SIGTERM: 15 universe-98PmJS-0 | [init] [2017-03-02 06:18:36,300] init detected end of child process 1135 with exit code 0, killed by SIGTERM: 15 universe-98PmJS-0 | [init] [2017-03-02 06:18:36,316] init detected end of child process 914 with exit code 0, not killed by signal universe-98PmJS-0 | [init] [2017-03-02 06:18:36,332] init detected end of child process 1145 with exit code 0, killed by SIGTERM: 15 universe-98PmJS-0 | [init] [2017-03-02 06:18:36,807] init detected end of child process 910 with exit code 0, not killed by signal universe-98PmJS-0 | [init] [2017-03-02 06:18:36,807] init detected end of child process 911 with exit code 0, not killed by signal universe-98PmJS-0 | [init] [2017-03-02 06:18:36,807] init detected end of child process 913 with exit code 0, killed by SIGTERM: 15 universe-98PmJS-0 | [init] [2017-03-02 06:18:36,808] init detected end of child process 902 with exit code 0, not killed by signal universe-98PmJS-0 | [2017-03-02 06:18:36,913] [selenium_wrapper_server] Calling webdriver.Chrome() universe-98PmJS-0 | [nginx] 2017/03/02 06:18:38 [info] 63#63: 43 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1" universe-98PmJS-0 | [nginx] 2017/03/02 06:18:38 [info] 63#63: 44 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1" universe-98PmJS-0 | [nginx] 2017/03/02 06:18:38 [info] 63#63: 45 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1" universe-98PmJS-0 | [2017-03-02 06:18:38,765] [selenium_wrapper_server] Call to webdriver.Chrome() completed: 1.85s universe-98PmJS-0 | [2017-03-02 06:18:38,768] [INFO:gym_flashgames.launcher] [EnvController] Navigating browser to url=http://localhost/flashgames.DuskDrive-v0 universe-98PmJS-0 | [2017-03-02 06:18:38,893] [INFO:root] [EnvController] Running command: /app/universe-envs/controlplane/bin/play_vexpect -e flashgames.DuskDrive-v0 -r vnc://127.0.0.1:5900 -d universe-98PmJS-0 | [nginx] 2017/03/02 06:18:39 [info] 63#63: 51 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google-analytics.com:443 HTTP/1.1" universe-98PmJS-0 | [2017-03-02 06:18:40,476] [play_vexpect] No rewarder addresses were provided, so this env cannot connect to the remote's rewarder channel, and cannot send control messages (e.g. reset) universe-98PmJS-0 | [2017-03-02 06:18:40,476] [play_vexpect] Using the golang VNC implementation universe-98PmJS-0 | [2017-03-02 06:18:40,477] [play_vexpect] Using VNCSession arguments: {'subsample_level': 2, 'start_timeout': 7, 'encoding': 'zrle', 'compress_level': 0, 'fine_quality_level': 50}. (Customize by running "env.configure(vnc_kwargs={...})" universe-98PmJS-0 | [2017-03-02 06:18:40,477] [play_vexpect] Printed stats will ignore clock skew. (This usually makes sense only when the environment and agent are on the same machine.) universe-98PmJS-0 | [2017-03-02 06:18:40,481] [play_vexpect] [0] Connecting to environment: vnc://127.0.0.1:5900 password=openai. If desired, you can manually connect a VNC viewer, such as TurboVNC. Most environments provide a convenient in-browser VNC client: http://None/viewer/?password=openai universe-98PmJS-0 | [2017-03-02 06:18:40,482] [play_vexpect] [0] Connecting to environment details: vnc_address=127.0.0.1:5900 vnc_password=openai rewarder_address=None rewarder_password=openai universe-98PmJS-0 | 2017/03/02 06:18:40 I0302 06:18:40.483989 1626 gymvnc.go:417] [0:127.0.0.1:5900] opening connection to VNC server universe-98PmJS-0 | [tigervnc] universe-98PmJS-0 | [tigervnc] Thu Mar 2 06:18:40 2017 universe-98PmJS-0 | [tigervnc] Connections: accepted: 127.0.0.1::38960 universe-98PmJS-0 | [tigervnc] SConnection: Client needs protocol version 3.8 universe-98PmJS-0 | [tigervnc] SConnection: Client requests security type VncAuth(2) universe-98PmJS-0 | [tigervnc] VNCSConnST: Server default pixel format depth 24 (32bpp) little-endian rgb888 universe-98PmJS-0 | 2017/03/02 06:18:40 I0302 06:18:40.492997 1626 gymvnc.go:550] [0:127.0.0.1:5900] connection established universe-98PmJS-0 | [tigervnc] VNCSConnST: Client pixel format depth 24 (32bpp) little-endian bgr888 universe-98PmJS-0 | [2017-03-02 06:18:41,086] [play_vexpect] Waiting for any of [MaskState] to activate universe-98PmJS-0 | [2017-03-02 06:18:48,169] [play_vexpect] Applying transition: ClickTransition['initializing1'] x=429 y=539 buttonmask=1> for active state MaskState. (Summary: plausible_states=MaskState distance_m=0.0489 match_time_m=210us) universe-98PmJS-0 | [2017-03-02 06:18:48,186] [play_vexpect] Waiting for any of [MaskState] to activate (or whether any of [MaskState] are still active) universe-98PmJS-0 | [2017-03-02 06:18:52,205] [play_vexpect] Advancing to the next hopeful state (2/2): MaskState universe-98PmJS-0 | [2017-03-02 06:18:56,111] [play_vexpect] Fell behind by 2.186384677886963s from target; losing 131 frames universe-98PmJS-0 | [2017-03-02 06:18:57,801] [play_vexpect] Advancing to the next hopeful state (1/2): MaskState universe-98PmJS-0 | [2017-03-02 06:18:58,962] [play_vexpect] Fell behind by 1.7146668434143066s from target; losing 102 frames universe-98PmJS-0 | [2017-03-02 06:19:00,076] [play_vexpect] Fell behind by 0.5247094631195068s from target; losing 31 frames universe-98PmJS-0 | [2017-03-02 06:19:01,676] [play_vexpect] Fell behind by 1.0185282230377197s from target; losing 61 frames universe-98PmJS-0 | [2017-03-02 06:19:03,565] [play_vexpect] Fell behind by 1.2375974655151367s from target; losing 74 frames universe-98PmJS-0 | [2017-03-02 06:19:04,781] [play_vexpect] Fell behind by 0.49079203605651855s from target; losing 29 frames universe-98PmJS-0 | [2017-03-02 06:19:07,083] [play_vexpect] Fell behind by 1.2382397651672363s from target; losing 74 frames universe-98PmJS-0 | [2017-03-02 06:19:09,343] [play_vexpect] Advancing to the next hopeful state (2/2): MaskState universe-98PmJS-0 | [2017-03-02 06:19:11,901] [play_vexpect] Fell behind by 3.639575242996216s from target; losing 218 frames universe-98PmJS-0 | [2017-03-02 06:19:16,337] [play_vexpect] Fell behind by 3.3225719928741455s from target; losing 199 frames universe-98PmJS-0 | [2017-03-02 06:19:18,411] [play_vexpect] Fell behind by 1.254944086074829s from target; losing 75 frames universe-98PmJS-0 | [2017-03-02 06:19:21,394] [play_vexpect] Fell behind by 2.25596022605896s from target; losing 135 frames universe-98PmJS-0 | [2017-03-02 06:19:23,603] [play_vexpect] Fell behind by 1.4227886199951172s from target; losing 85 frames universe-98PmJS-0 | [2017-03-02 06:19:27,022] [play_vexpect] Fell behind by 2.5479354858398438s from target; losing 152 frames universe-98PmJS-0 | [2017-03-02 06:19:29,078] [play_vexpect] Advancing to the next hopeful state (1/2): MaskState universe-98PmJS-0 | [2017-03-02 06:19:31,021] [play_vexpect] Fell behind by 2.9127960205078125s from target; losing 174 frames universe-98PmJS-0 | [2017-03-02 06:19:34,223] [play_vexpect] Fell behind by 1.9591279029846191s from target; losing 117 frames universe-98PmJS-0 | [nginx] 2017/03/02 06:19:38 [info] 63#63: 47 client timed out (110: Connection timed out) while waiting for request, client: 127.0.0.1, server: 0.0.0.0:80 universe-98PmJS-0 | [2017-03-02 06:19:37,307] [play_vexpect] Fell behind by 2.144737720489502s from target; losing 128 frames universe-98PmJS-0 | [nginx] 2017/03/02 06:19:38 [info] 63#63: 48 client timed out (110: Connection timed out) while waiting for request, client: 127.0.0.1, server: 0.0.0.0:80 universe-98PmJS-0 | [nginx] 2017/03/02 06:19:38 [info] 63#63: 49 client timed out (110: Connection timed out) while waiting for request, client: 127.0.0.1, server: 0.0.0.0:80 universe-98PmJS-0 | [nginx] 2017/03/02 06:19:38 [info] 63#63: 50 client timed out (110: Connection timed out) while waiting for request, client: 127.0.0.1, server: 0.0.0.0:80 universe-98PmJS-0 | [2017-03-02 06:19:40,637] [play_vexpect] Fell behind by 2.4985806941986084s from target; losing 149 frames universe-98PmJS-0 | [2017-03-02 06:19:44,643] [play_vexpect] Fell behind by 2.3357648849487305s from target; losing 140 frames universe-98PmJS-0 | [2017-03-02 06:19:46,981] [play_vexpect] Fell behind by 1.3960158824920654s from target; losing 83 frames universe-98PmJS-0 | [2017-03-02 06:19:47,834] [play_vexpect] Advancing to the next hopeful state (2/2): MaskState universe-98PmJS-0 | [2017-03-02 06:19:49,925] [play_vexpect] Fell behind by 2.447624683380127s from target; losing 146 frames universe-98PmJS-0 | [2017-03-02 06:19:51,391] [play_vexpect] Handled error.VExpectTimeout: Error: vexpect has been looking for the same states for 60s: [MaskState] (old plausible states: [MaskState]) (runtime: 70.852685s) universe-98PmJS-0 | [tigervnc] universe-98PmJS-0 | [tigervnc] Thu Mar 2 06:19:52 2017 universe-98PmJS-0 | [tigervnc] Connections: closed: 127.0.0.1::38960 (Clean disconnection) universe-98PmJS-0 | [tigervnc] universe-98PmJS-0 | [tigervnc] Thu Mar 2 06:19:53 2017 universe-98PmJS-0 | [tigervnc] EncodeManager: Framebuffer updates: 195 universe-98PmJS-0 | [tigervnc] EncodeManager: ZRLE: universe-98PmJS-0 | [tigervnc] EncodeManager: Solid: 6 rects, 46.88 kpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 224 B (1:837.464 ratio) universe-98PmJS-0 | [tigervnc] EncodeManager: Bitmap RLE: 74 rects, 1.11225 Mpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 144.779 KiB (1:30.0152 ratio) universe-98PmJS-0 | [tigervnc] EncodeManager: Indexed RLE: 126 rects, 462.497 kpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 118.318 KiB (1:15.2817 ratio) universe-98PmJS-0 | [tigervnc] EncodeManager: Full Colour: 120 rects, 3.4624 Mpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 9.91114 MiB (1:1.33278 ratio) universe-98PmJS-0 | [tigervnc] EncodeManager: Total: 326 rects, 5.08402 Mpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 10.1683 MiB (1:1.90767 ratio) universe-98PmJS-0 | [2017-03-02 06:19:54,043] [INFO:root] [EnvController] RESET CAUSE: VExpect failed with returncode 10, which means it timed out internally. Going to trigger a reset. universe-98PmJS-0 | [2017-03-02 06:19:54,195] [INFO:root] [EnvController] Triggering a reset on EnvController universe-98PmJS-0 | [2017-03-02 06:19:54,223] [INFO:root] [EnvStatus] Changing env_state: resetting (env_id=flashgames.DuskDrive-v0) -> resetting (env_id=flashgames.DuskDrive-v0) (episode_id: 4->5, fps=60) universe-98PmJS-0 | [Thu Mar 2 06:19:54 UTC 2017] [/usr/local/bin/sudoable-env-setup] Allowing outbound network traffic to non-private IPs for git-lfs. (Going to fetch files via git lfs.) universe-98PmJS-0 | [Thu Mar 2 06:19:54 UTC 2017] [/usr/local/bin/sudoable-env-setup] Completion file /usr/local/openai/git-lfs/flashgames.DuskDrive-v0 exists; not git-lfs pulling universe-98PmJS-0 | [Thu Mar 2 06:19:54 UTC 2017] [/usr/local/bin/sudoable-env-setup] Disabling outbound network traffic for flashgames.DuskDrive-v0 universe-98PmJS-0 | [2017-03-02 06:19:54,667] [INFO:gym_flashgames.launcher] [EnvController] Launching new Chrome process (attempt 0/10) universe-98PmJS-0 | [2017-03-02 06:19:54,668] [INFO:root] Replacing selenium_wrapper_server since we currently do it at every episode boundary universe-98PmJS-0 | [2017-03-02 06:19:54,668] [ERROR:root] Closing server (via subprocess.close()) and all chromes (via pkill chromedriver || :; pkill chrome || :) universe-98PmJS-0 | [init] [2017-03-02 06:19:54,683] init detected end of child process 1388 with exit code 0, killed by SIGTERM: 15 universe-98PmJS-0 | [init] [2017-03-02 06:19:54,688] init detected end of child process 1609 with exit code 0, killed by SIGTERM: 15 universe-98PmJS-0 | [init] [2017-03-02 06:19:54,691] init detected end of child process 1624 with exit code 0, killed by SIGTERM: 15 universe-98PmJS-0 | [init] [2017-03-02 06:19:54,717] init detected end of child process 1634 with exit code 0, killed by SIGTERM: 15 universe-98PmJS-0 | [init] [2017-03-02 06:19:54,780] init detected end of child process 1403 with exit code 0, not killed by signal universe-98PmJS-0 | [init] [2017-03-02 06:19:55,464] init detected end of child process 1399 with exit code 0, not killed by signal universe-98PmJS-0 | [init] [2017-03-02 06:19:55,464] init detected end of child process 1400 with exit code 0, not killed by signal universe-98PmJS-0 | [init] [2017-03-02 06:19:55,464] init detected end of child process 1402 with exit code 0, killed by SIGTERM: 15 universe-98PmJS-0 | [init] [2017-03-02 06:19:55,464] init detected end of child process 1391 with exit code 0, not killed by signal universe-98PmJS-0 | [2017-03-02 06:19:55,494] [selenium_wrapper_server] Calling webdriver.Chrome() universe-98PmJS-0 | [nginx] 2017/03/02 06:19:57 [info] 63#63: 54 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1" universe-98PmJS-0 | [nginx] 2017/03/02 06:19:57 [info] 63#63: 55 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1" universe-98PmJS-0 | [nginx] 2017/03/02 06:19:57 [info] 63#63: 56 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1" universe-98PmJS-0 | [2017-03-02 06:19:57,373] [selenium_wrapper_server] Call to webdriver.Chrome() completed: 1.88s universe-98PmJS-0 | [2017-03-02 06:19:57,374] [INFO:gym_flashgames.launcher] [EnvController] Navigating browser to url=http://localhost/flashgames.DuskDrive-v0 universe-98PmJS-0 | [2017-03-02 06:19:57,497] [INFO:root] [EnvController] Running command: /app/universe-envs/controlplane/bin/play_vexpect -e flashgames.DuskDrive-v0 -r vnc://127.0.0.1:5900 -d universe-98PmJS-0 | [nginx] 2017/03/02 06:19:58 [info] 63#63: 62 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google-analytics.com:443 HTTP/1.1" universe-98PmJS-0 | [2017-03-02 06:19:59,150] [play_vexpect] No rewarder addresses were provided, so this env cannot connect to the remote's rewarder channel, and cannot send control messages (e.g. reset) universe-98PmJS-0 | [2017-03-02 06:19:59,150] [play_vexpect] Using the golang VNC implementation universe-98PmJS-0 | [2017-03-02 06:19:59,150] [play_vexpect] Using VNCSession arguments: {'compress_level': 0, 'fine_quality_level': 50, 'subsample_level': 2, 'start_timeout': 7, 'encoding': 'zrle'}. (Customize by running "env.configure(vnc_kwargs={...})" universe-98PmJS-0 | [2017-03-02 06:19:59,151] [play_vexpect] Printed stats will ignore clock skew. (This usually makes sense only when the environment and agent are on the same machine.) universe-98PmJS-0 | [2017-03-02 06:19:59,155] [play_vexpect] [0] Connecting to environment: vnc://127.0.0.1:5900 password=openai. If desired, you can manually connect a VNC viewer, such as TurboVNC. Most environments provide a convenient in-browser VNC client: http://None/viewer/?password=openai universe-98PmJS-0 | [2017-03-02 06:19:59,156] [play_vexpect] [0] Connecting to environment details: vnc_address=127.0.0.1:5900 vnc_password=openai rewarder_address=None rewarder_password=openai universe-98PmJS-0 | 2017/03/02 06:19:59 I0302 06:19:59.157075 2115 gymvnc.go:417] [0:127.0.0.1:5900] opening connection to VNC server universe-98PmJS-0 | [tigervnc] universe-98PmJS-0 | [tigervnc] Thu Mar 2 06:19:59 2017 universe-98PmJS-0 | [tigervnc] Connections: accepted: 127.0.0.1::39070 universe-98PmJS-0 | [tigervnc] SConnection: Client needs protocol version 3.8 universe-98PmJS-0 | [tigervnc] SConnection: Client requests security type VncAuth(2) universe-98PmJS-0 | [tigervnc] VNCSConnST: Server default pixel format depth 24 (32bpp) little-endian rgb888 universe-98PmJS-0 | 2017/03/02 06:19:59 I0302 06:19:59.171959 2115 gymvnc.go:550] [0:127.0.0.1:5900] connection established universe-98PmJS-0 | [tigervnc] VNCSConnST: Client pixel format depth 24 (32bpp) little-endian bgr888 universe-98PmJS-0 | [2017-03-02 06:19:59,768] [play_vexpect] Waiting for any of [MaskState] to activate universe-98PmJS-0 | [2017-03-02 06:20:06,835] [play_vexpect] Applying transition: ClickTransition['initializing1'] x=429 y=539 buttonmask=1> for active state MaskState. (Summary: plausible_states=MaskState distance_m=0.0489 match_time_m=212us) universe-98PmJS-0 | [2017-03-02 06:20:06,851] [play_vexpect] Waiting for any of [MaskState] to activate (or whether any of [MaskState] are still active) universe-98PmJS-0 | [2017-03-02 06:20:10,886] [play_vexpect] Advancing to the next hopeful state (2/2): MaskState universe-98PmJS-0 | [2017-03-02 06:20:13,846] [play_vexpect] Fell behind by 1.4401819705963135s from target; losing 86 frames universe-98PmJS-0 | [2017-03-02 06:20:20,654] [play_vexpect] Advancing to the next hopeful state (1/2): MaskState universe-98PmJS-0 | [2017-03-02 06:20:24,350] [play_vexpect] Fell behind by 6.512059450149536s from target; losing 390 frames universe-98PmJS-0 | [2017-03-02 06:20:31,356] [play_vexpect] Fell behind by 5.579269170761108s from target; losing 334 frames universe-98PmJS-0 | [2017-03-02 06:20:34,966] [play_vexpect] Fell behind by 2.3119914531707764s from target; losing 138 frames universe-98PmJS-0 | [2017-03-02 06:20:37,978] [play_vexpect] Fell behind by 1.8190491199493408s from target; losing 109 frames universe-98PmJS-0 | [2017-03-02 06:20:41,007] [play_vexpect] Fell behind by 2.284169912338257s from target; losing 137 frames universe-98PmJS-0 | [2017-03-02 06:20:43,581] [play_vexpect] Fell behind by 1.8236465454101562s from target; losing 109 frames universe-98PmJS-0 | [2017-03-02 06:20:44,839] [play_vexpect] Advancing to the next hopeful state (2/2): MaskState universe-98PmJS-0 | [2017-03-02 06:20:49,648] [play_vexpect] Fell behind by 5.152446031570435s from target; losing 309 frames universe-98PmJS-0 | [2017-03-02 06:20:55,085] [play_vexpect] Fell behind by 4.1734960079193115s from target; losing 250 frames universe-98PmJS-0 | [2017-03-02 06:21:08,013] [play_vexpect] Fell behind by 10.946985483169556s from target; losing 656 frames universe-98PmJS-0 | [2017-03-02 06:21:14,698] [play_vexpect] Handled error.VExpectTimeout: Error: vexpect has been looking for the same states for 60s: [MaskState] (old plausible states: [MaskState]) (runtime: 75.459079s) universe-98PmJS-0 | [nginx] 2017/03/02 06:20:57 [info] 63#63: 58 client timed out (110: Connection timed out) while waiting for request, client: 127.0.0.1, server: 0.0.0.0:80 universe-98PmJS-0 | [nginx] 2017/03/02 06:20:57 [info] 63#63: 59 client timed out (110: Connection timed out) while waiting for request, client: 127.0.0.1, server: 0.0.0.0:80 universe-98PmJS-0 | [nginx] 2017/03/02 06:20:57 [info] 63#63: 60 client timed out (110: Connection timed out) while waiting for request, client: 127.0.0.1, server: 0.0.0.0:80 universe-98PmJS-0 | [nginx] 2017/03/02 06:20:57 [info] 63#63: 61 client timed out (110: Connection timed out) while waiting for request, client: 127.0.0.1, server: 0.0.0.0:80 universe-98PmJS-0 | [nginx] 2017/03/02 06:21:18 [info] 61#61: 65 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900 universe-98PmJS-0 | [nginx] 2017/03/02 06:21:18 [info] 61#61: 66 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900 universe-98PmJS-0 | [nginx] 2017/03/02 06:21:18 [info] 61#61: 67 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900 universe-98PmJS-0 | [nginx] 2017/03/02 06:21:18 [info] 61#61: 68 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900 universe-98PmJS-0 | [nginx] 2017/03/02 06:21:18 [info] 61#61: 69 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900 universe-98PmJS-0 | [nginx] 2017/03/02 06:21:18 [info] 61#61: 70 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900 universe-98PmJS-0 | [nginx] 2017/03/02 06:21:18 [info] 61#61: 71 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900 universe-98PmJS-0 | [nginx] 2017/03/02 06:21:18 [info] 61#61: 72 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900 universe-98PmJS-0 | [nginx] 2017/03/02 06:21:18 [info] 61#61: 73 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900 universe-98PmJS-0 | [nginx] 2017/03/02 06:21:18 [info] 61#61: 74 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900 universe-98PmJS-0 | [tigervnc] universe-98PmJS-0 | [tigervnc] Thu Mar 2 06:21:18 2017 universe-98PmJS-0 | [tigervnc] Connections: closed: 127.0.0.1::39070 (Clean disconnection) universe-98PmJS-0 | [tigervnc] EncodeManager: Framebuffer updates: 190 universe-98PmJS-0 | [tigervnc] EncodeManager: ZRLE: universe-98PmJS-0 | [tigervnc] EncodeManager: Solid: 14 rects, 423.712 kpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 1 KiB (1:1655.29 ratio) universe-98PmJS-0 | [tigervnc] EncodeManager: Bitmap RLE: 66 rects, 708.924 kpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 94.2383 KiB (1:29.3937 ratio) universe-98PmJS-0 | [tigervnc] EncodeManager: Indexed RLE: 114 rects, 523.595 kpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 130.088 KiB (1:15.7327 ratio) universe-98PmJS-0 | [tigervnc] EncodeManager: Full Colour: 119 rects, 3.43331 Mpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 9.82787 MiB (1:1.33278 ratio) universe-98PmJS-0 | [tigervnc] EncodeManager: Total: 313 rects, 5.08954 Mpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 10.0479 MiB (1:1.9326 ratio) universe-98PmJS-0 | [2017-03-02 06:21:19,267] [INFO:root] [EnvController] RESET CAUSE: VExpect failed with returncode 10, which means it timed out internally. Going to trigger a reset. universe-98PmJS-0 | [2017-03-02 06:21:19,268] [INFO:root] [EnvController] Triggering a reset on EnvController universe-98PmJS-0 | [2017-03-02 06:21:19,268] [INFO:root] [EnvStatus] Changing env_state: resetting (env_id=flashgames.DuskDrive-v0) -> resetting (env_id=flashgames.DuskDrive-v0) (episode_id: 5->6, fps=60) universe-98PmJS-0 | [Thu Mar 2 06:21:19 UTC 2017] [/usr/local/bin/sudoable-env-setup] Allowing outbound network traffic to non-private IPs for git-lfs. (Going to fetch files via git lfs.) universe-98PmJS-0 | [Thu Mar 2 06:21:19 UTC 2017] [/usr/local/bin/sudoable-env-setup] Completion file /usr/local/openai/git-lfs/flashgames.DuskDrive-v0 exists; not git-lfs pulling universe-98PmJS-0 | [Thu Mar 2 06:21:19 UTC 2017] [/usr/local/bin/sudoable-env-setup] Disabling outbound network traffic for flashgames.DuskDrive-v0 universe-98PmJS-0 | [2017-03-02 06:21:19,763] [INFO:gym_flashgames.launcher] [EnvController] Launching new Chrome process (attempt 0/10) universe-98PmJS-0 | [2017-03-02 06:21:19,763] [INFO:root] Replacing selenium_wrapper_server since we currently do it at every episode boundary universe-98PmJS-0 | [2017-03-02 06:21:19,763] [ERROR:root] Closing server (via subprocess.close()) and all chromes (via pkill chromedriver || :; pkill chrome || :) universe-98PmJS-0 | [init] [2017-03-02 06:21:19,786] init detected end of child process 1877 with exit code 0, killed by SIGTERM: 15 universe-98PmJS-0 | [init] [2017-03-02 06:21:19,791] init detected end of child process 2098 with exit code 0, killed by SIGTERM: 15 universe-98PmJS-0 | [init] [2017-03-02 06:21:19,794] init detected end of child process 2113 with exit code 0, killed by SIGTERM: 15 universe-98PmJS-0 | [init] [2017-03-02 06:21:19,824] init detected end of child process 2122 with exit code 0, killed by SIGTERM: 15 universe-98PmJS-0 | [init] [2017-03-02 06:21:19,846] init detected end of child process 1892 with exit code 0, not killed by signal universe-98PmJS-0 | [init] [2017-03-02 06:21:20,249] init detected end of child process 1888 with exit code 0, not killed by signal universe-98PmJS-0 | [init] [2017-03-02 06:21:20,249] init detected end of child process 1889 with exit code 0, not killed by signal universe-98PmJS-0 | [init] [2017-03-02 06:21:20,250] init detected end of child process 1891 with exit code 0, killed by SIGTERM: 15 universe-98PmJS-0 | [init] [2017-03-02 06:21:20,250] init detected end of child process 1880 with exit code 0, not killed by signal universe-98PmJS-0 | [2017-03-02 06:21:20,367] [selenium_wrapper_server] Calling webdriver.Chrome() universe-98PmJS-0 | [nginx] 2017/03/02 06:21:22 [info] 61#61: 75 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1" universe-98PmJS-0 | [nginx] 2017/03/02 06:21:22 [info] 61#61: 76 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1" universe-98PmJS-0 | [nginx] 2017/03/02 06:21:22 [info] 61#61: 77 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1" universe-98PmJS-0 | [2017-03-02 06:21:22,202] [selenium_wrapper_server] Call to webdriver.Chrome() completed: 1.84s universe-98PmJS-0 | [2017-03-02 06:21:22,203] [INFO:gym_flashgames.launcher] [EnvController] Navigating browser to url=http://localhost/flashgames.DuskDrive-v0 universe-98PmJS-0 | [2017-03-02 06:21:22,318] [INFO:root] [EnvController] Running command: /app/universe-envs/controlplane/bin/play_vexpect -e flashgames.DuskDrive-v0 -r vnc://127.0.0.1:5900 -d universe-98PmJS-0 | [nginx] 2017/03/02 06:21:23 [info] 61#61: 83 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google-analytics.com:443 HTTP/1.1" universe-98PmJS-0 | [2017-03-02 06:21:23,869] [play_vexpect] No rewarder addresses were provided, so this env cannot connect to the remote's rewarder channel, and cannot send control messages (e.g. reset) universe-98PmJS-0 | [2017-03-02 06:21:23,869] [play_vexpect] Using the golang VNC implementation universe-98PmJS-0 | [2017-03-02 06:21:23,869] [play_vexpect] Using VNCSession arguments: {'fine_quality_level': 50, 'subsample_level': 2, 'compress_level': 0, 'encoding': 'zrle', 'start_timeout': 7}. (Customize by running "env.configure(vnc_kwargs={...})" universe-98PmJS-0 | [2017-03-02 06:21:23,869] [play_vexpect] Printed stats will ignore clock skew. (This usually makes sense only when the environment and agent are on the same machine.) universe-98PmJS-0 | [2017-03-02 06:21:23,874] [play_vexpect] [0] Connecting to environment: vnc://127.0.0.1:5900 password=openai. If desired, you can manually connect a VNC viewer, such as TurboVNC. Most environments provide a convenient in-browser VNC client: http://None/viewer/?password=openai universe-98PmJS-0 | [2017-03-02 06:21:23,874] [play_vexpect] [0] Connecting to environment details: vnc_address=127.0.0.1:5900 vnc_password=openai rewarder_address=None rewarder_password=openai universe-98PmJS-0 | 2017/03/02 06:21:23 I0302 06:21:23.87579 2604 gymvnc.go:417] [0:127.0.0.1:5900] opening connection to VNC server universe-98PmJS-0 | [tigervnc] universe-98PmJS-0 | [tigervnc] Thu Mar 2 06:21:23 2017 universe-98PmJS-0 | [tigervnc] Connections: accepted: 127.0.0.1::39220 universe-98PmJS-0 | [tigervnc] SConnection: Client needs protocol version 3.8 universe-98PmJS-0 | [tigervnc] SConnection: Client requests security type VncAuth(2) universe-98PmJS-0 | [tigervnc] VNCSConnST: Server default pixel format depth 24 (32bpp) little-endian rgb888 universe-98PmJS-0 | 2017/03/02 06:21:23 I0302 06:21:23.884837 2604 gymvnc.go:550] [0:127.0.0.1:5900] connection established universe-98PmJS-0 | [tigervnc] VNCSConnST: Client pixel format depth 24 (32bpp) little-endian bgr888 universe-98PmJS-0 | [2017-03-02 06:21:24,485] [play_vexpect] Waiting for any of [MaskState] to activate universe-98PmJS-0 | [2017-03-02 06:21:31,570] [play_vexpect] Applying transition: ClickTransition['initializing1'] x=429 y=539 buttonmask=1> for active state MaskState. (Summary: plausible_states=MaskState distance_m=0.048 match_time_m=262us) universe-98PmJS-0 | [2017-03-02 06:21:31,585] [play_vexpect] Waiting for any of [MaskState] to activate (or whether any of [MaskState] are still active) universe-98PmJS-0 | [2017-03-02 06:21:35,623] [play_vexpect] Advancing to the next hopeful state (2/2): MaskState universe-98PmJS-0 | [2017-03-02 06:21:37,874] [play_vexpect] Advancing to the next hopeful state (1/2): MaskState universe-98PmJS-0 | [2017-03-02 06:21:38,580] [play_vexpect] Fell behind by 0.9204063415527344s from target; losing 55 frames universe-98PmJS-0 | [2017-03-02 06:21:39,555] [play_vexpect] Fell behind by 0.40032124519348145s from target; losing 24 frames universe-98PmJS-0 | [2017-03-02 06:21:40,664] [play_vexpect] Fell behind by 0.4050295352935791s from target; losing 24 frames universe-98PmJS-0 | [2017-03-02 06:21:41,801] [play_vexpect] Fell behind by 0.22504329681396484s from target; losing 13 frames universe-98PmJS-0 | [2017-03-02 06:21:42,824] [play_vexpect] Fell behind by 0.41593265533447266s from target; losing 24 frames universe-98PmJS-0 | [2017-03-02 06:21:43,884] [play_vexpect] Fell behind by 0.5130949020385742s from target; losing 30 frames universe-98PmJS-0 | [2017-03-02 06:21:45,097] [play_vexpect] Fell behind by 0.5564746856689453s from target; losing 33 frames universe-98PmJS-0 | [2017-03-02 06:21:45,960] [play_vexpect] Advancing to the next hopeful state (2/2): MaskState universe-98PmJS-0 | [2017-03-02 06:21:46,664] [play_vexpect] Fell behind by 0.835756778717041s from target; losing 50 frames universe-98PmJS-0 | [2017-03-02 06:21:47,817] [play_vexpect] Fell behind by 0.43486714363098145s from target; losing 26 frames universe-98PmJS-0 | [2017-03-02 06:21:48,981] [play_vexpect] Fell behind by 0.4889070987701416s from target; losing 29 frames universe-98PmJS-0 | [2017-03-02 06:21:50,352] [play_vexpect] Fell behind by 0.502030611038208s from target; losing 30 frames universe-98PmJS-0 | [2017-03-02 06:21:51,305] [play_vexpect] Fell behind by 0.3129422664642334s from target; losing 18 frames universe-98PmJS-0 | [2017-03-02 06:21:52,458] [play_vexpect] Fell behind by 0.45851778984069824s from target; losing 27 frames universe-98PmJS-0 | [2017-03-02 06:21:53,717] [play_vexpect] Fell behind by 0.41113829612731934s from target; losing 24 frames universe-98PmJS-0 | [2017-03-02 06:21:54,525] [play_vexpect] Fell behind by 0.28251028060913086s from target; losing 16 frames universe-98PmJS-0 | [2017-03-02 06:21:54,928] [play_vexpect] Advancing to the next hopeful state (1/2): MaskState universe-98PmJS-0 | [2017-03-02 06:21:55,900] [play_vexpect] Fell behind by 1.1288948059082031s from target; losing 67 frames universe-98PmJS-0 | [2017-03-02 06:21:56,675] [play_vexpect] Fell behind by 0.3901543617248535s from target; losing 23 frames universe-98PmJS-0 | [2017-03-02 06:21:57,946] [play_vexpect] Fell behind by 0.46291351318359375s from target; losing 27 frames universe-98PmJS-0 | [2017-03-02 06:21:58,950] [play_vexpect] Fell behind by 0.43482470512390137s from target; losing 26 frames universe-98PmJS-0 | [2017-03-02 06:21:59,699] [play_vexpect] Fell behind by 0.33150196075439453s from target; losing 19 frames universe-98PmJS-0 | [2017-03-02 06:21:59,908] [play_vexpect] Fell behind by 0.1069793701171875s from target; losing 6 frames universe-98PmJS-0 | [2017-03-02 06:22:02,077] [play_vexpect] Advancing to the next hopeful state (2/2): MaskState universe-98PmJS-0 | [2017-03-02 06:22:02,551] [play_vexpect] Fell behind by 0.6356573104858398s from target; losing 38 frames universe-98PmJS-0 | [2017-03-02 06:22:03,154] [play_vexpect] Fell behind by 0.29749512672424316s from target; losing 17 frames universe-98PmJS-0 | [2017-03-02 06:22:04,170] [play_vexpect] Fell behind by 0.13274240493774414s from target; losing 7 frames universe-98PmJS-0 | [2017-03-02 06:22:04,811] [play_vexpect] Fell behind by 0.28722262382507324s from target; losing 17 frames universe-98PmJS-0 | [2017-03-02 06:22:05,511] [play_vexpect] Fell behind by 0.36983394622802734s from target; losing 22 frames universe-98PmJS-0 | [2017-03-02 06:22:06,141] [play_vexpect] Fell behind by 0.26584839820861816s from target; losing 15 frames universe-98PmJS-0 | [2017-03-02 06:22:07,011] [play_vexpect] Fell behind by 0.5080990791320801s from target; losing 30 frames universe-98PmJS-0 | [2017-03-02 06:22:07,810] [play_vexpect] Fell behind by 0.2762622833251953s from target; losing 16 frames universe-98PmJS-0 | [2017-03-02 06:22:08,928] [play_vexpect] Fell behind by 0.25778698921203613s from target; losing 15 frames universe-98PmJS-0 | [2017-03-02 06:22:09,981] [play_vexpect] Fell behind by 0.5240662097930908s from target; losing 31 frames universe-98PmJS-0 | [2017-03-02 06:22:10,400] [play_vexpect] Advancing to the next hopeful state (1/2): MaskState universe-98PmJS-0 | [2017-03-02 06:22:10,636] [play_vexpect] Fell behind by 0.41970157623291016s from target; losing 25 frames universe-98PmJS-0 | [2017-03-02 06:22:10,831] [play_vexpect] Fell behind by 0.15285420417785645s from target; losing 9 frames universe-98PmJS-0 | [2017-03-02 06:22:11,721] [play_vexpect] Fell behind by 0.2397594451904297s from target; losing 14 frames universe-98PmJS-0 | [2017-03-02 06:22:12,849] [play_vexpect] Fell behind by 0.6656510829925537s from target; losing 39 frames universe-98PmJS-0 | [2017-03-02 06:22:13,385] [play_vexpect] Fell behind by 0.3119471073150635s from target; losing 18 frames universe-98PmJS-0 | [2017-03-02 06:22:14,273] [play_vexpect] Fell behind by 0.4114377498626709s from target; losing 24 frames universe-98PmJS-0 | [2017-03-02 06:22:15,386] [play_vexpect] Fell behind by 0.5758328437805176s from target; losing 34 frames universe-98PmJS-0 | [2017-03-02 06:22:15,966] [play_vexpect] Fell behind by 0.2510523796081543s from target; losing 15 frames universe-98PmJS-0 | [2017-03-02 06:22:16,747] [play_vexpect] Fell behind by 0.4120774269104004s from target; losing 24 frames universe-98PmJS-0 | [2017-03-02 06:22:17,363] [play_vexpect] Fell behind by 0.3358635902404785s from target; losing 20 frames universe-98PmJS-0 | [2017-03-02 06:22:17,605] [play_vexpect] Advancing to the next hopeful state (2/2): MaskState universe-98PmJS-0 | [2017-03-02 06:22:17,623] [play_vexpect] Fell behind by 0.12583041191101074s from target; losing 7 frames universe-98PmJS-0 | [2017-03-02 06:22:18,984] [play_vexpect] Fell behind by 0.20969891548156738s from target; losing 12 frames universe-98PmJS-0 | [2017-03-02 06:22:19,845] [play_vexpect] Fell behind by 0.5471441745758057s from target; losing 32 frames universe-98PmJS-0 | [2017-03-02 06:22:20,454] [play_vexpect] Fell behind by 0.45263195037841797s from target; losing 27 frames universe-98PmJS-0 | [2017-03-02 06:22:21,146] [play_vexpect] Fell behind by 0.2775237560272217s from target; losing 16 frames universe-98PmJS-0 | [2017-03-02 06:22:22,501] [play_vexpect] Fell behind by 0.507530689239502s from target; losing 30 frames universe-98PmJS-0 | [nginx] 2017/03/02 06:22:22 [info] 61#61: 79 client timed out (110: Connection timed out) while waiting for request, client: 127.0.0.1, server: 0.0.0.0:80 universe-98PmJS-0 | [nginx] 2017/03/02 06:22:22 [info] 61#61: 80 client timed out (110: Connection timed out) while waiting for request, client: 127.0.0.1, server: 0.0.0.0:80 universe-98PmJS-0 | [nginx] 2017/03/02 06:22:22 [info] 61#61: 81 client timed out (110: Connection timed out) while waiting for request, client: 127.0.0.1, server: 0.0.0.0:80 universe-98PmJS-0 | [nginx] 2017/03/02 06:22:22 [info] 61#61: 82 client timed out (110: Connection timed out) while waiting for request, client: 127.0.0.1, server: 0.0.0.0:80 universe-98PmJS-0 | [2017-03-02 06:22:23,616] [play_vexpect] Fell behind by 0.4348020553588867s from target; losing 26 frames universe-98PmJS-0 | [2017-03-02 06:22:24,408] [play_vexpect] Fell behind by 0.31290340423583984s from target; losing 18 frames universe-98PmJS-0 | [2017-03-02 06:22:25,272] [play_vexpect] Advancing to the next hopeful state (1/2): MaskState universe-98PmJS-0 | [2017-03-02 06:22:25,950] [play_vexpect] Fell behind by 0.9084317684173584s from target; losing 54 frames universe-98PmJS-0 | [2017-03-02 06:22:27,159] [play_vexpect] Fell behind by 0.5271806716918945s from target; losing 31 frames universe-98PmJS-0 | [2017-03-02 06:22:28,007] [play_vexpect] Fell behind by 0.29807019233703613s from target; losing 17 frames universe-98PmJS-0 | [2017-03-02 06:22:28,979] [play_vexpect] Fell behind by 0.3469259738922119s from target; losing 20 frames universe-98PmJS-0 | [2017-03-02 06:22:29,740] [play_vexpect] Fell behind by 0.3994636535644531s from target; losing 23 frames universe-98PmJS-0 | [2017-03-02 06:22:30,852] [play_vexpect] Fell behind by 0.5203826427459717s from target; losing 31 frames universe-98PmJS-0 | [2017-03-02 06:22:31,724] [play_vexpect] Handled error.VExpectTimeout: Error: vexpect has been looking for the same states for 60s: [MaskState] (old plausible states: [MaskState]) (runtime: 67.785048s) universe-98PmJS-0 | [tigervnc] universe-98PmJS-0 | [tigervnc] Thu Mar 2 06:22:32 2017 universe-98PmJS-0 | [tigervnc] Connections: closed: 127.0.0.1::39220 (Clean disconnection) universe-98PmJS-0 | [tigervnc] universe-98PmJS-0 | [tigervnc] Thu Mar 2 06:22:33 2017 universe-98PmJS-0 | [tigervnc] EncodeManager: Framebuffer updates: 221 universe-98PmJS-0 | [tigervnc] EncodeManager: ZRLE: universe-98PmJS-0 | [tigervnc] EncodeManager: Solid: 60 rects, 839.552 kpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 2.98047 KiB (1:1100.57 ratio) universe-98PmJS-0 | [tigervnc] EncodeManager: Bitmap RLE: 62 rects, 716.266 kpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 95.1582 KiB (1:29.4104 ratio) universe-98PmJS-0 | [tigervnc] EncodeManager: Indexed RLE: 131 rects, 444.001 kpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 110.966 KiB (1:15.6437 ratio) universe-98PmJS-0 | [tigervnc] EncodeManager: Full Colour: 120 rects, 3.43327 Mpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 9.82777 MiB (1:1.33278 ratio) universe-98PmJS-0 | [tigervnc] EncodeManager: Total: 373 rects, 5.43309 Mpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 10.032 MiB (1:2.06638 ratio) universe-98PmJS-0 | [2017-03-02 06:22:33,635] [INFO:root] [EnvController] RESET CAUSE: VExpect failed with returncode 10, which means it timed out internally. Going to trigger a reset. universe-98PmJS-0 | [2017-03-02 06:22:33,647] [INFO:root] [EnvController] Triggering a reset on EnvController universe-98PmJS-0 | [2017-03-02 06:22:33,654] [INFO:root] [EnvStatus] Changing env_state: resetting (env_id=flashgames.DuskDrive-v0) -> resetting (env_id=flashgames.DuskDrive-v0) (episode_id: 6->7, fps=60) universe-98PmJS-0 | Traceback (most recent call last): universe-98PmJS-0 | File "/app/universe-envs/controlplane/bin/controlplane.py", line 738, in universe-98PmJS-0 | sys.exit(main()) universe-98PmJS-0 | File "/app/universe-envs/controlplane/bin/controlplane.py", line 730, in main universe-98PmJS-0 | error_buffer.blocking_check(timeout=60) universe-98PmJS-0 | File "/app/universe/universe/utils/init.py", line 57, in blocking_check universe-98PmJS-0 | self.check(timeout) universe-98PmJS-0 | File "/app/universe/universe/utils/init.py", line 49, in check universe-98PmJS-0 | raise error universe-98PmJS-0 | universe.error.Error: Traceback (most recent call last): universe-98PmJS-0 | File "/app/universe-envs/controlplane/bin/controlplane.py", line 91, in run universe-98PmJS-0 | self.do_run() universe-98PmJS-0 | File "/app/universe-envs/controlplane/bin/controlplane.py", line 97, in do_run universe-98PmJS-0 | self.process_control_messages() universe-98PmJS-0 | File "/app/universe-envs/controlplane/bin/controlplane.py", line 138, in process_control_messages universe-98PmJS-0 | self.process_rpc(context, message) universe-98PmJS-0 | File "/app/universe-envs/controlplane/bin/controlplane.py", line 202, in process_rpc universe-98PmJS-0 | self.reset() universe-98PmJS-0 | File "/app/universe-envs/controlplane/bin/controlplane.py", line 251, in reset universe-98PmJS-0 | raise error.Error('controlplane: Failed to start environment with 5 consecutive attempts. Probably not going to happen.') universe-98PmJS-0 | gym_controlplane.error.Error: controlplane: Failed to start environment with 5 consecutive attempts. Probably not going to happen. universe-98PmJS-0 | [2017-03-02 06:22:33,749] [ERROR:root] Closing server (via subprocess.close()) and all chromes (via pkill chromedriver || :; pkill chrome || :) universe-98PmJS-0 | [init] [2017-03-02 06:22:33,773] init detected end of child process 2366 with exit code 0, killed by SIGTERM: 15 universe-98PmJS-0 | [init] [2017-03-02 06:22:33,774] init detected end of child process 2587 with exit code 0, killed by SIGTERM: 15 universe-98PmJS-0 | [init] [2017-03-02 06:22:33,777] init detected end of child process 2602 with exit code 0, killed by SIGTERM: 15 universe-98PmJS-0 | [init] [2017-03-02 06:22:33,798] init detected end of child process 2613 with exit code 0, killed by SIGTERM: 15 universe-98PmJS-0 | [init] [2017-03-02 06:22:33,832] init detected end of child process 2381 with exit code 0, not killed by signal universe-98PmJS-0 | [tigervnc] Connections: closed: 127.0.0.1::38406 (Clean disconnection) universe-98PmJS-0 | [tigervnc] EncodeManager: Framebuffer updates: 79 universe-98PmJS-0 | [tigervnc] EncodeManager: ZRLE: universe-98PmJS-0 | [tigervnc] EncodeManager: Solid: 71 rects, 3.88653 Mpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 7.92578 KiB (1:1915.59 ratio) universe-98PmJS-0 | [tigervnc] EncodeManager: Bitmap RLE: 39 rects, 492.676 kpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 64.792 KiB (1:29.71 ratio) universe-98PmJS-0 | [tigervnc] EncodeManager: Indexed RLE: 28 rects, 544.576 kpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 155.534 KiB (1:13.6792 ratio) universe-98PmJS-0 | [tigervnc] EncodeManager: Full Colour: 70 rects, 1.40981 Mpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 4.03621 MiB (1:1.33263 ratio) universe-98PmJS-0 | [tigervnc] EncodeManager: Total: 208 rects, 6.33359 Mpixels universe-98PmJS-0 | [tigervnc] EncodeManager: 4.25911 MiB (1:5.67327 ratio) universe-98PmJS-0 | [init] [2017-03-02 06:22:34,105] init detected end of child process 51 with exit code 1, not killed by signal universe-98PmJS-0 | [init] [2017-03-02 06:22:34,105] main process died, init exiting with code 1

`

Versions

Please include the result of running

$ uname -a ; python --version; pip show universe gym tensorflow numpy go-vncdriver Pillow
Linux ip-172-31-50-118 4.4.0-64-generic #85-Ubuntu SMP Mon Feb 20 11:50:30 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux
Python 3.5.2
---
Metadata-Version: 1.0
Name: universe
Version: 0.21.2
Summary: Universe: a software platform for measuring and training an AI's general intelligence across the world's supply of games, websites and other applications.
Home-page: https://github.com/openai/universe
Author: OpenAI
Author-email: universe@openai.com
License: UNKNOWN
Location: /home/ubuntu/universe
Requires: autobahn, docker-py, docker-pycreds, fastzbarlight, go-vncdriver, gym, Pillow, PyYAML, six, twisted, ujson
Classifiers:
---
Metadata-Version: 2.0
Name: gym
Version: 0.7.3
Summary: The OpenAI Gym: A toolkit for developing and comparing your reinforcement learning agents.
Home-page: https://github.com/openai/gym
Author: OpenAI
Author-email: gym@openai.com
Installer: pip
License: UNKNOWN
Location: /home/ubuntu/.local/lib/python3.5/site-packages
Requires: pyglet, numpy, requests, six
Classifiers:
---
Metadata-Version: 2.0
Name: numpy
Version: 1.12.0
Summary: NumPy: array processing for numbers, strings, records, and objects.
Home-page: http://www.numpy.org
Author: NumPy Developers
Author-email: numpy-discussion@scipy.org
Installer: pip
License: BSD
Location: /home/ubuntu/.local/lib/python3.5/site-packages
Requires:
Classifiers:
  Development Status :: 5 - Production/Stable
  Intended Audience :: Science/Research
  Intended Audience :: Developers
  License :: OSI Approved
  Programming Language :: C
  Programming Language :: Python
  Programming Language :: Python :: 2
  Programming Language :: Python :: 2.7
  Programming Language :: Python :: 3
  Programming Language :: Python :: 3.4
  Programming Language :: Python :: 3.5
  Programming Language :: Python :: 3.6
  Programming Language :: Python :: Implementation :: CPython
  Topic :: Software Development
  Topic :: Scientific/Engineering
  Operating System :: Microsoft :: Windows
  Operating System :: POSIX
  Operating System :: Unix
  Operating System :: MacOS
---
Metadata-Version: 2.0
Name: go-vncdriver
Version: 0.4.19
Summary: UNKNOWN
Home-page: UNKNOWN
Author: UNKNOWN
Author-email: UNKNOWN
Installer: pip
License: UNKNOWN
Location: /home/ubuntu/.local/lib/python3.5/site-packages
Requires: numpy
Classifiers:
---
Metadata-Version: 2.0
Name: Pillow
Version: 4.0.0
Summary: Python Imaging Library (Fork)
Home-page: http://python-pillow.org
Author: Alex Clark (Fork Author)
Author-email: aclark@aclark.net
Installer: pip
License: Standard PIL License
Location: /home/ubuntu/.local/lib/python3.5/site-packages
Requires: olefile
Classifiers:
  Development Status :: 6 - Mature
  Topic :: Multimedia :: Graphics
  Topic :: Multimedia :: Graphics :: Capture :: Digital Camera
  Topic :: Multimedia :: Graphics :: Capture :: Screen Capture
  Topic :: Multimedia :: Graphics :: Graphics Conversion
  Topic :: Multimedia :: Graphics :: Viewers
  Programming Language :: Python :: 2
  Programming Language :: Python :: 2.7
  Programming Language :: Python :: 3
  Programming Language :: Python :: 3.3
  Programming Language :: Python :: 3.4
  Programming Language :: Python :: 3.5
  Programming Language :: Python :: 3.6
  Programming Language :: Python :: Implementation :: CPython
  Programming Language :: Python :: Implementation :: PyPy
You are using pip version 8.1.1, however version 9.0.1 is available.
You should consider upgrading via the 'pip install --upgrade pip' command.
tlbtlbtlb commented 7 years ago

I expected to able to go to http://{my-IP-address}/flashgames.DuskDrive-v0 and see the game running

That URL is only reachable from inside the container. You should go to http://{my-IP-address}:15900 to see the environment running.

j8lp commented 7 years ago

I see. Thanks. Also, can you tell why the environment is failing to start and the code eventually terminates? I opened up AWS machine to lo accept all incoming traffic, so I'm not sure why it might be timing out.

Thanks

tlbtlbtlb commented 7 years ago

I'm not sure. Can you try putting the example code in a file instead of typing it interactively? (eg, create j8lptest.py and run python j8lptest.py

j8lp commented 7 years ago

Hello,

Sorry for the delay. I just got back and tried running the starter code as it's own script. It got farther this time I think. I was able to see the AI at port 15900. The AI launched the game and pressed the first play button, but didn't make it past the second loading screen (after the Kongregate logo and before the main menu).

ubuntu@ip-172-31-50-118:~$ cd universe/
ubuntu@ip-172-31-50-118:~/universe$ python3 runDuskDrive.py
[2017-03-03 02:37:36,894] Making new env: flashgames.DuskDrive-v0
[2017-03-03 02:37:36,917] Writing logs to file: /tmp/universe-1596.log
[2017-03-03 02:37:36,965] Ports used: dict_keys([])
[2017-03-03 02:37:36,965] [0] Creating container: image=quay.io/openai/universe.flashgames:0.20.28. Run the same thing by hand as: docker run -p 5900:5900 -p 15900:15900 --ipc host --cap-add SYS_ADMIN --privileged quay.io/openai/universe.flashgames:0.20.28
[2017-03-03 02:37:37,367] Remote closed: address=localhost:5900
[2017-03-03 02:37:37,368] Remote closed: address=localhost:15900
[2017-03-03 02:37:37,368] At least one sockets was closed by the remote. Sleeping 1s...
universe-gQsXDO-0 | Setting VNC and rewarder password: openai
universe-gQsXDO-0 | [Fri Mar  3 02:37:37 UTC 2017] Waiting for /tmp/.X11-unix/X0 to be created (try 1/10)
universe-gQsXDO-0 | [Fri Mar  3 02:37:38 UTC 2017] [/usr/local/bin/sudoable-env-setup] Disabling outbound network traffic for none
universe-gQsXDO-0 | [tigervnc]
universe-gQsXDO-0 | [tigervnc] Xvnc TigerVNC 1.7.0 - built Sep  8 2016 10:39:22
universe-gQsXDO-0 | [tigervnc] Copyright (C) 1999-2016 TigerVNC Team and many others (see README.txt)
universe-gQsXDO-0 | [tigervnc] See http://www.tigervnc.org for information on TigerVNC.
universe-gQsXDO-0 | [tigervnc] Underlying X server release 11400000, The X.Org Foundation
universe-gQsXDO-0 | [tigervnc]
universe-gQsXDO-0 | [tigervnc] Initializing built-in extension VNC-EXTENSION
universe-gQsXDO-0 | [tigervnc] Initializing built-in extension Generic Event Extension
universe-gQsXDO-0 | [tigervnc] Initializing built-in extension SHAPE
universe-gQsXDO-0 | [tigervnc] Initializing built-in extension MIT-SHM
universe-gQsXDO-0 | [tigervnc] Initializing built-in extension XInputExtension
universe-gQsXDO-0 | [tigervnc] Initializing built-in extension XTEST
universe-gQsXDO-0 | [tigervnc] Initializing built-in extension BIG-REQUESTS
universe-gQsXDO-0 | [tigervnc] Initializing built-in extension SYNC
universe-gQsXDO-0 | [tigervnc] Initializing built-in extension XKEYBOARD
universe-gQsXDO-0 | [tigervnc] Initializing built-in extension XC-MISC
universe-gQsXDO-0 | [tigervnc] Initializing built-in extension XINERAMA
universe-gQsXDO-0 | [tigervnc] Initializing built-in extension XFIXES
universe-gQsXDO-0 | [tigervnc] Initializing built-in extension RENDER
universe-gQsXDO-0 | [tigervnc] Initializing built-in extension RANDR
universe-gQsXDO-0 | [tigervnc] Initializing built-in extension COMPOSITE
universe-gQsXDO-0 | [tigervnc] Initializing built-in extension DAMAGE
universe-gQsXDO-0 | [tigervnc] Initializing built-in extension MIT-SCREEN-SAVER
universe-gQsXDO-0 | [tigervnc] Initializing built-in extension DOUBLE-BUFFER
universe-gQsXDO-0 | [tigervnc] Initializing built-in extension RECORD
universe-gQsXDO-0 | [tigervnc] Initializing built-in extension DPMS
universe-gQsXDO-0 | [tigervnc] Initializing built-in extension X-Resource
universe-gQsXDO-0 | [tigervnc] Initializing built-in extension XVideo
universe-gQsXDO-0 | [tigervnc] Initializing built-in extension XVideo-MotionCompensation
universe-gQsXDO-0 | [tigervnc] Initializing built-in extension GLX
universe-gQsXDO-0 | [tigervnc]
universe-gQsXDO-0 | [tigervnc] Fri Mar  3 02:37:38 2017
universe-gQsXDO-0 | [tigervnc]  vncext:      VNC extension running!
universe-gQsXDO-0 | [tigervnc]  vncext:      Listening for VNC connections on all interface(s), port 5900
universe-gQsXDO-0 | [tigervnc]  vncext:      created VNC server for screen 0
universe-gQsXDO-0 | [init] [2017-03-03 02:37:38,123] Launching system_diagnostics_logger.py, recorder_logdir=/tmp/demo
universe-gQsXDO-0 | [init] [2017-03-03 02:37:38,127] Launching reward_recorder.py, recorder_logdir=/tmp/demo
universe-gQsXDO-0 | [init] [2017-03-03 02:37:38,132] Launching vnc_recorder.py, recorder_logdir=/tmp/demo
universe-gQsXDO-0 | [tigervnc] [dix] Could not init font path element /usr/share/fonts/X11/Type1/, removing from list!
universe-gQsXDO-0 | [tigervnc] [dix] Could not init font path element /usr/share/fonts/X11/75dpi/, removing from list!
universe-gQsXDO-0 | [tigervnc] [dix] Could not init font path element /usr/share/fonts/X11/100dpi/, removing from list!
universe-gQsXDO-0 | [init] [2017-03-03 02:37:38,162] PID 52 launched with command ['sudo', '-H', '-u', 'nobody', 'DISPLAY=:0', 'DBUS_SESSION_BUS_ADDRESS=/dev/null', '/app/universe-envs/controlplane/bin/controlplane.py', '--rewarder-port=15901']
universe-gQsXDO-0 | [init] [2017-03-03 02:37:38,331] init detected end of child process 55 with exit code 0, not killed by signal
[2017-03-03 02:37:38,369] Remote closed: address=localhost:15900
[2017-03-03 02:37:38,369] Remote closed: address=localhost:5900
[2017-03-03 02:37:38,370] At least one sockets was closed by the remote. Sleeping 1s...
universe-gQsXDO-0 | [nginx] 2017/03/03 02:37:38 [error] 61#61: *1 connect() failed (111: Connection refused) while connecting to upstream, client: 172.17.0.1, server: , request: "GET / HTTP/1.1", upstream: "http://127.0.0.1:15901/", host: "127.0.0.1:10003"
universe-gQsXDO-0 | [tigervnc]  Connections: accepted: 172.17.0.1::34448
universe-gQsXDO-0 | [nginx] 172.17.0.1 - openai [03/Mar/2017:02:37:38 +0000] "GET / HTTP/1.1" 502 182 "-" "-"
universe-gQsXDO-0 | WebSocket server settings:
universe-gQsXDO-0 |   - Listen on :5898
universe-gQsXDO-0 |   - Flash security policy server
universe-gQsXDO-0 |   - No SSL/TLS support (no cert file)
universe-gQsXDO-0 |   - proxying from :5898 to localhost:5900
universe-gQsXDO-0 | [init] [2017-03-03 02:37:38,996] init detected end of child process 15 with exit code 0, not killed by signal
[2017-03-03 02:37:39,371] Using the golang VNC implementation
[2017-03-03 02:37:39,371] Using VNCSession arguments: {'fine_quality_level': 50, 'subsample_level': 2, 'encoding': 'tight', 'start_timeout': 7}. (Customize by running "env.configure(vnc_kwargs={...})"
universe-gQsXDO-0 | [nginx] 2017/03/03 02:37:39 [info] 61#61: *1 client 172.17.0.1 closed keepalive connection
universe-gQsXDO-0 | [tigervnc]
universe-gQsXDO-0 | [tigervnc] Fri Mar  3 02:37:39 2017
universe-gQsXDO-0 | [tigervnc]  Connections: closed: 172.17.0.1::34448 (Clean disconnection)
universe-gQsXDO-0 | [tigervnc]  EncodeManager: Framebuffer updates: 0
universe-gQsXDO-0 | [tigervnc]  EncodeManager:   Total: 0 rects, 0 pixels
universe-gQsXDO-0 | [tigervnc]  EncodeManager:          0 B (1:-nan ratio)
[2017-03-03 02:37:39,378] [0] Connecting to environment: vnc://localhost:5900 password=openai. If desired, you can manually connect a VNC viewer, such as TurboVNC. Most environments provide a convenient in-browser VNC client: http://localhost:15900/viewer/?password=openai
2017/03/03 02:37:39 I0303 02:37:39.379452 1596 gymvnc.go:417] [0:localhost:5900] opening connection to VNC server
universe-gQsXDO-0 | [tigervnc]  Connections: accepted: 172.17.0.1::34454
universe-gQsXDO-0 | [tigervnc]  SConnection: Client needs protocol version 3.8
universe-gQsXDO-0 | [tigervnc]  SConnection: Client requests security type VncAuth(2)
universe-gQsXDO-0 | [tigervnc]  VNCSConnST:  Server default pixel format depth 24 (32bpp) little-endian rgb888
2017/03/03 02:37:39 I0303 02:37:39.389515 1596 gymvnc.go:550] [0:localhost:5900] connection established
universe-gQsXDO-0 | [tigervnc]  VNCSConnST:  Client pixel format depth 24 (32bpp) little-endian bgr888
universe-gQsXDO-0 | [nginx] 2017/03/03 02:37:39 [error] 61#61: *3 connect() failed (111: Connection refused) while connecting to upstream, client: 172.17.0.1, server: , request: "GET / HTTP/1.1", upstream: "http://127.0.0.1:15901/", host: "localhost:15900"
[2017-03-03 02:37:39,420] [0:localhost:5900] Waiting on rewarder: failed to complete WebSocket handshake. Retry in 1s (slept 0s/7s): connection was closed uncleanly (WebSocket connection upgrade failed (502 - BadGateway))
universe-gQsXDO-0 | [nginx] 172.17.0.1 - openai [03/Mar/2017:02:37:39 +0000] "GET / HTTP/1.1" 502 182 "-" "AutobahnPython/0.17.2"
universe-gQsXDO-0 | [nginx] 2017/03/03 02:37:39 [info] 61#61: *3 client 172.17.0.1 closed keepalive connection
universe-gQsXDO-0 | [reward_recorder] [2017-03-03 02:37:39,941] Listening on 0.0.0.0:15898
universe-gQsXDO-0 | [vnc_recorder] [2017-03-03 02:37:39,971] Listening on 0.0.0.0:5899
universe-gQsXDO-0 | [2017-03-03 02:37:40,229] [INFO:root] Starting play_controlplane.py with the following: command=['/app/universe-envs/controlplane/bin/controlplane.py', '--rewarder-port=15901'] args=Namespace(bot_demonstration=False, demonstration=False, env_id=None, idle_timeout=None, integrator_mode=False, no_env=False, no_rewarder=False, no_scorer=False, no_vexpect=False, remotes='vnc://127.0.0.1:5900', rewarder_fps=60, rewarder_port=15901, verbosity=0) env=environ({'LOGNAME': 'nobody', 'HOME': '/nonexistent', 'DBUS_SESSION_BUS_ADDRESS': '/dev/null', 'USERNAME': 'nobody', 'HOSTNAME': '2f6ccd43d6f4', 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin', 'SUDO_USER': 'root', 'SHELL': '/usr/sbin/nologin', 'TERM': 'xterm', 'SUDO_COMMAND': '/app/universe-envs/controlplane/bin/controlplane.py --rewarder-port=15901', 'DISPLAY': ':0', 'MAIL': '/var/mail/nobody', 'USER': 'nobody', 'SUDO_UID': '0', 'SUDO_GID': '0'})
universe-gQsXDO-0 | [2017-03-03 02:37:40,229] [INFO:root] [EnvStatus] Changing env_state: None (env_id=None) -> None (env_id=None) (episode_id: 0->0, fps=60)
universe-gQsXDO-0 | [2017-03-03 02:37:40,229] [INFO:universe.rewarder.remote] Starting Rewarder on port=15901
universe-gQsXDO-0 | [2017-03-03 02:37:40,233] [INFO:universe.extra.universe.wrappers.logger] Running VNC environments with Logger set to print_frequency=5. To change this, pass "print_frequency=k" or "print_frequency=None" to "env.configure".
universe-gQsXDO-0 | [2017-03-03 02:37:40,234] [INFO:universe.remotes.hardcoded_addresses] No rewarder addresses were provided, so this env cannot connect to the remote's rewarder channel, and cannot send control messages (e.g. reset)
universe-gQsXDO-0 | [2017-03-03 02:37:40,235] [INFO:universe.envs.vnc_env] Using the golang VNC implementation
universe-gQsXDO-0 | [2017-03-03 02:37:40,235] [INFO:universe.envs.vnc_env] Using VNCSession arguments: {'encoding': 'zrle', 'subsample_level': 2, 'start_timeout': 7, 'compress_level': 9, 'fine_quality_level': 50}. (Customize by running "env.configure(vnc_kwargs={...})"
universe-gQsXDO-0 | [2017-03-03 02:37:40,235] [INFO:universe.envs.vnc_env] Printed stats will ignore clock skew. (This usually makes sense only when the environment and agent are on the same machine.)
universe-gQsXDO-0 | [2017-03-03 02:37:40,241] [INFO:universe.envs.vnc_env] [0] Connecting to environment: vnc://127.0.0.1:5900 password=openai. If desired, you can manually connect a VNC viewer, such as TurboVNC. Most environments provide a convenient in-browser VNC client: http://None/viewer/?password=openai
universe-gQsXDO-0 | [2017-03-03 02:37:40,241] [INFO:universe.extra.universe.envs.vnc_env] [0] Connecting to environment details: vnc_address=127.0.0.1:5900 vnc_password=openai rewarder_address=None rewarder_password=openai
universe-gQsXDO-0 | 2017/03/03 02:37:40 I0303 02:37:40.241818 58 gymvnc.go:417] [0:127.0.0.1:5900] opening connection to VNC server
universe-gQsXDO-0 | [tigervnc]
universe-gQsXDO-0 | [tigervnc] Fri Mar  3 02:37:40 2017
universe-gQsXDO-0 | [tigervnc]  Connections: accepted: 127.0.0.1::39856
universe-gQsXDO-0 | [tigervnc]  SConnection: Client needs protocol version 3.8
universe-gQsXDO-0 | [tigervnc]  SConnection: Client requests security type VncAuth(2)
universe-gQsXDO-0 | [2017-03-03 02:37:40,241] [INFO:root] [EnvStatus] Changing env_state: None (env_id=None) -> resetting (env_id=None) (episode_id: 0->1, fps=60)
universe-gQsXDO-0 | [2017-03-03 02:37:40,244] [INFO:root] [MainThread] Env state: env_id=None episode_id=1
universe-gQsXDO-0 | [tigervnc]  VNCSConnST:  Server default pixel format depth 24 (32bpp) little-endian rgb888
universe-gQsXDO-0 | 2017/03/03 02:37:40 I0303 02:37:40.246058 58 gymvnc.go:550] [0:127.0.0.1:5900] connection established
universe-gQsXDO-0 | [2017-03-03 02:37:40,244] [INFO:root] [MainThread] Writing None to /tmp/demo/env_id.txt
universe-gQsXDO-0 | [tigervnc]  VNCSConnST:  Client pixel format depth 24 (32bpp) little-endian bgr888
universe-gQsXDO-0 | [Fri Mar  3 02:37:40 UTC 2017] [/usr/local/bin/sudoable-env-setup] Disabling outbound network traffic for none
universe-gQsXDO-0 | [2017-03-03 02:37:40,269] [INFO:gym_flashgames.launcher] [MainThread] Launching new Chrome process (attempt 0/10)
universe-gQsXDO-0 | [2017-03-03 02:37:40,269] [INFO:root] Replacing selenium_wrapper_server since we currently do it at every episode boundary
universe-gQsXDO-0 | [2017-03-03 02:37:40,427] [INFO:universe.rewarder.remote] Client connecting: peer=tcp4:127.0.0.1:52836 observer=False
universe-gQsXDO-0 | [2017-03-03 02:37:40,427] [INFO:universe.rewarder.remote] WebSocket connection established
universe-gQsXDO-0 | [2017-03-03 02:37:40,477] [selenium_wrapper_server] Calling webdriver.Chrome()
universe-gQsXDO-0 | [nginx] 2017/03/03 02:37:43 [info] 61#61: *7 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1"
universe-gQsXDO-0 | [nginx] 2017/03/03 02:37:43 [info] 61#61: *8 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1"
universe-gQsXDO-0 | [nginx] 2017/03/03 02:37:43 [info] 61#61: *9 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1"
universe-gQsXDO-0 | [nginx] 2017/03/03 02:37:43 [info] 61#61: *10 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1"
universe-gQsXDO-0 | [2017-03-03 02:37:43,462] [selenium_wrapper_server] Call to webdriver.Chrome() completed: 2.99s
universe-gQsXDO-0 | [2017-03-03 02:37:43,465] [INFO:gym_flashgames.launcher] [MainThread] Navigating browser to url=http://localhost
universe-gQsXDO-0 | [2017-03-03 02:37:43,604] [INFO:root] [EnvStatus] Changing env_state: resetting (env_id=None) -> running (env_id=None) (episode_id: 1->1, fps=60)
universe-gQsXDO-0 | [2017-03-03 02:37:43,626] [INFO:root] [MainThread] Writing None to /tmp/demo/env_id.txt
universe-gQsXDO-0 | Manhole[1488508663.6457]: Patched <built-in function fork> and <built-in function fork>.
universe-gQsXDO-0 | Manhole[1488508663.6461]: Manhole UDS path: /tmp/manhole-58
universe-gQsXDO-0 | Manhole[1488508663.6468]: Waiting for new connection (in pid:58) ...
universe-gQsXDO-0 | [2017-03-03 02:37:45,244] [INFO:universe.wrappers.logger] Stats for the past 5.00s: vnc_updates_ps=3.0 n=1 reaction_time=None observation_lag=None action_lag=None reward_ps=0.0 reward_total=0.0 vnc_bytes_ps[total]=510593.5 vnc_pixels_ps[total]=500624.1 reward_lag=None rewarder_message_lag=None fps=19.39
universe-gQsXDO-0 | [2017-03-03 02:37:48,644] [INFO:universe.pyprofile] [pyprofile] period=5.01s timers={"rewarder.compute_reward": {"calls": 301, "mean": "428.37us", "std": "1.97ms"}, "rewarder.sleep": {"calls": 298, "mean": "16.17ms", "std": "1.09ms"}, "rewarder.sleep.missed": {"calls": 2, "mean": "3.92ms", "std": "3.16ms"}, "vnc_env.VNCEnv.vnc_session.step": {"calls": 301, "mean": "314.69us", "std": "1.94ms"}, "rewarder.frame": {"calls": 300, "mean": "16.86ms", "std": "424.36us"}} counters={"reward.vnc.updates.n": {"std": 0.5423789932459657, "mean": 0.04983388704318941, "calls": 301}} gauges={} (export_time=124.69us)
universe-gQsXDO-0 | [2017-03-03 02:37:48,644] [INFO:universe.rewarder.remote] [Rewarder] Over past 5.01s, sent 1 reward messages to agent: reward=0 reward_min=0 reward_max=0 done=False info={'rewarder.vnc.updates.pixels': 0, 'rewarder.vnc.updates.bytes': 0, 'rewarder.vnc.updates.n': 0, 'rewarder.profile': '<873 bytes>'}
universe-gQsXDO-0 | [2017-03-03 02:37:50,261] [INFO:universe.wrappers.logger] Stats for the past 5.02s: vnc_updates_ps=0.0 n=1 reaction_time=None observation_lag=None action_lag=None reward_ps=0.0 reward_total=0.0 vnc_bytes_ps[total]=0.0 vnc_pixels_ps[total]=0.0 reward_lag=None rewarder_message_lag=None fps=60.01
universe-gQsXDO-0 | [nginx] {myDesktopIP} - - [03/Mar/2017:02:37:50 +0000] "GET /viewer/ HTTP/1.1" 200 3759 "-" "Mozilla/5.0 (Windows NT 10.0; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/56.0.2924.87 Safari/537.36"
universe-gQsXDO-0 | 127.0.0.1 - - [03/Mar/2017 02:37:50] 127.0.0.1: Plain non-SSL (ws://) WebSocket connection
universe-gQsXDO-0 | 127.0.0.1 - - [03/Mar/2017 02:37:50] 127.0.0.1: Version hybi-13, base64: 'False'
universe-gQsXDO-0 | 127.0.0.1 - - [03/Mar/2017 02:37:50] 127.0.0.1: Path: '/websockify'
universe-gQsXDO-0 | 127.0.0.1 - - [03/Mar/2017 02:37:50] connecting to: localhost:5900
universe-gQsXDO-0 | [tigervnc]
universe-gQsXDO-0 | [tigervnc] Fri Mar  3 02:37:50 2017
universe-gQsXDO-0 | [tigervnc]  Connections: accepted: 127.0.0.1::40040
universe-gQsXDO-0 | [tigervnc]  SConnection: Client needs protocol version 3.8
universe-gQsXDO-0 | [tigervnc]  SConnection: Client requests security type VncAuth(2)
universe-gQsXDO-0 | [tigervnc]  VNCSConnST:  Server default pixel format depth 24 (32bpp) little-endian rgb888
universe-gQsXDO-0 | [tigervnc]
universe-gQsXDO-0 | [tigervnc] Fri Mar  3 02:37:51 2017
universe-gQsXDO-0 | [tigervnc]  VNCSConnST:  Client pixel format depth 24 (32bpp) little-endian rgb888
universe-gQsXDO-0 | [2017-03-03 02:37:53,660] [INFO:universe.pyprofile] [pyprofile] period=5.02s timers={"rewarder.compute_reward": {"calls": 301, "mean": "149.32us", "std": "74.76us"}, "rewarder.sleep": {"calls": 301, "mean": "16.31ms", "std": "158.36us"}, "vnc_env.VNCEnv.vnc_session.step": {"calls": 301, "mean": "52.20us", "std": "24.37us"}, "rewarder.frame": {"calls": 301, "mean": "16.83ms", "std": "110.94us"}} counters={"agent_conn.reward": {"std": 0, "mean": 0.0, "calls": 1}, "reward.vnc.updates.n": {"std": 0.7770660668204248, "mean": 0.4817275747508304, "calls": 301}} gauges={} (export_time=89.41us)
universe-gQsXDO-0 | [2017-03-03 02:37:53,661] [INFO:universe.rewarder.remote] [Rewarder] Over past 5.02s, sent 1 reward messages to agent: reward=0 reward_min=0 reward_max=0 done=False info={'rewarder.vnc.updates.pixels': 0, 'rewarder.vnc.updates.bytes': 0, 'rewarder.vnc.updates.n': 0, 'rewarder.profile': '<850 bytes>'}
universe-gQsXDO-0 | [2017-03-03 02:37:55,277] [INFO:universe.wrappers.logger] Stats for the past 5.02s: vnc_updates_ps=29.7 n=1 reaction_time=None observation_lag=None action_lag=None reward_ps=0.0 reward_total=0.0 vnc_bytes_ps[total]=108516.7 vnc_pixels_ps[total]=37558.7 reward_lag=None rewarder_message_lag=None fps=60.01
universe-gQsXDO-0 | [2017-03-03 02:37:58,677] [INFO:universe.pyprofile] [pyprofile] period=5.02s timers={"rewarder.compute_reward": {"calls": 301, "mean": "156.27us", "std": "71.05us"}, "rewarder.sleep": {"calls": 301, "mean": "16.31ms", "std": "152.33us"}, "vnc_env.VNCEnv.vnc_session.step": {"calls": 301, "mean": "58.33us", "std": "21.09us"}, "rewarder.frame": {"calls": 301, "mean": "16.82ms", "std": "96.36us"}} counters={"agent_conn.reward": {"std": 0, "mean": 0.0, "calls": 1}, "reward.vnc.updates.n": {"std": 0.1147002448968702, "mean": 0.013289036544850492, "calls": 301}} gauges={} (export_time=106.10us)
universe-gQsXDO-0 | [2017-03-03 02:37:58,677] [INFO:universe.rewarder.remote] [Rewarder] Over past 5.02s, sent 1 reward messages to agent: reward=0 reward_min=0 reward_max=0 done=False info={'rewarder.vnc.updates.pixels': 0, 'rewarder.vnc.updates.bytes': 0, 'rewarder.vnc.updates.n': 0, 'rewarder.profile': '<853 bytes>'}
universe-gQsXDO-0 | [2017-03-03 02:38:00,294] [INFO:universe.wrappers.logger] Stats for the past 5.02s: vnc_updates_ps=0.0 n=1 reaction_time=None observation_lag=None action_lag=None reward_ps=0.0 reward_total=0.0 vnc_bytes_ps[total]=0.0 vnc_pixels_ps[total]=0.0 reward_lag=None rewarder_message_lag=None fps=60.01
[2017-03-03 02:38:00,433] [0:localhost:5900] ntpdate -q -p 8 localhost call timed out after 20.0s; killing the subprocess. This is ok, but you could have more accurate timings by enabling UDP port 123 traffic to your env. (Alternatively, you can try increasing the timeout by setting environment variable UNIVERSE_NTPDATE_TIMEOUT=10.)
universe-gQsXDO-0 | [nginx] 2017/03/03 02:38:00 [info] 61#61: *22 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900
universe-gQsXDO-0 | [nginx] 2017/03/03 02:38:00 [info] 61#61: *23 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900
universe-gQsXDO-0 | [nginx] 2017/03/03 02:38:00 [info] 61#61: *24 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900
universe-gQsXDO-0 | [nginx] 2017/03/03 02:38:00 [info] 61#61: *25 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900
universe-gQsXDO-0 | [nginx] 2017/03/03 02:38:00 [info] 61#61: *26 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900
universe-gQsXDO-0 | [nginx] 2017/03/03 02:38:00 [info] 61#61: *27 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900
universe-gQsXDO-0 | [nginx] 2017/03/03 02:38:00 [info] 61#61: *28 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900
universe-gQsXDO-0 | [nginx] 2017/03/03 02:38:00 [info] 61#61: *29 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900
universe-gQsXDO-0 | [nginx] 2017/03/03 02:38:00 [info] 61#61: *30 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900
universe-gQsXDO-0 | [2017-03-03 02:38:00,450] [INFO:universe.rewarder.remote] CONNECTION STATUS: Marking connection as active: observer=False peer=tcp4:127.0.0.1:52836 total_conns=1
universe-gQsXDO-0 | [nginx] 2017/03/03 02:38:00 [info] 61#61: *31 client closed connection while waiting for request, client: 172.17.0.1, server: 0.0.0.0:15900
[2017-03-03 02:38:00,462] [0:localhost:5900] Sending reset for env_id=flashgames.DuskDrive-v0 fps=60 episode_id=0
universe-gQsXDO-0 | [2017-03-03 02:38:00,463] [INFO:universe.rewarder.remote] Received reset message: {'headers': {'episode_id': '0', 'message_id': 10, 'sent_at': 1488508680.4629247}, 'body': {'seed': None, 'fps': 60, 'env_id': 'flashgames.DuskDrive-v0'}, 'method': 'v0.env.reset'}
universe-gQsXDO-0 | [2017-03-03 02:38:00,475] [INFO:root] [EnvStatus] Changing env_state: running (env_id=None) -> resetting (env_id=flashgames.DuskDrive-v0) (episode_id: 1->2, fps=60)
universe-gQsXDO-0 | [2017-03-03 02:38:00,476] [ERROR:root] Closing server (via subprocess.close()) and all chromes (via pkill chromedriver || :; pkill chrome || :)
universe-gQsXDO-0 | [2017-03-03 02:38:00,477] [INFO:root] [Rewarder] Blocking until env finishes resetting
universe-gQsXDO-0 | [init] [2017-03-03 02:38:00,487] init detected end of child process 103 with exit code 0, killed by SIGTERM: 15
universe-gQsXDO-0 | [init] [2017-03-03 02:38:00,505] init detected end of child process 118 with exit code 0, not killed by signal
universe-gQsXDO-0 | [2017-03-03 02:38:00,509] [INFO:root] [EnvController] RESET CAUSE: changing out environments due to v0.env.reset (with episode_id=0): flashgames.DuskDrive-v0 -> flashgames.DuskDrive-v0 (new episode_id=2 fps=60)
universe-gQsXDO-0 | [2017-03-03 02:38:00,509] [INFO:root] [EnvController] Env state: env_id=flashgames.DuskDrive-v0 episode_id=2
universe-gQsXDO-0 | [2017-03-03 02:38:00,510] [INFO:root] [EnvController] Writing flashgames.DuskDrive-v0 to /tmp/demo/env_id.txt
universe-gQsXDO-0 | [nginx] 2017/03/03 02:38:00 [info] 61#61: *12 client closed connection while waiting for request, client: 127.0.0.1, server: 0.0.0.0:80
universe-gQsXDO-0 | [nginx] 2017/03/03 02:38:00 [info] 61#61: *11 client 127.0.0.1 closed keepalive connection
universe-gQsXDO-0 | [Fri Mar  3 02:38:00 UTC 2017] [/usr/local/bin/sudoable-env-setup] Allowing outbound network traffic to non-private IPs for git-lfs. (Going to fetch files via git lfs.)
universe-gQsXDO-0 | [init] [2017-03-03 02:38:00,584] init detected end of child process 114 with exit code 0, not killed by signal
universe-gQsXDO-0 | [init] [2017-03-03 02:38:00,584] init detected end of child process 115 with exit code 0, not killed by signal
universe-gQsXDO-0 | [init] [2017-03-03 02:38:00,584] init detected end of child process 117 with exit code 0, killed by SIGTERM: 15
universe-gQsXDO-0 | [init] [2017-03-03 02:38:00,584] init detected end of child process 106 with exit code 0, not killed by signal
universe-gQsXDO-0 | [unpack-lfs] [2017-03-03 02:38:00,679] Unpacking files for flashgames.DuskDrive-v0
universe-gQsXDO-0 | [unpack-lfs] [2017-03-03 02:38:00,823] Merged 5 files from /tmp/flashgames.DuskDrive-v0/public -> /app/universe-envs/flashgames/build/public/flashgames.DuskDrive-v0
universe-gQsXDO-0 | [unpack-lfs] [2017-03-03 02:38:00,828] Merged 20 files from /tmp/flashgames.DuskDrive-v0/private -> /app/universe-envs/flashgames/build/private/flashgames.DuskDrive-v0
universe-gQsXDO-0 | [unpack-lfs] [2017-03-03 02:38:00,829] Completed unpack for flashgames.DuskDrive-v0 in 0.156s
universe-gQsXDO-0 | [Fri Mar  3 02:38:00 UTC 2017] [/usr/local/bin/sudoable-env-setup] [debug] unpack-lfs completed with status code: 0. Created completion file: /usr/local/openai/git-lfs/flashgames.DuskDrive-v0
universe-gQsXDO-0 | [Fri Mar  3 02:38:00 UTC 2017] [/usr/local/bin/sudoable-env-setup] Disabling outbound network traffic for flashgames.DuskDrive-v0
universe-gQsXDO-0 | [2017-03-03 02:38:00,909] [INFO:gym_flashgames.launcher] [EnvController] Launching new Chrome process (attempt 0/10)
universe-gQsXDO-0 | [2017-03-03 02:38:00,909] [INFO:root] Replacing selenium_wrapper_server since we currently do it at every episode boundary
universe-gQsXDO-0 | [2017-03-03 02:38:01,030] [selenium_wrapper_server] Calling webdriver.Chrome()
universe-gQsXDO-0 | [nginx] 2017/03/03 02:38:01 [info] 61#61: *15 client closed connection while waiting for request, client: {myDesktopIP}, server: 0.0.0.0:15900
universe-gQsXDO-0 | [nginx] 2017/03/03 02:38:01 [info] 61#61: *17 client closed connection while waiting for request, client: {myDesktopIP}, server: 0.0.0.0:15900
universe-gQsXDO-0 | [nginx] 2017/03/03 02:38:01 [info] 61#61: *16 client closed connection while waiting for request, client: {myDesktopIP}, server: 0.0.0.0:15900
universe-gQsXDO-0 | [nginx] 2017/03/03 02:38:01 [info] 61#61: *18 client closed connection while waiting for request, client: {myDesktopIP}, server: 0.0.0.0:15900
universe-gQsXDO-0 | [nginx] 2017/03/03 02:38:01 [info] 61#61: *19 client closed connection while waiting for request, client: {myDesktopIP}, server: 0.0.0.0:15900
universe-gQsXDO-0 | [nginx] 2017/03/03 02:38:02 [info] 61#61: *32 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1"
universe-gQsXDO-0 | [nginx] 2017/03/03 02:38:02 [info] 61#61: *33 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1"
universe-gQsXDO-0 | [nginx] 2017/03/03 02:38:02 [info] 61#61: *34 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1"
universe-gQsXDO-0 | [nginx] 2017/03/03 02:38:02 [info] 61#61: *35 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google.com:443 HTTP/1.1"
universe-gQsXDO-0 | [2017-03-03 02:38:02,619] [selenium_wrapper_server] Call to webdriver.Chrome() completed: 1.59s
universe-gQsXDO-0 | [2017-03-03 02:38:02,620] [INFO:gym_flashgames.launcher] [EnvController] Navigating browser to url=http://localhost/flashgames.DuskDrive-v0
universe-gQsXDO-0 | [2017-03-03 02:38:02,686] [INFO:root] [EnvController] Running command: /app/universe-envs/controlplane/bin/play_vexpect -e flashgames.DuskDrive-v0 -r vnc://127.0.0.1:5900 -d
universe-gQsXDO-0 | [nginx] 2017/03/03 02:38:03 [info] 61#61: *39 client sent invalid request while reading client request line, client: 127.0.0.1, server: , request: "CONNECT www.google-analytics.com:443 HTTP/1.1"
universe-gQsXDO-0 | [2017-03-03 02:38:04,243] [play_vexpect] No rewarder addresses were provided, so this env cannot connect to the remote's rewarder channel, and cannot send control messages (e.g. reset)
universe-gQsXDO-0 | [2017-03-03 02:38:04,243] [play_vexpect] Using the golang VNC implementation
universe-gQsXDO-0 | [2017-03-03 02:38:04,244] [play_vexpect] Using VNCSession arguments: {'compress_level': 0, 'start_timeout': 7, 'fine_quality_level': 50, 'subsample_level': 2, 'encoding': 'zrle'}. (Customize by running "env.configure(vnc_kwargs={...})"
universe-gQsXDO-0 | [2017-03-03 02:38:04,246] [play_vexpect] Printed stats will ignore clock skew. (This usually makes sense only when the environment and agent are on the same machine.)
universe-gQsXDO-0 | [2017-03-03 02:38:04,254] [play_vexpect] [0] Connecting to environment: vnc://127.0.0.1:5900 password=openai. If desired, you can manually connect a VNC viewer, such as TurboVNC. Most environments provide a convenient in-browser VNC client: http://None/viewer/?password=openai
universe-gQsXDO-0 | [2017-03-03 02:38:04,254] [play_vexpect] [0] Connecting to environment details: vnc_address=127.0.0.1:5900 vnc_password=openai rewarder_address=None rewarder_password=openai
universe-gQsXDO-0 | 2017/03/03 02:38:04 I0303 02:38:04.256306 646 gymvnc.go:417] [0:127.0.0.1:5900] opening connection to VNC server
universe-gQsXDO-0 | [tigervnc]
universe-gQsXDO-0 | [tigervnc] Fri Mar  3 02:38:04 2017
universe-gQsXDO-0 | [tigervnc]  Connections: accepted: 127.0.0.1::40184
universe-gQsXDO-0 | [tigervnc]  SConnection: Client needs protocol version 3.8
universe-gQsXDO-0 | [tigervnc]  SConnection: Client requests security type VncAuth(2)
universe-gQsXDO-0 | [tigervnc]  VNCSConnST:  Server default pixel format depth 24 (32bpp) little-endian rgb888
universe-gQsXDO-0 | 2017/03/03 02:38:04 I0303 02:38:04.260226 646 gymvnc.go:550] [0:127.0.0.1:5900] connection established
universe-gQsXDO-0 | [tigervnc]  VNCSConnST:  Client pixel format depth 24 (32bpp) little-endian bgr888
universe-gQsXDO-0 | [2017-03-03 02:38:05,211] [play_vexpect] Waiting for any of [MaskState<initializing0>] to activate
universe-gQsXDO-0 | 2017/03/03 02:38:09 I0303 02:38:09.002052 58 gymvnc.go:374] [0:127.0.0.1:5900] update queue max of 60 reached; pausing further updates
universe-gQsXDO-0 | [2017-03-03 02:38:12,327] [play_vexpect] Applying transition: ClickTransition<initializing0->['initializing1'] x=429 y=539 buttonmask=1> for active state MaskState<initializing0>. (Summary: plausible_states=MaskState<initializing0> distance_m=0.0489 match_time_m=212us)
universe-gQsXDO-0 | [2017-03-03 02:38:12,343] [play_vexpect] Waiting for any of [MaskState<initializing1>] to activate (or whether any of [MaskState<initializing0>] are still active)
universe-gQsXDO-0 | [2017-03-03 02:38:16,384] [play_vexpect] Advancing to the next hopeful state (2/2): MaskState<initializing0>
[2017-03-03 02:38:22,733] Throttle fell behind by 4.36s; lost 261.47 frames
universe-gQsXDO-0 | [2017-03-03 02:38:19,593] [play_vexpect] Advancing to the next hopeful state (1/2): MaskState<initializing1>
universe-gQsXDO-0 | [2017-03-03 02:38:21,640] [play_vexpect] Fell behind by 3.249847650527954s from target; losing 194 frames
[2017-03-03 02:38:34,348] env.step took a long time: 8.00s
universe-gQsXDO-0 | [2017-03-03 02:38:23,925] [play_vexpect] Fell behind by 1.4121217727661133s from target; losing 84 frames
[2017-03-03 02:38:34,815] Throttle fell behind by 8.80s; lost 528.00 frames
[2017-03-03 02:38:37,299] Throttle fell behind by 1.05s; lost 63.08 frames
universe-gQsXDO-0 | [2017-03-03 02:38:25,306] [play_vexpect] Fell behind by 0.310593843460083s from target; losing 18 frames
[2017-03-03 02:38:46,869] env.step took a long time: 4.44s
[2017-03-03 02:38:52,229] Throttle fell behind by 10.23s; lost 613.87 frames
universe-gQsXDO-0 | [2017-03-03 02:38:27,185] [play_vexpect] Fell behind by 0.8206968307495117s from target; losing 49 frames
[2017-03-03 02:38:57,705] env.step took a long time: 3.18s
universe-gQsXDO-0 | [2017-03-03 02:38:28,759] [play_vexpect] Fell behind by 0.587425708770752s from target; losing 35 frames
[2017-03-03 02:39:06,965] Throttle fell behind by 12.51s; lost 750.73 frames
[2017-03-03 02:39:13,539] [0] Closing rewarder connection
universe-gQsXDO-0 | [2017-03-03 02:38:30,326] [play_vexpect] Fell behind by 0.543900728225708s from target; losing 32 frames
universe-gQsXDO-0 | [2017-03-03 02:38:31,626] [play_vexpect] Advancing to the next hopeful state (2/2): MaskState<initializing0>
universe-gQsXDO-0 | [2017-03-03 02:38:33,188] [play_vexpect] Fell behind by 1.9984524250030518s from target; losing 119 frames
universe-gQsXDO-0 | [2017-03-03 02:38:34,419] [play_vexpect] Fell behind by 0.4174227714538574s from target; losing 25 frames
universe-gQsXDO-0 | [2017-03-03 02:38:35,393] [play_vexpect] Fell behind by 0.4256148338317871s from target; losing 25 frames
universe-gQsXDO-0 | [2017-03-03 02:38:36,036] [play_vexpect] Fell behind by 0.2503645420074463s from target; losing 15 frames
universe-gQsXDO-0 | [2017-03-03 02:38:37,298] [play_vexpect] Fell behind by 0.642174243927002s from target; losing 38 frames
universe-gQsXDO-0 | [2017-03-03 02:38:39,907] [play_vexpect] Fell behind by 1.2979941368103027s from target; losing 77 frames
universe-gQsXDO-0 | [2017-03-03 02:38:42,205] [play_vexpect] Fell behind by 1.1340808868408203s from target; losing 68 frames
universe-gQsXDO-0 | [2017-03-03 02:38:44,104] [play_vexpect] Advancing to the next hopeful state (1/2): MaskState<initializing1>
universe-gQsXDO-0 | [2017-03-03 02:38:45,741] [play_vexpect] Fell behind by 2.5220162868499756s from target; losing 151 frames
universe-gQsXDO-0 | [2017-03-03 02:38:47,796] [play_vexpect] Fell behind by 1.171518087387085s from target; losing 70 frames
universe-gQsXDO-0 | [2017-03-03 02:38:50,471] [play_vexpect] Fell behind by 1.6444649696350098s from target; losing 98 frames
universe-gQsXDO-0 | [2017-03-03 02:38:51,747] [play_vexpect] Fell behind by 0.7890357971191406s from target; losing 47 frames
universe-gQsXDO-0 | [2017-03-03 02:38:52,339] [play_vexpect] Fell behind by 0.36475372314453125s from target; losing 21 frames
universe-gQsXDO-0 | [2017-03-03 02:38:53,337] [play_vexpect] Fell behind by 0.2942931652069092s from target; losing 17 frames
universe-gQsXDO-0 | [2017-03-03 02:38:54,027] [play_vexpect] Fell behind by 0.33390259742736816s from target; losing 20 frames
universe-gQsXDO-0 | [2017-03-03 02:38:55,654] [play_vexpect] Fell behind by 1.2552344799041748s from target; losing 75 frames
universe-gQsXDO-0 | [2017-03-03 02:38:56,698] [play_vexpect] Advancing to the next hopeful state (2/2): MaskState<initializing0>
universe-gQsXDO-0 | [2017-03-03 02:38:57,259] [play_vexpect] Fell behind by 0.9729859828948975s from target; losing 58 frames
universe-gQsXDO-0 | [nginx] 2017/03/03 02:39:00 [info] 61#61: *5 upstream timed out (110: Connection timed out) while proxying upgraded connection, client: 172.17.0.1, server: , request: "GET / HTTP/1.1", upstream: "http://127.0.0.1:15901/", host: "localhost:15900"
universe-gQsXDO-0 | [nginx] 172.17.0.1 - openai [03/Mar/2017:02:39:00 +0000] "GET / HTTP/1.1" 101 4593 "-" "AutobahnPython/0.17.2"
universe-gQsXDO-0 | [2017-03-03 02:38:58,551] [play_vexpect] Fell behind by 1.0632195472717285s from target; losing 63 frames
universe-gQsXDO-0 | [2017-03-03 02:38:59,884] [play_vexpect] Fell behind by 0.7042245864868164s from target; losing 42 frames
universe-gQsXDO-0 | [2017-03-03 02:39:01,570] [INFO:universe.rewarder.remote] WebSocket connection closed: connection was closed uncleanly (peer dropped the TCP connection without previous WebSocket closing handshake)
universe-gQsXDO-0 | [2017-03-03 02:39:01,570] [play_vexpect] Fell behind by 1.1364576816558838s from target; losing 68 frames
universe-gQsXDO-0 | [2017-03-03 02:39:02,225] [INFO:universe.rewarder.remote] [Twisted] Active client disconnected (sent 11 messages). Still have 0 active clients left
universe-gQsXDO-0 | [2017-03-03 02:39:03,970] [play_vexpect] Fell behind by 1.7842795848846436s from target; losing 107 frames
universe-gQsXDO-0 | [2017-03-03 02:39:05,667] [play_vexpect] Fell behind by 1.2556054592132568s from target; losing 75 frames
universe-gQsXDO-0 | [2017-03-03 02:39:06,616] [play_vexpect] Advancing to the next hopeful state (1/2): MaskState<initializing1>
universe-gQsXDO-0 | [2017-03-03 02:39:08,154] [play_vexpect] Fell behind by 1.9478459358215332s from target; losing 116 frames
universe-gQsXDO-0 | [2017-03-03 02:39:09,308] [play_vexpect] Fell behind by 0.5848073959350586s from target; losing 35 frames
universe-gQsXDO-0 | [2017-03-03 02:39:11,156] [play_vexpect] Fell behind by 1.5454647541046143s from target; losing 92 frames
universe-gQsXDO-0 | [2017-03-03 02:39:12,018] [play_vexpect] Fell behind by 0.4630317687988281s from target; losing 27 frames
universe-gQsXDO-0 | [2017-03-03 02:39:12,668] [play_vexpect] Handled error.VExpectTimeout: Error: vexpect has been looking for the same states for 60s: [MaskState<initializing1>] (old plausible states: [MaskState<initializing0>]) (runtime: 68.318196s)
universe-gQsXDO-0 | [tigervnc]
universe-gQsXDO-0 | [tigervnc] Fri Mar  3 02:39:13 2017
universe-gQsXDO-0 | [tigervnc]  Connections: closed: 172.17.0.1::34454 (Clean disconnection)
universe-gQsXDO-0 | [tigervnc]  EncodeManager: Framebuffer updates: 384
universe-gQsXDO-0 | [tigervnc]  EncodeManager:   Tight:
universe-gQsXDO-0 | [tigervnc]  EncodeManager:     Solid: 120 rects, 3.97165 Mpixels
universe-gQsXDO-0 | [tigervnc]  EncodeManager:            1.875 KiB (1:8275.02 ratio)
universe-gQsXDO-0 | [tigervnc]  EncodeManager:     Bitmap RLE: 91 rects, 953.276 kpixels
universe-gQsXDO-0 | [tigervnc]  EncodeManager:                 13.7529 KiB (1:270.837 ratio)
universe-gQsXDO-0 | [tigervnc]  EncodeManager:     Indexed RLE: 412 rects, 861.802 kpixels
universe-gQsXDO-0 | [tigervnc]  EncodeManager:                  91.9365 KiB (1:36.6692 ratio)
universe-gQsXDO-0 | [tigervnc]  EncodeManager:   Tight (JPEG):
universe-gQsXDO-0 | [tigervnc]  EncodeManager:     Full Colour: 140 rects, 3.94058 Mpixels
universe-gQsXDO-0 | [tigervnc]  EncodeManager:                  498.318 KiB (1:30.893 ratio)
universe-gQsXDO-0 | [tigervnc]  EncodeManager:   Total: 763 rects, 9.72731 Mpixels
universe-gQsXDO-0 | [tigervnc]  EncodeManager:          605.883 KiB (1:62.7287 ratio)
universe-gQsXDO-0 | [tigervnc]  Connections: closed: 127.0.0.1::40184 (Clean disconnection)
universe-gQsXDO-0 | [tigervnc]  EncodeManager: Framebuffer updates: 189
universe-gQsXDO-0 | [tigervnc]  EncodeManager:   ZRLE:
universe-gQsXDO-0 | [tigervnc]  EncodeManager:     Solid: 14 rects, 427.168 kpixels
universe-gQsXDO-0 | [tigervnc]  EncodeManager:            1 KiB (1:1668.79 ratio)
universe-gQsXDO-0 | [tigervnc]  EncodeManager:     Bitmap RLE: 75 rects, 759.708 kpixels
universe-gQsXDO-0 | [tigervnc]  EncodeManager:                 101.181 KiB (1:29.3385 ratio)
universe-gQsXDO-0 | [tigervnc]  EncodeManager:     Indexed RLE: 136 rects, 372.745 kpixels
universe-gQsXDO-0 | [tigervnc]  EncodeManager:                  103.978 KiB (1:14.0187 ratio)
universe-gQsXDO-0 | [tigervnc]  EncodeManager:     Full Colour: 103 rects, 2.91158 Mpixels
universe-gQsXDO-0 | [tigervnc]  EncodeManager:                  8.3345 MiB (1:1.33277 ratio)
universe-gQsXDO-0 | [tigervnc]  EncodeManager:   Total: 328 rects, 4.4712 Mpixels
universe-gQsXDO-0 | [tigervnc]  EncodeManager:          8.53582 MiB (1:1.99864 ratio)
universe-gQsXDO-0 | [2017-03-03 02:39:14,742] [INFO:root] [EnvController] RESET CAUSE: VExpect failed with returncode 10, which means it timed out internally. Going to trigger a reset.
universe-gQsXDO-0 | [2017-03-03 02:39:14,840] [INFO:root] [EnvController] Triggering a reset on EnvController
universe-gQsXDO-0 | [2017-03-03 02:39:14,840] [INFO:root] [EnvStatus] Changing env_state: resetting (env_id=flashgames.DuskDrive-v0) -> resetting (env_id=flashgames.DuskDrive-v0) (episode_id: 2->3, fps=60)
Traceback (most recent call last):
  File "runDuskDrive.py", line 10, in <module>
    observation_n, reward_n, done_n, info = env.step(action_n)
  File "/home/ubuntu/.local/lib/python3.5/site-packages/gym/core.py", line 110, in step
    observation, reward, done, info = self._step(action)
  File "/home/ubuntu/universe/universe/wrappers/timer.py", line 20, in _step
    observation_n, reward_n, done_n, info = self.env.step(action_n)
  File "/home/ubuntu/.local/lib/python3.5/site-packages/gym/core.py", line 110, in step
    observation, reward, done, info = self._step(action)
  File "/home/ubuntu/universe/universe/wrappers/render.py", line 30, in _step
    observation_n, reward_n, done_n, info_n = self.env.step(action_n)
  File "/home/ubuntu/.local/lib/python3.5/site-packages/gym/core.py", line 110, in step
    observation, reward, done, info = self._step(action)
  File "/home/ubuntu/universe/universe/wrappers/throttle.py", line 51, in _step
    accum_observation_n, accum_reward_n, accum_done_n, accum_info = self._substep(action_n)
  File "/home/ubuntu/universe/universe/wrappers/throttle.py", line 132, in _substep
    observation_n, reward_n, done_n, info = self.env.step(action_n)
  File "/home/ubuntu/.local/lib/python3.5/site-packages/gym/core.py", line 110, in step
    observation, reward, done, info = self._step(action)
  File "/home/ubuntu/universe/universe/envs/vnc_env.py", line 464, in _step
    self._handle_crashed_n(info_n)
  File "/home/ubuntu/universe/universe/envs/vnc_env.py", line 537, in _handle_crashed_n
    raise error.Error('{}/{} environments have crashed! Most recent error: {}'.format(len(self.crashed), self.n, errors))
universe.error.Error: 1/1 environments have crashed! Most recent error: {'0': 'Rewarder session failed: Lost connection: connection was closed uncleanly (peer dropped the TCP connection without previous WebSocket closing handshake) (clean=False code=1006)'}
[2017-03-03 02:39:15,127] Killing and removing container: id=2f6ccd43d6f4483fdd26d84faeb09e6c3da67c1885326a532560e8f971052b25
ubuntu@ip-172-31-50-118:~/universe$

Thanks for your help

tlbtlbtlb commented 7 years ago

It must be a slow machine, or busy with other load. Running these environments in real time requires at least 2 fast cores each.

universe-gQsXDO-0 | [2017-03-03 02:38:21,640] [play_vexpect] Fell behind by 3.249847650527954s from target; losing 194 frames
j8lp commented 7 years ago

Hello,

That was the problem. I guess I should've known that a free tier t2.micro AWS machine wasn't going to be powerful enough. I launced an AWS t2.medium instance and was able to run the starter agent without any problems.

I think this issue can be closed. I'm going to edit the title to make it more clear what the problem was.

Thank you for your help