[MDEV-9382] After updating mariadb server apt-configure fails Created: 2016-01-07  Updated: 2016-03-31  Resolved: 2016-03-18

Status: Closed
Project: MariaDB Server
Component/s: Platform Debian
Affects Version/s: 10.1.10
Fix Version/s: 10.1.13

Type: Bug Priority: Major
Reporter: Jorge Ferrando Assignee: Nirbhay Choubey (Inactive)
Resolution: Fixed Votes: 0
Labels: apt, debian
Environment:

Ubuntu 14.04

Attachments: File cluster.cnf     File my.cnf     Text File syslog.log    
Issue Links:
Relates
relates to MDEV-9202 Systemd timeout is not sufficient for... Closed
relates to MDEV-8509 make it possible to change MYSQLD_STA... Closed
Sprint: 10.1.13

 Description   

After apt-upgrade mariadb, apt shows a fail trying to start but in fact the database is up and running and that provokes apt to remain in a non finished state.

Every time I do apt-upgrade it tries to stop and start the database with the same result

# apt-get upgrade
 
Reading package lists... Done
 
Building dependency tree
 
Reading state information... Done
 
Calculating upgrade... Done
 
0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
 
2 not fully installed or removed.
 
After this operation, 0 B of additional disk space will be used.
 
Do you want to continue? [Y/n]
 
Setting up mariadb-server-10.1 (10.1.10+maria-1~trusty) ...
 
 * Stopping MariaDB database server mysqld
 
   ...done.
 
 * Starting MariaDB database server mysqld
 
   ...fail!
 
invoke-rc.d: initscript mysql, action "start" failed.
 
dpkg: error processing package mariadb-server-10.1 (--configure):
 
 subprocess installed post-installation script returned error exit status 1
 
dpkg: dependency problems prevent configuration of mariadb-server:
 
 mariadb-server depends on mariadb-server-10.1 (= 10.1.10+maria-1~trusty); however:
 
  Package mariadb-server-10.1 is not configured yet.
 
 
 
dpkg: error processing package mariadb-server (--configure):
 
 dependency problems - leaving unconfigured
 
No apport report written because the error message indicates its a followup error from a previous failure.
 
                                                                                                          Errors were encountered while processing:
 
 mariadb-server-10.1
 
 mariadb-server
 
E: Sub-process /usr/bin/dpkg returned an error code (1)



 Comments   
Comment by Jorge Ferrando [ 2016-01-11 ]

Same symptoms restarting the service:

# service mysql restart
 
 * Stopping MariaDB database server mysqld
 
   ...done.
 
 * Starting MariaDB database server mysqld
 
   ...fail!

But mariadb starts correctly

Comment by Elena Stepanova [ 2016-01-11 ]

jorfermo,

Please attach or paste the contents of syslog, error log or wherever your MariaDB server error log is written, at least from the last server start that happened before the upgrade attempt, and till after it failed.

Please also paste the output of 

dpkg -l | grep -iE 'mysql|maria'
 
ps -ef | grep mysql

and attach your cnf file(s).

Thanks.

Comment by Jorge Ferrando [ 2016-01-11 ]

I attached the syslog output for mysqld after service restart cluster.cnf my.cnf syslog.log and the cnf files

# dpkg -l | grep -iE 'mysql|maria'
 
ii  libdbd-mysql-perl                    4.025-1                          amd64        Perl5 database interface to the MySQL database
 
ii  libmariadbclient18                   10.1.10+maria-1~trusty           amd64        MariaDB database client library
 
ii  libmysqlclient18                     10.1.10+maria-1~trusty           amd64        Virtual package to satisfy external depends
 
ii  mariadb-client-10.1                  10.1.10+maria-1~trusty           amd64        MariaDB database client binaries
 
ii  mariadb-client-core-10.1             10.1.10+maria-1~trusty           amd64        MariaDB database core client binaries
 
ii  mariadb-common                       10.1.10+maria-1~trusty           all          MariaDB database common files (e.g. /etc/mysql/conf.d/mariadb.cnf)
 
iU  mariadb-server                       10.1.10+maria-1~trusty           all          MariaDB database server (metapackage depending on the latest version)
 
iF  mariadb-server-10.1                  10.1.10+maria-1~trusty           amd64        MariaDB database server binaries
 
ii  mariadb-server-core-10.1             10.1.10+maria-1~trusty           amd64        MariaDB database core server files
 
ii  mysql-common                         10.1.10+maria-1~trusty           all          MariaDB database common files (e.g. /etc/mysql/my.cnf)

Comment by Elena Stepanova [ 2016-01-12 ]

Thanks.

So, it's just the slow SST and systemd timeout. I believe it's exactly the problem that is currently being discussed in scope of MDEV-9202.

nirbhay_c, do you agree?

Comment by Jorge Ferrando [ 2016-01-12 ]

I followed the steps suggested on that thread, creating the file /etc/systemd/system/mariadb.service.d/timeout.conf

with content

[Service]
 
 
 
TimeoutStartSec=0

But I'm still having the same problem. Did I miss something?

EDIT: I'm using Ubuntu 14.04. I think it doesn't use systemd but upstart. What would be the steps in this case?

Comment by Elena Stepanova [ 2016-01-12 ]

My bad, indeed, Trusty shouldn't be using systemd.
It still looks like a timing problem – either some kind of timeout, or startup script getting a bad response from the server while SST is running, or something alike. If so, it shouldn't be unique. nirbhay_c, have you seen this before?

Comment by Jorge Ferrando [ 2016-02-02 ]

Any news on this? Anything I can try?

It's a pain having mariadb rebooted everytime apt-get is run

Comment by Jorge Ferrando [ 2016-02-26 ]

It's not fixed:

# apt-get upgrade
 
Reading package lists... Done
 
Building dependency tree
 
Reading state information... Done
 
Calculating upgrade... Done
 
0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
 
2 not fully installed or removed.
 
After this operation, 0 B of additional disk space will be used.
 
Do you want to continue? [Y/n]
 
Setting up mariadb-server-10.1 (10.1.12+maria-1~trusty) ...
 
 * Stopping MariaDB database server mysqld
 
   ...done.
 
 * Starting MariaDB database server mysqld
 
   ...fail!
 
invoke-rc.d: initscript mysql, action "start" failed.
 
dpkg: error processing package mariadb-server-10.1 (--configure):
 
 subprocess installed post-installation script returned error exit status 1
 
dpkg: dependency problems prevent configuration of mariadb-server:
 
 mariadb-server depends on mariadb-server-10.1 (= 10.1.12+maria-1~trusty); however:
 
  Package mariadb-server-10.1 is not configured yet.
 
 
 
dpkg: error processing package mariadb-server (--configure):
 
 dependency problems - leaving unconfigured
 
No apport report written because the error message indicates its a followup error from a previous failure.
 
                                                                                                          Errors were encountered while processing:
 
 mariadb-server-10.1
 
 mariadb-server
 
E: Sub-process /usr/bin/dpkg returned an error code (1)

Comment by Nirbhay Choubey (Inactive) [ 2016-02-26 ]

jorfermo Could you please paste MariaDB related errors you get in either its error log or syslog around the time this failure happens?

Comment by Jorge Ferrando [ 2016-02-26 ]

Here it is:

Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139801150134016 [Note] /usr/sbin/mysqld: Normal shutdown
 
Feb 26 18:46:46 mysqld:
 
Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139801150134016 [Note] WSREP: Stop replication
 
Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139801150134016 [Note] WSREP: Closing send monitor...
 
Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139801150134016 [Note] WSREP: Closed send monitor.
 
Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139801150134016 [Note] WSREP: gcomm: terminating thread
 
Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139801150134016 [Note] WSREP: gcomm: joining thread
 
Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139801150134016 [Note] WSREP: gcomm: closing backend
 
Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139801150134016 [Note] WSREP: view(view_id(NON_PRIM,1134827a,55) memb {
 
Feb 26 18:46:46 mysqld: #0111134827a,0
 
Feb 26 18:46:46 mysqld: } joined {
 
Feb 26 18:46:46 mysqld: } left {
 
Feb 26 18:46:46 mysqld: } partitioned {
 
Feb 26 18:46:46 mysqld: #01144c706b4,0
 
Feb 26 18:46:46 mysqld: #011916e4859,0
 
Feb 26 18:46:46 mysqld: })
 
Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139800877086464 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1
 
Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139801150134016 [Note] WSREP: view((empty))
 
Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139801150134016 [Note] WSREP: gcomm: closed
 
Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139800877086464 [Note] WSREP: Flow-control interval: [16, 16]
 
Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139800877086464 [Note] WSREP: Received NON-PRIMARY.
 
Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139800877086464 [Note] WSREP: Shifting SYNCED -> OPEN (TO: 8441351)
 
Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139800877086464 [Note] WSREP: Received self-leave message.
 
Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139800877086464 [Note] WSREP: Flow-control interval: [0, 0]
 
Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139800877086464 [Note] WSREP: Received SELF-LEAVE. Closing connection.
 
Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139800877086464 [Note] WSREP: Shifting OPEN -> CLOSED (TO: 8441351)
 
Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139800877086464 [Note] WSREP: RECV thread exiting 0: Success
 
Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139801168217856 [Note] WSREP: New cluster view: global state: 0b0379b3-a949-11e5-b414-ab8a34af3e6e:8441351, view# -1: non-Primary, number of nodes: 1, my index: 0, protocol version 3
 
Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139801150134016 [Note] WSREP: recv_thread() joined.
 
Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139801150134016 [Note] WSREP: Closing replication queue.
 
Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139801150134016 [Note] WSREP: Closing slave action queue.
 
Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139801168217856 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
 
Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139801168217856 [Note] WSREP: New cluster view: global state: 0b0379b3-a949-11e5-b414-ab8a34af3e6e:8441351, view# -1: non-Primary, number of nodes: 0, my index: -1, protocol version 3
 
Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139801168217856 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
 
Feb 26 18:46:46 mysqld: 2016-02-26 18:46:46 139801168217856 [Note] WSREP: applier thread exiting (code:0)
 
Feb 26 18:46:48 mysqld: 2016-02-26 18:46:48 139801168418560 [Note] WSREP: rollbacker thread exiting
 
Feb 26 18:46:48 mysqld: 2016-02-26 18:46:48 139801150134016 [Note] Event Scheduler: Purging the queue. 0 events
 
Feb 26 18:46:48 mysqld: 2016-02-26 18:46:48 139801150134016 [Note] WSREP: dtor state: CLOSED
 
Feb 26 18:46:48 mysqld: 2016-02-26 18:46:48 139801150134016 [Note] WSREP: mon: entered 37729 oooe fraction 0 oool fraction 0.000185534
 
Feb 26 18:46:48 mysqld: 2016-02-26 18:46:48 139801150134016 [Note] WSREP: mon: entered 37729 oooe fraction 0.0126958 oool fraction 0.000185534
 
Feb 26 18:46:48 mysqld: 2016-02-26 18:46:48 139801150134016 [Note] WSREP: mon: entered 38357 oooe fraction 0 oool fraction 2.60709e-05
 
Feb 26 18:46:48 mysqld: 2016-02-26 18:46:48 139801150134016 [Note] WSREP: cert index usage at exit 0
 
Feb 26 18:46:48 mysqld: 2016-02-26 18:46:48 139801150134016 [Note] WSREP: cert trx map usage at exit 66
 
Feb 26 18:46:48 mysqld: 2016-02-26 18:46:48 139801150134016 [Note] WSREP: deps set usage at exit 0
 
Feb 26 18:46:48 mysqld: 2016-02-26 18:46:48 139801150134016 [Note] WSREP: avg deps dist 44.8149
 
Feb 26 18:46:48 mysqld: 2016-02-26 18:46:48 139801150134016 [Note] WSREP: avg cert interval 0.0370124
 
Feb 26 18:46:48 mysqld: 2016-02-26 18:46:48 139801150134016 [Note] WSREP: cert index size 150
 
Feb 26 18:46:48 mysqld: 2016-02-26 18:46:48 139800941876992 [Note] WSREP: Service thread queue flushed.
 
Feb 26 18:46:48 mysqld: 2016-02-26 18:46:48 139801150134016 [Note] WSREP: wsdb trx map usage 0 conn query map usage 0
 
Feb 26 18:46:48 mysqld: 2016-02-26 18:46:48 139801150134016 [Note] WSREP: MemPool(LocalTrxHandle): hit ratio: 0.989969, misses: 128, in use: 0, in pool: 128
 
Feb 26 18:46:48 mysqld: 2016-02-26 18:46:48 139801150134016 [Note] WSREP: MemPool(SlaveTrxHandle): hit ratio: 0.995237, misses: 119, in use: 0, in pool: 119
 
Feb 26 18:46:48 mysqld: 2016-02-26 18:46:48 139801150134016 [Note] WSREP: Shifting CLOSED -> DESTROYED (TO: 8441351)
 
Feb 26 18:46:48 mysqld: 2016-02-26 18:46:48 139801150134016 [Note] WSREP: Flushing memory map to disk...
 
Feb 26 18:46:49 mysqld: 2016-02-26 18:46:49 139798006163200 [Note] InnoDB: FTS optimize thread exiting.
 
Feb 26 18:46:49 mysqld: 2016-02-26 18:46:49 139801150134016 [Note] InnoDB: Starting shutdown...
 
Feb 26 18:46:51 mysqld: 2016-02-26 18:46:51 139801150134016 [Note] InnoDB: Shutdown completed; log sequence number 211806924820
 
Feb 26 18:46:51 mysqld: 2016-02-26 18:46:51 139801150134016 [Note] /usr/sbin/mysqld: Shutdown complete
 
Feb 26 18:46:51 mysqld:
 
Feb 26 18:46:51 mysqld_safe: mysqld from pid file /var/run/mysqld/mysqld.pid ended
 
Feb 26 18:46:52 mysqld_safe[11090]: 2016-02-26 18:46:52 140013467244480 [Note] Using unique option prefix 'key_buffer' is error-prone and can break in the future. Please use the full name 'key_buffer_size' instead.
 
Feb 26 18:46:52 mysqld_safe[11090]: 2016-02-26 18:46:52 140013467244480 [Note] /usr/sbin/mysqld (mysqld 10.1.12-MariaDB-1~trusty) starting as process 11118 ...
 
Feb 26 18:47:19 mysqld_safe[11090]: 2016-02-26 18:47:19 139641629259712 [Note] Using unique option prefix 'key_buffer' is error-prone and can break in the future. Please use the full name 'key_buffer_size' instead.
 
Feb 26 18:47:19 mysqld_safe[11090]: 2016-02-26 18:47:19 139641629259712 [Note] /usr/sbin/mysqld (mysqld 10.1.12-MariaDB-1~trusty) starting as process 11177 ...
 
Feb 26 18:47:46 mysqld_safe[11090]: 2016-02-26 18:47:46 139647823509440 [Note] Using unique option prefix 'key_buffer' is error-prone and can break in the future. Please use the full name 'key_buffer_size' instead.
 
Feb 26 18:47:46 mysqld_safe[11090]: 2016-02-26 18:47:46 139647823509440 [Note] /usr/sbin/mysqld (mysqld 10.1.12-MariaDB-1~trusty) starting as process 11256 ...
 
Feb 26 18:48:10 mysqld_safe[11090]:
 
Feb 26 18:48:10 mysqld_safe[11090]: PLEASE REMEMBER TO SET A PASSWORD FOR THE MariaDB root USER !
 
Feb 26 18:48:10 mysqld_safe[11090]: To do so, start the server, then issue the following commands:
 
Feb 26 18:48:10 mysqld_safe[11090]:
 
Feb 26 18:48:10 mysqld_safe[11090]: '/usr/bin/mysqladmin' -u root password 'new-password'
 
Feb 26 18:48:10 mysqld_safe[11090]: '/usr/bin/mysqladmin' -u root -h dbmysql1 password 'new-password'
 
Feb 26 18:48:10 mysqld_safe[11090]:
 
Feb 26 18:48:10 mysqld_safe[11090]: Alternatively you can run:
 
Feb 26 18:48:10 mysqld_safe[11090]: '/usr/bin/mysql_secure_installation'
 
Feb 26 18:48:10 mysqld_safe[11090]:
 
Feb 26 18:48:10 mysqld_safe[11090]: which will also give you the option of removing the test
 
Feb 26 18:48:10 mysqld_safe[11090]: databases and anonymous user created by default.  This is
 
Feb 26 18:48:10 mysqld_safe[11090]: strongly recommended for production servers.
 
Feb 26 18:48:10 mysqld_safe[11090]:
 
Feb 26 18:48:10 mysqld_safe[11090]: See the MariaDB Knowledgebase at http://mariadb.com/kb or the
 
Feb 26 18:48:10 mysqld_safe[11090]: MySQL manual for more instructions.
 
Feb 26 18:48:10 mysqld_safe[11090]:
 
Feb 26 18:48:10 mysqld_safe[11090]: Please report any problems at http://mariadb.org/jira
 
Feb 26 18:48:10 mysqld_safe[11090]:
 
Feb 26 18:48:10 mysqld_safe[11090]: The latest information about MariaDB is available at http://mariadb.org/.
 
Feb 26 18:48:10 mysqld_safe[11090]: You can find additional information about the MySQL part at:
 
Feb 26 18:48:10 mysqld_safe[11090]: http://dev.mysql.com
 
Feb 26 18:48:10 mysqld_safe[11090]: Support MariaDB development by buying support/new features from MariaDB
 
Feb 26 18:48:10 mysqld_safe[11090]: Corporation Ab. You can contact us about this at sales@mariadb.com.
 
Feb 26 18:48:10 mysqld_safe[11090]: Alternatively consider joining our community based development effort:
 
Feb 26 18:48:10 mysqld_safe[11090]: http://mariadb.com/kb/en/contributing-to-the-mariadb-project/
 
Feb 26 18:48:10 mysqld_safe[11090]:
 
Feb 26 18:48:10 mysqld_safe[11325]: 2016-02-26 18:48:10 139966677604288 [Note] Using unique option prefix 'key_buffer' is error-prone and can break in the future. Please use the full name 'key_buffer_size' instead.
 
Feb 26 18:48:10 mysqld_safe[11325]: 2016-02-26 18:48:10 139966677604288 [Note] /usr/sbin/mysqld (mysqld 10.1.12-MariaDB-1~trusty) starting as process 11324 ...
 
Feb 26 18:48:34 mysqld_safe: Starting mysqld_using_numactl daemon with databases from /mnt/disco2/mysql
 
Feb 26 18:48:34 mysqld_safe: WSREP: Running position recovery with --log_error='/mnt/disco2/mysql/wsrep_recovery.lhPGsR' --pid-file='/mnt/disco2/mysql/dbmysql1-recover.pid'
 
Feb 26 18:48:34 mysqld: 2016-02-26 18:48:34 140616772061120 [Note] Using unique option prefix 'key_buffer' is error-prone and can break in the future. Please use the full name 'key_buffer_size' instead.
 
Feb 26 18:48:34 mysqld: 2016-02-26 18:48:34 140616772061120 [Note] /usr/sbin/mysqld (mysqld 10.1.12-MariaDB-1~trusty) starting as process 11759 ...
 
Feb 26 18:48:56 mysqld_safe: WSREP: Recovered position 0b0379b3-a949-11e5-b414-ab8a34af3e6e:8441351
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] Using unique option prefix 'key_buffer' is error-prone and can break in the future. Please use the full name 'key_buffer_size' instead.
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] /usr/sbin/mysqld (mysqld 10.1.12-MariaDB-1~trusty) starting as process 12051 ...
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] WSREP: Read nil XID from storage engines, skipping position init
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib/galera/libgalera_smm.so'
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] WSREP: wsrep_load(): Galera 25.3.14(r3560) by Codership Oy <info@codership.com> loaded successfully.
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] WSREP: CRC-32C: using "slicing-by-8" algorithm.
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] WSREP: Found saved state: 0b0379b3-a949-11e5-b414-ab8a34af3e6e:8441351
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] WSREP: Passing config to GCS: base_dir = /mnt/disco2/mysql/; base_host = ******; base_port = 4567; cert.log_conflicts = no; debug = no; evs.auto_evict = 0; evs.delay_margin = PT1S; evs.delayed_keep_period = PT30S; evs.inactive_check_period = PT0.5S; evs.inactive_timeout = PT15S; evs.join_retrans_period = PT1S; evs.max_install_timeouts = 3; evs.send_window = 4; evs.stats_report_period = PT1M; evs.suspect_timeout = PT5S; evs.user_send_window = 2; evs.view_forget_timeout = PT24H; gcache.dir = /mnt/disco2/mysql/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = /mnt/disco2/mysql//galera.cache; gcache.page_size = 128M; gcache.size = 128M; gcs.fc_debug = 0; gcs.fc_factor = 1.0; gcs.fc_limit = 16; gcs.fc_master_slave = no; gcs.max_packet_size = 64500; gcs.max_throttle = 0.25; gcs.recv_q_hard_limit = 9223372036854775807; gcs.recv_q_soft_limit = 0.25; gcs.sync_donor = no; gmcast.segment = 0; gmcast.version = 0; pc.announce_timeout = PT3S; pc.checksum =
 
Feb 26 18:48:56 mysqld: false; pc.ignore_quorum = false; pc.ignore_
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915502966528 [Note] WSREP: Service thread queue flushed.
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] WSREP: Assign initial position for certification: 8441351, protocol version: -1
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] WSREP: wsrep_sst_grab()
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] WSREP: Start replication
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] WSREP: Setting initial position to 0b0379b3-a949-11e5-b414-ab8a34af3e6e:8441351
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] WSREP: protonet asio version 0
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] WSREP: Using CRC-32C for message checksums.
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] WSREP: backend: asio
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Warning] WSREP: access file(/mnt/disco2/mysql//gvwstate.dat) failed(No such file or directory)
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] WSREP: restore pc from disk failed
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] WSREP: GMCast version 0
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] WSREP: (3540c976, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] WSREP: (3540c976, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] WSREP: EVS version 0
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] WSREP: gcomm: connecting to group 'asic_db_cluster', peer 'dbmysql1:,dbmysql2:,dbmysql3:'
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Warning] WSREP: (3540c976, 'tcp://0.0.0.0:4567') address 'tcp://127.0.1.1:4567' points to own listening address, blacklisting
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] WSREP: (3540c976, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers:
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] WSREP: declaring 44c706b4 at tcp://******:4567 stable
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] WSREP: declaring 916e4859 at tcp://******:4567 stable
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] WSREP: Node 44c706b4 state prim
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] WSREP: view(view_id(PRIM,3540c976,57) memb {
 
Feb 26 18:48:56 mysqld: #0113540c976,0
 
Feb 26 18:48:56 mysqld: #01144c706b4,0
 
Feb 26 18:48:56 mysqld: #011916e4859,0
 
Feb 26 18:48:56 mysqld: } joined {
 
Feb 26 18:48:56 mysqld: } left {
 
Feb 26 18:48:56 mysqld: } partitioned {
 
Feb 26 18:48:56 mysqld: })
 
Feb 26 18:48:56 mysqld: 2016-02-26 18:48:56 139915729721280 [Note] WSREP: save pc into disk
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915729721280 [Note] WSREP: gcomm: connected
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915729721280 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915729721280 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915729721280 [Note] WSREP: Opened channel 'asic_db_cluster'
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915429934848 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 3
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915729721280 [Note] WSREP: Waiting for SST to complete.
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915429934848 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 358ee918-dcb1-11e5-985f-23688863414a
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915429934848 [Note] WSREP: STATE EXCHANGE: sent state msg: 358ee918-dcb1-11e5-985f-23688863414a
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915429934848 [Note] WSREP: STATE EXCHANGE: got state msg: 358ee918-dcb1-11e5-985f-23688863414a from 0 (dbmysql1)
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915429934848 [Note] WSREP: STATE EXCHANGE: got state msg: 358ee918-dcb1-11e5-985f-23688863414a from 1 (dbmysql3)
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915429934848 [Note] WSREP: STATE EXCHANGE: got state msg: 358ee918-dcb1-11e5-985f-23688863414a from 2 (dbmysql2)
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915429934848 [Note] WSREP: Quorum results:
 
Feb 26 18:48:57 mysqld: #011version    = 3,
 
Feb 26 18:48:57 mysqld: #011component  = PRIMARY,
 
Feb 26 18:48:57 mysqld: #011conf_id    = 56,
 
Feb 26 18:48:57 mysqld: #011members    = 2/3 (joined/total),
 
Feb 26 18:48:57 mysqld: #011act_id     = 8441554,
 
Feb 26 18:48:57 mysqld: #011last_appl. = -1,
 
Feb 26 18:48:57 mysqld: #011protocols  = 0/7/3 (gcs/repl/appl),
 
Feb 26 18:48:57 mysqld: #011group UUID = 0b0379b3-a949-11e5-b414-ab8a34af3e6e
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915429934848 [Note] WSREP: Flow-control interval: [28, 28]
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915429934848 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 8441554)
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915729512192 [Note] WSREP: State transfer required:
 
Feb 26 18:48:57 mysqld: #011Group state: 0b0379b3-a949-11e5-b414-ab8a34af3e6e:8441554
 
Feb 26 18:48:57 mysqld: #011Local state: 0b0379b3-a949-11e5-b414-ab8a34af3e6e:8441351
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915729512192 [Note] WSREP: New cluster view: global state: 0b0379b3-a949-11e5-b414-ab8a34af3e6e:8441554, view# 57: Primary, number of nodes: 3, my index: 0, protocol version 3
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915729512192 [Warning] WSREP: Gap in state sequence. Need state transfer.
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915404769024 [Note] WSREP: Running: 'wsrep_sst_rsync --role 'joiner' --address '*****' --datadir '/mnt/disco2/mysql/'   --parent '12051'  '' '
 
Feb 26 18:48:57 rsyncd[12092]: rsyncd version 3.1.0 starting, listening on port 4444
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915729512192 [Note] WSREP: Prepared SST request: rsync|*****:4444/rsync_sst
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915729512192 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915729512192 [Note] WSREP: REPL Protocols: 7 (3, 2)
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915502966528 [Note] WSREP: Service thread queue flushed.
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915729512192 [Note] WSREP: Assign initial position for certification: 8441554, protocol version: 3
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915502966528 [Note] WSREP: Service thread queue flushed.
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915729512192 [Note] WSREP: Prepared IST receiver, listening at: tcp://*****:4568
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915429934848 [Note] WSREP: Member 0.0 (dbmysql1) requested state transfer from '*any*'. Selected 1.0 (dbmysql3)(SYNCED) as donor.
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915429934848 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 8441556)
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915729512192 [Note] WSREP: Requesting state transfer: success, donor: 1
 
Feb 26 18:48:57 rsyncd[12125]: connect from dbmysql3 (*****)
 
Feb 26 18:48:57 rsyncd[12125]: rsync to rsync_sst/ from dbmysql3 (******)
 
Feb 26 18:48:57 rsyncd[12125]: receiving file list
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915429934848 [Note] WSREP: 1.0 (dbmysql3): State transfer to 0.0 (dbmysql1) complete.
 
Feb 26 18:48:57 mysqld: 2016-02-26 18:48:57 139915429934848 [Note] WSREP: Member 1.0 (dbmysql3) synced with group.
 
Feb 26 18:48:57 rsyncd[12125]: sent 48 bytes  received 191 bytes  total size 47
 
Feb 26 18:48:58 mysqld: WSREP_SST: [INFO] Joiner cleanup. rsync PID: 12092 (20160226 18:48:58.352)
 
Feb 26 18:48:58 rsyncd[12092]: sent 0 bytes  received 0 bytes  total size 0
 
Feb 26 18:48:58 mysqld: WSREP_SST: [INFO] Joiner cleanup done. (20160226 18:48:58.861)
 
Feb 26 18:48:58 mysqld: 2016-02-26 18:48:58 139915729721280 [Note] WSREP: SST complete, seqno: 8441351
 
Feb 26 18:48:58 mysqld: 2016-02-26 18:48:58 139915729721280 [Note] InnoDB: Using mutexes to ref count buffer pool pages
 
Feb 26 18:48:58 mysqld: 2016-02-26 18:48:58 139915729721280 [Note] InnoDB: The InnoDB memory heap is disabled
 
Feb 26 18:48:58 mysqld: 2016-02-26 18:48:58 139915729721280 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
Feb 26 18:48:58 mysqld: 2016-02-26 18:48:58 139915729721280 [Note] InnoDB: Memory barrier is not used
 
Feb 26 18:48:58 mysqld: 2016-02-26 18:48:58 139915729721280 [Note] InnoDB: Compressed tables use zlib 1.2.8
 
Feb 26 18:48:58 mysqld: 2016-02-26 18:48:58 139915729721280 [Note] InnoDB: Using Linux native AIO
 
Feb 26 18:48:58 mysqld: 2016-02-26 18:48:58 139915729721280 [Note] InnoDB: Using generic crc32 instructions
 
Feb 26 18:48:58 mysqld: 2016-02-26 18:48:58 139915729721280 [Note] InnoDB: Initializing buffer pool, size = 2.0G
 
Feb 26 18:48:59 mysqld: 2016-02-26 18:48:59 139915729721280 [Note] InnoDB: Completed initialization of buffer pool
 
Feb 26 18:48:59 mysqld: 2016-02-26 18:48:59 139915729721280 [Note] InnoDB: Highest supported file format is Barracuda.
 
Feb 26 18:49:00 mysqld: 2016-02-26 18:49:00 139915446576896 [Note] WSREP: (3540c976, 'tcp://0.0.0.0:4567') turning message relay requesting off
 
Feb 26 18:49:06 /etc/init.d/mysql[12253]: 0 processes alive and '/usr/bin/mysqladmin --defaults-file=/etc/mysql/debian.cnf ping' resulted in
 
Feb 26 18:49:06 /etc/init.d/mysql[12253]: #007/usr/bin/mysqladmin: connect to server at 'localhost' failed
 
Feb 26 18:49:06 /etc/init.d/mysql[12253]: error: 'Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111 "Connection refused")'
 
Feb 26 18:49:06 /etc/init.d/mysql[12253]: Check that mysqld is running and that the socket: '/var/run/mysqld/mysqld.sock' exists!
 
Feb 26 18:49:06 /etc/init.d/mysql[12253]:
 
Feb 26 18:49:20 mysqld: 2016-02-26 18:49:20 139915729721280 [Note] InnoDB: 128 rollback segment(s) are active.
 
Feb 26 18:49:20 mysqld: 2016-02-26 18:49:20 139915729721280 [Note] InnoDB: Waiting for purge to start
 
Feb 26 18:49:20 mysqld: 2016-02-26 18:49:20 139915729721280 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.28-76.1 started; log sequence number 211806936998
 
Feb 26 18:49:20 mysqld: 2016-02-26 18:49:20 139912577779456 [Note] InnoDB: Dumping buffer pool(s) not yet started
 
Feb 26 18:49:20 mysqld: 2016-02-26 18:49:20 139915729721280 [Note] Plugin 'FEEDBACK' is disabled.
 
Feb 26 18:49:20 mysqld: 2016-02-26 18:49:20 139915729721280 [Note] Server socket created on IP: '0.0.0.0'.
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: Status information:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: Current dir: /mnt/disco2/mysql/
 
Feb 26 18:49:20 mysqld: Running threads: 2  Stack size: 196608
 
Feb 26 18:49:20 mysqld: Current locks:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40a7874188:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab77a0a0:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab779fc0:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab779000:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab778f20:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab778e40:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab7791c0:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab777400:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab779ee0:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab777b00:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab777da0:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab777a20:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab777cc0:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab777940:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab777be0:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab778120:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab778200:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab7782e0:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab777860:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab7775c0:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab777780:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab7774e0:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab7776a0:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab777e80:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab777f60:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab778040:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab779b60:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab779e00:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab779d20:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab779c40:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab7797e0:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab779700:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab779620:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab779540:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab779460:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab7799a0:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab779380:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab7792a0:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab779a80:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab7790e0:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab778c80:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab778d60:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab778ba0:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab778ac0:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab778740:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab7789e0:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab778900:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab778660:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab778820:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab7783c0:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab7784a0:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab778580:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: lock: 0x7f40ab7798c0:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: Key caches:
 
Feb 26 18:49:20 mysqld: default
 
Feb 26 18:49:20 mysqld: Buffer_size:      16777216
 
Feb 26 18:49:20 mysqld: Block_size:           1024
 
Feb 26 18:49:20 mysqld: Division_limit:        100
 
Feb 26 18:49:20 mysqld: Age_threshold:         300
 
Feb 26 18:49:20 mysqld: Partitions:              0
 
Feb 26 18:49:20 mysqld: blocks used:             0
 
Feb 26 18:49:20 mysqld: not flushed:             0
 
Feb 26 18:49:20 mysqld: w_requests:              0
 
Feb 26 18:49:20 mysqld: writes:                  0
 
Feb 26 18:49:20 mysqld: r_requests:              0
 
Feb 26 18:49:20 mysqld: reads:                   0
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: handler status:
 
Feb 26 18:49:20 mysqld: read_key:            0
 
Feb 26 18:49:20 mysqld: read_next:           0
 
Feb 26 18:49:20 mysqld: read_rnd             0
 
Feb 26 18:49:20 mysqld: read_first:          0
 
Feb 26 18:49:20 mysqld: write:               0
 
Feb 26 18:49:20 mysqld: delete               0
 
Feb 26 18:49:20 mysqld: update:              0
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: Table status:
 
Feb 26 18:49:20 mysqld: Opened tables:          0
 
Feb 26 18:49:20 mysqld: Open tables:            1
 
Feb 26 18:49:20 mysqld: Open files:             8
 
Feb 26 18:49:20 mysqld: Open streams:           0
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: Alarm status:
 
Feb 26 18:49:20 mysqld: Active alarms:   0
 
Feb 26 18:49:20 mysqld: Max used alarms: 0
 
Feb 26 18:49:20 mysqld: Next alarm time: 0
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: Memory status:
 
Feb 26 18:49:20 mysqld: Non-mmapped space allocated from system: 0
 
Feb 26 18:49:20 mysqld: Number of free chunks:#011#011#011 1
 
Feb 26 18:49:20 mysqld: Number of fastbin blocks:#011#011 0
 
Feb 26 18:49:20 mysqld: Number of mmapped regions:#011#011 0
 
Feb 26 18:49:20 mysqld: Space in mmapped regions:#011#011 0
 
Feb 26 18:49:20 mysqld: Maximum total allocated space:#011#011 0
 
Feb 26 18:49:20 mysqld: Space available in freed fastbin blocks: 0
 
Feb 26 18:49:20 mysqld: Total allocated space:#011#011#011 0
 
Feb 26 18:49:20 mysqld: Total free space:#011#011#011 0
 
Feb 26 18:49:20 mysqld: Top-most, releasable space:#011#011 0
 
Feb 26 18:49:20 mysqld: Estimated memory (with thread stack):    393216
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: message repeated 2 times: [ ]
 
Feb 26 18:49:20 mysqld: Events status:
 
Feb 26 18:49:20 mysqld: LLA = Last Locked At  LUA = Last Unlocked At
 
Feb 26 18:49:20 mysqld: WOC = Waiting On Condition  DL = Data Locked
 
Feb 26 18:49:20 mysqld: The Event Scheduler is disabled
 
Feb 26 18:49:20 mysqld:
 
Feb 26 18:49:20 mysqld: 2016-02-26 18:49:20 139915729721280 [Note] WSREP: Signalling provider to continue.
 
Feb 26 18:49:20 mysqld: 2016-02-26 18:49:20 139915729721280 [Note] WSREP: SST received: 0b0379b3-a949-11e5-b414-ab8a34af3e6e:8441351
 
Feb 26 18:49:20 mysqld: 2016-02-26 18:49:20 139915729512192 [Note] WSREP: Receiving IST: 203 writesets, seqnos 8441351-8441554
 
Feb 26 18:49:20 mysqld: 2016-02-26 18:49:20 139915729721280 [Note] /usr/sbin/mysqld: ready for connections.
 
Feb 26 18:49:20 mysqld: Version: '10.1.12-MariaDB-1~trusty'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution
 
Feb 26 18:49:22 mysqld: 2016-02-26 18:49:22 139915729512192 [Note] WSREP: IST received: 0b0379b3-a949-11e5-b414-ab8a34af3e6e:8441554
 
Feb 26 18:49:22 mysqld: 2016-02-26 18:49:22 139915429934848 [Note] WSREP: 0.0 (dbmysql1): State transfer from 1.0 (dbmysql3) complete.
 
Feb 26 18:49:22 mysqld: 2016-02-26 18:49:22 139915429934848 [Note] WSREP: Shifting JOINER -> JOINED (TO: 8441584)
 
Feb 26 18:49:22 mysqld: 2016-02-26 18:49:22 139915429934848 [Note] WSREP: Member 0.0 (dbmysql1) synced with group.
 
Feb 26 18:49:22 mysqld: 2016-02-26 18:49:22 139915429934848 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 8441584)
 
Feb 26 18:49:22 mysqld: 2016-02-26 18:49:22 139915729512192 [Note] WSREP: Synchronized with group, ready for connections
 
Feb 26 18:49:22 mysqld: 2016-02-26 18:49:22 139915729512192 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.

Comment by Nirbhay Choubey (Inactive) [ 2016-02-27 ]

jorfermo The system is taking quite sometime to fully start (~48 secs from the logs,
where wsrep recovery alone takes 22 secs), while the timeout in the init script is set
to 30secs. Thus after around 30 secs, the init script performs a ping only to find that
server is not running. So, you will have to increase the timeout for your init script.
This can be done by setting MYSQLD_STARTUP_TIMEOUT either directly in the
script or via command line. I would try setting it to something around 60 secs
based on the above logs.

Comment by Jorge Ferrando [ 2016-02-27 ]

That fixed the problem!

Thank you very much!

Comment by Nirbhay Choubey (Inactive) [ 2016-03-02 ]

http://lists.askmonty.org/pipermail/commits/2016-March/009068.html

Comment by Nirbhay Choubey (Inactive) [ 2016-03-17 ]

http://lists.askmonty.org/pipermail/commits/2016-March/009117.html

Comment by Nirbhay Choubey (Inactive) [ 2016-03-18 ]

greenman Could you please suggest me a KB page to document this change?

Comment by Ian Gilfillan [ 2016-03-31 ]

nirbhay_c I have created an article under Debian/Ubuntu installation issues at https://mariadb.com/kb/en/mariadb/apt-upgrade-fails-but-the-database-is-running/ based on this report. Feel free to enhance if needs be.

Comment by Nirbhay Choubey (Inactive) [ 2016-03-31 ]

greenman I have updated it a bit. Thank you.

Generated at Thu Feb 08 07:34:15 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.