Once started Zalenium goes into a loop of tearing down a container, then starting a new one, without ever reaching the number of `--desiredContainers`. #624

matthew-horrocks · 2018-06-19T05:38:48Z

Zalenium Image Version(s):

REPOSITORY              TAG                 IMAGE ID            CREATED             SIZE
elgalu/selenium         latest              216c5ee3c7f4        2 days ago          1.38GB
dosel/zalenium          latest              863438256003        4 days ago          799MB

Docker Version:
Docker version 17.12.1-ce, build 7390fc6qq

If using docker-compose, version:

docker-compose version 1.20.1, build 5d8c71b
docker-py version: 3.1.4
CPython version: 3.6.4
OpenSSL version: OpenSSL 1.0.1t  3 May 2016

OS:

cat /etc/issue
Ubuntu 16.04.3 LTS \n \l

Docker Command to start Zalenium:
sudo docker-compose up --force-recreate

 # Usage:
    #   docker-compose up --force-recreate
    version: '3'

    services:
      #--------------#
      zalenium:
        privileged: true
        restart: always
        image: dosel/zalenium
        container_name: zalenium
        hostname: zalenium
        tty: true
        volumes:
          - /dev/shm:/dev/shm
          - /tmp/videos:/home/seluser/videos
          - /home/seluser/mounted:/tmp/node/home/seluser/mounted
          - /var/run/docker.sock:/var/run/docker.sock
          - /usr/bin/docker:/usr/bin/docker
        ports:
          - 4444:4444
        command: >
          start --desiredContainers 32
                --screenWidth 1920
                --screenHeight 1080
                --timeZone "Europe/London"
                --videoRecordingEnabled false
                --keepOnlyFailedTests true
                --sauceLabsEnabled false
                --browserStackEnabled false
                --testingBotEnabled false
                --startTunnel false
                --debugEnabled true

Expected Behavior -

Zalenium starts all requested containers.

Actual Behavior -

Once started Zalenium starts a number of containers, then goes into a loop of tearing down a container, then starting a new one, without ever reaching the number of --desiredContainers.

The text was updated successfully, but these errors were encountered:

matthew-horrocks · 2018-06-19T05:43:03Z

startup log;
https://gist.github.com/matthew-horrocks/b9409a3b98d5df5efb79a4b89b00b245

matthew-horrocks · 2018-06-19T05:47:32Z

debug log;
https://drive.google.com/file/d/1ur5tlq-urW6JHehNWSPWC57s5bTnuI-m/view?usp=sharing

pearj · 2018-06-19T09:28:29Z

How much memory does your machine have? 32 containers seems like quite a lot given you’re not using kubernetes. If you make the desiredContainers 10 does it work?

I suspect if you want the scale you’re after you’re going to need to switch to kubernetes. When I run zalenium in kubernetes I assign 1Gb per selenium node and 1/2 a cpu which for you would be 32 GB ram and 16 cores. Which is a pretty large machine. And that’s ignoring zalenium itself and anything else running on the server.

matthew-horrocks · 2018-06-19T09:55:29Z

It's an Azure instance, just running Zalenium... Standard DS5 v2 (16 vcpus, 56 GB memory)

It seems to be a recent update to Zalenium that's caused this error (I had to go back to docker-selenium for a while). I can try rolling back to a previous version and report back.

I do need to look into Kubernetes in Azure and VSTS.

pearj · 2018-06-19T11:05:51Z

@matthew-horrocks what version of zalenium were you running beforehand?

@bramvdklinkenberg is running Zalenium on the Azure Kubernetes Service (AKS) after a little bit of effort, see #603 for some of the detail.

youssefbouzaine · 2018-06-27T11:54:34Z

I have the same issue

matthew-horrocks · 2018-06-27T17:09:45Z

Hi, sorry, I've been away and haven't had time to look at this. I'll roll back the version of zalenium tomorrow and find out when the problem started.

matthew-horrocks · 2018-06-28T12:43:48Z

What's the best way to roll back to a previous Zalenium version? Change the image: dosel/zalenium to image: dosel/zalenium:3.11.0a?

How do I find out what elgalu/selenium image to use?

matthew-horrocks · 2018-07-03T08:15:22Z

nudge @pearj I have free time for this over the next couple of days.

pearj · 2018-07-07T13:51:27Z

@matthew-horrocks yes you can roll back to previous versions that way. Generally, it's a good idea to keep the same selenium version, so for elaglu/selenium choose the latest tag in the 3.11 series or use the 3.11. tag. Good luck

matthew-horrocks · 2018-07-12T19:15:23Z

@pearj finally nailed this to a release.

This bug first appeared in https://github.com/zalando/zalenium/releases/tag/3.11.0f

If I roll back to 3.11.0e, the bug goes away and I can start and use all the 32 containers.

matthew-horrocks · 2018-07-12T19:44:05Z

Ignore this comment. I had a brain fart :)

pearj · 2018-07-13T13:44:03Z

3.11.0f was a fairly significant rewrite of how zalenium starts containers. @dspasojevic did most of the work here, he might have some insight into your problem.

dspasojevic · 2018-07-15T02:29:17Z

Looking at the first set of logs, I see the first container of 40008 started:

�[36mzalenium    |�[0m 05:59:33.215 [AutoStartProxyPoolPoller] INFO  d.z.e.z.p.DockeredSeleniumStarter - Created container [zalenium_IdqIxW] with dimensions [(1920, 1080)] and tz [sun.util.calendar.ZoneInfo[id="Europe/London",offset=0,dstSavings=3600000,useDaylight=true,transitions=242,lastRule=java.util.SimpleTimeZone[id=Europe/London,offset=0,dstSavings=3600000,useDaylight=true,startYear=0,startMode=2,startMonth=2,startDay=-1,startDayOfWeek=1,startTime=3600000,startTimeMode=2,endMode=2,endMonth=9,endDay=-1,endDayOfWeek=1,endTime=3600000,endTimeMode=2]]].
�[36mzalenium    |�[0m 05:59:33.215 [AutoStartProxyPoolPoller] INFO  d.z.e.z.proxy.AutoStartProxySet - Created ContainerCreationStatus [isCreated=true, containerName=zalenium_IdqIxW, containerId=21c8f75bf68af8949e38bcefbdd4a74e9b7be77e665729c8acdca5c88827e319, nodePort=40008].	

�[36mzalenium    |�[0m 05:59:46.328 [Thread-45] INFO  d.z.e.z.registry.ZaleniumRegistry - Registered a node http://172.18.0.11:40008

�[36mzalenium    |�[0m 06:00:13.872 [AutoStartProxyPoolPoller] INFO  d.z.e.z.proxy.AutoStartProxySet - Container zalenium_IdqIxW started after 40657

�[36mzalenium    |�[0m 06:00:13.218 [Thread-45] INFO  d.z.e.z.proxy.AutoStartProxySet - Registered a container 21c8f75bf68af8949e38bcefbdd4a74e9b7be77e665729c8acdca5c88827e319 http://172.18.0.11:40008.
�[36mzalenium    |�[0m 06:00:13.249 [Thread-59] WARN  d.z.e.z.registry.ZaleniumRegistry - Cleaning up stale test sessions on the unregistered node http://172.18.0.11:40008
�[36mzalenium    |�[0m 06:00:13.249 [Thread-59] INFO  d.z.e.z.proxy.AutoStartProxySet - Stopping removed container [21c8f75bf68af8949e38bcefbdd4a74e9b7be77e665729c8acdca5c88827e319].

�[36mzalenium    |�[0m 06:00:17.902 [Thread-59] INFO  d.z.e.z.proxy.AutoStartProxySet - Registered a container 21c8f75bf68af8949e38bcefbdd4a74e9b7be77e665729c8acdca5c88827e319 http://172.18.0.11:40008.

But going missing from the point of view of the docker container a few seconds later:

�[36mzalenium    |�[0m 06:00:19.092 [AutoStartProxyPoolPoller] INFO  d.z.e.z.c.DockerContainerClient - Container ContainerCreationStatus [isCreated=true, containerName=zalenium_IdqIxW, containerId=21c8f75bf68af8949e38bcefbdd4a74e9b7be77e665729c8acdca5c88827e319, nodePort=40008] not found - it is terminated.
�[36mzalenium    |�[0m 06:00:19.154 [AutoStartProxyPoolPoller] INFO  d.z.e.z.proxy.AutoStartProxySet - Container ContainerCreationStatus [isCreated=true, containerName=zalenium_IdqIxW, containerId=21c8f75bf68af8949e38bcefbdd4a74e9b7be77e665729c8acdca5c88827e319, nodePort=40008] is terminated. Removing from tracked set.
�[36mzalenium    |�[0m 06:00:19.155 [AutoStartProxyPoolPoller] INFO  d.z.e.z.p.DockerSeleniumRemoteProxy - 21c8f75bf68af8949e38bcefbdd4a74e9b7be77e665729c8acdca5c88827e319 Marking node down.

Zalenium then attempts to start a new container because 40008 went missing:

�[36mzalenium    |�[0m 06:00:20.156 [AutoStartProxyPoolPoller] INFO  d.z.e.z.proxy.AutoStartProxySet - Autostarting container, because 31 is less than min 32

I don't see anything in the first set of logs that indicates why the containers are being terminated. It would be helpful to see the shutdown reason for those containers if you can get it from your docker instance.

I'll look through the debug logs a little later.

dspasojevic · 2018-07-15T02:30:21Z

@matthew-horrocks do you see the same behaviour when running with - for example - 10 desired containers?

matthew-horrocks · 2018-07-18T14:01:56Z

@dspasojevic --desiredContainers 10 works OK. Set --desiredContainers 11 and the containers get terminated.

dspasojevic · 2018-07-18T22:39:21Z

Thanks. Can you see termination reasons for the containers from docker's point of view?

matthew-horrocks · 2018-07-19T09:26:37Z

What's the best way to get those logs? If a container has been terminated, aren't the logs lost?

pearj · 2018-07-19T13:03:38Z

maybe docker ps -a ?

pearj · 2018-07-19T13:04:17Z

Or it might be in your system logs? journalctl -xe?

matthew-horrocks · 2018-07-23T10:06:07Z

Sorry for the delay getting this info... broke my collar bone a week ago, so out of action for a while :(

got some logs from a failed container...

{"log":"--LOG 11:02:40:510275870 Stopping supervisord to support docker restart...\n","stream":"stdout","time":"2018-07-23T10:02:40.52037923Z"}
{"log":"-- INFO: Docker Img. Version: 3.13.0-267\n","stream":"stdout","time":"2018-07-23T10:02:41.067782358Z"}
{"log":"-- INFO: Chrome..... Version: 67.0.3396.99\n","stream":"stdout","time":"2018-07-23T10:02:41.067810358Z"}
{"log":"-- INFO: Firefox.... Version: 61.0.1\n","stream":"stdout","time":"2018-07-23T10:02:41.067813958Z"}
{"log":"-- INFO: Using Selenium.....: 3.13.0\n","stream":"stdout","time":"2018-07-23T10:02:41.067816758Z"}
{"log":"supervisord --version=4.0.0.dev0\n","stream":"stdout","time":"2018-07-23T10:02:41.670687667Z"}
{"log":"2018-07-23 11:02:41,905 INFO Included extra file \"/etc/supervisor/conf.d/novnc.conf\" during parsing\n","stream":"stdout","time":"2018-07-23T10:02:41.906020034Z"}
{"log":"2018-07-23 11:02:41,905 INFO Included extra file \"/etc/supervisor/conf.d/selenium-hub.conf\" during parsing\n","stream":"stdout","time":"2018-07-23T10:02:41.906041734Z"}
{"log":"2018-07-23 11:02:41,905 INFO Included extra file \"/etc/supervisor/conf.d/selenium-multinode.conf\" during parsing\n","stream":"stdout","time":"2018-07-23T10:02:41.906046134Z"}
{"log":"2018-07-23 11:02:41,905 INFO Included extra file \"/etc/supervisor/conf.d/selenium-node-chrome.conf\" during parsing\n","stream":"stdout","time":"2018-07-23T10:02:41.906049534Z"}
{"log":"2018-07-23 11:02:41,905 INFO Included extra file \"/etc/supervisor/conf.d/selenium-node-firefox.conf\" during parsing\n","stream":"stdout","time":"2018-07-23T10:02:41.906052934Z"}
{"log":"2018-07-23 11:02:41,905 INFO Included extra file \"/etc/supervisor/conf.d/video-rec.conf\" during parsing\n","stream":"stdout","time":"2018-07-23T10:02:41.906163033Z"}
{"log":"2018-07-23 11:02:41,906 INFO Included extra file \"/etc/supervisor/conf.d/vnc.conf\" during parsing\n","stream":"stdout","time":"2018-07-23T10:02:41.906177433Z"}
{"log":"2018-07-23 11:02:41,906 INFO Included extra file \"/etc/supervisor/conf.d/xmanager.conf\" during parsing\n","stream":"stdout","time":"2018-07-23T10:02:41.906181633Z"}
{"log":"2018-07-23 11:02:41,906 INFO Included extra file \"/etc/supervisor/conf.d/xterm.conf\" during parsing\n","stream":"stdout","time":"2018-07-23T10:02:41.906185233Z"}
{"log":"2018-07-23 11:02:41,916 INFO RPC interface 'supervisor' initialized\n","stream":"stdout","time":"2018-07-23T10:02:41.916601692Z"}
{"log":"2018-07-23 11:02:41,916 INFO RPC interface 'supervisor' initialized\n","stream":"stdout","time":"2018-07-23T10:02:41.91711149Z"}
{"log":"2018-07-23 11:02:41,917 INFO supervisord started with pid 201\n","stream":"stdout","time":"2018-07-23T10:02:41.917315789Z"}
{"log":"2018-07-23 11:02:42,919 INFO spawned: 'xmanager' with pid 204\n","stream":"stdout","time":"2018-07-23T10:02:42.920016913Z"}
{"log":"2018-07-23 11:02:42,921 INFO spawned: 'vnc' with pid 205\n","stream":"stdout","time":"2018-07-23T10:02:42.922169405Z"}
{"log":"2018-07-23 11:02:42,923 INFO spawned: 'novnc' with pid 206\n","stream":"stdout","time":"2018-07-23T10:02:42.924254296Z"}
{"log":"2018-07-23 11:02:42,925 INFO spawned: 'selenium-multinode' with pid 207\n","stream":"stdout","time":"2018-07-23T10:02:42.926187989Z"}
{"log":"2018-07-23 11:02:42,927 INFO spawned: 'xterm' with pid 211\n","stream":"stdout","time":"2018-07-23T10:02:42.928149981Z"}
{"log":"2018-07-23 11:02:42,930 INFO success: xterm entered RUNNING state, process has stayed up for \u003e than 0 seconds (startsecs)\n","stream":"stdout","time":"2018-07-23T10:02:42.930734971Z"}
{"log":"2018-07-23 11:02:45,327 INFO success: xmanager entered RUNNING state, process has stayed up for \u003e than 2 seconds (startsecs)\n","stream":"stdout","time":"2018-07-23T10:02:45.327199874Z"}
{"log":"2018-07-23 11:02:45,327 INFO success: vnc entered RUNNING state, process has stayed up for \u003e than 2 seconds (startsecs)\n","stream":"stdout","time":"2018-07-23T10:02:45.327250974Z"}
{"log":"2018-07-23 11:02:45,327 INFO success: novnc entered RUNNING state, process has stayed up for \u003e than 2 seconds (startsecs)\n","stream":"stdout","time":"2018-07-23T10:02:45.327354274Z"}
{"log":"2018-07-23 11:02:46,330 INFO success: selenium-multinode entered RUNNING state, process has stayed up for \u003e than 3 seconds (startsecs)\n","stream":"stdout","time":"2018-07-23T10:02:46.336090579Z"}
{"log":"Trapped SIGTERM/SIGINT/x so shutting down supervisord gracefully...\n","stream":"stdout","time":"2018-07-23T10:03:40.81872395Z"}
{"log":"2018-07-23 11:03:41,231 INFO waiting for xmanager to stop\n","stream":"stdout","time":"2018-07-23T10:03:41.231423744Z"}
{"log":"2018-07-23 11:03:41,231 INFO waiting for vnc to stop\n","stream":"stdout","time":"2018-07-23T10:03:41.231465444Z"}
{"log":"2018-07-23 11:03:41,231 INFO waiting for novnc to stop\n","stream":"stdout","time":"2018-07-23T10:03:41.231469644Z"}
{"log":"2018-07-23 11:03:41,231 INFO waiting for selenium-multinode to stop\n","stream":"stdout","time":"2018-07-23T10:03:41.231489144Z"}
{"log":"2018-07-23 11:03:41,231 INFO waiting for xterm to stop\n","stream":"stdout","time":"2018-07-23T10:03:41.231505944Z"}
{"log":"2018-07-23 11:03:41,231 INFO stopped: xmanager (exit status 0)\n","stream":"stdout","time":"2018-07-23T10:03:41.231902142Z"}
{"log":"2018-07-23 11:03:41,231 INFO stopped: novnc (terminated by SIGTERM)\n","stream":"stdout","time":"2018-07-23T10:03:41.232061542Z"}
{"log":"2018-07-23 11:03:41,236 INFO stopped: vnc (exit status 0)\n","stream":"stdout","time":"2018-07-23T10:03:41.236363125Z"}
{"log":"2018-07-23 11:03:41,243 INFO stopped: selenium-multinode (exit status 137)\n","stream":"stdout","time":"2018-07-23T10:03:41.243340898Z"}
{"log":"2018-07-23 11:03:42,942 INFO stopped: xterm (exit status 150)\n","stream":"stdout","time":"2018-07-23T10:03:42.942313287Z"}
{"log":"2018-07-23 11:03:42,942 WARN received SIGTERM indicating exit request\n","stream":"stdout","time":"2018-07-23T10:03:42.942379987Z"}

journalctl -xe doesn't yield anything.

matthew-horrocks · 2018-07-23T10:22:41Z

I have started docker in debug mode with dockerd --debug - the following extract is from the logging for a container which has been destroyed...

ss@ss:~$ grep 666ec8211c6 file.txt
time="2018-07-23T10:17:37.111682881Z" level=debug msg="Calling POST /containers/666ec8211c66e0754478433e5efcca4bce5972f989c06b23df950119a04d5e21/start"
time="2018-07-23T10:17:37.144929231Z" level=debug msg="e679c49e0d96502238030f4bf4037677a9662c179648dc67603eebb3301b510b (2989458).addSvcRecords(666ec8211c66, 172.18.0.11, <nil>, false) updateSvcRecord sid:e679c49e0d96502238030f4bf4037677a9662c179648dc67603eebb3301b510b"
time="2018-07-23T10:17:37.166363534Z" level=debug msg="e679c49e0d96502238030f4bf4037677a9662c179648dc67603eebb3301b510b (2989458).addSvcRecords(666ec8211c66, 172.18.0.11, <nil>, false) updateSvcRecord sid:e679c49e0d96502238030f4bf4037677a9662c179648dc67603eebb3301b510b"
time="2018-07-23T10:17:37.188047135Z" level=debug msg="EnableService 666ec8211c66e0754478433e5efcca4bce5972f989c06b23df950119a04d5e21 START"
time="2018-07-23T10:17:37.188068435Z" level=debug msg="EnableService 666ec8211c66e0754478433e5efcca4bce5972f989c06b23df950119a04d5e21 DONE"
time="2018-07-23T10:17:37.215371212Z" level=debug msg="bundle dir created" bundle=/var/run/docker/containerd/666ec8211c66e0754478433e5efcca4bce5972f989c06b23df950119a04d5e21 module=libcontainerd namespace=moby root=/var/lib/docker/overlay2/fcbe04c17ccf8788ae1c97caa6f9b3b3b3b86495f78b6806ad2eec7543dfe0ea/merged
time="2018-07-23T10:17:37Z" level=info msg="shim docker-containerd-shim started" address="/containerd-shim/moby/666ec8211c66e0754478433e5efcca4bce5972f989c06b23df950119a04d5e21/shim.sock" debug=true module="containerd/tasks" pid=21785
time="2018-07-23T10:17:37.879645208Z" level=debug msg="sandbox set key processing took 564.978945ms for container 666ec8211c66e0754478433e5efcca4bce5972f989c06b23df950119a04d5e21"
time="2018-07-23T10:17:38.604356631Z" level=debug msg="Name To resolve: 666ec8211c66."
time="2018-07-23T10:17:38.604394830Z" level=debug msg="[resolver] lookup name 666ec8211c66. present without IPv6 address"
time="2018-07-23T10:17:38.604693729Z" level=debug msg="Name To resolve: 666ec8211c66.3vvawaigy1butbjlkbtmqtukhb.ax.internal.cloudapp.net."
time="2018-07-23T10:17:38.604798829Z" level=debug msg="[resolver] query 666ec8211c66.3vvawaigy1butbjlkbtmqtukhb.ax.internal.cloudapp.net. (AAAA) from 172.18.0.11:37512, forwarding to udp:168.63.129.16"
time="2018-07-23T10:17:38.606556021Z" level=debug msg="[resolver] external DNS udp:168.63.129.16 did not return any AAAA records for \"666ec8211c66.3vvawaigy1butbjlkbtmqtukhb.ax.internal.cloudapp.net.\""
time="2018-07-23T10:18:19.290350861Z" level=debug msg="Calling GET /containers/666ec8211c66e0754478433e5efcca4bce5972f989c06b23df950119a04d5e21/json"
time="2018-07-23T10:18:20.063997204Z" level=debug msg="Calling GET /containers/666ec8211c66e0754478433e5efcca4bce5972f989c06b23df950119a04d5e21/json"
time="2018-07-23T10:18:22.571487105Z" level=debug msg="Calling GET /containers/666ec8211c66e0754478433e5efcca4bce5972f989c06b23df950119a04d5e21/json"
time="2018-07-23T10:18:25.243098183Z" level=debug msg="Calling GET /containers/666ec8211c66e0754478433e5efcca4bce5972f989c06b23df950119a04d5e21/json"
time="2018-07-23T10:18:27.610237426Z" level=debug msg="Calling GET /containers/666ec8211c66e0754478433e5efcca4bce5972f989c06b23df950119a04d5e21/json"
time="2018-07-23T10:18:28.862987042Z" level=debug msg="Calling GET /containers/666ec8211c66e0754478433e5efcca4bce5972f989c06b23df950119a04d5e21/json"
time="2018-07-23T10:18:31.748365887Z" level=debug msg="Calling GET /containers/666ec8211c66e0754478433e5efcca4bce5972f989c06b23df950119a04d5e21/json"
time="2018-07-23T10:18:36.592577828Z" level=debug msg="Calling GET /containers/666ec8211c66e0754478433e5efcca4bce5972f989c06b23df950119a04d5e21/json"
time="2018-07-23T10:18:37.774669671Z" level=debug msg="Calling GET /containers/666ec8211c66e0754478433e5efcca4bce5972f989c06b23df950119a04d5e21/json"
time="2018-07-23T10:18:41.732415584Z" level=debug msg="Calling GET /containers/666ec8211c66e0754478433e5efcca4bce5972f989c06b23df950119a04d5e21/json"
time="2018-07-23T10:18:44.262099752Z" level=debug msg="Calling GET /containers/666ec8211c66e0754478433e5efcca4bce5972f989c06b23df950119a04d5e21/json"
time="2018-07-23T10:18:45.442677613Z" level=debug msg="Calling GET /containers/666ec8211c66e0754478433e5efcca4bce5972f989c06b23df950119a04d5e21/json"
time="2018-07-23T10:18:46.184814920Z" level=debug msg="Calling POST /containers/666ec8211c66e0754478433e5efcca4bce5972f989c06b23df950119a04d5e21/stop?t=5"
time="2018-07-23T10:18:46.184872420Z" level=debug msg="Sending kill signal 15 to container 666ec8211c66e0754478433e5efcca4bce5972f989c06b23df950119a04d5e21"
time="2018-07-23T10:18:47.324189167Z" level=debug msg="Calling GET /containers/666ec8211c66e0754478433e5efcca4bce5972f989c06b23df950119a04d5e21/json"
time="2018-07-23T10:18:49Z" level=info msg="shim reaped" id=666ec8211c66e0754478433e5efcca4bce5972f989c06b23df950119a04d5e21 module="containerd/tasks"
time="2018-07-23T10:18:49.938368177Z" level=debug msg="e679c49e0d96502238030f4bf4037677a9662c179648dc67603eebb3301b510b (2989458).deleteSvcRecords(666ec8211c66, 172.18.0.11, <nil>, false) updateSvcRecord sid:e679c49e0d96502238030f4bf4037677a9662c179648dc67603eebb3301b510b "
time="2018-07-23T10:18:51.194656611Z" level=debug msg="Calling GET /containers/666ec8211c66e0754478433e5efcca4bce5972f989c06b23df950119a04d5e21/json"
ss@ss:~$

diemol · 2018-09-17T08:25:41Z

I was trying to reproduce by starting an EC2 instance with Ubuntu, 16CPUs and 64GB RAM. I was able to create the 32 containers without any problem, but what I saw is that the logging is misleading, since the --maxDockerSeleniumContainers parameter is not taking into account when the minimum amount of containers is being created.

I will push a change that should help this issue, and if it does not fix it, at least we will be able to diagnose it better.

in case --desiredContainers is bigger. Should fix #624

) in case --desiredContainers is bigger. Should fix #624

diemol · 2018-09-17T08:45:20Z

Just merged this into master, will release today. So please let us know how it evolves after the release, feel free to reopen the issue in case it does not solve it.

matthew-horrocks · 2018-09-21T13:32:29Z

Hi @diemol I just tried this with 3.14.0c and the same failure occurs...

I turned on debug logging and found

zalenium | 14:23:50.955 [jersey-client-async-executor-0] DEBUG org.apache.http.headers - http-outgoing-754 << HTTP/1.1 200 OK zalenium | 14:23:50.955 [jersey-client-async-executor-0] DEBUG org.apache.http.headers - http-outgoing-754 << Api-Version: 1.35 zalenium | 14:23:50.955 [jersey-client-async-executor-0] DEBUG org.apache.http.headers - http-outgoing-754 << Content-Type: application/json zalenium | 14:23:50.955 [jersey-client-async-executor-0] DEBUG org.apache.http.headers - http-outgoing-754 << Docker-Experimental: false zalenium | 14:23:50.955 [jersey-client-async-executor-0] DEBUG org.apache.http.headers - http-outgoing-754 << Ostype: linux zalenium | 14:23:50.955 [jersey-client-async-executor-0] DEBUG org.apache.http.headers - http-outgoing-754 << Server: Docker/17.12.1-ce (linux) zalenium | 14:23:50.955 [jersey-client-async-executor-0] DEBUG org.apache.http.headers - http-outgoing-754 << Date: Fri, 21 Sep 2018 13:23:50 GMT zalenium | 14:23:50.956 [jersey-client-async-executor-0] DEBUG org.apache.http.headers - http-outgoing-754 << Transfer-Encoding: chunked zalenium | 14:23:50.956 [jersey-client-async-executor-0] DEBUG o.a.h.impl.execchain.MainClientExec - Connection can be kept alive indefinitely zalenium | 14:23:50.956 [jersey-client-async-executor-0] DEBUG org.apache.http.wire - http-outgoing-754 << "rDir":"/var/lib/docker/overlay2/4c3ce06b3a61bbfa058e7980502b38c9bdb1cfd81b0ba184b04bda0794fbee38/diff","WorkDir":"/var/lib/docker/overlay2/4c3ce06b3a61bbfa058e7980502b38c9bdb1cfd81b0ba184b04bda0794fbee38/work"},"Name":"overlay2"},"Mounts":[{"Type":"bind","Source":"/home/seluser/mounted","Destination":"/home/seluser/mounted","Mode":"","RW":true,"Propagation":"rprivate"},{"Type":"bind","Source":"/dev/shm","Destination":"/dev/shm","Mode":"","RW":true,"Propagation":"rprivate"}],"Config":{"Hostname":"51b7dc12f19e","Domainname":"","User":"seluser","AttachStdin":false,"AttachStdout":false,"AttachStderr":false,"ExposedPorts":{"40009":{},"50009":{}},"Tty":false,"OpenStdin":false,"StdinOnce":false,"Env":["SEL_NODEPOLLING_MS=117000","SELENIUM_HUB_HOST=172.18.0.2","TZ=Europe/London","NOVNC_PORT=50009","CHROME=false","SELENIUM_MULTINODE_PORT=40009","WAIT_TIME_OUT_VIDEO_STOP=20s","FIREFOX=false","SCREEN_HEIGHT=1080","WAIT_TIMEOUT=120s","SCREEN_WIDTH=1920","NOVNC=true","SELENIUM_NODE_PARAMS=","SEND_ANONYMOUS_USAGE_INFO=false","GRID=false","MULTINODE=true","VIDEO_STOP_SLEEP_SECS=1","SELENIUM_NODE_REGISTER_CYCLE=15000","ZALENIUM=true","SELENIUM_NODE_HOST={{CONTAINER_IP}}","PICK_ALL_RANDOM_PORTS=false","BUILD_URL=","VNC_PORT=60009","SELENIUM_HUB_PORT=4445","SELENIUM_NODE_PROXY_PARAMS=de.zalando.ep.zalenium.proxy.DockerSeleniumRemoteProxy","PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin","DEBIAN_FRONTEND=","DEBCONF_NONINTERACTIVE_SEEN=","LANG_WHICH=en","LANG_WHERE=US","ENCODING=UTF-8","LANGUAGE=en_US.UTF-8","LANG=en_US.UTF-8","SEL_VER=3.14.0","RUN_DIR=/var/run/sele","NOVNC_SHA=9223e8f2d1c207fb74cb4b8cc243e59d84f9e2f6","WEBSOCKIFY_SHA=cb1508fa495bea4b333173705772c1997559ae4b","FF_LANG=en-US","FF_BASE_URL=https://archive.mozilla.org/pub","FF_PLATFORM=linux-x86_64","FF_INNER_PATH=firefox/releases","FF_COMP=firefox-62.0.tar.bz2","FF_URL=https://archive.mozilla.org/pub/firefox/releases/62.0/linux-x86_64/en-US/firefox-62.0.tar.bz2","GECKOD_URL=https://github.com/mozilla/geckodriver/releases/download","CHROME_URL=https://dl.google.com/linux/direct","CHROME_BASE_DEB_PATH=/home/seluser/chrome-deb/google-chrome","GREP_ONLY_NUMS_VER=[0-9.]{2,20}","CHROME_DRIVER_BASE=chromedriver.storage.googleapis.com","CPU_ARCH=64","CHROME_DRIVER_FILE=chromedriver_linux64.zip","CHROME_DRIVER_URL=https://chromedriver.storage.googleapis.com/2.42/chromedriver_linux64.zip","DEFAULT_SELENIUM_HUB_PORT=24444","DEFAULT_SELENIUM_NODE_CH_PORT=25550","DEFAULT_SELENIUM_NODE_FF_PORT=25551","DEFAULT_SELENIUM_MULTINODE_PORT=25552","DEFAULT_VNC_PORT=25900","DEFAULT_NOVNC_PORT=26080","DEFAULT_SUPERVISOR_HTTP_PORT=19001","FIREFOX_VERSION=62.0","USE_SELENIUM=3","CHROME_FLAVOR=stable","DEBUG=false","RANDOM_PORT_FROM=23100","RANDOM_PORT_TO=29999","USER=seluser","HOME=/home/seluser","VNC_STORE_PWD_FILE=/home/seluser/.vnc/passwd","BIN_UTILS=/usr/bin","MEM_JAVA_PERCENT=80","WAIT_FOREGROUND_RETRY=2s","WAIT_VNC_FOREGROUND_RETRY=6s","XVFB_STARTRETRIES=0","XMANAGER_STARTSECS=2","XMANAGER_STARTRETRIES=3","SCREEN_MAIN_DEPTH=24","SCREEN_SUB_DEPTH=32","DISP_N=-1","MAX_DISPLAY_SEARCH=99","SCREEN_NUM=0","SELENIUM_HUB_PROTO=http","SELENIUM_NODE_CH_PORT=25550","SELENIUM_NODE_FF_PORT=25551","SELENIUM_HUB_PARAMS=","CHROME_ARGS=--no-sandbox --disable-setuid-sandbox --disable-gpu --disable-infobars","CHROME_ADDITIONAL_ARGS=","CHROME_VERBOSELOGGING=true","MAX_INSTANCES=1","MAX_SESSIONS=1","SEL_RELEASE_TIMEOUT_SECS=19000","SEL_BROWSER_TIMEOUT_SECS=16000","SEL_CLEANUPCYCLE_MS=5000","SEL_UNREGISTER_IF_STILL_DOWN_AFTER=2500","no_proxy=localhost","HUB_ENV_no_proxy=localhost","XVFB_CLI_OPTS_TCP=-nolisten tcp -nolisten inet6","XVFB_CLI_OPTS_BASE=-ac -r -cc 4 -accessx -xinerama","XVFB_CLI_OPTS_EXT=+extension Composite +extension RANDR +extension GLX","VNC_START=true","VNC_FROM_PORT=","VNC_TO_PORT=","VNC_CLI_OPTS=-forever -shared","VNC_PASSWORD=no","NOVNC_WAIT_TIMEOUT=5s","SUPERVISOR_HTTP_PORT=19001","SUPERVISOR_HTTP_USERNAME=supervisorweb","SUPERVISOR_HTTP_PASSWORD=somehttpbasicauthpwd","SUPERVISOR_REQUIRED_SRV_LIST=xmanager","SUPERVISOR_NOT_REQUIRED_SRV_LIST1=ignoreMe","SUPERVISOR_NOT_REQUIRED_SRV_LIST2=ignoreMe","SLEEP_SECS_AFTER_KILLING_SUPERVISORD=3","SUPERVISOR_STOPWAITSECS=20","SUPERVISOR_STOPSIGNAL=TERM","SUPERVISOR_KILLASGROUP=false","SUPERVISOR_STOPASGROUP=false","LOG_LEVEL=info","DISABLE_ROLLBACK=false","LOGFILE_MAXBYTES=10MB","LOGFILE_BACKUPS=5","LOGS_DIR=/var/log/cont","VIDEO=false","FFMPEG_FRAME_RATE=10","FFMPEG_CODEC_ARGS=-crf 0 -preset ultrafast -qp 0 -pix_fmt yuv420p","FFMPEG_FINAL_CRF=0","FFMPEG_DRAW_MOUSE=1","VIDEO_TMP_FILE_EXTENSION=mkv","VIDEO_FILE_EXTENSION=mp4","MP4_INTERLEAVES_MEDIA_DATA_CHUNKS_SECS=500","VIDEO_FILE_NAME=","VIDEO_BEFORE_STOP_SLEEP_SECS=1","VIDEO_AFTER_STOP_SLEEP_SECS=0.5","VIDEO_STOPWAITSECS=50","VIDEO_CONVERSION_MAX_WAIT=20s","VIDEO_MP4_FIX_MAX_WAIT=8s","VIDEO_WAIT_VID_TOOL_PID_1st_sig_UP_TO_SECS=6s","VIDEO_WAIT_VID_TOOL_PID_2nd_sig_UP_TO_SECS=2s","VIDEO_WAIT_VID_TOOL_PID_3rd_sig_UP_TO_SECS=1s","VIDEO_STOP_1st_sig_TYPE=SIGTERM","VIDEO_STOP_2nd_sig_TYPE=SIGINT","VIDEO_STOP_3rd_sig_TYPE=SIGKILL","VIDEOS_DIR=/home/seluser/videos","XMANAGER=fluxbox","FLUXBOX_START_MAX_RETRIES=5","TAIL_LOG_LINES=50","SHM_TRY_MOUNT_UNMOUNT=false","SHM_SIZE=512M","ETHERNET_DEVICE_NAME=eth0","XMANAGER_STOP_SIGNAL=TERM","XVFB_STOP_SIGNAL=TERM","XTERM_START=false","XTERM_STOP_SIGNAL=INT","SELENIUM_NODE_FIREFOX_STOP_SIGNAL=TERM","SELENIUM_NODE_CHROME_STOP_SIGNAL=TERM","SELENIUM_MULTINODE_STOP_SIGNAL=TERM","SELENIUM_HUB_STOP_SIGNAL=TERM","VNC_STOP_SIGNAL=TERM","NOVNC_STOP_SIGNAL=TERM","VIDEO_REC_STOP_SIGNAL=INT","DOCKER_SOCK=/var/run/docker.sock","TEST_SLEEPS=0.1","GA_TRACKING_ID=UA-18144954-9","GA_ENDPOINT=https://www.google-analytics.com/collect","GA_API_VERSION=1","LD_LIBRARY_PATH=/usr/lib/x86_64-linux-gnu/","USE_KUBERNETES=false","REMOVE_SELUSER_FROM_SUDOERS_FOR_TESTING=false","SUPERVISOR_PIDFILE=/var/run/sele/supervisord.pid","DOCKER_SELENIUM_STATUS=/var/log/cont/docker-selenium-status.log","VNC_TRYOUT_ERR_LOG=/var/log/cont/vnc-tryouts-stderr","VNC_TRYOUT_OUT_LOG=/var/log/cont/vnc-tryouts-stdout"],"Cmd":["entry.sh"],"ArgsEscaped":true,"Image":"elgalu/selenium:latest","Volumes":null,"WorkingDir":"/home/seluser","Entrypoint":null,"OnBuild":null,"Labels":{"maintainer":"Leo Gallucci <[email protected]>","selenium_chrome_version":"69.0.3497.92","selenium_firefox_version":"62.0","selenium_version":"3.14.0"}},"NetworkSettings":{"Bridge":"","SandboxID":"24384296669d88f8e299341122ea2ecf2b18d8355d828c7d411d2fe7bc5b2764","HairpinMode":false,"LinkLocalIPv6Address":"","LinkLocalIPv6PrefixLen":0,"Ports":{"40009/tcp":null,"50009/tcp":null},"SandboxKey":"/var/run/docker/netns/24384296669d","SecondaryIPAddresses":null,"SecondaryIPv6Addresses":null,"EndpointID":"","Gateway":"","GlobalIPv6Address":"","GlobalIPv6PrefixLen":0,"IPAddress":"","IPPrefixLen":0,"IPv6Gateway":"","MacAddress":"","Networks":{"nwdocker_default":{"IPAMConfig":null,"Links":null,"Aliases":["51b7dc12f19e"],"NetworkID":"a1c2551d804bccc92873ca9cc4b0101e1be1a0781c7faed2d42d995789fcb840","EndpointID":"428d56dfd00a7cd6eccaae010dc88d299ba7db8138e90a0dcd1366d9614799d0","Gateway":"172.18.0.1","IPAddress":"172.18.0.12","IPPrefixLen":16,"IPv6Gateway":"","GlobalIPv6Address":"","GlobalIPv6PrefixLen":0,"MacAddress":"02:42:ac:12:00:0c","DriverOpts":null}}}}[\n]" zalenium | 14:23:50.957 [jersey-client-async-executor-0] DEBUG o.a.h.i.c.DefaultManagedHttpClientConnection - http-outgoing-754: Close connection zalenium | 14:23:50.957 [jersey-client-async-executor-0] DEBUG o.a.h.impl.execchain.MainClientExec - Connection discarded zalenium | 14:23:50.957 [jersey-client-async-executor-0] DEBUG o.a.h.i.c.PoolingHttpClientConnectionManager - Connection released: [id: 754][route: {}->unix://localhost:80][total kept alive: 0; route allocated: 0 of 100; total allocated: 0 of 100] zalenium | 14:23:50.957 [jersey-client-async-executor-0] DEBUG org.apache.http.wire - http-outgoing-754 << "[read] I/O error: Bad file descriptor" zalenium | 14:23:50.957 [AutoStartProxyPoolPoller] DEBUG d.z.e.z.proxy.AutoStartProxySet - [0] proxies are idle and will be removed. zalenium | 14:23:50.957 [AutoStartProxyPoolPoller] DEBUG d.z.e.z.proxy.AutoStartProxySet - Checked containers.

I don't know if the Bad file descriptor errors are anything important.

If I set --desiredContainers to 12, the service starts OK. If I set --desiredContainers to 13, the service fails as in the description above. --maxDockerSeleniumContainers is set to 30.

It seems like this should be re-opened.

matthew-horrocks · 2018-09-21T14:38:43Z

If I set --desiredContainers to 12, the service starts OK. If I set --desiredContainers to 13, the service fails as in the description above.

This now seems inconclusive as the number of --desiredContainers which causes a failure seems to change.

ilusi0npl · 2018-11-01T13:14:19Z

Same here.

Why this bug is closed?

matthew-horrocks · 2018-11-02T11:54:48Z

Nudge @diemol :)

straris · 2018-11-16T13:46:21Z

still there on latest release

diemol · 2018-11-16T13:48:12Z

We'll reopen and check again.

diemol · 2018-12-02T21:30:56Z

Hi all,

Could you please try again with the latest release? Different improvements in the internals have been done, I tried myself to create 32 containers and it went well. So we would like to get some feedback from the latest release https://github.com/zalando/zalenium/releases/tag/3.141.59d

matthew-horrocks · 2018-12-03T10:46:34Z

Hi,

I've tried again with https://github.com/zalando/zalenium/releases/tag/3.141.59d and found that the containers are continually being torn down and recreated.

Please also see bug #786 it appears they are also having the same issue with 3.141.59d

diemol · 2018-12-03T10:48:12Z

Would it be possible to see the log please?

straris · 2018-12-03T11:02:40Z

@diemol just tried with 3.141.59d

zalenium container log

11:58:11.846 [jersey-client-async-executor-0] DEBUG o.a.h.i.c.DefaultManagedHttpClientConnection - http-outgoing-324: Shutdown connection
11:58:11.867 [jersey-client-async-executor-0] DEBUG o.a.h.impl.execchain.MainClientExec - Connection discarded
11:58:11.869 [jersey-client-async-executor-0] DEBUG o.a.h.i.c.DefaultManagedHttpClientConnection - http-outgoing-324: Close connection
11:58:11.871 [jersey-client-async-executor-0] DEBUG o.a.h.i.c.PoolingHttpClientConnectionManager - Connection released: [id: 324][route: {}->unix://localhost:80][total kept alive: 0; route allocated: 0 of 100; total allocated: 0 of 100]
11:58:11.874 [jersey-client-async-executor-0] DEBUG org.apache.http.wire - http-outgoing-324 << "[read] I/O error: Bad file descriptor"
11:58:11.885 [jersey-client-async-executor-2] DEBUG o.a.h.c.protocol.RequestAddCookies - CookieSpec selected: default
11:58:11.888 [jersey-client-async-executor-2] DEBUG o.a.h.c.protocol.RequestAuthCache - Auth cache not set in the context
11:58:11.897 [jersey-client-async-executor-2] DEBUG o.a.h.i.c.PoolingHttpClientConnectionManager - Connection request: [route: {}->unix://localhost:80][total kept alive: 0; route allocated: 0 of 100; total allocated: 0 of 100]
11:58:11.901 [jersey-client-async-executor-2] DEBUG o.a.h.i.c.PoolingHttpClientConnectionManager - Connection leased: [id: 325][route: {}->unix://localhost:80][total kept alive: 0; route allocated: 1 of 100; total allocated: 1 of 100]
11:58:11.908 [jersey-client-async-executor-2] DEBUG o.a.h.impl.execchain.MainClientExec - Opening connection {}->unix://localhost:80
11:58:11.911 [jersey-client-async-executor-2] DEBUG o.a.h.i.c.DefaultHttpClientConnectionOperator - Connecting to localhost/127.0.0.1:80
11:58:11.913 [jersey-client-async-executor-2] DEBUG o.a.h.i.c.DefaultHttpClientConnectionOperator - Connection established [family=PF_UNIX path=]<->[family=PF_UNIX path=/var/run/docker.sock]
11:58:11.914 [jersey-client-async-executor-2] DEBUG o.a.h.impl.execchain.MainClientExec - Executing request GET /containers/5808a1bb7c91d80c513870c1ef6417f4004290720dcc2f407f8d5f6c7ffd058d/json HTTP/1.1
11:58:11.915 [jersey-client-async-executor-2] DEBUG o.a.h.impl.execchain.MainClientExec - Target auth state: UNCHALLENGED
11:58:11.931 [jersey-client-async-executor-2] DEBUG o.a.h.impl.execchain.MainClientExec - Proxy auth state: UNCHALLENGED
11:58:11.932 [jersey-client-async-executor-2] DEBUG org.apache.http.headers - http-outgoing-325 >> GET /containers/5808a1bb7c91d80c513870c1ef6417f4004290720dcc2f407f8d5f6c7ffd058d/json HTTP/1.1
11:58:11.933 [jersey-client-async-executor-2] DEBUG org.apache.http.headers - http-outgoing-325 >> Accept: application/json
11:58:11.936 [jersey-client-async-executor-2] DEBUG org.apache.http.headers - http-outgoing-325 >> User-Agent: Jersey/2.22.2 (Apache HttpClient 4.5)
11:58:11.937 [jersey-client-async-executor-2] DEBUG org.apache.http.headers - http-outgoing-325 >> Host: localhost:80
11:58:11.938 [jersey-client-async-executor-2] DEBUG org.apache.http.headers - http-outgoing-325 >> Connection: Keep-Alive
11:58:11.939 [jersey-client-async-executor-2] DEBUG org.apache.http.headers - http-outgoing-325 >> Accept-Encoding: gzip,deflate
11:58:11.940 [jersey-client-async-executor-2] DEBUG org.apache.http.wire - http-outgoing-325 >> "GET /containers/5808a1bb7c91d80c513870c1ef6417f4004290720dcc2f407f8d5f6c7ffd058d/json HTTP/1.1[\r][\n]"
11:58:11.947 [jersey-client-async-executor-2] DEBUG org.apache.http.wire - http-outgoing-325 >> "Accept: application/json[\r][\n]"
11:58:11.950 [jersey-client-async-executor-2] DEBUG org.apache.http.wire - http-outgoing-325 >> "User-Agent: Jersey/2.22.2 (Apache HttpClient 4.5)[\r][\n]"
11:58:11.951 [jersey-client-async-executor-2] DEBUG org.apache.http.wire - http-outgoing-325 >> "Host: localhost:80[\r][\n]"
11:58:11.952 [jersey-client-async-executor-2] DEBUG org.apache.http.wire - http-outgoing-325 >> "Connection: Keep-Alive[\r][\n]"
11:58:11.952 [jersey-client-async-executor-2] DEBUG org.apache.http.wire - http-outgoing-325 >> "Accept-Encoding: gzip,deflate[\r][\n]"
11:58:11.953 [jersey-client-async-executor-2] DEBUG org.apache.http.wire - http-outgoing-325 >> "[\r][\n]"
11:58:11.961 [jersey-client-async-executor-2] DEBUG org.apache.http.wire - http-outgoing-325 << "HTTP/1.1 200 OK[\r][\n]"
11:58:11.961 [jersey-client-async-executor-2] DEBUG org.apache.http.wire - http-outgoing-325 << "Api-Version: 1.39[\r][\n]"
11:58:11.961 [jersey-client-async-executor-2] DEBUG org.apache.http.wire - http-outgoing-325 << "Content-Type: application/json[\r][\n]"
11:58:11.961 [jersey-client-async-executor-2] DEBUG org.apache.http.wire - http-outgoing-325 << "Docker-Experimental: false[\r][\n]"
11:58:11.961 [jersey-client-async-executor-2] DEBUG org.apache.http.wire - http-outgoing-325 << "Ostype: linux[\r][\n]"
11:58:11.962 [jersey-client-async-executor-2] DEBUG org.apache.http.wire - http-outgoing-325 << "Server: Docker/18.09.0 (linux)[\r][\n]"
11:58:11.963 [jersey-client-async-executor-2] DEBUG org.apache.http.wire - http-outgoing-325 << "Date: Mon, 03 Dec 2018 10:58:11 GMT[\r][\n]"
11:58:11.964 [jersey-client-async-executor-2] DEBUG org.apache.http.wire - http-outgoing-325 << "Transfer-Encoding: chunked[\r][\n]"
11:58:11.965 [jersey-client-async-executor-2] DEBUG org.apache.http.wire - http-outgoing-325 << "[\r][\n]"
11:58:11.965 [jersey-client-async-executor-2] DEBUG org.apache.http.wire - http-outgoing-325 << "3d2c[\r][\n]"
11:58:11.966 [jersey-client-async-executor-2] DEBUG org.apache.http.wire - http-outgoing-325 << "{"Id":"5808a1bb7c91d80c513870c1ef6417f4004290720dcc2f407f8d5f6c7ffd058d","Created":"2018-12-03T10:55:13.908175802Z","Path":"entry.sh","Args":[],"State":{"Status":"running","Running":true,"Paused":false,"Restarting":false,"OOMKilled":false,"Dead":false,"Pid":3970,"ExitCode":0,"Error":"","StartedAt":"2018-12-03T10:55:14.407636394Z","FinishedAt":"0001-01-01T00:00:00Z"},"Image":"sha256:4893edb5b1a82c32fa51c5b5a6302ad1e0a93fe9ac484404973aff07c4ed0038","ResolvConfPath":"/mnt/sda1/var/lib/docker/containers/5808a1bb7c91d80c513870c1ef6417f4004290720dcc2f407f8d5f6c7ffd058d/resolv.conf","HostnamePath":"/mnt/sda1/var/lib/docker/containers/5808a1bb7c91d80c513870c1ef6417f4004290720dcc2f407f8d5f6c7ffd058d/hostname","HostsPath":"/mnt/sda1/var/lib/docker/containers/5808a1bb7c91d80c513870c1ef6417f4004290720dcc2f407f8d5f6c7ffd058d/hosts","LogPath":"/mnt/sda1/var/lib/docker/containers/5808a1bb7c91d80c513870c1ef6417f4004290720dcc2f407f8d5f6c7ffd058d/5808a1bb7c91d80c513870c1ef6417f4004290720dcc2f407f8d5f6c7ffd058d-json.log","Name":"/zalenium_44ZhhS","RestartCount":0,"Driver":"overlay2","Platform":"linux","MountLabel":"","ProcessLabel":"","AppArmorProfile":"","ExecIDs":null,"HostConfig":{"Binds":["/dev/shm:/dev/shm"],"ContainerIDFile":"","LogConfig":{"Type":"json-file","Config":{}},"NetworkMode":"default","PortBindings":null,"RestartPolicy":{"Name":"","MaximumRetryCount":0},"AutoRemove":true,"VolumeDriver":"","VolumesFrom":null,"CapAdd":null,"CapDrop":null,"Dns":null,"DnsOptions":null,"DnsSearch":null,"ExtraHosts":[],"GroupAdd":null,"IpcMode":"shareable","Cgroup":"","Links":null,"OomScoreAdj":0,"PidMode":"","Privileged":true,"PublishAllPorts":false,"ReadonlyRootfs":false,"SecurityOpt":["label=disable"],"UTSMode":"","UsernsMode":"","ShmSize":67108864,"Runtime":"runc","ConsoleSize":[0,0],"Isolation":"","CpuShares":0,"Memory":0,"NanoCpus":0,"CgroupParent":"","BlkioWeight":0,"BlkioWeightDevice":null,"BlkioDeviceReadBps":null,"BlkioDeviceWriteBps":null,"BlkioDeviceReadIOps":null,"BlkioDeviceWriteIOps":null,"CpuPeriod":0,"CpuQuota":0,"CpuRealtimePeriod":0,"CpuRealtimeRuntime":0,"CpusetCpus":"","CpusetMems":"","Devices":null,"DeviceCgroupRules":null,"DiskQuota":0,"KernelMemory":0,"MemoryReservation":0,"MemorySwap":0,"MemorySwappiness":null,"OomKillDisable":false,"PidsLimit":0,"Ulimits":null,"CpuCount":0,"CpuPercent":0,"IOMaximumIOps":0,"IOMaximumBandwidth":0,"MaskedPaths":null,"ReadonlyPaths":null},"GraphDriver":{"Data":{"LowerDir":"/mnt/sda1/var/lib/docker/overlay2/095fae43739899ed9f87c1ed687c79d28bbb1de8723721a47c73b4f6ae25f9ad-init/diff:/mnt/sda1/var/lib/docker/overlay2/b5e869207e3cbaf01b35e959a8ed81d5dd32ac0a9deb432066f1c55813b20433/diff:/mnt/sda1/var/lib/docker/overlay2/1ea3fde648220e7907e1d500b35229c3e7778832b99f3ecfe2b6e123202fd5c7/diff:/mnt/sda1/var/lib/docker/overlay2/a23b798d5a57bb4c27a669d8d0dfe24c07f20e9ec1c17e8a430cda14398fb8b6/diff:/mnt/sda1/var/lib/docker/overlay2/21014d226c9c9cbf00fbdfe43cfcca44de4afc8e7d6f4645f75e6346a5b564f2/diff:/mnt/sda1/var/lib/docker/overlay2/fb708137190f7f375af30d63b631cbe0f3a2952ee7c38ffd499d8ceaf05676e6/diff:/mnt/sda1/var/lib/docker/overlay2/a71e19d20f763889fc3e6c6c9649b1904d73f16b284904a2a6898bc52eb3b101/diff:/mnt/sda1/var/lib/docker/overlay2/c28c2c7d0ebd9be5f39ed5fb8f1c49163ae58abe0222b6a9ca9dec85c684f536/diff:/mnt/sda1/var/lib/docker/overlay2/83e03bbf7b1243f87db8c31efafa9e825047bb129792ff1322879bb3f8a66c99/diff:/mnt/sda1/var/lib/docker/overlay2/fcde6e57d82d718e3094bc2d1481270c8eb2e791765bd757c2b0d39302701051/diff:/mnt/sda1/var/lib/docker/overlay2/0a5ee93efca1e7c89cb46b635269c4cbb7e3367f1ee949b9c30d5da168aa8ec8/diff:/mnt/sda1/var/lib/docker/overlay2/d4e46c9b1216565fb4c302df0493e6352b7932b498e71b518c76af882f529074/diff:/mnt/sda1/var/lib/docker/overlay2/4e130d764005b54b69c8e898fcfe1ad9251ff0f8908f9627bd605885737883c9/diff:/mnt/sda1/var/lib/docker/overlay2/f6e372ffea37916cfc403f2f7c7cc5fec628b8e17ff4ce267701d241d0ea75a6/diff:/mnt/sda1/var/lib/docker/overlay2/d0b82f78ee3c18fb5e381d3eb618e70301fe7899124640bc3286941a1e9094ad/diff:/mnt/sda1/var/lib/docker/overlay2/d8641b78e0aa6d1ed6c1f0cadd3554c94b60be9c810a77f8338359965745486f/diff:/mnt/sda1/var/lib/docker/overlay2/4afbbfa8d16708d2902ac5fc601d7c18c041ae55d5828436448838ba94f2e024/diff:/mnt/sda1/var/lib/docker/overlay2/067e85c87aab03b7e8342a4169c388436a5f0acc222295a46282a2cac9270a16/diff:/mnt/sda1/var/lib/docker/overlay2/666c2ed1ac6a63a6eee485ed670bab46206ab48ebdb7e0bd7ecadf7a45bb0484/diff:/mnt/sda1/var/lib/docker/overlay2/2507b59eb9f46e04b75168beb5574d5986ed2f741aa17a25182c9c44c101214b/diff:/mnt/sda1/var/lib/docker/overlay2/04ddd44dc0939d3e2c1c774b4e39c154d9dfce405d9eda4c4c6091162251129f/diff:/mnt/sda1/var/lib/docker/overlay2/8e411f9f88effec4a48142d33ae6627bbf98472c6805d9bf720844428efc896d/diff:/mnt/sda1/var/lib/docker/overlay2/f791968c3a1c8e674d7b9a636b7ed1a70c81b769d41caf210c3a6b8783856711/diff:/mnt/sda1/var/lib/docker/overlay2/b45b06e4c53e934bb24dfc355910990401cdf26d571935a9e940465017548a87/diff:/mnt/sda1/var/lib/docker/overlay2/175b8575e401025ba96be31f34e3fac82ce3b8861196ff05559a58ea0a83d6e9/diff:/mnt/sda1/var/lib/docker/overlay2/d78998775f8fdcd7920fcee813fe867afc50394590bbbecf295b5b2aa929bbec/diff:/mnt/sda1/var/lib/docker/overlay2/944c8ebf488b534b677e3bf70e71ced1d11903d9624ff7d72382fdbc0a306f1c/diff:/mnt/sda1/var/lib/docker/overlay2/c87d9ec231cbc08c5eed3e2bab24537d79fbec969e6390212207ff1e9fbac7d5/diff:/mnt/sda1/var/lib/docker/overlay2/d2616586582276b81fd7199f5d2dec49356017c046ab6a54fcc58bff0a654508/diff:/mnt/sda1/var/lib/docker/overlay2/df74fd08b04efd22b59dc6ad0ae6f95fbc2312a8cf4a1f73b5e835046aa8979c/diff:/mnt/sda1/var/lib/docker/overlay2/0028cc87914434cedcdee3492ea2d99e547d4b7be6be18832fdbf3eb95ca8ca2/diff:/mnt/sda1/var/lib/docker/overlay2/404644c3d71577fa4118b425c24f61f2e4df944d225c3e0fb849054f2a6292db/diff:/mnt/sda1/var/lib/docker/overlay2/747ccb0f74c95108177856f228eb80ce6bbca2bb5ad5de741d19862ab03faaf0/diff:/mnt/sda1/var/lib/docker/overlay2/33b81f5905c4db8c99b30bc189a708faba498f6e7a0f69201778463c871f44be/diff:/mnt/sda1/var/lib/docker/overlay2/8b6e3f8bb0f00e48c60ab03aa104d032463cd2280f352258a7fc09041e9f5eb5/diff:/mnt/sda1/var/lib/docker/overlay2/62ad8662f690763dc2cdaaf3a56a4d5df37b3e793a2335a579520616718e99a2/diff:/mnt/sda1/var/lib/docker/overlay2/cf4502c760b81387dbfd9c744717f6036dc63807ea8dea8d50f1b561453eb67d/diff:/mnt/sda1/var/lib/docker/overlay2/b174ba684ca90a003c536e681be6e181069a290955fece09d2ca8085f75b6111/diff:/mnt/sda1/var/lib/docker/overlay2/9386ac6d6dc92e5f2960f9527cce646931e89ab9831d5fbead371e1b30b44572/diff:/mnt/sda1/var/lib/docker/overlay2/0d18c44939be28ba734a5b01467406561493f03cadbc64fdb0892f9f8c3a764e/diff:/mnt/sda1/var/lib/docker/overlay2/71c8c079ef10905d0523e5e0ea1b85dbb518d50ed519d0932f0f8ced5d7f4009/diff:/mnt/sda1/var/lib/docker/overlay2/1e7c61d2ed9b35a85ca248e9ed4e8b60b50bbca4d252fee0151f222cbc84f18a/diff:/mnt/sda1/var/lib/docker/overlay2/8c4aad7bfc6e72d9ea7cc609bc3c6eca28ec55b750b9b5ee558a286638d70257/diff:/mnt/sda1/var/lib/docker/overlay2/3ce2796f0ed1481062bf344d07293de06d26d93352ef41e00c7c5d6bb6fbc498/diff:/mnt/sda1/var/lib/docker/overlay2/14ea6d33adb402975277b00cc91da99c8a96ced12d0897ae969c7a6ba54b3222/diff:/mnt/sda1/var/lib/docker/overlay2/e2d04955bcc6f181df0a7123480f30ab6c6098bd97af65bb608bd38dcfd8d1df/diff:/mnt/sda1/var/lib/docker/overlay2/d17faec97fa3723b44c47d13bac2d7debb5b8301a0f93ccb8a9a2ae1cb06394b/diff:/mnt/sda1/var/lib/docker/overlay2/b6743872aad22c3712b569a0af8bf4d347db1406636ed2d5a5d0f28680c5c026/diff:/mnt/sda1/var/lib/docker/overlay2/1e6a96077c4bfa92bfe355d6f4fd3050a27573de559f31986b597312ae0bd8fe/diff:/mnt/sda1/var/lib/docker/overlay2/5af0ed1b966ddea2792453acc38f145809352a1ca8548f0f2c956e14ae10a4c5/diff:/mnt/sda1/var/lib/docker/overlay2/336b3caa16cf9b72cd9711dae10fac64a645d7de64e158d43585ac3e47c58f14/diff:/mnt/sda1/var/lib/docker/overlay2/3c2f37496434e80823705da84dda6ee8ce5ecd08a4e5e938fa8a36f7e64909d3/diff:/mnt/sda1/var/lib/docker/overlay2/d1037e933fd897a8a6ae7b5fa069691eece068b8c4dab0faeb605c328a065c43/diff:/mnt/sda1/va"
11:58:11.970 [jersey-client-async-executor-2] DEBUG org.apache.http.headers - http-outgoing-325 << HTTP/1.1 200 OK
11:58:11.971 [jersey-client-async-executor-2] DEBUG org.apache.http.headers - http-outgoing-325 << Api-Version: 1.39
11:58:11.975 [jersey-client-async-executor-2] DEBUG org.apache.http.headers - http-outgoing-325 << Content-Type: application/json
11:58:11.976 [jersey-client-async-executor-2] DEBUG org.apache.http.headers - http-outgoing-325 << Docker-Experimental: false
11:58:11.977 [jersey-client-async-executor-2] DEBUG org.apache.http.headers - http-outgoing-325 << Ostype: linux
11:58:11.979 [jersey-client-async-executor-2] DEBUG org.apache.http.headers - http-outgoing-325 << Server: Docker/18.09.0 (linux)
11:58:11.980 [jersey-client-async-executor-2] DEBUG org.apache.http.headers - http-outgoing-325 << Date: Mon, 03 Dec 2018 10:58:11 GMT
11:58:11.981 [jersey-client-async-executor-2] DEBUG org.apache.http.headers - http-outgoing-325 << Transfer-Encoding: chunked
11:58:11.982 [jersey-client-async-executor-2] DEBUG o.a.h.impl.execchain.MainClientExec - Connection can be kept alive indefinitely

Started with:

docker run -d -ti --name zalenium -p 4444:4444 -v /var/run/docker.sock:/var/run/docker.sock -v /tmp/videos:/Users/monkey/selenium/videos --privileged dosel/zalenium:3.141.59d start --debugEnabled true --maxTestSessions 20 --seleniumImageName elgalu/selenium:3.141.59-p2 --videoRecordingEnabled false --keepOnlyFailedTests true --maxDockerSeleniumContainers 3

Running on MacOS Mojave 10.14

diemol · 2018-12-03T11:06:47Z

@straris it is a bit confusing, the issue is about not being able to start 32 containers properly, and I kind of see in your log that something goes wrong while running tests. So maybe you can open a new issue describing the problem you have? It is hard for me to understand what is going on when different things get mixed under the same issue, but in the end the logs are not showing the same issue.

straris · 2018-12-03T11:12:56Z

@diemol my mistake, I assumed the issues are connected due to the same exception.
In this case, no tests are actually run, the error keeps looping from the moment zalenium is up.

diemol · 2018-12-03T11:19:52Z

No worries @straris :)
Please create a new issue with the description, in the end the root cause of the issue might be the same one, but it is better to understand the issues separately.

diemol · 2018-12-06T20:56:49Z

Logs from a conversation in Slack
https://gist.github.com/IGenegabus/1e0bce3edf244f5d3e28f50492de8d56

@matthew-horrocks would it be possible to have the logs you got after trying the latest release?

diemol · 2018-12-06T21:17:42Z

Logs for latest release https://gist.github.com/IGenegabus/aa68617103584e76ce4d67ae5eb12d60

* Avoiding the removal part since we don't use the same proxy in a long period of time, and it will likely be removed when the proxy shuts down. * Checking if the proxy has already been registered in a previous request, maybe the current thread is a subsequent registration attempt from the proxy. This fixes #624

diemol · 2018-12-10T16:34:50Z

I was finally able to reproduce this during the weekend, and I pushed a commit that fixes it, which is part of #793.
We will merge this during the week and have a release the next one.

matthew-horrocks · 2018-12-11T12:24:34Z

Great, I'll keep an eye out for the new release.

diemol · 2018-12-17T09:26:03Z

This was fixed in https://github.com/zalando/zalenium/releases/tag/3.141.59e

diemol added a commit that referenced this issue Sep 17, 2018

Creating containers only up to --maxDockerSeleniumContainers says,

94bd2ee

in case --desiredContainers is bigger. Should fix #624

diemol mentioned this issue Sep 17, 2018

Creating containers only up to --maxDockerSeleniumContainers says, #725

Merged

diemol closed this as completed in #725 Sep 17, 2018

diemol added a commit that referenced this issue Sep 17, 2018

Creating containers only up to --maxDockerSeleniumContainers says, (#725

5fc5b53

) in case --desiredContainers is bigger. Should fix #624

diemol reopened this Nov 16, 2018

diemol added the waiting-retest label Dec 2, 2018

diemol mentioned this issue Dec 13, 2018

Unable to start more than 50 containers #786

Closed

diemol closed this as completed in 9ef64b3 Dec 15, 2018

Once started Zalenium goes into a loop of tearing down a container, then starting a new one, without ever reaching the number of --desiredContainers. #624

Once started Zalenium goes into a loop of tearing down a container, then starting a new one, without ever reaching the number of --desiredContainers. #624

Comments

matthew-horrocks commented Jun 19, 2018

Expected Behavior -

Actual Behavior -

matthew-horrocks commented Jun 19, 2018

matthew-horrocks commented Jun 19, 2018

pearj commented Jun 19, 2018

matthew-horrocks commented Jun 19, 2018 • edited Loading

pearj commented Jun 19, 2018

youssefbouzaine commented Jun 27, 2018

matthew-horrocks commented Jun 27, 2018

matthew-horrocks commented Jun 28, 2018

matthew-horrocks commented Jul 3, 2018

pearj commented Jul 7, 2018

matthew-horrocks commented Jul 12, 2018 • edited Loading

matthew-horrocks commented Jul 12, 2018 • edited Loading

pearj commented Jul 13, 2018

dspasojevic commented Jul 15, 2018

dspasojevic commented Jul 15, 2018

matthew-horrocks commented Jul 18, 2018

dspasojevic commented Jul 18, 2018

matthew-horrocks commented Jul 19, 2018

pearj commented Jul 19, 2018

pearj commented Jul 19, 2018

matthew-horrocks commented Jul 23, 2018

matthew-horrocks commented Jul 23, 2018

diemol commented Sep 17, 2018

diemol commented Sep 17, 2018

matthew-horrocks commented Sep 21, 2018

matthew-horrocks commented Sep 21, 2018

ilusi0npl commented Nov 1, 2018

matthew-horrocks commented Nov 2, 2018

straris commented Nov 16, 2018

diemol commented Nov 16, 2018

diemol commented Dec 2, 2018

matthew-horrocks commented Dec 3, 2018

diemol commented Dec 3, 2018

straris commented Dec 3, 2018 • edited by diemol Loading

diemol commented Dec 3, 2018

straris commented Dec 3, 2018 • edited Loading

diemol commented Dec 3, 2018

diemol commented Dec 6, 2018

diemol commented Dec 6, 2018

diemol commented Dec 10, 2018

matthew-horrocks commented Dec 11, 2018

diemol commented Dec 17, 2018

Once started Zalenium goes into a loop of tearing down a container, then starting a new one, without ever reaching the number of `--desiredContainers`. #624

Once started Zalenium goes into a loop of tearing down a container, then starting a new one, without ever reaching the number of `--desiredContainers`. #624

matthew-horrocks commented Jun 19, 2018 •

edited

Loading

matthew-horrocks commented Jul 12, 2018 •

edited

Loading

matthew-horrocks commented Jul 12, 2018 •

edited

Loading

straris commented Dec 3, 2018 •

edited by diemol

Loading

straris commented Dec 3, 2018 •

edited

Loading