Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Open
macmule opened this issue Apr 8, 2024 · 8 comments

Comments

@macmule
Copy link

macmule commented Apr 8, 2024

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
Copy link
Author

macmule commented Apr 8, 2024

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
Copy link
Author

macmule commented Apr 8, 2024

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
Copy link
Member

tianon commented Apr 8, 2024

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
Copy link
Author

macmule commented Apr 8, 2024

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
Copy link
Author

macmule commented Apr 8, 2024

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
Copy link
Author

macmule commented Apr 8, 2024

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
Copy link
Member

yosifkit commented Apr 8, 2024

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
Copy link
Author

macmule commented Apr 9, 2024

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.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants