Bug 1269014

Summary: -c combined with -P totally broken
Product: [Fedora] Fedora Reporter: Harald Reindl <h.reindl>
Component: grepAssignee: Jaroslav Škarvada <jskarvad>
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 23CC: dhgutteridge, jskarvad, lkundrak, mjuszkie, pbrobinson
Target Milestone: ---Keywords: Reopened
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: grep-2.22-3.fc23 grep-2.21-6.fc22 grep-2.22-5.fc23 grep-2.21-9.fc22 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-01-24 03:18:27 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
coredump due build
none
sample logfile triggering the problem
none
Proposed fix none

Description Harald Reindl 2015-10-06 00:24:39 UTC
[root@localhost:~]$ grep -P -c 'Blocked by (SpamAssassin|Spamfilter)' /var/log/maillog
393

[root@localhost:~]$ grep -P 'Blocked by (SpamAssassin|Spamfilter)' /var/log/maillog | wc -l
752

[root@localhost:~]$ grep -c 'Blocked by Spamfilter' /var/log/maillog
752

Comment 1 Harald Reindl 2015-10-06 08:47:49 UTC
this smells like a hardware dependent optimization / cpu runtime detection because "-P -c" worked for sure and we switched 2 weeks ago to new hardware, in fact Westmere -> SandyBridge

maybe there is a different codepath in case AVX or other CPU features are available with a bug

however the number 393 is strange, it looks like a hardcoded number if something matches, on my workstation (also SandyBridge) the same command says correctly 0 while "grep -P -c '(SpamAssassin|status)' /var/log/maillog" correctly says 38 - thats very strange

[root@localhost:~]$ grep -P -c 'Blocked by (SpamAssassin|Spamfilter)' /var/log/maillog
393

[root@localhost:~]$ grep -P 'Blocked by (SpamAssassin|Spamfilter)' /var/log/maillog | wc -l
855

Comment 2 Jaroslav Škarvada 2015-10-06 09:02:56 UTC
I am currently unable to reproduce.

Could you strip down the test data and attach them to this BZ? Also please provide content of your /proc/cpuinfo.

Comment 3 Harald Reindl 2015-10-06 09:07:43 UTC
testdata is not that easy because that's a production mailserver and i can't publish logs with valid RCPT's - will try to get some anonymized data showing the problem ASAP

VMware cluster in SandyBridge EVC mode (it's just a guess that it may be hardware dependent because i don't see recent grep updates and in the last month the numbers looked correct while the HW change was at the end of the month and so got visible after rotate the maillog)

processor       : 3
vendor_id       : GenuineIntel
cpu family      : 6
model           : 45
model name      : Intel(R) Xeon(R) CPU E5-2643 v3 @ 3.40GHz
stepping        : 2
microcode       : 0x35
cpu MHz         : 3396.067
cache size      : 20480 KB
physical id     : 0
siblings        : 4
core id         : 3
cpu cores       : 4
apicid          : 3
initial apicid  : 3
fpu             : yes
fpu_exception   : yes
cpuid level     : 13
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts mmx fxsr sse sse2 ss ht syscall nx rdtscp lm constant_tsc arch_perfmon pebs bts nopl xtopology tsc_reliable nonstop_tsc aperfmperf pni pclmulqdq ssse3 cx16 pcid sse4_1 sse4_2 x2apic popcnt aes xsave avx hypervisor lahf_lm ida arat epb pln pts dtherm
bugs            :
bogomips        : 6792.13
clflush size    : 64
cache_alignment : 64
address sizes   : 40 bits physical, 48 bits virtual
power management:

Comment 4 Harald Reindl 2015-10-06 12:52:49 UTC
that looks indeed hardware-related and is independent from VMware

my physical workstation F22 while above is F21 shows also 393 while the logfile has grown in the meantime

a physical mini PC running CentOS7 on a Intel Celeron does not have that problem
___________________________________________

grep-2.21-5.fc22.x86_64 / grep-2.21-3.fc21.x86_64

[harry@rh:/downloads]$ grep -P -c 'Blocked by (SpamAssassin|Spamfilter)' maillog
393

processor       : 7
vendor_id       : GenuineIntel
cpu family      : 6
model           : 42
model name      : Intel(R) Core(TM) i7-2600 CPU @ 3.40GHz
stepping        : 7
microcode       : 0x29
cpu MHz         : 3523.781
cache size      : 8192 KB
physical id     : 0
siblings        : 8
core id         : 3
cpu cores       : 4
apicid          : 7
initial apicid  : 7
fpu             : yes
fpu_exception   : yes
cpuid level     : 13
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx rdtscp lm constant_tsc arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc aperfmperf eagerfpu pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer aes xsave avx lahf_lm ida arat epb pln pts dtherm tpr_shadow vnmi flexpriority ept vpid xsaveopt
bugs            :
bogomips        : 6783.95
clflush size    : 64
cache_alignment : 64
address sizes   : 36 bits physical, 48 bits virtual
power management:
___________________________________________

grep-2.20-1.el7.x86_64

[root@ingo-home:~]$ grep -P -c 'Blocked by (SpamAssassin|Spamfilter)' maillog-lounge 
910

[root@ingo-home:~]$ grep -P 'Blocked by (SpamAssassin|Spamfilter)' maillog-lounge | wc -l
910

processor       : 3
vendor_id       : GenuineIntel
cpu family      : 6
model           : 55
model name      : Intel(R) Celeron(R) CPU  J1900  @ 1.99GHz
stepping        : 8
microcode       : 0x808
cpu MHz         : 1600.031
cache size      : 1024 KB
physical id     : 0
siblings        : 4
core id         : 3
cpu cores       : 4
apicid          : 6
initial apicid  : 6
fpu             : yes
fpu_exception   : yes
cpuid level     : 11
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx rdtscp lm constant_tsc arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc aperfmperf pni pclmulqdq dtes64 monitor ds_cpl vmx est tm2 ssse3 cx16 xtpr pdcm sse4_1 sse4_2 movbe popcnt tsc_deadline_timer rdrand lahf_lm 3dnowprefetch ida arat epb dtherm tpr_shadow vnmi flexpriority ept vpid tsc_adjust smep erms
bogomips        : 3999.66
clflush size    : 64
cache_alignment : 64
address sizes   : 36 bits physical, 48 bits virtual
power management:

Comment 5 Harald Reindl 2015-10-06 13:00:56 UTC
hmm - it's Fedora's grep on SandyBridge

the first below is CentOS 7 on the same VMware cluster as the original report, the second with the correct number is my home-machine running IvyBridge which was cloned, has exactly the same software versions and counts correctly

now i need to find a way filter out the trigger without leak the whole maillog
___________________________________________

grep-2.20-1.el7.x86_64

[root@hosting:~]$ grep -P 'Blocked by (SpamAssassin|Spamfilter)' maillog-lounge | wc -l
910

processor       : 3
vendor_id       : GenuineIntel
cpu family      : 6
model           : 45
model name      : Intel(R) Xeon(R) CPU E5-2643 v3 @ 3.40GHz
stepping        : 2
microcode       : 0x35
cpu MHz         : 3396.066
cache size      : 20480 KB
physical id     : 0
siblings        : 4
core id         : 3
cpu cores       : 4
apicid          : 3
initial apicid  : 3
fpu             : yes
fpu_exception   : yes
cpuid level     : 13
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts mmx fxsr sse sse2 ss ht syscall nx rdtscp lm constant_tsc arch_perfmon pebs bts nopl xtopology tsc_reliable nonstop_tsc aperfmperf pni pclmulqdq ssse3 cx16 pcid sse4_1 sse4_2 x2apic popcnt aes xsave avx hypervisor lahf_lm ida arat epb pln pts dtherm
bogomips        : 6792.13
clflush size    : 64
cache_alignment : 64
address sizes   : 40 bits physical, 48 bits virtual
power management:
___________________________________________

grep-2.21-5.fc22.x86_64

[harry@srv-rhsoft:/downloads]$ grep -P 'Blocked by (SpamAssassin|Spamfilter)' maillog-lounge | wc -l
910

processor       : 7
vendor_id       : GenuineIntel
cpu family      : 6
model           : 58
model name      : Intel(R) Core(TM) i7-3770 CPU @ 3.40GHz
stepping        : 9
microcode       : 0x1b
cpu MHz         : 1694.820
cache size      : 8192 KB
physical id     : 0
siblings        : 8
core id         : 3
cpu cores       : 4
apicid          : 7
initial apicid  : 7
fpu             : yes
fpu_exception   : yes
cpuid level     : 13
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx rdtscp lm constant_tsc arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc aperfmperf eagerfpu pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm ida arat epb pln pts dtherm tpr_shadow vnmi flexpriority ept vpid fsgsbase smep erms xsaveopt
bugs            :
bogomips        : 6784.77
clflush size    : 64
cache_alignment : 64
address sizes   : 36 bits physical, 48 bits virtual

Comment 6 Jaroslav Škarvada 2015-10-07 00:07:54 UTC
I am able to reproduce the problem on 'Intel(R) Core(TM) i7-3770 CPU @ 3.40GHz'. It seems the problem disappears if recompiled with -O0 (gcc-4.9.2-6/f21 compiler). The problem doesn't seem to be reproducible with gcc-5.1.1-4. The outputs from grep seem to be the same and that only the internal counter is affected. It's probably gcc bug

Comment 7 Harald Reindl 2015-10-07 09:25:49 UTC
 
hmm - on F22 at least rebuild the src.rpm with gcc-5.1.1-4.fc22.x86_64 2.21-5.fc22.20151007.rh and optimizations enabled (see flags below) i still get 393 so i can't confirm "doesn't seem to be reproducible with gcc-5.1.1-4"
_______________________________________________

my usual compiler flags

-m64 -O2 -g0 -march=sandybridge -mtune=sandybridge -fopenmp -mfpmath=sse -pipe -fno-strict-aliasing -fomit-frame-pointer -finline-functions -finline-limit=60 -fexceptions -fstack-protector-strong --param=ssp-buffer-size=6 -D_FORTIFY_SOURCE=2 -Wstack-protector -Wformat -Werror=format-security  -Wl,-z,now -Wl,-z,relro,-z,noexecstack
_______________________________________________

the same with -O0

-m64 -O0 -g0 -march=sandybridge -mtune=sandybridge -fopenmp -mfpmath=sse -pipe -fno-strict-aliasing -fomit-frame-pointer -finline-functions -finline-limit=60 -fexceptions -fstack-protector-strong --param=ssp-buffer-size=6 -D_FORTIFY_SOURCE=2 -Wstack-protector -Wformat -Werror=format-security  -Wl,-z,now -Wl,-z,relro,-z,noexecstack
_______________________________________________

the same with -O0 and no inlining

-m64 -O0 -g0 -march=sandybridge -mtune=sandybridge -fopenmp -mfpmath=sse -pipe -fno-strict-aliasing -fomit-frame-pointer -fexceptions -fstack-protector-strong --param=ssp-buffer-size=6 -D_FORTIFY_SOURCE=2 -Wstack-protector -Wformat -Werror=format-security  -Wl,-z,now -Wl,-z,relro,-z,noexecstack
_______________________________________________

the same with -O0, no inlining and mtune=generic

-m64 -O0 -g0 -mtune=generic -fopenmp -mfpmath=sse -pipe -fno-strict-aliasing -fomit-frame-pointer -fexceptions -fstack-protector-strong --param=ssp-buffer-size=6 -D_FORTIFY_SOURCE=2 -Wstack-protector -Wformat -Werror=format-security  -Wl,-z,now -Wl,-z,relro,-z,noexecstack
_______________________________________________

the same with removing nearly any options

-m64 -O0 -g0 -mtune=generic -fstack-protector-strong --param=ssp-buffer-size=6 -D_FORTIFY_SOURCE=2 -Wstack-protector -Wformat -Werror=format-security  -Wl,-z,now -Wl,-z,relro,-z,noexecstack
_______________________________________________

in all previous builds that alias for "rpmbuild" was used to make sure FULL RELRO while i
know one software (webalizer-extended) which breaks with FULL RELRO
alias rpmbuild='export LDFLAGS="-Wl,-z,now -Wl,-z,relro,-z,noexecstack"; export SH_LDFLAGS="-Wl,-z,now -Wl,-z,relro,-z,noexecstack"; rpmbuild'

*but* "-m64 -O0 -g0 -mtune=generic -fstack-protector-strong --param=ssp-buffer-size=6 -D_FORTIFY_SOURCE=2 -Wstack-protector -Wformat -Werror=format-security" the same error


Partial RELRO   Canary found      NX enabled    No PIE          No RPATH   No RUNPATH   /usr/bin/grep

[harry@rh:/downloads]$ grep -P -c 'Blocked by (SpamAssassin|Spamfilter)' maillog 
393
_______________________________________________

Comment 8 Harald Reindl 2015-10-07 10:11:19 UTC
maybe unrelated but it seems one or more of the autotests due rpmbuild are segfaulting

Oct  7 10:28:05 testserver kernel: traps: grep[13400] general protection ip:7fc297154bd8 sp:7ffe97d58640 error:0 in libc-2.21.so[7fc297135000+1b7000]
Oct  7 10:28:05 testserver systemd-coredump: Process 13400 (grep) of user 5000 dumped core.#012#012Stack trace of thread 13400:#012#0  0x00007fc297154bd8 pop_fail_stack (libc.so.6)#012#1  0x00007fc297155226 set_regs (libc.so.6)#012#2  0x00007fc297213759 re_search_internal (libc.so.6)#012#3  0x00007fc2972190d5 re_search_stub (libc.so.6)#012#4  0x00007fc297219980 re_search (libc.so.6)#012#5  0x000000000040fea9 EGexecute (grep)#012#6  0x00000000004050ed grepbuf (grep)#012#7  0x00000000004061ee grepdesc (grep)#012#8  0x000000000040353e main (grep)#012#9  0x00007fc297155700 __libc_start_main (libc.so.6)#012#10 0x0000000000404169 _start (grep)
Oct  7 10:35:12 testserver kernel: traps: grep[7036] general protection ip:7f9e7f999bd8 sp:7ffe486488b0 error:0 in libc-2.21.so[7f9e7f97a000+1b7000]
Oct  7 10:35:12 testserver systemd-coredump: Process 7036 (grep) of user 5000 dumped core.#012#012Stack trace of thread 7036:#012#0  0x00007f9e7f999bd8 pop_fail_stack (libc.so.6)#012#1  0x00007f9e7f99a226 set_regs (libc.so.6)#012#2  0x00007f9e7fa58759 re_search_internal (libc.so.6)#012#3  0x00007f9e7fa5e0d5 re_search_stub (libc.so.6)#012#4  0x00007f9e7fa5e980 re_search (libc.so.6)#012#5  0x0000000000412dea EGexecute (grep)#012#6  0x0000000000404dc2 grepbuf (grep)#012#7  0x0000000000405250 grep (grep)#012#8  0x0000000000405ce2 grepdesc (grep)#012#9  0x00000000004059a4 grepfile (grep)#012#10 0x0000000000405ef9 grep_command_line_arg (grep)#012#11 0x00000000004078fd main (grep)#012#12 0x00007f9e7f99a700 __libc_start_main (libc.so.6)#012#13 0x0000000000403029 _start (grep)
Oct  7 10:40:50 testserver kernel: traps: grep[564] general protection ip:7f1d9246dbd8 sp:7ffccd689830 error:0 in libc-2.21.so[7f1d9244e000+1b7000]
Oct  7 10:40:50 testserver systemd-coredump: Process 564 (grep) of user 5000 dumped core.#012#012Stack trace of thread 564:#012#0  0x00007f1d9246dbd8 pop_fail_stack (libc.so.6)#012#1  0x00007f1d9246e226 set_regs (libc.so.6)#012#2  0x00007f1d9252c759 re_search_internal (libc.so.6)#012#3  0x00007f1d925320d5 re_search_stub (libc.so.6)#012#4  0x00007f1d92532980 re_search (libc.so.6)#012#5  0x0000000000412dea EGexecute (grep)#012#6  0x0000000000404dc2 grepbuf (grep)#012#7  0x0000000000405250 grep (grep)#012#8  0x0000000000405ce2 grepdesc (grep)#012#9  0x00000000004059a4 grepfile (grep)#012#10 0x0000000000405ef9 grep_command_line_arg (grep)#012#11 0x00000000004078fd main (grep)#012#12 0x00007f1d9246e700 __libc_start_main (libc.so.6)#012#13 0x0000000000403029 _start (grep)
Oct  7 10:45:32 testserver kernel: traps: grep[26577] general protection ip:7fc724912bd8 sp:7ffdcd75c6c0 error:0 in libc-2.21.so[7fc7248f3000+1b7000]
Oct  7 10:45:32 testserver systemd-coredump: Process 26577 (grep) of user 5000 dumped core.#012#012Stack trace of thread 26577:#012#0  0x00007fc724912bd8 pop_fail_stack (libc.so.6)#012#1  0x00007fc724913226 set_regs (libc.so.6)#012#2  0x00007fc7249d1759 re_search_internal (libc.so.6)#012#3  0x00007fc7249d70d5 re_search_stub (libc.so.6)#012#4  0x00007fc7249d7980 re_search (libc.so.6)#012#5  0x0000000000412de2 EGexecute (grep)#012#6  0x0000000000404dc2 grepbuf (grep)#012#7  0x0000000000405250 grep (grep)#012#8  0x0000000000405ce2 grepdesc (grep)#012#9  0x00000000004059a4 grepfile (grep)#012#10 0x0000000000405ef9 grep_command_line_arg (grep)#012#11 0x00000000004078fb main (grep)#012#12 0x00007fc724913700 __libc_start_main (libc.so.6)#012#13 0x0000000000403029 _start (grep)
Oct  7 10:50:11 testserver kernel: traps: grep[20072] general protection ip:7f168e573bd8 sp:7fff92adbce0 error:0 in libc-2.21.so[7f168e554000+1b7000]
Oct  7 10:50:11 testserver systemd-coredump: Process 20072 (grep) of user 5000 dumped core.#012#012Stack trace of thread 20072:#012#0  0x00007f168e573bd8 pop_fail_stack (libc.so.6)#012#1  0x00007f168e574226 set_regs (libc.so.6)#012#2  0x00007f168e632759 re_search_internal (libc.so.6)#012#3  0x00007f168e6380d5 re_search_stub (libc.so.6)#012#4  0x00007f168e638980 re_search (libc.so.6)#012#5  0x0000000000412850 EGexecute (grep)#012#6  0x0000000000404c17 grepbuf (grep)#012#7  0x000000000040505b grep (grep)#012#8  0x0000000000405b6b grepdesc (grep)#012#9  0x00000000004057de grepfile (grep)#012#10 0x0000000000405da5 grep_command_line_arg (grep)#012#11 0x00000000004077bb main (grep)#012#12 0x00007f168e574700 __libc_start_main (libc.so.6)#012#13 0x0000000000402ff9 _start (grep)
Oct  7 10:55:41 testserver kernel: traps: grep[13698] general protection ip:7f146e574bd8 sp:7fffd6290b30 error:0 in libc-2.21.so[7f146e555000+1b7000]
Oct  7 10:55:41 testserver systemd-coredump: Process 13698 (grep) of user 5000 dumped core.#012#012Stack trace of thread 13698:#012#0  0x00007f146e574bd8 pop_fail_stack (libc.so.6)#012#1  0x00007f146e575226 set_regs (libc.so.6)#012#2  0x00007f146e633759 re_search_internal (libc.so.6)#012#3  0x00007f146e6390d5 re_search_stub (libc.so.6)#012#4  0x00007f146e639980 re_search (libc.so.6)#012#5  0x0000000000412850 EGexecute (grep)#012#6  0x0000000000404c17 grepbuf (grep)#012#7  0x000000000040505b grep (grep)#012#8  0x0000000000405b6b grepdesc (grep)#012#9  0x00000000004057de grepfile (grep)#012#10 0x0000000000405da5 grep_command_line_arg (grep)#012#11 0x00000000004077bb main (grep)#012#12 0x00007f146e575700 __libc_start_main (libc.so.6)#012#13 0x0000000000402ff9 _start (grep)
Oct  7 10:58:34 testserver kernel: traps: grep[7221] general protection ip:7fca6c910bd8 sp:7ffd8a362510 error:0 in libc-2.21.so[7fca6c8f1000+1b7000]
Oct  7 10:58:34 testserver systemd-coredump: Process 7221 (grep) of user 5000 dumped core.#012#012Stack trace of thread 7221:#012#0  0x00007fca6c910bd8 pop_fail_stack (libc.so.6)#012#1  0x00007fca6c911226 set_regs (libc.so.6)#012#2  0x00007fca6c9cf759 re_search_internal (libc.so.6)#012#3  0x00007fca6c9d50d5 re_search_stub (libc.so.6)#012#4  0x00007fca6c9d5980 re_search (libc.so.6)#012#5  0x0000000000412850 EGexecute (grep)#012#6  0x0000000000404c17 grepbuf (grep)#012#7  0x000000000040505b grep (grep)#012#8  0x0000000000405b6b grepdesc (grep)#012#9  0x00000000004057de grepfile (grep)#012#10 0x0000000000405da5 grep_command_line_arg (grep)#012#11 0x00000000004077bb main (grep)#012#12 0x00007fca6c911700 __libc_start_main (libc.so.6)#012#13 0x0000000000402ff9 _start (grep)

[root@testserver:~]$ stat /usr/bin/grep
  Datei: „/usr/bin/grep“
  Größe: 193144         Blöcke: 384        EA Block: 4096   reguläre Datei
Gerät: 811h/2065d       Inode: 460704      Verknüpfungen: 1
Zugriff: (0755/-rwxr-xr-x)  Uid: (    0/    root)   Gid: (    0/    root)
Zugriff    : 2015-10-07 12:08:21.422053185 +0200
Modifiziert: 2015-10-07 10:58:26.000000000 +0200
Geändert   : 2015-10-07 12:01:45.722041776 +0200
 Geburt    : -

Comment 9 Harald Reindl 2015-10-07 10:12:50 UTC
Created attachment 1080592 [details]
coredump due build

Comment 10 Harald Reindl 2015-10-07 10:45:56 UTC
i can't also on F21 with GCC 4.9.x get a build not ending in 393 as count, no optimizations, -mtune=generic, -mtune=westmere makes all no difference

maybe i hit a different bug or hit it harder then in https://bugzilla.redhat.com/show_bug.cgi?id=1269014#c6 and so i need to split the maillog somehow in pieces to provide something smaller than some hundret MB and finally with as much as anonymized userdata - stay tuned.....

Comment 11 Harald Reindl 2015-10-07 12:39:41 UTC
Created attachment 1080646 [details]
sample logfile triggering the problem

see attachment, anonymized logpart which triggers the bug

[harry@rh:/data/lounge-daten/grep-debug]$ cat test.sh 
#!/usr/bin/bash

grep -P -c 'Blocked by (SpamAssassin|Spamfilter)' ./filtered.txt
grep -P 'Blocked by (SpamAssassin|Spamfilter)' ./filtered.txt | wc -l
[harry@rh:/data/lounge-daten/grep-debug]$ ./test.sh 
1
2

[harry@rh:/data/lounge-daten/grep-debug]$ ls filtered.txt
-rw-rw----+ 1 harry verwaltung 129K 2015-10-07 14:26 filtered.txt

see also:
https://bugzilla.redhat.com/show_bug.cgi?id=1269500

Comment 12 Harald Reindl 2015-10-07 13:23:42 UTC
for what it's worth: when i remove the offending line and anything below i get exactly "393" with "-P -c" which means grep just stop proceeding there

Comment 13 Jaroslav Škarvada 2015-10-09 08:41:10 UTC
Maybe it is different problem. I used generated data, and compared output of the 'grep -P -c' with 'grep -P | wc -l'. Unfortunately I currently don't have the machine to do more testing. I will try to reproduce the problem on different machine.

Comment 14 Fedora End Of Life 2015-11-04 15:20:44 UTC
This message is a reminder that Fedora 21 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 21. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as EOL if it remains open with a Fedora  'version'
of '21'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 21 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 15 Harald Reindl 2015-11-04 15:21:49 UTC
affects F21, F22 as well as F23

Comment 16 Jaroslav Škarvada 2015-11-09 17:42:11 UTC
Thanks for stripped down reproducer and test data. Are you able to reproduce the problem with latest grep-2.22?

So far I have tried different machines from our pool, but I wasn't able to reproduce the problem again (unfortunately I don't have access to machine mentioned in comment 6 any more).

Comment 17 Harald Reindl 2015-11-09 17:44:15 UTC
sadly yes, see me comment at bodhi where i gave positive karma for the latest updates and noted that this still exists, but since it's there for longer no reason to hold back that updates

Comment 18 Harald Reindl 2015-11-09 17:46:04 UTC
BTW: if it's needed i could clone you a virtual machine with Fedora 22 on affected hardware and root-access, ping me private at h.reindl with your public ssh-key and i will forward such a machine with root access on a non-default port

Comment 19 Jaroslav Škarvada 2015-11-09 17:51:51 UTC
(In reply to Harald Reindl from comment #18)
> BTW: if it's needed i could clone you a virtual machine with Fedora 22 on
> affected hardware and root-access, ping me private at h.reindl
> with your public ssh-key and i will forward such a machine with root access
> on a non-default port

Great, thanks, I will look on it. I am currently working on different more prio problem, please give me a week or so to finish it and move to this. Feel free to ping me if no response from me after cca. week.

Comment 20 Jaroslav Škarvada 2015-11-19 16:03:46 UTC
I finally found machine in our pool where the problem is reproducible:
Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz

I will look on it.

Comment 21 Harald Reindl 2015-11-19 18:48:38 UTC
thanks for feedback!

that sort of bugs makes me somehow nervous - depending on CPU wrong counting - well, we know now grep is affected but what else and we don't realize it :-(

Comment 22 Jaroslav Škarvada 2015-11-20 13:54:11 UTC
Just to be sure that I am reproducing the same issue, could you try forcing grep to ascii mode (with the -a switch):

$ grep -aPc 'Blocked by (SpamAssassin|Spamfilter)' ./filtered.txt
2

It seems to resolve the problem for me. The counter seems not to work correctly in combination of PCRE and binary mode, investigating why.

Comment 23 Harald Reindl 2015-11-20 14:27:04 UTC
confirmed

[harry@srv-rhsoft:/data/lounge-daten/grep-debug]$ grep -aPc 'Blocked by (SpamAssassin|Spamfilter)' ./filtered.txt
2

[harry@srv-rhsoft:/data/lounge-daten/grep-debug]$ grep -Pc 'Blocked by (SpamAssassin|Spamfilter)' ./filtered.txt
1

Comment 24 Jaroslav Škarvada 2015-11-26 18:32:12 UTC
Created attachment 1099348 [details]
Proposed fix

Regarding the reproducer from comment 11, the following happens:

- the file is too big to be processed in one step from buffer, thus it's processed in several steps (parts)
- for the first part grep is undecided whether it is text or binary, because it saw only text so far. For non PCRE matchers so it switches to the TEXTBIN_TEXT (text mode), so the bug cannot manifest. This is not the case for the PCRE matcher. With PCRE it continues with the TEXTBIN_UNKNOWN. It's there as performance optimization for PCRE to do multiline search for non binary data.
- it loads the next part of the file into the buffer
- it sees NULLs in the buffer, this means the file is binary, so it switches to TEXTBIN_BINARY.
- in binary mode it stops on the first match
- so it mistakenly stops on the first match and doesn't count the second match
- this first-match-check is overridden in no_quiet mode (when outputting text)

So it's apparently grep bug, but I am unsure how to solve it the right way. The proposed patch just makes the '-Pc' not to stop on the first match, so it counts all matches, but it may be not the right behaviour for binary files. I am forwarding this to upstream for discussion.

Nevertheless this doesn't seem to be architecture dependant, I can reproduce it also on the Core 2 Duo and probably all others. So there may be also different bug.

Comment 25 Jaroslav Škarvada 2015-11-27 11:48:34 UTC
(In reply to Jaroslav Škarvada from comment #24)
> Nevertheless this doesn't seem to be architecture dependant, I can reproduce
> it also on the Core 2 Duo and probably all others. So there may be also
> different bug.

There was a bit confusion regarding this:
- there was probably architecture dependant problem, which I initially reproduced on 'Intel(R) Core(TM) i7-3770 CPU @ 3.40GHz', but it seems it is there no more with current GCC (comment 6).
- I later mixed various grep codebases with various configurations when searched for the suitable machine, which added more confusion

Comment 26 Harald Reindl 2015-11-27 12:02:07 UTC
> but it seems it is there no more with current GCC (comment 6)

hmm - see https://bugzilla.redhat.com/show_bug.cgi?id=1269014#c7

Comment 27 Jaroslav Škarvada 2015-11-27 13:20:44 UTC
Please try the following scratch build adding patch from comment 24. It's not yet in Fedora, I am waiting for upstream, there may be different patch merged.
http://koji.fedoraproject.org/koji/taskinfo?taskID=11994404

Comment 28 Harald Reindl 2015-11-27 13:37:10 UTC
looks good on Intel(R) Core(TM) i7-2600 CPU @ 3.40GHz, see testcase before and after "rpm -Uvh --force grep-2.22-2.fc23.x86_64.rpm"

[harry@rh:/data/lounge-daten/grep-debug]$ ./test.sh
1
2

[harry@rh:/data/lounge-daten/grep-debug]$ ./test.sh
2
2

Comment 29 Jaroslav Škarvada 2015-12-01 13:55:54 UTC
Upstream proposed different patch, but the result is same.

Comment 30 Fedora Update System 2015-12-01 15:38:17 UTC
grep-2.22-3.fc23 has been submitted as an update to Fedora 23. https://bodhi.fedoraproject.org/updates/FEDORA-2015-7cf8dc41da

Comment 31 David H. Gutteridge 2015-12-01 22:04:37 UTC
I can reproduce the issue with grep-2.22-2.fc23 and confirm it's fixed for me with grep-2.22-3.fc23.

Comment 32 Fedora Update System 2015-12-01 22:30:02 UTC
grep-2.22-3.fc23 has been pushed to the Fedora 23 testing repository. If problems still persist, please make note of it in this bug report.
If you want to test the update, you can install it with
$ su -c 'dnf --enablerepo=updates-testing update grep'
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2015-7cf8dc41da

Comment 33 Fedora Update System 2015-12-02 11:23:39 UTC
grep-2.21-6.fc22 has been submitted as an update to Fedora 22. https://bodhi.fedoraproject.org/updates/FEDORA-2015-bee294be57

Comment 34 Fedora Update System 2015-12-02 21:50:12 UTC
grep-2.22-3.fc23 has been pushed to the Fedora 23 stable repository. If problems still persist, please make note of it in this bug report.

Comment 35 Fedora Update System 2015-12-03 16:02:04 UTC
grep-2.21-6.fc22 has been pushed to the Fedora 22 testing repository. If problems still persist, please make note of it in this bug report.
If you want to test the update, you can install it with
$ su -c 'dnf --enablerepo=updates-testing update grep'
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2015-bee294be57

Comment 36 Fedora Update System 2015-12-12 01:53:40 UTC
grep-2.21-6.fc22 has been pushed to the Fedora 22 stable repository. If problems still persist, please make note of it in this bug report.

Comment 37 Harald Reindl 2016-01-06 15:58:01 UTC
sorry, but the latest koji-build re-introduces the problem!

[harry@rh:/data/lounge-daten/grep-debug]$ ./test.sh
1
2

[harry@rh:/data/lounge-daten/grep-debug]$ rpm -q grep
grep-2.22-4.fc23.x86_64

Comment 38 Jaroslav Škarvada 2016-01-06 16:49:29 UTC
Thanks for spotting the regression. Upstream finally used third and different patch for this problem and the effect of our patch was cancelled by backported fix for bug 1219141. I switched to latest upstream patches for both problems and also added built-in test for this issue, so the problem shouldn't re-appear again.

Comment 39 Fedora Update System 2016-01-06 17:07:40 UTC
grep-2.22-5.fc23 has been submitted as an update to Fedora 23. https://bodhi.fedoraproject.org/updates/FEDORA-2016-313013441f

Comment 40 Harald Reindl 2016-01-06 17:12:43 UTC
looks better

i guess "grep-2.21-7.fc22" has the same regression (untested) and a update will follow too, in doubt i can build a testcase for that too (panned anyways next week on our admin/testserver in the office since infrastructure keeps running on F22 for now)

[harry@rh:/data/lounge-daten/grep-debug]$ ./test.sh
2
2

[harry@rh:/data/lounge-daten/grep-debug]$ rpm -q grep
grep-2.22-5.fc23.x86_64

Comment 41 Jaroslav Škarvada 2016-01-06 17:33:55 UTC
Sure, I was aware about the problem in f22, but I wasn't fast enough to release both updates at the same time. In f22 there is different version of grep and the patches required backport. Build-time tests for both problem are also there now.

Comment 42 Fedora Update System 2016-01-06 17:42:09 UTC
grep-2.21-8.fc22 has been submitted as an update to Fedora 22. https://bodhi.fedoraproject.org/updates/FEDORA-2016-d41031d2d0

Comment 43 Fedora Update System 2016-01-07 04:53:22 UTC
grep-2.22-5.fc23 has been pushed to the Fedora 23 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2016-313013441f

Comment 44 Fedora Update System 2016-01-07 05:23:51 UTC
grep-2.21-8.fc22 has been pushed to the Fedora 22 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2016-d41031d2d0

Comment 45 Fedora Update System 2016-01-07 19:52:03 UTC
grep-2.22-5.fc23 has been pushed to the Fedora 23 stable repository. If problems still persist, please make note of it in this bug report.

Comment 46 Marcin Juszkiewicz 2016-01-11 09:41:00 UTC
Now it is broken on aarch64 and ppc64(le).

Comment 47 Jaroslav Škarvada 2016-01-11 11:14:46 UTC
(In reply to Marcin Juszkiewicz from comment #46)
> Now it is broken on aarch64 and ppc64(le).

Thanks for info, I will check.

Comment 49 Jaroslav Škarvada 2016-01-11 17:03:32 UTC
It's also failing with upstream git head on secondary arches. Reported upstream. 
I am going to track the pcre-count test failure on secondary arches in bug 1296842.

Comment 51 Fedora Update System 2016-01-12 10:21:37 UTC
grep-2.21-9.fc22 has been submitted as an update to Fedora 22. https://bodhi.fedoraproject.org/updates/FEDORA-2016-8883879d28

Comment 52 Harald Reindl 2016-01-12 11:18:51 UTC
grep-2.22-6.fc23.x86_64.rpm works fine on Intel
Jan 12 12:16:59 Updated: grep-2.22-6.fc23.x86_64

[harry@rh:/data/lounge-daten/grep-debug]$ ./test.sh
2
2

Comment 53 Fedora Update System 2016-01-13 07:22:18 UTC
grep-2.21-9.fc22 has been pushed to the Fedora 22 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2016-8883879d28

Comment 54 Fedora Update System 2016-01-24 03:18:18 UTC
grep-2.21-9.fc22 has been pushed to the Fedora 22 stable repository. If problems still persist, please make note of it in this bug report.