[Tarantool-patches] [PATCH] say: fix format for fiber()->fid

[Tarantool-patches] [PATCH] say: fix format for fiber()->fid

[Cyrill Gorcunov via Tarantool-patches]

The fiber's ID (fiber::fid) is unsigned integer so
we should use a proper format specificator when printing
it out, otherwise the logger show us weird strings like

 | main/-244760339/cartridge.failover.task I> Instance state changed

Fixes #5846

Signed-off-by: Cyrill Gorcunov <gorcunov@gmail.com>
---
 src/lib/core/say.c | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/src/lib/core/say.c b/src/lib/core/say.c
index cbd10e107..6138752a7 100644
--- a/src/lib/core/say.c
+++ b/src/lib/core/say.c
@@ -792,7 +792,7 @@ say_format_plain_tail(char *buf, int len, int level, const char *filename,
 	if (cord) {
 		SNPRINT(total, snprintf, buf, len, " %s", cord->name);
 		if (fiber() && fiber()->fid != FIBER_ID_SCHED) {
-			SNPRINT(total, snprintf, buf, len, "/%i/%s",
+			SNPRINT(total, snprintf, buf, len, "/%u/%s",
 				fiber()->fid, fiber_name(fiber()));
 		}
 	}
@@ -918,7 +918,7 @@ say_format_json(struct log *log, char *buf, int len, int level, const char *file
 		SNPRINT(total, snprintf, buf, len, "\"");
 		if (fiber() && fiber()->fid != FIBER_ID_SCHED) {
 			SNPRINT(total, snprintf, buf, len,
-				", \"fiber_id\": %i, ", fiber()->fid);
+				", \"fiber_id\": %u, ", fiber()->fid);
 			SNPRINT(total, snprintf, buf, len,
 				"\"fiber_name\": \"");
 			SNPRINT(total, json_escape, buf, len,

base-commit: 6610bce9bf43a139043518cd76d3c0c81c981ce2
-- 
2.29.2

Re: [Tarantool-patches] [PATCH] say: fix format for fiber()->fid

[Cyrill Gorcunov via Tarantool-patches]

On Mon, Feb 22, 2021 at 09:20:30PM +0300, Cyrill Gorcunov wrote:
> The fiber's ID (fiber::fid) is unsigned integer so
> we should use a proper format specificator when printing
> it out, otherwise the logger show us weird strings like
> 
>  | main/-244760339/cartridge.failover.task I> Instance state changed
> 
> Fixes #5846
> 
> Signed-off-by: Cyrill Gorcunov <gorcunov@gmail.com>

Since it is one simple patch I though it doesn't deserve separate
branch but just in case pushed gorcunov/gh-5846-fid-name out.

Re: [Tarantool-patches] [PATCH] say: fix format for fiber()->fid

[Vladislav Shpilevoy via Tarantool-patches]

Hi! Please, add a changelog file. This is user-visible behaviour
so it must be reflected in the changes.

On 22.02.2021 19:20, Cyrill Gorcunov wrote:
> The fiber's ID (fiber::fid) is unsigned integer so
> we should use a proper format specificator when printing
> it out, otherwise the logger show us weird strings like
> 
>  | main/-244760339/cartridge.failover.task I> Instance state changed
> 
> Fixes #5846
> 
> Signed-off-by: Cyrill Gorcunov <gorcunov@gmail.com>
> ---
>  src/lib/core/say.c | 4 ++--
>  1 file changed, 2 insertions(+), 2 deletions(-)
> 
> diff --git a/src/lib/core/say.c b/src/lib/core/say.c
> index cbd10e107..6138752a7 100644
> --- a/src/lib/core/say.c
> +++ b/src/lib/core/say.c
> @@ -792,7 +792,7 @@ say_format_plain_tail(char *buf, int len, int level, const char *filename,
>  	if (cord) {
>  		SNPRINT(total, snprintf, buf, len, " %s", cord->name);
>  		if (fiber() && fiber()->fid != FIBER_ID_SCHED) {
> -			SNPRINT(total, snprintf, buf, len, "/%i/%s",
> +			SNPRINT(total, snprintf, buf, len, "/%u/%s",
>  				fiber()->fid, fiber_name(fiber()));

I remember we had some issues about %u not being compatible with uint32_t so
we did manual casts to 'unsigned'. Not sure though what was the commit/ticket,
or if it really happened.

I am fine with not using the cast as long as all platforms and compilers
build flawlessly. Also it is ok for me if you will add an explicit cast in
the next version of the patch. Up to you. The same below.

>  		}
>  	}
> @@ -918,7 +918,7 @@ say_format_json(struct log *log, char *buf, int len, int level, const char *file
>  		SNPRINT(total, snprintf, buf, len, "\"");
>  		if (fiber() && fiber()->fid != FIBER_ID_SCHED) {
>  			SNPRINT(total, snprintf, buf, len,
> -				", \"fiber_id\": %i, ", fiber()->fid);
> +				", \"fiber_id\": %u, ", fiber()->fid);
>  			SNPRINT(total, snprintf, buf, len,
>  				"\"fiber_name\": \"");
>  			SNPRINT(total, json_escape, buf, len,
> 
> base-commit: 6610bce9bf43a139043518cd76d3c0c81c981ce2

Re: [Tarantool-patches] [PATCH] say: fix format for fiber()->fid

[Cyrill Gorcunov via Tarantool-patches]

On Tue, Feb 23, 2021 at 09:41:46PM +0100, Vladislav Shpilevoy wrote:
> Hi! Please, add a changelog file. This is user-visible behaviour
> so it must be reflected in the changes.
> 
> On 22.02.2021 19:20, Cyrill Gorcunov wrote:
> > The fiber's ID (fiber::fid) is unsigned integer so
> > we should use a proper format specificator when printing
> > it out, otherwise the logger show us weird strings like
> > 
> >  | main/-244760339/cartridge.failover.task I> Instance state changed
> > 
> > Fixes #5846
> > 
> > Signed-off-by: Cyrill Gorcunov <gorcunov@gmail.com>
> > ---
> >  src/lib/core/say.c | 4 ++--
> >  1 file changed, 2 insertions(+), 2 deletions(-)
> > 
> > diff --git a/src/lib/core/say.c b/src/lib/core/say.c
> > index cbd10e107..6138752a7 100644
> > --- a/src/lib/core/say.c
> > +++ b/src/lib/core/say.c
> > @@ -792,7 +792,7 @@ say_format_plain_tail(char *buf, int len, int level, const char *filename,
> >  	if (cord) {
> >  		SNPRINT(total, snprintf, buf, len, " %s", cord->name);
> >  		if (fiber() && fiber()->fid != FIBER_ID_SCHED) {
> > -			SNPRINT(total, snprintf, buf, len, "/%i/%s",
> > +			SNPRINT(total, snprintf, buf, len, "/%u/%s",
> >  				fiber()->fid, fiber_name(fiber()));
> 
> I remember we had some issues about %u not being compatible with uint32_t so
> we did manual casts to 'unsigned'. Not sure though what was the commit/ticket,
> or if it really happened.

I suspect you rather mean uint64_t, which indeed better convert to
excplicit "long long". Strictly speaking if we really need to cover
compatibility we would _had_ to use PRIx macros which are so ugly :/
So no, uint32_t is known to be safe with %u format.

Side note: I found that we still use %u for some of uint64_t,
in particuar

	if (req->term < raft->volatile_term) {
		say_info("RAFT: the message is ignored due to outdated term - "
			 "current term is %u", raft->volatile_term);
		return 0;
	}

probably should use %llu and explicit "long long" for long standing
servers where raft term would overflow 32 bit value.

> 
> I am fine with not using the cast as long as all platforms and compilers
> build flawlessly. Also it is ok for me if you will add an explicit cast in
> the next version of the patch. Up to you. The same below.

No, Vlad, I think we don't need explicit casts for 32bit values. I pushed
an update to the branch gorcunov/gh-5846-fid-name and here is a new
changelog. Does it look better?
---
Subject: [PATCH] say: use unsigned  format for fiber()->fid

The fiber's ID (fiber::fid) is defined as unsigned integer
so we should use a proper format specificator when printing
it out. Currently logger prints such fibers as negative

 | main/-244760339/cartridge.failover.task I> Instance state changed

why it should be

 | main/4271292179/cartridge.failover.task I> Instance state changed

After the fix all fibers are logged with natural numbers (both in
plain logger and json output formats) which might be considered
as API change but should not cause any problems because if there
were tools which scans for "zahlen" numbers they will scan for
natural numbers without problems. After all there is no such
things as fibers with negative numbers and when their fids
are printed in Lua's "info" they are all natural (because
they are converted into real numbers internally).

Fixes #5846

Re: [Tarantool-patches] [PATCH] say: fix format for fiber()->fid

[Vladislav Shpilevoy via Tarantool-patches]

>>> diff --git a/src/lib/core/say.c b/src/lib/core/say.c
>>> index cbd10e107..6138752a7 100644
>>> --- a/src/lib/core/say.c
>>> +++ b/src/lib/core/say.c
>>> @@ -792,7 +792,7 @@ say_format_plain_tail(char *buf, int len, int level, const char *filename,
>>>  	if (cord) {
>>>  		SNPRINT(total, snprintf, buf, len, " %s", cord->name);
>>>  		if (fiber() && fiber()->fid != FIBER_ID_SCHED) {
>>> -			SNPRINT(total, snprintf, buf, len, "/%i/%s",
>>> +			SNPRINT(total, snprintf, buf, len, "/%u/%s",
>>>  				fiber()->fid, fiber_name(fiber()));
>>
>> I remember we had some issues about %u not being compatible with uint32_t so
>> we did manual casts to 'unsigned'. Not sure though what was the commit/ticket,
>> or if it really happened.
> 
> I suspect you rather mean uint64_t, which indeed better convert to
> excplicit "long long".

No, I mean exactly uint32_t. You don't have a guarantee that it is
the same as 'unsigned' AFAIK.

> Strictly speaking if we really need to cover
> compatibility we would _had_ to use PRIx macros which are so ugly :/

This is why I want us to use casts to 'unsigned' when we use %u. They
are less ugly.

> So no, uint32_t is known to be safe with %u format.

Is it written in the standard somewhere? I honestly don't know.

> Side note: I found that we still use %u for some of uint64_t,
> in particuar
> 
> 	if (req->term < raft->volatile_term) {
> 		say_info("RAFT: the message is ignored due to outdated term - "
> 			 "current term is %u", raft->volatile_term);
> 		return 0;
> 	}
> 
> probably should use %llu and explicit "long long" for long standing
> servers where raft term would overflow 32 bit value.

Yes, looks like a bug.

But a more appropriate fix would be to investigate why don't we have
compile time checks for this. The bug in raft's say_info() is clearly
an error and should have been alarmed at compilation.

At least clang supports an attribute which you can set for a function
and get printf-like checks and warnings in case of format issues.

We should adopt this: https://clang.llvm.org/docs/AttributeReference.html#id278

Somewhy I thought we already use it, but now I don't see any usages.
It is easy to add, and helps to catch some weird stuff.

Lets do it in scope of this patch series to fix the issue entirely. Not
just in one exploded place.

>> I am fine with not using the cast as long as all platforms and compilers
>> build flawlessly. Also it is ok for me if you will add an explicit cast in
>> the next version of the patch. Up to you. The same below.
> 
> No, Vlad, I think we don't need explicit casts for 32bit values.

Do you have a proof for this? That it is safe. Where in the standard do they
say that '%u' is exactly 4 bytes?

> I pushed
> an update to the branch gorcunov/gh-5846-fid-name and here is a new
> changelog. Does it look better?

It seems you didn't really read my comment, did you? I said:

	"Please, add a changelog file"

I didn't ask for more info in the commit message. This particular
bug in this particular line was obvious.

But you didn't add a changelog **file**. It should be added here:
https://github.com/tarantool/tarantool/tree/master/changelogs/unreleased


After more consideration I also realized we should not use uint32_t
for fiber ids. It is monotonically growing. Which means it will overflow
in the foreseeable future on a long-running instance.

For example, assume one fiber is started and recycled each millisecond
(which is quite a small rate). Then uint32 will overflow in less than
50 days. Considering we have instances running for years (at least from
what I heard from Mons), this is clearly a bug.


On the summary, it seems we need to

- Add compile-time format checks using clang __format__ attribute;
- Fix all the wrong formats;
- Use 64bit ids for fibers. Unless I am wrong somewhere in my thoughts
  above.

Re: [Tarantool-patches] [PATCH] say: fix format for fiber()->fid

[Cyrill Gorcunov via Tarantool-patches]

On Tue, Feb 23, 2021 at 11:47:44PM +0100, Vladislav Shpilevoy wrote:
> >>> diff --git a/src/lib/core/say.c b/src/lib/core/say.c
> >>> index cbd10e107..6138752a7 100644
> >>> --- a/src/lib/core/say.c
> >>> +++ b/src/lib/core/say.c
> >>> @@ -792,7 +792,7 @@ say_format_plain_tail(char *buf, int len, int level, const char *filename,
> >>>  	if (cord) {
> >>>  		SNPRINT(total, snprintf, buf, len, " %s", cord->name);
> >>>  		if (fiber() && fiber()->fid != FIBER_ID_SCHED) {
> >>> -			SNPRINT(total, snprintf, buf, len, "/%i/%s",
> >>> +			SNPRINT(total, snprintf, buf, len, "/%u/%s",
> >>>  				fiber()->fid, fiber_name(fiber()));
> >>
> >> I remember we had some issues about %u not being compatible with uint32_t so
> >> we did manual casts to 'unsigned'. Not sure though what was the commit/ticket,
> >> or if it really happened.
> > 
> > I suspect you rather mean uint64_t, which indeed better convert to
> > excplicit "long long".
> 
> No, I mean exactly uint32_t. You don't have a guarantee that it is
> the same as 'unsigned' AFAIK.

It is, on x86. And I really doubt if we ever meet an arch where int
is not 4 bytes long. Though in embedded world this might be a common
situation (but if we aim ourself to run tarantool here the output
issue gonna be a least problem).

> 
> > Strictly speaking if we really need to cover
> > compatibility we would _had_ to use PRIx macros which are so ugly :/
> 
> This is why I want us to use casts to 'unsigned' when we use %u. They
> are less ugly.

We will have to cover a bunch of already existing code for nothing :(
But OK, I'll add explicit cast.

> 
> > So no, uint32_t is known to be safe with %u format.
> 
> Is it written in the standard somewhere? I honestly don't know.

Standart for builtin types doesn't cover the size of machine words
as far as I remember because this would tie a hands for compiler developers
which have to deal with custom archs. It specifies the integer classes
covering and on x86 we know that we're safe. But as I said I'll add
explicit cast.

> > Side note: I found that we still use %u for some of uint64_t,
> > in particuar
> > 
> > 	if (req->term < raft->volatile_term) {
> > 		say_info("RAFT: the message is ignored due to outdated term - "
> > 			 "current term is %u", raft->volatile_term);
> > 		return 0;
> > 	}
> > 
> > probably should use %llu and explicit "long long" for long standing
> > servers where raft term would overflow 32 bit value.
> 
> Yes, looks like a bug.

Should not be critical, though. It is logging for debug mostly but we
should fix it.

> But a more appropriate fix would be to investigate why don't we have
> compile time checks for this. The bug in raft's say_info() is clearly
> an error and should have been alarmed at compilation.

We have kind of check

/** Internal function used to implement say() macros */
CFORMAT(printf, 5, 0) extern sayfunc_t _say;

still I must confess I don't know yet why it didn't trigger, need
to investigate.

> At least clang supports an attribute which you can set for a function
> and get printf-like checks and warnings in case of format issues.
> 
> We should adopt this: https://clang.llvm.org/docs/AttributeReference.html#id278
> 
> Somewhy I thought we already use it, but now I don't see any usages.
> It is easy to add, and helps to catch some weird stuff.
> 
> Lets do it in scope of this patch series to fix the issue entirely. Not
> just in one exploded place.

OK

> 
> >> I am fine with not using the cast as long as all platforms and compilers
> >> build flawlessly. Also it is ok for me if you will add an explicit cast in
> >> the next version of the patch. Up to you. The same below.
> > 
> > No, Vlad, I think we don't need explicit casts for 32bit values.
> 
> Do you have a proof for this? That it is safe. Where in the standard do they
> say that '%u' is exactly 4 bytes?

Already explained. I'll make it use explicit cast though I still
think it is redundant.

> > I pushed
> > an update to the branch gorcunov/gh-5846-fid-name and here is a new
> > changelog. Does it look better?
> 
> It seems you didn't really read my comment, did you? I said:
> 
> 	"Please, add a changelog file"
> 
> I didn't ask for more info in the commit message. This particular
> bug in this particular line was obvious.
> 
> But you didn't add a changelog **file**. It should be added here:
> https://github.com/tarantool/tarantool/tree/master/changelogs/unreleased

Ah, you mean this new tecique for changelogs. OK, misread your comment,
at first I thought to update commit message for better export into
changelog. Will do.

> 
> After more consideration I also realized we should not use uint32_t
> for fiber ids. It is monotonically growing. Which means it will overflow
> in the foreseeable future on a long-running instance.

 - it is explected to be overlowable from the beginning
 - the IDs are recycled

I've been talking to Kostya about a year ago once I discovered that
we're walking in cycle when reusing IDs. He assured me that this is
fine and to get a problem we have to allocate 4294967195 fibers at
once which will require ~1.5T of memory just to allocate fiber structure.
Hardy to happen. Still I think we at least should add a painc in case of
hash collision for future.

> For example, assume one fiber is started and recycled each millisecond
> (which is quite a small rate). Then uint32 will overflow in less than
> 50 days. Considering we have instances running for years (at least from
> what I heard from Mons), this is clearly a bug.
> 
> On the summary, it seems we need to
> 
> - Add compile-time format checks using clang __format__ attribute;
> - Fix all the wrong formats;

+1

> - Use 64bit ids for fibers. Unless I am wrong somewhere in my thoughts
>   above.

This is dubious. Personally I would prefer to have them as uint64_t too
now and for all, to simply forget about this potential issue. +4 bytes
to fiber structure seems to be acceptable trade off.

	Cyrill

[Tarantool-patches] [PATCH v2 00/10] say: fix format strings

[Cyrill Gorcunov via Tarantool-patches]

When been fixing issue 5846 we've found that our
format specification test simply doesn't work. Lets
use proper formatting and turn it back on.

Guys, I split the series per-file for better review
and probably fixups if there will be a need. After
all committer may simply merge all them except the
first one.

issue https://github.com/tarantool/tarantool/issues/5846
branch gorcunov/gh-5846-fid-name-2

v2:
 - add changelog
 - revisit CFORMAT
 - fix all warnings covered so far

Cyrill Gorcunov (10):
  say: use unsigned  format for fiber()->fid
  popen: fix say_x format arguments
  raft: fix say_x arguments
  box/error: fix argument for CustomError
  xlog: fix say_x format
  box/vynil: fix say_x format
  txn: fix say_x format
  limbo: fix say_x format
  wal: fix say_x format
  say: fix CFORMAT specification

 changelogs/unreleased/fix-fiber-fid-log.md |  5 +++++
 src/box/error.cc                           |  2 +-
 src/box/txn.c                              |  3 ++-
 src/box/txn_limbo.c                        |  2 +-
 src/box/vy_scheduler.c                     |  2 +-
 src/box/wal.c                              | 15 ++++++++-------
 src/box/xlog.c                             |  4 ++--
 src/lib/core/popen.c                       |  4 ++--
 src/lib/core/say.c                         |  6 +++---
 src/lib/core/say.h                         |  2 +-
 src/lib/raft/raft.c                        |  5 +++--
 11 files changed, 29 insertions(+), 21 deletions(-)
 create mode 100644 changelogs/unreleased/fix-fiber-fid-log.md


base-commit: 6610bce9bf43a139043518cd76d3c0c81c981ce2
-- 
2.29.2

[Tarantool-patches] [PATCH v2 01/10] say: use unsigned format for fiber()->fid

[Cyrill Gorcunov via Tarantool-patches]

The fiber's ID (fiber::fid) is defined as unsigned integer
so we should use a proper format specificator when printing
it out. Currently logger prints such fibers as negative

 | main/-244760339/cartridge.failover.task I> Instance state changed

why it should be

 | main/4271292179/cartridge.failover.task I> Instance state changed

After the fix all fibers are logged with natural numbers (both in
plain logger and json output formats).

Fixes #5846

Signed-off-by: Cyrill Gorcunov <gorcunov@gmail.com>
---
 changelogs/unreleased/fix-fiber-fid-log.md | 5 +++++
 src/lib/core/say.c                         | 6 +++---
 2 files changed, 8 insertions(+), 3 deletions(-)
 create mode 100644 changelogs/unreleased/fix-fiber-fid-log.md

diff --git a/changelogs/unreleased/fix-fiber-fid-log.md b/changelogs/unreleased/fix-fiber-fid-log.md
new file mode 100644
index 000000000..fb75af804
--- /dev/null
+++ b/changelogs/unreleased/fix-fiber-fid-log.md
@@ -0,0 +1,5 @@
+## bugfix/core
+
+* Fix logger output for fiber id: format specificator has been
+  using signed integers while fibers actually are defined as
+  unsigned numbers (gh-5846).
diff --git a/src/lib/core/say.c b/src/lib/core/say.c
index cbd10e107..76c524872 100644
--- a/src/lib/core/say.c
+++ b/src/lib/core/say.c
@@ -792,8 +792,8 @@ say_format_plain_tail(char *buf, int len, int level, const char *filename,
 	if (cord) {
 		SNPRINT(total, snprintf, buf, len, " %s", cord->name);
 		if (fiber() && fiber()->fid != FIBER_ID_SCHED) {
-			SNPRINT(total, snprintf, buf, len, "/%i/%s",
-				fiber()->fid, fiber_name(fiber()));
+			SNPRINT(total, snprintf, buf, len, "/%u/%s",
+				(unsigned)fiber()->fid, fiber_name(fiber()));
 		}
 	}
 
@@ -918,7 +918,7 @@ say_format_json(struct log *log, char *buf, int len, int level, const char *file
 		SNPRINT(total, snprintf, buf, len, "\"");
 		if (fiber() && fiber()->fid != FIBER_ID_SCHED) {
 			SNPRINT(total, snprintf, buf, len,
-				", \"fiber_id\": %i, ", fiber()->fid);
+				", \"fiber_id\": %u, ", (unsigned)fiber()->fid);
 			SNPRINT(total, snprintf, buf, len,
 				"\"fiber_name\": \"");
 			SNPRINT(total, json_escape, buf, len,
-- 
2.29.2

[Tarantool-patches] [PATCH v2 02/10] popen: fix say_x format arguments

[Cyrill Gorcunov via Tarantool-patches]

Drop redundant "%s" from format.

Part-of #5846

Signed-off-by: Cyrill Gorcunov <gorcunov@gmail.com>
---
 src/lib/core/popen.c | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/src/lib/core/popen.c b/src/lib/core/popen.c
index 3b5fd1062..99a3d3cbd 100644
--- a/src/lib/core/popen.c
+++ b/src/lib/core/popen.c
@@ -240,7 +240,7 @@ handle_new(struct popen_opts *opts)
 static inline void
 handle_free(struct popen_handle *handle)
 {
-	say_debug("popen: handle %p free %p", handle);
+	say_debug("popen: handle free %p", handle);
 	free(handle);
 }
 
@@ -533,7 +533,7 @@ popen_shutdown(struct popen_handle *handle, unsigned int flags)
 		if (handle->ios[idx].fd < 0)
 			continue;
 
-		say_debug("popen: %d: shutdown idx [%s:%d] fd %s",
+		say_debug("popen: %d: shutdown idx [%s:%zd] fd %d",
 			  handle->pid, stdX_str(idx), idx,
 			  handle->ios[idx].fd);
 		coio_close_io(loop(), &handle->ios[idx]);
-- 
2.29.2

[Tarantool-patches] [PATCH v2 03/10] raft: fix say_x arguments

[Cyrill Gorcunov via Tarantool-patches]

Use explicit "%lld" for int64_t type.

Signed-off-by: Cyrill Gorcunov <gorcunov@gmail.com>
---
 src/lib/raft/raft.c | 5 +++--
 1 file changed, 3 insertions(+), 2 deletions(-)

diff --git a/src/lib/raft/raft.c b/src/lib/raft/raft.c
index 4ea4fc3f8..261ff072b 100644
--- a/src/lib/raft/raft.c
+++ b/src/lib/raft/raft.c
@@ -322,7 +322,8 @@ raft_process_msg(struct raft *raft, const struct raft_msg *req, uint32_t source)
 	/* Outdated request. */
 	if (req->term < raft->volatile_term) {
 		say_info("RAFT: the message is ignored due to outdated term - "
-			 "current term is %u", raft->volatile_term);
+			 "current term is %llu",
+			 (long long)raft->volatile_term);
 		return 0;
 	}
 
@@ -653,7 +654,7 @@ raft_sm_become_candidate(struct raft *raft)
 static void
 raft_sm_schedule_new_term(struct raft *raft, uint64_t new_term)
 {
-	say_info("RAFT: bump term to %llu, follow", new_term);
+	say_info("RAFT: bump term to %llu, follow", (long long)new_term);
 	assert(new_term > raft->volatile_term);
 	assert(raft->volatile_term >= raft->term);
 	raft->volatile_term = new_term;
-- 
2.29.2

[Tarantool-patches] [PATCH v2 04/10] box/error: fix argument for CustomError

[Cyrill Gorcunov via Tarantool-patches]

Drop redundant "%s" argument.

Part-of #5846

Signed-off-by: Cyrill Gorcunov <gorcunov@gmail.com>
---
 src/box/error.cc | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/src/box/error.cc b/src/box/error.cc
index f3b4ffe86..225b377b7 100644
--- a/src/box/error.cc
+++ b/src/box/error.cc
@@ -345,7 +345,7 @@ CustomError::CustomError(const char *file, unsigned int line,
 void
 CustomError::log() const
 {
-	say_file_line(S_ERROR, file, line, errmsg, "%s",
+	say_file_line(S_ERROR, file, line, errmsg,
 		      "Custom type %s", m_custom_type);
 }
 
-- 
2.29.2

[Tarantool-patches] [PATCH v2 05/10] xlog: fix say_x format

[Cyrill Gorcunov via Tarantool-patches]

The string length specificator expects length as
integer value.

Part-of #5846

Signed-off-by: Cyrill Gorcunov <gorcunov@gmail.com>
---
 src/box/xlog.c | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/src/box/xlog.c b/src/box/xlog.c
index 974f460be..40c07abf0 100644
--- a/src/box/xlog.c
+++ b/src/box/xlog.c
@@ -314,8 +314,8 @@ xlog_meta_parse(struct xlog_meta *meta, const char **data,
 			/*
 			 * Unknown key
 			 */
-			say_warn("Unknown meta item: `%.*s'", key_end - key,
-				 key);
+			say_warn("Unknown meta item: `%.*s'",
+				 (int)(key_end - key), key);
 		}
 	}
 	*data = end + 1; /* skip the last trailing \n of \n\n sequence */
-- 
2.29.2

[Tarantool-patches] [PATCH v2 06/10] box/vynil: fix say_x format

[Cyrill Gorcunov via Tarantool-patches]

Drop redundant "%s" from format.

Part-of #5846

Signed-off-by: Cyrill Gorcunov <gorcunov@gmail.com>
---
 src/box/vy_scheduler.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/src/box/vy_scheduler.c b/src/box/vy_scheduler.c
index b641dd9b8..6f6e9c340 100644
--- a/src/box/vy_scheduler.c
+++ b/src/box/vy_scheduler.c
@@ -1714,7 +1714,7 @@ vy_task_compaction_new(struct vy_scheduler *scheduler, struct vy_worker *worker,
 	vy_task_delete(task);
 err_task:
 	diag_log();
-	say_error("%s: could not start compacting range %s: %s",
+	say_error("%s: could not start compacting range %s",
 		  vy_lsm_name(lsm), vy_range_str(range));
 	return -1;
 }
-- 
2.29.2

[Tarantool-patches] [PATCH v2 07/10] txn: fix say_x format

[Cyrill Gorcunov via Tarantool-patches]

Use explicit conversion for 64 bit number.

Part-of #5846

Signed-off-by: Cyrill Gorcunov <gorcunov@gmail.com>
---
 src/box/txn.c | 3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/src/box/txn.c b/src/box/txn.c
index a5edbfc60..c9c0579b8 100644
--- a/src/box/txn.c
+++ b/src/box/txn.c
@@ -585,7 +585,8 @@ txn_on_journal_write(struct journal_entry *entry)
 		int n_rows = txn->n_new_rows + txn->n_applier_rows;
 		say_warn_ratelimited("too long WAL write: %d rows at LSN %lld: "
 				     "%.3f sec", n_rows,
-				     txn->signature - n_rows + 1, delta);
+				     (long long)(txn->signature - n_rows + 1),
+				     delta);
 	}
 	if (txn_has_flag(txn, TXN_HAS_TRIGGERS))
 		txn_run_wal_write_triggers(txn);
-- 
2.29.2

[Tarantool-patches] [PATCH v2 08/10] limbo: fix say_x format

[Cyrill Gorcunov via Tarantool-patches]

Use explicit cast for 64 bit number.

Part-of #5846

Signed-off-by: Cyrill Gorcunov <gorcunov@gmail.com>
---
 src/box/txn_limbo.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/src/box/txn_limbo.c b/src/box/txn_limbo.c
index 9c4c3cdf1..0ca4a478a 100644
--- a/src/box/txn_limbo.c
+++ b/src/box/txn_limbo.c
@@ -354,7 +354,7 @@ txn_limbo_write_synchro(struct txn_limbo *limbo, uint32_t type, int64_t lsn)
 		 * Or retry automatically with some period.
 		 */
 		panic("Could not write a synchro request to WAL: "
-		      "lsn = %lld, type = %s\n", lsn,
+		      "lsn = %lld, type = %s\n", (long long)lsn,
 		      iproto_type_name(type));
 	}
 }
-- 
2.29.2

[Tarantool-patches] [PATCH v2 09/10] wal: fix say_x format

[Cyrill Gorcunov via Tarantool-patches]

 - vclock_get returns int64_t
 - vclock_sum returns int64_t

Part-of #5846

Signed-off-by: Cyrill Gorcunov <gorcunov@gmail.com>
---
 src/box/wal.c | 15 ++++++++-------
 1 file changed, 8 insertions(+), 7 deletions(-)

diff --git a/src/box/wal.c b/src/box/wal.c
index 937d47ba9..1c0076f26 100644
--- a/src/box/wal.c
+++ b/src/box/wal.c
@@ -993,13 +993,14 @@ wal_assign_lsn(struct vclock *vclock_diff, struct vclock *base,
 			int64_t diff = (*row)->lsn - vclock_get(base, (*row)->replica_id);
 			if (diff <= vclock_get(vclock_diff,
 					       (*row)->replica_id)) {
+				int64_t confirmed_lsn =
+					vclock_get(base, (*row)->replica_id) +
+					vclock_get(vclock_diff, (*row)->replica_id);
 				say_crit("Attempt to write a broken LSN to WAL:"
-					 " replica id: %d, confirmed lsn: %d,"
-					 " new lsn %d", (*row)->replica_id,
-					 vclock_get(base, (*row)->replica_id) +
-					 vclock_get(vclock_diff,
-						    (*row)->replica_id),
-						    (*row)->lsn);
+					 " replica id: %d, confirmed lsn: %lld,"
+					 " new lsn %lld", (*row)->replica_id,
+					 (long long)confirmed_lsn,
+					 (long long)(*row)->lsn);
 				assert(false);
 			} else {
 				vclock_follow(vclock_diff, (*row)->replica_id, diff);
@@ -1241,7 +1242,7 @@ wal_write_async(struct journal *journal, struct journal_entry *entry)
 		 */
 		say_error("Aborting transaction %llu during "
 			  "cascading rollback",
-			  vclock_sum(&writer->vclock));
+			  (long long)vclock_sum(&writer->vclock));
 		goto fail;
 	}
 
-- 
2.29.2

[Tarantool-patches] [PATCH v2 10/10] say: fix CFORMAT specification

[Cyrill Gorcunov via Tarantool-patches]

The position of first argument to check from is 6, not 0.
Looks like our tests with CFORMAT was simply not working
since commit 7d12d66e67a1ce843a2712980f4d3ba04bc0d4f2.

Lets turn them all back.

Part-of #5846

Reported-by: Vladislav Shpilevoy <v.shpilevoy@tarantool.org>
Signed-off-by: Cyrill Gorcunov <gorcunov@gmail.com>
---
 src/lib/core/say.h | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/src/lib/core/say.h b/src/lib/core/say.h
index fe8251e4c..e1fec8c60 100644
--- a/src/lib/core/say.h
+++ b/src/lib/core/say.h
@@ -287,7 +287,7 @@ typedef void (*sayfunc_t)(int, const char *, int, const char *,
 		    const char *, ...);
 
 /** Internal function used to implement say() macros */
-CFORMAT(printf, 5, 0) extern sayfunc_t _say;
+CFORMAT(printf, 5, 6) extern sayfunc_t _say;
 
 /**
  * Format and print a message to Tarantool log file.
-- 
2.29.2

Re: [Tarantool-patches] [PATCH] say: fix format for fiber()->fid

[Vladislav Shpilevoy via Tarantool-patches]

On 24.02.2021 09:28, Cyrill Gorcunov wrote:
> On Tue, Feb 23, 2021 at 11:47:44PM +0100, Vladislav Shpilevoy wrote:
>>>>> diff --git a/src/lib/core/say.c b/src/lib/core/say.c
>>>>> index cbd10e107..6138752a7 100644
>>>>> --- a/src/lib/core/say.c
>>>>> +++ b/src/lib/core/say.c
>>>>> @@ -792,7 +792,7 @@ say_format_plain_tail(char *buf, int len, int level, const char *filename,
>>>>>  	if (cord) {
>>>>>  		SNPRINT(total, snprintf, buf, len, " %s", cord->name);
>>>>>  		if (fiber() && fiber()->fid != FIBER_ID_SCHED) {
>>>>> -			SNPRINT(total, snprintf, buf, len, "/%i/%s",
>>>>> +			SNPRINT(total, snprintf, buf, len, "/%u/%s",
>>>>>  				fiber()->fid, fiber_name(fiber()));
>>>>
>>>> I remember we had some issues about %u not being compatible with uint32_t so
>>>> we did manual casts to 'unsigned'. Not sure though what was the commit/ticket,
>>>> or if it really happened.
>>>
>>> I suspect you rather mean uint64_t, which indeed better convert to
>>> excplicit "long long".
>>
>> No, I mean exactly uint32_t. You don't have a guarantee that it is
>> the same as 'unsigned' AFAIK.
> 
> It is, on x86.

In the close future we will build on the new ARM Macs. Simply because many
of our developers use Macs and they want the new models. All our assumptions
about x86 being the only platform should not be made anymore.

>>> Strictly speaking if we really need to cover
>>> compatibility we would _had_ to use PRIx macros which are so ugly :/
>>
>> This is why I want us to use casts to 'unsigned' when we use %u. They
>> are less ugly.
> 
> We will have to cover a bunch of already existing code for nothing :(
> But OK, I'll add explicit cast.

It is ok to keep the old code intact where the compiler won't give any
errors when you enable the compile time checking.

>> After more consideration I also realized we should not use uint32_t
>> for fiber ids. It is monotonically growing. Which means it will overflow
>> in the foreseeable future on a long-running instance.
> 
>  - it is explected to be overlowable from the beginning

Why? It is not safe. There is no any protection in case of overflow
and ids clash.

>  - the IDs are recycled

Exactly. They start recycle on overflow. This means if you had a long
living fiber for 50 days, and the scenario described by me happens,
you will get id clash.

> I've been talking to Kostya about a year ago once I discovered that
> we're walking in cycle when reusing IDs. He assured me that this is
> fine and to get a problem we have to allocate 4294967195 fibers at
> once which will require ~1.5T of memory just to allocate fiber structure.

It is not about at once. It is about long running instances.

> Hardy to happen. Still I think we at least should add a painc in case of
> hash collision for future.

We should just make it int64_t and forget about it IMO.

>> - Use 64bit ids for fibers. Unless I am wrong somewhere in my thoughts
>>   above.
> 
> This is dubious. Personally I would prefer to have them as uint64_t too
> now and for all, to simply forget about this potential issue. +4 bytes
> to fiber structure seems to be acceptable trade off.

Exactly.

Re: [Tarantool-patches] [PATCH v2 02/10] popen: fix say_x format arguments

[Vladislav Shpilevoy via Tarantool-patches]

Hi! Thanks for the patch!

On 24.02.2021 16:36, Cyrill Gorcunov wrote:
> Drop redundant "%s" from format.

Neither of the changes below are about dropping a redundant %s.
First one drops %p, second one replaces it with %d and fixes
size_t.

> Part-of #5846
> 
> Signed-off-by: Cyrill Gorcunov <gorcunov@gmail.com>
> ---
>  src/lib/core/popen.c | 4 ++--
>  1 file changed, 2 insertions(+), 2 deletions(-)
> 
> diff --git a/src/lib/core/popen.c b/src/lib/core/popen.c
> index 3b5fd1062..99a3d3cbd 100644
> --- a/src/lib/core/popen.c
> +++ b/src/lib/core/popen.c
> @@ -240,7 +240,7 @@ handle_new(struct popen_opts *opts)
>  static inline void
>  handle_free(struct popen_handle *handle)
>  {
> -	say_debug("popen: handle %p free %p", handle);
> +	say_debug("popen: handle free %p", handle);
>  	free(handle);
>  }
>  
> @@ -533,7 +533,7 @@ popen_shutdown(struct popen_handle *handle, unsigned int flags)
>  		if (handle->ios[idx].fd < 0)
>  			continue;
>  
> -		say_debug("popen: %d: shutdown idx [%s:%d] fd %s",
> +		say_debug("popen: %d: shutdown idx [%s:%zd] fd %d",
>  			  handle->pid, stdX_str(idx), idx,
>  			  handle->ios[idx].fd);
>  		coio_close_io(loop(), &handle->ios[idx]);
> 

Re: [Tarantool-patches] [PATCH v2 03/10] raft: fix say_x arguments

[Vladislav Shpilevoy via Tarantool-patches]

Thanks for the patch!

On 24.02.2021 16:36, Cyrill Gorcunov wrote:
> Use explicit "%lld" for int64_t type.

In the changes you use %llu in both cases.

> Signed-off-by: Cyrill Gorcunov <gorcunov@gmail.com>
> ---
>  src/lib/raft/raft.c | 5 +++--
>  1 file changed, 3 insertions(+), 2 deletions(-)
> 
> diff --git a/src/lib/raft/raft.c b/src/lib/raft/raft.c
> index 4ea4fc3f8..261ff072b 100644
> --- a/src/lib/raft/raft.c
> +++ b/src/lib/raft/raft.c
> @@ -322,7 +322,8 @@ raft_process_msg(struct raft *raft, const struct raft_msg *req, uint32_t source)
>  	/* Outdated request. */
>  	if (req->term < raft->volatile_term) {
>  		say_info("RAFT: the message is ignored due to outdated term - "
> -			 "current term is %u", raft->volatile_term);
> +			 "current term is %llu",
> +			 (long long)raft->volatile_term);

It is unsigned. So the cast must be 'unsigned long long'.
The same below.

>  		return 0;
>  	}
>  
> @@ -653,7 +654,7 @@ raft_sm_become_candidate(struct raft *raft)
>  static void
>  raft_sm_schedule_new_term(struct raft *raft, uint64_t new_term)
>  {
> -	say_info("RAFT: bump term to %llu, follow", new_term);
> +	say_info("RAFT: bump term to %llu, follow", (long long)new_term);
>  	assert(new_term > raft->volatile_term);
>  	assert(raft->volatile_term >= raft->term);
>  	raft->volatile_term = new_term;
> 

Re: [Tarantool-patches] [PATCH v2 05/10] xlog: fix say_x format

[Vladislav Shpilevoy via Tarantool-patches]

Thanks for the patch!

On 24.02.2021 16:36, Cyrill Gorcunov wrote:
> The string length specificator expects length as
> integer value.
> 
> Part-of #5846
> 
> Signed-off-by: Cyrill Gorcunov <gorcunov@gmail.com>
> ---
>  src/box/xlog.c | 4 ++--
>  1 file changed, 2 insertions(+), 2 deletions(-)
> 
> diff --git a/src/box/xlog.c b/src/box/xlog.c
> index 974f460be..40c07abf0 100644
> --- a/src/box/xlog.c
> +++ b/src/box/xlog.c
> @@ -314,8 +314,8 @@ xlog_meta_parse(struct xlog_meta *meta, const char **data,
>  			/*
>  			 * Unknown key
>  			 */
> -			say_warn("Unknown meta item: `%.*s'", key_end - key,
> -				 key);
> +			say_warn("Unknown meta item: `%.*s'",

The quotes around %s are inconsistent: `' instead of '' or ``. Lets
use ''. I know it was there before your patch, but lets fix it anyway,
considering it a part of the format.

> +				 (int)(key_end - key), key);
>  		}
>  	}
>  	*data = end + 1; /* skip the last trailing \n of \n\n sequence */
> 

Re: [Tarantool-patches] [PATCH v2 09/10] wal: fix say_x format

[Vladislav Shpilevoy via Tarantool-patches]

Thanks for the patch!

On 24.02.2021 16:36, Cyrill Gorcunov via Tarantool-patches wrote:
>  - vclock_get returns int64_t
>  - vclock_sum returns int64_t
> 
> Part-of #5846
> 
> Signed-off-by: Cyrill Gorcunov <gorcunov@gmail.com>
> ---
>  src/box/wal.c | 15 ++++++++-------
>  1 file changed, 8 insertions(+), 7 deletions(-)
> 
> diff --git a/src/box/wal.c b/src/box/wal.c
> index 937d47ba9..1c0076f26 100644
> --- a/src/box/wal.c
> +++ b/src/box/wal.c
> @@ -993,13 +993,14 @@ wal_assign_lsn(struct vclock *vclock_diff, struct vclock *base,
>  			int64_t diff = (*row)->lsn - vclock_get(base, (*row)->replica_id);
>  			if (diff <= vclock_get(vclock_diff,
>  					       (*row)->replica_id)) {
> +				int64_t confirmed_lsn =
> +					vclock_get(base, (*row)->replica_id) +
> +					vclock_get(vclock_diff, (*row)->replica_id);
>  				say_crit("Attempt to write a broken LSN to WAL:"
> -					 " replica id: %d, confirmed lsn: %d,"
> -					 " new lsn %d", (*row)->replica_id,
> -					 vclock_get(base, (*row)->replica_id) +
> -					 vclock_get(vclock_diff,
> -						    (*row)->replica_id),
> -						    (*row)->lsn);
> +					 " replica id: %d, confirmed lsn: %lld,"

`replica_id` is uint32_t. So it should be %u and cast to (unsigned) I suppose.

> +					 " new lsn %lld", (*row)->replica_id,
> +					 (long long)confirmed_lsn,
> +					 (long long)(*row)->lsn);
>  				assert(false);
>  			} else {
>  				vclock_follow(vclock_diff, (*row)->replica_id, diff);
> @@ -1241,7 +1242,7 @@ wal_write_async(struct journal *journal, struct journal_entry *entry)
>  		 */
>  		say_error("Aborting transaction %llu during "
>  			  "cascading rollback",
> -			  vclock_sum(&writer->vclock));
> +			  (long long)vclock_sum(&writer->vclock));

Long long should use %lld, not %llu. I have no idea why is the format checker
silent about this.

Re: [Tarantool-patches] [PATCH v2 10/10] say: fix CFORMAT specification

[Vladislav Shpilevoy via Tarantool-patches]

Thanks for the patch!

On 24.02.2021 16:36, Cyrill Gorcunov via Tarantool-patches wrote:
> The position of first argument to check from is 6, not 0.
> Looks like our tests with CFORMAT was simply not working
> since commit 7d12d66e67a1ce843a2712980f4d3ba04bc0d4f2.

Please, add the commit title here in braces like we usually do
when reference old commits.

Re: [Tarantool-patches] [PATCH v2 06/10] box/vynil: fix say_x format

[Vladislav Shpilevoy via Tarantool-patches]

Thanks for the patch!

This bug could actually lead to a crash. Because the printer would
try to read memory by a not passed string pointer.

Nikita, does it look related to any of the crashes we have in vinyl?

On 24.02.2021 16:36, Cyrill Gorcunov wrote:
> Drop redundant "%s" from format.
> 
> Part-of #5846
> 
> Signed-off-by: Cyrill Gorcunov <gorcunov@gmail.com>
> ---
>  src/box/vy_scheduler.c | 2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
> 
> diff --git a/src/box/vy_scheduler.c b/src/box/vy_scheduler.c
> index b641dd9b8..6f6e9c340 100644
> --- a/src/box/vy_scheduler.c
> +++ b/src/box/vy_scheduler.c
> @@ -1714,7 +1714,7 @@ vy_task_compaction_new(struct vy_scheduler *scheduler, struct vy_worker *worker,
>  	vy_task_delete(task);
>  err_task:
>  	diag_log();
> -	say_error("%s: could not start compacting range %s: %s",
> +	say_error("%s: could not start compacting range %s",
>  		  vy_lsm_name(lsm), vy_range_str(range));
>  	return -1;
>  }
> 

Re: [Tarantool-patches] [PATCH v2 02/10] popen: fix say_x format arguments

[Cyrill Gorcunov via Tarantool-patches]

On Wed, Feb 24, 2021 at 11:39:39PM +0100, Vladislav Shpilevoy wrote:
> Hi! Thanks for the patch!
> 
> On 24.02.2021 16:36, Cyrill Gorcunov wrote:
> > Drop redundant "%s" from format.
> 
> Neither of the changes below are about dropping a redundant %s.
> First one drops %p, second one replaces it with %d and fixes
> size_t.

Sigh, sorry. This slipped in from series reordering. Thanks for catching!

Re: [Tarantool-patches] [PATCH v2 03/10] raft: fix say_x arguments

[Cyrill Gorcunov via Tarantool-patches]

On Wed, Feb 24, 2021 at 11:39:47PM +0100, Vladislav Shpilevoy wrote:
> Thanks for the patch!
> 
> On 24.02.2021 16:36, Cyrill Gorcunov wrote:
> > Use explicit "%lld" for int64_t type.
> 
> In the changes you use %llu in both cases.

Good catch! Thanks.

> > @@ -322,7 +322,8 @@ raft_process_msg(struct raft *raft, const struct raft_msg *req, uint32_t source)
> >  	/* Outdated request. */
> >  	if (req->term < raft->volatile_term) {
> >  		say_info("RAFT: the message is ignored due to outdated term - "
> > -			 "current term is %u", raft->volatile_term);
> > +			 "current term is %llu",
> > +			 (long long)raft->volatile_term);
> 
> It is unsigned. So the cast must be 'unsigned long long'.
> The same below.

Atually this is done on a purpose. Signed/unsigned objects are kept
in same amount of memory storage, which is guaranteed by the standart.
We can use (long long) here to specify the size of object while
the sign gonna be interpreted by formatter itself, and this is
what our static formatter does test -- storage size. So no, I
think we can continue use (long long) specificator here.

Re: [Tarantool-patches] [PATCH v2 09/10] wal: fix say_x format

[Cyrill Gorcunov via Tarantool-patches]

On Wed, Feb 24, 2021 at 11:41:18PM +0100, Vladislav Shpilevoy wrote:
> >  		say_error("Aborting transaction %llu during "
> >  			  "cascading rollback",
> > -			  vclock_sum(&writer->vclock));
> > +			  (long long)vclock_sum(&writer->vclock));
> 
> Long long should use %lld, not %llu. I have no idea why is the format checker
> silent about this.

Because they are same in size and can be freely exchanged, io it is
up to you hot to interpret data inside formatter as signed or unsigned,
the cast must provide the _size_ of argument, not its sign.

Re: [Tarantool-patches] [PATCH v2 06/10] box/vynil: fix say_x format

[Nikita Pettik via Tarantool-patches]

On 24 Feb 23:43, Vladislav Shpilevoy wrote:
> Thanks for the patch!
> 
> This bug could actually lead to a crash. Because the printer would
> try to read memory by a not passed string pointer.
> 
> Nikita, does it look related to any of the crashes we have in vinyl?

No, it doesn't. Errors at compatin start are rather rare.
 
> On 24.02.2021 16:36, Cyrill Gorcunov wrote:
> > Drop redundant "%s" from format.
> > 
> > Part-of #5846
> > 
> > Signed-off-by: Cyrill Gorcunov <gorcunov@gmail.com>
> > ---
> >  src/box/vy_scheduler.c | 2 +-
> >  1 file changed, 1 insertion(+), 1 deletion(-)
> > 
> > diff --git a/src/box/vy_scheduler.c b/src/box/vy_scheduler.c
> > index b641dd9b8..6f6e9c340 100644
> > --- a/src/box/vy_scheduler.c
> > +++ b/src/box/vy_scheduler.c
> > @@ -1714,7 +1714,7 @@ vy_task_compaction_new(struct vy_scheduler *scheduler, struct vy_worker *worker,
> >  	vy_task_delete(task);
> >  err_task:
> >  	diag_log();
> > -	say_error("%s: could not start compacting range %s: %s",
> > +	say_error("%s: could not start compacting range %s",
> >  		  vy_lsm_name(lsm), vy_range_str(range));
> >  	return -1;
> >  }
> >