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

"it is impossible to select State Transfer donor: Resource temporarily unavailable" upgrading Galera cluster 10.4 to 10.5

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Open (View Workflow)
    • Priority: Major
    • Resolution: Unresolved
    • Affects Version/s: 10.5.10
    • Fix Version/s: None
    • Component/s: Galera, Galera SST
    • Labels:
      None
    • Environment:
      Debian Buster

      Description

      I'm upgrading a MariaDB Galera cluster from 10.4 to 10.5.
      I'm following the same rolling upgrade procedure for upgrading from 10.3 to 10.4 (https://mariadb.com/kb/en/upgrading-from-mariadb-103-to-mariadb-104-with-galera-cluster/) as a document is not available from 10.4 to 10.5 for Galera installations.

      I updated APT repositories, removed old MariaDB and Galera installation and installed new MariaDB 10.5 and Galera 4:

      root@mysql1-staging:~# dpkg -l|grep mariadb-server
      rc  mariadb-server-10.2                  10.2.38+maria~stretch         amd64        MariaDB database server binaries
      rc  mariadb-server-10.3                  1:10.3.29+maria~stretch       amd64        MariaDB database server binaries
      rc  mariadb-server-10.4                  1:10.4.19+maria~buster        amd64        MariaDB database server binaries
      ii  mariadb-server-10.5                  1:10.5.10+maria~buster        amd64        MariaDB database server binaries
      ii  mariadb-server-core-10.5             1:10.5.10+maria~buster        amd64        MariaDB database core server files
      root@mysql1-staging:~# dpkg -l|grep galera
      ii  galera-4                             26.4.8-buster                 amd64        Replication framework for transactional applications
      

      When I try to start new MariaDB Server 10.5 is does not start and I see these logs:

      Jun 21 14:33:06 mysql1-staging systemd[1]: mariadb.service: Service RestartSec=5s expired, scheduling restart.
      Jun 21 14:33:06 mysql1-staging systemd[1]: mariadb.service: Scheduled restart job, restart counter is at 1.
      Jun 21 14:33:06 mysql1-staging systemd[1]: Stopped MariaDB 10.5.10 database server.
      Jun 21 14:33:06 mysql1-staging systemd[1]: Starting MariaDB 10.5.10 database server...
      Jun 21 14:33:08 mysql1-staging sh[13696]: WSREP: Recovered position b1cd6daa-31b7-11e8-8055-4b48ddd00b55:36320194
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] /usr/sbin/mariadbd (mysqld 10.5.10-MariaDB-1:10.5.10+maria~buster-log) starting as process 14083 ...
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: Loading provider /usr/lib/galera/libgalera_smm.so initial position: b1cd6daa-31b7-11e8-8055-4b48ddd00b55:36320194
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib/galera/libgalera_smm.so'
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: wsrep_load(): Galera 26.4.8(r902dd268) by Codership Oy <info@codership.com> loaded successfully.
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: CRC-32C: using "slicing-by-8" algorithm.
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1, safe_to_bootstrap: 0
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: GCache DEBUG: opened preamble:
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: Version: 2
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: UUID: b1cd6daa-31b7-11e8-8055-4b48ddd00b55
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: Seqno: -1 - -1
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: Offset: -1
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: Synced: 0
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: Recovering GCache ring buffer: version: 2, UUID: b1cd6daa-31b7-11e8-8055-4b48ddd00b55, offset: -1
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: GCache::RingBuffer initial scan...  0.0% (        0/134217752 bytes) complete.
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: GCache::RingBuffer initial scan...100.0% (134217752/134217752 bytes) complete.
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: Recovering GCache ring buffer: didn't recover any events.
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: Passing config to GCS: base_dir = /var/lib/mysql/; base_host = 127.0.0.1; base_port = 4567; cert.log_conflicts = no; cert.optimistic_pa = yes; 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 = /var/lib/mysql/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = galera.cache; gcache.page_size = 128M; gcache.recover = yes; gcache.size = 128M; gcomm.thread_prio = ; 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 = fal
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: Start replication
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: Connecting with bootstrap option: 0
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: Setting GCS initial position to 00000000-0000-0000-0000-000000000000:-1
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: protonet asio version 0
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: Using CRC-32C for message checksums.
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: backend: asio
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: gcomm thread scheduling priority set to other:0
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: restore pc from disk successfully
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: GMCast version 0
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: (fae0ea58-b1d2, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: (fae0ea58-b1d2, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: EVS version 1
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: gcomm: connecting to group 'staging', peer 'mysql1-staging:,mysql2-staging:,mysql3-staging:'
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: (fae0ea58-b1d2, 'tcp://0.0.0.0:4567') Found matching local endpoint for a connection, blacklisting address tcp://192.168.70.165:4567
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: (fae0ea58-b1d2, 'tcp://0.0.0.0:4567') connection established to ec08b611-b20d tcp://192.168.70.167:4567
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: (fae0ea58-b1d2, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers:
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: (fae0ea58-b1d2, 'tcp://0.0.0.0:4567') connection established to bea34926-a486 tcp://192.168.70.166:4567
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: EVS version upgrade 0 -> 1
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: declaring bea34926-a486 at tcp://192.168.70.166:4567 stable
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: declaring ec08b611-b20d at tcp://192.168.70.167:4567 stable
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: PC protocol upgrade 0 -> 1
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: Node bea34926-a486 state prim
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: view(view_id(PRIM,bea34926-a486,53) memb {
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: #011bea34926-a486,0
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: #011ec08b611-b20d,0
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: #011fae0ea58-b1d2,0
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: } joined {
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: } left {
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: } partitioned {
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: })
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: save pc into disk
      Jun 21 14:33:09 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:09 0 [Note] WSREP: clear restored view
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 0 [Note] WSREP: gcomm: connected
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 0 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 0 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 0 [Note] WSREP: Opened channel 'staging'
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 2, memb_num = 3
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 0 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 1 [Note] WSREP: Starting applier thread 1
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 0 [Note] WSREP: STATE EXCHANGE: sent state msg: d630fb55-d28c-11eb-b501-fba164ff70e9
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 0 [Note] WSREP: STATE EXCHANGE: got state msg: d630fb55-d28c-11eb-b501-fba164ff70e9 from 0 (mysql2-staging)
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 0 [Note] WSREP: STATE EXCHANGE: got state msg: d630fb55-d28c-11eb-b501-fba164ff70e9 from 1 (mysql3-staging)
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 2 [Note] WSREP: Starting rollbacker thread 2
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 0 [Note] WSREP: STATE EXCHANGE: got state msg: d630fb55-d28c-11eb-b501-fba164ff70e9 from 2 (mysql1-staging)
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 0 [Note] WSREP: Quorum results:
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: #011version    = 6,
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: #011component  = PRIMARY,
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: #011conf_id    = 51,
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: #011members    = 2/3 (joined/total),
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: #011act_id     = 36320213,
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: #011last_appl. = 36320069,
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: #011protocols  = 2/10/4 (gcs/repl/appl),
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: #011vote policy= 0,
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: #011group UUID = b1cd6daa-31b7-11e8-8055-4b48ddd00b55
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 0 [Note] WSREP: Flow-control interval: [28, 28]
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 0 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 36320214)
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 1 [Note] WSREP: ####### processing CC 36320214, local, ordered
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 1 [Note] WSREP: Process first view: b1cd6daa-31b7-11e8-8055-4b48ddd00b55 my uuid: fae0ea58-d285-11eb-b1d2-be2824309b8a
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 1 [Note] WSREP: Server mysql1-staging connected to cluster at position b1cd6daa-31b7-11e8-8055-4b48ddd00b55:36320214 with ID fae0ea58-d285-11eb-b1d2-be2824309b8a
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 1 [Note] WSREP: Server status change disconnected -> connected
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 1 [Note] WSREP: ####### My UUID: fae0ea58-d285-11eb-b1d2-be2824309b8a
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 1 [Note] WSREP: Cert index reset to 00000000-0000-0000-0000-000000000000:-1 (proto: 10), state transfer needed: yes
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 0 [Note] WSREP: Service thread queue flushed.
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 1 [Note] WSREP: ####### Assign initial position for certification: 00000000-0000-0000-0000-000000000000:-1, protocol version: -1
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 1 [Note] WSREP: State transfer required:
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: #011Group state: b1cd6daa-31b7-11e8-8055-4b48ddd00b55:36320214
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: #011Local state: 00000000-0000-0000-0000-000000000000:-1
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 1 [Note] WSREP: Server status change connected -> joiner
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 0 [Note] WSREP: Running: 'wsrep_sst_mariabackup --role 'joiner' --address '127.0.0.1' --datadir '/var/lib/mysql/' --parent '14083' --binlog '/var/log/mysql/mariadb-bin' --binlog-index '/var/log/mysql/mariadb-bin.index' --mysqld-args --wsrep_start_position=b1cd6daa-31b7-11e8-8055-4b48ddd00b55:36320194'
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 0 [Note] WSREP: Joiner monitor thread started to monitor
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: WSREP_SST: [INFO] Logging all stderr of SST/Innobackupex to syslog (20210621 14:33:10.299)
      Jun 21 14:33:10 mysql1-staging -wsrep-sst-joiner: Streaming with xbstream
      Jun 21 14:33:10 mysql1-staging -wsrep-sst-joiner: Using socat as streamer
      Jun 21 14:33:10 mysql1-staging -wsrep-sst-joiner: Stale sst_in_progress file: /var/lib/mysql//sst_in_progress
      Jun 21 14:33:10 mysql1-staging -wsrep-sst-joiner: Evaluating timeout -k 310 300 socat -u TCP-LISTEN:4444,reuseaddr stdio | pv -f -i 10 -N joiner -F '%N => Rate:%r Avg:%a Elapsed:%t %e Bytes: %b %p'  2>>/var/log/mysql/xtrabackup-progress.log | mbstream -x; RC=( ${PIPESTATUS[@]} )
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 1 [Note] WSREP: Prepared SST request: mariabackup|127.0.0.1:4444/xtrabackup_sst//1
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 1 [Note] WSREP: ####### IST uuid:00000000-0000-0000-0000-000000000000 f: 0, l: 36320214, STRv: 3
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 1 [Note] WSREP: IST receiver addr using tcp://127.0.0.1:4568
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 1 [Note] WSREP: Prepared IST receiver for 0-36320214, listening at: tcp://127.0.0.1:4568
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 0 [Warning] WSREP: Member 2.0 (mysql1-staging) requested state transfer from '*any*', but it is impossible to select State Transfer donor: Resource temporarily unavailable
      Jun 21 14:33:10 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:10 1 [Note] WSREP: Requesting state transfer failed: -11(Resource temporarily unavailable). Will keep retrying every 1 second(s)
      Jun 21 14:33:11 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:11 0 [Warning] WSREP: Member 2.0 (mysql1-staging) requested state transfer from '*any*', but it is impossible to select State Transfer donor: Resource temporarily unavailable
      Jun 21 14:33:12 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:12 0 [Note] WSREP: (fae0ea58-b1d2, 'tcp://0.0.0.0:4567') turning message relay requesting off
      Jun 21 14:33:12 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:12 0 [Warning] WSREP: Member 2.0 (mysql1-staging) requested state transfer from '*any*', but it is impossible to select State Transfer donor: Resource temporarily unavailable
      Jun 21 14:33:13 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:13 0 [Warning] WSREP: Member 2.0 (mysql1-staging) requested state transfer from '*any*', but it is impossible to select State Transfer donor: Resource temporarily unavailable
      Jun 21 14:33:14 mysql1-staging mariadbd[14083]: 2021-06-21 14:33:14 0 [Warning] WSREP: Member 2.0 (mysql1-staging) requested state transfer from '*any*', but it is impossible to select State Transfer donor: Resource temporarily unavailable
      

      I cannot find any official documentation about how to upgrade a Galera cluster from MariaDB 10.4 to 10.5.

      Is it supported or will I not be able to upgrade?
      Could you help me to understand where I'm wrong, please?

      Thank you!

        Attachments

          Activity

            People

            Assignee:
            Unassigned Unassigned
            Reporter:
            decibel83 Mattia Martinello
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

              Dates

              Created:
              Updated:

                Git Integration