Bug 583075

This sounds similar to bug 531353 which appended command output to `backtick` command output.

Another reproducer method:

1. echo "echo running test script" >/tmp/test.csh
2. mv ~/.history ~/.history.ORIG
3. echo "This is the history file" > ~/.history
4. tcsh -v /tmp/test.csh
5. mv ~/.history.ORIG ~/.history

Actual results:
$ tcsh -v /tmp/test.csh
echo running test script
running test script
This is the history file                   <--- this shouldn't be here!

Expected results:
$ tcsh -v /tmp/test.csh
echo running test script
running test script

The reason this appears to be a new bug in RHEL 5 and newer is because this line was added to /etc/csh.cshrc:
   set savehist = (1024 merge)

If you add that line to /etc/csh.cshrc on RHEL 4, the bug can be reproduced there as well.

I wonder if tcsh is trying to do history expansion when it ends the end-of-file character.  You can reproduce the bug with a 0 byte file:

$ cat /dev/null > /tmp/eof.csh
$ ls -l /tmp/eof.csh
-rw-rw-r--  1 user group 0 Apr 16 15:51 /tmp/eof.csh
$ tcsh -v /tmp/eof.csh

This is the history file

The first problem I see is that 1024 should be less or equal to the value of history variable (which is by default 100), but fixing that doesn't help.

Quick workaround of the problem is changing
set savehist = (1024 merge)
to
set savehist
in /etc/csh.cshrc.

With a bit of experimentation, I was able to get a backtrace using gdb just before it writes a line of history out to the terminal.

First I created this set of batch commands for gdb (this was the experimentation part) and saved them in gdb.cmds
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
b xprintf
run -v /tmp/eof.csh
c 3
b doprnt
c
b flush
c
n 8
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

Next, run tcsh through gdb:
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
$ cat /dev/null >/tmp/eof.csh
$ echo "my tcsh history" >~/.history
$ gdb -x gdb.cmds /bin/tcsh
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

gdb breaks just before the write() syscall:
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
259         if (write(unit, linbuf, sz) == -1)
(gdb) p unit
$1 = 18
(gdb) n
my tcsh history
301         linp = linbuf;
(gdb) bt
#0  flush () at sh.print.c:301
#1  0x000000000043d3b3 in doprnt (addchar=0x41c5b0 <xputchar>, 
    sfmt=<value optimized out>, ap=0x7fffffff4ed0) at tc.printf.c:264
#2  0x000000000043db43 in xprintf (fmt=0x6b15e0 "my tcsh history\n")
    at tc.printf.c:377
#3  0x0000000000418d4f in prlex (sp0=0x673b80) at sh.lex.c:245
#4  0x0000000000403a91 in process (catch=0) at sh.c:2102
#5  0x000000000040470c in srcunit (unit=6, onlyown=<value optimized out>, 
    hflg=2, av=0x8743d0) at sh.c:1724
#6  0x0000000000404932 in srcfile (f=<value optimized out>, onlyown=0, flag=2, 
    av=0x8743d0) at sh.c:1494
#7  0x0000000000404a43 in dosource (t=0x8743d0, c=<value optimized out>)
    at sh.c:2233
#8  0x000000000041674c in rechist (fname=0x0, ref=<value optimized out>)
    at sh.hist.c:450
#9  0x0000000000405fda in main (argc=<value optimized out>, 
    argv=0x7fffffffc778) at sh.c:1381
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~


Notice the 'unit', or file descriptor, is 18.  This matches an strace on tcsh:
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
$ strace -e trace=file -e trace=desc -o /tmp/tcsh.strace tcsh -v /tmp/eof.csh
my tcsh history

$ cat /tmp/tcsh.strace
...
dup2(2, 18)                             = 18
...
write(18, "\n", 1)                      = 1
write(18, "my tcsh history\n", 16)      = 16
...
open("/home/jbastian/.history", O_WRONLY|O_CREAT|O_TRUNC|O_LARGEFILE, 0600) = 0
write(0, "#+1273068294\n", 13)          = 13
write(0, "my tcsh history\n", 16)       = 16
close(0)                                = 0 
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

Created attachment 411763 [details]
patch to not print history

I think I see the problem.                                                      

When savehist has the 'merge' keyword in it, rechist() calls loadhist():
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
    if ((shist = adrof(STRsavehist)) != NULL && shist->vec != NULL)
        if (shist->vec[1] && eq(shist->vec[1], STRmerge))
            loadhist(fname, 1);
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

loadhist() just calls dosource() like it was an interactive shell.

Continuing up the stack through srcfile() and srcunit() and process() we get to this:
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
    /*
     * Echo not only on VERBOSE, but also with history expansion. If there
     * is a lexical error then we forego history echo.
     */
    if ((lex(&paraml) && !seterr && intty && !tellwhat && !Expand &&
         !whyles) || adrof(STRverbose)) {
        int odidfds = didfds;
        haderr = 1;
        didfds = 0;
        prlex(&paraml);
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~


And prlex() goes on to print to stderr the line of the history file being processed.


My solution was to just unset STRverbose when recording the history at the end of main().  See the attached patch.  Maybe it would be better, though, to save the STRverbose state and restore it after the record() call?

This is still a problem with tcsh-6.17 so I've been discussing it upstream at
  http://mx.gw.com/pipermail/tcsh-bugs/2010-May/000667.html

This request was evaluated by Red Hat Product Management for
inclusion in the current release of Red Hat Enterprise Linux.
Because the affected component is not scheduled to be updated in the
current release, Red Hat is unfortunately unable to address this
request at this time. Red Hat invites you to ask your support
representative to propose this request, if appropriate and relevant,
in the next release of Red Hat Enterprise Linux.

This request was evaluated by Red Hat Product Management for
inclusion in the current release of Red Hat Enterprise Linux.
Because the affected component is not scheduled to be updated in the
current release, Red Hat is unfortunately unable to address this
request at this time. Red Hat invites you to ask your support
representative to propose this request, if appropriate and relevant,
in the next release of Red Hat Enterprise Linux.

This request was erroneously denied for the current release of
Red Hat Enterprise Linux.  The error has been fixed and this
request has been re-proposed for the current release.

Created attachment 475409 [details]
Do not print history on verbose (patch v2)

Added if statement to the previous version of the patch.
- Fix error message on exit "verbose: Undefined variable."

Created attachment 475790 [details]
Do not print history on verbose (upstream patch)

Prevents printing also on `history -S`.

*** This bug has been marked as a duplicate of bug 688173 ***