Unexpected fmt::print flush behavior

[tupaschoal]

(Opening this on behalf of @brenoguim who did all the heavy lifting of creating a reduced test)

We're seeing an issue when using fmt::print on Ubuntu 14.04 that does not happen on equivalent CentOS/RHEL, here's the snippet:

#include <cassert>
#include <fcntl.h>
#include <fmt/core.h>

int main()
{
    auto name  = "/tmp/some_file";
    // Remove old file and create new one
    system(fmt::format("rm {}", name).c_str());
    system(fmt::format("touch {}", name).c_str());

    // Open file descriptor
    int fd = open(name, O_WRONLY | O_RDONLY);
    assert(fd != -1);

    // Associate FILE with file descriptor
    auto file = fdopen(fd, "w");
    assert(file);

    // Write a lot of data
    for (int i = 0; i < 20001; ++i)
    {
        fmt::print(file, "{}\n", i);   // this fails
        // fmt::println(file, "{}", i);       // this works
    }

    // Close and expect it to flush, so the last line should be 20000
    fclose(file);

    // Print last lines and show that last chunk of file is missing
    system(fmt::format("tail {}", name).c_str());
}

Basically, it should print up to 20000, but on Ubuntu it stops at 19600. A few things we know:

1. Started happening after upgrading from fmt 10.2.1 to 11.1.1
2. Still fails on fmt 11.1.4
3. Does not happen on later Ubuntu release (16, 18 and 20)
4. Changing to fmt::println fixes the issue, as shared in the snippet above.
5. Forcing the needs_flush to return true fixes the issue too

[localspook]

I believe this snippet is the culprit; the if condition is wrong:

fmt/include/fmt/format-inl.h

Lines 1528 to 1534 in b2dfcb2

	void init_buffer() {
	if (this->file_->_IO_write_ptr) return;
	// Force buffer initialization by placing and removing a char in a buffer.
	assume(this->file_->_IO_write_ptr >= this->file_->_IO_write_end);
	putc_unlocked(0, this->file_);
	--this->file_->_IO_write_ptr;
	}

One of the things that putc_unlocked does is set the _IO_CURRENTLY_PUTTING flag on the file, without which fclose will not flush it. putc_unlocked is just a wrapper around _IO_putc_unlocked:

__STDIO_INLINE int putc_unlocked (int __c, FILE *__stream) {
  return _IO_putc_unlocked (__c, __stream);
}

And _IO_putc_unlocked looks like this (cleaned up slightly):

#define _IO_putc_unlocked(_ch, _fp)             \
   _fp->_IO_write_ptr >= _fp->_IO_write_end     \
     ? __overflow(_fp, _ch)                     \
     : (*(_fp)->_IO_write_ptr++ = _ch)

That __overflow call is what specifically sets the _IO_CURRENTLY_PUTTING flag. Notice that _IO_putc_unlocked's and fmt's conditions for skipping it don't agree. Seeing as putc_unlocked already does this check, I think the best solution here is to simply remove ours:

 void init_buffer() { 
-  if (this->file_->_IO_write_ptr) return; 
   // Force buffer initialization by placing and removing a char in a buffer. 
-  assume(this->file_->_IO_write_ptr >= this->file_->_IO_write_end); 
   putc_unlocked(0, this->file_);  
   --this->file_->_IO_write_ptr; 
 }

[brenoguim]

@localspook thanks for the analysis. I searched glibc for places where buffers are initialized but IO_PUTTING is not set, and it happens with fseek.

So the following test seems fail with more OSes, making this issue more critical:

#include <cassert>
#include <fcntl.h>
#include <fmt/core.h>

int main()
{
    auto name  = "/tmp/some_file";
    // Remove old file and create new one
    system(fmt::format("rm {}", name).c_str());
    system(fmt::format("touch {}", name).c_str());

    // Open file
    FILE* file = fopen(name, "w");
    assert(file);

    // This initialize buffers but doesn't set IO_PUTTING
    fseek(file, 0, SEEK_SET);

    // Write a lot of data
    for (int i = 0; i < 20001; ++i)
    {
        fmt::print(file, "{}\n", i);   // this fails
        // fmt::println(file, "{}", i);       // this works
    }

    // Close and expect it to flush, so the last line should be 20000
    fclose(file);

    // Print last lines and show that last chunk of file is missing
    system(fmt::format("tail {}", name).c_str());
}

[tupaschoal]

I've edited the title to remove Ubuntu since Breno reproduced on other OSes

[vitaut]

Thanks for reporting and the repro. I fixed a small issue in the repro: replaced int fd with FILE* file.

[vitaut]

Fixed in 5199e0f. Thanks again @tupaschoal for reporting and @localspook and @brenoguim for investigating!

[tupaschoal]

Hi @vitaut do you have any timeline expectation of a minor release that would include this fix?

[vitaut]

I plan to (re)start putting together a new minor release once #4417 is fixed. Don't have a specific timeline, probably a couple of weeks.

[tupaschoal]

Great, thank you!

[vitaut]

New release that includes the fix among other things is available: https://github.com/fmtlib/fmt/releases/tag/11.2.0

[tupaschoal]

Thank you!