docker-library / mysql

Docker Official Image packaging for MySQL Community Server
https://dev.mysql.com/
GNU General Public License v2.0
2.42k stars 2.18k forks source link

Kubernetes CrashLoopBackOff where attempting to upgrade from mysql 5.7.x to 8.0.34 #1041

Open macmule opened 2 months ago

macmule commented 2 months ago

Hi folks,

We've been running various flavours of mysql 5.7.x for a few years, and now one of the items we're hosting requires 8.0.34 (prior release was 5.7.39).

In attempting to upgrade the deployment, it seems that the /usr/local/bin/docker-entrypoint.sh runs once as root and then attempts to run as the user mysql.. this latter step fails.. and then we have no logging to advise why (despite passing --verbose to /usr/local/bin/docker-entrypoint.sh)..

The /usr/local/bin/docker-entrypoint.sh, is loaded within our images own entrypoint and per the below:

{
    {
        if [ -f /usr/local/bin/docker-entrypoint.sh ]
        then
            /bin/echo "Running /usr/local/bin/docker-entrypoint.sh..."
            /bin/bash -x /usr/local/bin/docker-entrypoint.sh mysqld --verbose 2>&1
        else
            /bin/echo "ERROR: Cannot find /usr/local/bin/docker-entrypoint.sh..."
        fi
    } | /usr/bin/tee -a "${debugFile}"
}

Prior to upgrading, we're gracefully shutting down mysql 5.7 via mysqladmin.

I'm just a little stumped as no real helpful logs to advise what the issue is, so help appreciated!

macmule commented 2 months ago

Adding more details in case it helps, Dockerfile below:

# MySQL Version
ARG build_ver

# Base Details
FROM mysql:"${build_ver}"-debian

# build_type var
ARG build_type

# Delete list as contains expired key - https://github.com/apache/airflow/issues/36231#issuecomment-1856583460
RUN /bin/rm /etc/apt/sources.list.d/mysql.list

# Package installs
RUN /usr/bin/apt-get update && /usr/bin/apt-get install -y --no-install-recommends \
    ca-certificates \
    curl \
    nano \
    procps \
    tzdata

# Timezone
# https://serverfault.com/a/826222
ENV TZ=Europe/London

# Papertrail (pull latest)
RUN RS_LATEST=$(/usr/bin/curl -Ls -o /dev/null -w %{url_effective} https://github.com/papertrail/remote_syslog2/releases/latest | /usr/bin/awk -F / '{$
    /usr/bin/curl -SL https://github.com/papertrail/remote_syslog2/releases/download/v"${RS_LATEST}"/remote_syslog_linux_amd64.tar.gz -o /tmp/remote_s$
    /bin/tar -xzf /tmp/remote_syslog_linux_amd64.tar.gz -C /tmp; \
    /bin/mv /tmp/remote_syslog/remote_syslog /usr/local/bin; \
    /bin/chmod +x /usr/local/bin/remote_syslog

# Papertrail config items
# from: https://github.com/papertrail/remote_syslog2/blob/master/README.md
COPY ./"${build_type}"/config/remote_syslog /etc/init.d/
RUN /bin/ln -s /etc/init.d/remote_syslog /etc/rc3.d/S30remote_syslog

# Config
COPY ./"${build_type}"/config/my.cnf /etc/mysql
COPY ./"${build_type}"/config/log_files.yml /etc/log_files.yml
COPY ./"${build_type}"/mysql/run.sh /usr/local/bin/

# Run
RUN /bin/mkdir -p /etc/mysql/mysql.conf.d/; \
    /bin/chmod -R a+rx /etc/mysql/mysql.conf.d/; \
    /bin/mkdir -p /var/log/mysql/; \
    /bin/chmod -R a+rx /var/log/mysql; \
    /bin/chmod +x /usr/local/bin/run.sh

# Housekeeping
RUN /usr/bin/apt-get clean; \
    /bin/rm -rf /tmp/*; \
    /bin/rm -rf /var/lib/apt/lists/*

# Environment variables
ENV TERM xterm

CMD ["/usr/local/bin/run.sh"]

Where build_type and build_ver are arguments passed where building with Docker..

and my.cnf:

!includedir /etc/mysql/conf.d/
!includedir /etc/mysql/mysql.conf.d/

[mysqld]
authentication-policy = mysql_native_password
ignore-db-dir = lost+found
log_error = /var/log/mysql/mysql_error.log
long_query_time = 10
max_allowed_packet = 1G
max_connections = 241
slow_query_log = on
slow_query_log_file = /var/log/mysql/mysql-slow.log
[mysqld_safe]
log_error = /var/log/mysql/mysql_error.log
macmule commented 2 months ago

Verbose output below, hopefully <redacted> anything sensitive.. but left the other details in place..

Running /usr/local/bin/docker-entrypoint.sh...
+ set -eo pipefail
+ shopt -s nullglob
+ _verboseHelpArgs=(--verbose --help --log-bin-index="$(mktemp -u)")
++ mktemp -u
+ _is_sourced
+ '[' 2 -ge 2 ']'
+ '[' _is_sourced = _is_sourced ']'
+ '[' main = source ']'
+ _main mysqld --verbose
+ '[' m = - ']'
+ '[' mysqld = mysqld ']'
+ _mysql_want_help mysqld --verbose
+ local arg
+ for arg in "$@"
+ case "$arg" in
+ for arg in "$@"
+ case "$arg" in
+ return 1
+ mysql_note 'Entrypoint script for MySQL Server 8.0.34-1debian11 started.'
+ mysql_log Note 'Entrypoint script for MySQL Server 8.0.34-1debian11 started.'
+ local type=Note
+ shift
+ local 'text=Entrypoint script for MySQL Server 8.0.34-1debian11 started.'
+ '[' 1 -eq 0 ']'
+ local dt
++ date --rfc-3339=seconds
+ dt='2024-04-08 17:34:19+01:00'
+ printf '%s [%s] [Entrypoint]: %s\n' '2024-04-08 17:34:19+01:00' Note 'Entrypoint script for MySQL Server 8.0.34-1debian11 started.'
2024-04-08 17:34:19+01:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 8.0.34-1debian11 started.
+ mysql_check_config mysqld --verbose
+ toRun=('mysqld' '--verbose' '--verbose' '--help' '--log-bin-index=/tmp/tmp.UvA2V6iRXS')
+ local toRun errors
++ mysqld --verbose --verbose --help --log-bin-index=/tmp/tmp.UvA2V6iRXS
+ errors=
+ docker_setup_env mysqld --verbose
+ declare -g DATADIR SOCKET
++ mysql_get_config datadir mysqld --verbose
++ local conf=datadir
++ shift
++ mysqld --verbose --verbose --help --log-bin-index=/tmp/tmp.UvA2V6iRXS
++ awk -v conf=datadir '$1 == conf && /^[^ \t]/ { sub(/^[^ \t]+[ \t]+/, ""); print; exit }'
+ DATADIR=/var/lib/mysql/
++ mysql_get_config socket mysqld --verbose
++ local conf=socket
++ shift
++ mysqld --verbose --verbose --help --log-bin-index=/tmp/tmp.UvA2V6iRXS
++ awk -v conf=socket '$1 == conf && /^[^ \t]/ { sub(/^[^ \t]+[ \t]+/, ""); print; exit }'
+ SOCKET=/var/run/mysqld/mysqld.sock
+ file_env MYSQL_ROOT_HOST %
+ local var=MYSQL_ROOT_HOST
+ local fileVar=MYSQL_ROOT_HOST_FILE
+ local def=%
+ '[' '' ']'
+ local val=%
+ '[' '' ']'
+ '[' '' ']'
+ export MYSQL_ROOT_HOST=%
+ MYSQL_ROOT_HOST=%
+ unset MYSQL_ROOT_HOST_FILE
+ file_env MYSQL_DATABASE
+ local var=MYSQL_DATABASE
+ local fileVar=MYSQL_DATABASE_FILE
+ local def=
+ '[' <redacted> ']'
+ '[' '' ']'
+ local val=
+ '[' <redacted> ']'
+ val=<redacted>
+ export MYSQL_DATABASE=<redacted>
+ MYSQL_DATABASE=<redacted>
+ unset MYSQL_DATABASE_FILE
+ file_env MYSQL_USER
+ local var=MYSQL_USER
+ local fileVar=MYSQL_USER_FILE
+ local def=
+ '[' <redacted> ']'
+ '[' '' ']'
+ local val=
+ '[' <redacted> ']'
+ val=<redacted>
+ export MYSQL_USER=<redacted>
+ MYSQL_USER=<redacted>
+ unset MYSQL_USER_FILE
+ file_env MYSQL_PASSWORD
+ local var=MYSQL_PASSWORD
+ local fileVar=MYSQL_PASSWORD_FILE
+ local def=
+ '[' <redacted> ']'
+ '[' '' ']'
+ local val=
+ '[' <redacted> ']'
+ val=<redacted>
+ export MYSQL_PASSWORD=<redacted>
+ MYSQL_PASSWORD=<redacted>
+ unset MYSQL_PASSWORD_FILE
+ file_env MYSQL_ROOT_PASSWORD
+ local var=MYSQL_ROOT_PASSWORD
+ local fileVar=MYSQL_ROOT_PASSWORD_FILE
+ local def=
+ '[' <redacted> ']'
+ '[' '' ']'
+ local val=
+ '[' <redacted> ']'
+ val=<redacted>
+ export MYSQL_ROOT_PASSWORD=<redacted>
+ MYSQL_ROOT_PASSWORD=<redacted>
+ unset MYSQL_ROOT_PASSWORD_FILE
+ declare -g DATABASE_ALREADY_EXISTS
+ '[' -d /var/lib/mysql//mysql ']'
+ DATABASE_ALREADY_EXISTS=true
+ docker_create_db_directories mysqld --verbose
+ local user
++ id -u
+ user=0
+ dirs=(['/var/lib/mysql/']='1')
+ local -A dirs
+ local dir
++ dirname /var/run/mysqld/mysqld.sock
+ dir=/var/run/mysqld
+ dirs["$dir"]=1
+ local conf
+ for conf in general-log-file keyring_file_data pid-file secure-file-priv slow-query-log-file
++ mysql_get_config general-log-file mysqld --verbose
++ local conf=general-log-file
++ shift
++ mysqld --verbose --verbose --help --log-bin-index=/tmp/tmp.UvA2V6iRXS
++ awk -v conf=general-log-file '$1 == conf && /^[^ \t]/ { sub(/^[^ \t]+[ \t]+/, ""); print; exit }'
+ dir=/var/lib/mysql/<redacted>-54f55b98c-xz2hq.log
+ '[' -z /var/lib/mysql/<redacted>-54f55b98c-xz2hq.log ']'
+ '[' /var/lib/mysql/<redacted>-54f55b98c-xz2hq.log = NULL ']'
+ case "$conf" in
++ dirname /var/lib/mysql/<redacted>-54f55b98c-xz2hq.log
+ dir=/var/lib/mysql
+ dirs["$dir"]=1
+ for conf in general-log-file keyring_file_data pid-file secure-file-priv slow-query-log-file
++ mysql_get_config keyring_file_data mysqld --verbose
++ local conf=keyring_file_data
++ shift
++ mysqld --verbose --verbose --help --log-bin-index=/tmp/tmp.UvA2V6iRXS
++ awk -v conf=keyring_file_data '$1 == conf && /^[^ \t]/ { sub(/^[^ \t]+[ \t]+/, ""); print; exit }'
+ dir=
+ '[' -z '' ']'
+ continue
+ for conf in general-log-file keyring_file_data pid-file secure-file-priv slow-query-log-file
++ mysql_get_config pid-file mysqld --verbose
++ local conf=pid-file
++ shift
++ mysqld --verbose --verbose --help --log-bin-index=/tmp/tmp.UvA2V6iRXS
++ awk -v conf=pid-file '$1 == conf && /^[^ \t]/ { sub(/^[^ \t]+[ \t]+/, ""); print; exit }'
+ dir=/var/lib/mysql/<redacted>-54f55b98c-xz2hq.pid
+ '[' -z /var/lib/mysql/<redacted>-54f55b98c-xz2hq.pid ']'
+ '[' /var/lib/mysql/<redacted>-54f55b98c-xz2hq.pid = NULL ']'
+ case "$conf" in
++ dirname /var/lib/mysql/<redacted>-54f55b98c-xz2hq.pid
+ dir=/var/lib/mysql
+ dirs["$dir"]=1
+ for conf in general-log-file keyring_file_data pid-file secure-file-priv slow-query-log-file
++ mysql_get_config secure-file-priv mysqld --verbose
++ local conf=secure-file-priv
++ shift
++ mysqld --verbose --verbose --help --log-bin-index=/tmp/tmp.UvA2V6iRXS
++ awk -v conf=secure-file-priv '$1 == conf && /^[^ \t]/ { sub(/^[^ \t]+[ \t]+/, ""); print; exit }'
+ dir=/var/lib/mysql-files
+ '[' -z /var/lib/mysql-files ']'
+ '[' /var/lib/mysql-files = NULL ']'
+ case "$conf" in
+ dirs["$dir"]=1
+ for conf in general-log-file keyring_file_data pid-file secure-file-priv slow-query-log-file
++ mysql_get_config slow-query-log-file mysqld --verbose
++ local conf=slow-query-log-file
++ shift
++ mysqld --verbose --verbose --help --log-bin-index=/tmp/tmp.UvA2V6iRXS
++ awk -v conf=slow-query-log-file '$1 == conf && /^[^ \t]/ { sub(/^[^ \t]+[ \t]+/, ""); print; exit }'
+ dir=/var/log/mysql/mysql-slow.log
+ '[' -z /var/log/mysql/mysql-slow.log ']'
+ '[' /var/log/mysql/mysql-slow.log = NULL ']'
+ case "$conf" in
++ dirname /var/log/mysql/mysql-slow.log
+ dir=/var/log/mysql
+ dirs["$dir"]=1
+ mkdir -p /var/lib/mysql/ /var/lib/mysql-files /var/run/mysqld /var/log/mysql /var/lib/mysql
+ '[' 0 = 0 ']'
+ find /var/lib/mysql/ /var/lib/mysql-files /var/run/mysqld /var/log/mysql /var/lib/mysql '!' -user mysql -exec chown --no-dereference mysql '{}' +
++ id -u
+ '[' 0 = 0 ']'
+ mysql_note 'Switching to dedicated user '\''mysql'\'''
+ mysql_log Note 'Switching to dedicated user '\''mysql'\'''
+ local type=Note
+ shift
+ local 'text=Switching to dedicated user '\''mysql'\'''
+ '[' 1 -eq 0 ']'
+ local dt
++ date --rfc-3339=seconds
+ dt='2024-04-08 17:34:20+01:00'
+ printf '%s [%s] [Entrypoint]: %s\n' '2024-04-08 17:34:20+01:00' Note 'Switching to dedicated user '\''mysql'\'''
2024-04-08 17:34:20+01:00 [Note] [Entrypoint]: Switching to dedicated user 'mysql'
+ exec gosu mysql /usr/local/bin/docker-entrypoint.sh mysqld --verbose
2024-04-08 17:34:20+01:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 8.0.34-1debian11 started.

After the last line is when the image starts to show in kubernetes as CrashLoopBackOff.. and then it goes around again

tianon commented 2 months ago

Unfortunately, I don't see anything particularly interesting in those logs. Would it be possible for you to try again, but replacing /bin/bash -x /usr/local/bin/docker-entrypoint.sh mysqld --verbose 2>&1 with gosu mysql /bin/bash -x /usr/local/bin/docker-entrypoint.sh mysqld --verbose 2>&1 so we get a trace of the real entrypoint run not just the "as root" portion?

macmule commented 2 months ago

Thanks @tianon

Seems to have helped find an issue, at least!

+ mkdir -p /var/lib/mysql/ /var/lib/mysql-files /var/run/mysqld /var/log/mysql /var/lib/mysql
mkdir: cannot create directory '/var/lib/mysql-files': Permission denied

I'm going to make sure that all those dirs are created in the Dockerfile, and will try again.

macmule commented 2 months ago

Ok, after creating the dirs and making the prior mentioned change.. still sticking, and log below:

Running /usr/local/bin/docker-entrypoint.sh...
+ set -eo pipefail
+ shopt -s nullglob
+ _verboseHelpArgs=(--verbose --help --log-bin-index="$(mktemp -u)")
++ mktemp -u
+ _is_sourced
+ '[' 2 -ge 2 ']'
+ '[' _is_sourced = _is_sourced ']'
+ '[' main = source ']'
+ _main mysqld --verbose
+ '[' m = - ']'
+ '[' mysqld = mysqld ']'
+ _mysql_want_help mysqld --verbose
+ local arg
+ for arg in "$@"
+ case "$arg" in
+ for arg in "$@"
+ case "$arg" in
+ return 1
+ mysql_note 'Entrypoint script for MySQL Server 8.0.34-1debian11 started.'
+ mysql_log Note 'Entrypoint script for MySQL Server 8.0.34-1debian11 started.'
+ local type=Note
+ shift
+ local 'text=Entrypoint script for MySQL Server 8.0.34-1debian11 started.'
+ '[' 1 -eq 0 ']'
+ local dt
++ date --rfc-3339=seconds
+ dt='2024-04-08 22:56:41+01:00'
+ printf '%s [%s] [Entrypoint]: %s\n' '2024-04-08 22:56:41+01:00' Note 'Entrypoint script for MySQL Server 8.0.34-1debian11 started.'
2024-04-08 22:56:41+01:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 8.0.34-1debian11 started.
+ mysql_check_config mysqld --verbose
+ toRun=('mysqld' '--verbose' '--verbose' '--help' '--log-bin-index=/tmp/tmp.Kn7kAGTin5')
+ local toRun errors
++ mysqld --verbose --verbose --help --log-bin-index=/tmp/tmp.Kn7kAGTin5
+ errors=
+ docker_setup_env mysqld --verbose
+ declare -g DATADIR SOCKET
++ mysql_get_config datadir mysqld --verbose
++ local conf=datadir
++ shift
++ mysqld --verbose --verbose --help --log-bin-index=/tmp/tmp.Kn7kAGTin5
++ awk -v conf=datadir '$1 == conf && /^[^ \t]/ { sub(/^[^ \t]+[ \t]+/, ""); print; exit }'
+ DATADIR=/var/lib/mysql/
++ mysql_get_config socket mysqld --verbose
++ local conf=socket
++ shift
++ mysqld --verbose --verbose --help --log-bin-index=/tmp/tmp.Kn7kAGTin5
++ awk -v conf=socket '$1 == conf && /^[^ \t]/ { sub(/^[^ \t]+[ \t]+/, ""); print; exit }'
+ SOCKET=/var/run/mysqld/mysqld.sock
+ file_env MYSQL_ROOT_HOST %
+ local var=MYSQL_ROOT_HOST
+ local fileVar=MYSQL_ROOT_HOST_FILE
+ local def=%
+ '[' '' ']'
+ local val=%
+ '[' '' ']'
+ '[' '' ']'
+ export MYSQL_ROOT_HOST=%
+ MYSQL_ROOT_HOST=%
+ unset MYSQL_ROOT_HOST_FILE
+ file_env MYSQL_DATABASE
+ local var=MYSQL_DATABASE
+ local fileVar=MYSQL_DATABASE_FILE
+ local def=
+ '[' <redacted> ']'
+ '[' '' ']'
+ local val=
+ '[' <redacted> ']'
+ val=<redacted>
+ export MYSQL_DATABASE=<redacted>
+ MYSQL_DATABASE=<redacted>
+ unset MYSQL_DATABASE_FILE
+ file_env MYSQL_USER
+ local var=MYSQL_USER
+ local fileVar=MYSQL_USER_FILE
+ local def=
+ '[' <redacted> ']'
+ '[' '' ']'
+ local val=
+ '[' <redacted> ']'
+ val=<redacted>
+ export MYSQL_USER=<redacted>
+ MYSQL_USER=<redacted>
+ unset MYSQL_USER_FILE
+ file_env MYSQL_PASSWORD
+ local var=MYSQL_PASSWORD
+ local fileVar=MYSQL_PASSWORD_FILE
+ local def=
+ '[' <redacted> ']'
+ '[' '' ']'
+ local val=
+ '[' <redacted> ']'
+ val=<redacted>
+ export MYSQL_PASSWORD=<redacted>
+ MYSQL_PASSWORD=<redacted>
+ unset MYSQL_PASSWORD_FILE
+ file_env MYSQL_ROOT_PASSWORD
+ local var=MYSQL_ROOT_PASSWORD
+ local fileVar=MYSQL_ROOT_PASSWORD_FILE
+ local def=
+ '[' <redacted> ']'
+ '[' '' ']'
+ local val=
+ '[' <redacted> ']'
+ val=<redacted>
+ export MYSQL_ROOT_PASSWORD=<redacted>
+ MYSQL_ROOT_PASSWORD=<redacted>
+ unset MYSQL_ROOT_PASSWORD_FILE
+ declare -g DATABASE_ALREADY_EXISTS
+ '[' -d /var/lib/mysql//mysql ']'
+ DATABASE_ALREADY_EXISTS=true
+ docker_create_db_directories mysqld --verbose
+ local user
++ id -u
+ user=999
+ dirs=(['/var/lib/mysql/']='1')
+ local -A dirs
+ local dir
++ dirname /var/run/mysqld/mysqld.sock
+ dir=/var/run/mysqld
+ dirs["$dir"]=1
+ local conf
+ for conf in general-log-file keyring_file_data pid-file secure-file-priv slow-query-log-file
++ mysql_get_config general-log-file mysqld --verbose
++ local conf=general-log-file
++ shift
++ mysqld --verbose --verbose --help --log-bin-index=/tmp/tmp.Kn7kAGTin5
++ awk -v conf=general-log-file '$1 == conf && /^[^ \t]/ { sub(/^[^ \t]+[ \t]+/, ""); print; exit }'
+ dir=/var/lib/mysql/<redacted>-7f9888656f-4zxz7.log
+ '[' -z /var/lib/mysql/<redacted>-7f9888656f-4zxz7.log ']'
+ '[' /var/lib/mysql/<redacted>-7f9888656f-4zxz7.log = NULL ']'
+ case "$conf" in
++ dirname /var/lib/mysql/<redacted>-7f9888656f-4zxz7.log
+ dir=/var/lib/mysql
+ dirs["$dir"]=1
+ for conf in general-log-file keyring_file_data pid-file secure-file-priv slow-query-log-file
++ mysql_get_config keyring_file_data mysqld --verbose
++ local conf=keyring_file_data
++ shift
++ mysqld --verbose --verbose --help --log-bin-index=/tmp/tmp.Kn7kAGTin5
++ awk -v conf=keyring_file_data '$1 == conf && /^[^ \t]/ { sub(/^[^ \t]+[ \t]+/, ""); print; exit }'
+ dir=
+ '[' -z '' ']'
+ continue
+ for conf in general-log-file keyring_file_data pid-file secure-file-priv slow-query-log-file
++ mysql_get_config pid-file mysqld --verbose
++ local conf=pid-file
++ shift
++ mysqld --verbose --verbose --help --log-bin-index=/tmp/tmp.Kn7kAGTin5
++ awk -v conf=pid-file '$1 == conf && /^[^ \t]/ { sub(/^[^ \t]+[ \t]+/, ""); print; exit }'
+ dir=/var/lib/mysql/<redacted>-7f9888656f-4zxz7.pid
+ '[' -z /var/lib/mysql/<redacted>-7f9888656f-4zxz7.pid ']'
+ '[' /var/lib/mysql/<redacted>-7f9888656f-4zxz7.pid = NULL ']'
+ case "$conf" in
++ dirname /var/lib/mysql/<redacted>-7f9888656f-4zxz7.pid
+ dir=/var/lib/mysql
+ dirs["$dir"]=1
+ for conf in general-log-file keyring_file_data pid-file secure-file-priv slow-query-log-file
++ mysql_get_config secure-file-priv mysqld --verbose
++ local conf=secure-file-priv
++ shift
++ mysqld --verbose --verbose --help --log-bin-index=/tmp/tmp.Kn7kAGTin5
++ awk -v conf=secure-file-priv '$1 == conf && /^[^ \t]/ { sub(/^[^ \t]+[ \t]+/, ""); print; exit }'
+ dir=/var/lib/mysql-files
+ '[' -z /var/lib/mysql-files ']'
+ '[' /var/lib/mysql-files = NULL ']'
+ case "$conf" in
+ dirs["$dir"]=1
+ for conf in general-log-file keyring_file_data pid-file secure-file-priv slow-query-log-file
++ mysql_get_config slow-query-log-file mysqld --verbose
++ local conf=slow-query-log-file
++ shift
++ mysqld --verbose --verbose --help --log-bin-index=/tmp/tmp.Kn7kAGTin5
++ awk -v conf=slow-query-log-file '$1 == conf && /^[^ \t]/ { sub(/^[^ \t]+[ \t]+/, ""); print; exit }'
+ dir=/var/log/mysql/mysql-slow.log
+ '[' -z /var/log/mysql/mysql-slow.log ']'
+ '[' /var/log/mysql/mysql-slow.log = NULL ']'
+ case "$conf" in
++ dirname /var/log/mysql/mysql-slow.log
+ dir=/var/log/mysql
+ dirs["$dir"]=1
+ mkdir -p /var/lib/mysql/ /var/lib/mysql-files /var/run/mysqld /var/log/mysql /var/lib/mysql
+ '[' 999 = 0 ']'
++ id -u
+ '[' 999 = 0 ']'
+ '[' -z true ']'
+ mysql_socket_fix
+ local defaultSocket
++ mysql_get_config socket mysqld --no-defaults
++ local conf=socket
++ shift
++ mysqld --no-defaults --verbose --help --log-bin-index=/tmp/tmp.Kn7kAGTin5
++ awk -v conf=socket '$1 == conf && /^[^ \t]/ { sub(/^[^ \t]+[ \t]+/, ""); print; exit }'
+ defaultSocket=/var/run/mysqld/mysqld.sock
+ '[' /var/run/mysqld/mysqld.sock '!=' /var/run/mysqld/mysqld.sock ']'
+ exec mysqld --verbose
macmule commented 2 months ago

If I'm reading the entrypoint.sh right, the above means we should be good.. as we're at the end of the _main() function:

https://github.com/docker-library/mysql/blob/master/docker-entrypoint.sh#L407-L411

yosifkit commented 2 months ago

I don't think it is actually stuck; it is just no longer logging to stdout becuase it was told to log to a file: log_error = /var/log/mysql/mysql_error.log. If you check there, you should see the regular logs (and maybe hints to why it is failing):

$ # /var/lib/mysql/ so I didn't have non-existent directory issues
$ docker run -it --rm --name sql -e MYSQL_ROOT_PASSWORD=12345 mysql --log-error=/var/lib/mysql/mysql_error.log
2024-04-08 22:59:10+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 8.3.0-1.el8 started.
2024-04-08 22:59:10+00:00 [Note] [Entrypoint]: Switching to dedicated user 'mysql'
2024-04-08 22:59:10+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 8.3.0-1.el8 started.
2024-04-08 22:59:10+00:00 [Note] [Entrypoint]: Initializing database files
2024-04-08 22:59:14+00:00 [Note] [Entrypoint]: Database files initialized
2024-04-08 22:59:14+00:00 [Note] [Entrypoint]: Starting temporary server
mysqld will log errors to /var/lib/mysql/mysql_error.log
mysqld is running as pid 126
2024-04-08 22:59:14+00:00 [Note] [Entrypoint]: Temporary server started.
'/var/lib/mysql/mysql.sock' -> '/var/run/mysqld/mysqld.sock'
Warning: Unable to load '/usr/share/zoneinfo/iso3166.tab' as time zone. Skipping it.
Warning: Unable to load '/usr/share/zoneinfo/leap-seconds.list' as time zone. Skipping it.
Warning: Unable to load '/usr/share/zoneinfo/leapseconds' as time zone. Skipping it.
Warning: Unable to load '/usr/share/zoneinfo/tzdata.zi' as time zone. Skipping it.
Warning: Unable to load '/usr/share/zoneinfo/zone.tab' as time zone. Skipping it.
Warning: Unable to load '/usr/share/zoneinfo/zone1970.tab' as time zone. Skipping it.

2024-04-08 22:59:15+00:00 [Note] [Entrypoint]: Stopping temporary server
2024-04-08 22:59:17+00:00 [Note] [Entrypoint]: Temporary server stopped

2024-04-08 22:59:17+00:00 [Note] [Entrypoint]: MySQL init process done. Ready for start up.

And in another terminal:

$ docker exec -it sql bash
bash-4.4# cat /var/lib/mysql/mysql_error.log
2024-04-08T22:59:10.736937Z 0 [System] [MY-015017] [Server] MySQL Server Initialization - start.
2024-04-08T22:59:10.737825Z 0 [System] [MY-013169] [Server] /usr/sbin/mysqld (mysqld 8.3.0) initializing of server in progress as process 80
2024-04-08T22:59:10.742891Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2024-04-08T22:59:10.969314Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2024-04-08T22:59:11.733066Z 6 [Warning] [MY-010453] [Server] root@localhost is created with an empty password ! Please consider switching off the --initialize-insecure option.
2024-04-08T22:59:14.068064Z 0 [System] [MY-015018] [Server] MySQL Server Initialization - end.
2024-04-08T22:59:14.153071Z 0 [System] [MY-015015] [Server] MySQL Server - start.
2024-04-08T22:59:14.325924Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.3.0) starting as process 124
2024-04-08T22:59:14.349655Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2024-04-08T22:59:14.422623Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2024-04-08T22:59:14.600078Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2024-04-08T22:59:14.600094Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
2024-04-08T22:59:14.601968Z 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-04-08T22:59:14.610625Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Socket: /var/run/mysqld/mysqlx.sock
2024-04-08T22:59:14.610835Z 0 [System] [MY-010931] [Server] /usr/sbin/mysqld: ready for connections. Version: '8.3.0'  socket: '/var/run/mysqld/mysqld.sock'  port: 0  MySQL Community Server - GPL.
2024-04-08T22:59:15.906063Z 10 [System] [MY-013172] [Server] Received SHUTDOWN from user root. Shutting down mysqld (Version: 8.3.0).
2024-04-08T22:59:17.192951Z 0 [System] [MY-010910] [Server] /usr/sbin/mysqld: Shutdown complete (mysqld 8.3.0)  MySQL Community Server - GPL.
2024-04-08T22:59:17.192961Z 0 [System] [MY-015016] [Server] MySQL Server - end.
2024-04-08T22:59:17.913668Z 0 [System] [MY-015015] [Server] MySQL Server - start.
2024-04-08T22:59:18.091380Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.3.0) starting as process 1
2024-04-08T22:59:18.106253Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2024-04-08T22:59:18.177430Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2024-04-08T22:59:18.330705Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2024-04-08T22:59:18.330721Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
2024-04-08T22:59:18.332498Z 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-04-08T22:59:18.342427Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Bind-address: '::' port: 33060, socket: /var/run/mysqld/mysqlx.sock
2024-04-08T22:59:18.342484Z 0 [System] [MY-010931] [Server] /usr/sbin/mysqld: ready for connections. Version: '8.3.0'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  MySQL Community Server - GPL.
macmule commented 2 months ago

Thanks @yosifkit, it seems that the pod might not be running long enough for the logs to be sent to our SIEM.. I have made a change and can see the below in /var/log/mysql/mysql_error.log:

2024-04-09T08:24:00.041891Z 0 [Warning] [MY-011068] [Server] The syntax '--skip-host-cache' is deprecated and will be removed in a future release. Please use SET GLOBAL host_cache_size=0 instead.
2024-04-09T08:24:00.042088Z 0 [ERROR] [MY-010083] [Server] --verbose is for use with --help; did you mean --log-error-verbosity?
2024-04-09T08:24:00.045759Z 0 [Warning] [MY-010101] [Server] Insecure configuration for --secure-file-priv: Location is accessible to all OS users. Consider choosing a different directory.
2024-04-09T08:24:00.045863Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.34) starting as process 75
2024-04-09T08:24:00.062905Z 1 [System] [MY-011012] [Server] Starting upgrade of data directory.
2024-04-09T08:24:00.062949Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2024-04-09T08:24:00.610436Z 1 [ERROR] [MY-012526] [InnoDB] Upgrade is not supported after a crash or shutdown with innodb_fast_shutdown = 2. This redo log was created with MySQL 5.7.37, and it appears logically non empty. Please follow the instructions at http://dev.mysql.com/doc/refman/8.0/en/upgrading.html
2024-04-09T08:24:00.610481Z 1 [ERROR] [MY-012930] [InnoDB] Plugin initialization aborted with error Generic error.
2024-04-09T08:24:01.028603Z 1 [ERROR] [MY-011013] [Server] Failed to initialize DD Storage Engine.
2024-04-09T08:24:01.030214Z 0 [ERROR] [MY-010020] [Server] Data Dictionary initialization failed.
2024-04-09T08:24:01.030246Z 0 [ERROR] [MY-010119] [Server] Aborting
2024-04-09T08:24:01.031095Z 0 [System] [MY-010910] [Server] /usr/sbin/mysqld: Shutdown complete (mysqld 8.0.34)  MySQL Community Server - GPL.

I have been issuing a shutdown via mysqladmin prior, guessing this doesn't suffice.

https://serverfault.com/a/1110090 advises to delete the ib_logfile* files and create the folder #innodb_redo within the mysql data dir.

After following the above, and restarting mysql.. the database was upgraded and all looks good!

Is there a "cleaner" shutdown process? The steps at: https://dev.mysql.com/doc/refman/8.3/en/docker-mysql-getting-started.html#docker-upgrading seem to suggest that stopping the pod and starting with the new version will suffice.. but that's also 8.0 > 8.3, and not 5.7.x to 8.0.34.