dockerrestcommphusion

restcomm phusion baseimage runsv unable to start ./run: file does not exist


I'm following the Restcomm Docker Quick Start Guide. I'm trying to launch restcomm connect on a "large" VM (8GB mem and 4vCPUs) on which I installed docker. I'm behind a corporate http proxy, so running "docker-compose up" out of the box was not enough. I created my own restcomm/restcomm docker image: I cloned the Restcomm-Docker git project and made a few changes:

I added http_proxy and https_proxy ENV instructions in Dockerfile and in scripts/{restcomm_autoconf.sh,restcomm_sslconf.sh} so that all the wgets could work.

I configured the VM ip address in Restcomm-Connect/docker-compose.yml in RCBCONF_STATIC_ADDRESS.

When I build the "custom" docker image, I have some error messages on the apt-get install step:

docker build -t restcomm/restcomm:latest -f Dockerfile .
...
Setting up x11-common (1:7.7+13ubuntu3) ...
update-rc.d: warning: start and stop actions are no longer supported; falling back to defaults
insserv: can not remove(../rc0.d/K01hwclock.sh): No such file or directory
insserv: can not remove(../rc0.d/K01sendsigs): No such file or directory
...

So I checked the original docker image you rely on (phusion/baseimage) and found those odd files:

run -it phusion/baseimage bash
root@3485dcc8fe85:/# ls -l /etc/rc0.d/
ls: cannot access '/etc/rc0.d/K01hwclock.sh': No such file or directory
ls: cannot access '/etc/rc0.d/K01sendsigs': No such file or directory
ls: cannot access '/etc/rc0.d/K02umountnfs.sh': No such file or directory
ls: cannot access '/etc/rc0.d/K03umountfs': No such file or directory
ls: cannot access '/etc/rc0.d/K04umountroot': No such file or directory
ls: cannot access '/etc/rc0.d/K05halt': No such file or directory
total 4
??????????? ? ?    ?      ?            ? K01hwclock.sh
??????????? ? ?    ?      ?            ? K01sendsigs
lrwxrwxrwx. 1 root root  19 May 17  2017 K01syslog-ng -> ../init.d/syslog-ng
lrwxrwxrwx. 1 root root  17 May 10  2017 K01urandom -> ../init.d/urandom
lrwxrwxrwx. 1 root root  20 May 17  2017 K02hwclock.sh -> ../init.d/hwclock.sh
lrwxrwxrwx. 1 root root  18 May 17  2017 K02sendsigs -> ../init.d/sendsigs
??????????? ? ?    ?      ?            ? K02umountnfs.sh
??????????? ? ?    ?      ?            ? K03umountfs
lrwxrwxrwx. 1 root root  22 May 17  2017 K03umountnfs.sh -> ../init.d/umountnfs.sh
lrwxrwxrwx. 1 root root  18 May 17  2017 K04umountfs -> ../init.d/umountfs
??????????? ? ?    ?      ?            ? K04umountroot
??????????? ? ?    ?      ?            ? K05halt
lrwxrwxrwx. 1 root root  20 May 17  2017 K05umountroot -> ../init.d/umountroot
lrwxrwxrwx. 1 root root  14 May 17  2017 K06halt -> ../init.d/halt
-rw-r--r--. 1 root root 353 Jan 19  2016 README
root@3485dcc8fe85:/#

I'm sorry, this is probably a very common issue but found nothing obvious on google.

Then, when I run docker-compose up, I have the following error messages:

restcomm_1  | *** Running /etc/my_init.d/restcomm6.sh...
restcomm_1  | mv: cannot remove '/etc/service/cron/run': No such file or directory
restcomm_1  | mv: cannot remove '/etc/service/sshd/down': No such file or directory
restcomm_1  | mv: cannot remove '/etc/service/sshd/run': No such file or directory
restcomm_1  | mv: cannot remove '/etc/service/syslog-forwarder/run': No such file or directory
restcomm_1  | mv: cannot remove '/etc/service/syslog-ng/run': No such file or directory

Then the following error messages in loop:

restcomm_1  | *** Running /etc/rc.local...
restcomm_1  | *** Booting runit daemon...
restcomm_1  | *** Runit started as PID 281
restcomm_1  | runsv syslog-ng: fatal: unable to start ./run: file does not exist
restcomm_1  | runsv syslog-forwarder: fatal: unable to start ./run: file does not exist
restcomm_1  | runsv cron: fatal: unable to start ./run: file does not exist
restcomm_1  | runsv sshd: fatal: unable to start ./run: file does not exist

I think it's related to the issues I have while building the docker image, but I'm not 100% sure.

I found the following line in Restcomm-Docker/scripts/restcomm-runlevels.sh added as /etc/my_init.d/restcomm6.sh in docker image:

cp -pR /etc/service/* /etc/runit/runsvdir/current/

which is probably the origin of the previous error messages. Should it add only the right scripts?

edit 1: I commented out the following block in Restcomm-Docker/scripts/restcomm-runlevels.sh :

#cd /etc/runit/runsvdir
#ln -s default /etc/runit/runsvdir/current
#cp -pR /etc/service/* /etc/runit/runsvdir/current/
#mv -f /etc/service /service.old && ln -s /etc/runit/runsvdir/current /etc/service

and now the restcomm service starts but I have the feeling that something is started multiple times (might be an inappropriate runit monitoring due to my changes?): I can see the following line and the subsequent log block twice in different threads:

Initializing RVD. Project version: 1.13

and then end up with a binding exception:

restcomm_1  | 21:05:18,291 ERROR [org.mobicents.protocols.mgcp.stack.JainMgcpStackImpl] (RestComm-akka.actor.default-dispatcher-2) java.net.BindException: Address already in use
restcomm_1  | 21:05:18,293 ERROR [org.restcomm.connect.mrb.MediaResourceBrokerGeneric] (RestComm-akka.actor.default-dispatcher-4) Failed to find a local port 2727 to bound stack: java.lang.RuntimeException: Failed to find a local port 2727 to bound stack
restcomm_1  |   at org.mobicents.protocols.mgcp.stack.JainMgcpStackImpl.init(JainMgcpStackImpl.java:172) [mgcp-driver-6.0.23.jar:6.0.23]
restcomm_1  |   at org.mobicents.protocols.mgcp.stack.JainMgcpStackImpl.createProvider(JainMgcpStackImpl.java:250) [mgcp-driver-6.0.23.jar:6.0.23]
restcomm_1  |   at org.restcomm.connect.mrb.MediaResourceBrokerGeneric.bindMGCPStack(MediaResourceBrokerGeneric.java:134) [restcomm-connect.mrb-8.3.0-140.jar:8.3.0-140]
restcomm_1  |   at org.restcomm.connect.mrb.MediaResourceBrokerGeneric.onStartMediaResourceBroker(MediaResourceBrokerGeneric.java:120) [restcomm-connect.mrb-8.3.0-140.jar:8.3.0-140]
restcomm_1  |   at org.restcomm.connect.mrb.MediaResourceBrokerGeneric.onReceive(MediaResourceBrokerGeneric.java:99) [restcomm-connect.mrb-8.3.0-140.jar:8.3.0-140]
restcomm_1  |   at akka.actor.UntypedActor$$anonfun$receive$1.applyOrElse(UntypedActor.scala:159) [akka-actor_2.10-2.1.2.jar:]
restcomm_1  |   at akka.actor.ActorCell.receiveMessage(ActorCell.scala:425) [akka-actor_2.10-2.1.2.jar:]
restcomm_1  |   at akka.actor.ActorCell.invoke(ActorCell.scala:386) [akka-actor_2.10-2.1.2.jar:]
restcomm_1  |   at akka.dispatch.Mailbox.processMailbox(Mailbox.scala:230) [akka-actor_2.10-2.1.2.jar:]
restcomm_1  |   at akka.dispatch.Mailbox.run(Mailbox.scala:212) [akka-actor_2.10-2.1.2.jar:]
restcomm_1  |   at akka.dispatch.ForkJoinExecutorConfigurator$MailboxExecutionTask.exec(AbstractDispatcher.scala:506) [akka-actor_2.10-2.1.2.jar:]
restcomm_1  |   at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:262) [scala-library-2.10.1.jar:]
restcomm_1  |   at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:975) [scala-library-2.10.1.jar:]
restcomm_1  |   at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1478) [scala-library-2.10.1.jar:]
restcomm_1  |   at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:104) [scala-library-2.10.1.jar:]

Solution

  • I found where the problem was coming from. It was related to the docker /var/lib/docker underlying filesystem. I had an xfs file system which was not formated with d_type support. I attached a new volume to my (openstack) VM, formatted it with d_type parameter and it worked! Actually, without this option, it messed the phusion/baseimage and then indirectly the restcomm image that relied on this image.

    Here are the details:

    # docker info
    ...
    Storage Driver: overlay
     Backing Filesystem: xfs
     Supports d_type: false
    ...
    WARNING: overlay: the backing xfs filesystem is formatted without d_type support, which leads to incorrect behavior.
             Reformat the filesystem with ftype=1 to enable d_type support.
             Running without d_type support will not be supported in future releases.
    

    This is how I found the issue. Confirmed with xfs_info: ftype=0, should be 1

    [root@yohann telestax]# xfs_info /
    meta-data=/dev/vda1              isize=256    agcount=10, agsize=524224 blks
             =                       sectsz=512   attr=2, projid32bit=1
             =                       crc=0        finobt=0 spinodes=0
    data     =                       bsize=4096   blocks=5240950, imaxpct=25
             =                       sunit=0      swidth=0 blks
    naming   =version 2              bsize=4096   ascii-ci=0 ftype=0
    log      =internal               bsize=4096   blocks=2560, version=2
             =                       sectsz=512   sunit=0 blks, lazy-count=1
    realtime =none                   extsz=4096   blocks=0, rtextents=0
    [root@yohann telestax]#
    

    created a new volume on openstack

    attached this volume to the running instance

    (device created was /dev/vdb)

    create a partition using "fdisk /dev/vdb"

    Commands: n, p, 1 and default

    Then "w" to write the partition table

    create an xfs file system on this partition with the right parameters:

    [root@yohann centos]# mkfs.xfs -n ftype=1 /dev/vdb1
    meta-data=/dev/vdb1              isize=512    agcount=4, agsize=655296 blks
             =                       sectsz=512   attr=2, projid32bit=1
             =                       crc=1        finobt=0, sparse=0
    data     =                       bsize=4096   blocks=2621184, imaxpct=25
             =                       sunit=0      swidth=0 blks
    naming   =version 2              bsize=4096   ascii-ci=0 ftype=1
    log      =internal log           bsize=4096   blocks=2560, version=2
             =                       sectsz=512   sunit=0 blks, lazy-count=1
    realtime =none                   extsz=4096   blocks=0, rtextents=0
    [root@yohann centos]#
    

    with docker stopped, mount this file system:

    rm -fr /var/lib/docker
    mkdir /var/lib/docker
    mount /dev/vdb1 /var/lib/docker/
    

    Then, docker info gave the right details:

    docker info
    ...
    Storage Driver: overlay
     Backing Filesystem: xfs
     Supports d_type: true
    ...
    (no more warning)
    

    tried with baseimage successfully:

    [root@yohann centos]# docker run -it phusion/baseimage bash
    Unable to find image 'phusion/baseimage:latest' locally
    latest: Pulling from phusion/baseimage
    22ecafbbcc4a: Pull complete
    580435e0a086: Pull complete
    8321ffd10031: Pull complete
    08b8f28a13c2: Pull complete
    2b401702069a: Pull complete
    a3ed95caeb02: Pull complete
    eae027dcdc0e: Pull complete
    93bc98227159: Pull complete
    Digest: sha256:d7507394a2e31759297a8726ac1f61e1c135b5255f8be42e7081d85b6fb3f903
    Status: Downloaded newer image for phusion/baseimage:latest
    root@4a3b26f2748e:/# ls -l /etc/rc0.d/
    total 4
    lrwxrwxrwx.  1 root root  19 May 17  2017 K01syslog-ng -> ../init.d/syslog-ng
    lrwxrwxrwx.  1 root root  17 May 10  2017 K01urandom -> ../init.d/urandom
    lrwxrwxrwx.  1 root root  20 May 17  2017 K02hwclock.sh -> ../init.d/hwclock.sh
    lrwxrwxrwx.  1 root root  18 May 17  2017 K02sendsigs -> ../init.d/sendsigs
    lrwxrwxrwx.  1 root root  22 May 17  2017 K03umountnfs.sh -> ../init.d/umountnfs.sh
    lrwxrwxrwx.  1 root root  18 May 17  2017 K04umountfs -> ../init.d/umountfs
    lrwxrwxrwx.  1 root root  20 May 17  2017 K05umountroot -> ../init.d/umountroot
    lrwxrwxrwx.  1 root root  14 May 17  2017 K06halt -> ../init.d/halt
    -rw-r--r--. 13 root root 353 Jan 19  2016 README
    root@4a3b26f2748e:/# exit
    [root@yohann centos]#
    

    (no more symlink issues)

    Then, I rebuilt the restcomm docker image and ran it again using "docker-compose up".

    I tested with https://myip:8443 administrator@company.com, password: RestComm

    and it worked! (and it was not related to a tainted image over http).