[SOLVED-ish] Performance weirdness with netbsd-9 /usr/bin/grep

[Paul Ripke <stix%stix.id.au@localhost>]

I figured this out, but felt this was worth sending in any case.
Answer(-ish) at the end...

I noticed grep was slow, and went to investigate. Examples probably
speak louder:

slave:ksh$ uname -a
NetBSD slave 9.0_STABLE NetBSD 9.0_STABLE (SLAVE) #1: Sat Apr 25 11:26:56 AEST 2020  stix@slave:/home/netbsd/netbsd-9/obj.amd64/home/netbsd/netbsd-9/src/sys/arch/amd64/compile/SLAVE amd64
slave:ksh$ time /usr/bin/wc /home/httpd/log/access.log
 2052218 31811880 550868855 /home/httpd/log/access.log
   13.77s real    13.27s user     0.47s system
slave:ksh$ time /usr/bin/grep -c Jan/2020 /home/httpd/log/access.log
407186
  105.52s real   100.10s user     0.91s system
slave:ksh$ time /rescue/grep -c Jan/2020 /home/httpd/log/access.log
407186
    2.33s real     1.57s user     0.53s system
slave:ksh$ time /usr/pkg/bin/ggrep -c Jan/2020 /home/httpd/log/access.log
407186
    1.16s real     0.57s user     0.59s system

I note that the time increases dramatically (10x) with the number of
matches, so the time isn't all spent in the regex engine, per-se, but
somewhere in match processing:

slave:ksh$ time /usr/bin/grep -c XXXXX /home/httpd/log/access.log
0
   10.48s real     9.92s user     0.56s system

I note that /rescue/grep appears to be built from src/usr.bin/grep/,
whereas /usr/bin/grep is built from src/external/gpl2/grep/.

Running under ktruss, I don't see anything odd - it's all user time,
anyway. I tried building a profiling version (-pg) and it coredumps:

Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x00000000baa48d10 in dl_iterate_phdr ()
#1  0x00000000baa24ebd in __libc_static_tls_setup ()
#2  0x00000000baaaa287 in _libc_init ()
#3  0x00007eb7a9a41d14 in ?? () from /usr/lib/libc.so.12
#4  0x00007eb7aa28f180 in ?? ()
#5  0x00007eb7a9a3cdf9 in _init () from /usr/lib/libc.so.12
#6  0x0000000000000000 in ?? ()

Does anyone else see this?

[SOLVID-ish]: Argh! I thought this sounded familiar...

slave:ksh$ LC_ALL=C time /usr/bin/grep -c Jan/2020 /home/httpd/log/access.log
407186
        0.91 real         0.42 user         0.48 sys

So has the default value of LC_ALL (or LC_.*) changed recently?

-- 
Paul Ripke
"Great minds discuss ideas, average minds discuss events, small minds
 discuss people."
-- Disputed: Often attributed to Eleanor Roosevelt. 1948.