BUG: Zsh loses history entries since 2015

[Michael Stapelberg <stapelberg+zsh@xxxxxxxxxx>]

Hey Zsh contributors

After years of being plagued by mysteriously lost history entries,
I have finally tracked down one way to make Zsh lose history entries!

# Steps to reproduce

I tested the following steps on Ubuntu 24.04 under a newly created
UNIX user account with Zsh 5.9 (latest released version), and I have
also verified that the steps also trigger the issue with Zsh built
from Git (at commit 435cb1b, latest at the time of writing).

0. If you are starting from scratch, without any Zsh config,
   here is the minimal setup you need to reproduce this issue:

   for i in $(seq 50000); do echo "line $i" >> ~/.zsh_history; done
   echo HISTFILE=$HOME/.zsh_history > ~/.zshrc
   echo SAVEHIST=85000 >> ~/.zshrc

1. Apply the attached patch which adds zwarn() debug messages
   and nanosleep() calls to intentionally slow down history reading
   to give you enough time to trigger the issue. You might need to
   increase/decrease the nanosleep argument based on the number of
   lines in your history file to make it just fast/slow enough.
   Loading about 50000 lines takes about 5s on the machines I tested.

2. Make a backup of your ~/.zsh_history :-)

3. Start your patched zsh and exit it by pressing Ctrl+D (EOF).
   You should see the following log messages (the number 2 in my
   prompt indicates a subshell):

   ~/src/zsh-repro % ./Src/zsh
   zsh: readhistfile() start

   ~/src/zsh-repro 2 % wc -l ~/.zsh_history
   zsh: savehistfile() start
   55071 /home/stapelberg/.zsh_history

   ~/src/zsh-repro 2 % ^D
   zsh: savehistfile() start
   zsh: savehistfile() start
   zsh: readhistfile() start
   zsh: readhistfile() done
   zsh: readhistfile() returned, histlinect = 51291
   zsh: savehistfile() start
   zsh: renaming /home/stapelberg/.zsh_history.new to
/home/stapelberg/.zsh_history
   zsh: savehistfile() done
   zsh: savehistfile() done

   ~/src/zsh-repro % wc -l ~/.zsh_history
   55071 /home/stapelberg/.zsh_history

   So far, so good!

4. Start your patched zsh and exit it by pressing Ctrl+D (EOF),
   but press Ctrl+C (SIGINT) while readhistfile() is running:

   % wc -l ~/.zsh_history
   55075 /home/stapelberg/.zsh_history
   ~/src/zsh-repro % ./Src/zsh
   zsh: readhistfile() start
   ~/src/zsh-repro 2 % ^D
   zsh: savehistfile() start
   zsh: savehistfile() done
   zsh: savehistfile() start
   zsh: readhistfile() start
   ^C%
   ~/src/zsh-repro % echo $?
   0
   ~/src/zsh-repro % wc -l ~/.zsh_history
   12962 /home/stapelberg/.zsh_history

   Oh no! We just lost most of our history :-(

# Digging into the root cause

Looking at the Zsh source code, I see that commit f1c702f from March 2015
(https://github.com/zsh-users/zsh/commit/f1c702f, released in Zsh 5.4)
added the following lines of code to readhistfile():

   while (fpos += readbytes, readbytes = 0,
          (l = readhistline(0, &buf, &bufsiz, in, &readbytes))) {
     // …

     // newly added to break out of the line-reading loop:
     if (errflag & ERRFLAG_INT)
       break;
   }

The errflag gets set from the Zsh signal handler when receiving SIGINT:
https://github.com/zsh-users/zsh/blob/zsh-5.9/Src/signals.c#L675

Later, commit 0afe9dc from February 2019 introduced a new flag called
lasthist.interrupted to make reading the history safer on interrupt:
https://github.com/zsh-users/zsh/commit/0afe9dc

Fundamentally, I think the savehistfile() function, when called because
Zsh is exiting, is not handling an interrupted readhistfile() call correctly.

I would have attached a patch with a suggested fix, but I am not entirely sure
which way we should go: Would we want to gracefully handle an interrupted
readhistfile()? Should readhistfile() even be interruptible at all?

Thanks in advance for any extra details and/or fixes
Best regards
Michael

diff --git i/Src/hist.c w/Src/hist.c
index fa1ede3f0..b276e4836 100644
--- i/Src/hist.c
+++ w/Src/hist.c
@@ -2678,6 +2678,8 @@ readhistfile(char *fn, int err, int readflags)
     int nwordpos, nwords, bufsiz;
     int searching, newflags, l, ret, uselex, readbytes;
 
+    zwarn("readhistfile() start");
+
     if (!fn && !(fn = getsparam("HISTFILE")))
 	return;
     if (stat(unmeta(fn), &sb) < 0 ||
@@ -2838,6 +2840,9 @@ readhistfile(char *fn, int err, int readflags)
 	     */
 	    if (uselex || remeta)
 		freeheap();
+	    // Delay the history file reading to provide ample time
+	    // to press Ctrl+C (= send SIGINT).
+	    nanosleep((const struct timespec[]){{0, 10000L}}, NULL);
 	    if (errflag & ERRFLAG_INT) {
 		/* Can't assume fast read next time if interrupted. */
 		lasthist.interrupted = 1;
@@ -2860,6 +2865,8 @@ readhistfile(char *fn, int err, int readflags)
 
     if (zleactive)
 	zleentry(ZLE_CMD_SET_HIST_LINE, curhist);
+
+    zwarn("readhistfile() done");
 }
 
 #ifdef HAVE_FCNTL_H
@@ -2921,6 +2928,8 @@ savehistfile(char *fn, int err, int writeflags)
     int extended_history = isset(EXTENDEDHISTORY);
     int ret;
 
+    zwarn("savehistfile() start");
+
     if (!interact || savehistsiz <= 0 || !hist_ring
      || (!fn && !(fn = getsparam("HISTFILE"))))
 	return;
@@ -3080,6 +3089,7 @@ savehistfile(char *fn, int err, int writeflags)
 	    ret = -1;
 	if (ret >= 0) {
 	    if (tmpfile) {
+		zwarn("renaming %s to %s", tmpfile, unmeta(fn));
 		if (rename(tmpfile, unmeta(fn)) < 0) {
 		    zerr("can't rename %s.new to $HISTFILE", fn);
 		    ret = -1;
@@ -3107,6 +3117,7 @@ savehistfile(char *fn, int err, int writeflags)
 
 		hist_ignore_all_dups |= isset(HISTSAVENODUPS);
 		readhistfile(fn, err, 0);
+		zwarn("readhistfile() returned, histlinect = %d", histlinect);
 		hist_ignore_all_dups = isset(HISTIGNOREALLDUPS);
 		if (histlinect)
 		    savehistfile(fn, err, 0);
@@ -3130,6 +3141,7 @@ savehistfile(char *fn, int err, int writeflags)
 	free(tmpfile);
 
     unlockhistfile(fn);
+    zwarn("savehistfile() done");
 }
 
 static int lockhistct;