I have been doing a lot more bash on LINUX RedHat and Ubuntu lately, and one thing keeps cropping up intermittently. If I do a $( some-commands ) Command Substitution, the some-commands are logged onto my screen each time they are evaluated. Did I turn on some odd option? It seems to happen just some times.
Not sure what you mean by logging. There's a few different things I can think of; maybe you did set -x, or maybe you put commands in the background and are seeing when they return.
Could you copy-paste exactly what it shows you?
If set -x was on, there would be logging all over and as I recall it also does not log sub-shells.
$ for p in 9330 9329 9328 9327 9326 9314
do
ect=$( cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load' )
echo "show processlist;
set global max_connections=5;
show global variables like 'max_connections';"
kill -9 $p
while [ $ect = $( cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load' ) ]
do
sleep 5
done
echo "set global max_connections=151;
show global variables like 'max_connections';"
ect2=0
while [ $ect2 != $ect ]
do
ect2=$ect
sleep 5
ect=$( cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load' )
done
done | mysql -n -uxxxuser -pxxxpass xxx_db ; psm 9311
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
Id User Host db Command Time State Info
41421 c64confuser arges9.xmen.eti:45334 host_sw_db Connect 1151 Reading from net NULL
41423 c64confuser arges9.xmen.eti:45336 host_sw_db Connect 1151 Reading from net NULL
41424 c64confuser arges9.xmen.eti:45337 host_sw_db Sleep 1151 NULL
41428 c64confuser arges9.xmen.eti:45343 host_sw_db Sleep 1 NULL
41434 c64confuser arges9.xmen.eti:45350 host_sw_db Sleep 245 NULL
41437 c64confuser arges9.xmen.eti:45353 host_sw_db Sleep 1151 NULL
41439 c64confuser arges9.xmen.eti:45355 host_sw_db Sleep 0 NULL
41440 c64confuser localhost host_sw_db Query 0 NULL show processlist
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
Variable_name Value
max_connections 5
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
Variable_name Value
max_connections 151
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
Id User Host db Command Time State Info
41421 c64confuser arges9.xmen.eti:45334 host_sw_db Connect 1234 Reading from net NULL
41423 c64confuser arges9.xmen.eti:45336 host_sw_db Connect 1234 Reading from net NULL
41424 c64confuser arges9.xmen.eti:45337 host_sw_db Sleep 1234 NULL
41428 c64confuser arges9.xmen.eti:45343 host_sw_db Sleep 0 NULL
41437 c64confuser arges9.xmen.eti:45353 host_sw_db Sleep 1234 NULL
41439 c64confuser arges9.xmen.eti:45355 host_sw_db Sleep 1 NULL
41440 c64confuser localhost host_sw_db Query 0 NULL show processlist
41444 c64confuser arges9.xmen.eti:45414 host_sw_db Sleep 10 NULL
Variable_name Value
max_connections 5
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
Variable_name Value
max_connections 151
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
cat host-local/var/log/*|grep -c 'MySQL server is experiencing heavy load'
Odd.
echo $-
to see what options you have set in your shell
$ echo $-
himBH
$ bash --version
GNU bash, version 3.00.15(1)-release (x86_64-redhat-linux-gnu)
Copyright (C) 2004 Free Software Foundation, Inc.
$ set -o
allexport off
braceexpand on
emacs off
errexit off
errtrace off
functrace off
hashall on
histexpand on
history on
ignoreeof off
interactive-comments on
keyword off
monitor on
noclobber off
noexec off
noglob off
nolog off
notify off
nounset off
onecmd off
physical off
pipefail off
posix off
privileged off
verbose off
vi on
xtrace off
$
I am mystified. That's the same shell options I have and I've never observed anything like that 
The script is quite horrid. It looks like an attempt to avoid starting MySQL more than once while feeding it commands at varying time intervals down a pipeline dependent on external events. In the process MySQL appears to have managed to "set -v" each time a sub-shell is executed, suggesting that the MySQL is acting like a background task within the same sub-shell and messing with the environment.
The order of the output is interesting because there is Shell output within the MySQL program output. This implies concurrency.
If I were to write a script with a similar function I'd prepare the two simple MySQL programs in files and invoke MySQL when required with the relevant SQL program file as a parameter.
I guess that the "kill -9" is for previously identified looping clients and that setting the allowed concurrency artificially low is to stop more clients logging in while you kill the rogue process?
The script would be less complicated if it took the rogue pid as a parameter and was called from a wrapper script once per pid.
The script itself has great potential to loop - particularly if one of the pids is wrong.
Hmm. Just realised that the author may be trying to keep a connection open in case he can't make a new connection to clear the problem (presumably not an admin user of the database)? The whole process might be better as a MySQL program.
I was testing how the restart of daemons reacted to a shortage of mysql connections, so I drop the limit, kill a daemon, wait for new messages, then raise the limit, wait for the message count to quiesce and move to the next daemon. It works fine except for the bash blowing out junk from $() onto the console. I guess I am singularly cursed.
Maybe it comes from the ENV?
$ set
BASH=/bin/bash
BASH_ARGC=()
BASH_ARGV=()
BASH_LINENO=()
BASH_SOURCE=()
BASH_VERSINFO=([0]="3" [1]="00" [2]="15" [3]="1" [4]="release" [5]="x86_64-redhat-linux-gnu")
BASH_VERSION='3.00.15(1)-release'
COLORS=/etc/DIR_COLORS.xterm
COLUMNS=81
CYCLOPS_HOME=/var/xxx/6_1_22_rc4
DIRSTACK=()
EDITOR=vim
EUID=10103
GROUPS=()
G_BROKEN_FILENAMES=1
HISTFILE=/var/xxx/.bash_history
HISTFILESIZE=1000000
HISTSIZE=1000000
HOME=/var/xxx
HOSTNAME=xxx.yyy.zzz
HOSTTYPE=x86_64
IFS=$' \t\n'
INPUTRC=/etc/inputrc
LANG=en_US.UTF-8
LESSOPEN='|/usr/bin/lesspipe.sh %s'
LINES=25
LOGNAME=xxx
LS_COLORS='no=00:fi=00:di=00;34:ln=00;36:pi=40;33:so=00;35:bd=40;33;01:cd=40;33;01:or=01;05;37;41:mi=01;05;37;41:ex=00;32:*.cmd=00;32:*.exe=00;32:*.com=00;32:*.btm=00;32:*.bat=00;32:*.sh=00;32:*.csh=00;32:*.tar=00;31:*.tgz=00;31:*.arj=00;31:*.taz=00;31:*.lzh=00;31:*.zip=00;31:*.z=00;31:*.Z=00;31:*.gz=00;31:*.bz2=00;31:*.bz=00;31:*.tz=00;31:*.rpm=00;31:*.cpio=00;31:*.jpg=00;35:*.gif=00;35:*.bmp=00;35:*.xbm=00;35:*.xpm=00;35:*.png=00;35:*.tif=00;35:'
MACHTYPE=x86_64-redhat-linux-gnu
MAIL=/var/spool/mail/c64adm
MAILCHECK=60
OLDPWD=/var/c64adm
OPTERR=1
OPTIND=1
OSTYPE=linux-gnu
PATH=/home2/xxx/6_1_22_rc4/test-local/bin:/home2/xxx/6_1_22_rc4/mon-local/bin:/home2/xxx/6_1_22_rc4/host-local/bin:/home2/xxx/6_1_22_rc4/local/bin:/usr/kerberos/bin:/usr/local/bin:/bin:/usr/bin:/usr/X11R6/bin:/home2/xxx/bin:/sbin:/usr/sbin:/home/yyy/bin
PIPESTATUS=([0]="0")
PPID=19816
PS1='\[\e]0;\u@\h: \w\a\]\[\033[01;32m\]\u@\h\[\033[00m\]:\[\033[01;34m\]\w\[\033[00m\]\$ '
PS2='> '
PS4='+ '
PWD=/var/xxx/6_1_22_rc4
SHELL=/bin/bash
SHELLOPTS=braceexpand:hashall:histexpand:history:interactive-comments:monitor:vi
SHLVL=1
SSH_CLIENT='::ffff:192.168.9.73 46673 22'
SSH_CONNECTION='::ffff:192.168.9.73 46673 ::ffff:192.168.9.109 22'
SSH_TTY=/dev/pts/0
SUPPORTED=en_US.UTF-8:en_US:en
TERM=xterm
UID=10103
USER=xxx
_=--no-diag-kern
f=local/bin/cyclops64-linux-elf-sim
i=host-local/var/log/swras-master.log
I never heard of the input generating shell caring that it was feeding mysql. I suspect the messages are on stderr or tty, since they cannot pipe through mysql! It is a very obnoxious thing for a shell to do. Maybe I have to take it to bash-dev-land.
Yes, I too had a theory that the last command was sitting in a buffer but I couldn't account for the selective repetition, the overlap and the fact that it stops.
Imho it's something to do with MySQL because the issue starts when MySQL gets its first program line. I suspect that it is by-passing unix I/O mechanisms and messing with the raw device (and upsetting the Shell in the process).
If it doesn't need a terminal context, maybe try backgrounding the MySQL program.
I seem to remember you advising me that the following ksh construct doesn't work in bash (but if it does, it's worth a try):
(
# shell lines
) | program
in that case, maybe mysql --raw or --batch?
1 Like
Nothing wrong with that construct. ksh evaluates pipes in a different order is all, so read on the end of a pipe-chain would set values in the subshell in a bourne shell, but the parent shell in ksh.
1 Like
Yes, bash is less handy at
(....)|read x
which has to be recoded, often to:
x=$(....|line)
The 'read x' saves calling 'line', if your LINUX/UNIX has 'line' installed, else 'head -1'. I suspect 'head -1' is not fully equivalent to 'line', like when reading a fd with many commands, but the 'head -1' is equivalent, if an extra fork and exec, to 'read x' (both have a FILE* stdin that reads ahead, which is fine for throughput and reduced overhead but no good for reading the same fd with many commands). Bash is mostly just as handy with
(....)|while read x
do
...
done
as long as you do not, later, want variables set in there including x, as it is in a subshell. Sometimes a bash script can be fixed with just a more explicit sub-shell where the variable is read and used (only)):
....|(read x; ... $x ....)
It is an article of faith in bash that any ksh thing that malfunctions is a feature. 
If I could make the $(...) echoing '...' out happen on demand, I could take a shot at seeing what and where it is writing that, but alas, it just comes and goes. I am not buying the mysql reaches up the stdin pipe theory. Pipes have a very few and bland set of behaviors, thank goodness.
I have been wishing for a revised stdio, unified FILE* library that would flush all output FILE* when blocking any, and read input ahead when blocking on other FILE*. Then, there would always be low latency, and fflush() or buffering restrictions like line or none would not be necessary for most programs, so you get good buffering during high throughput and yet low latency during data drought, all with no code. You would only need such controls when many threads/processes write the same fd or file, to avoid splitting/mixing lines/packets.
Try this:
$ echo mypassword | mysql -uroot -p
Enter password:
Commandline mysql features a full-fledged line editor complete with arrow keys and history recall. It can and does mess with your terminal. It doesn't have to "reach up stdin" to do this -- it can open /dev/tty and mess with it direct. Any interactive program has the potential to do this, really. How else would more work when stuck on the end of a pipe chain?
You can also do
read x <<<$(....)
It's not a BASH problem, or at least not just a BASH problem. Lots of non-bash bourne shells have the same shortcoming. ksh's behavior is an extension.
---------- Post updated at 01:29 PM ---------- Previous update was at 01:17 PM ----------
Like the memory buffer used for pipes, and the caching+read-ahead Linux and UNIX do for files? That's handled decently well at the kernel level. (I've noticed some changes lately, actually, in pipes being flushed more often.) The trouble I've found is how to tell the kernel when not to do that. Any operation on a large file fills the file cache with junk that'll probably not be reused, and you need to posix_fadvise every step of the way to prevent it...
I think the default line-buffering for printf() and such is to make situations like this more efficient:
for(x=0; x<10; x++) printf("asdf");
printf("\n");
With buffering, that's only one context switch, when write() is called by printf("\n"); Turn off all buffering and it's 11 context switches.
1 Like
I suppose a FILE* could be double buffered and use aio to move the data! Maybe I will write a lib! Double buffering (i/o in one buffer area while you memory write/read another buffer area) got seriously neglected in UNIX except within TCP sockets.
I have never used the 'cmd <<< word', being pretty close to 'echo word | cmd' or 'cmd <<!
word
!', and in this '<<<$(...)' case, takes data from stdout a to stdin b, which is normally a pipe's simple job.
I suppose that if all non-ENV shell variables of a session were in an mmap'd file, all sub-shells could see and change all variables. Of course, it might get a bit tricky with the locking and moving as things expand, soon becoming another heap in need of GC.