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.

Sign up for GitHub

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

Jump to bottom

mysql 8.0.33 fails on Fly.io but works with 8.0.32 #967

Open
fideloper opened this issue Apr 18, 2023 · 7 comments
Open

mysql 8.0.33 fails on Fly.io but works with 8.0.32 #967

fideloper opened this issue Apr 18, 2023 · 7 comments

Comments

@fideloper
Copy link

fideloper commented Apr 18, 2023 •
edited
Loading

Hi!

I work at Fly.io, where we convert Docker images to Firecracker VM's. This has worked great for MySQL users until the current (as I write this) release of MySQL.

The current tag mysql:8 (which is mysql:8.0.33) fails during the Entrypoint execution, with no error message. However this works on my local Docker.

Here's what I see in version 8.0.33 output in Fly:

fly m run mysql:8.0.33 \
    -a some-fly-team --cpus 1 --memory 2048 --region ewr \
    -e "MYSQL_DATABASE=my_db" \
    -e "MYSQL_PASSWORD=secret" \
    -e "MYSQL_ROOT_PASSWORD=secret" \
    -e "MYSQL_USER=my_user"
👉 view log output of failing run (8.0.33) 
2023-04-18T00:30:06Z app[9185ee3c792383] ewr [info]Starting init (commit: ed64554)...
2023-04-18T00:30:06Z app[9185ee3c792383] ewr [info]Preparing to run: `docker-entrypoint.sh mysqld` as root
2023-04-18T00:30:06Z app[9185ee3c792383] ewr [info]2023/04/18 00:30:06 listening on [fdaa:1:40e4:a7b:21a1:b5fe:357b:2]:22 (DNS: [fdaa::3]:53)
2023-04-18T00:30:06Z app[9185ee3c792383] ewr [info]2023-04-18 00:30:06+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 8.0.33-1.el8 started.
2023-04-18T00:30:07Z app[9185ee3c792383] ewr [info]Starting clean up.
2023-04-18T00:30:08Z app[9185ee3c792383] ewr [info][    2.133634] reboot: Restarting system
2023-04-18T00:30:10Z app[9185ee3c792383] ewr [info]Starting init (commit: ed64554)...
2023-04-18T00:30:10Z app[9185ee3c792383] ewr [info]Preparing to run: `docker-entrypoint.sh mysqld` as root
2023-04-18T00:30:10Z app[9185ee3c792383] ewr [info]2023/04/18 00:30:10 listening on [fdaa:1:40e4:a7b:21a1:b5fe:357b:2]:22 (DNS: [fdaa::3]:53)
2023-04-18T00:30:10Z app[9185ee3c792383] ewr [info]2023-04-18 00:30:10+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 8.0.33-1.el8 started.
2023-04-18T00:30:11Z app[9185ee3c792383] ewr [info]Starting clean up.
2023-04-18T00:30:12Z app[9185ee3c792383] ewr [info][    2.132792] reboot: Restarting system
2023-04-18T00:30:13Z app[9185ee3c792383] ewr [info]Starting init (commit: ed64554)...
2023-04-18T00:30:13Z app[9185ee3c792383] ewr [info]Preparing to run: `docker-entrypoint.sh mysqld` as root
2023-04-18T00:30:13Z app[9185ee3c792383] ewr [info]2023/04/18 00:30:13 listening on [fdaa:1:40e4:a7b:21a1:b5fe:357b:2]:22 (DNS: [fdaa::3]:53)
2023-04-18T00:30:13Z app[9185ee3c792383] ewr [info]2023-04-18 00:30:13+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 8.0.33-1.el8 started.
2023-04-18T00:30:14Z app[9185ee3c792383] ewr [info]Starting clean up.
2023-04-18T00:30:15Z app[9185ee3c792383] ewr [info][    2.138144] reboot: Restarting system
2023-04-18T00:30:16Z app[9185ee3c792383] ewr [info]2023/04/18 00:30:16 listening on [fdaa:1:40e4:a7b:21a1:b5fe:357b:2]:22 (DNS: [fdaa::3]:53)
2023-04-18T00:30:16Z app[9185ee3c792383] ewr [info]2023-04-18 00:30:16+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 8.0.33-1.el8 started.
2023-04-18T00:30:17Z app[9185ee3c792383] ewr [info]Starting clean up.
2023-04-18T00:30:18Z app[9185ee3c792383] ewr [info][    2.135679] reboot: Restarting system
2023-04-18T00:30:21Z app[9185ee3c792383] ewr [info]Starting clean up

The entrypoint script is exiting with some non-zero status code, and Fly is rebooting it. It goes until it hits the max restart limit (defaulting to 10).

Version 8.0.32 does not do this, and works as you'd expect:

fly m run mysql:8.0.32 \
    -a some-fly-team --cpus 1 --memory 2048 --region ewr \
    -e "MYSQL_DATABASE=my_db" \
    -e "MYSQL_PASSWORD=secret" \
    -e "MYSQL_ROOT_PASSWORD=secret" \
    -e "MYSQL_USER=my_user"
👉 view log output of successful run (8.0.32) 
2023-04-18T00:29:02Z app[91857775f1d308] ewr [info]Starting init (commit: ed64554)...
2023-04-18T00:29:02Z app[91857775f1d308] ewr [info]Preparing to run: `docker-entrypoint.sh mysqld` as root
2023-04-18T00:29:02Z app[91857775f1d308] ewr [info]2023/04/18 00:29:02 listening on [fdaa:1:40e4:a7b:ce:414e:3b11:2]:22 (DNS: [fdaa::3]:53)
2023-04-18T00:29:02Z app[91857775f1d308] ewr [info]2023-04-18 00:29:02+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 8.0.32-1.el8 started.
2023-04-18T00:29:02Z app[91857775f1d308] ewr [info]2023-04-18 00:29:02+00:00 [Note] [Entrypoint]: Switching to dedicated user 'mysql'
2023-04-18T00:29:02Z app[91857775f1d308] ewr [info]2023-04-18 00:29:02+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 8.0.32-1.el8 started.
2023-04-18T00:29:02Z app[91857775f1d308] ewr [info]2023-04-18 00:29:02+00:00 [Note] [Entrypoint]: Initializing database files
2023-04-18T00:29:02Z app[91857775f1d308] ewr [info]2023-04-18T00:29:02.659391Z 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.
2023-04-18T00:29:02Z app[91857775f1d308] ewr [info]2023-04-18T00:29:02.659604Z 0 [System] [MY-013169] [Server] /usr/sbin/mysqld (mysqld 8.0.32) initializing of server in progress as process 591
2023-04-18T00:29:02Z app[91857775f1d308] ewr [info]2023-04-18T00:29:02.667692Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2023-04-18T00:29:03Z app[91857775f1d308] ewr [info]2023-04-18T00:29:03.049568Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2023-04-18T00:29:03Z app[91857775f1d308] ewr [info]2023-04-18T00:29:03.986375Z 6 [Warning] [MY-010453] [Server] root@localhost is created with an empty password ! Please consider switching off the --initialize-insecure option.
2023-04-18T00:29:05Z app[91857775f1d308] ewr [info]2023-04-18 00:29:05+00:00 [Note] [Entrypoint]: Database files initialized
2023-04-18T00:29:05Z app[91857775f1d308] ewr [info]2023-04-18 00:29:05+00:00 [Note] [Entrypoint]: Starting temporary server
2023-04-18T00:29:06Z app[91857775f1d308] ewr [info]2023-04-18T00:29:06.095803Z 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.
2023-04-18T00:29:06Z app[91857775f1d308] ewr [info]2023-04-18T00:29:06.098734Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.32) starting as process 633
2023-04-18T00:29:06Z app[91857775f1d308] ewr [info]2023-04-18T00:29:06.112757Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2023-04-18T00:29:06Z app[91857775f1d308] ewr [info]2023-04-18T00:29:06.363615Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2023-04-18T00:29:06Z app[91857775f1d308] ewr [info]2023-04-18T00:29:06.598917Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to suppo
2023-04-18T00:29:06Z app[91857775f1d308] ewr [info]2023-04-18T00:29:06.598917Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
2023-04-18T00:29:06Z app[91857775f1d308] ewr [info]2023-04-18T00:29:06.599453Z 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.
2023-04-18T00:29:06Z app[91857775f1d308] ewr [info]2023-04-18T00:29:06.612631Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Socket: /var/run/mysqld/mysqlx.sock
2023-04-18T00:29:06Z app[91857775f1d308] ewr [info]2023-04-18T00:29:06.612803Z 0 [System] [MY-010931] [Server] /usr/sbin/mysqld: ready for connections. Version: '8.0.32'  socket: '/var/run/mysqld/mysqld.sock'  port: 0  MySQL Community Server - GPL.

I'd love some help in seeing what changed or may be failing here! In theory whatever works in Docker should work in a Fly VM...

Is the only notable change the update of the Gosu version? 99f9c41
@fideloper
Copy link
Author

fideloper commented Apr 18, 2023 •
edited
Loading

Looks like 8.0.33 isn't GA yet (or isn't released yet) but the official Docker site might just be behind (or, rather, has a tag for this not-yet-released release)

image

@tianon
Copy link
Member

tianon commented Apr 18, 2023

That's really odd; I don't think we have any specific insight into what might've changed that could've caused this. It's very unlikely that the gosu bump did.

For what it's worth, your link to the release notes is live now (I think we were just faster at getting the release published than the MySQL docs team was 😅).

@fideloper
Copy link
Author

Makes sense! I'll keep an eye on it to see if something changes either within this tag or the next. If it continues to be an issue, I'll dig in further to see what I can surface.

Thanks

@fideloper
Copy link
Author

fideloper commented Apr 25, 2023 •
edited
Loading

Hi again!

I did get a bit more useful output today trying this out again (I didn't really change anything except perhaps adding some startup flags that I suspect are unrelated, but I did get a more useful error message from mysqld):

👉 full output on 8.0.33 
2023-04-25T14:21:40.194 app[fc8e61ad] bos [info] Preparing to run: `docker-entrypoint.sh --default-authentication-plugin mysql_native_password --datadir /data/mysql --performance-schema=OFF --innodb-buffer-pool-size 64M` as root

2023-04-25T14:21:40.207 app[fc8e61ad] bos [info] 2023/04/25 14:21:40 listening on [fdaa:0:6ba9:a7b:eb:7:292e:2]:22 (DNS: [fdaa::3]:53)


2023-04-25T14:21:40.241 app[fc8e61ad] bos [info] 2023-04-25 14:21:40+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 8.0.33-1.el8 started.


2023-04-25T14:21:40.446 app[fc8e61ad] bos [info] 2023-04-25 14:21:40+00:00 [ERROR] [Entrypoint]: mysqld failed while attempting to check config


2023-04-25T14:21:40.446 app[fc8e61ad] bos [info] command was: mysqld --default-authentication-plugin mysql_native_password --datadir /data/mysql --performance-schema=OFF --innodb-buffer-pool-size 64M --verbose --help --log-bin-index=/tmp/tmp.p9nJLOlyru


2023-04-25T14:21:40.446 app[fc8e61ad] bos [info] 2023-04-25T14:21:40Z UTC - mysqld got signal 11 ;


2023-04-25T14:21:40.446 app[fc8e61ad] bos [info] Most likely, you have hit a bug, but this error can also be caused by malfunctioning hardware.


2023-04-25T14:21:40.446 app[fc8e61ad] bos [info] BuildID[sha1]=8076d8618232dd0b5c9df333b4ee48d26d2170ca


2023-04-25T14:21:40.446 app[fc8e61ad] bos [info] Thread pointer: 0x0


2023-04-25T14:21:40.446 app[fc8e61ad] bos [info] Attempting backtrace. You can use the following information to find out


2023-04-25T14:21:40.446 app[fc8e61ad] bos [info] where mysqld died. If you see no messages after this, something went


2023-04-25T14:21:40.446 app[fc8e61ad] bos [info] terribly wrong...


2023-04-25T14:21:40.446 app[fc8e61ad] bos [info] stack_bottom = 0 thread_stack 0x100000


2023-04-25T14:21:40.446 app[fc8e61ad] bos [info] /usr/sbin/mysqld(my_print_stacktrace(unsigned char const*, unsigned long)+0x41) [0x2123181]


2023-04-25T14:21:40.446 app[fc8e61ad] bos [info] /usr/sbin/mysqld(print_fatal_signal(int)+0x397) [0xfe6b07]


2023-04-25T14:21:40.446 app[fc8e61ad] bos [info] /usr/sbin/mysqld(handle_fatal_signal+0xa5) [0xfe6bc5]


2023-04-25T14:21:40.446 app[fc8e61ad] bos [info] /lib64/libpthread.so.0(+0x12d00) [0x7fc0455c9d00]


2023-04-25T14:21:40.446 app[fc8e61ad] bos [info] /usr/sbin/mysqld(Delegate::Delegate(unsigned int)+0xaf) [0x1db91bf]


2023-04-25T14:21:40.446 app[fc8e61ad] bos [info] /usr/sbin/mysqld(delegates_init()+0x34) [0x1db94c4]


2023-04-25T14:21:40.446 app[fc8e61ad] bos [info] /usr/sbin/mysqld() [0xd6ee6d]


2023-04-25T14:21:40.446 app[fc8e61ad] bos [info] /usr/sbin/mysqld(mysqld_main(int, char**)+0x220f) [0xd7581f]


2023-04-25T14:21:40.446 app[fc8e61ad] bos [info] /lib64/libc.so.6(__libc_start_main+0xe5) [0x7fc043b6ed85]


2023-04-25T14:21:40.446 app[fc8e61ad] bos [info] /usr/sbin/mysqld(_start+0x2e) [0xd5680e]


2023-04-25T14:21:40.446 app[fc8e61ad] bos [info] The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains


2023-04-25T14:21:40.446 app[fc8e61ad] bos [info] information that should help you find out what is causing the crash.


2023-04-25T14:21:41.203 app[fc8e61ad] bos [info] Starting clean up.

Here's the relevant stuff:

[info] Preparing to run: `docker-entrypoint.sh --default-authentication-plugin mysql_native_password --datadir /data/mysql --performance-schema=OFF --innodb-buffer-pool-size 64M` as root
[info] 2023/04/25 14:21:40 listening on [fdaa:0:6ba9:a7b:eb:7:292e:2]:22 (DNS: [fdaa::3]:53)
[info] 2023-04-25 14:21:40+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 8.0.33-1.el8 started.
[info] 2023-04-25 14:21:40+00:00 [ERROR] [Entrypoint]: mysqld failed while attempting to check config
[info] command was: mysqld --default-authentication-plugin mysql_native_password --datadir /data/mysql --performance-schema=OFF --innodb-buffer-pool-size 64M --verbose --help --log-bin-index=/tmp/tmp.p9nJLOlyru
[info] 2023-04-25T14:21:40Z UTC - mysqld got signal 11 ;
[info] Most likely, you have hit a bug, but this error can also be caused by malfunctioning hardware.
[info] BuildID[sha1]=8076d8618232dd0b5c9df333b4ee48d26d2170ca
[info] Thread pointer: 0x0
[info] Attempting backtrace. You can use the following information to find out
[info] where mysqld died. If you see no messages after this, something went
[info] terribly wrong...
[info] stack_bottom = 0 thread_stack 0x100000
[info] /usr/sbin/mysqld(my_print_stacktrace(unsigned char const*, unsigned long)+0x41) [0x2123181]
[info] /usr/sbin/mysqld(print_fatal_signal(int)+0x397) [0xfe6b07]
[info] /usr/sbin/mysqld(handle_fatal_signal+0xa5) [0xfe6bc5]
[info] /lib64/libpthread.so.0(+0x12d00) [0x7fc0455c9d00]
[info] /usr/sbin/mysqld(Delegate::Delegate(unsigned int)+0xaf) [0x1db91bf]
[info] /usr/sbin/mysqld(delegates_init()+0x34) [0x1db94c4]
[info] /usr/sbin/mysqld() [0xd6ee6d]
[info] /usr/sbin/mysqld(mysqld_main(int, char**)+0x220f) [0xd7581f]
[info] /lib64/libc.so.6(__libc_start_main+0xe5) [0x7fc043b6ed85]
[info] /usr/sbin/mysqld(_start+0x2e) [0xd5680e]
[info] The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
[info] information that should help you find out what is causing the crash.
[info] Starting clean up.

MySQL 8.0.32 starts up without issue (via the official Docker container)

@tianon tianon mentioned this issue May 9, 2023
Closed
@fideloper
Copy link
Author

Unfortunately, this continues with version 8.0.34, same error when attempting to boot the official MySQL image on a Fly.io VM

[info]2023-09-18 14:01:31+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 8.0.34-1.el8 started.
[info]2023-09-18 14:01:32+00:00 [ERROR] [Entrypoint]: mysqld failed while attempting to check config
[info] command was: mysqld --datadir /data/mysql --default-authentication-plugin mysql_native_password --performance-schema=OFF --innodb-buffer-pool-size 64M --verbose --help --log-bin-index=/tmp/tmp.TOh7WZIsF4
[info] 2023-09-18T14:01:32Z UTC - mysqld got signal 11 ;
[info]Most likely, you have hit a bug, but this error can also be caused by malfunctioning hardware.
[info]BuildID[sha1]=1758de1e111952b1f61480360c447dc27d6caddc
[info]Thread pointer: 0x0
[info]Attempting backtrace. You can use the following information to find out
[info]where mysqld died. If you see no messages after this, something went
[info]terribly wrong...
[info]stack_bottom = 0 thread_stack 0x100000
[info]/usr/sbin/mysqld(my_print_stacktrace(unsigned char const*, unsigned long)+0x41) [0x2130f51]
[info]/usr/sbin/mysqld(print_fatal_signal(int)+0x397) [0xfee797]
[info]/usr/sbin/mysqld(handle_fatal_signal+0xa5) [0xfee855]
[info]/lib64/libpthread.so.0(+0x12d40) [0x7fa6d58dcd40]
[info]/usr/sbin/mysqld(Delegate::Delegate(unsigned int)+0xaf) [0x1dc4e6f]
[info]/usr/sbin/mysqld(delegates_init()+0x34) [0x1dc5174]
[info]/usr/sbin/mysqld() [0xd7473d]
[info]/usr/sbin/mysqld(mysqld_main(int, char**)+0x23fb) [0xd7b45b]
[info]/lib64/libc.so.6(__libc_start_main+0xe5) [0x7fa6d3e82e45]
[info]/usr/sbin/mysqld(_start+0x2e) [0xd5c17e]
[info]The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
[info]information that should help you find out what is causing the crash.

@helloqiu
Copy link

MySQL used a new malloc function my_aligned_malloc in 8.0.33:
mysql/mysql-server@be8348a
According to the stack:
/usr/sbin/mysqld(Delegate::Delegate(unsigned int)+0xaf)
mysqld malloc an atomic<int> and wrote '0' into it then crashed here: https://github.com/mysql/mysql-server/blob/ea7087d885006918ad54458e7aad215b1650312c/sql/rpl_handler.cc#L94
This error may be caused by the new malloc function.

@fideloper
Copy link
Author

fideloper commented Nov 1, 2023 •
edited
Loading

Hi! Thanks for the shout out!

That looks like perhaps a fix is in place? Altho that's for mysql-cluster 8.2 rather than mysql-server, so I'm not sure if that helps us here!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@tianon @fideloper @helloqiu