[PATCH] EXTENDED_HISTORY documentation typo

[PATCH] EXTENDED_HISTORY documentation typo

[Simon Ruderich]

[-- Attachment #1: Type: text/plain, Size: 1056 bytes --]

Hi,

There is a minor typo in the documentation of EXTENDED_HISTORY.
According to Src/hist.c the following syntax is used for
EXTENDED_HISTORY:

    ret = fprintf(out, ": %ld:%ld;", (long)he->stim,

But the documentation says this:

    :<beginning time>:<elapsed seconds>:<command>

So the last : must be a ; and there is a space after the first :
(or the source code is wrong).

diff --git a/Doc/Zsh/options.yo b/Doc/Zsh/options.yo
index 003071a..e9c8ff9 100644
--- a/Doc/Zsh/options.yo
+++ b/Doc/Zsh/options.yo
@@ -746,7 +746,7 @@ Save each command's beginning timestamp (in seconds since the epoch)
 and the duration (in seconds) to the history file.  The format of
 this prefixed data is:

-`tt(:)var(<beginning time>)tt(:)var(<elapsed seconds>)tt(:)var(<command>)'.
+`tt(:) var(<beginning time>)tt(:)var(<elapsed seconds>)tt(;)var(<command>)'.
 )
 pindex(HIST_ALLOW_CLOBBER)
 pindex(NO_HIST_ALLOW_CLOBBER)

Thanks,
Simon
-- 
+ privacy is necessary
+ using gnupg http://gnupg.org
+ public key id: 0x92FEFDB7E44C32F9

[-- Attachment #2: Type: application/pgp-signature, Size: 835 bytes --]

Re: [PATCH] EXTENDED_HISTORY documentation typo

[Mikael Magnusson]

On 29 March 2010 01:59, Simon Ruderich <simon@ruderich.org> wrote:
> Hi,
>
> There is a minor typo in the documentation of EXTENDED_HISTORY.
> According to Src/hist.c the following syntax is used for
> EXTENDED_HISTORY:
>
>    ret = fprintf(out, ": %ld:%ld;", (long)he->stim,
>
> But the documentation says this:
>
>    :<beginning time>:<elapsed seconds>:<command>

When I enable extendedhistory and run a command for a few seconds (in
the foreground), the <elapsed seconds> field is always 0.

-- 
Mikael Magnusson

Re: [PATCH] EXTENDED_HISTORY documentation typo

[Bart Schaefer]

On Oct 27,  3:51pm, Mikael Magnusson wrote:
}
} When I enable extendedhistory and run a command for a few seconds (in
} the foreground), the <elapsed seconds> field is always 0.

Hrm.

torch% history -dD
    1  08:09  0:00  setopt extendedhistory
    2  08:12  0:30  sleep 30
torch% SAVEHIST=50
torch% fc -W /tmp/ehist
torch% cat /tmp/ehist
: 1319728176:0;setopt extendedhistory
: 1319728336:30;sleep 30
: 1319729722:0;history -dD
: 1319729869:0;SAVEHIST=50

(Timestamps are a bit far apart because I was distracted by phone call
while doing this).

Here's a thing ... if you're using a zshaddhistory hook to store lines
to the history with "print -s" or "print -S", the start time of the
command is lost and consequently so is the elapsed time; print forces
the start and end times of the entry it writes to both be the time of
the call to print.

There may be a similar issue with HIST_IGNORE_ALL_DUPS in that the times
for the oldest duplicate are kept, whereas HIST_EXPIRE_DUPS_FIRST keeps
those of the most recent duplicate.

Re: [PATCH] EXTENDED_HISTORY documentation typo

[Mikael Magnusson]

On 27 October 2011 17:57, Bart Schaefer <schaefer@brasslantern.com> wrote:
> On Oct 27,  3:51pm, Mikael Magnusson wrote:
> }
> } When I enable extendedhistory and run a command for a few seconds (in
> } the foreground), the <elapsed seconds> field is always 0.
>
> Hrm.
>
> torch% history -dD
>    1  08:09  0:00  setopt extendedhistory
>    2  08:12  0:30  sleep 30
> torch% SAVEHIST=50
> torch% fc -W /tmp/ehist
> torch% cat /tmp/ehist
> : 1319728176:0;setopt extendedhistory
> : 1319728336:30;sleep 30
> : 1319729722:0;history -dD
> : 1319729869:0;SAVEHIST=50
>
> (Timestamps are a bit far apart because I was distracted by phone call
> while doing this).
>
> Here's a thing ... if you're using a zshaddhistory hook to store lines
> to the history with "print -s" or "print -S", the start time of the
> command is lost and consequently so is the elapsed time; print forces
> the start and end times of the entry it writes to both be the time of
> the call to print.
>
> There may be a similar issue with HIST_IGNORE_ALL_DUPS in that the times
> for the oldest duplicate are kept, whereas HIST_EXPIRE_DUPS_FIRST keeps
> those of the most recent duplicate.

Ah, i have none of those set though, and i don't use a zshaddhistory
hook... This is a zsh -f session:

% cat /tmp/test
HISTFILE=/tmp/test
HISTSIZE=50
SAVEHIST=50
setopt incappendhist
setopt incappendhistory
cat /tmp/test
setopt extendedhistory
: 1319731616:0;cat /tmp/test
: 1319731618:0;sleep 5
: 1319731624:0;cat /tmp/test

% history -dD
    1  18:06  0:00  HISTFILE=/tmp/test
    2  18:06  0:00  HISTSIZE=50
    3  18:06  0:00  SAVEHIST=50
    4  18:06  0:00  setopt incappendhist
    5  18:06  0:00  setopt incappendhistory
    6  18:06  0:00  cat /tmp/test
    7  18:06  0:00  setopt extendedhistory
    8  18:06  0:00  cat /tmp/test
    9  18:06  0:05  sleep 5
   10  18:07  0:00  cat /tmp/test

At first i thought maybe it's one of my local patches, but i get the
same result on a remote host running 4.3.10.

-- 
Mikael Magnusson

Re: [PATCH] EXTENDED_HISTORY documentation typo

[Bart Schaefer]

On Oct 27,  6:12pm, Mikael Magnusson wrote:
} Subject: Re: [PATCH] EXTENDED_HISTORY documentation typo
}
} % history -dD
}     1  18:06  0:00  HISTFILE=/tmp/test
}     2  18:06  0:00  HISTSIZE=50
}     3  18:06  0:00  SAVEHIST=50
}     4  18:06  0:00  setopt incappendhist
}     5  18:06  0:00  setopt incappendhistory
}     6  18:06  0:00  cat /tmp/test
}     7  18:06  0:00  setopt extendedhistory
}     8  18:06  0:00  cat /tmp/test
}     9  18:06  0:05  sleep 5
}    10  18:07  0:00  cat /tmp/test
} 
} At first i thought maybe it's one of my local patches, but i get the
} same result on a remote host running 4.3.10.

This is exactly what I'd expect.  Zsh doesn't even bother storing the
time delta if extended history isn't set.  Hence you get the delta
at event 9 after having set the option at event 7.

There isn't a HIST_REVISIONIST option. :-)

-- 
Barton E. Schaefer

Re: [PATCH] EXTENDED_HISTORY documentation typo

[Mikael Magnusson]

On 27 October 2011 20:50, Bart Schaefer <schaefer@brasslantern.com> wrote:
> On Oct 27,  6:12pm, Mikael Magnusson wrote:
> } Subject: Re: [PATCH] EXTENDED_HISTORY documentation typo
> }
> } % history -dD
> }     1  18:06  0:00  HISTFILE=/tmp/test
> }     2  18:06  0:00  HISTSIZE=50
> }     3  18:06  0:00  SAVEHIST=50
> }     4  18:06  0:00  setopt incappendhist
> }     5  18:06  0:00  setopt incappendhistory
> }     6  18:06  0:00  cat /tmp/test
> }     7  18:06  0:00  setopt extendedhistory
> }     8  18:06  0:00  cat /tmp/test
> }     9  18:06  0:05  sleep 5
> }    10  18:07  0:00  cat /tmp/test
> }
> } At first i thought maybe it's one of my local patches, but i get the
> } same result on a remote host running 4.3.10.
>
> This is exactly what I'd expect.  Zsh doesn't even bother storing the
> time delta if extended history isn't set.  Hence you get the delta
> at event 9 after having set the option at event 7.
>
> There isn't a HIST_REVISIONIST option. :-)

Hm? I ran the sleep after I did setopt extendedhistory. Note also that
the time delta 0:05 is output by history -dD but isn't stored in the
history file. You didn't quote the histfile excerpt:

setopt extendedhistory
: 1319731616:0;cat /tmp/test
: 1319731618:0;sleep 5
: 1319731624:0;cat /tmp/test


-- 
Mikael Magnusson

Re: [PATCH] EXTENDED_HISTORY documentation typo

[Bart Schaefer]

On Oct 27,  9:13pm, Mikael Magnusson wrote:
} Subject: Re: [PATCH] EXTENDED_HISTORY documentation typo
}
} On 27 October 2011 20:50, Bart Schaefer <schaefer@brasslantern.com> wrote:
} > On Oct 27,  6:12pm, Mikael Magnusson wrote:
} > }
} > }     5  18:06  0:00  setopt incappendhistory
} > }     6  18:06  0:00  cat /tmp/test
} > }     7  18:06  0:00  setopt extendedhistory
} > }     8  18:06  0:00  cat /tmp/test
} > }     9  18:06  0:05  sleep 5
} > }    10  18:07  0:00  cat /tmp/test
} 
} Hm? I ran the sleep after I did setopt extendedhistory. Note also that
} the time delta 0:05 is output by history -dD but isn't stored in the
} history file. You didn't quote the histfile excerpt:
} 
} setopt extendedhistory
} : 1319731616:0;cat /tmp/test
} : 1319731618:0;sleep 5
} : 1319731624:0;cat /tmp/test

Ah, I see.  You've found a conflicting feature -- I can't call it a bug
-- with INC_APPEND_HISTORY (which will also affect SHARE_HISTORY).

The history entry is written out in hend() as soon as the command
line is accepted for execution, but the elapsed time isn't (clearly
cannot be) recorded until the call to hbegin() after the command has
finished.  The HISTFILE is never re-written when it's being appended
on the fly, so there is no opportunity for the elapsed time to be
updated.

Particularly with respect to SHARE_HISTORY there's really no way to
fix this -- to be useful, the history has to be shared before the
elapsed time is known.  Since SHARE and INC_APPEND are handled in
the same code, I'm reluctant to suggest that we attempt to change
this behavior.

The same thing happens when the shell exits because of an "exec":
There's no hbegin() call after that final command, so the elapsed
time is never logged.

: 1319811645:3;sleep 3
: 1319811651:0;exec sleep 9

This should at least be documented.  In fact it's even slightly
worse (?) than what I just described -- if the file happens to be
locked at the instant the append is attempted, zsh simply skips
the operation for speed/responsiveness and writes all entries after
the *next* command finishes (or the shell exits).  In that case the
duration of any command whose write was postponed will in fact be
recorded.  The upshot is that the elapsed time is unreliable if the
INC_APPEND_HISTORY or SHARE_HISTORY options are set.

(I was wrong about order dependence on setopt extendedhistory; the
shell DOES record the elapsed time even when not saving it.  I'm
surprised no one corrected me on that.)

There's one further thing pursuant to another thread:  If you setopt
INC_APPEND_HISTORY, then the history file does get updated on the
fly even though NO_RCS may prevent it being written at shell exit.
There are, obviously, an incredible number of these obscure setopt
interactions that it's very difficult to track and document.