Не поднимается база tarantool 1.10.3

[Сергей Малых]

База создана достаточно давно, но затем была успешно обновлена до 1.10.2

 

2018-11-23 13:04:04.623 [11418] main/101/trp I> systemd: NOTIFY_SOCKET variable is empty, skipping
2018-11-23 13:04:04.624 [11420] main/101/trp C> Tarantool 1.10.2-29-g6dd0d2fb7
2018-11-23 13:04:04.624 [11420] main/101/trp C> log level 5
2018-11-23 13:04:04.806 [11420] main/101/trp I> mapping 134217728 bytes for memtx tuple arena...
2018-11-23 13:04:04.806 [11420] main/101/trp I> mapping 134217728 bytes for vinyl tuple arena...
2018-11-23 13:04:04.946 [11420] iproto/101/main I> binary: bound to 127.0.0.1:3311
2018-11-23 13:04:04.955 [11420] main/101/trp I> recovery start
2018-11-23 13:04:04.955 [11420] main/101/trp I> recovering from `.../00000000000002947807.snap'
2018-11-23 13:04:12.146 [11420] main/101/trp I> recover from `.../00000000000002936383.xlog'
2018-11-23 13:04:12.607 [11420] main/101/trp I> done `.../00000000000002936383.xlog'
2018-11-23 13:04:12.609 [11420] main/101/trp I> ready to accept requests
2018-11-23 13:04:12.609 [11420] main/108/checkpoint_daemon I> started
2018-11-23 13:04:12.609 [11420] main/108/checkpoint_daemon I> scheduled the next snapshot at Fri Nov 23 14:07:40 2018
2018-11-23 13:04:12.609 [11420] main/101/trp I> set 'vinyl_max_tuple_size' configuration option to 10485760
2018-11-23 13:04:12.609 [11420] main/101/trp I> set 'checkpoint_count' configuration option to 6
2018-11-23 13:04:12.609 [11420] main/101/trp upgrade.lua:1039 W> cannot auto upgrade schema version to 1.7.6, please call box.schema.upgrade() manually
2018-11-23 13:04:12.610 [11420] main C> entering the event loop
2018-11-23 13:04:28.797 [11420] main/114/console/unix/: I> create space _sequence
...
2018-11-23 13:04:28.800 [11420] main/114/console/unix/: I> set schema version to 1.7.6
2018-11-23 13:04:28.801 [11420] main/114/console/unix/: I> set schema version to 1.7.7
...
2018-11-23 13:04:28.803 [11420] main/114/console/unix/: I> set schema version to 1.10.0
...
2018-11-23 13:04:28.809 [11420] main/114/console/unix/: I> set schema version to 1.10.2

После обновления полгода все работало

 

2019-05-16 08:34:29.976 [11420] main/104/vinyl.scheduler I> 3/0: started compacting range ([...]), runs 3/10
2019-05-16 08:34:29.987 [11420] main/104/vinyl.scheduler I> 3/0: completed compacting range ([...]"])
2019-05-16 09:34:26.914 [11420] main/108/checkpoint_daemon I> making snapshot...
2019-05-16 09:34:26.927 [11420] main/108/checkpoint_daemon I> scheduled the next snapshot at Thu May 16 10:34:26 2019
2019-05-16 10:34:26.930 [11420] main/108/checkpoint_daemon I> making snapshot...
2019-05-16 10:34:26.960 [11420] main/108/checkpoint_daemon I> scheduled the next snapshot at Thu May 16 11:34:26 2019
...
2019-06-05 00:35:44.689 [11420] main/108/checkpoint_daemon I> making snapshot...
2019-06-05 00:35:44.750 [11420] main/108/checkpoint_daemon I> scheduled the next snapshot at Wed Jun  5 01:35:44 2019

В какой-то момент произошло падение (вряд ли это имеет какое-то значение)

 

2019-06-05 01:19:42.214 [11420] main C> got signal 1 - Hangup
2019-06-05 01:19:42.221 [11420] main C> got signal 15 - Terminated
2019-06-05 01:19:42.222 [11420] coio I> log file has been reopened

Сервис так и не был запущен вновь, и спустя еще некоторое время обновили tarantool до 1.10.3, после чего начались проблемы

 

2019-06-16 21:55:19.151 [19767] main/101/trp I> systemd: NOTIFY_SOCKET variable is empty, skipping
2019-06-16 21:55:19.152 [19769] main/101/trp C> Tarantool 1.10.3-70-ga978d0d63
2019-06-16 21:55:19.153 [19769] main/101/trp C> log level 5
2019-06-16 21:55:19.153 [19769] main/101/trp I> mapping 134217728 bytes for memtx tuple arena...
2019-06-16 21:55:19.153 [19769] main/101/trp I> mapping 134217728 bytes for vinyl tuple arena...
2019-06-16 21:55:19.155 [19769] main/101/trp I> instance uuid 5885a3ec-33ce-4c66-b8ba-c1e975d53b5f
2019-06-16 21:55:19.155 [19769] main/101/trp I> instance vclock {1: 4015348}
2019-06-16 21:55:19.156 [19769] iproto/101/main I> binary: bound to 127.0.0.1:3311
2019-06-16 21:55:19.577 [19769] main/101/trp I> recovery start
2019-06-16 21:55:19.577 [19769] main/101/trp I> recovering from `.../00000000000004015348.snap'
2019-06-16 21:55:19.578 [19769] main/101/trp I> cluster uuid 2591ef83-b9e4-42bd-ab66-f649d027216e
2019-06-16 21:55:19.578 [19769] main/101/trp memtx_engine.c:233 E> can't apply row:
2019-06-16 21:55:19.578 [19769] main/101/trp key_def.h:400 E> ER_FIELD_TYPE: Tuple field 6 type does not match one required by operation: expected string
2019-06-16 21:55:19.579 [19769] main/101/trp memtx_space.c:329 E> rollback: Tuple field 5 type does not match one required by operation: expected array
2019-06-16 21:55:19.579 [19769] main/101/trp memtx_engine.c:233 E> can't apply row:
2019-06-16 21:55:19.579 [19769] main/101/trp key_def.h:400 E> ER_FIELD_TYPE: Tuple field 5 type does not match one required by operation: expected array
2019-06-16 21:55:19.579 [19769] main/101/trp memtx_space.c:329 E> rollback: Tuple field 5 type does not match one required by operation: expected array

... 

2019-06-16 21:55:19.580 [19769] main/101/trp memtx_tree.c:467 E> ER_TUPLE_FOUND: Duplicate key exists in unique index 'primary' in space '_priv'

2019-06-16 21:55:19.580 [19769] main/101/trp I> assigned id 1 to replica 5885a3ec-33ce-4c66-b8ba-c1e975d53b5f

2019-06-16 21:55:19.580 [19769] main/101/trp I> recover from `.../00000000000004015106.xlog'

2019-06-16 21:55:25.621 [19769] main/101/trp I> done `.../00000000000004015106.xlog'

2019-06-16 21:55:25.651 [19769] main/101/trp I> ready to accept requests

Подскажите, что можно проверить/попробовать? гугление ничего не дает. Есть подозрение, что неработоспоспоность связана с использованием space_id 0/1/2

Конфиг:

box.cfg {
    listen = 'localhost:3311';
    io_collect_interval = nil;
    readahead = 16320;
    memtx_memory = 128 * 1024 * 1024; -- 128Mb
    memtx_min_tuple_size = 16;
    memtx_max_tuple_size = 1 * 1024 * 1024; -- 1Mb
    vinyl_memory = 128 * 1024 * 1024; -- 128Mb
    vinyl_cache = 128 * 1024 * 1024; -- 128Mb
    vinyl_write_threads = 2;
    vinyl_max_tuple_size = 10 * 1024 * 1024;
    wal_mode = "write";
    wal_max_size = 256 * 1024 * 1024;
    checkpoint_interval = 60 * 60; -- one hour
    checkpoint_count = 6;
    snap_io_rate_limit = nil;
    force_recovery = true;
    log_level = 5;
    log_nonblock = true;
    too_long_threshold = 0.5;
}
function bootstrap()
    local space = box.schema.create_space('trp0', { engine = 'vinyl', id = 3 })
    space:create_index('primary', {type = 'tree', parts = {1, 'string'}})
    local space = box.schema.create_space('trp1', { engine = 'vinyl', id = 1 })
    space:create_index('primary', {type = 'tree', parts = {1, 'string'}})
    local space = box.schema.create_space('trp2', { engine = 'vinyl', id = 2 })
    space:create_index('primary', {type = 'tree', parts = {1, 'string'}})
    box.schema.user.grant('guest', 'read,write,execute', 'universe')
end
box.once('trp-1.0', bootstrap)

[Konstantin Osipov]

* Сергей Малых <xrono...@gmail.com> [19/07/01 23:05]:

> База создана достаточно давно, но затем была успешно обновлена до 1.10.2

Криво прошёл апгрейд схемы с 1.7.6.

Мы умеем это чинить руками.

Попробуйте mt_schema_upgrade.lua из списка файлов в чате в
Telegram, но лучше сделайте это под надзором.


--
Konstantin Osipov, Moscow, Russia

[Сергей Малых]

Спасибо, попробуем