CEV Problem with Grants?

Hi everyone.

It seems I found a bug in CEV mechanism. Or at least it looks like a bug - I need your advice here.

Situation:
I need to change password to user that has SYSTEM_USER privilege. But I as a user who wants to change that password - have no such permissions. When I try to execute such request on pxc1 node - it fails with next error:
Access denied; you need (at least one of) the SYSTEM_USER privilege(s) for this operation, Error_code: 1227;

Meantime, cluster initiates CEV:

2022-06-15T20:15:51.603942Z 0 [Note] [MY-000000] [Galera] Member 0(pxc-uc-node2) initiates vote on 5c78866e-de52-11ec-8c63-db0e768e920f:454158114,eaaf6466ca51fa98:  Access denied; you need (at least one of)
 the SYSTEM_USER privilege(s) for this operation, Error_code: 1227;                                                                                                                                           
2022-06-15T20:15:51.604022Z 0 [Note] [MY-000000] [Galera] Votes over 5c78866e-de52-11ec-8c63-db0e768e920f:454158114:                                                                                          
   eaaf6466ca51fa98:   1/2                                                                                                                                                                                    
Waiting for more votes.                                                                                                                                                                                       
2022-06-15T20:15:51.604097Z 1 [Note] [MY-000000] [Galera] Got vote request for seqno 5c78866e-de52-11ec-8c63-db0e768e920f:454158114                                                                           
2022-06-15T20:15:51.604409Z 0 [Note] [MY-000000] [Galera] Member 1(pxc-uc-node3) responds to vote on 5c78866e-de52-11ec-8c63-db0e768e920f:454158114,0000000000000000: Success                                 
2022-06-15T20:15:51.604443Z 0 [Note] [MY-000000] [Galera] Votes over 5c78866e-de52-11ec-8c63-db0e768e920f:454158114:                                                                                          
   0000000000000000:   1/2                                                                                                                                                                                    
   eaaf6466ca51fa98:   1/2                                                                                                                                                                                    
Winner: 0000000000000000                                                                                                                                                                                      
2022-06-15T20:15:51.604486Z 1 [Note] [MY-000000] [Galera] Vote 0 (success) on 5c78866e-de52-11ec-8c63-db0e768e920f:454158114 is consistent with group. Continue.                                              
2022-06-15T20:15:52.613398Z 0 [Note] [MY-000000] [Galera] Deferred close timer started for socket with remote endpoint: ssl://xx.xxx.xxx.229:4567                                                             
2022-06-15T20:15:52.613472Z 0 [Note] [MY-000000] [Galera] forgetting 1868705a-8ded (ssl://xx.xxx.xxx.229:4567)                                                                                                
2022-06-15T20:15:52.613526Z 0 [Note] [MY-000000] [Galera] Node cb87eba3-9645 state primary                                                                                                                    
2022-06-15T20:15:52.613586Z 0 [Note] [MY-000000] [Galera] Current view of cluster as seen by this node       

As you can see, cluster kicks pxc1 node, since all other nodes executed this request correctly. This happens probably due to fact that cluster node uses it’s internal user (like ‘mysql.pxc.internal.session’ or so), that actually HAS SYSTEM_USER permissions, and therefore executes query correctly.

Seconds try to execute same statement will kick pxc2 node respectively. So, in two tries you are getting cluster with only pxc3 node on board.

This is awkward. Or am I doing something wrong in this case? It looks like a bug in CEV. Thanks.

1 Like

If the other nodes executed the request correctly then that implies the user had correct privileges on those nodes and that node1 was out of sync (since it didn’t have correct privs). This is correct behavior. All nodes should always have the exact same data, always.

Yes, user accounts are local to each node.

Correct. You cannot modify the password/privileges of an account with higher privs than your own.

1 Like

Hi Matthew,

No, the situation is that node was IN SYNC for sure. I’ve just repeated this case locally on 3-node local cluster. Steps to reproduce:

  1. create 3-node cluster with standard bootstrapping pxc1 and then setup pxc2, pxc3
  2. Login to pxc1 and:
create user 'high_priv'@'%' identified by '123321';
grant all privileges on *.* to 'high_priv'@'%' with grant option;

create user 'low_priv'@'%' identified by '123321';
grant usage on *.* to 'low_priv'@'%' with grant option;
flush privileges;
  1. Login with low_priv and try to alter password for high_priv:
mysql> alter user 'high_priv'@'%' identified by '123321';
ERROR 1227 (42000): Access denied; you need (at least one of) the SYSTEM_USER privilege(s) for this operation
  1. Look into pxc2 logs:
mysql_node2     | 2022-06-17T20:18:23.065262Z 0 [Note] [MY-000000] [Galera] Member 0(pxc1) initiates vote on 39ce6acf-ee79-11ec-86d9-f2ec353fb536:31,e70c86177bfbeb29:  Access denied; you need (at least one of) the SYSTEM_USER privilege(s) for this operation, Error_code: 1227;
mysql_node2     | 2022-06-17T20:18:23.065364Z 0 [Note] [MY-000000] [Galera] Votes over 39ce6acf-ee79-11ec-86d9-f2ec353fb536:31:
mysql_node2     |    e70c86177bfbeb29:   1/3
mysql_node2     | Waiting for more votes.
mysql_node2     | 2022-06-17T20:18:23.065471Z 10 [Note] [MY-000000] [Galera] Got vote request for seqno 39ce6acf-ee79-11ec-86d9-f2ec353fb536:31
mysql_node2     | 2022-06-17T20:18:23.068037Z 0 [Note] [MY-000000] [Galera] Member 2(pxc3) responds to vote on 39ce6acf-ee79-11ec-86d9-f2ec353fb536:31,0000000000000000: Success
mysql_node2     | 2022-06-17T20:18:23.068206Z 0 [Note] [MY-000000] [Galera] Votes over 39ce6acf-ee79-11ec-86d9-f2ec353fb536:31:
mysql_node2     |    0000000000000000:   1/3
mysql_node2     |    e70c86177bfbeb29:   1/3
mysql_node2     | Waiting for more votes.
mysql_node2     | 2022-06-17T20:18:23.071045Z 0 [Note] [MY-000000] [Galera] Member 1(pxc2) responds to vote on 39ce6acf-ee79-11ec-86d9-f2ec353fb536:31,0000000000000000: Success
mysql_node2     | 2022-06-17T20:18:23.071120Z 0 [Note] [MY-000000] [Galera] Votes over 39ce6acf-ee79-11ec-86d9-f2ec353fb536:31:
mysql_node2     |    0000000000000000:   2/3
mysql_node2     |    e70c86177bfbeb29:   1/3
mysql_node2     | Winner: 0000000000000000
mysql_node2     | 2022-06-17T20:18:23.071290Z 10 [Note] [MY-000000] [Galera] Vote 0 (success) on 39ce6acf-ee79-11ec-86d9-f2ec353fb536:31 is consistent with group. Continue.
mysql_node2     | 2022-06-17T20:18:23.077846Z 0 [Note] [MY-000000] [Galera] declaring e1606e1d-9d64 at tcp://172.20.0.4:4567 stable
mysql_node2     | 2022-06-17T20:18:23.077993Z 0 [Note] [MY-000000] [Galera] forgetting 42de9f99-bbc3 (tcp://172.20.0.2:4567)
mysql_node2     | 2022-06-17T20:18:23.078800Z 0 [Note] [MY-000000] [Galera] Node 5a4c7630-b084 state primary
mysql_node2     | 2022-06-17T20:18:23.079370Z 0 [Note] [MY-000000] [Galera] Current view of cluster as seen by this node
mysql_node2     | view (view_id(PRIM,5a4c7630-b084,8)
mysql_node2     | memb {
mysql_node2     | 	5a4c7630-b084,0
mysql_node2     | 	e1606e1d-9d64,0
mysql_node2     | 	}
mysql_node2     | joined {
mysql_node2     | 	}
mysql_node2     | left {
mysql_node2     | 	}
mysql_node2     | partitioned {
mysql_node2     | 	42de9f99-bbc3,0
mysql_node2     | 	}
mysql_node2     | )
mysql_node2     | 2022-06-17T20:18:23.079434Z 0 [Note] [MY-000000] [Galera] Save the discovered primary-component to disk
mysql_node2     | 2022-06-17T20:18:23.083384Z 0 [Note] [MY-000000] [Galera] forgetting 42de9f99-bbc3 (tcp://172.20.0.2:4567)
mysql_node2     | 2022-06-17T20:18:23.083421Z 0 [Note] [MY-000000] [Galera] New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 2
mysql_node2     | 2022-06-17T20:18:23.083995Z 0 [Note] [MY-000000] [Galera] STATE_EXCHANGE: sent state UUID: a3108e20-ee7a-11ec-8c26-128475f718b3
mysql_node2     | 2022-06-17T20:18:23.088162Z 0 [Note] [MY-000000] [Galera] STATE EXCHANGE: sent state msg: a3108e20-ee7a-11ec-8c26-128475f718b3
mysql_node2     | 2022-06-17T20:18:23.088809Z 0 [Note] [MY-000000] [Galera] STATE EXCHANGE: got state msg: a3108e20-ee7a-11ec-8c26-128475f718b3 from 0 (pxc2)
mysql_node2     | 2022-06-17T20:18:23.088897Z 0 [Note] [MY-000000] [Galera] STATE EXCHANGE: got state msg: a3108e20-ee7a-11ec-8c26-128475f718b3 from 1 (pxc3)
mysql_node2     | 2022-06-17T20:18:23.088935Z 0 [Note] [MY-000000] [Galera] Quorum results:
mysql_node2     | 	version    = 6,
mysql_node2     | 	component  = PRIMARY,
mysql_node2     | 	conf_id    = 6,
mysql_node2     | 	members    = 2/2 (primary/total),
mysql_node2     | 	act_id     = 31,
mysql_node2     | 	last_appl. = 19,
mysql_node2     | 	protocols  = 2/10/4 (gcs/repl/appl),
mysql_node2     | 	vote policy= 0,
mysql_node2     | 	group UUID = 39ce6acf-ee79-11ec-86d9-f2ec353fb536
mysql_node2     | 2022-06-17T20:18:23.089033Z 0 [Note] [MY-000000] [Galera] Flow-control interval: [141, 141]
mysql_node2     | 2022-06-17T20:18:23.097382Z 10 [Note] [MY-000000] [Galera] ####### processing CC 32, local, ordered
mysql_node2     | 2022-06-17T20:18:23.097430Z 10 [Note] [MY-000000] [Galera] Maybe drain monitors from 31 upto current CC event 32 upto:31
mysql_node2     | 2022-06-17T20:18:23.097451Z 10 [Note] [MY-000000] [Galera] Drain monitors from 31 up to 31
mysql_node2     | 2022-06-17T20:18:23.097474Z 10 [Note] [MY-000000] [Galera] ####### My UUID: 5a4c7630-ee79-11ec-b084-ae82d1e53e18
mysql_node2     | 2022-06-17T20:18:23.097491Z 10 [Note] [MY-000000] [Galera] Skipping cert index reset
mysql_node2     | 2022-06-17T20:18:23.097509Z 10 [Note] [MY-000000] [Galera] REPL Protocols: 10 (5)
mysql_node2     | 2022-06-17T20:18:23.097526Z 10 [Note] [MY-000000] [Galera] ####### Adjusting cert position: 31 -> 32
mysql_node2     | 2022-06-17T20:18:23.097584Z 0 [Note] [MY-000000] [Galera] Service thread queue flushed.
mysql_node2     | 2022-06-17T20:18:23.101976Z 10 [Note] [MY-000000] [Galera] ================================================
mysql_node2     | View:
mysql_node2     |   id: 39ce6acf-ee79-11ec-86d9-f2ec353fb536:32
mysql_node2     |   status: primary
mysql_node2     |   protocol_version: 4
mysql_node2     |   capabilities: MULTI-MASTER, CERTIFICATION, PARALLEL_APPLYING, REPLAY, ISOLATION, PAUSE, CAUSAL_READ, INCREMENTAL_WS, UNORDERED, PREORDERED, STREAMING, NBO
mysql_node2     |   final: no
mysql_node2     |   own_index: 0
mysql_node2     |   members(2):
mysql_node2     | 	0: 5a4c7630-ee79-11ec-b084-ae82d1e53e18, pxc2
mysql_node2     | 	1: e1606e1d-ee79-11ec-9d64-f6d5ba45e580, pxc3
mysql_node2     | =================================================

As you can see, all nodes were in sync, but after executing this scenario pxc1 was kicked from cluster. Further starting pxc1 leads to full SST due to it’s “inconsistency” (that is not true).

That’s exactly the case I am talking about.

1 Like

So IMO it looks like during the VOTE pxc2 and pxc3 use not the same user with same permissions, but it’s own internal pxc user that HAS SYSTEM_USER privileges. Therefore the same query is executed correctly on those nodes, but not on the pxc1.

1 Like

I had the same issue an there is already a BUG for this.
[PXC-3872] Normal user dropping system user - Percona JIRA.

2 Likes