Re: backquote peculiarities (was: Re: Combination of "eval set -- ..." and $() command substitution is slow)
On 7/15/19 6:19 PM, astian wrote: >> I doubt it makes any difference to the timing, which I think >> Chet has already answered, but it is worth pointing out that these >> two commands ... >> >> printf '%s\n' "`printf %s "$i"`" >> printf '%s\n' "$(printf %s "$i")" >> >> which (I believe)) are supposed to be the same thing, using the >> different (ancient, and modern) forms of command substitution aren't >> actually the same. In the first $i is unquoted, in the second it is >> quoted. Here, since its value is just a number and IFS isn't being >> fiddled, there is not likely to be any effect, but if you really >> want to make those two the same, the first needs to be written as >> >> printf '%s\n' "`printf %s \"$i\"`" >> >> Such are the joys of `` command substitutions (just avoid them). >> >> kre > > Dear Robert Elz, I'm aware of several of its peculiarities and I typically do > avoid them. However, is it true that $i is unquoted in the first case? POSIX makes it undefined behavior, and different shells do it differently. Bash makes the $i quoted within the `` string, as you discovered. -- ``The lyf so short, the craft so long to lerne.'' - Chaucer ``Ars longa, vita brevis'' - Hippocrates Chet Ramey, UTech, CWRUc...@case.eduhttp://tiswww.cwru.edu/~chet/
Re: Combination of "eval set -- ..." and $() command substitution is slow
On Jul 16 2019, Ilkka Virta wrote: > On 15.7. 20:49, Robert Elz wrote: > >> printf '%s\n' "`printf %s "$i"`" >> printf '%s\n' "$(printf %s "$i")" >> >> aren't actually the same. In the first $i is unquoted, in the second it is >> quoted. > > Huh, really? It looks to me like the first one treats $i as quoted too: > > $ touch file.txt; i='123 *' > $ printf '%s\n' "`printf :%s: "$i"`" > :123 *: It is not portable, see the autoconf manual: ... is not portable, since not all shells properly understand `"`..."..."...`"', for example Solaris 10 ksh: $ foo="`echo " bar" | sed 's, ,,'`" ksh: : cannot execute ksh: bar | sed 's, ,,': cannot execute Posix does not specify behavior for this sequence. Andreas. -- Andreas Schwab, SUSE Labs, sch...@suse.de GPG Key fingerprint = 0196 BAD8 1CE9 1970 F4BE 1748 E4D4 88E3 0EEA B9D7 "And now for something completely different."
Re: Combination of "eval set -- ..." and $() command substitution is slow
On 15.7. 20:49, Robert Elz wrote: printf '%s\n' "`printf %s "$i"`" printf '%s\n' "$(printf %s "$i")" aren't actually the same. In the first $i is unquoted, in the second it is quoted. Huh, really? It looks to me like the first one treats $i as quoted too: $ touch file.txt; i='123 *' $ printf '%s\n' "`printf :%s: "$i"`" :123 *: But not here, of course: $ printf '%s\n' "`printf :%s: $i`" :123::file.txt: I tried with Bash and some other shells, but couldn't find one where the result was different. Did I miss something? -- Ilkka Virta / itvi...@iki.fi
backquote peculiarities (was: Re: Combination of "eval set -- ..." and $() command substitution is slow)
Robert Elz: > Date:Wed, 10 Jul 2019 17:21:00 + > From:astian > Message-ID: > > I doubt it makes any difference to the timing, which I think > Chet has already answered, but it is worth pointing out that these > two commands ... > > printf '%s\n' "`printf %s "$i"`" > printf '%s\n' "$(printf %s "$i")" > > which (I believe)) are supposed to be the same thing, using the > different (ancient, and modern) forms of command substitution aren't > actually the same. In the first $i is unquoted, in the second it is > quoted. Here, since its value is just a number and IFS isn't being > fiddled, there is not likely to be any effect, but if you really > want to make those two the same, the first needs to be written as > > printf '%s\n' "`printf %s \"$i\"`" > > Such are the joys of `` command substitutions (just avoid them). > > kre Dear Robert Elz, I'm aware of several of its peculiarities and I typically do avoid them. However, is it true that $i is unquoted in the first case? Consider: i='foo bar' set -x printf '%s\n' "`printf '<%s>' "$i"`" printf '%s\n' "`printf '<%s>' \"$i\"`" printf '%s\n' "`printf '<%s>' $i`" Which outputs: ++ printf '<%s>' 'foo bar' + printf '%s\n' '' ++ printf '<%s>' 'foo bar' + printf '%s\n' '' ++ printf '<%s>' foo bar + printf '%s\n' '' Cheers.
Re: Combination of "eval set -- ..." and $() command substitution is slow
Date:Wed, 10 Jul 2019 17:21:00 + From:astian Message-ID: I doubt it makes any difference to the timing, which I think Chet has already answered, but it is worth pointing out that these two commands ... printf '%s\n' "`printf %s "$i"`" printf '%s\n' "$(printf %s "$i")" which (I believe)) are supposed to be the same thing, using the different (ancient, and modern) forms of command substitution aren't actually the same. In the first $i is unquoted, in the second it is quoted. Here, since its value is just a number and IFS isn't being fiddled, there is not likely to be any effect, but if you really want to make those two the same, the first needs to be written as printf '%s\n' "`printf %s \"$i\"`" Such are the joys of `` command substitutions (just avoid them). kre
Re: Combination of "eval set -- ..." and $() command substitution is slow
On 7/13/19 1:36 PM, astian wrote: > Chet Ramey: >>> - $() seems generally slightly slower than ``, but becomes >>> pathologically >>> so when preceded with "eval set -- ...". >> >> It is slightly slower -- POSIX requires that the shell parse the contents >> of $(...) to determine that it's a valid script as part of finding the >> closing `)'. The rules for finding the closing "`" don't have that >> requirement. >> >>> - "eval set -- ..." itself doesn't seem slow at all, but obviously it >>> has >>> side-effects not captured by the "time" measurement tool. >> >> What happens is you end up with a 4900-character command string that you >> have to parse multiple times. But that's not the worst of it. > > Since this statement ought to run exactly once, naïvely I would expect that by > "multiple times" you really mean at most "twice": once for the top-level > script, another time "inside" the eval "sub-script". I meant scan, as part of set_line_mbstate(), examining the contents. One side effect of running the parser so many times (the command substitutions) is that it saves and restores the previous value of the shell's input line. Using `eval' sets that to the 4900-character string. Part of restoring the old value of the line was running through it to set the multibyte state of the characters, so you run through set_line_mbstate on the 4900-character string every time you run the parser for the $(...) command substitution. > >> The gprof output provides a clue. >> >> >>> case 1 1 0 (pathological): >>>% cumulative self self total >>> time seconds secondscalls us/call us/call name >>> 38.89 0.21 0.2128890 7.27 7.27 set_line_mbstate >> >> set_line_mbstate() runs through each command line before parsing, creating >> a bitmap that indicates whether each element is a single-byte character or >> part of a multi-byte character. The scanner uses this to determine whether >> a shell metacharacter should act as a delimiter or get skipped over as part >> of a multibyte character. For a single run with args `1 1 0', it gets >> called around 7300 times, with around 2400 of them for the 4900-character >> string with all the arguments. >> >> When you're in a multibyte locale (en_US.UTF-8 is one such), each one of >> those characters requires a call to mbrlen/mbrtowc. So that ends up being >> 2400 * 4900 calls to mbrlen. > > I am indeed using an UTF-8 locale, but I tested also with export LC_ALL=C and > the > behaviour did not change, I should have mentioned that. Once you take care of that bottleneck, it's the parser. >> There is something happening here -- there's no way there should be that >> many calls to set_line_mbstate(), > > Notice that there are almost as many calls (only 2 fewer) in case "0 1 0" (in > which eval is not used) yet in that case the performance is not harmed. Yes, but the string it runs through is literally a thousand times shorter. In any event, it's the parser. Yacc-based parsers are fairly slow, and running yyparse 2400 times (1200 to find the closing paren while scanning the double-quoted string, then 1200 more times (!) to find it again while doing the command substitution -- I should do something about that) accounts for almost all of the performance difference. It just about doubles the number of malloc/free calls, for example. On a version of your script where I ran `f' in a loop 10 times to exaggerate performance issues, running the parser for the $(...) command substitution accounted for around 35% of the program's running time, according to gprof. Chet -- ``The lyf so short, the craft so long to lerne.'' - Chaucer ``Ars longa, vita brevis'' - Hippocrates Chet Ramey, UTech, CWRUc...@case.eduhttp://tiswww.cwru.edu/~chet/
Re: Combination of "eval set -- ..." and $() command substitution is slow
Dear Chet Ramey, thanks for the explanations, I assume you were able to reproduce the issue. First a warning that I forgot to include in the previous email: the quoted excerpts of the gprof tables correspond to a slightly modified test script in which I tried to magnify the overhead in order to more easily spot performance differences. Therefore, the absolute values displayed, e.g. number of function calls, are exaggerated. The relative values (and hopefully your conclusions) remain largely the same, though. Sorry for any potential confusion. A few short comments prompted by your reply (probably not very useful, feel free to ignore them). Chet Ramey: >> - $() seems generally slightly slower than ``, but becomes pathologically >> so when preceded with "eval set -- ...". > > It is slightly slower -- POSIX requires that the shell parse the contents > of $(...) to determine that it's a valid script as part of finding the > closing `)'. The rules for finding the closing "`" don't have that > requirement. > >> - "eval set -- ..." itself doesn't seem slow at all, but obviously it has >> side-effects not captured by the "time" measurement tool. > > What happens is you end up with a 4900-character command string that you > have to parse multiple times. But that's not the worst of it. Since this statement ought to run exactly once, naïvely I would expect that by "multiple times" you really mean at most "twice": once for the top-level script, another time "inside" the eval "sub-script". > The gprof output provides a clue. > > >> case 1 1 0 (pathological): >>% cumulative self self total >> time seconds secondscalls us/call us/call name >> 38.89 0.21 0.2128890 7.27 7.27 set_line_mbstate > > set_line_mbstate() runs through each command line before parsing, creating > a bitmap that indicates whether each element is a single-byte character or > part of a multi-byte character. The scanner uses this to determine whether > a shell metacharacter should act as a delimiter or get skipped over as part > of a multibyte character. For a single run with args `1 1 0', it gets > called around 7300 times, with around 2400 of them for the 4900-character > string with all the arguments. > > When you're in a multibyte locale (en_US.UTF-8 is one such), each one of > those characters requires a call to mbrlen/mbrtowc. So that ends up being > 2400 * 4900 calls to mbrlen. I am indeed using an UTF-8 locale, but I tested also with export LC_ALL=C and the behaviour did not change, I should have mentioned that. Also, it occurs to me that since all shell metacharacters are surely 7-bit ASCII, and all UTF-8 code units are strictly and deliberately non-ASCII 8-bit bytes, at least in the case of UTF-8 it may not be necessary to construct such bitmap: there cannot be a shell-metacharacter byte part of a UTF-8 sequence representing something else, so there's no need for the distinction. Of course, this observation applies only to such specially crafted multibyte encodings as UTF-8 (which nonetheless is surely by far the most common). Furthermore, it does not explain the issue at hand. > There is something happening here -- there's no way there should be that > many calls to set_line_mbstate(), Notice that there are almost as many calls (only 2 fewer) in case "0 1 0" (in which eval is not used) yet in that case the performance is not harmed. Quoting from the previous email: case 0 1 0: 2.08 0.32 0.012 0.00 0.00 set_line_mbstate case 1 1 0 (pathological): 38.89 0.21 0.2128890 7.27 7.27 set_line_mbstate OTOH, all other test cases show less than 100 calls (these numbers correspond to a profiling run of the given script, unmodified): $ grep -m1 set_line_mbstate gmon*.table gmon.out.0-0-X.table: 0.00 0.00 0.00 88 0.00 0.00 set_line_mbstate gmon.out.0-1-0.table: 0.00 0.13 0.00 7288 0.00 0.00 set_line_mbstate gmon.out.0-1-1.table: 0.00 0.18 0.00 88 0.00 0.00 set_line_mbstate gmon.out.1-0-X.table: 0.00 0.01 0.00 90 0.00 0.00 set_line_mbstate gmon.out.1-1-0.table: 37.50 0.06 0.06 7290 8.23 8.23 set_line_mbstate gmon.out.1-1-1.table: 0.00 0.07 0.00 90 0.00 0.00 set_line_mbstate > even when you have to save and restore > the input line because you have to parse the contents of $(). There must > be some combination of the effect of `eval' on the line bitmap and the > long string. I'll see what I can figure out. > > Chet Cheers.
Re: Combination of "eval set -- ..." and $() command substitution is slow
On 7/10/19 1:21 PM, astian wrote: > Bash Version: 5.0 > Patch Level: 3 > Release Status: release > > Description: > > I discovered a curious performance degradation in the combined usage of the > constructs "eval set -- ..." and new-style command substitution. In short, > setting the positional arguments via eval and then iterating over each one > while performing $() command substitution(s) is significantly slower than > not using eval, or not making command substitution, or using `` instead. > > I include below a reduced test script that illustrates the issue. A few > notes: > - The pathological case is "1 1 0". > - I did not observe performance difference in unoptimised builds (-O0). > > -- > case 1 1 0 > eval set > real0m0.002s > user0m0.000s > sys 0m0.000s > for loop cmdsubst-currency > real0m0.968s > user0m0.432s > sys 0m0.148s > -- > > Observations: > - The pathological case "1 1 0" spends about 10 times more time doing > something in userspace during the loop, relative to the comparable cases > "0 1 0", "0 1 1", and "1 1 1". > - $() seems generally slightly slower than ``, but becomes pathologically > so when preceded with "eval set -- ...". It is slightly slower -- POSIX requires that the shell parse the contents of $(...) to determine that it's a valid script as part of finding the closing `)'. The rules for finding the closing "`" don't have that requirement. > - "eval set -- ..." itself doesn't seem slow at all, but obviously it has > side-effects not captured by the "time" measurement tool. What happens is you end up with a 4900-character command string that you have to parse multiple times. But that's not the worst of it. The gprof output provides a clue. > case 1 1 0 (pathological): >% cumulative self self total > time seconds secondscalls us/call us/call name > 38.89 0.21 0.2128890 7.27 7.27 set_line_mbstate set_line_mbstate() runs through each command line before parsing, creating a bitmap that indicates whether each element is a single-byte character or part of a multi-byte character. The scanner uses this to determine whether a shell metacharacter should act as a delimiter or get skipped over as part of a multibyte character. For a single run with args `1 1 0', it gets called around 7300 times, with around 2400 of them for the 4900-character string with all the arguments. When you're in a multibyte locale (en_US.UTF-8 is one such), each one of those characters requires a call to mbrlen/mbrtowc. So that ends up being 2400 * 4900 calls to mbrlen. There is something happening here -- there's no way there should be that many calls to set_line_mbstate(), even when you have to save and restore the input line because you have to parse the contents of $(). There must be some combination of the effect of `eval' on the line bitmap and the long string. I'll see what I can figure out. Chet -- ``The lyf so short, the craft so long to lerne.'' - Chaucer ``Ars longa, vita brevis'' - Hippocrates Chet Ramey, UTech, CWRUc...@case.eduhttp://tiswww.cwru.edu/~chet/
Combination of "eval set -- ..." and $() command substitution is slow
Configuration Information [Automatically generated, do not change]: Machine: x86_64 OS: linux-gnu Compiler: gcc Compilation CFLAGS: -g -O2 -fdebug-prefix-map=/tmp/bash/bash-5.0=. -fstack-protector-strong -Wformat -Werror=format-security -Wall -Wno-parentheses -Wno-format-security uname output: Linux $nodename 4.9.0-9-amd64 #1 SMP Debian 4.9.168-1+deb9u2 (2019-05-13) x86_64 GNU/Linux Machine Type: x86_64-pc-linux-gnu Bash Version: 5.0 Patch Level: 3 Release Status: release Description: I discovered a curious performance degradation in the combined usage of the constructs "eval set -- ..." and new-style command substitution. In short, setting the positional arguments via eval and then iterating over each one while performing $() command substitution(s) is significantly slower than not using eval, or not making command substitution, or using `` instead. I include below a reduced test script that illustrates the issue. A few notes: - The pathological case is "1 1 0". - I did not observe performance difference in unoptimised builds (-O0). Example output: case 0 0 X set real0m0.001s user0m0.000s sys 0m0.000s for loop real0m0.008s user0m0.008s sys 0m0.000s -- case 0 1 0 set real0m0.001s user0m0.000s sys 0m0.000s for loop cmdsubst-currency real0m0.551s user0m0.048s sys 0m0.144s -- case 0 1 1 set real0m0.001s user0m0.000s sys 0m0.000s for loop cmdsubst-grave real0m0.520s user0m0.048s sys 0m0.116s -- case 1 0 X eval set real0m0.002s user0m0.004s sys 0m0.000s for loop real0m0.008s user0m0.008s sys 0m0.000s -- case 1 1 0 eval set real0m0.002s user0m0.000s sys 0m0.000s for loop cmdsubst-currency real0m0.968s user0m0.432s sys 0m0.148s -- case 1 1 1 eval set real0m0.002s user0m0.004s sys 0m0.000s for loop cmdsubst-grave real0m0.529s user0m0.044s sys 0m0.124s -- Observations: - The pathological case "1 1 0" spends about 10 times more time doing something in userspace during the loop, relative to the comparable cases "0 1 0", "0 1 1", and "1 1 1". - $() seems generally slightly slower than ``, but becomes pathologically so when preceded with "eval set -- ...". - "eval set -- ..." itself doesn't seem slow at all, but obviously it has side-effects not captured by the "time" measurement tool. I tested an --enable-profiling build but the results are vastly different between test cases so I wasn't able to gain much insight by comparing them. (Also I'm inexperienced with gprof.) For reference, though, these are the top 10 functions in the flat listing for 3 of the test cases: case 0 1 0: % cumulative self self total time seconds secondscalls ms/call ms/call name 18.75 0.09 0.09 4801 0.02 0.02 make_child 13.54 0.16 0.07 1200 0.05 0.05 reap_dead_jobs 13.54 0.22 0.07 sigchld_handler 6.25 0.25 0.0338586 0.00 0.00 read_token.constprop.9 6.25 0.28 0.03 7259 0.00 0.04 param_expand 4.17 0.30 0.02 9609 0.00 0.01 yyparse 2.08 0.31 0.0128910 0.00 0.00 assignment 2.08 0.32 0.012 0.00 0.00 set_line_mbstate 2.08 0.33 0.0114417 0.00 0.00 set_signal_handler 2.08 0.34 0.01 9643 0.00 0.00 zread case 1 1 1: % cumulative self self total time seconds secondscalls us/call us/call name 31.03 0.09 0.09 480118.7518.75 make_child 15.52 0.14 0.05 120037.5037.50 reap_dead_jobs 15.52 0.18 0.05 sigchld_handler 6.90 0.20 0.02 9889 2.02 2.02 hash_search 3.45 0.21 0.0114464 0.69 0.69 dequote_string 3.45 0.22 0.01 8461 1.1816.14 param_expand 3.45 0.23 0.01 4808 2.08 3.12 run_sigchld_trap 3.45 0.24 0.01 4801 2.0823.05 command_substitute 3.45 0.25 0.01 4801 2.08 2.09 wait_for 3.45 0.26 0.01 4800 2.08 2.08 string_extract case 1 1 0 (pathological): % cumulative self self total time seconds secondscalls us/call
