lnav re-emits piped input on quit

[aspiers]

If I run something like:

tail /var/log/messages | /usr/bin/lnav

then lnav receives and displays the piped input correctly, but when I hit q to quit, after lnav's UI vanishes the same log lines are also output again to the terminal. When the piped input is long (e.g. replacing the tail command with journalctl) then this becomes quite an inconvenience.

---

Want to back this issue? Post a bounty on it! We accept bounties via Bountysource.

[xapienz]

Hello,
I found that this is solved by argument -q.
For example:
tail /var/log/messages | /usr/bin/lnav -q

[grrosegr]

@xapienz thanks, that helps! However, now, it just hangs on quit (as if still processing stuff but just not printing it) until I hit ctrl+c

Is there a way to fix that? And shouldn't -q in this case be the default behavior? Who wants log spam?

[oryband]

I'm sorry but -q doesn't do the trick. Logs still get dumped into stdout after quitting lnav when piping. My scenario tries to pipe Docker Compose: docker-compose logs | lnav -q.

[tstack]

@oryband Can you provide a gif or something? I can't reproduce this...

[oryband]

@oryband Can you provide a gif or something? I can't reproduce this...

@tstack
There's not much to show - just that the log text shown in lnav gets printed to the screen after I close lnav when running docker-compose logs | lnav -q. If the log had 10K+ lines I have to wait quite some time for my prompt to be available again since it prints a huge amount of text on screen.

I have to mention -q does work in other cases e.g. using journalctl -xe | lnav -q. No idea why this doesn't work with docker-compose logs command.

[oryband]

Any news on this? Can anyone try piping docker-compose logs to lnav -q and see his result?

[oryband]

I take it back. This indeed works with latest lnav (0.8.3). I was using an older version on AWS Ubuntu 16.04.

Thanks for the help.

[aspiers]

I can confirm that -q addresses this. However @tstack Is there a good reason for having the default behaviour acting a bit like tee(1)? Effectively it's multiplexing the output of the pipe writer so that it goes both into lnav and to STDOUT, which is the opposite of the default behaviour in any other normal UNIX pipe situation.

IMHO it would be more intuitive if it didn't output to STDOUT on exit unless an option was specified.

[piotrlg]

I can confirm this also.
$ journalctl |./lnav
.... use lnav, quit and
all output from journalctl copied to console: unnecessary, annoying and bad behavior from UX point of view.
lnav should just quit silently like any other unix command line program which swallowed piped data.
P.

[aspiers]

@tstack Any thoughts on this?

I did some digging, and found that the -q option is activated here:

lnav/src/lnav.cc

Lines 1941 to 1943 in ffd9d88

	case 'q':
	lnav_data.ld_flags |= LNF_QUIET;
	break;

and used here:

lnav/src/lnav.cc

Lines 2478 to 2546 in ffd9d88

	if (!found_error &&
	!(lnav_data.ld_flags & LNF_QUIET) &&
	!lnav_data.ld_view_stack.vs_views.empty() &&
	!lnav_data.ld_stdout_used) {
	bool suppress_empty_lines = false;
	list_overlay_source *los;
	unsigned long view_index;
	vis_line_t y;
	tc = *lnav_data.ld_view_stack.top();
	view_index = tc - lnav_data.ld_views;
	switch (view_index) {
	case LNV_DB:
	case LNV_HISTOGRAM:
	suppress_empty_lines = true;
	break;
	default:
	break;
	}
	los = tc->get_overlay_source();
	vis_line_t vl;
	for (vl = tc->get_top();
	vl < tc->get_inner_height();
	++vl, ++y) {
	attr_line_t al;
	string &line = al.get_string();
	while (los != nullptr &&
	los->list_value_for_overlay(*tc, y, tc->get_inner_height(), vl, al)) {
	if (write(STDOUT_FILENO, line.c_str(),
	line.length()) == -1 ||
	write(STDOUT_FILENO, "\n", 1) == -1) {
	perror("1 write to STDOUT");
	}
	++y;
	}
	vector<attr_line_t> rows(1);
	tc->listview_value_for_rows(*tc, vl, rows);
	if (suppress_empty_lines && rows[0].empty()) {
	continue;
	}
	struct line_range lr = find_string_attr_range(
	rows[0].get_attrs(), &textview_curses::SA_ORIGINAL_LINE);
	if (write(STDOUT_FILENO, lr.substr(rows[0].get_string()),
	lr.sublen(rows[0].get_string())) == -1 ||
	write(STDOUT_FILENO, "\n", 1) == -1) {
	perror("2 write to STDOUT");
	}
	}
	{
	attr_line_t al;
	string &line = al.get_string();
	while (los != nullptr &&
	los->list_value_for_overlay(*tc, y, tc->get_inner_height(), vl, al) &&
	!al.empty()) {
	if (write(STDOUT_FILENO, line.c_str(),
	line.length()) == -1 ||
	write(STDOUT_FILENO, "\n", 1) == -1) {
	perror("1 write to STDOUT");
	}
	++y;
	}
	}
	}

and here when reading from stdin (the comment reveals some of the thinking behind this feature, which shows that it was deliberate):

lnav/src/lnav.cc

Lines 2589 to 2617 in ffd9d88

	// When reading from stdin, dump out the last couple hundred lines so
	// the user can have the text in their terminal history.
	if (stdin_out_fd != -1 &&
	!(lnav_data.ld_flags & LNF_QUIET) &&
	!(lnav_data.ld_flags & LNF_HEADLESS)) {
	struct stat st;
	fstat(stdin_out_fd, &st);
	auto file_iter = find_if(lnav_data.ld_files.begin(),
	lnav_data.ld_files.end(),
	same_file(st));
	if (file_iter != lnav_data.ld_files.end()) {
	logfile::iterator line_iter;
	auto lf = *file_iter;
	string str;
	for (line_iter = lf->begin();
	line_iter != lf->end();
	++line_iter) {
	lf->read_line(line_iter).then([](const auto &sbr) {
	if (write(STDOUT_FILENO, sbr.get_data(), sbr.length()) == -1 ||
	write(STDOUT_FILENO, "\n", 1) == -1) {
	perror("3 write to STDOUT");
	}
	});
	}
	}
	}

[aspiers]

Given the comment immediately above, it was deliberately implemented so presumably some people must like the current behaviour, but equally others who jumped on this issue report would prefer the -q behaviour to be the default. So clearly there is no single behaviour which pleases everyone. This suggests maybe the need for a configurable option. Although as previously noted, personally I think it would be more intuitive if the default behaviour was consistent with the rest of the UNIX world.

[tstack]

I implemented the behavior because I don't want to lose the output that was piped into lnav and I tend to be lazy about using the -w flag to save the output. For example, when analyzing the output of a build, I would pipe it into lnav with timestamps. The dump was nice to have when I wanted to go back after exiting. The commit changes the behavior to keep the temporary file used to store the stdin data and print a message saying where the file is so it can be reopened. That way, the user doesn't have to think ahead, can't mistakenly lose the data, and it's not so noisy anymore.

[aspiers]

@tstack Thanks, that's a great idea which works really well for the use case of analyzing the outputs of builds!

However I really don't think it makes sense for the journalctl | lnav use case, because that just results in filling up the filesystem with temporary files which duplicate data already stored by journald. And as I mentioned, it doesn't align with the standard behaviour of UNIX tools which accept input from a pipe.

Here's a crazy idea: how about teaching lnav to look at what's on the other end of the pipe (i.e. the writer) and then automatically adjust its behaviour accordingly? If it's some kind of compiler / make build, trigger the -w behaviour, otherwise just act like a normal pipe reader.

[tstack]

Here's a crazy idea: how about teaching lnav to look at what's on the other end of the pipe (i.e. the writer) and then automatically adjust its behaviour accordingly? If it's some kind of compiler / make build, trigger the -w behaviour, otherwise just act like a normal pipe reader.

I was looking at that so that I could save a note with the capture file to make it easier to where the data came from. But, I don't think there's a portable/reliable way to make that work.

However I really don't think it makes sense for the journalctl | lnav use case, because that just results in filling up the filesystem with temporary files which duplicate data already stored by journald.

The stdin data was already being saved to a file so that scrollback could be supported. Beyond that, disks are big, saving a copy of some text is not a huge deal. The capture files are removed if they're older than a day and they aren't saved if they're too big (10MB). I could also compress the captures to save even more space. So, I don't think this will be a problem in practice.

And as I mentioned, it doesn't align with the standard behaviour of UNIX tools which accept input from a pipe.

I would say the current behavior of piping data into less and losing it sucks. Having to think ahead and add a tee into the pipeline to save it also sucks. lnav is all about trying to do as much automatically as possible without getting in the way too much. The new behavior seems like a reasonable balance.