Shell code appears before "Advanced Shell History enabled: session ..."

[MaienM]

I use ZSH. I have put the following code in my zshrc:

source /usr/local/etc/advanced-shell-history/config
export ASH_CFG_SYSTEM_QUERY_FILE
source /usr/local/lib/advanced_shell_history/sh/zsh

When I start zsh, the following appears above my prompt.

__ash_end_session () {
        [[ "${ASH:-0}" == "0" ]] && __ash_info __ash_end_session && return
        __ash_log "${@}"
        ${ASH_LOG_BIN} --end_session --exit ${1}
}
__ash_log () {
        [[ "${ASH:-0}" == "0" ]] && __ash_info __ash_log && return
        if [[ "${ASH_SKIP:-1}" == "1" ]]
        then
                ASH_SKIP=0
                return
        fi
        local no start end cmd rval="${1}"  && shift
        read -r no start end cmd <<< "$( __ash_last_command )"
        local pipes="$( sed -e 's: :_:g' <<< "${@}" )"
        ${ASH_LOG_BIN} -e ${rval:-0} -s ${start:-0} -f ${end:-0} -n ${no:-0} -p "${pipes:-0}" -c "${cmd:-UNKNOWN}"
}
Advanced Shell History enabled: session 7

I had only expected the last line, not the two function definitions. I noticed the reporter of #8 had the same, but it seemed unrelated to their issue.

(Seemingly) relevant environment variables:

ASH_CFG=/usr/local/etc/advanced-shell-history/config
ASH_CFG_DB_FAIL_RANDOM_TIMEOUT=4
ASH_CFG_DB_FAIL_TIMEOUT=2
ASH_CFG_DB_MAX_RETRIES=30
ASH_CFG_DEFAULT_FORMAT=auto
ASH_CFG_HIDE_USAGE_FOR_NO_ARGS=false
ASH_CFG_HISTORY_DB=/home/maienm/.ash/history.db
ASH_CFG_LIB=/usr/local/lib/advanced_shell_history/sh
ASH_CFG_LOG_DATE_FMT='%Y-%m-%d %H:%M:%S %Z: '
ASH_CFG_LOG_FILE=/home/maienm/.ash/ash.log
ASH_CFG_LOG_IPV4=true
ASH_CFG_LOG_IPV6=true
ASH_CFG_LOG_LEVEL=WARNING
ASH_CFG_MOTD='Advanced Shell History enabled: '
ASH_CFG_SKIP_LOOPBACK=true
ASH_CFG_SYSTEM_QUERY_FILE=/usr/local/etc/advanced-shell-history/queries
ASH_LOG_BIN=/usr/local/bin/_ash_log
ASH_SESSION_ID=7
ASH_SKIP=0
HISTFILE=/home/maienm/.zhistory
HISTSIZE=10000
SAVEHIST=10000

zsh version: 5.6.2 (x86_64-pc-linux-gnu)
ash commit: 3a9b1fc2fcbe57496a70ec062cc0a4fdb1bb2ad5

[xkortex]

I'm seeing the same shell-barf. Ubuntu 18.04, zsh 5.4.2. Installed the c version.

It only seems to happen the first time source /usr/local/lib/advanced_shell_history/sh/zsh is run, subsequent calls to it in the same shell are clean (but also don't display the session # line, either).

I ran shellcheck on sh/zsh and it flagged a bunch of lines, but this line stuck out to me:

In zsh line 99:
      ASH=1 __ash_log ${pipest_ash[@]}
                      ^-- SC2068: Double quote array expansions to avoid re-splitting elements.

I wish my bash-fu were better to provide some more insight, but alas. However here's an interesting anecdote which might shed some light. In my .zshrc I had a function definition

function colors() {
    for i in {0..255} ; do 
          printf "\x1b[38;5;${i}m%3d " "${i}"
    done
}

which just prints the ANSII shell colors and their number, and whenever I would source ~/.zshrc, it would run that function and dump the output to the shell, but NOT when starting zsh normally. I changed the name to colorsz() and lo and behold, problem goes away. This makes me think, hm maybe it's happening when precmd() is getting called.

... okay that was a dead end, but I think I tracked it down to sourcing of the common script.

I modified sh/common by removing the readonly lines as such:

# Protect the functions.
#readonly -f __ash_end_session
#readonly -f __ash_log

and boom, the problem is gone. Personally, I don't care about the possibility of accidentally running the dunder functions, so I plan on just leaving it commented out.

Oh, and ash_query -Q gives me FAILED TO FIND A FILE TO PARSE!, despite all of the requisite ASH_CFG variables being set.

➜  ~ env | grep ASH
ASH_CFG_SYSTEM_QUERY_FILE=/usr/local/etc/advanced-shell-history/queries
ASH_CFG_LIB=/usr/local/lib/advanced_shell_history/sh
ASH_CFG_HIDE_USAGE_FOR_NO_ARGS=false
ASH_CFG_MOTD=Advanced Shell History enabled: 
ASH_CFG_LOG_FILE=/home/mike/.ash/ash.log
ASH_CFG_LOG_LEVEL=WARNING
ASH_CFG_LOG_DATE_FMT=%Y-%m-%d %H:%M:%S %Z: 
ASH_CFG_DEFAULT_FORMAT=auto
ASH_CFG_HISTORY_DB=/home/mike/.ash/history.db
ASH_CFG_DB_MAX_RETRIES=30
ASH_CFG_DB_FAIL_TIMEOUT=2
ASH_CFG_DB_FAIL_RANDOM_TIMEOUT=4
ASH_CFG_SKIP_LOOPBACK=true
ASH_CFG_LOG_IPV4=true
ASH_CFG_LOG_IPV6=true
ASH_SKIP=0
ASH_SESSION_ID=26

[MaienM]

For what it's worth, shellcheck does not support zsh. This doesn't mean all advice will be useless, as plenty of zsh's behavior is POSIX compliant, but it's good to keep in mind.

I have/had the same problem with ash_query. I don't remember whether I resolved it or not, to be honest. I don't currently have the system I attempted this on available, but I will in a few days, and I'll check then. I will also try and see if commenting these lines resolves the problem for me.

[xkortex]

Yeah, I know shellcheck does not support zsh, but I try to write bash- or sh-compliant scripts regardless as sometimes I need to port them to systems without zsh.