After Incus upgraded, I cannot start mysql oci container anymore

Hello,

I used MySQL database container that used as demo in first announce of Incus support for OCI

after I upgraded incus and restart the pc, I cannot start the container anymore

what I’m getting is the following

 To detach from the console, press: <ctrl>+a q
2024-08-06T13:58:56.714197Z 0 [System] [MY-015018] [Server] MySQL Server Initialization - end.
2024-08-06 13:58:56+00:00 [Note] [Entrypoint]: Database files initialized
2024-08-06 13:58:56+00:00 [Note] [Entrypoint]: Starting temporary server
mysqld will log errors to /var/lib/mysql/mysql.err
2024-08-06T13:58:57.149398Z 0 [ERROR] [MY-010946] [Server] Failed to start mysqld daemon. Check mysqld error log.
2024-08-06 13:58:57+00:00 [ERROR] [Entrypoint]: Unable to start server.
Error: write /dev/pts/ptmx: file already closed

start command:

$ incus start mysql

Best Regards

incus file pull mysql/var/lib/mysql/mysql.err - so you can see why the DB is failing to start.

nothing specified

2024-07-17T11:47:11.689223Z 0 [System] [MY-015015] [Server] MySQL Server - start.
2024-07-17T11:47:11.892531Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 9.0.0) starting as process 152
2024-07-17T11:47:11.920021Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2024-07-17T11:47:12.538640Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2024-07-17T11:47:12.995016Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2024-07-17T11:47:12.995034Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
2024-07-17T11:47:13.004886Z 0 [Warning] [MY-011810] [Server] Insecure configuration for --pid-file: Location '/var/run/mysqld' in the path is accessible to all OS users. Consider choosing a different directory.
2024-07-17T11:47:13.020836Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Socket: /var/run/mysqld/mysqlx.sock
2024-07-17T11:47:13.020876Z 0 [System] [MY-010931] [Server] /usr/sbin/mysqld: ready for connections. Version: '9.0.0'  socket: '/var/run/mysqld/mysqld.sock'  port: 0  MySQL Community Server - GPL.
2024-07-17T11:47:14.083855Z 13 [System] [MY-013172] [Server] Received SHUTDOWN from user root. Shutting down mysqld (Version: 9.0.0).
2024-07-17T11:47:15.289611Z 0 [System] [MY-010910] [Server] /usr/sbin/mysqld: Shutdown complete (mysqld 9.0.0)  MySQL Community Server - GPL.
2024-07-17T11:47:15.289625Z 0 [System] [MY-015016] [Server] MySQL Server - end.

Given you started the container on the 6th of August and that log file shows the 17th of July, there’s either something preventing it from logging or mysql is failing so early it didn’t get to log yet.

Can you show incus config show --expanded mysql?

$ incus config show --expanded mysql
architecture: x86_64
config:
  environment.GOSU_VERSION: "1.17"
  environment.HOME: /root
  environment.MYSQL_DATABASE: wordpress
  environment.MYSQL_MAJOR: innovation
  environment.MYSQL_PASSWORD: wordpress
  environment.MYSQL_RANDOM_ROOT_PASSWORD: "1"
  environment.MYSQL_SHELL_VERSION: 9.0.0-1.el9
  environment.MYSQL_USER: wordpress
  environment.MYSQL_VERSION: 9.0.0-1.el9
  environment.PATH: /usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
  environment.TERM: xterm
  image.architecture: x86_64
  image.description: docker.io/library/mysql (OCI)
  image.type: oci
  volatile.base_image: 72a37ddc9f839cfd84f1f6815fb31ba26f37f4c200b90e49607797480e3be446
  volatile.cloud-init.instance-id: 039c379f-11fc-495c-8ba8-b3351c67dde3
  volatile.container.oci: "true"
  volatile.eth0.hwaddr: 00:16:3e:f0:e8:9e
  volatile.idmap.base: "0"
  volatile.idmap.current: '[{"Isuid":true,"Isgid":false,"Hostid":1000000,"Nsid":0,"Maprange":1000000000},{"Isuid":false,"Isgid":true,"Hostid":1000000,"Nsid":0,"Maprange":1000000000}]'
  volatile.idmap.next: '[{"Isuid":true,"Isgid":false,"Hostid":1000000,"Nsid":0,"Maprange":1000000000},{"Isuid":false,"Isgid":true,"Hostid":1000000,"Nsid":0,"Maprange":1000000000}]'
  volatile.last_state.idmap: '[]'
  volatile.last_state.power: STOPPED
  volatile.last_state.ready: "false"
  volatile.uuid: d4a7a872-35e8-4d64-8e0c-31388def5e7a
  volatile.uuid.generation: d4a7a872-35e8-4d64-8e0c-31388def5e7a
devices:
  eth0:
    name: eth0
    network: incusbr0
    type: nic
  root:
    path: /
    pool: default
    type: disk
ephemeral: false
profiles:
- default
stateful: false
description: ""

I didn’t change anything in the config from first time I run it

Does it happen with a new mysql container too?

No, it works fine as I just created new mysql database by the following command

$ incus launch docker:mysql mysql2 \
 -c environment.MYSQL_DATABASE=wordpress \
 -c environment.MYSQL_USER=wordpress \
 -c environment.MYSQL_PASSWORD=wordpress \
 -c environment.MYSQL_RANDOM_ROOT_PASSWORD=1

the config info

$ incus config show --expanded mysql2
architecture: x86_64
config:
  environment.GOSU_VERSION: "1.17"
  environment.HOME: /root
  environment.MYSQL_DATABASE: wordpress
  environment.MYSQL_MAJOR: innovation
  environment.MYSQL_PASSWORD: wordpress
  environment.MYSQL_RANDOM_ROOT_PASSWORD: "1"
  environment.MYSQL_SHELL_VERSION: 9.0.1-1.el9
  environment.MYSQL_USER: wordpress
  environment.MYSQL_VERSION: 9.0.1-1.el9
  environment.PATH: /usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
  environment.TERM: xterm
  image.architecture: x86_64
  image.description: docker.io/library/mysql (OCI)
  image.type: oci
  volatile.base_image: d8df069848906979fd7511db00dc22efeb0a33a990d87c3c6d3fcdafd6fc6123
  volatile.cloud-init.instance-id: cc117d59-ba96-4f01-87dd-8da8fc4849fd
  volatile.container.oci: "true"
  volatile.eth0.host_name: vetha65a316a
  volatile.eth0.hwaddr: 00:16:3e:5b:51:b8
  volatile.idmap.base: "0"
  volatile.idmap.current: '[{"Isuid":true,"Isgid":false,"Hostid":1000000,"Nsid":0,"Maprange":1000000000},{"Isuid":false,"Isgid":true,"Hostid":1000000,"Nsid":0,"Maprange":1000000000}]'
  volatile.idmap.next: '[{"Isuid":true,"Isgid":false,"Hostid":1000000,"Nsid":0,"Maprange":1000000000},{"Isuid":false,"Isgid":true,"Hostid":1000000,"Nsid":0,"Maprange":1000000000}]'
  volatile.last_state.idmap: '[]'
  volatile.last_state.power: RUNNING
  volatile.uuid: 65c52b5b-a017-45ba-bcb4-1d16b4878bae
  volatile.uuid.generation: 65c52b5b-a017-45ba-bcb4-1d16b4878bae
devices:
  eth0:
    name: eth0
    network: incusbr0
    type: nic
  root:
    path: /
    pool: default
    type: disk
ephemeral: false
profiles:
- default
stateful: false
description: ""

Okay, so it’s indeed some kind of issue with the data on your existing container.

What storage pool are you using? Could it have run out of disk space?

There about 360GB left, I can clear some space

Okay, that’s not too likely to be the problem then.

You can probably use something like:

  • mkdir ~/mysql-container
  • incus file mount mysql/ ~/mysql-container

Which should then let you explore ~/mysql-container to try and figure out what’s preventing that container from starting. For example looking for any recently modified log file.

1 Like

I got way mysql.err is outdated
turn out if container is stopped then the incus pull old file but when container is running it get the correct file

$ incus start mysql && sleep 3 && incus file pull mysql/var/lib/mysql/mysql.err .
$ cat mysql.err 
2024-08-09T20:55:19.275123Z 0 [System] [MY-015015] [Server] MySQL Server - start.
2024-08-09T20:55:19.458631Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 9.0.0) starting as process 153
2024-08-09T20:55:19.468015Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2024-08-09T20:55:19.554199Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2024-08-09T20:55:19.588329Z 0 [ERROR] [MY-011292] [Server] Plugin mysqlx reported: 'Preparation of I/O interfaces failed, X Protocol won't be accessible'
2024-08-09T20:55:19.588345Z 0 [ERROR] [MY-011300] [Server] Plugin mysqlx reported: 'Setup of socket: '/var/run/mysqld/mysqlx.sock' failed, another process with PID 21 is using UNIX socket file'
2024-08-09T20:55:19.672840Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2024-08-09T20:55:19.672852Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
2024-08-09T20:55:19.673935Z 0 [ERROR] [MY-010259] [Server] Another process with pid 21 is using unix socket file.
2024-08-09T20:55:19.673940Z 0 [ERROR] [MY-010268] [Server] Unable to setup unix socket lock file.
2024-08-09T20:55:19.673944Z 0 [ERROR] [MY-010119] [Server] Aborting

look like there something other use the PID of mysql of my container, I didn’t run anything

as I understand the issue is somehow related to docker volume (in my case I use Incus)

what is possible solution for it?

I followed the following suggestion mysql - Docker db container running. Another process with pid <id> is using unix socket file - Stack Overflow and it solved the issue

1 Like

@stgraber I restart my PC today and same issue happen again, it become annoying and OCI is not reliable

From that post you linked to, does running:

incus file delete mysql/_data/mysql.sock
incus file delete mysql/_data/mysql.sock.lock

Help with the issue

Yes, that helped but I don’t know why it happen?

execute that command make me lost the database content but it come back and running

It says that another process, with PID 21 (in that case) is using the Unix socket file.

Therefore, start again the container and look for the updated error that says that some other process with the given PID (Process ID) is interfering.
With the new PID at hand, you can run ps ax and identify what other process is messing with the Unix socket.