From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from [87.239.111.99] (localhost [127.0.0.1]) by dev.tarantool.org (Postfix) with ESMTP id 17FF36FC82; Fri, 12 Nov 2021 02:56:08 +0300 (MSK) DKIM-Filter: OpenDKIM Filter v2.11.0 dev.tarantool.org 17FF36FC82 DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=tarantool.org; s=dev; t=1636674968; bh=c0tZ59n1SKKcU17LIrrylMVxKGZB6Bd/3RT6Imd2LRc=; h=To:Date:In-Reply-To:References:Subject:List-Id:List-Unsubscribe: List-Archive:List-Post:List-Help:List-Subscribe:From:Reply-To: From; b=oFKkgqy9rQ7IHilmmJHhKpwjNUo85TNORaMjWAQhgMQnnOPbrj7oP7v4z1yriZkrk +EpsWaYoEC8QxZDVAQ2mUMAOTyDIFYQTGWWxMVZ71Om8W5w1Nwi6czufLE4GIH5Wkm 6umceIxN67L6w9r4NN3SbzTGgEVrgAn7naCWDqTU= Received: from smtpng1.i.mail.ru (smtpng1.i.mail.ru [94.100.181.251]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by dev.tarantool.org (Postfix) with ESMTPS id F149C6FC82 for ; Fri, 12 Nov 2021 02:54:34 +0300 (MSK) DKIM-Filter: OpenDKIM Filter v2.11.0 dev.tarantool.org F149C6FC82 Received: by smtpng1.m.smailru.net with esmtpa (envelope-from ) id 1mlJtq-0003tY-5y; Fri, 12 Nov 2021 02:54:34 +0300 To: tarantool-patches@dev.tarantool.org, sergepetrenko@tarantool.org Date: Fri, 12 Nov 2021 00:54:22 +0100 Message-Id: X-Mailer: git-send-email 2.24.3 (Apple Git-128) In-Reply-To: References: MIME-Version: 1.0 Content-Transfer-Encoding: 8bit X-7564579A: 78E4E2B564C1792B X-77F55803: 4F1203BC0FB41BD9731B3922EC063979B1F6335FDD7DA46529643274CFE4D7E800894C459B0CD1B9BEDC2EFF12B3516BFEB31502303C4DF77F76FE7EF67E38FF80ACAB8EAC650A75 X-7FA49CB5: FF5795518A3D127A4AD6D5ED66289B5278DA827A17800CE7D950999244A4B2E6EA1F7E6F0F101C67BD4B6F7A4D31EC0BCC500DACC3FED6E28638F802B75D45FF8AA50765F79006377A7A7D315BEE81B48638F802B75D45FF36EB9D2243A4F8B5A6FCA7DBDB1FC311F39EFFDF887939037866D6147AF826D863A97BBB9C85512C0E037FC83D4AF007117882F4460429724CE54428C33FAD305F5C1EE8F4F765FCAA867293B0326636D2E47CDBA5A96583BD4B6F7A4D31EC0BC014FD901B82EE079FA2833FD35BB23D27C277FBC8AE2E8BAA867293B0326636D2E47CDBA5A96583BA9C0B312567BB231DD303D21008E29813377AFFFEAFD269A417C69337E82CC2E827F84554CEF50127C277FBC8AE2E8BA83251EDC214901ED5E8D9A59859A8B6300D3B61E77C8D3B089D37D7C0E48F6C5571747095F342E88FB05168BE4CE3AF X-B7AD71C0: AC4F5C86D027EB782CDD5689AFBDA7A213B5FB47DCBC3458834459D11680B50537BF44C8E1EC058A4250998EDE830631 X-C1DE0DAB: C20DE7B7AB408E4181F030C43753B8183A4AFAF3EA6BDC44671AA518CC42EA907E9FEBB9C11794A1C200C345AFA2762D47D71829AD4AA4AE9C2B6934AE262D3EE7EAB7254005DCED114C52B35DBB74F4E7EAB7254005DCED08988D4D34163C9D1E0A4E2319210D9B64D260DF9561598F01A9E91200F654B0D1E3F5DE2301FFC68E8E86DC7131B365E7726E8460B7C23C X-C8649E89: 4E36BF7865823D7055A7F0CF078B5EC49A30900B95165D34B3611847B8BC2D0BD8E9713B56D898B23AE20996BA426A32746FA1F3969D1315A4E8088F6A7F76AF1D7E09C32AA3244CC897B3A53F91DA5757AADE545EF33002D08D48398F32B4A6729B2BEF169E0186 X-D57D3AED: 3ZO7eAau8CL7WIMRKs4sN3D3tLDjz0dLbV79QFUyzQ2Ujvy7cMT6pYYqY16iZVKkSc3dCLJ7zSJH7+u4VD18S7Vl4ZUrpaVfd2+vE6kuoey4m4VkSEu530nj6fImhcD4MUrOEAnl0W826KZ9Q+tr5ycPtXkTV4k65bRjmOUUP8cvGozZ33TWg5HZplvhhXbhDGzqmQDTd6OAevLeAnq3Ra9uf7zvY2zzsIhlcp/Y7m53TZgf2aB4JOg4gkr2bioj4t8MBgWr8bI9IfN7mOG/0g== X-Mailru-Sender: 689FA8AB762F7393C37E3C1AEC41BA5D99F50E137699079F362A657A74A09DCB3841015FED1DE5223CC9A89AB576DD93FB559BB5D741EB963CF37A108A312F5C27E8A8C3839CE0E267EA787935ED9F1B X-Mras: Ok Subject: [Tarantool-patches] [PATCH v2 11/11] error: report ER_READONLY reason in message X-BeenThere: tarantool-patches@dev.tarantool.org X-Mailman-Version: 2.1.34 Precedence: list List-Id: Tarantool development patches List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , From: Vladislav Shpilevoy via Tarantool-patches Reply-To: Vladislav Shpilevoy Errors-To: tarantool-patches-bounces@dev.tarantool.org Sender: "Tarantool-patches" A previous commit added reason details as error fields. But error objects are serialized as strings by default thus loosing all the details. This commit makes ER_READONLY message contain the reason why it happened in a human-readable form. That way it will be well visible in the logs at least. Follow-up #5568 --- src/box/box.cc | 33 ++++++++++++++----- src/box/errcode.h | 2 +- src/lib/core/diag.c | 11 +++++++ src/lib/core/diag.h | 3 ++ .../gh_5568_read_only_reason_test.lua | 19 +++++++++++ test/replication/anon.result | 6 ++-- test/replication/catch.result | 4 +-- test/replication/election_qsync.result | 11 +++++-- test/replication/election_qsync.test.lua | 4 ++- .../gh-6034-qsync-limbo-ownership.result | 22 ++++++++++--- .../gh-6034-qsync-limbo-ownership.test.lua | 8 +++-- test/vinyl/misc.result | 2 +- 12 files changed, 101 insertions(+), 24 deletions(-) diff --git a/src/box/box.cc b/src/box/box.cc index 323982969..f5162e67c 100644 --- a/src/box/box.cc +++ b/src/box/box.cc @@ -181,6 +181,7 @@ box_check_writable(void) return 0; struct error *e = diag_set(ClientError, ER_READONLY); struct raft *raft = box_raft(); + error_append_msg(e, " - "); /* * In case of multiple reasons at the same time only one is reported. * But the order is important. For example, if the instance has election @@ -188,40 +189,56 @@ box_check_writable(void) * and who is the leader than just see cfg 'read_only' is true. */ if (raft_is_ro(raft)) { + const char *state = raft_state_str(raft->state); + uint64_t term = raft->volatile_term; error_set_str(e, "reason", "election"); - error_set_str(e, "state", raft_state_str(raft->state)); - error_set_uint(e, "term", raft->volatile_term); + error_set_str(e, "state", state); + error_set_uint(e, "term", term); + error_append_msg(e, "state is election %s with term %llu", + state, term); uint32_t id = raft->leader; if (id != REPLICA_ID_NIL) { error_set_uint(e, "leader_id", id); + error_append_msg(e, ", leader is %u", id); struct replica *r = replica_by_id(id); /* * XXX: when the leader is dropped from _cluster, it * is not reported to Raft. */ - if (r != NULL) + if (r != NULL) { error_set_uuid(e, "leader_uuid", &r->uuid); + error_append_msg(e, " (%s)", + tt_uuid_str(&r->uuid)); + } } } else if (txn_limbo_is_ro(&txn_limbo)) { error_set_str(e, "reason", "synchro"); uint32_t id = txn_limbo.owner_id; + uint64_t term = raft->volatile_term; error_set_uint(e, "queue_owner_id", id); - error_set_uint(e, "term", raft->volatile_term); + error_set_uint(e, "term", term); + error_append_msg(e, "synchro queue with term %llu belongs " + "to %u", term, id); struct replica *r = replica_by_id(id); /* * XXX: when an instance is deleted from _cluster, its limbo's * ownership is not cleared. */ - if (r != NULL) + if (r != NULL) { error_set_uuid(e, "queue_owner_uuid", &r->uuid); + error_append_msg(e, " (%s)", tt_uuid_str(&r->uuid)); + } } else { error_set_str(e, "reason", "state"); - if (is_ro) + if (is_ro) { error_set_str(e, "state", "read_only"); - else if (is_orphan) + error_append_msg(e, "box.cfg.read_only is true"); + } else if (is_orphan) { error_set_str(e, "state", "orphan"); - else + error_append_msg(e, "it is an orphan"); + } else { assert(false); + } } diag_log(); return -1; diff --git a/src/box/errcode.h b/src/box/errcode.h index ac178f1f1..66c335c20 100644 --- a/src/box/errcode.h +++ b/src/box/errcode.h @@ -59,7 +59,7 @@ struct errcode_record { /* 4 */_(ER_TUPLE_NOT_FOUND, "Tuple doesn't exist in index '%s' in space '%s'") \ /* 5 */_(ER_UNSUPPORTED, "%s does not support %s") \ /* 6 */_(ER_NONMASTER, "Can't modify data on a replication slave. My master is: %s") \ - /* 7 */_(ER_READONLY, "Can't modify data because this instance is in read-only mode.") \ + /* 7 */_(ER_READONLY, "Can't modify data on a read-only instance") \ /* 8 */_(ER_INJECTION, "Error injection '%s'") \ /* 9 */_(ER_CREATE_SPACE, "Failed to create space '%s': %s") \ /* 10 */_(ER_SPACE_EXISTS, "Space '%s' already exists") \ diff --git a/src/lib/core/diag.c b/src/lib/core/diag.c index b05f2793f..2eda31ae9 100644 --- a/src/lib/core/diag.c +++ b/src/lib/core/diag.c @@ -155,6 +155,17 @@ error_format_msg(struct error *e, const char *format, ...) va_end(ap); } +void +error_append_msg(struct error *e, const char *format, ...) +{ + va_list ap; + va_start(ap, format); + int prefix_len = strlen(e->errmsg); + char *msg = e->errmsg + prefix_len; + vsnprintf(msg, sizeof(e->errmsg) - prefix_len, format, ap); + va_end(ap); +} + void error_vformat_msg(struct error *e, const char *format, va_list ap) { diff --git a/src/lib/core/diag.h b/src/lib/core/diag.h index be81689ce..0522d9e5a 100644 --- a/src/lib/core/diag.h +++ b/src/lib/core/diag.h @@ -273,6 +273,9 @@ error_format_msg(struct error *e, const char *format, ...); void error_vformat_msg(struct error *e, const char *format, va_list ap); +void +error_append_msg(struct error *e, const char *format, ...); + /** * Diagnostics Area - a container for errors */ diff --git a/test/replication-luatest/gh_5568_read_only_reason_test.lua b/test/replication-luatest/gh_5568_read_only_reason_test.lua index 8effa69e8..5e67029c0 100644 --- a/test/replication-luatest/gh_5568_read_only_reason_test.lua +++ b/test/replication-luatest/gh_5568_read_only_reason_test.lua @@ -47,6 +47,8 @@ local g = t.group('gh-5568-read-only-reason1') g.before_all(make_create_cluster(g)) g.after_all(make_destroy_cluster(g)) +local read_only_msg = "Can't modify data on a read-only instance - " + -- -- Read-only because of box.cfg{read_only = true}. -- @@ -57,6 +59,8 @@ g.test_read_only_reason_cfg = function(g) return ok, err:unpack() end) t.assert(not ok, 'fail ddl') + t.assert_str_contains(err.message, read_only_msg.. + 'box.cfg.read_only is true') t.assert_covers(err, { reason = 'state', state = 'read_only', @@ -88,6 +92,7 @@ g.test_read_only_reason_orphan = function(g) return old_timeout, ok, err:unpack() end, {fake_uri}) t.assert(not ok, 'fail ddl') + t.assert_str_contains(err.message, read_only_msg..'it is an orphan') t.assert_covers(err, { reason = 'state', state = 'orphan', @@ -117,6 +122,8 @@ g.test_read_only_reason_election_no_leader = function(g) end) t.assert(not ok, 'fail ddl') t.assert(err.term, 'has term') + t.assert_str_contains(err.message, read_only_msg..('state is election '.. + '%s with term %s'):format(err.state, err.term)) t.assert_covers(err, { reason = 'election', state = 'follower', @@ -148,6 +155,9 @@ g.test_read_only_reason_election_has_leader = function(g) end) t.assert(not ok, 'fail ddl') t.assert(err.term, 'has term') + t.assert_str_contains(err.message, read_only_msg..('state is election '.. + '%s with term %s, leader is %s (%s)'):format( + err.state, err.term, err.leader_id, err.leader_uuid)) t.assert_covers(err, { reason = 'election', state = 'follower', @@ -187,6 +197,9 @@ g.test_read_only_reason_synchro = function(g) end) t.assert(not ok, 'fail ddl') t.assert(err.term, 'has term') + t.assert_str_contains(err.message, read_only_msg..('synchro queue with '.. + 'term %s belongs to %s (%s)'):format(err.term, + err.queue_owner_id, err.queue_owner_uuid)) t.assert_covers(err, { reason = 'synchro', queue_owner_id = g.master:instance_id(), @@ -242,6 +255,9 @@ g.test_read_only_reason_election_has_leader_no_uuid = function(g) t.assert(not ok, 'fail ddl') t.assert(err.term, 'has term') t.assert(not err.leader_uuid, 'has no leader uuid') + t.assert_str_contains(err.message, read_only_msg..('state is election %s '.. + 'with term %s, leader is %s'):format(err.state, + err.term, err.leader_id)) t.assert_covers(err, { reason = 'election', state = 'follower', @@ -276,6 +292,9 @@ g.test_read_only_reason_synchro_no_uuid = function(g) t.assert(not ok, 'fail ddl') t.assert(err.term, 'has term') t.assert(not err.queue_owner_uuid) + t.assert_str_contains(err.message, read_only_msg..('synchro queue with '.. + 'term %s belongs to %s'):format(err.term, + err.queue_owner_id)) t.assert_covers(err, { reason = 'synchro', queue_owner_id = leader_id, diff --git a/test/replication/anon.result b/test/replication/anon.result index dd470797c..3359be1d1 100644 --- a/test/replication/anon.result +++ b/test/replication/anon.result @@ -136,16 +136,16 @@ box.cfg{read_only=false} box.space.test:insert{2} | --- - | - error: Can't modify data because this instance is in read-only mode. + | - error: Can't modify data on a read-only instance - box.cfg.read_only is true | ... box.space.loc:drop() | --- - | - error: Can't modify data because this instance is in read-only mode. + | - error: Can't modify data on a read-only instance - box.cfg.read_only is true | ... box.space.loc:truncate() | --- - | - error: Can't modify data because this instance is in read-only mode. + | - error: Can't modify data on a read-only instance - box.cfg.read_only is true | ... test_run:cmd('switch default') diff --git a/test/replication/catch.result b/test/replication/catch.result index e1b2995ec..3fbc07fbd 100644 --- a/test/replication/catch.result +++ b/test/replication/catch.result @@ -92,7 +92,7 @@ box.space.test ~= nil ... box.space.test:replace{1} --- -- error: Can't modify data because this instance is in read-only mode. +- error: Can't modify data on a read-only instance - it is an orphan ... -- Case #2: replace tuple on replica by net.box. test_run:cmd("switch default") @@ -108,7 +108,7 @@ c = net_box.connect(r_uri) ... d = c.space.test:replace{1} --- -- error: Can't modify data because this instance is in read-only mode. +- error: Can't modify data on a read-only instance - it is an orphan ... -- Resume replication. errinj.set('ERRINJ_RELAY_SEND_DELAY', false) diff --git a/test/replication/election_qsync.result b/test/replication/election_qsync.result index c6ec5e352..798f9d493 100644 --- a/test/replication/election_qsync.result +++ b/test/replication/election_qsync.result @@ -115,9 +115,16 @@ test_run:cmd('stop server replica') | - true | ... -- Will fail - the node is not a leader. -box.space.test:replace{2} +ok, err = pcall(box.space.test.replace, box.space.test, {2}) | --- - | - error: Can't modify data because this instance is in read-only mode. + | ... +assert(not ok) + | --- + | - true + | ... +assert(err.code == box.error.READONLY) + | --- + | - true | ... -- Set synchro timeout to a huge value to ensure, that when a leader is elected, diff --git a/test/replication/election_qsync.test.lua b/test/replication/election_qsync.test.lua index f3c7c290b..3fb6a9be7 100644 --- a/test/replication/election_qsync.test.lua +++ b/test/replication/election_qsync.test.lua @@ -58,7 +58,9 @@ test_run:wait_lsn('default', 'replica') test_run:switch('default') test_run:cmd('stop server replica') -- Will fail - the node is not a leader. -box.space.test:replace{2} +ok, err = pcall(box.space.test.replace, box.space.test, {2}) +assert(not ok) +assert(err.code == box.error.READONLY) -- Set synchro timeout to a huge value to ensure, that when a leader is elected, -- it won't wait for this timeout. diff --git a/test/replication/gh-6034-qsync-limbo-ownership.result b/test/replication/gh-6034-qsync-limbo-ownership.result index b4f53cd2a..58acf7db2 100644 --- a/test/replication/gh-6034-qsync-limbo-ownership.result +++ b/test/replication/gh-6034-qsync-limbo-ownership.result @@ -94,9 +94,16 @@ assert(box.info.synchro.queue.owner == test_run:get_server_id('default')) | --- | - true | ... -box.space.async:insert{2} -- failure. +ok, err = pcall(box.space.async.insert, box.space.async, {2}) | --- - | - error: Can't modify data because this instance is in read-only mode. + | ... +assert(not ok) + | --- + | - true + | ... +assert(err.code == box.error.READONLY) + | --- + | - true | ... -- Promotion on the other node. Default should become ro. @@ -131,9 +138,16 @@ assert(box.info.synchro.queue.owner == test_run:get_server_id('replica')) | --- | - true | ... -box.space.sync:insert{3} -- failure. +ok, err = pcall(box.space.sync.insert, box.space.sync, {3}) | --- - | - error: Can't modify data because this instance is in read-only mode. + | ... +assert(not ok) + | --- + | - true + | ... +assert(err.code == box.error.READONLY) + | --- + | - true | ... box.ctl.promote() diff --git a/test/replication/gh-6034-qsync-limbo-ownership.test.lua b/test/replication/gh-6034-qsync-limbo-ownership.test.lua index f9ef5ca41..0f62ba6a4 100644 --- a/test/replication/gh-6034-qsync-limbo-ownership.test.lua +++ b/test/replication/gh-6034-qsync-limbo-ownership.test.lua @@ -34,7 +34,9 @@ box.cfg{replication=rpl_listen} test_run:switch('replica') assert(box.info.ro) assert(box.info.synchro.queue.owner == test_run:get_server_id('default')) -box.space.async:insert{2} -- failure. +ok, err = pcall(box.space.async.insert, box.space.async, {2}) +assert(not ok) +assert(err.code == box.error.READONLY) -- Promotion on the other node. Default should become ro. box.ctl.promote() @@ -46,7 +48,9 @@ test_run:switch('default') test_run:wait_lsn('default', 'replica') assert(box.info.ro) assert(box.info.synchro.queue.owner == test_run:get_server_id('replica')) -box.space.sync:insert{3} -- failure. +ok, err = pcall(box.space.sync.insert, box.space.sync, {3}) +assert(not ok) +assert(err.code == box.error.READONLY) box.ctl.promote() box.ctl.demote() diff --git a/test/vinyl/misc.result b/test/vinyl/misc.result index e5a56ee62..3bb4e379c 100644 --- a/test/vinyl/misc.result +++ b/test/vinyl/misc.result @@ -359,7 +359,7 @@ ch2:put(true) ... ch1:get() --- -- Can't modify data because this instance is in read-only mode. +- Can't modify data on a read-only instance - box.cfg.read_only is true ... ch1:get() --- -- 2.24.3 (Apple Git-128)