Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-7694

MariaDB - mysqld cannot start when restarting from systemd

Details

    Description

      MariaDB - mysqld cannot start when restarting from systemd

      s390vsl048:~/tmpmariadb # systemctl restart mysql.service
      s390vsl048:~/tmpmariadb # mysql -u ssluser -pssluser -D test --ssl-cipher=DHE-RSA-AES256-SHA:AES128-SHA --ssl-ca=/etc/mysql/certs/ca-cert.pem --ssl-cert=/etc/mysql/certs/client-cert.pem --ssl-key=/etc/mysql/certs/client-key.pem
      ERROR 2013 (HY000): Lost connection to MySQL server at 'reading initial communication packet', system error: 104 "Connection reset by peer"

      s390vsl048:~/tmpmariadb # systemctl status mysql.service
      mysql.service - LSB: Start the MySQL database server
         Loaded: loaded (/etc/init.d/mysql)
         Active: active (exited) since Fri 2015-03-06 17:57:33 CET; 3min 21s ago
        Process: 6875 ExecStop=/etc/init.d/mysql stop (code=exited, status=0/SUCCESS)
        Process: 6942 ExecStart=/etc/init.d/mysql start (code=exited, status=0/SUCCESS)
       
      Mar 06 17:57:33 s390vsl048 mysql[6942]: Starting service MySQL Starting service MySQL ..done

      s390vsl048:~/tmpmariadb # systemctl restart mysql.service
      Job for mysql.service failed. See "systemctl status mysql.service" and "journalctl -xn" for details.

      s390vsl048:~/tmpmariadb # journalctl -xn
      -- Logs begin at Fri 2015-03-06 17:46:11 CET, end at Fri 2015-03-06 18:01:30 CET. --
      Mar 06 17:57:33 s390vsl048 mysql[6942]: Starting service MySQL Starting service MySQL ..done
      Mar 06 18:00:01 s390vsl048 kernel: type=1006 audit(1425661201.794:45): pid=7221 uid=0 old auid=4294967295 new auid=0 old ses=4294967295 new ses=4 res=1
      Mar 06 18:00:01 s390vsl048 cron[7221]: pam_unix(crond:session): session opened for user root by (uid=0)
      Mar 06 18:00:01 s390vsl048 CRON[7221]: pam_unix(crond:session): session closed for user root
      Mar 06 18:01:30 s390vsl048 systemd[1]: Stopping LSB: Start the MySQL database server...
      -- Subject: Unit mysql.service has begun shutting down
      -- Defined-By: systemd
      -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
      -- 
      -- Unit mysql.service has begun shutting down.
      Mar 06 18:01:30 s390vsl048 mysql[7289]: Shutting down service MySQL ..done
      Mar 06 18:01:30 s390vsl048 mysql[7318]: Starting service MySQL Starting service MySQL chmod: cannot access '/var/run/mysql/mysqld.pid': No such file or directory
      Mar 06 18:01:30 s390vsl048 systemd[1]: Failed to start LSB: Start the MySQL database server.
      -- Subject: Unit mysql.service has failed
      -- Defined-By: systemd
      -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
      -- 
      -- Unit mysql.service has failed.
      -- 
      -- The result is failed.
      Mar 06 18:01:30 s390vsl048 systemd[1]: Unit mysql.service entered failed state.
      Mar 06 18:01:30 s390vsl048 mysql[7318]: ..failed

      == mysqld.log ==

      150306 17:57:32 [Note] /usr/sbin/mysqld: Shutdown complete
       
      150306 17:57:32 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
      150306 17:57:32 [Note] InnoDB: Using mutexes to ref count buffer pool pages
      150306 17:57:32 [Note] InnoDB: The InnoDB memory heap is disabled
      150306 17:57:32 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
      150306 17:57:32 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
      150306 17:57:32 [Note] InnoDB: Compressed tables use zlib 1.2.8
      150306 17:57:32 [Note] InnoDB: Using Linux native AIO
      150306 17:57:32 [Note] InnoDB: Not using CPU crc32 instructions
      150306 17:57:32 [Note] InnoDB: Initializing buffer pool, size = 128.0M
      150306 17:57:32 [Note] InnoDB: Completed initialization of buffer pool
      150306 17:57:32 [Note] InnoDB: Highest supported file format is Barracuda.
      150306 17:57:33 [Note] InnoDB: 128 rollback segment(s) are active.
      150306 17:57:33 [Note] InnoDB: Waiting for purge to start
      150306 17:57:33 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.22-71.0 started; log sequence number 1616797
      150306 17:57:33 [Note] Server socket created on IP: '::'.
      150306 17:57:33 [Note] Event Scheduler: Loaded 0 events
      150306 17:57:33 [Note] /usr/sbin/mysqld: ready for connections.
      Version: '10.0.16-MariaDB'  socket: '/var/run/mysql/mysql.sock'  port: 3306  openSUSE package
      150306 17:57:33 mysqld_safe Number of processes running now: 1
      150306 17:57:33 mysqld_safe mysqld process hanging, pid 7111 - killed
      150306 17:57:33 mysqld_safe mysqld restarted
      150306 17:57:33 [ERROR] mysqld: Can't lock aria control file '/var/lib/mysql/aria_log_control' for exclusive use, error: 11. Will retry for 30 seconds
      150306 17:57:34 mysqld_safe mysqld from pid file /var/run/mysql/mysqld.pid ended
      150306 17:57:35 [Note] InnoDB: Using mutexes to ref count buffer pool pages
      150306 17:57:35 [Note] InnoDB: The InnoDB memory heap is disabled
      150306 17:57:35 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
      150306 17:57:35 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
      150306 17:57:35 [Note] InnoDB: Compressed tables use zlib 1.2.8
      150306 17:57:35 [Note] InnoDB: Using Linux native AIO
      150306 17:57:35 [Note] InnoDB: Not using CPU crc32 instructions
      150306 17:57:35 [ERROR] mysqld: Can't create/write to file '/var/tmp/mysql.DjJntU/ibuao7B9' (Errcode: 2 "No such file or directory")
      2015-03-06 17:57:35 3fffd051730  InnoDB: Error: unable to create temporary file; errno: 2
      150306 17:57:35 [ERROR] Plugin 'InnoDB' init function returned error.
      150306 17:57:35 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
      150306 17:57:35 [ERROR] Unknown/unsupported storage engine: InnoDB
      150306 17:57:35 [ERROR] Aborting
       
      150306 17:57:35 [Note] /usr/sbin/mysqld: Shutdown complete

      Workaround: - use stop and start
      ================================

      s390vsl048:~/tmpmariadb # systemctl stop mysql.service
      s390vsl048:~/tmpmariadb # systemctl status mysql.service
      mysql.service - LSB: Start the MySQL database server
         Loaded: loaded (/etc/init.d/mysql)
         Active: failed (Result: exit-code) since Fri 2015-03-06 18:01:30 CET; 54s ago
        Process: 7289 ExecStop=/etc/init.d/mysql stop (code=exited, status=0/SUCCESS)
        Process: 7318 ExecStart=/etc/init.d/mysql start (code=exited, status=1/FAILURE)
       
      Mar 06 18:01:30 s390vsl048 mysql[7318]: Starting service MySQL Starting service MySQL chmod: cannot access '/var/run/mysql/mysqld.pid': No such file or directory
      Mar 06 18:01:30 s390vsl048 systemd[1]: Failed to start LSB: Start the MySQL database server.
      Mar 06 18:01:30 s390vsl048 systemd[1]: Unit mysql.service entered failed state.
      Mar 06 18:01:30 s390vsl048 mysql[7318]: ..failed

      s390vsl048:~/tmpmariadb # systemctl start mysql.service
      s390vsl048:~/tmpmariadb # systemctl status mysql.service
      mysql.service - LSB: Start the MySQL database server
         Loaded: loaded (/etc/init.d/mysql)
         Active: active (running) since Fri 2015-03-06 18:02:29 CET; 1s ago
        Process: 7289 ExecStop=/etc/init.d/mysql stop (code=exited, status=0/SUCCESS)
        Process: 7542 ExecStart=/etc/init.d/mysql start (code=exited, status=0/SUCCESS)
         CGroup: /system.slice/mysql.service
                 |-7366 /bin/sh /usr/bin/mysqld_safe --mysqld=mysqld --user=mysql --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock --datadir=/var/lib/mysql...
                 `-7487 /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --user=mysql --log-error=/var/log/mysql/mysqld.log --pid-fil...
       
      Mar 06 18:02:29 s390vsl048 mysql[7542]: ..done
      s390vsl048:~/tmpmariadb # mysql -u ssluser -pssluser -D test --ssl-cipher=DHE-RSA-AES256-SHA:AES128-SHA --ssl-ca=/etc/mysql/certs/ca-cert.pem --ssl-cert=/etc/mysql/certs/client-cert.pem --ssl-key=/etc/mysql/certs/client-key.pem
      Welcome to the MariaDB monitor.  Commands end with ; or \g.
      Your MariaDB connection id is 2
      Server version: 10.0.16-MariaDB openSUSE package

      Note:
      Cannot reproduce on every system but looks like on s390 is 100 reproducible.

      https://bugzilla.suse.com/show_bug.cgi?id=921115

      Attachments

        Issue Links

          Activity

            vkijasev Viktor Kijasev added a comment - - edited

            Hi Elena,
            (sorry for late answer)
            Yes it is still happening:

            s390vsl020:~/tmpmariadb # systemctl restart mysql.service 
            Job for mysql.service failed. See "systemctl status mysql.service" and "journalctl -xn" for details.
            s390vsl020:~/tmpmariadb # systemctl status mysql.service
            mysql.service - LSB: Start the MySQL database server
               Loaded: loaded (/etc/init.d/mysql)
               Active: failed (Result: exit-code) since Wed 2015-04-15 11:39:41 CEST; 9s ago
              Process: 32954 ExecStop=/etc/init.d/mysql stop (code=exited, status=0/SUCCESS)
              Process: 32981 ExecStart=/etc/init.d/mysql start (code=exited, status=1/FAILURE)
             
            Apr 15 11:39:41 s390vsl020 mysql[32981]: Starting service MySQL Starting service MySQL chmod: cannot access '/var/run/mysql/mysqld.pid': No such file or directory
            Apr 15 11:39:41 s390vsl020 systemd[1]: Unit mysql.service entered failed state.
            Apr 15 11:39:41 s390vsl020 mysql[32981]: ..failed
            s390vsl020:~/tmpmariadb # journalctl -xn
            -- Logs begin at Thu 2015-04-09 16:18:57 CEST, end at Wed 2015-04-15 11:39:41 CEST. --
            Apr 15 11:30:01 s390vsl020 CRON[32475]: pam_unix(crond:session): session closed for user root
            Apr 15 11:38:49 s390vsl020 systemd[1]: Configuration file /usr/lib/systemd/system/wdmd.service is marked executable. Please remove executable permission bits. Proceeding anyway.
            Apr 15 11:38:56 s390vsl020 systemd[1]: Stopping LSB: Start the MySQL database server...
            -- Subject: Unit mysql.service has begun shutting down
            -- Defined-By: systemd
            -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
            -- 
            -- Unit mysql.service has begun shutting down.
            Apr 15 11:38:58 s390vsl020 mysql[32677]: Shutting down service MySQL ..done
            Apr 15 11:38:58 s390vsl020 mysql[32727]: Starting service MySQL Starting service MySQL ..done
            Apr 15 11:39:40 s390vsl020 systemd[1]: Stopping LSB: Start the MySQL database server...
            -- Subject: Unit mysql.service has begun shutting down
            -- Defined-By: systemd
            -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
            -- 
            -- Unit mysql.service has begun shutting down.
            Apr 15 11:39:40 s390vsl020 mysql[32954]: Shutting down service MySQL ..done
            Apr 15 11:39:41 s390vsl020 mysql[32981]: Starting service MySQL Starting service MySQL chmod: cannot access '/var/run/mysql/mysqld.pid': No such file or directory
            Apr 15 11:39:41 s390vsl020 systemd[1]: Unit mysql.service entered failed state.
            Apr 15 11:39:41 s390vsl020 mysql[32981]: ..failed
            s390vsl020:~/tmpmariadb # ps -ef | grep mysqld
            root     33031     1  0 11:39 ?        00:00:00 /bin/sh /usr/bin/mysqld_safe --mysqld=mysqld --user=mysql --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock --datadir=/var/lib/mysql
            mysql    33140 33031  0 11:39 ?        00:00:00 /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --user=mysql --log-error=/var/log/mysql/mysqld.log --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock
            root     33193 29773  0 11:41 pts/0    00:00:00 grep --color=auto mysqld
            s390vsl020:~/tmpmariadb # ps -ef | grep mysqld
            root     33031     1  0 11:39 ?        00:00:00 /bin/sh /usr/bin/mysqld_safe --mysqld=mysqld --user=mysql --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock --datadir=/var/lib/mysql
            mysql    33140 33031  0 11:39 ?        00:00:00 /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --user=mysql --log-error=/var/log/mysql/mysqld.log --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock
            root     33211 29773  0 11:42 pts/0    00:00:00 grep --color=auto mysqld
            s390vsl020:~/tmpmariadb # ps -ef | grep mysqld
            root     33031     1  0 11:39 ?        00:00:00 /bin/sh /usr/bin/mysqld_safe --mysqld=mysqld --user=mysql --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock --datadir=/var/lib/mysql
            mysql    33140 33031  0 11:39 ?        00:00:00 /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --user=mysql --log-error=/var/log/mysql/mysqld.log --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock
            root     33215 29773  0 11:42 pts/0    00:00:00 grep --color=auto mysqld
            s390vsl020:~/tmpmariadb # ps -ef | grep mysqld
            root     33031     1  0 11:39 ?        00:00:00 /bin/sh /usr/bin/mysqld_safe --mysqld=mysqld --user=mysql --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock --datadir=/var/lib/mysql
            mysql    33140 33031  0 11:39 ?        00:00:00 /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --user=mysql --log-error=/var/log/mysql/mysqld.log --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock
            root     33219 29773  0 11:42 pts/0    00:00:00 grep --color=auto mysqld
            s390vsl020:~/tmpmariadb # ps -ef | grep mysqld
            root     33031     1  0 11:39 ?        00:00:00 /bin/sh /usr/bin/mysqld_safe --mysqld=mysqld --user=mysql --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock --datadir=/var/lib/mysql
            mysql    33140 33031  0 11:39 ?        00:00:00 /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --user=mysql --log-error=/var/log/mysql/mysqld.log --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock
            root     33222 29773  0 11:42 pts/0    00:00:00 grep --color=auto mysqld
            s390vsl020:~/tmpmariadb # ps -ef | grep mysqld
            root     33031     1  0 11:39 ?        00:00:00 /bin/sh /usr/bin/mysqld_safe --mysqld=mysqld --user=mysql --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock --datadir=/var/lib/mysql
            mysql    33140 33031  0 11:39 ?        00:00:00 /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --user=mysql --log-error=/var/log/mysql/mysqld.log --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock
            root     33226 29773  0 11:43 pts/0    00:00:00 grep --color=auto mysqld
            s390vsl020:~/tmpmariadb # date;ps -ef | grep mysqld
            Wed Apr 15 11:43:22 CEST 2015
            root     33031     1  0 11:39 ?        00:00:00 /bin/sh /usr/bin/mysqld_safe --mysqld=mysqld --user=mysql --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock --datadir=/var/lib/mysql
            mysql    33140 33031  0 11:39 ?        00:00:00 /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --user=mysql --log-error=/var/log/mysql/mysqld.log --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock
            root     33234 29773  0 11:43 pts/0    00:00:00 grep --color=auto mysqld

            vkijasev Viktor Kijasev added a comment - - edited Hi Elena, (sorry for late answer) Yes it is still happening: s390vsl020:~/tmpmariadb # systemctl restart mysql.service Job for mysql.service failed. See "systemctl status mysql.service" and "journalctl -xn" for details. s390vsl020:~/tmpmariadb # systemctl status mysql.service mysql.service - LSB: Start the MySQL database server Loaded: loaded (/etc/init.d/mysql) Active: failed (Result: exit-code) since Wed 2015-04-15 11:39:41 CEST; 9s ago Process: 32954 ExecStop=/etc/init.d/mysql stop (code=exited, status=0/SUCCESS) Process: 32981 ExecStart=/etc/init.d/mysql start (code=exited, status=1/FAILURE)   Apr 15 11:39:41 s390vsl020 mysql[32981]: Starting service MySQL Starting service MySQL chmod: cannot access '/var/run/mysql/mysqld.pid': No such file or directory Apr 15 11:39:41 s390vsl020 systemd[1]: Unit mysql.service entered failed state. Apr 15 11:39:41 s390vsl020 mysql[32981]: ..failed s390vsl020:~/tmpmariadb # journalctl -xn -- Logs begin at Thu 2015-04-09 16:18:57 CEST, end at Wed 2015-04-15 11:39:41 CEST. -- Apr 15 11:30:01 s390vsl020 CRON[32475]: pam_unix(crond:session): session closed for user root Apr 15 11:38:49 s390vsl020 systemd[1]: Configuration file /usr/lib/systemd/system/wdmd.service is marked executable. Please remove executable permission bits. Proceeding anyway. Apr 15 11:38:56 s390vsl020 systemd[1]: Stopping LSB: Start the MySQL database server... -- Subject: Unit mysql.service has begun shutting down -- Defined-By: systemd -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel -- -- Unit mysql.service has begun shutting down. Apr 15 11:38:58 s390vsl020 mysql[32677]: Shutting down service MySQL ..done Apr 15 11:38:58 s390vsl020 mysql[32727]: Starting service MySQL Starting service MySQL ..done Apr 15 11:39:40 s390vsl020 systemd[1]: Stopping LSB: Start the MySQL database server... -- Subject: Unit mysql.service has begun shutting down -- Defined-By: systemd -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel -- -- Unit mysql.service has begun shutting down. Apr 15 11:39:40 s390vsl020 mysql[32954]: Shutting down service MySQL ..done Apr 15 11:39:41 s390vsl020 mysql[32981]: Starting service MySQL Starting service MySQL chmod: cannot access '/var/run/mysql/mysqld.pid': No such file or directory Apr 15 11:39:41 s390vsl020 systemd[1]: Unit mysql.service entered failed state. Apr 15 11:39:41 s390vsl020 mysql[32981]: ..failed s390vsl020:~/tmpmariadb # ps -ef | grep mysqld root 33031 1 0 11:39 ? 00:00:00 /bin/sh /usr/bin/mysqld_safe --mysqld=mysqld --user=mysql --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock --datadir=/var/lib/mysql mysql 33140 33031 0 11:39 ? 00:00:00 /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --user=mysql --log-error=/var/log/mysql/mysqld.log --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock root 33193 29773 0 11:41 pts/0 00:00:00 grep --color=auto mysqld s390vsl020:~/tmpmariadb # ps -ef | grep mysqld root 33031 1 0 11:39 ? 00:00:00 /bin/sh /usr/bin/mysqld_safe --mysqld=mysqld --user=mysql --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock --datadir=/var/lib/mysql mysql 33140 33031 0 11:39 ? 00:00:00 /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --user=mysql --log-error=/var/log/mysql/mysqld.log --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock root 33211 29773 0 11:42 pts/0 00:00:00 grep --color=auto mysqld s390vsl020:~/tmpmariadb # ps -ef | grep mysqld root 33031 1 0 11:39 ? 00:00:00 /bin/sh /usr/bin/mysqld_safe --mysqld=mysqld --user=mysql --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock --datadir=/var/lib/mysql mysql 33140 33031 0 11:39 ? 00:00:00 /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --user=mysql --log-error=/var/log/mysql/mysqld.log --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock root 33215 29773 0 11:42 pts/0 00:00:00 grep --color=auto mysqld s390vsl020:~/tmpmariadb # ps -ef | grep mysqld root 33031 1 0 11:39 ? 00:00:00 /bin/sh /usr/bin/mysqld_safe --mysqld=mysqld --user=mysql --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock --datadir=/var/lib/mysql mysql 33140 33031 0 11:39 ? 00:00:00 /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --user=mysql --log-error=/var/log/mysql/mysqld.log --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock root 33219 29773 0 11:42 pts/0 00:00:00 grep --color=auto mysqld s390vsl020:~/tmpmariadb # ps -ef | grep mysqld root 33031 1 0 11:39 ? 00:00:00 /bin/sh /usr/bin/mysqld_safe --mysqld=mysqld --user=mysql --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock --datadir=/var/lib/mysql mysql 33140 33031 0 11:39 ? 00:00:00 /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --user=mysql --log-error=/var/log/mysql/mysqld.log --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock root 33222 29773 0 11:42 pts/0 00:00:00 grep --color=auto mysqld s390vsl020:~/tmpmariadb # ps -ef | grep mysqld root 33031 1 0 11:39 ? 00:00:00 /bin/sh /usr/bin/mysqld_safe --mysqld=mysqld --user=mysql --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock --datadir=/var/lib/mysql mysql 33140 33031 0 11:39 ? 00:00:00 /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --user=mysql --log-error=/var/log/mysql/mysqld.log --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock root 33226 29773 0 11:43 pts/0 00:00:00 grep --color=auto mysqld s390vsl020:~/tmpmariadb # date;ps -ef | grep mysqld Wed Apr 15 11:43:22 CEST 2015 root 33031 1 0 11:39 ? 00:00:00 /bin/sh /usr/bin/mysqld_safe --mysqld=mysqld --user=mysql --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock --datadir=/var/lib/mysql mysql 33140 33031 0 11:39 ? 00:00:00 /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --user=mysql --log-error=/var/log/mysql/mysqld.log --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock root 33234 29773 0 11:43 pts/0 00:00:00 grep --color=auto mysqld

            Also I was suspicious before, it can be related to setting up ssl connection - like creating new ssl user, generating certificates, opening session as ssl user etc.
            After that I saw this problem.
            And last time after the reboot of machine I could not reproduce it again.
            (however I may be wrong)

            vkijasev Viktor Kijasev added a comment - Also I was suspicious before, it can be related to setting up ssl connection - like creating new ssl user, generating certificates, opening session as ssl user etc. After that I saw this problem. And last time after the reboot of machine I could not reproduce it again. (however I may be wrong)

            So, there is nothing wrong with the actual server startup, mysqld_safe starts once, survives, and starts mysqld which also survives. The whole problem is simply the service script not being able to chmod on the pid file, apparently because the pid file doesn't get created in time.

            I don't know if it can be related to SSL – I suppose hypothetically it's possible if some SSL-related activity happens upon startup before creating the pid file, thus delaying it a little bit. I didn't check it though.

            Daniel's changes look rather invasive, I don't know if they'll make it to the 10.0 which is well post-GA.

            On the other hand, this particular problem can probably have a simple workaround. Currently chmod on the pid file is the very last thing the service script does, then it exits with the status of the operation. While with the socket file there is a wait, and even after the wait its absence is not considered an error, with the pid file it's much simpler – a single attempt to chmod and then exit. I suppose adding at least a timed wait on the pid file should highly reduce the probability of the failure, if not eliminate it completely.

            elenst Elena Stepanova added a comment - So, there is nothing wrong with the actual server startup, mysqld_safe starts once, survives, and starts mysqld which also survives. The whole problem is simply the service script not being able to chmod on the pid file, apparently because the pid file doesn't get created in time. I don't know if it can be related to SSL – I suppose hypothetically it's possible if some SSL-related activity happens upon startup before creating the pid file, thus delaying it a little bit. I didn't check it though. Daniel's changes look rather invasive, I don't know if they'll make it to the 10.0 which is well post-GA. On the other hand, this particular problem can probably have a simple workaround. Currently chmod on the pid file is the very last thing the service script does, then it exits with the status of the operation. While with the socket file there is a wait, and even after the wait its absence is not considered an error, with the pid file it's much simpler – a single attempt to chmod and then exit. I suppose adding at least a timed wait on the pid file should highly reduce the probability of the failure, if not eliminate it completely.
            danblack Daniel Black added a comment -

            Daniel's changes look rather invasive

            Predominately in the socket activation mode of systemd.

            Removing 'Requires=%p.socket' from the mariadb.service would make this run in the Type=Notify mode which also bypasses the pid file/mysqld_safe issues and all of the socket activation code (https://github.com/MariaDB/server/pull/26/files#diff-e7d51f293adc9257284fbdec858056dfR6149 because sd_listen_fds() return 0). The storage engine notify commands could also be removed from 10.0 if this is too much.

            some SSL-related activity happens upon startup before creating the pid file, thus delaying it a little bit. I didn't check it though.

            init_ssl is called in mysqd just before the bit that creates the pid. While it initializes a few variables and reads the ssl server side key/certs it doesn't seem to be that intensive.

            The whole problem is simply the service script not being able to chmod on the pid file, apparently because the pid file doesn't get created in time

            Looks like it too me too. And why is it doing a chmod on a pid file anyway? No idea.

            danblack Daniel Black added a comment - Daniel's changes look rather invasive Predominately in the socket activation mode of systemd. Removing 'Requires=%p.socket' from the mariadb.service would make this run in the Type=Notify mode which also bypasses the pid file/mysqld_safe issues and all of the socket activation code ( https://github.com/MariaDB/server/pull/26/files#diff-e7d51f293adc9257284fbdec858056dfR6149 because sd_listen_fds() return 0). The storage engine notify commands could also be removed from 10.0 if this is too much. some SSL-related activity happens upon startup before creating the pid file, thus delaying it a little bit. I didn't check it though. init_ssl is called in mysqd just before the bit that creates the pid. While it initializes a few variables and reads the ssl server side key/certs it doesn't seem to be that intensive. The whole problem is simply the service script not being able to chmod on the pid file, apparently because the pid file doesn't get created in time Looks like it too me too. And why is it doing a chmod on a pid file anyway? No idea.

            As far as I understand, it's not a MariaDB bug, both mysqld and mysqld_safe work correctly. This is an issue with the systemd service script, but we do not have systemd service script (yet). You're having a problem with a third-party systemd service script, we cannot fix it.

            But there is MDEV-427 which is about a native MariaDB systemd support. When it will be released, you will be able to use our systemd service script, which will not have this issue.

            serg Sergei Golubchik added a comment - As far as I understand, it's not a MariaDB bug, both mysqld and mysqld_safe work correctly. This is an issue with the systemd service script, but we do not have systemd service script (yet). You're having a problem with a third-party systemd service script, we cannot fix it. But there is MDEV-427 which is about a native MariaDB systemd support. When it will be released, you will be able to use our systemd service script, which will not have this issue.

            People

              serg Sergei Golubchik
              nirbhay_c Nirbhay Choubey (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              5 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

                  Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.