[PATCH v2 0/2] iproto: update readahead in existing connections

[PATCH v2 0/2] iproto: update readahead in existing connections

[Serge Petrenko]

https://github.com/tarantool/tarantool/issues/3958
https://github.com/tarantool/tarantool/tree/sp/gh-3958-iproto-update-readahead

Changes in v2:
  - added the second patch which moves
    readahead setting before replicaset sync.
  - reworked the test and moved it to box/net.box.test.lua
    from box/iproto_stress.test.lua

Serge Petrenko (2):
  iproto: update readahead in existing connections
  box: set readahead before replicaset sync

 src/box/box.cc            |  1 +
 src/box/iproto.cc         |  5 ++++
 src/box/lua/load_cfg.lua  |  1 +
 test/box/net.box.result   | 62 +++++++++++++++++++++++++++++++++++++++
 test/box/net.box.test.lua | 37 +++++++++++++++++++++++
 5 files changed, 106 insertions(+)

-- 
2.17.2 (Apple Git-113)

[PATCH v2 1/2] iproto: update readahead in existing connections

[Serge Petrenko]

Iproto connections keep old readahead values for input buffers even
after box.cfg.readahead reconfiguration. This means that for the changes
to take place for the old clients, they have to reconnect. Otherwise
tarantool log will be spammed with 'readahead limit is reached' errors.

To fix this, start updating input buffer size for iproto connections
if needed every time the buffer is empty.

Closes: #3958
---
 src/box/iproto.cc         |  5 ++++
 test/box/net.box.result   | 62 +++++++++++++++++++++++++++++++++++++++
 test/box/net.box.test.lua | 37 +++++++++++++++++++++++
 3 files changed, 104 insertions(+)

diff --git a/src/box/iproto.cc b/src/box/iproto.cc
index a08c8c5cb..7a1d3bfd0 100644
--- a/src/box/iproto.cc
+++ b/src/box/iproto.cc
@@ -670,6 +670,11 @@ iproto_connection_input_buffer(struct iproto_connection *con)
 		 */
 		return NULL;
 	}
+	/* Update buffer size if readahead has changed. */
+	if (new_ibuf->start_capacity != iproto_readahead) {
+		ibuf_destroy(new_ibuf);
+		ibuf_create(new_ibuf, cord_slab_cache(), iproto_readahead);
+	}
 
 	ibuf_reserve_xc(new_ibuf, to_read + con->parse_size);
 	/*
diff --git a/test/box/net.box.result b/test/box/net.box.result
index 6351898b3..d143f98f6 100644
--- a/test/box/net.box.result
+++ b/test/box/net.box.result
@@ -3452,3 +3452,65 @@ box.schema.user.revoke('guest', 'read,write', 'space', '_space')
 box.schema.user.revoke('guest', 'create', 'space')
 ---
 ...
+--
+-- gh-3958 updating box.cfg.readahead doesn't affect existing connections.
+--
+-- purge old 'readahead limit is reached' messages from the log.
+test_run:cmd("restart server default")
+netbox = require('net.box')
+---
+...
+readahead = box.cfg.readahead
+---
+...
+box.cfg{readahead = 128}
+---
+...
+s = box.schema.space.create("test")
+---
+...
+_ = s:create_index("pk")
+---
+...
+box.schema.user.grant("guest", "read,write", "space", "test")
+---
+...
+-- connection is created with small readahead value,
+-- make sure it is updated if box.cfg.readahead is changed.
+c = netbox.connect(box.cfg.listen)
+---
+...
+box.cfg{readahead = 100 * 1024}
+---
+...
+box.error.injection.set("ERRINJ_WAL_DELAY", true)
+---
+- ok
+...
+test_run:cmd('setopt delimiter ";"')
+---
+- true
+...
+local pad = string.rep('x', 8192)
+for i = 1,5 do
+        c.space.test:replace({i, pad}, {is_async=true})
+end;
+---
+...
+test_run:cmd('setopt delimiter ""');
+---
+- true
+...
+box.error.injection.set("ERRINJ_WAL_DELAY", false)
+---
+- ok
+...
+test_run:wait_log('default', 'readahead limit is reached', nil, 1.0)
+---
+...
+s:drop()
+---
+...
+box.cfg{readahead = readahead}
+---
+...
diff --git a/test/box/net.box.test.lua b/test/box/net.box.test.lua
index 6c527f506..d69a4ee73 100644
--- a/test/box/net.box.test.lua
+++ b/test/box/net.box.test.lua
@@ -1397,3 +1397,40 @@ box.schema.func.drop('do_long')
 box.schema.user.revoke('guest', 'write', 'space', '_schema')
 box.schema.user.revoke('guest', 'read,write', 'space', '_space')
 box.schema.user.revoke('guest', 'create', 'space')
+
+--
+-- gh-3958 updating box.cfg.readahead doesn't affect existing connections.
+--
+-- purge old 'readahead limit is reached' messages from the log.
+test_run:cmd("restart server default")
+netbox = require('net.box')
+
+readahead = box.cfg.readahead
+
+box.cfg{readahead = 128}
+
+s = box.schema.space.create("test")
+_ = s:create_index("pk")
+box.schema.user.grant("guest", "read,write", "space", "test")
+
+-- connection is created with small readahead value,
+-- make sure it is updated if box.cfg.readahead is changed.
+c = netbox.connect(box.cfg.listen)
+
+box.cfg{readahead = 100 * 1024}
+
+box.error.injection.set("ERRINJ_WAL_DELAY", true)
+
+test_run:cmd('setopt delimiter ";"')
+local pad = string.rep('x', 8192)
+for i = 1,5 do
+        c.space.test:replace({i, pad}, {is_async=true})
+end;
+test_run:cmd('setopt delimiter ""');
+
+box.error.injection.set("ERRINJ_WAL_DELAY", false)
+
+test_run:wait_log('default', 'readahead limit is reached', nil, 1.0)
+
+s:drop()
+box.cfg{readahead = readahead}
-- 
2.17.2 (Apple Git-113)

Re: [PATCH v2 1/2] iproto: update readahead in existing connections

[Vladimir Davydov]

On Thu, Feb 21, 2019 at 09:02:35PM +0300, Serge Petrenko wrote:
> diff --git a/test/box/net.box.result b/test/box/net.box.result
> index 6351898b3..d143f98f6 100644
> --- a/test/box/net.box.result
> +++ b/test/box/net.box.result
> @@ -3452,3 +3452,65 @@ box.schema.user.revoke('guest', 'read,write', 'space', '_space')
>  box.schema.user.revoke('guest', 'create', 'space')
>  ---
>  ...
> +--
> +-- gh-3958 updating box.cfg.readahead doesn't affect existing connections.
> +--
> +-- purge old 'readahead limit is reached' messages from the log.
> +test_run:cmd("restart server default")

Please avoid restarting the default instance in tests when you can avoid
it - it increases the test runtime. I removed it and instead decreased
the wait_log buffer size down to 1024 bytes.

> +netbox = require('net.box')
> +---
> +...
> +readahead = box.cfg.readahead
> +---
> +...
> +box.cfg{readahead = 128}
> +---
> +...
> +s = box.schema.space.create("test")
> +---
> +...
> +_ = s:create_index("pk")
> +---
> +...
> +box.schema.user.grant("guest", "read,write", "space", "test")
> +---
> +...
> +-- connection is created with small readahead value,
> +-- make sure it is updated if box.cfg.readahead is changed.
> +c = netbox.connect(box.cfg.listen)
> +---
> +...
> +box.cfg{readahead = 100 * 1024}
> +---
> +...
> +box.error.injection.set("ERRINJ_WAL_DELAY", true)
> +---
> +- ok
> +...
> +test_run:cmd('setopt delimiter ";"')
> +---
> +- true
> +...
> +local pad = string.rep('x', 8192)
> +for i = 1,5 do
> +        c.space.test:replace({i, pad}, {is_async=true})


> +end;
> +---
> +...
> +test_run:cmd('setopt delimiter ""');

Could be written in one line without hurting readability.

> +---
> +- true
> +...
> +box.error.injection.set("ERRINJ_WAL_DELAY", false)
> +---
> +- ok
> +...
> +test_run:wait_log('default', 'readahead limit is reached', nil, 1.0)

0.1 timeout is enough.

> +---
> +...
> +s:drop()
> +---
> +...
> +box.cfg{readahead = readahead}
> +---
> +...

Pushed to 2.1 and 1.10 with the following incremental changes:

diff --git a/test/box/net.box.result b/test/box/net.box.result
index d143f98f..b800531b 100644
--- a/test/box/net.box.result
+++ b/test/box/net.box.result
@@ -3455,11 +3455,6 @@ box.schema.user.revoke('guest', 'create', 'space')
 --
 -- gh-3958 updating box.cfg.readahead doesn't affect existing connections.
 --
--- purge old 'readahead limit is reached' messages from the log.
-test_run:cmd("restart server default")
-netbox = require('net.box')
----
-...
 readahead = box.cfg.readahead
 ---
 ...
@@ -3477,7 +3472,7 @@ box.schema.user.grant("guest", "read,write", "space", "test")
 ...
 -- connection is created with small readahead value,
 -- make sure it is updated if box.cfg.readahead is changed.
-c = netbox.connect(box.cfg.listen)
+c = net.connect(box.cfg.listen)
 ---
 ...
 box.cfg{readahead = 100 * 1024}
@@ -3487,25 +3482,17 @@ box.error.injection.set("ERRINJ_WAL_DELAY", true)
 ---
 - ok
 ...
-test_run:cmd('setopt delimiter ";"')
+pad = string.rep('x', 8192)
 ---
-- true
 ...
-local pad = string.rep('x', 8192)
-for i = 1,5 do
-        c.space.test:replace({i, pad}, {is_async=true})
-end;
+for i = 1, 5 do c.space.test:replace({i, pad}, {is_async = true}) end
 ---
 ...
-test_run:cmd('setopt delimiter ""');
----
-- true
-...
 box.error.injection.set("ERRINJ_WAL_DELAY", false)
 ---
 - ok
 ...
-test_run:wait_log('default', 'readahead limit is reached', nil, 1.0)
+test_run:wait_log('default', 'readahead limit is reached', 1024, 0.1)
 ---
 ...
 s:drop()
diff --git a/test/box/net.box.test.lua b/test/box/net.box.test.lua
index d69a4ee7..9e5ecfa0 100644
--- a/test/box/net.box.test.lua
+++ b/test/box/net.box.test.lua
@@ -1401,10 +1401,6 @@ box.schema.user.revoke('guest', 'create', 'space')
 --
 -- gh-3958 updating box.cfg.readahead doesn't affect existing connections.
 --
--- purge old 'readahead limit is reached' messages from the log.
-test_run:cmd("restart server default")
-netbox = require('net.box')
-
 readahead = box.cfg.readahead
 
 box.cfg{readahead = 128}
@@ -1415,22 +1411,16 @@ box.schema.user.grant("guest", "read,write", "space", "test")
 
 -- connection is created with small readahead value,
 -- make sure it is updated if box.cfg.readahead is changed.
-c = netbox.connect(box.cfg.listen)
+c = net.connect(box.cfg.listen)
 
 box.cfg{readahead = 100 * 1024}
 
 box.error.injection.set("ERRINJ_WAL_DELAY", true)
-
-test_run:cmd('setopt delimiter ";"')
-local pad = string.rep('x', 8192)
-for i = 1,5 do
-        c.space.test:replace({i, pad}, {is_async=true})
-end;
-test_run:cmd('setopt delimiter ""');
-
+pad = string.rep('x', 8192)
+for i = 1, 5 do c.space.test:replace({i, pad}, {is_async = true}) end
 box.error.injection.set("ERRINJ_WAL_DELAY", false)
 
-test_run:wait_log('default', 'readahead limit is reached', nil, 1.0)
+test_run:wait_log('default', 'readahead limit is reached', 1024, 0.1)
 
 s:drop()
 box.cfg{readahead = readahead}

[PATCH v2 2/2] box: set readahead before replicaset sync

[Serge Petrenko]

Previously readahead was set after the instance synced with all existing
masters. This could lead to a case when some client connections created
rather early would start with default readahead value even when
it was explicitly set to some value.
So, start setting readahead before replicaset sync.

Follow-up: #3958
---
 src/box/box.cc           | 1 +
 src/box/lua/load_cfg.lua | 1 +
 2 files changed, 2 insertions(+)

diff --git a/src/box/box.cc b/src/box/box.cc
index a3d708fc9..cf2254d0c 100644
--- a/src/box/box.cc
+++ b/src/box/box.cc
@@ -2122,6 +2122,7 @@ box_cfg_xc(void)
 	box_check_replicaset_uuid(&replicaset_uuid);
 
 	box_set_net_msg_max();
+	box_set_readahead();
 	box_set_too_long_threshold();
 	box_set_replication_timeout();
 	box_set_replication_connect_timeout();
diff --git a/src/box/lua/load_cfg.lua b/src/box/lua/load_cfg.lua
index fc4e560d9..6c9a82042 100644
--- a/src/box/lua/load_cfg.lua
+++ b/src/box/lua/load_cfg.lua
@@ -274,6 +274,7 @@ local dynamic_cfg_skip_at_load = {
     instance_uuid           = true,
     replicaset_uuid         = true,
     net_msg_max             = true,
+    readahead               = true,
 }
 
 local function convert_gb(size)
-- 
2.17.2 (Apple Git-113)

Re: [PATCH v2 2/2] box: set readahead before replicaset sync

[Vladimir Davydov]

On Thu, Feb 21, 2019 at 09:02:36PM +0300, Serge Petrenko wrote:
> Previously readahead was set after the instance synced with all existing
> masters. This could lead to a case when some client connections created
> rather early would start with default readahead value even when
> it was explicitly set to some value.
> So, start setting readahead before replicaset sync.
> 
> Follow-up: #3958

Pushed to 2.1 and 1.10.