search

elgalu / docker-selenium

[NOT MAINTAINED] Please use <https://github.com/SeleniumHQ/docker-selenium>
https://github.com/SeleniumHQ/docker-selenium
Other
1.42k stars 335 forks source link

Remove need for sudo when running in Kubernetes/OpenShift #175

Closed mojsha closed 6 years ago

mojsha commented 6 years ago

Please make sure that the boxes below are checked before you submit your issue. Thank you!

Operating System

OpenShift 3.6

Image version

Docker version

I am a user of Zalenium and it uses docker-selenium to dynamically spin up pods. However, we want to be able to run our Zalenium instance without providing it with root / privileged access. There is a fix that @diemol has provided removing the need for sudo commands if you run in Kubernetes. The outstanding part now is to have the Docker-selenium image that is used to setup a Zalenium pod not use sudo.

elgalu commented 6 years ago

Travis has pushed the fix, can you docker pull and try again? https://github.com/elgalu/docker-selenium/releases/tag/3.5.3-p2

mojsha commented 6 years ago

I cannot get it to work properly:

--LOG 11:21:20:353856476 Kubernetes service account found.

  | sudo: unknown uid 1000140000: who are you?   | sudo: unknown uid 1000140000: who are you?   | rm: cannot remove '/var/lib/dbus/machine-id': Permission denied   | sudo: unknown uid 1000140000: who are you?   | mkdir: cannot create directory ‘/var/run/dbus’: Permission denied   | /usr/bin/entry.sh: line 38: dbus_service.log: Permission denied   | /usr/bin/entry.sh: line 38: dbus_service.log: Permission denied   | /usr/bin/entry.sh: line 40: dbus_service_status.log: Permission denied   | Could not get password database information for UID of current process: User "???" unknown or no memory to allocate password entry   |     | Failed to start message bus: Memory allocation failure in message bus

declare -x no_proxy="localhost"

  | -- INFO: Docker Img. Version: 3.5.3-p2   | -- INFO: Chrome..... Version: 61.0.3163.91   | -- INFO: Firefox.... Version: 55.0.3   | -- INFO: Using Selenium.....: 3.5.3   | touch: cannot touch '/var/log/cont/docker-selenium-status.log': Permission denied

elgalu commented 6 years ago

For now the error output will appear however the errors are ignored if sudo doesn't work for DBUS.

But I've missed that touch command, I will release with the fix soon. I may be missing something else so we will have to circle back until we catch them all. Sorry I don't currently have OpenShift to try this out.

mojsha commented 6 years ago

No worries. Let me know when you release the fix.

Are you saying that the "sudo unknown id" errors, etc. are just noise that can be ignored?

elgalu commented 6 years ago

the "sudo unknown id" errors, etc. are just noise that can be ignored?

Yes, I will improve it later, for now is noise when sudo is not there.

elgalu commented 6 years ago

@mojsha you can try again: https://github.com/elgalu/docker-selenium/releases/tag/3.5.3-p3

mojsha commented 6 years ago

I am getting these, and then the pod dies:

rm: cannot remove '/var/log/cont/docker-selenium-status.log': Permission denied

  | rm: cannot remove '/var/log/cont/vnc-tryouts-stderr': Permission denied   | rm: cannot remove '/var/log/cont/vnc-tryouts-stdout': Permission denied

Full log output:

--LOG 14:39:08:199222979 Kubernetes service account found.
--
  | sudo: unknown uid 1000140000: who are you?
  | sudo: unknown uid 1000140000: who are you?
  | rm: cannot remove '/var/lib/dbus/machine-id': Permission denied
  | sudo: unknown uid 1000140000: who are you?
  | mkdir: cannot create directory ‘/var/run/dbus’: Permission denied
  | /usr/bin/entry.sh: line 38: dbus_service.log: Permission denied
  | /usr/bin/entry.sh: line 38: dbus_service.log: Permission denied
  | /usr/bin/entry.sh: line 40: dbus_service_status.log: Permission denied
  | Could not get password database information for UID of current process: User "???" unknown or no memory to allocate password entry
  |  
  | Failed to start message bus: Memory allocation failure in message bus
  | EOF in dbus-launch reading address from bus daemon
  | declare -x BIN_UTILS="/usr/bin"
  | declare -x BUILD_URL=""
  | declare -x CHROME="true"
  | declare -x CHROME_ADDITIONAL_ARGS=""
  | declare -x CHROME_ARGS="--no-sandbox --disable-setuid-sandbox --disable-gpu --disable-infobars"
  | declare -x CHROME_BASE_DEB_PATH="/home/seluser/chrome-deb/google-chrome"
  | declare -x CHROME_DRIVER_BASE="chromedriver.storage.googleapis.com"
  | declare -x CHROME_DRIVER_FILE="chromedriver_linux64.zip"
  | declare -x CHROME_DRIVER_URL="https://chromedriver.storage.googleapis.com/2.32/chromedriver_linux64.zip"
  | declare -x CHROME_DRIVER_VERSION="2.32"
  | declare -x CHROME_FLAVOR="stable"
  | declare -x CHROME_URL="https://dl.google.com/linux/direct"
  | declare -x CHROME_VERBOSELOGGING="true"
  | declare -x CHROME_VERSION_TRIGGER="61.0.3163.100"
  | declare -x CPU_ARCH="64"
  | declare -x DEBCONF_NONINTERACTIVE_SEEN=""
  | declare -x DEBIAN_FRONTEND=""
  | declare -x DEFAULT_NOVNC_PORT="26080"
  | declare -x DEFAULT_SELENIUM_HUB_PORT="24444"
  | declare -x DEFAULT_SELENIUM_MULTINODE_PORT="25552"
  | declare -x DEFAULT_SELENIUM_NODE_CH_PORT="25550"
  | declare -x DEFAULT_SELENIUM_NODE_FF_PORT="25551"
  | declare -x DEFAULT_SUPERVISOR_HTTP_PORT="19001"
  | declare -x DEFAULT_VNC_PORT="25900"
  | declare -x DISABLE_ROLLBACK="false"
  | declare -x DISP_N="-1"
  | declare -x DOCKER_SELENIUM_STATUS="/var/log/cont/docker-selenium-status.log"
  | declare -x DOCKER_SOCK="/var/run/docker.sock"
  | declare -x ENCODING="UTF-8"
  | declare -x ETHERNET_DEVICE_NAME="eth0"
  | declare -x FFMPEG_CODEC_ARGS="-crf 0 -preset ultrafast -qp 0"
  | declare -x FFMPEG_DRAW_MOUSE="1"
  | declare -x FFMPEG_FINAL_CRF="0"
  | declare -x FFMPEG_FRAME_RATE="10"
  | declare -x FF_BASE_URL="https://archive.mozilla.org/pub"
  | declare -x FF_COMP="firefox-55.0.3.tar.bz2"
  | declare -x FF_INNER_PATH="firefox/releases"
  | declare -x FF_LANG="en-US"
  | declare -x FF_PLATFORM="linux-x86_64"
  | declare -x FF_URL="https://archive.mozilla.org/pub/firefox/releases/55.0.3/linux-x86_64/en-US/firefox-55.0.3.tar.bz2"
  | declare -x FF_VER="55.0.3"
  | declare -x FIREFOX="false"
  | declare -x FIREFOX_VERSION="55.0.3"
  | declare -x FLUXBOX_START_MAX_RETRIES="5"
  | declare -x GA_API_VERSION="1"
  | declare -x GA_ENDPOINT="https://www.google-analytics.com/collect"
  | declare -x GA_TRACKING_ID="UA-18144954-9"
  | declare -x GECKOD_URL="https://github.com/mozilla/geckodriver/releases/download"
  | declare -x GECKOD_VER="0.19.0"
  | declare -x GREP_ONLY_NUMS_VER="[0-9.]{2,20}"
  | declare -x GRID="false"
  | declare -x HOME="/home/seluser"
  | declare -x HOSTNAME="zalenium-40000-j3k3p"
  | declare -x HUB_ENV_no_proxy="localhost"
  | declare -x KUBERNETES_PORT="tcp://172.30.0.1:443"
  | declare -x KUBERNETES_PORT_443_TCP="tcp://172.30.0.1:443"
  | declare -x KUBERNETES_PORT_443_TCP_ADDR="172.30.0.1"
  | declare -x KUBERNETES_PORT_443_TCP_PORT="443"
  | declare -x KUBERNETES_PORT_443_TCP_PROTO="tcp"
  | declare -x KUBERNETES_PORT_53_TCP="tcp://172.30.0.1:53"
  | declare -x KUBERNETES_PORT_53_TCP_ADDR="172.30.0.1"
  | declare -x KUBERNETES_PORT_53_TCP_PORT="53"
  | declare -x KUBERNETES_PORT_53_TCP_PROTO="tcp"
  | declare -x KUBERNETES_PORT_53_UDP="udp://172.30.0.1:53"
  | declare -x KUBERNETES_PORT_53_UDP_ADDR="172.30.0.1"
  | declare -x KUBERNETES_PORT_53_UDP_PORT="53"
  | declare -x KUBERNETES_PORT_53_UDP_PROTO="udp"
  | declare -x KUBERNETES_SERVICE_HOST="172.30.0.1"
  | declare -x KUBERNETES_SERVICE_PORT="443"
  | declare -x KUBERNETES_SERVICE_PORT_DNS="53"
  | declare -x KUBERNETES_SERVICE_PORT_DNS_TCP="53"
  | declare -x KUBERNETES_SERVICE_PORT_HTTPS="443"
  | declare -x LANG="en_US.UTF-8"
  | declare -x LANGUAGE="en_US.UTF-8"
  | declare -x LANG_WHERE="US"
  | declare -x LANG_WHICH="en"
  | declare -x LOGFILE_BACKUPS="5"
  | declare -x LOGFILE_MAXBYTES="10MB"
  | declare -x LOGS_DIR="/var/log/cont"
  | declare -x LOG_LEVEL="info"
  | declare -x MAX_DISPLAY_SEARCH="99"
  | declare -x MAX_INSTANCES="1"
  | declare -x MAX_SESSIONS="1"
  | declare -x MEM_JAVA_PERCENT="80"
  | declare -x MP4_INTERLEAVES_MEDIA_DATA_CHUNKS_SECS="500"
  | declare -x MULTINODE="false"
  | declare -x NOVNC="true"
  | declare -x NOVNC_PORT="50000"
  | declare -x NOVNC_SHA="9223e8f2d1c207fb74cb4b8cc243e59d84f9e2f6"
  | declare -x NOVNC_STOP_SIGNAL="TERM"
  | declare -x NOVNC_WAIT_TIMEOUT="5s"
  | declare -x OLDPWD
  | declare -x PATH="/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin"
  | declare -x PICK_ALL_RANDOM_PORTS="false"
  | declare -x PWD="/home/seluser"
  | declare -x RANDOM_PORT_FROM="23100"
  | declare -x RANDOM_PORT_TO="29999"
  | declare -x RUN_DIR="/var/run/sele"
  | declare -x SCREEN_HEIGHT="1880"
  | declare -x SCREEN_MAIN_DEPTH="24"
  | declare -x SCREEN_NUM="0"
  | declare -x SCREEN_SUB_DEPTH="32"
  | declare -x SCREEN_WIDTH="1900"
  | declare -x SELENIUM_HUB_HOST="10.130.5.56"
  | declare -x SELENIUM_HUB_PARAMS=""
  | declare -x SELENIUM_HUB_PORT="4445"
  | declare -x SELENIUM_HUB_PROTO="http"
  | declare -x SELENIUM_HUB_STOP_SIGNAL="TERM"
  | declare -x SELENIUM_MULTINODE_PORT="25552"
  | declare -x SELENIUM_MULTINODE_STOP_SIGNAL="TERM"
  | declare -x SELENIUM_NODE_CHROME_STOP_SIGNAL="TERM"
  | declare -x SELENIUM_NODE_CH_PORT="40000"
  | declare -x SELENIUM_NODE_FF_PORT="25551"
  | declare -x SELENIUM_NODE_FIREFOX_STOP_SIGNAL="TERM"
  | declare -x SELENIUM_NODE_HOST="{{CONTAINER_IP}}"
  | declare -x SELENIUM_NODE_PARAMS=""
  | declare -x SELENIUM_NODE_PROXY_PARAMS="de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy"
  | declare -x SELENIUM_NODE_REGISTER_CYCLE="0"
  | declare -x SEL_BROWSER_TIMEOUT_SECS="16000"
  | declare -x SEL_CLEANUPCYCLE_MS="5000"
  | declare -x SEL_DIRECTORY="3.5"
  | declare -x SEL_NODEPOLLING_MS="115000"
  | declare -x SEL_RELEASE_TIMEOUT_SECS="19000"
  | declare -x SEL_UNREGISTER_IF_STILL_DOWN_AFTER="2500"
  | declare -x SEL_VER="3.5.3"
  | declare -x SEND_ANONYMOUS_USAGE_INFO="false"
  | declare -x SHLVL="1"
  | declare -x SHM_SIZE="512M"
  | declare -x SHM_TRY_MOUNT_UNMOUNT="false"
  | declare -x SLEEP_SECS_AFTER_KILLING_SUPERVISORD="3"
  | declare -x SUPERVISOR_HTTP_PASSWORD="somehttpbasicauthpwd"
  | declare -x SUPERVISOR_HTTP_PORT="19001"
  | declare -x SUPERVISOR_HTTP_USERNAME="supervisorweb"
  | declare -x SUPERVISOR_KILLASGROUP="false"
  | declare -x SUPERVISOR_NOT_REQUIRED_SRV_LIST1="ignoreMe"
  | declare -x SUPERVISOR_NOT_REQUIRED_SRV_LIST2="ignoreMe"
  | declare -x SUPERVISOR_PIDFILE="/var/run/sele/supervisord.pid"
  | declare -x SUPERVISOR_REQUIRED_SRV_LIST="xmanager"
  | declare -x SUPERVISOR_STOPASGROUP="false"
  | declare -x SUPERVISOR_STOPSIGNAL="TERM"
  | declare -x SUPERVISOR_STOPWAITSECS="20"
  | declare -x TAIL_LOG_LINES="50"
  | declare -x TEST_SLEEPS="0.1"
  | declare -x TZ="Europe/Berlin"
  | declare -x UBUNTU_DATE="20170915"
  | declare -x UBUNTU_FLAVOR="xenial"
  | declare -x USER="seluser"
  | declare -x USE_KUBERNETES="true"
  | declare -x USE_SELENIUM="3"
  | declare -x VIDEO="false"
  | declare -x VIDEOS_DIR="/home/seluser/videos"
  | declare -x VIDEO_AFTER_STOP_SLEEP_SECS="0.5"
  | declare -x VIDEO_BEFORE_STOP_SLEEP_SECS="1"
  | declare -x VIDEO_CONVERSION_MAX_WAIT="20s"
  | declare -x VIDEO_FILE_EXTENSION="mp4"
  | declare -x VIDEO_FILE_NAME=""
  | declare -x VIDEO_MP4_FIX_MAX_WAIT="8s"
  | declare -x VIDEO_REC_STOP_SIGNAL="INT"
  | declare -x VIDEO_STOPWAITSECS="50"
  | declare -x VIDEO_STOP_1st_sig_TYPE="SIGTERM"
  | declare -x VIDEO_STOP_2nd_sig_TYPE="SIGINT"
  | declare -x VIDEO_STOP_3rd_sig_TYPE="SIGKILL"
  | declare -x VIDEO_STOP_SLEEP_SECS="1"
  | declare -x VIDEO_TMP_FILE_EXTENSION="mkv"
  | declare -x VIDEO_WAIT_VID_TOOL_PID_1st_sig_UP_TO_SECS="6s"
  | declare -x VIDEO_WAIT_VID_TOOL_PID_2nd_sig_UP_TO_SECS="2s"
  | declare -x VIDEO_WAIT_VID_TOOL_PID_3rd_sig_UP_TO_SECS="1s"
  | declare -x VNC_CLI_OPTS="-forever -shared"
  | declare -x VNC_FROM_PORT=""
  | declare -x VNC_PASSWORD="no"
  | declare -x VNC_PORT="60000"
  | declare -x VNC_START="true"
  | declare -x VNC_STOP_SIGNAL="TERM"
  | declare -x VNC_STORE_PWD_FILE="/home/seluser/.vnc/passwd"
  | declare -x VNC_TO_PORT=""
  | declare -x VNC_TRYOUT_ERR_LOG="/var/log/cont/vnc-tryouts-stderr"
  | declare -x VNC_TRYOUT_OUT_LOG="/var/log/cont/vnc-tryouts-stdout"
  | declare -x WAIT_FOREGROUND_RETRY="2s"
  | declare -x WAIT_TIMEOUT="120s"
  | declare -x WAIT_TIME_OUT_VIDEO_STOP="20s"
  | declare -x WAIT_VNC_FOREGROUND_RETRY="6s"
  | declare -x WEBSOCKIFY_SHA="cb1508fa495bea4b333173705772c1997559ae4b"
  | declare -x XMANAGER="fluxbox"
  | declare -x XMANAGER_STARTRETRIES="3"
  | declare -x XMANAGER_STARTSECS="2"
  | declare -x XMANAGER_STOP_SIGNAL="TERM"
  | declare -x XTERM_START="false"
  | declare -x XTERM_STOP_SIGNAL="INT"
  | declare -x XVFB_CLI_OPTS_BASE="-ac -r -cc 4 -accessx -xinerama"
  | declare -x XVFB_CLI_OPTS_EXT="+extension Composite -extension RANDR +extension GLX"
  | declare -x XVFB_CLI_OPTS_TCP="-nolisten tcp -nolisten inet6"
  | declare -x XVFB_STARTRETRIES="0"
  | declare -x XVFB_STOP_SIGNAL="TERM"
  | declare -x ZALENIUM="true"
  | declare -x ZALENIUM_PORT="tcp://172.30.108.180:80"
  | declare -x ZALENIUM_PORT_80_TCP="tcp://172.30.108.180:80"
  | declare -x ZALENIUM_PORT_80_TCP_ADDR="172.30.108.180"
  | declare -x ZALENIUM_PORT_80_TCP_PORT="80"
  | declare -x ZALENIUM_PORT_80_TCP_PROTO="tcp"
  | declare -x ZALENIUM_SERVICE_HOST="172.30.108.180"
  | declare -x ZALENIUM_SERVICE_PORT="80"
  | declare -x no_proxy="localhost"
  | rm: cannot remove '/var/log/cont/docker-selenium-status.log': Permission denied
  | rm: cannot remove '/var/log/cont/vnc-tryouts-stderr': Permission denied
  | rm: cannot remove '/var/log/cont/vnc-tryouts-stdout': Permission denied
elgalu commented 6 years ago

@mojsha I've released again: https://github.com/elgalu/docker-selenium/releases/tag/3.5.3-p4 this time there should not be permission denied errors in the logs (hopefully) please make sure you pull and use the latest image as I won't have time to take a look at this again until Monday:)

mojsha commented 6 years ago

It's still not working. Pod starts up, and shows this, and then shuts down:

  --LOG 10:29:13:523405359 Kubernetes service account found.
  rm: cannot remove '/var/log/cont/docker-selenium-status.log': Permission denied
  rm: cannot remove '/var/log/cont/vnc-tryouts-stderr': Permission denied
  rm: cannot remove '/var/log/cont/vnc-tryouts-stdout': Permission denied
elgalu commented 6 years ago

Oh, I still need to figure out why that doesn't happen locally when I remove my sudo access.

But this error doesn't happen anymore: mkdir: cannot create directory ‘/var/run/dbus’: Permission denied

or still does?

mojsha commented 6 years ago

No, it doesn't. The output I pasted above is now the sole output.

elgalu commented 6 years ago

@mojsha could you send a PR to Zalenium adding a folder like docs/k8s/sudoless_openshift in a similar fashion as done with docs/k8s/gke for Google Cloud.

I think I'm going to need a very detail config setup in order to recreate, removing my local sudo rights in the container doesn't recreate the last 3 permission denied errors :(

elgalu commented 6 years ago

@mojsha I released 3.5.3-p8 with more logging to see what's going on, feel free to pull again and report back with the output.

pearj commented 6 years ago

@elgalu the easiest way to reproduce would be to use minishift instead of minikube. If you follow the openshift directions here: https://github.com/zalando/zalenium/blob/master/docs/k8s/kubernetes.md

Skip the oc adm policy add-scc-to-user anyuid -z zalenium line, and then openshift won't allow the container to run as root, so sudo should fail.

mojsha commented 6 years ago

I read in the Gitter channel that you can recreate it with MiniShift, but just in case, here is my log output with the latest image (p8):

--LOG 13:40:24:081769420 Kubernetes service account found.

  | --WARN 13:40:24:148508696 We don't have sudo   | --LOG 13:40:24:168824394 Stopping supervisord to support docker restart...   | rm: cannot remove '/var/log/cont/docker-selenium-status.log': Permission denied   | rm: cannot remove '/var/log/cont/vnc-tryouts-stderr': Permission denied   | rm: cannot remove '/var/log/cont/vnc-tryouts-stdout': Permission denied   | --WARN 13:40:25:388526032 The container has just started yet we already don't have write access to /var/log/cont/   | total 0   | drwxr-xr-x. 2 seluser seluser 92 Sep 25 12:23 .   | drwxr-xr-x. 5 root root 191 Sep 25 12:23 ..   | -rw-r--r--. 1 seluser seluser 0 Sep 25 12:23 docker-selenium-status.log   | -rw-r--r--. 1 seluser seluser 0 Sep 25 12:23 vnc-tryouts-stderr   | -rw-r--r--. 1 seluser seluser 0 Sep 25 12:23 vnc-tryouts-stdout   | rm: cannot remove '/var/run/sele/supervisord.pid': Permission denied   | --WARN 13:40:25:420158306 The container has just started yet we already don't have write access to /var/run/sele/   | total 0   | drwxr-xr-x. 2 seluser seluser 29 Sep 25 12:23 .   | drwxr-xr-x. 7 root root 106 Sep 26 13:40 ..   | -rw-r--r--. 1 seluser seluser 0 Sep 25 12:23 supervisord.pid   | -- INFO: Docker Img. Version: 3.5.3-p8   | -- INFO: Chrome..... Version: 61.0.3163.100   | -- INFO: Firefox.... Version: 55.0.3   | -- INFO: Using Selenium.....: 3.5.3   | /usr/bin/entry.sh: line 212: /var/log/cont/firefox_browser.log: Permission denied

elgalu commented 6 years ago

@pearj thanks for pointing me to Minishift. Do you know if I can run minishift tests in TravisCI? so far it looks like NO due to kvm virtualization requirements.

@mojsha thanks for the logs, I can recreate the issue locally now so the fix shouldn't be too far.

pearj commented 6 years ago

@elgalu Originally I would have thought not, but @diemol found some guy got minikube running on travis https://github.com/zalando/zalenium/issues/157 minishift shares a bunch of its code with minikube, so there is some chance the same technique works. It looks like the magic flag is --vm-driver=none, it'd be worth a try. Generally, you can exchange the minikube command for minishift and the kubectl command for oc.

elgalu commented 6 years ago

Looks like minishift in TravisCI is a no-go:

INFO: Your CPU does not support KVM extensions

And --vm-driver=none doesn't work with minishift.

So there won't be tests for this in Travis, just local.

Locally, I know where the perms problem starts, minishift docker runs with some user ID that of course doesn't match our seluser:

whoami: cannot find name for user ID 1000060000
elgalu commented 6 years ago

Good news is, I can re-create now by simply docker run ... -u 1000060000:1000060000

pearj commented 6 years ago

@elgalu ahh, yes forgot to mention that. OpenShift randomly assigns as userid at container start for security reasons. The thing that is constant though is the root group, that's how you solve permissions issues in containers when running on OpenShift. See https://docs.openshift.com/container-platform/3.6/creating_images/guidelines.html#openshift-container-platform-specific-guidelines for their recommendations.

mojsha commented 6 years ago

@elgalu I am not sure of the status since your last post - is there a new fix to test I should pull down?

elgalu commented 6 years ago

I believe I have fixed it already docker-selenium side.

But I still need to fix it Zalenium side.

mojsha commented 6 years ago

Ok - without the "anyuid" rights, I am getting the following errors:

--LOG 11:56:45:684364656 Kubernetes service account found.

  | --WARN 11:56:45:785699209 We don't have sudo   | --LOG 11:56:45:818020671 Stopping supervisord to support docker restart...   | rm: cannot remove '/var/log/cont/docker-selenium-status.log': Permission denied   | rm: cannot remove '/var/log/cont/vnc-tryouts-stderr': Permission denied   | rm: cannot remove '/var/log/cont/vnc-tryouts-stdout': Permission denied   | --WARN 11:56:47:024657238 The container has just started yet we already don't have write access to /var/log/cont/   | total 0   | drwxr-xr-x. 2 seluser seluser 92 Sep 25 12:23 .   | drwxr-xr-x. 5 root root 191 Sep 25 12:23 ..   | -rw-r--r--. 1 seluser seluser 0 Sep 25 12:23 docker-selenium-status.log   | -rw-r--r--. 1 seluser seluser 0 Sep 25 12:23 vnc-tryouts-stderr   | -rw-r--r--. 1 seluser seluser 0 Sep 25 12:23 vnc-tryouts-stdout   | rm: cannot remove '/var/run/sele/supervisord.pid': Permission denied   | --WARN 11:56:47:049551577 The container has just started yet we already don't have write access to /var/run/sele/   | total 0   | drwxr-xr-x. 2 seluser seluser 29 Sep 25 12:23 .   | drwxr-xr-x. 7 root root 106 Oct 3 11:56 ..   | -rw-r--r--. 1 seluser seluser 0 Sep 25 12:23 supervisord.pid   | -- INFO: Docker Img. Version: 3.5.3-p8   | -- INFO: Chrome..... Version: 61.0.3163.100   | -- INFO: Firefox.... Version: 55.0.3   | -- INFO: Using Selenium.....: 3.5.3   | /usr/bin/entry.sh: line 212: /var/log/cont/firefox_browser.log: Permission denied

and then it dies.

elgalu commented 6 years ago

Log says you are using 3.5.3-p8 but you should be using p13, check the releases page ;)

elgalu commented 6 years ago

@mojsha can you pull latest of both images and try again?

https://github.com/zalando/zalenium/releases/tag/3.5.3d https://github.com/elgalu/docker-selenium/releases/tag/3.5.3-p14

mojsha commented 6 years ago

I've pulled the following versions:

zalenium 3.6.0b docker-selenium 3.6.0-p3

and it is unfortunately not working. However now it might be Zalenium as I cannot see errors in the Docker-selenium pod.

--LOG 15:38:48:312799251 Kubernetes service account found.
--
  | --WARN 15:38:48:430990533 We don't have sudo
  | --LOG 15:38:48:747329851 Stopping supervisord to support docker restart...
  | -- INFO: Docker Img. Version: 3.6.0-p3
  | -- INFO: Chrome..... Version: 61.0.3163.100
  | -- INFO: Firefox.... Version: 56.0.1
  | -- INFO: Using Selenium.....: 3.6.0
  | supervisord --version=4.0.0.dev0
  | 2017-10-11 15:38:53,109 INFO Included extra file "/etc/supervisor/conf.d/novnc.conf" during parsing
  | 2017-10-11 15:38:53,109 INFO Included extra file "/etc/supervisor/conf.d/selenium-hub.conf" during parsing
  | 2017-10-11 15:38:53,109 INFO Included extra file "/etc/supervisor/conf.d/selenium-multinode.conf" during parsing
  | 2017-10-11 15:38:53,109 INFO Included extra file "/etc/supervisor/conf.d/selenium-node-chrome.conf" during parsing
  | 2017-10-11 15:38:53,109 INFO Included extra file "/etc/supervisor/conf.d/selenium-node-firefox.conf" during parsing
  | 2017-10-11 15:38:53,109 INFO Included extra file "/etc/supervisor/conf.d/video-rec.conf" during parsing
  | 2017-10-11 15:38:53,109 INFO Included extra file "/etc/supervisor/conf.d/vnc.conf" during parsing
  | 2017-10-11 15:38:53,109 INFO Included extra file "/etc/supervisor/conf.d/xmanager.conf" during parsing
  | 2017-10-11 15:38:53,109 INFO Included extra file "/etc/supervisor/conf.d/xterm.conf" during parsing
  | 2017-10-11 15:38:53,180 INFO RPC interface 'supervisor' initialized
  | 2017-10-11 15:38:53,182 INFO RPC interface 'supervisor' initialized
  | 2017-10-11 15:38:53,182 INFO supervisord started with pid 157
  | 2017-10-11 15:38:54,185 INFO spawned: 'xmanager' with pid 160
  | 2017-10-11 15:38:54,187 INFO spawned: 'vnc' with pid 161
  | 2017-10-11 15:38:54,188 INFO spawned: 'novnc' with pid 162
  | 2017-10-11 15:38:54,190 INFO spawned: 'selenium-node-chrome' with pid 163
  | 2017-10-11 15:38:54,192 INFO spawned: 'xterm' with pid 164
  | 2017-10-11 15:38:54,211 INFO success: xterm entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
  | 2017-10-11 15:38:56,268 INFO success: xmanager entered RUNNING state, process has stayed up for > than 2 seconds (startsecs)
  | 2017-10-11 15:38:56,268 INFO success: vnc entered RUNNING state, process has stayed up for > than 2 seconds (startsecs)
  | 2017-10-11 15:38:56,268 INFO success: novnc entered RUNNING state, process has stayed up for > than 2 seconds (startsecs)
  | 2017-10-11 15:38:57,219 INFO success: selenium-node-chrome entered RUNNING state, process has stayed up for > than 3 seconds (startsecs)
  | 2017-10-11 15:39:02,988 INFO spawned: 'video-rec' with pid 1035
  | 2017-10-11 15:39:02,989 INFO success: video-rec entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)

--LOG 15:38:48:312799251 Kubernetes service account found.
--
  | --WARN 15:38:48:430990533 We don't have sudo
  | --LOG 15:38:48:747329851 Stopping supervisord to support docker restart...
  | -- INFO: Docker Img. Version: 3.6.0-p3
  | -- INFO: Chrome..... Version: 61.0.3163.100
  | -- INFO: Firefox.... Version: 56.0.1
  | -- INFO: Using Selenium.....: 3.6.0
  | supervisord --version=4.0.0.dev0
  | 2017-10-11 15:38:53,109 INFO Included extra file "/etc/supervisor/conf.d/novnc.conf" during parsing
  | 2017-10-11 15:38:53,109 INFO Included extra file "/etc/supervisor/conf.d/selenium-hub.conf" during parsing
  | 2017-10-11 15:38:53,109 INFO Included extra file "/etc/supervisor/conf.d/selenium-multinode.conf" during parsing
  | 2017-10-11 15:38:53,109 INFO Included extra file "/etc/supervisor/conf.d/selenium-node-chrome.conf" during parsing
  | 2017-10-11 15:38:53,109 INFO Included extra file "/etc/supervisor/conf.d/selenium-node-firefox.conf" during parsing
  | 2017-10-11 15:38:53,109 INFO Included extra file "/etc/supervisor/conf.d/video-rec.conf" during parsing
  | 2017-10-11 15:38:53,109 INFO Included extra file "/etc/supervisor/conf.d/vnc.conf" during parsing
  | 2017-10-11 15:38:53,109 INFO Included extra file "/etc/supervisor/conf.d/xmanager.conf" during parsing
  | 2017-10-11 15:38:53,109 INFO Included extra file "/etc/supervisor/conf.d/xterm.conf" during parsing
  | 2017-10-11 15:38:53,180 INFO RPC interface 'supervisor' initialized
  | 2017-10-11 15:38:53,182 INFO RPC interface 'supervisor' initialized
  | 2017-10-11 15:38:53,182 INFO supervisord started with pid 157
  | 2017-10-11 15:38:54,185 INFO spawned: 'xmanager' with pid 160
  | 2017-10-11 15:38:54,187 INFO spawned: 'vnc' with pid 161
  | 2017-10-11 15:38:54,188 INFO spawned: 'novnc' with pid 162
  | 2017-10-11 15:38:54,190 INFO spawned: 'selenium-node-chrome' with pid 163
  | 2017-10-11 15:38:54,192 INFO spawned: 'xterm' with pid 164
  | 2017-10-11 15:38:54,211 INFO success: xterm entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
  | 2017-10-11 15:38:56,268 INFO success: xmanager entered RUNNING state, process has stayed up for > than 2 seconds (startsecs)
  | 2017-10-11 15:38:56,268 INFO success: vnc entered RUNNING state, process has stayed up for > than 2 seconds (startsecs)
  | 2017-10-11 15:38:56,268 INFO success: novnc entered RUNNING state, process has stayed up for > than 2 seconds (startsecs)
  | 2017-10-11 15:38:57,219 INFO success: selenium-node-chrome entered RUNNING state, process has stayed up for > than 3 seconds (startsecs)
  | 2017-10-11 15:39:02,988 INFO spawned: 'video-rec' with pid 1035
  | 2017-10-11 15:39:02,989 INFO success: video-rec entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
  | 2017-10-11 15:40:33,804 INFO waiting for video-rec to stop
  | 2017-10-11 15:40:35,804 INFO waiting for video-rec to stop
  | 2017-10-11 15:40:37,805 INFO waiting for video-rec to stop
  | 2017-10-11 15:40:39,805 INFO waiting for video-rec to stop
  | 2017-10-11 15:40:41,805 INFO waiting for video-rec to stop
  | 2017-10-11 15:40:43,805 INFO waiting for video-rec to stop
  | 2017-10-11 15:40:45,805 INFO waiting for video-rec to stop
  | 2017-10-11 15:40:47,805 INFO waiting for video-rec to stop
  | 2017-10-11 15:40:49,805 INFO waiting for video-rec to stop
  | 2017-10-11 15:40:51,805 INFO waiting for video-rec to stop
  | 2017-10-11 15:40:53,805 INFO waiting for video-rec to stop
  | 2017-10-11 15:40:55,805 INFO waiting for video-rec to stop
  | 2017-10-11 15:40:57,805 INFO waiting for video-rec to stop
  | 2017-10-11 15:40:59,805 INFO waiting for video-rec to stop
  | 2017-10-11 15:41:01,805 INFO waiting for video-rec to stop
  | 2017-10-11 15:41:03,806 INFO waiting for video-rec to stop
  | 2017-10-11 15:41:03,843 INFO stopped: video-rec (exit status 0)
  | Trapped SIGTERM/SIGINT/x so shutting down supervisord gracefully...
  | 2017-10-11 15:41:05,784 INFO waiting for xmanager to stop
  | 2017-10-11 15:41:05,784 INFO waiting for vnc to stop
  | 2017-10-11 15:41:05,784 INFO waiting for novnc to stop
  | 2017-10-11 15:41:05,784 INFO waiting for selenium-node-chrome to stop
  | 2017-10-11 15:41:05,785 INFO waiting for xterm to stop
  | 2017-10-11 15:41:05,787 INFO stopped: xmanager (exit status 0)
  | 2017-10-11 15:41:05,787 INFO stopped: novnc (terminated by SIGTERM)
  | 2017-10-11 15:41:05,808 INFO stopped: vnc (exit status 0)
  | 2017-10-11 15:41:05,809 INFO stopped: selenium-node-chrome (exit status 137)
  | 2017-10-11 15:41:07,756 INFO stopped: xterm (exit status 150)
  | 2017-10-11 15:41:07,756 WARN received SIGTERM indicating exit request

Zalenium log:

--WARN 15:37:23:420834928 We don't have sudo
--
  | Kubernetes service account found.
  | -- LOG 15:37:23:465741833 Running additional checks...
  | Copying files for Dashboard...
  | cp: cannot create regular file '/home/seluser/videos/index.html': No such file or directory
  | cp: cannot create directory '/home/seluser/videos': Permission denied
  | cp: cannot create directory '/home/seluser/videos': Permission denied
  | Starting Nginx reverse proxy...
  | Starting Selenium Hub...
  | mkdir: cannot create directory ‘logs’: Permission denied
  | Can't load log handler "java.util.logging.FileHandler"
  | java.nio.file.NoSuchFileException: /home/seluser/logs/zalenium0.log.lck
  | java.nio.file.NoSuchFileException: /home/seluser/logs/zalenium0.log.lck
  | at sun.nio.fs.UnixException.translateToIOException(UnixException.java:86)
  | at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:102)
  | at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:107)
  | at sun.nio.fs.UnixFileSystemProvider.newFileChannel(UnixFileSystemProvider.java:177)
  | at java.nio.channels.FileChannel.open(FileChannel.java:287)
  | at java.nio.channels.FileChannel.open(FileChannel.java:335)
  | at java.util.logging.FileHandler.openFiles(FileHandler.java:459)
  | at java.util.logging.FileHandler.<init>(FileHandler.java:263)
  | at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
  | at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
  | at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
  | at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
  | at java.lang.Class.newInstance(Class.java:442)
  | at java.util.logging.LogManager$5.run(LogManager.java:966)
  | at java.security.AccessController.doPrivileged(Native Method)
  | at java.util.logging.LogManager.loadLoggerHandlers(LogManager.java:958)
  | at java.util.logging.LogManager.initializeGlobalHandlers(LogManager.java:1578)
  | at java.util.logging.LogManager.access$1500(LogManager.java:145)
  | at java.util.logging.LogManager$RootLogger.accessCheckedHandlers(LogManager.java:1667)
  | at java.util.logging.Logger.getHandlers(Logger.java:1777)
  | at org.openqa.grid.selenium.GridLauncherV3.configureLogging(GridLauncherV3.java:212)
  | at org.openqa.grid.selenium.GridLauncherV3.main(GridLauncherV3.java:92)
  | 15:37:25.394 INFO - Selenium build info: version: '3.6.0', revision: '6fbf3ec767'
  | 15:37:25.396 INFO - Launching Selenium Grid hub
  | 15:37:26.464 INFO - binding de.zalando.ep.zalenium.servlet.LivePreviewServlet to /grid/admin/LivePreviewServlet/*
  | 15:37:26.473 INFO - binding de.zalando.ep.zalenium.servlet.ZaleniumConsoleServlet to /grid/admin/ZaleniumConsoleServlet/*
  | 15:37:26.474 INFO - binding de.zalando.ep.zalenium.servlet.ZaleniumResourceServlet to /grid/admin/ZaleniumResourceServlet/*
  | 15:37:26.474 INFO - binding de.zalando.ep.zalenium.dashboard.DashboardCleanupServlet to /grid/admin/DashboardCleanupServlet/*
  | 15:37:26.941 INFO - Will listen on 4445
  | 15:37:27.122 INFO - Nodes should register to http://10.129.4.240:4445/grid/register/
  | 15:37:27.122 INFO - Selenium Grid hub is up and running
  | ..............Selenium Hub started!
  | Starting DockerSeleniumStarter node...
  | Can't load log handler "java.util.logging.FileHandler"
  | java.nio.file.NoSuchFileException: /home/seluser/logs/zalenium0.log.lck
  | java.nio.file.NoSuchFileException: /home/seluser/logs/zalenium0.log.lck
  | at sun.nio.fs.UnixException.translateToIOException(UnixException.java:86)
  | at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:102)
  | at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:107)
  | at sun.nio.fs.UnixFileSystemProvider.newFileChannel(UnixFileSystemProvider.java:177)
  | at java.nio.channels.FileChannel.open(FileChannel.java:287)
  | at java.nio.channels.FileChannel.open(FileChannel.java:335)
  | at java.util.logging.FileHandler.openFiles(FileHandler.java:459)
  | at java.util.logging.FileHandler.<init>(FileHandler.java:263)
  | at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
  | at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
  | at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
  | at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
  | at java.lang.Class.newInstance(Class.java:442)
  | at java.util.logging.LogManager$5.run(LogManager.java:966)
  | at java.security.AccessController.doPrivileged(Native Method)
  | at java.util.logging.LogManager.loadLoggerHandlers(LogManager.java:958)
  | at java.util.logging.LogManager.initializeGlobalHandlers(LogManager.java:1578)
  | at java.util.logging.LogManager.access$1500(LogManager.java:145)
  | at java.util.logging.LogManager$RootLogger.accessCheckedHandlers(LogManager.java:1667)
  | at java.util.logging.Logger.getHandlers(Logger.java:1777)
  | at org.openqa.grid.selenium.GridLauncherV3.configureLogging(GridLauncherV3.java:212)
  | at org.openqa.grid.selenium.GridLauncherV3.main(GridLauncherV3.java:92)
  | 15:37:27.883 INFO - Selenium build info: version: '3.6.0', revision: '6fbf3ec767'
  | 15:37:27.883 INFO - Launching a Selenium Grid node
  | 2017-10-11 15:37:28.380:INFO::main: Logging initialized @819ms to org.seleniumhq.jetty9.util.log.StdErrLog
  | 15:37:28.444 INFO - Driver class not found: com.opera.core.systems.OperaDriver
  | 15:37:28.468 INFO - Driver provider class org.openqa.selenium.ie.InternetExplorerDriver registration is skipped:
  | registration capabilities Capabilities [{ensureCleanSession=true, browserName=internet explorer, version=, platform=WINDOWS}] does not match the current platform LINUX
  | 15:37:28.468 INFO - Driver provider class org.openqa.selenium.edge.EdgeDriver registration is skipped:
  | registration capabilities Capabilities [{browserName=MicrosoftEdge, version=, platform=WINDOWS}] does not match the current platform LINUX
  | 15:37:28.468 INFO - Driver provider class org.openqa.selenium.safari.SafariDriver registration is skipped:
  | registration capabilities Capabilities [{browserName=safari, version=, platform=MAC}] does not match the current platform LINUX
  | 15:37:28.513 INFO - Using the passthrough mode handler
  | 2017-10-11 15:37:28.536:INFO:osjs.Server:main: jetty-9.4.5.v20170502
  | 2017-10-11 15:37:28.559:WARN:osjs.SecurityHandler:main: ServletContext@o.s.j.s.ServletContextHandler@6aba2b86{/,null,STARTING} has uncovered http methods for path: /
  | 2017-10-11 15:37:28.562:INFO:osjsh.ContextHandler:main: Started o.s.j.s.ServletContextHandler@6aba2b86{/,null,AVAILABLE}
  | 2017-10-11 15:37:28.583:INFO:osjs.AbstractConnector:main: Started ServerConnector@36bc55de{HTTP/1.1,[http/1.1]}{0.0.0.0:30000}
  | 2017-10-11 15:37:28.583:INFO:osjs.Server:main: Started @1022ms
  | 15:37:28.583 INFO - Selenium Grid node is up and ready to register to the hub
  | 15:37:28.599 INFO - Registering the node to the hub: http://localhost:4444/grid/register
  | 15:37:28.848 INFO - Initialising Kubernetes support
  | 15:37:29.631 INFO - Kubernetes support initialised.
  | Pod name: zalenium-1-1tsqm
  | app label: zalenium
  | zalenium service name: zalenium
  | Kubernetes flavour: OpenShift
  | Selenium Pod Resource Limits: {memory=Quantity(amount=1Gi, format=null, additionalProperties={}), cpu=Quantity(amount=1000m, format=null, additionalProperties={})}
  | Selenium Pod Resource Requests: {memory=Quantity(amount=500Mi, format=null, additionalProperties={}), cpu=Quantity(amount=500m, format=null, additionalProperties={})}
  | 15:37:29.637 INFO - [DS] Capabilities grabbed from the docker-selenium image
  | 15:37:29.642 INFO - Registered a node http://10.129.4.240:30000
  | 15:37:29.643 INFO - About to clean up any left over selenium pods created by Zalenium
  | 15:37:29.643 INFO - The node is registered to the hub and ready to use
  | 15:37:29.702 INFO - [DS]  Setting up 0 nodes...
  | 15:37:29.702 INFO - 0 containers were created, it will take a bit more until all get registered.
  | .........DockerSeleniumStarter node started!
  | Sauce Labs not enabled...
  | Browser Stack not enabled...
  | TestingBot not enabled...
  | Zalenium is now ready!
  | 15:37:43.712 INFO - Mismatched capabilities. Creating a synthetic w3c capability.
  | 15:37:43.717 INFO - Got a request to create a new session: Capabilities [{proxy={httpProxy=172.21.64.14:8080, proxyType=manual, sslProxy=172.21.64.14:8080}, acceptSslCerts=true, acceptInsecureCerts=true, recordVideo=true, browserName=chrome, platformName=ANY, version=, platform=ANY}]
  | 15:37:43.719 INFO - [DS] Starting new node for {proxy={httpProxy=172.21.64.14:8080, proxyType=manual, sslProxy=172.21.64.14:8080}, acceptSslCerts=true, acceptInsecureCerts=true, recordVideo=true, browserName=chrome, platformName=ANY, version=, platform=ANY}.
  | 15:37:43.741 INFO - Pods in the list 0
  | 15:38:58.656 INFO - Registered a node http://10.130.4.158:40000
  | 15:38:58.658 INFO - Trying to create a new session on test slot {seleniumProtocol=WebDriver, acceptSslCerts=true, screen-resolution=1920x1080, tz=Europe/Berlin, browserName=chrome, maxInstances=1, screenResolution=1920x1080, resolution=1920x1080, version=61.0.3163.100, platform=LINUX}
  | 15:38:59.528 INFO - [DS] Container zalenium-40000-j4bg8 is up after ~25 seconds...
  | 15:39:02.416 INFO - zalenium-40000-j4bg8 [bash, -c, start-video]
  | 15:39:03.871 INFO - zalenium-40000-j4bg8 video-rec: started
  | Waiting for ffmpeg video recording to start...
  | ....Videos at /home/seluser/videos/vid_chrome_40000.mp4* started to be recorded! (wait-video-rec.sh)
  |  
  | 15:40:32.681 INFO - http://10.130.4.158:40000 Shutting down node due to test inactivity
  | 15:40:32.682 INFO - zalenium-40000-j4bg8 [bash, -c, notify 'Zalenium', 'TEST TIMED OUT', --icon=/home/seluser/images/timeout.png]
  | 15:40:33.190 INFO - zalenium-40000-j4bg8
  | 15:40:33.191 INFO - zalenium-40000-j4bg8 [bash, -c, stop-video]
  | 15:41:04.213 INFO - zalenium-40000-j4bg8 video-rec: stopped
  | Waiting for video to stop recording...
  | video-rec                        STOPPED   Oct 11 03:41 PM
  | Done waiting for video recording to stop.
  | Video recording stopped
  | --LOG 15:41:04:172089893 -- DEBUG: video-rec-stdout.log ----
  | Stream #0:0 -> #0:0 (rawvideo (native) -> h264 (libx264))
  | Press [q] to stop, [?] for help
  | frame=    8 fps=0.0 q=0.0 size=       1kB time=00:00:00.00 bitrate=N/A     frame=   14 fps= 12 q=0.0 size=      71kB time=00:00:00.40 bitrate=1452.3kbits/s     frame=   20 fps= 11 q=0.0 size=     126kB time=00:00:01.00 bitrate=1030.3kbits/s     frame=   26 fps= 11 q=0.0 size=     181kB time=00:00:01.60 bitrate= 925.9kbits/s     frame=   31 fps= 11 q=0.0 size=     227kB time=00:00:02.10 bitrate= 883.7kbits/s     frame=   37 fps= 11 q=0.0 size=     282kB time=00:00:02.70 bitrate= 854.4kbits/s     frame=   42 fps= 11 q=0.0 size=     327kB time=00:00:03.20 bitrate= 837.8kbits/s     frame=   47 fps= 10 q=0.0 size=     373kB time=00:00:03.70 bitrate= 826.3kbits/s     frame=   52 fps= 10 q=0.0 size=     419kB time=00:00:04.20 bitrate= 817.1kbits/s     frame=   57 fps= 10 q=0.0 size=     465kB time=00:00:04.70 bitrate= 810.2kbits/s     frame=   63 fps= 10 q=0.0 size=     520kB time=00:00:05.30 bitrate= 803.3kbits/s     frame=   68 fps= 10 q=0.0 size=     566kB time=00:00:05.80 bitrate= 798.9kbits/s     frame=   74 fps= 10 q=0.0 size=     621kB time=00:00:06.40 bitrate= 794.6kbits/s     frame=   80 fps= 10 q=0.0 size=     676kB time=00:00:07.00 bitrate= 790.7kbits/s     frame=   85 fps= 10 q=0.0 size=     722kB time=00:00:07.50 bitrate= 788.3kbits/s     frame=   91 fps= 10 q=0.0 size=     777kB time=00:00:08.10 bitrate= 785.4kbits/s     frame=   97 fps= 10 q=0.0 size=     832kB time=00:00:08.70 bitrate= 783.0kbits/s     frame=  103 fps= 10 q=0.0 size=     886kB time=00:00:09.30 bitrate= 780.8kbits/s     frame=  108 fps= 10 q=0.0 size=     932kB time=00:00:09.80 bitrate= 779.4kbits/s     frame=  113 fps= 10 q=0.0 size=     978kB time=00:00:10.30 bitrate= 777.9kbits/s     frame=  119 fps= 10 q=0.0 size=    1033kB time=00:00:10.90 bitrate= 776.5kbits/s     frame=  124 fps= 10 q=0.0 size=    1079kB time=00:00:11.40 bitrate= 775.4kbits/s     frame=  130 fps= 10 q=0.0 size=    1134kB time=00:00:12.00 bitrate= 774.1kbits/s     frame=  136 fps= 10 q=0.0 size=    1189kB time=00:00:12.60 bitrate= 773.0kbits/s     frame=  142 fps= 1

--LOG 15:40:33:810185066 Trapped SIGTERM or SIGINT so shutting down ffmpeg gracefully...
--
  | --LOG 15:40:33:815363313 Will kill VID_TOOL_PID=1038 ...
  | frame=  902 fps= 10 q=-1.0 Lsize=    8404kB time=00:01:30.20 bitrate= 763.3kbits/s
  | video:8397kB audio:0kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: 0.085971%
  | [libx264 @ 0x10a98c0] frame I:4     Avg QP: 0.00  size: 43098
  | [libx264 @ 0x10a98c0] frame P:898   Avg QP: 0.00  size:  9382
  | [libx264 @ 0x10a98c0] mb I  I16..4: 100.0%  0.0%  0.0%
  | [libx264 @ 0x10a98c0] mb P  I16..4: 90.4%  0.0%  0.0%  P16..4:  0.0%  0.0%  0.0%  0.0%  0.0%    skip: 9.6%
  | [libx264 @ 0x10a98c0] coded y,u,v intra: 0.0% 0.0% 0.0% inter: 0.1% 0.0% 0.0%
  | [libx264 @ 0x10a98c0] i16 v,h,dc,p: 100%  0%  0%  0%
  | [libx264 @ 0x10a98c0] kb/s:762.55
  | Exiting normally, received signal 2.
  | --LOG 15:40:34:823646823 Tried to kill -SIGTERM VID_TOOL_PID=1038
  | --LOG 15:40:34:831081127 Waiting up to 6s for VID_TOOL_PID=1038 to end with SIGTERM...
  | --LOG 15:40:34:848931130 wait_pid successfully managed to SIGTERM:VID_TOOL_PID=1038 within less than 6s
  | --LOG 15:40:34:855248106 Will try to fix the videos...
  | --LOG 15:40:35:408641416 Fixing perms for /home/seluser/videos/vid_chrome_40000.mkv*
  | --LOG 15:40:35:418060650 Changing video encoding from mkv to mp4...
  | --LOG 15:40:55:813736889 Conversion from mkv to mp4 FAILED! in within the 20s
  | --LOG 15:40:55:826803938 Optimizing /home/seluser/videos/vid_chrome_40000.mp4 for HTTP streaming...
  | Error opening file /home/seluser/videos/vid_chrome_40000.mp4: Invalid IsoMedia File
  | --LOG 15:40:55:961634417 MP4Box got errors meaning the mp4 video file is corrupted, trying again...
  | Error opening file /home/seluser/videos/vid_chrome_40000.mp4: Invalid IsoMedia File
  | --LOG 15:40:56:975260339 MP4Box got errors meaning the mp4 video file is corrupted, trying again...
  | Error opening file /home/seluser/videos/vid_chrome_40000.mp4: Invalid IsoMedia File
  | --LOG 15:40:58:004025227 MP4Box got errors meaning the mp4 video file is corrupted, trying again...
  | Error opening file /home/seluser/videos/vid_chrome_40000.mp4: Invalid IsoMedia File
  | --LOG 15:40:59:017546452 MP4Box got errors meaning the mp4 video file is corrupted, trying again...
  | Error opening file /home/seluser/videos/vid_chrome_40000.mp4: Invalid IsoMedia File
  | --LOG 15:41:00:058741110 MP4Box got errors meaning the mp4 video file is corrupted, trying again...
  | Error opening file /home/seluser/videos/vid_chrome_40000.mp4: Invalid IsoMedia File
  | --LOG 15:41:01:117278822 MP4Box got errors meaning the mp4 video file is corrupted, trying again...
  | Error opening file /home/seluser/videos/vid_chrome_40000.mp4: Invalid IsoMedia File
  | --LOG 15:41:02:134835331 MP4Box got errors meaning the mp4 video file is corrupted, trying again...
  | Error opening file /home/seluser/videos/vid_chrome_40000.mp4: Invalid IsoMedia File
  | --LOG 15:41:03:148572621 MP4Box got errors meaning the mp4 video file is corrupted, trying again...
  | --LOG 15:41:03:835375245 Failed! to mp4box_retry.sh within 8s
  | --LOG 15:41:03:841634833 ffmpeg shutdown complete.
  | --LOG 15:41:04:196528785 -- DEBUG: video-rec-stderr.log ----
  | libavdevice    56.  4.100 / 56.  4.100
  | libavfilter     5. 40.101 /  5. 40.101
  | libavresample   2.  1.  0 /  2.  1.  0
  | libswscale      3.  1.101 /  3.  1.101
  | libswresample   1.  2.101 /  1.  2.101
  | libpostproc    53.  3.100 / 53.  3.100
  | Input #0, matroska,webm, from '/home/seluser/videos/vid_chrome_40000.mkv':
  | Metadata:
  | ENCODER         : Lavf56.40.101
  | Duration: 00:01:30.20, start: 0.000000, bitrate: 763 kb/s
  | Stream #0:0: Video: h264 (High 4:4:4 Predictive), yuv444p, 1920x1080, SAR 1:1 DAR 16:9, 10 fps, 10 tbr, 1k tbn, 20 tbc (default)
  | Metadata:
  | ENCODER         : Lavc56.60.100 libx264
  | DURATION        : 00:01:30.200000000
  | No pixel format specified, yuv444p for H.264 encoding chosen.
  | Use -pix_fmt yuv420p for compatibility with outdated media players.
  | [libx264 @ 0x23b4420] using SAR=1/1
  | [libx264 @ 0x23b4420] using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2 AVX
  | [libx264 @ 0x23b4420] profile High 4:4:4 Predictive, level 4.0, 4:4:4 8-bit
  | [libx264 @ 0x23b4420] 264 - core 148 r2643 5c65704 - H.264/MPEG-4 AVC codec - Copyleft 2003-2015 - http://www.videolan.org/x264.html - options: cabac=0 ref=1 deblock=0:0:0 analyse=0:0 me=dia subme=0 psy=0 mixed_ref=0 me_range=16 chroma_me=1 trellis=0 8x8dct=0 cqm=0 deadzone=21,11 fast_pskip=0 chroma_qp_offset=0 threads=9 lookahead_threads=1 sliced_threads=0 nr=0 decimate=1 interlaced=0 bluray_compat=0 constrained_intra=0 bframes=0 weightp=0 keyint=250 keyint_min=10 scenecut=0 intra_refresh=0 rc=cqp mbtree=0 qp=0
  | Output #0, mp4, to '/home/seluser/videos/vid_chrome_40000.mp4':
  | Metadata:
  | encoder         : Lavf56.40.101
  | Stream #0:0: Video: h264 (libx264) ([33][0][0][0] / 0x0021), yuv444p, 1920x1080 [SAR 1:1 DAR 16:9], q=-1--1, 10 fps, 10240 tbn, 10 tbc (default)
  | Metadata:

15:41:04.457 WARN - http://10.130.4.158:40000 Error while copying the video
--
  | java.io.FileNotFoundException: /home/seluser/videos/zalenium_25b51707-00ef-47c2-a8c2-371f51377c87_chrome_LINUX_20171011154104.mp4 (No such file or directory)
  | at java.io.FileOutputStream.open0(Native Method)
  | at java.io.FileOutputStream.open(FileOutputStream.java:270)
  | at java.io.FileOutputStream.<init>(FileOutputStream.java:213)
  | at java.io.FileOutputStream.<init>(FileOutputStream.java:162)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.copyVideos(DockerSeleniumRemoteProxy.java:440)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.processContainerAction(DockerSeleniumRemoteProxy.java:414)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.processContainerAction(DockerSeleniumRemoteProxy.java:403)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.videoRecording(DockerSeleniumRemoteProxy.java:367)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.cleanupNode(DockerSeleniumRemoteProxy.java:487)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.shutdownNode(DockerSeleniumRemoteProxy.java:501)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.access$200(DockerSeleniumRemoteProxy.java:48)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy$DockerSeleniumNodePoller.run(DockerSeleniumRemoteProxy.java:56

15:41:04.972 WARN - http://10.130.4.158:40000 Error while copying the logs
--
  | java.io.FileNotFoundException: /home/seluser/videos/logs/zalenium_25b51707-00ef-47c2-a8c2-371f51377c87_chrome_LINUX_20171011154104/./firefox_browser.log (No such file or directory)
  | at java.io.FileOutputStream.open0(Native Method)
  | at java.io.FileOutputStream.open(FileOutputStream.java:270)
  | at java.io.FileOutputStream.<init>(FileOutputStream.java:213)
  | at java.io.FileOutputStream.<init>(FileOutputStream.java:162)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.copyLogs(DockerSeleniumRemoteProxy.java:473)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.processContainerAction(DockerSeleniumRemoteProxy.java:417)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.processContainerAction(DockerSeleniumRemoteProxy.java:403)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.cleanupNode(DockerSeleniumRemoteProxy.java:488)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.shutdownNode(DockerSeleniumRemoteProxy.java:501)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.access$200(DockerSeleniumRemoteProxy.java:48)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy$DockerSeleniumNodePoller.run(DockerSeleniumRemoteProxy.java:569)
  | 15:41:04.976 INFO - zalenium-40000-j4bg8 [bash, -c, cleanup-container.sh]
  | 15:41:05.268 INFO - zalenium-40000-j4bg8
  | 15:41:05.278 WARN - Error while updating the dashboard.
  | java.io.IOException: Directory '/home/seluser/videos' could not be created
  | at org.apache.commons.io.FileUtils.openOutputStream(FileUtils.java:356)
  | at org.apache.commons.io.FileUtils.writeStringToFile(FileUtils.java:1981)
  | at org.apache.commons.io.FileUtils.writeStringToFile(FileUtils.java:1947)
  | at de.zalando.ep.zalenium.dashboard.Dashboard.updateDashboard(Dashboard.java:89)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.cleanupNode(DockerSeleniumRemoteProxy.java:491)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.shutdownNode(DockerSeleniumRemoteProxy.java:501)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.access$200(DockerSeleniumRemoteProxy.java:48)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy$DockerSeleniumNodePoller.run(DockerSeleniumRemoteProxy.java:569)
  | 15:41:05.445 INFO - http://10.130.4.158:40000 Marking the node as down because the test has been idle for more than 90 seconds.
  | 15:41:05.446 INFO - http://10.130.4.158:40000 Marking the node as down because the test has been idle for more than 90 seconds.
  | 15:41:05.446 WARN - Cleaning up stale test sessions on the unregistered node http://10.130.4.158:40000
  | 15:41:05.461 [OkHttp https://kubernetes.default.svc/...] ERROR i.f.k.c.d.i.ExecWebSocketListener - Exec Failure: HTTP:0. Message:No response
  | io.fabric8.kubernetes.client.KubernetesClientException: An error has occurred.
  | at io.fabric8.kubernetes.client.KubernetesClientException.launderThrowable(KubernetesClientException.java:62)
  | at io.fabric8.kubernetes.client.KubernetesClientException.launderThrowable(KubernetesClientException.java:53)
  | at io.fabric8.kubernetes.client.dsl.internal.ExecWebSocketListener.onMessage(ExecWebSocketListener.java:253)
  | at okhttp3.internal.ws.RealWebSocket.onReadMessage(RealWebSocket.java:311)
  | at okhttp3.internal.ws.WebSocketReader.readMessageFrame(WebSocketReader.java:224)
  | at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.java:101)
  | at okhttp3.internal.ws.RealWebSocket.loopReader(RealWebSocket.java:262)
  | at okhttp3.internal.ws.RealWebSocket$2.onResponse(RealWebSocket.java:201)
  | at okhttp3.RealCall$AsyncCall.execute(RealCall.java:141)
  | at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
  | at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
  | at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
  | at java.lang.Thread.run(Thread.java:748)
  | Caused by: java.io.IOException: Read end dead
  | at java.io.PipedInputStream.checkStateForReceive(PipedInputStream.java:262)
  | at java.io.PipedInputStream.awaitSpace(PipedInputStream.java:268)
  | at java.io.PipedInputStream.receive(PipedInputStream.java:231)
  | at java.io.PipedOutputStream.write(PipedOutputStream.java:149)
  | at java.io.OutputStream.write(OutputStream.java:75)
  | at io.fabric8.kubernetes.client.dsl.internal.ExecWebSocketListener.onMessage(ExecWebSocketListener.java:235)
  | ... 10 common frames omitted
  | 15:41:05.464 ERROR - zalenium-40000-j4bg8 Failed to execute command [tar, -C, /videos/, -c, .]
  | io.fabric8.kubernetes.client.KubernetesClientException: An error has occurred.
  | at io.fabric8.kubernetes.client.KubernetesClientException.launderThrowable(KubernetesClientException.java:62)
  | at io.fabric8.kubernetes.client.KubernetesClientException.launderThrowable(KubernetesClientException.java:53)
  | at io.fabric8.kubernetes.client.dsl.internal.ExecWebSocketListener.onMessage(ExecWebSocketListener.java:253)
  | at okhttp3.internal.ws.RealWebSocket.onReadMessage(RealWebSocket.java:311)
  | at okhttp3.internal.ws.WebSocketReader.readMessageFrame(WebSocketReader.java:224)
  | at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.java:101)
  | at okhttp3.internal.ws.RealWebSocket.loopReader(RealWebSocket.java:262)
  | at okhttp3.internal.ws.RealWebSocket$2.onResponse(RealWebSocket.java:201)
  | at okhttp3.RealCall$AsyncCall.execute(RealCall.java:141)
  | at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
  | at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
  | at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
  | at java.lang.Thread.run(Thread.java:748)
  | Caused by: java.io.IOException: Read end dead
  | at java.io.PipedInputStream.checkStateForReceive(PipedInputStream.java:262)
  | at java.io.PipedInputStream.awaitSpace(PipedInputStream.java:268)
  | at java.io.PipedInputStream.receive(PipedInputStream.java:231)
  | at java.io.PipedOutputStream.write(PipedOutputStream.java:149)
  | at java.io.OutputStream.write(OutputStream.java:75)
  | at io.fabric8.kubernetes.client.dsl.internal.ExecWebSocketListener.onMessage(ExecWebSocketListener.java:235)
  | ... 10 more
  | 15:41:05.972 [OkHttp https://kubernetes.default.svc/...] ERROR i.f.k.c.d.i.ExecWebSocketListener - Exec Failure: HTTP:0. Message:No response
  | io.fabric8.kubernetes.client.KubernetesClientException: An error has occurred.
  | at io.fabric8.kubernetes.client.KubernetesClientException.launderThrowable(KubernetesClientException.java:62)
  | at io.fabric8.kubernetes.client.KubernetesClientException.launderThrowable(KubernetesClientException.java:53)
  | at io.fabric8.kubernetes.client.dsl.internal.ExecWebSocketListener.onMessage(ExecWebSocketListener.java:253)
  | at okhttp3.internal.ws.RealWebSocket.onReadMessage(RealWebSocket.java:311)
  | at okhttp3.internal.ws.WebSocketReader.readMessageFrame(WebSocketReader.java:224)
  | at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.java:101)
  | at okhttp3.internal.ws.RealWebSocket.loopReader(RealWebSocket.java:262)
  | at okhttp3.internal.ws.RealWebSocket$2.onResponse(RealWebSocket.java:201)
  | at okhttp3.RealCall$AsyncCall.execute(RealCall.java:141)
  | at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
  | at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
  | at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
  | at java.lang.Thread.run(Thread.java:748)
  | Caused by: java.io.IOException: Read end dead
  | at java.io.PipedInputStream.checkStateForReceive(PipedInputStream.java:262)
  | at java.io.PipedInputStream.awaitSpace(PipedInputStream.java:268)
  | at java.io.PipedInputStream.receive(PipedInputStream.java:231)
  | at java.io.PipedOutputStream.write(PipedOutputStream.java:149)
  | at java.io.OutputStream.write(OutputStream.java:75)
  | at io.fabric8.kubernetes.client.dsl.internal.ExecWebSocketListener.onMessage(ExecWebSocketListener.java:235)
  | ... 10 common frames omitted
  | 15:41:05.973 ERROR - zalenium-40000-j4bg8 Failed to execute command [tar, -C, /var/log/cont/, -c, .]
  | io.fabric8.kubernetes.client.KubernetesClientException: An error has occurred.
  | at io.fabric8.kubernetes.client.KubernetesClientException.launderThrowable(KubernetesClientException.java:62)
  | at io.fabric8.kubernetes.client.KubernetesClientException.launderThrowable(KubernetesClientException.java:53)
  | at io.fabric8.kubernetes.client.dsl.internal.ExecWebSocketListener.onMessage(ExecWebSocketListener.java:253)
  | at okhttp3.internal.ws.RealWebSocket.onReadMessage(RealWebSocket.java:311)
  | at okhttp3.internal.ws.WebSocketReader.readMessageFrame(WebSocketReader.java:224)
  | at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.java:101)
  | at okhttp3.internal.ws.RealWebSocket.loopReader(RealWebSocket.java:262)
  | at okhttp3.internal.ws.RealWebSocket$2.onResponse(RealWebSocket.java:201)
  | at okhttp3.RealCall$AsyncCall.execute(RealCall.java:141)
  | at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
  | at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
  | at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
  | at java.lang.Thread.run(Thread.java:748)
  | Caused by: java.io.IOException: Read end dead
  | at java.io.PipedInputStream.checkStateForReceive(PipedInputStream.java:262)
  | at java.io.PipedInputStream.awaitSpace(PipedInputStream.java:268)
  | at java.io.PipedInputStream.receive(PipedInputStream.java:231)
  | at java.io.PipedOutputStream.write(PipedOutputStream.java:149)
  | at java.io.OutputStream.write(OutputStream.java:75)
  | at io.fabric8.kubernetes.client.dsl.internal.ExecWebSocketListener.onMessage(ExecWebSocketListener.java:235)
  | ... 10 more

Maybe it would be good for @diemol to also look at the above-pasted Zalenium logs as well.

mojsha commented 6 years ago

Ok, I had an issue with an OpenShift ruleset, so now the test itself seems to successfully get executed, but I am still getting these errors in the Zalenium log:

--WARN 15:54:35:023878798 We don't have sudo
--
  | Kubernetes service account found.
  | -- LOG 15:54:35:061532712 Running additional checks...
  | Copying files for Dashboard...
  | cp: cannot create regular file '/home/seluser/videos/index.html': No such file or directory
  | cp: cannot create directory '/home/seluser/videos': Permission denied
  | cp: cannot create directory '/home/seluser/videos': Permission denied
  | Starting Nginx reverse proxy...
  | Starting Selenium Hub...
  | mkdir: cannot create directory ‘logs’: Permission denied
  | Can't load log handler "java.util.logging.FileHandler"
  | java.nio.file.NoSuchFileException: /home/seluser/logs/zalenium0.log.lck
  | java.nio.file.NoSuchFileException: /home/seluser/logs/zalenium0.log.lck
  | at sun.nio.fs.UnixException.translateToIOException(UnixException.java:86)
  | at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:102)
  | at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:107)
  | at sun.nio.fs.UnixFileSystemProvider.newFileChannel(UnixFileSystemProvider.java:177)
  | at java.nio.channels.FileChannel.open(FileChannel.java:287)
  | at java.nio.channels.FileChannel.open(FileChannel.java:335)
  | at java.util.logging.FileHandler.openFiles(FileHandler.java:459)
  | at java.util.logging.FileHandler.<init>(FileHandler.java:263)
  | at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
  | at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
  | at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
  | at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
  | at java.lang.Class.newInstance(Class.java:442)
  | at java.util.logging.LogManager$5.run(LogManager.java:966)
  | at java.security.AccessController.doPrivileged(Native Method)
  | at java.util.logging.LogManager.loadLoggerHandlers(LogManager.java:958)
  | at java.util.logging.LogManager.initializeGlobalHandlers(LogManager.java:1578)
  | at java.util.logging.LogManager.access$1500(LogManager.java:145)
  | at java.util.logging.LogManager$RootLogger.accessCheckedHandlers(LogManager.java:1667)
  | at java.util.logging.Logger.getHandlers(Logger.java:1777)
  | at org.openqa.grid.selenium.GridLauncherV3.configureLogging(GridLauncherV3.java:212)
  | at org.openqa.grid.selenium.GridLauncherV3.main(GridLauncherV3.java:92)
  | 15:54:36.598 INFO - Selenium build info: version: '3.6.0', revision: '6fbf3ec767'
  | 15:54:36.604 INFO - Launching Selenium Grid hub
  | 15:54:37.646 INFO - binding de.zalando.ep.zalenium.servlet.LivePreviewServlet to /grid/admin/LivePreviewServlet/*
  | 15:54:37.656 INFO - binding de.zalando.ep.zalenium.servlet.ZaleniumConsoleServlet to /grid/admin/ZaleniumConsoleServlet/*
  | 15:54:37.656 INFO - binding de.zalando.ep.zalenium.servlet.ZaleniumResourceServlet to /grid/admin/ZaleniumResourceServlet/*
  | 15:54:37.657 INFO - binding de.zalando.ep.zalenium.dashboard.DashboardCleanupServlet to /grid/admin/DashboardCleanupServlet/*
  | 15:54:38.109 INFO - Will listen on 4445
  | 15:54:38.248 INFO - Nodes should register to http://10.129.5.7:4445/grid/register/
  | 15:54:38.248 INFO - Selenium Grid hub is up and running
  | ............Selenium Hub started!
  | Starting DockerSeleniumStarter node...
  | Can't load log handler "java.util.logging.FileHandler"
  | java.nio.file.NoSuchFileException: /home/seluser/logs/zalenium0.log.lck
  | java.nio.file.NoSuchFileException: /home/seluser/logs/zalenium0.log.lck
  | at sun.nio.fs.UnixException.translateToIOException(UnixException.java:86)
  | at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:102)
  | at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:107)
  | at sun.nio.fs.UnixFileSystemProvider.newFileChannel(UnixFileSystemProvider.java:177)
  | at java.nio.channels.FileChannel.open(FileChannel.java:287)
  | at java.nio.channels.FileChannel.open(FileChannel.java:335)
  | at java.util.logging.FileHandler.openFiles(FileHandler.java:459)
  | at java.util.logging.FileHandler.<init>(FileHandler.java:263)
  | at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
  | at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
  | at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
  | at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
  | at java.lang.Class.newInstance(Class.java:442)
  | at java.util.logging.LogManager$5.run(LogManager.java:966)
  | at java.security.AccessController.doPrivileged(Native Method)
  | at java.util.logging.LogManager.loadLoggerHandlers(LogManager.java:958)
  | at java.util.logging.LogManager.initializeGlobalHandlers(LogManager.java:1578)
  | at java.util.logging.LogManager.access$1500(LogManager.java:145)
  | at java.util.logging.LogManager$RootLogger.accessCheckedHandlers(LogManager.java:1667)
  | at java.util.logging.Logger.getHandlers(Logger.java:1777)
  | at org.openqa.grid.selenium.GridLauncherV3.configureLogging(GridLauncherV3.java:212)
  | at org.openqa.grid.selenium.GridLauncherV3.main(GridLauncherV3.java:92)
  | 15:54:38.827 INFO - Selenium build info: version: '3.6.0', revision: '6fbf3ec767'
  | 15:54:38.828 INFO - Launching a Selenium Grid node
  | 2017-10-11 15:54:39.255:INFO::main: Logging initialized @735ms to org.seleniumhq.jetty9.util.log.StdErrLog
  | 15:54:39.309 INFO - Driver class not found: com.opera.core.systems.OperaDriver
  | 15:54:39.332 INFO - Driver provider class org.openqa.selenium.ie.InternetExplorerDriver registration is skipped:
  | registration capabilities Capabilities [{ensureCleanSession=true, browserName=internet explorer, version=, platform=WINDOWS}] does not match the current platform LINUX
  | 15:54:39.333 INFO - Driver provider class org.openqa.selenium.edge.EdgeDriver registration is skipped:
  | registration capabilities Capabilities [{browserName=MicrosoftEdge, version=, platform=WINDOWS}] does not match the current platform LINUX
  | 15:54:39.333 INFO - Driver provider class org.openqa.selenium.safari.SafariDriver registration is skipped:
  | registration capabilities Capabilities [{browserName=safari, version=, platform=MAC}] does not match the current platform LINUX
  | 15:54:39.354 INFO - Using the passthrough mode handler
  | 2017-10-11 15:54:39.376:INFO:osjs.Server:main: jetty-9.4.5.v20170502
  | 2017-10-11 15:54:39.400:WARN:osjs.SecurityHandler:main: ServletContext@o.s.j.s.ServletContextHandler@6aba2b86{/,null,STARTING} has uncovered http methods for path: /
  | 2017-10-11 15:54:39.406:INFO:osjsh.ContextHandler:main: Started o.s.j.s.ServletContextHandler@6aba2b86{/,null,AVAILABLE}
  | 2017-10-11 15:54:39.419:INFO:osjs.AbstractConnector:main: Started ServerConnector@36bc55de{HTTP/1.1,[http/1.1]}{0.0.0.0:30000}
  | 2017-10-11 15:54:39.419:INFO:osjs.Server:main: Started @900ms
  | 15:54:39.419 INFO - Selenium Grid node is up and ready to register to the hub
  | 15:54:39.431 INFO - Registering the node to the hub: http://localhost:4444/grid/register
  | 15:54:39.614 INFO - Initialising Kubernetes support
  | 15:54:40.386 INFO - Kubernetes support initialised.
  | Pod name: zalenium-1-r5m7r
  | app label: zalenium
  | zalenium service name: zalenium
  | Kubernetes flavour: OpenShift
  | Selenium Pod Resource Limits: {memory=Quantity(amount=1Gi, format=null, additionalProperties={}), cpu=Quantity(amount=1000m, format=null, additionalProperties={})}
  | Selenium Pod Resource Requests: {memory=Quantity(amount=500Mi, format=null, additionalProperties={}), cpu=Quantity(amount=500m, format=null, additionalProperties={})}
  | 15:54:40.391 INFO - [DS] Capabilities grabbed from the docker-selenium image
  | 15:54:40.395 INFO - Registered a node http://10.129.5.7:30000
  | 15:54:40.396 INFO - About to clean up any left over selenium pods created by Zalenium
  | 15:54:40.396 INFO - The node is registered to the hub and ready to use
  | 15:54:40.445 INFO - [DS]  Setting up 0 nodes...
  | 15:54:40.446 INFO - 0 containers were created, it will take a bit more until all get registered.
  | .........DockerSeleniumStarter node started!
  | Sauce Labs not enabled...
  | Browser Stack not enabled...
  | TestingBot not enabled...
  | Zalenium is now ready!
  | 15:55:02.751 INFO - Mismatched capabilities. Creating a synthetic w3c capability.
  | 15:55:02.757 INFO - Got a request to create a new session: Capabilities [{proxy={httpProxy=172.21.64.14:8080, proxyType=manual, sslProxy=172.21.64.14:8080}, acceptSslCerts=true, acceptInsecureCerts=true, recordVideo=true, browserName=chrome, platformName=ANY, version=, platform=ANY}]
  | 15:55:02.759 INFO - [DS] Starting new node for {proxy={httpProxy=172.21.64.14:8080, proxyType=manual, sslProxy=172.21.64.14:8080}, acceptSslCerts=true, acceptInsecureCerts=true, recordVideo=true, browserName=chrome, platformName=ANY, version=, platform=ANY}.
  | 15:55:02.796 INFO - Pods in the list 0
  | 15:55:18.788 INFO - Registered a node http://10.129.7.92:40000
  | 15:55:18.807 INFO - Trying to create a new session on test slot {seleniumProtocol=WebDriver, acceptSslCerts=true, screen-resolution=1920x1080, tz=Europe/Berlin, browserName=chrome, maxInstances=1, screenResolution=1920x1080, resolution=1920x1080, version=61.0.3163.100, platform=LINUX}
  | 15:55:21.144 INFO - [DS] Container zalenium-40000-jgphm is up after ~6 seconds...
  | 15:55:21.591 INFO - zalenium-40000-jgphm [bash, -c, start-video]
  | 15:55:23.161 INFO - zalenium-40000-jgphm video-rec: started
  | Waiting for ffmpeg video recording to start...
  | .....Videos at /home/seluser/videos/vid_chrome_40000.mp4* started to be recorded! (wait-video-rec.sh)
  |  
  | 15:55:28.343 INFO - http://10.129.7.92:40000 AFTER_SESSION command received. Node should shutdown soon...
  | 15:55:28.344 INFO - zalenium-40000-jgphm [bash, -c, notify 'Zalenium', 'TEST COMPLETED', --icon=/home/seluser/images/completed.png]
  | 15:55:28.972 INFO - zalenium-40000-jgphm
  | 15:55:28.972 INFO - zalenium-40000-jgphm [bash, -c, stop-video]
  | 15:55:34.009 INFO - zalenium-40000-jgphm video-rec: stopped
  | Waiting for video to stop recording...
  | video-rec                        STOPPED   Oct 11 03:55 PM
  | Done waiting for video recording to stop.
  | Video recording stopped
  | --LOG 15:55:33:961876099 -- DEBUG: video-rec-stdout.log ----
  | Input #0, x11grab, from ':55.0+0,0':
  | Duration: N/A, start: 1507730123.044331, bitrate: N/A
  | Stream #0:0: Video: rawvideo (BGR[0] / 0x524742), bgr0, 1920x1080, 10 fps, 10 tbr, 1000k tbn, 10 tbc
  | No pixel format specified, yuv444p for H.264 encoding chosen.
  | Use -pix_fmt yuv420p for compatibility with outdated media players.
  | [libx264 @ 0xeda8c0] using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2 AVX
  | [libx264 @ 0xeda8c0] profile High 4:4:4 Predictive, level 4.0, 4:4:4 8-bit
  | [libx264 @ 0xeda8c0] 264 - core 148 r2643 5c65704 - H.264/MPEG-4 AVC codec - Copyleft 2003-2015 - http://www.videolan.org/x264.html - options: cabac=0 ref=1 deblock=0:0:0 analyse=0:0 me=dia subme=0 psy=0 mixed_ref=0 me_range=16 chroma_me=1 trellis=0 8x8dct=0 cqm=0 deadzone=21,11 fast_pskip=0 chroma_qp_offset=0 threads=9 lookahead_threads=1 sliced_threads=0 nr=0 decimate=1 interlaced=0 bluray_compat=0 constrained_intra=0 bframes=0 weightp=0 keyint=250 keyint_min=10 scenecut=0 intra_refresh=0 rc=cqp mbtree=0 qp=0
  | Output #0, matroska, to '/home/seluser/videos/vid_chrome_40000.mkv':
  | Metadata:
  | encoder         : Lavf56.40.101
  | Stream #0:0: Video: h264 (libx264) (H264 / 0x34363248), yuv444p, 1920x1080, q=-1--1, 10 fps, 1k tbn, 10 tbc
  | Metadata:
  | encoder         : Lavc56.60.100 libx264
  | Stream mapping:
  | Stream #0:0 -> #0:0 (rawvideo (native) -> h264 (libx264))
  | Press [q] to stop, [?] for help
  | frame=    7 fps=0.0 q=0.0 size=       1kB time=00:00:00.00 bitrate=N/A     frame=   12 fps= 12 q=0.0 size=     110kB time=00:00:00.20 bitrate=4487.5kbits/s     frame=   18 fps= 11 q=0.0 size=     164kB time=00:00:00.80 bitrate=1676.9kbits/s     frame=   24 fps= 11 q=0.0 size=     214kB time=00:00:01.40 bitrate=1253.0kbits/s     frame=   29 fps= 11 q=0.0 size=     256kB time=00:00:01.90 bitrate=1103.6kbits/s     frame=   35 fps= 11 q=0.0 size=     306kB time=00:00:02.50 bitrate=1003.7kbits/s     frame=   40 fps= 11 q=0.0 size=     348kB time=00:00:03.00 bitrate= 950.6kbits/s     frame=   45 fps= 10 q=0.0 size=     390kB time=00:00:03.50 bitrate= 912.8kbits/s     frame=   51 fps= 10 q=0.0 size=     440kB time=00:00:04.10 bitrate= 879.8kbits/s     frame=   57 fps= 10 q=0.0 size=     491kB time=00:00:04.70 bitrate= 855.0kbits/s     frame=   63 fps= 10 q=0.0 size=     557kB time=00:00:05.30 bitrate= 860.3kbits/s     --LOG 15:55:29:562429668 Trapped SIGTERM or SIGINT so shutting down ffmpeg gracefully...
  | --LOG 15:55:29:572417202 Will kill VID_TOOL_PID=1041 ...
  | frame=   66 fps= 10 q=-1.0 Lsize=     681kB time=00:00:06.60 bitrate= 845.3kbits/s
  | video:680kB audio:0kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: 0.175259%
  | [libx264 @ 0xeda8c0] frame I:1     Avg QP: 0.00  size:101815
  | [libx264 @ 0xeda8c0] frame P:65    Avg QP: 0.00  size:  9135
  | [libx264 @ 0xeda8c0] mb I  I16..4: 100.0%  0.0%  0.0%
  | [libx264 @ 0xeda8c0] mb P  I16..4: 84.9%  0.0%  0.0%  P16..4:  0.0%  0.0%  0.0%  0.0%  0.0%    skip:15.1%
  | [libx264 @ 0xeda8c0] coded y,u,v intra: 0.1% 0.1% 0.1% inter: 0.0% 0.0% 0.0%
  | [libx264 @ 0xeda8c0] i16 v,h,dc,p: 100%  0%  0%  0%
  | [libx264 @ 0xeda8c0] kb/s:843.14
  | Exiting normally, received signal 2.
  | --LOG 15:55:30:578899615 Tried to kill -SIGTERM VID_TOOL_PID=1041
  | --LOG 15:55:30:583112461 Waiting up to 6s for VID_TOOL_PID=1041 to end with SIGTERM...
  | --LOG 15:55:30:591375954 wait_pid successfully managed to SIGTERM:VID_TOOL_PID=1041 within less than 6s
  | --LOG 15:55:30:595154645 Will try to fix the videos...
  | --LOG 15:55:31:110648355 Fixing perms for /home/seluser/videos/vid_chrome_40000.mkv*
  | --LOG 15:55:31:145072319 Changing video encoding from mkv to mp4...
  | --LOG 15:55:33:561692115 Conversion from mkv to mp4 succeeded!
  | --LOG 15:55:33:566881167 Cleaning up /home/seluser/videos/vid_chrome_40000.mkv ...
  | --LOG 15:55:33:575675701 Optimizing /home/seluser/videos/vid_chrome_40000.mp4 for HTTP streaming...
  | --LOG 15:55:33:662127376 Succeeded to mp4box_retry.sh within 8s
  | --LOG 15:55:33:666061129 ffmpeg shutdown complete.
  | --LOG 15:55:33:995206011 -- DEBUG: video-rec-stderr.log ----
  | libavformat    56. 40.101 / 56. 40.101
  | libavdevice    56.  4.100 / 56.  4.100
  | libavfilter     5. 40.101 /  5. 40.101
  | libavresample   2.  1.  0 /  2.  1.  0
  | libswscale      3.  1.101 /  3.  1.101
  | libswresample   1.  2.101 /  1.  2.101
  | libpostproc    53.  3.100 / 53.  3.100
  | Input #0, matroska,webm, from '/home/seluser/videos/vid_chrome_40000.mkv':
  | Metadata:
  | ENCODER         : Lavf56.40.101
  | Duration: 00:00:06.60, start: 0.000000, bitrate: 845 kb/s
  | Stream #0:0: Video: h264 (High 4:4:4 Predictive), yuv444p, 1920x1080, SAR 1:1 DAR 16:9, 10 fps, 10 tbr, 1k tbn, 20 tbc (default)
  | Metadata:
  | ENCODER         : Lavc56.60.100 libx264
  | DURATION        : 00:00:06.600000000
  | No pixel format specified, yuv444p for H.264 encoding chosen.
  | Use -pix_fmt yuv420p for compatibility with outdated media players.
  | [libx264 @ 0x1bc4320] using SAR=1/1
  | [libx264 @ 0x1bc4320] using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2 AVX
  | [libx264 @ 0x1bc4320] profile High 4:4:4 Predictive, level 4.0, 4:4:4 8-bit
  | [libx264 @ 0x1bc4320] 264 - core 148 r2643 5c65704 - H.264/MPEG-4 AVC codec - Copyleft 2003-2015 - http://www.videolan.org/x264.html - options: cabac=0 ref=1 deblock=0:0:0 analyse=0:0 me=dia subme=0 psy=0 mixed_ref=0 me_range=16 chroma_me=1 trellis=0 8x8dct=0 cqm=0 deadzone=21,11 fast_pskip=0 chroma_qp_offset=0 threads=9 lookahead_threads=1 sliced_threads=0 nr=0 decimate=1 interlaced=0 bluray_compat=0 constrained_intra=0 bframes=0 weightp=0 keyint=250 keyint_min=10 scenecut=0 intra_refresh=0 rc=cqp mbtree=0 qp=0
  | Output #0, mp4, to '/home/seluser/videos/vid_chrome_40000.mp4':
  | Metadata:
  | encoder         : Lavf56.40.101
  | Stream #0:0: Video: h264 (libx264) ([33][0][0][0] / 0x0021), yuv444p, 1920x1080 [SAR 1:1 DAR 16:9], q=-1--1, 10 fps, 10240 tbn, 10 tbc (default)
  | Metadata:
  | DURATION        : 00:00:06.600000000
  | encoder         : Lavc56.60.100 libx264
  | Stream mapping:
  | Stream #0:0 -> #0:0 (h264 (native) -> h264 (libx264))
  | Press [q] to stop, [?] for help
  | frame=   21 fps=0.0 q=0.0 size=     188kB time=00:00:01.10 bitrate=1402.5kbits/s     frame=   38 fps= 35 q=0.0 size=     331kB time=00:00:02.80 bitrate= 967.1kbits/s     frame=   54 fps= 34 q=0.0 size=     464kB time=00:00:04.40 bitrate= 864.8kbits/s     frame=   66 fps= 31 q=-1.0 Lsize=     681kB time=00:00:06.60 bitrate= 845.1kbits/s
  | video:680kB audio:0kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: 0.155866%
  | [libx264 @ 0x1bc4320] frame I:1     Avg QP: 0.00  size:101815
  | [libx264 @ 0x1bc4320] frame P:65    Avg QP: 0.00  size:  9135
  | [libx264 @ 0x1bc4320] mb I  I16..4: 100.0%  0.0%  0.0%
  | [libx264 @ 0x1bc4320] mb P  I16..4: 84.9%  0.0%  0.0%  P16..4:  0.0%  0.0%  0.0%  0.0%  0.0%    skip:15.1%
  | [libx264 @ 0x1bc4320] coded y,u,v intra: 0.1% 0.1% 0.1% inter: 0.0% 0.0% 0.0%
  | [libx264 @ 0x1bc4320] i16 v,h,dc,p: 100%  0%  0%  0%
  | [libx264 @ 0x1bc4320] kb/s:843.14
  |  
  | 15:55:34.202 WARN - http://10.129.7.92:40000 Error while copying the video
  | java.io.FileNotFoundException: /home/seluser/videos/zalenium_bd48daa0-33c1-4fe3-8cd3-d78585a424f3_chrome_LINUX_20171011155534.mp4 (No such file or directory)
  | at java.io.FileOutputStream.open0(Native Method)
  | at java.io.FileOutputStream.open(FileOutputStream.java:270)
  | at java.io.FileOutputStream.<init>(FileOutputStream.java:213)
  | at java.io.FileOutputStream.<init>(FileOutputStream.java:162)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.copyVideos(DockerSeleniumRemoteProxy.java:440)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.processContainerAction(DockerSeleniumRemoteProxy.java:414)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.processContainerAction(DockerSeleniumRemoteProxy.java:403)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.videoRecording(DockerSeleniumRemoteProxy.java:367)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.cleanupNode(DockerSeleniumRemoteProxy.java:487)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.shutdownNode(DockerSeleniumRemoteProxy.java:501)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.afterSession(DockerSeleniumRemoteProxy.java:262)
  | at org.openqa.grid.internal.TestSlot.performAfterSessionEvent(TestSlot.java:247)
  | at org.openqa.grid.internal.Registry._release(Registry.java:129)
  | at org.openqa.grid.internal.Registry.access$100(Registry.java:45)
  | at org.openqa.grid.internal.Registry$1.run(Registry.java:112)
  | at java.lang.Thread.run(Thread.java:748)
  | 15:55:34.204 INFO - zalenium-40000-jgphm [bash, -c, transfer-logs.sh]
  | 15:55:34.390 INFO - zalenium-40000-jgphm
  | 15:55:34.569 WARN - http://10.129.7.92:40000 Error while copying the logs
  | java.io.FileNotFoundException: /home/seluser/videos/logs/zalenium_bd48daa0-33c1-4fe3-8cd3-d78585a424f3_chrome_LINUX_20171011155534/./firefox_browser.log (No such file or directory)
  | at java.io.FileOutputStream.open0(Native Method)
  | at java.io.FileOutputStream.open(FileOutputStream.java:270)
  | at java.io.FileOutputStream.<init>(FileOutputStream.java:213)
  | at java.io.FileOutputStream.<init>(FileOutputStream.java:162)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.copyLogs(DockerSeleniumRemoteProxy.java:473)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.processContainerAction(DockerSeleniumRemoteProxy.java:417)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.processContainerAction(DockerSeleniumRemoteProxy.java:403)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.cleanupNode(DockerSeleniumRemoteProxy.java:488)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.shutdownNode(DockerSeleniumRemoteProxy.java:501)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.afterSession(DockerSeleniumRemoteProxy.java:262)
  | at org.openqa.grid.internal.TestSlot.performAfterSessionEvent(TestSlot.java:247)
  | at org.openqa.grid.internal.Registry._release(Registry.java:129)
  | at org.openqa.grid.internal.Registry.access$100(Registry.java:45)
  | at org.openqa.grid.internal.Registry$1.run(Registry.java:112)
  | at java.lang.Thread.run(Thread.java:748)
  | 15:55:34.569 INFO - zalenium-40000-jgphm [bash, -c, cleanup-container.sh]
  | 15:55:34.812 INFO - zalenium-40000-jgphm
  | 15:55:34.825 WARN - Error while updating the dashboard.
  | java.io.IOException: Directory '/home/seluser/videos' could not be created
  | at org.apache.commons.io.FileUtils.openOutputStream(FileUtils.java:356)
  | at org.apache.commons.io.FileUtils.writeStringToFile(FileUtils.java:1981)
  | at org.apache.commons.io.FileUtils.writeStringToFile(FileUtils.java:1947)
  | at de.zalando.ep.zalenium.dashboard.Dashboard.updateDashboard(Dashboard.java:89)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.cleanupNode(DockerSeleniumRemoteProxy.java:491)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.shutdownNode(DockerSeleniumRemoteProxy.java:501)
  | at de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy.afterSession(DockerSeleniumRemoteProxy.java:262)
  | at org.openqa.grid.internal.TestSlot.performAfterSessionEvent(TestSlot.java:247)
  | at org.openqa.grid.internal.Registry._release(Registry.java:129)
  | at org.openqa.grid.internal.Registry.access$100(Registry.java:45)
  | at org.openqa.grid.internal.Registry$1.run(Registry.java:112)
  | at java.lang.Thread.run(Thread.java:748)
  | 15:55:34.952 INFO - http://10.129.7.92:40000 Marking the node as down because it was stopped after 1 tests.
  | 15:55:34.952 INFO - http://10.129.7.92:40000 Marking the node as down because it was stopped after 1 tests.
  | 15:55:34.952 WARN - Cleaning up stale test sessions on the unregistered node http://10.129.7.92:40000
  | 15:55:35.210 ERROR - zalenium-40000-jgphm Failed to execute command [tar, -C, /videos/, -c, .]
  | io.fabric8.kubernetes.client.KubernetesClientException: An error has occurred.
  | at io.fabric8.kubernetes.client.KubernetesClientException.launderThrowable(KubernetesClientException.java:62)
  | at io.fabric8.kubernetes.client.KubernetesClientException.launderThrowable(KubernetesClientException.java:53)
  | at io.fabric8.kubernetes.client.dsl.internal.ExecWebSocketListener.onMessage(ExecWebSocketListener.java:253)
  | at okhttp3.internal.ws.RealWebSocket.onReadMessage(RealWebSocket.java:311)
  | at okhttp3.internal.ws.WebSocketReader.readMessageFrame(WebSocketReader.java:224)
  | at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.java:101)
  | at okhttp3.internal.ws.RealWebSocket.loopReader(RealWebSocket.java:262)
  | at okhttp3.internal.ws.RealWebSocket$2.onResponse(RealWebSocket.java:201)
  | at okhttp3.RealCall$AsyncCall.execute(RealCall.java:141)
  | at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
  | at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
  | at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
  | at java.lang.Thread.run(Thread.java:748)
  | Caused by: java.io.IOException: Read end dead
  | at java.io.PipedInputStream.checkStateForReceive(PipedInputStream.java:262)
  | at java.io.PipedInputStream.awaitSpace(PipedInputStream.java:268)
  | at java.io.PipedInputStream.receive(PipedInputStream.java:231)
  | at java.io.PipedOutputStream.write(PipedOutputStream.java:149)
  | at java.io.OutputStream.write(OutputStream.java:75)
  | at io.fabric8.kubernetes.client.dsl.internal.ExecWebSocketListener.onMessage(ExecWebSocketListener.java:235)
  | ... 10 more
  | 15:55:35.206 [OkHttp https://kubernetes.default.svc/...] ERROR i.f.k.c.d.i.ExecWebSocketListener - Exec Failure: HTTP:0. Message:No response
  | io.fabric8.kubernetes.client.KubernetesClientException: An error has occurred.
  | at io.fabric8.kubernetes.client.KubernetesClientException.launderThrowable(KubernetesClientException.java:62)
  | at io.fabric8.kubernetes.client.KubernetesClientException.launderThrowable(KubernetesClientException.java:53)
  | at io.fabric8.kubernetes.client.dsl.internal.ExecWebSocketListener.onMessage(ExecWebSocketListener.java:253)
  | at okhttp3.internal.ws.RealWebSocket.onReadMessage(RealWebSocket.java:311)
  | at okhttp3.internal.ws.WebSocketReader.readMessageFrame(WebSocketReader.java:224)
  | at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.java:101)
  | at okhttp3.internal.ws.RealWebSocket.loopReader(RealWebSocket.java:262)
  | at okhttp3.internal.ws.RealWebSocket$2.onResponse(RealWebSocket.java:201)
  | at okhttp3.RealCall$AsyncCall.execute(RealCall.java:141)
  | at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
  | at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
  | at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
  | at java.lang.Thread.run(Thread.java:748)
  | Caused by: java.io.IOException: Read end dead
  | at java.io.PipedInputStream.checkStateForReceive(PipedInputStream.java:262)
  | at java.io.PipedInputStream.awaitSpace(PipedInputStream.java:268)
  | at java.io.PipedInputStream.receive(PipedInputStream.java:231)
  | at java.io.PipedOutputStream.write(PipedOutputStream.java:149)
  | at java.io.OutputStream.write(OutputStream.java:75)
  | at io.fabric8.kubernetes.client.dsl.internal.ExecWebSocketListener.onMessage(ExecWebSocketListener.java:235)
  | ... 10 common frames omitted
  | 15:55:35.568 [OkHttp https://kubernetes.default.svc/...] ERROR i.f.k.c.d.i.ExecWebSocketListener - Exec Failure: HTTP:0. Message:No response
  | io.fabric8.kubernetes.client.KubernetesClientException: An error has occurred.
  | at io.fabric8.kubernetes.client.KubernetesClientException.launderThrowable(KubernetesClientException.java:62)
  | at io.fabric8.kubernetes.client.KubernetesClientException.launderThrowable(KubernetesClientException.java:53)
  | at io.fabric8.kubernetes.client.dsl.internal.ExecWebSocketListener.onMessage(ExecWebSocketListener.java:253)
  | at okhttp3.internal.ws.RealWebSocket.onReadMessage(RealWebSocket.java:311)
  | at okhttp3.internal.ws.WebSocketReader.readMessageFrame(WebSocketReader.java:224)
  | at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.java:101)
  | at okhttp3.internal.ws.RealWebSocket.loopReader(RealWebSocket.java:262)
  | at okhttp3.internal.ws.RealWebSocket$2.onResponse(RealWebSocket.java:201)
  | at okhttp3.RealCall$AsyncCall.execute(RealCall.java:141)
  | at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
  | at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
  | at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
  | at java.lang.Thread.run(Thread.java:748)
  | Caused by: java.io.IOException: Read end dead
  | at java.io.PipedInputStream.checkStateForReceive(PipedInputStream.java:262)
  | at java.io.PipedInputStream.awaitSpace(PipedInputStream.java:268)
  | at java.io.PipedInputStream.receive(PipedInputStream.java:231)
  | at java.io.PipedOutputStream.write(PipedOutputStream.java:149)
  | at java.io.OutputStream.write(OutputStream.java:75)
  | at io.fabric8.kubernetes.client.dsl.internal.ExecWebSocketListener.onMessage(ExecWebSocketListener.java:235)
  | ... 10 common frames omitted
  | 15:55:35.569 ERROR - zalenium-40000-jgphm Failed to execute command [tar, -C, /var/log/cont/, -c, .]
  | io.fabric8.kubernetes.client.KubernetesClientException: An error has occurred.
  | at io.fabric8.kubernetes.client.KubernetesClientException.launderThrowable(KubernetesClientException.java:62)
  | at io.fabric8.kubernetes.client.KubernetesClientException.launderThrowable(KubernetesClientException.java:53)
  | at io.fabric8.kubernetes.client.dsl.internal.ExecWebSocketListener.onMessage(ExecWebSocketListener.java:253)
  | at okhttp3.internal.ws.RealWebSocket.onReadMessage(RealWebSocket.java:311)
  | at okhttp3.internal.ws.WebSocketReader.readMessageFrame(WebSocketReader.java:224)
  | at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.java:101)
  | at okhttp3.internal.ws.RealWebSocket.loopReader(RealWebSocket.java:262)
  | at okhttp3.internal.ws.RealWebSocket$2.onResponse(RealWebSocket.java:201)
  | at okhttp3.RealCall$AsyncCall.execute(RealCall.java:141)
  | at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
  | at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
  | at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
  | at java.lang.Thread.run(Thread.java:748)
  | Caused by: java.io.IOException: Read end dead
  | at java.io.PipedInputStream.checkStateForReceive(PipedInputStream.java:262)
  | at java.io.PipedInputStream.awaitSpace(PipedInputStream.java:268)
  | at java.io.PipedInputStream.receive(PipedInputStream.java:231)
  | at java.io.PipedOutputStream.write(PipedOutputStream.java:149)
  | at java.io.OutputStream.write(OutputStream.java:75)
  | at io.fabric8.kubernetes.client.dsl.internal.ExecWebSocketListener.onMessage(ExecWebSocketListener.java:235)
  | ... 10 more

and the Zalenium dashboard doesn't come up.

elgalu commented 6 years ago

Seems somehow related to how the videos mount permissions are set from OpenShift. Are you sharing this volume? can you paste the relevant OpenShift configuration for that part?

mojsha commented 6 years ago

I am not sharing the volume. This is the template I use to setup Zalenium:

apiVersion: v1
kind: Template
metadata:
  name: zalenium
  annotations:
    "openshift.io/display-name": "Zalenium"
    "description": "Disposable Selenium Grid for use in OpenShift"
message: "A Zalenium grid has been created in your project. Continue to overview to verify that it exists and start the deployment."
parameters:
  - name: "FIREFOX_CONTAINERS"
    displayName: "Number of initial Firefox containers."
    description: "This is the number of Firefox containers that should be created when Zalenium starts up."
    value: "0"
    required: false
  - name: "CHROME_CONTAINERS"
    displayName: "Number of initial Chrome containers."
    description: "This is the number of Chrome containers that should be created when Zalenium starts up."
    value: "0"
    required: false
  - name: "ZALENIUM_KUBERNETES_CPU_REQUEST"
    displayName: "CPU request for the Selenium Pods."
    description: "This is the minimum amount of CPU that the container will be configured with."
    value: "500m"
    required: true
  - name: "ZALENIUM_KUBERNETES_CPU_LIMIT"
    displayName: "CPU Limit for the Selenium Pods."
    description: "This is the maximum amount of CPU that the container will be configured with."
    value: "1000m"
    required: true
  - name: "ZALENIUM_KUBERNETES_MEMORY_REQUEST"
    displayName: "Memory request for the Selenium Pods."
    description: "This is the minimum amount of memory that the container will be configured with."
    value: "500Mi"
    required: true
  - name: "ZALENIUM_KUBERNETES_MEMORY_LIMIT"
    displayName: "Memory limit for the Selenium Pods."
    description: "This is the maximum amount of memory that the container will be configured with."
    value: "1Gi"
    required: true
objects:
- apiVersion: v1
  kind: DeploymentConfig
  metadata:
    generation: 1
    labels:
      app: zalenium
      role: hub
    name: zalenium
  spec:
    replicas: 1
    selector:
      app: zalenium
      role: hub
    strategy:
      activeDeadlineSeconds: 21600
      resources: {}
      rollingParams:
        intervalSeconds: 1
        maxSurge: 25%
        maxUnavailable: 25%
        timeoutSeconds: 600
        updatePeriodSeconds: 1
      type: Rolling
    template:
      metadata:
        labels:
          app: zalenium
          role: hub
      spec:
        containers:
        - args:
          - start
          - --firefoxContainers
          - ${FIREFOX_CONTAINERS}
          - --chromeContainers
          - ${CHROME_CONTAINERS}
          - --seleniumImageName
          - "openshift/elgalu_selenium:3.6.0-p3"
          - --sendAnonymousUsageInfo
          - "false"
          env:
          - name: ZALENIUM_KUBERNETES_CPU_REQUEST
            value: ${ZALENIUM_KUBERNETES_CPU_REQUEST}
          - name: ZALENIUM_KUBERNETES_CPU_LIMIT
            value: ${ZALENIUM_KUBERNETES_CPU_LIMIT}
          - name: ZALENIUM_KUBERNETES_MEMORY_REQUEST
            value: ${ZALENIUM_KUBERNETES_MEMORY_REQUEST}
          - name: ZALENIUM_KUBERNETES_MEMORY_LIMIT
            value: ${ZALENIUM_KUBERNETES_MEMORY_LIMIT}
          image: openshift/dosel_zalenium:3.6.0b
          imagePullPolicy: IfNotPresent
          name: zalenium
          ports:
          - containerPort: 4444
            protocol: TCP
          resources:
            limits:
              cpu: '2'
              memory: 1Gi
            requests:
              cpu: '2'
              memory: 1Gi
          terminationMessagePath: /dev/termination-log
          terminationMessagePolicy: File
        dnsPolicy: ClusterFirst
        restartPolicy: Always
        schedulerName: default-scheduler
        securityContext: {}
        serviceAccount: zalenium
        serviceAccountName: zalenium
        terminationGracePeriodSeconds: 30
    test: false
    triggers:
    - type: ConfigChange
  status:
    availableReplicas: 0
    latestVersion: 0
    observedGeneration: 0
    replicas: 0
    unavailableReplicas: 0
    updatedReplicas: 0
- apiVersion: v1
  kind: Route
  metadata:
    annotations:
      openshift.io/host.generated: "true"
      haproxy.router.openshift.io/timeout: "2000s"
    name: zalenium
  spec:
    tls:
      termination: edge
    to:
      kind: Service
      name: zalenium
      weight: 100
    wildcardPolicy: None
- apiVersion: v1
  kind: Service
  metadata:
    name: zalenium
  spec:
    ports:
    - port: 80
      protocol: TCP
      targetPort: 4444
    selector:
      app: zalenium
    sessionAffinity: None
    type: ClusterIP
  status:
    loadBalancer: {}
- apiVersion: v1
  kind: ServiceAccount
  metadata:
    name: zalenium
diemol commented 6 years ago

@mojsha If you are referring to this error:

  | Copying files for Dashboard...
  | cp: cannot create regular file '/home/seluser/videos/index.html': No such file or directory
  | cp: cannot create directory '/home/seluser/videos': Permission denied
  | cp: cannot create directory '/home/seluser/videos': Permission denied

This happens because you are not mounting any volume to store the videos and related files for the dashboard. Since the files cannot be copied because there is no volume, the dashboard does not show up.

This is quite known, and it is not related to any sudo commands. Can you please mount a volume and try again?

pearj commented 6 years ago

@elgalu, it’s a bit late, but I finally discovered a way to run OpenShift in Travis. This project does it via oc cluster up instead of inside minishift https://github.com/tnozicka/openshift-acme/blob/master/.travis.yml

Not sure if it helps, but it does mean you can have integration tests with OpenShift.

diemol commented 6 years ago

I'll close this one since the job on docker-selenium side is done, one last thing pending on Zalenium's side.