Don't change password on start

[rosik]

Recently we've encountered an error on master restart:

Replication from open-bank-test-1:3502 (tdg-storage02-replica) to open-bank-test-3:3502 (tdg-storage02) state "stopped" (Transaction id must be equal to LSN of the first row in the transaction.)

Further investigation has shown that the problem was caused by the password change on cartridge start:

cartridge/cartridge/confapplier.lua

Lines 493 to 513 in 8e57ed8

	do
	log.info('Setting password for user %q ...', username)
	-- To be sure netbox is operable, password should always be
	-- equal to the cluster_cookie.
	-- Function `passwd` is safe to be called on multiple replicas,
	-- it never cause replication conflict
	local read_only = box.cfg.read_only
	box.cfg({read_only = false})
	if vars.upgrade_schema then
	cartridge_schema_upgrade(clusterwide_config)
	end
	BoxError:pcall(
	box.schema.user.passwd,
	username, password
	)
	box.cfg({read_only = read_only})
	end

It should be conditional.

[rosik]

Telegram conversation

Alexander Goryakin, [26.08.21 17:13]
[Forwarded from Alexander Goryakin]
Привет. Возникает такая ошибка на tdg 2.1:

Replication from open-bank-test-1:3502 (tdg-storage02-replica) to open-bank-test-3:3502 (tdg-storage02) state "stopped" (Transaction id must be equal to LSN of the first row in the transaction.)

Происходит если под нагрузкой откулючить мастер, а потом снова включить. Мастер при этом переходит в состояние ConnectingFullmesh. Также graphql запросы к сервису через UI через раз выполняются с ошибкой, как будто они отправляются попеременно то на мастер, то на реплику.Это баг, или так и должно быть?

Sergey Petrenko, [27.08.21 15:56]
[Forwarded from Sergey Petrenko]
Очень странно.
Всё ломается на том, что у мастера последняя запись такая:

HEADER:
  lsn: 16167
  replica_id: 1
  type: UPDATE
  timestamp: 1629985757.7819
BODY:
  space_id: 304
  index_base: 1
  key: [1]
  tuple: [['=', 5, {'chap-sha1': 'XXXXXXXXXXXXXXXXXXXXXXXXXXXX'}]]
...

А у реплики такая:

---                                                                                   
HEADER:                                                                               
  lsn: 16167                                                                              
  replica_id: 1                                                                       
  type: REPLACE                                                                       
  tsn: 16167                                                                          
  timestamp: 1629985698.8481                                                          
BODY:                                                                                 
  space_id: 516                                                                       
  tuple: [1629985698000596635, 05955be8-d842-46e3-9aae-64cdc2553a08, 2, 'anonymous',
    null, 'common.admin.auth', 'Access granted to anonymous user', 5865, 28295]  
---

Sergey Petrenko, [27.08.21 15:56]
[Forwarded from Sergey Petrenko]
Резюме такое.
Репликация идёт из журнала, но чтение релей делает из page cache, а не из файла на диске.

Sergey Petrenko, [27.08.21 15:56]
[Forwarded from Sergey Petrenko]
write() возвращает успех тоже после попадания в page cache

Sergey Petrenko, [27.08.21 15:56]
[Forwarded from Sergey Petrenko]
Соответственно, транзакция, на которой всё ломается, попала в page cache перед рестартом, и тарантул успел её среплицировать даже.
Но до рестарта page cache не сбросился на диск

Sergey Petrenko, [27.08.21 15:56]
[Forwarded from Sergey Petrenko]
После того как мастер вернулся, он восстановился из данных на диске (без последней транзакции).

Он, видимо сразу стал writeable, ещё до sync-a с репликой (которая бы могла вернуть ему его последнуюю транзакцию)

Как только он стал writeable, он выполнил новую транзакцию (которую мы видим под lsn 16167 в мастерском логе)

После этого репликация с репликой заработала, и реплика начала слать ему его старую транзакцию. Поскольку мастер уже записал что-то в lsn 16167, он получил транзакцию начиная с lsn 16168. Это был первый row транзакции, который до него дошёл, и у этого row не совпадали lsn (16168) и tsn (16167). На этом репликация встала.

Но, самое страшное тут то, что у реплики и мастера разные данные под lsn 16167. У реплики - начало транзакции, которую мастер «забыл» из-за рестарта. У мастера - новая транзакция, которую он записал после рестарта. Он же «забыл» про старую.

Sergey Petrenko, [27.08.21 15:56]
[Forwarded from Sergey Petrenko]
Если это какой-то тест стабильности, в котором нужно рестартнуть ноду под нагрузкой, то должен помочь wal_mode=‘fsync’.

Sergey Petrenko, [27.08.21 15:56]
[Forwarded from Sergey Petrenko]
Насчёт того, чтобы с wal_mode=‘write’ (дефолтным) не происходило таких косяков, можно попробовать сделать replication_connect_quorum=2, и указывать и себя, и реплику в репликации. Тогда мастер не будет становиться rw, пока не синканётся с репликой, которая вернёт ему потерянную транзакцию (вы наверное так и делаете, я просто не знаю).

[olegrok]

It should be conditional.

https://github.com/tarantool/tarantool/blob/ed7da7e638f4b6d56c32fcaae5a7fb04a813eb5b/src/box/lua/schema.lua#L2752-L2757

Probably solution could be much more simple without any options.

Just compare box.schema.user.password(cluster-cookie) with current password hash and don't update if password isn't changed.

[rosik]

Yep, that's exactly what I meant.

[rosik]

Here's a potential reproducer (I didn't test it yet)

1. Setup a cluster of two replicas.
2. Snapshot a master.
3. Commit a transaction (it'll be written to the WAL).
4. Stop the master
5. Remove two latest WALs (one empty and one with that transaction).
6. Start the master.

I expect it to fail with some error about LSN. And removing box.schema.user.passwd should fix it.