From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from omta002.cacentral1.a.cloudfilter.net (omta002.cacentral1.a.cloudfilter.net [3.97.99.33]) by sourceware.org (Postfix) with ESMTPS id 1DA2F3857345 for ; Mon, 6 Jun 2022 16:45:07 +0000 (GMT) DMARC-Filter: OpenDMARC Filter v1.4.1 sourceware.org 1DA2F3857345 Authentication-Results: sourceware.org; dmarc=none (p=none dis=none) header.from=SystematicSw.ab.ca Authentication-Results: sourceware.org; spf=none smtp.mailfrom=systematicsw.ab.ca Received: from shw-obgw-4002a.ext.cloudfilter.net ([10.228.9.250]) by cmsmtp with ESMTP id yEsonhRLVWi4QyFqOnURcp; Mon, 06 Jun 2022 16:44:44 +0000 Received: from [10.0.0.5] ([184.64.124.72]) by cmsmtp with ESMTP id yFqjnKwyByz1uyFqjnSBF8; Mon, 06 Jun 2022 16:45:06 +0000 X-Authority-Analysis: v=2.4 cv=J4G5USrS c=1 sm=1 tr=0 ts=629e2f12 a=oHm12aVswOWz6TMtn9zYKg==:117 a=oHm12aVswOWz6TMtn9zYKg==:17 a=IkcTkHD0fZMA:10 a=UqCG9HQmAAAA:8 a=mDV3o1hIAAAA:8 a=w_pzkKWiAAAA:8 a=OHzK3Ai6AAAA:8 a=gp_DfHudNbcP1IkTrXIA:9 a=QEXdDO2ut3YA:10 a=dI9p-avQWAUA:10 a=9c8rtzwoRDUA:10 a=_FVE-zBwftR9WsbkzFJk:22 a=sRI3_1zDfAgwuvI8zelB:22 a=UZnP5HNk2VwuXZgHQwfV:22 Message-ID: <7b9cb974-fef4-5681-0139-d7a6cdaaa688@SystematicSw.ab.ca> Date: Mon, 6 Jun 2022 10:45:05 -0600 MIME-Version: 1.0 User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:91.0) Gecko/20100101 Thunderbird/91.10.0 Reply-To: cygwin@cygwin.com Subject: Re: [EXT] Re: possible grep V3.7 issue Content-Language: en-CA To: cygwin@cygwin.com References: From: Brian Inglis Organization: Systematic Software In-Reply-To: Content-Type: text/plain; charset=UTF-8; format=flowed Content-Transfer-Encoding: 8bit X-CMAE-Envelope: MS4xfBvq6+m4hphErkAzBgA4hxyjyAZ5dhCoqKGG1FxD4Va5HT4TrArixBgCV85Uvz85fEedsz9obH5jh5R9QAmA7lZdIeXqFL0aKOOGlcYjs6qXWP3bAIT5 2SV1KuW1Goo50x7G3Q2naa4rMEtsV2OhuwONyNv8juNtyUk46nXMvQ5tpNigq9zbKcMjWJ0m/6/YxWgNiKhXgOpApXZx75ibnb0= X-Spam-Status: No, score=-1165.3 required=5.0 tests=BAYES_00, KAM_DMARC_STATUS, KAM_LAZY_DOMAIN_SECURITY, KAM_SHORT, NICE_REPLY_A, SPF_HELO_NONE, SPF_NONE, TXREP, T_SCC_BODY_TEXT_LINE autolearn=ham autolearn_force=no version=3.4.6 X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on server2.sourceware.org X-BeenThere: cygwin@cygwin.com X-Mailman-Version: 2.1.29 Precedence: list List-Id: General Cygwin discussions and problem reports List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 06 Jun 2022 16:45:09 -0000 On 2022-06-06 06:41, Gordon Grimes via Cygwin wrote: > On Monday, June 6, 2022 8:34 AM, Eliot Moss wrote: >> On 6/6/2022 8:26 AM, Gordon Grimes via Cygwin wrote: >>> I wanted to let you know about a possible issue I found in grep >>> v3.7. I run Cygwin and recently downgraded ‘grep’ to v3.6 from >>> v3.7 to address a performance issue (shown below). I just thought >>> you’d want to know (V3.6 is working well, so I’m in a good place 😊) >>> % time echo hi | grep h >>> hi >>> real 0m7.442s >>> user 0m0.030s >>> sys 0m6.576s >>> % /usr/bin/grep --version >>> grep (GNU grep) 3.7 >>> Packaged by Cygwin (3.7-2) >>> Copyright (C) 2021 Free Software Foundation, Inc. >>> License GPLv3+: GNU GPL version 3 or later https://nam04.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgnu.org%2Flicenses%2Fgpl.html&data=05%7C01%7CGordon.Grimes%40nortonlifelock.com%7C640f66e158104f7486ea08da47b8e328%7C94986b1d466f4fc0ab4b5c725603deab%7C0%7C0%7C637901156666044572%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C3000%7C%7C%7C&sdata=FujGNPbnS6TMO8I1RT%2FuczWHhImX6KnEUnLWC5EYYTE%3D&reserved=0. >>> This is free software: you are free to change and redistribute it. >>> There is NO WARRANTY, to the extent permitted by law. >>> Written by Mike Haertel and others; see >>> https://nam04.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgit.sv.gnu.org%2Fcgit%2Fgrep.git%2Ftree%2FAUTHORS&data=05%7C01%7CGordon.Grimes%40nortonlifelock.com%7C640f66e158104f7486ea08da47b8e328%7C94986b1d466f4fc0ab4b5c725603deab%7C0%7C0%7C637901156666044572%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C3000%7C%7C%7C&sdata=yXCYAppkPpbDwkD1h2BPA%2B5PPE6QYLRvmVHxvUwxP34%3D&reserved=0. >>> After the downgrade… >>> % time echo hi | grep h >>> hi >>> real 0m0.292s >>> user 0m0.015s >>> sys 0m0.124s >> I'm running 3.7-2 and get timing similar to what you give for 3.6: >> real 0m0.167s >> user 0m0.015s >> sys 0m0.061s >> Not sure what to say unless, if I downgraded, it would be an order >> of magnitude faster ... I wonder if maybe the new version triggers >> some anti-virus activity or something like that. > I suspected this wasn't 100% reproducible or else it'd have been > > reported/addressed by now. As you say, perhaps there's some > idiosyncrasy with my system/setup. If there's a wave of reporting a > similar issue then perhaps it's worth a look (e.g. perhaps a recent > MS update triggered this). Anyway, unless/until that happens, I'll > simply stick with V3.6. Not seeing any significant differences, over the timing granularity on Windows, between the installed or either of the built versions: $ grep --version grep (GNU grep) 3.7 Packaged by Cygwin (3.7-2) Copyright (C) 2021 Free Software Foundation, Inc. License GPLv3+: GNU GPL version 3 or later . This is free software: you are free to change and redistribute it. There is NO WARRANTY, to the extent permitted by law. Written by Mike Haertel and others; see . $ time echo hi hi real 0m0.000s user 0m0.000s sys 0m0.000s $ time echo hi | grep hi hi real 0m0.226s user 0m0.000s sys 0m0.139s $ time grep hi <<< hi hi real 0m0.214s user 0m0.046s sys 0m0.061s $ time grep-3.6-1.x86_64/inst/usr/bin/grep hi <<< hi hi real 0m0.203s user 0m0.015s sys 0m0.094s $ time echo hi | grep-3.6-1.x86_64/inst/usr/bin/grep hi hi real 0m0.198s user 0m0.030s sys 0m0.046s $ time grep-3.7-2.x86_64/inst/usr/bin/grep hi <<< hi hi real 0m0.214s user 0m0.015s sys 0m0.124s $ time echo hi | grep-3.7-2.x86_64/inst/usr/bin/grep hi hi real 0m0.287s user 0m0.030s sys 0m0.123s Please try running commands like the above to see if any other obvious anomalies appear in timing, and also: $ cygcheck /bin/bash /bin/grep C:/.../bin/bash.exe C:/.../bin/cygwin1.dll C:/WINDOWS/system32/KERNEL32.dll C:/WINDOWS/system32/ntdll.dll C:/WINDOWS/system32/KERNELBASE.dll C:/.../bin/cygiconv-2.dll C:/.../bin/cygintl-8.dll C:/.../bin/cygreadline7.dll C:/.../bin/cygncursesw-10.dll C:/.../bin/grep.exe C:/.../bin/cygwin1.dll C:/WINDOWS/system32/KERNEL32.dll C:/WINDOWS/system32/ntdll.dll C:/WINDOWS/system32/KERNELBASE.dll C:/.../bin/cygintl-8.dll C:/.../bin/cygiconv-2.dll C:/.../bin/cygpcre-1.dll to see if any other obvious anomalies appear such as paths other than Windows/System32 and your Cygwin /bin/, or DLLs other than base Windows or Cygwin locale, I/O, or search. Try running grep under strace, and look in the first column of the output for large time deltas (the second column is cumulative thread or process time) e.g.: $ strace -o grep.strace grep hi <<< hi hi $ awk '$1 > 1000' grep.strace 5864 6350 [main] grep (4000) sigprocmask: 0 = sigprocmask (0, 0x0, 0x180323570) 2157 30776 [main] grep 520 handle_to_fn: current match 'C:' = '\Device\HarddiskVolume2' 11188 44322 [main] grep 520 build_fh_pc: created an archetype (0x180350A90) for /dev/cons0(3/0) 1909 51867 [main] grep 520 open: open(/usr/share/locale/locale.alias, 0x0) 2933 65187 [main] grep 520 read: read(3, 0x800085510, 65536) blocking 3581 69642 [main] grep 520 open: open(/usr/share/locale/en_CA.ISO8859-1/LC_MESSAGES/grep.mo, 0x10000) 1713 87197 [main] grep 520 open: open(/usr/share/locale/en_GB.ISO8859-1/LC_MESSAGES/grep.mo, 0x10000) 1808 97122 [main] grep 520 open: open(/proc/self/maps, 0x0) 7609 105898 [main] grep 520 mmap64: addr 0x0, len 327680, prot 0x3, flags 0x22, fd -1, off 0x0 4845 110951 [main] grep 520 munmap: munmap (addr 0x6FFFFFFB0000, len 327680) 1103 152703 [main] grep 520 fhandler_base::set_flags: flags 0x18000, supplied_bin 0x0 6919 160062 [main] grep 520 mmap64: addr 0x0, len 327680, prot 0x3, flags 0x22, fd -1, off 0x0 4692 165018 [main] grep 520 munmap: munmap (addr 0x6FFFFFFA0000, len 327680) 1103 204304 [main] grep 520 lseek64: 0 = lseek(3, 0, 0) 4862 212220 [main] grep 520 fhandler_base::fstat_helper: 0 = fstat (\??\C:\$Extend\$Deleted\005C00000051F76035B2E0D4, 0xFFFFC870) st_size=0, st_mode=040600, st_ino=25895697862752096st_atim=629E2C2B.913C4C4 st_ctim=629E2C2B.913C4C4 st_mtim=629E2C2B.913C4C4 st_birthtim=629E2C2B.913C4C4 28876 244184 [main] grep 520 fhandler_console::free_console: freed console, res 1 and if you see any, look around those lines for traces of alien code injection. Some alien Norton product seems to have been injected above, so that is a likely culprit, until someone complains about its effect on performance, and gets Cygwin bash, grep 3.7, etc. added to its bypass list; see the FAQ: https://cygwin.com/faq/faq.html#faq.using.bloda. -- Take care. Thanks, Brian Inglis, Calgary, Alberta, Canada This email may be disturbing to some readers as it contains too much technical detail. Reader discretion is advised. [Data in binary units and prefixes, physical quantities in SI.]