3

When grepping log files, I often experience that grep does not find matches closer to the end of the file. Example file

For example, running

grep -n "demodulator_process" 2018_12_22_13_04_adfags-modem.log | less

shows up to line 2962 of the file, while the string is occurs further down in the file.

Running

grep -n "Finished" 2018_12_22_13_04_adfags-modem.log

which should catch the lasts lines in the file, does not return anything.

Does anyone know what causes this behavior?

I'm using grep version

--> grep --version 
grep (GNU grep) 3.1

Thanks.

  • 2
    Add the lines in file where the strings you are looking for appear to your question. – Nasir Riley Jan 2 at 23:40
  • 4
    The file is being reported as binary... so ... grep --binary-file=text -n "demodulator_process" 2018_12_22_13_04_adfags-modem.log – RubberStamp Jan 2 at 23:44
  • 2
    Perhaps you have aliased grep to grep -I? what does type -a grep report? – steeldriver Jan 2 at 23:46
  • 3
    Possibly stupid question - are the logs closed? Because you might be looking later and see lines that weren't there when grep ran. – Aaron D. Marasco Jan 3 at 0:23
  • 2
    ... or the fact that you're piping to less-- I assume you paged down to the end? – Jeff Schaller Jan 3 at 1:21
1

While the answer @Crypteya provided is a good practical answer, it may also be useful to understand where the problem areas may be in the log file itself.

Finding the problem areas

First, create a printable ASCII version of the log file:

strings 2018_12_22_13_04_adfags-modem.log > log_modified.txt

Then look at the differences:

diff -u 2018_12_22_13_04_adfags-modem.log log_modified.txt

--- 2018_12_22_13_04_adfags-modem.log   2019-01-02 18:37:53.656721949 -0500
+++ log_modified.txt    2019-01-03 09:49:37.961613556 -0500
@@ -2973,9 +2973,10 @@
 2018-12-22 13:13:07 INFO decoder_process  run                   :  188 -- worker yass-UHF-C    syncSigs 3  packets 1   time 9.66 ms
 2018-12-22 13:13:07 INFO decodeBRMM2      getBinaryData         :  546 -- packet length might be incorrect. number of bits don't fit in bytes
 2018-12-22 13:13:07 ERROR decodeBRMM2      reedSoloCheck         :  610 -- Reed-Solomon FEC failed
-2018-12-22 13:13:07 INFO decoder_process  run                   :  216 -- worker yass-UHF-C    found packet -PPIe�Gy.@ Bit errors: -1
-2018-12-22 13:13:07 INFO decoder_process  run                   :  227 -- worker yass-UHF-C    Bit errors:  -1, Len 5775, Bits destuffed [503, 655, 719, 773, 793, 1344, 1361, 1570, 2298, 2833, 3190, 4239, 4389, 4701, 5370, 5450, 5501], Packet: -PPIe�Gy.@, Split: 3788, Bits w. clipped peaks    0 
-
+2018-12-22 13:13:07 INFO decoder_process  run                   :  216 -- worker yass-UHF-C    found packet -PPI
+   Bit errors: -1
+2018-12-22 13:13:07 INFO decoder_process  run                   :  227 -- worker yass-UHF-C    Bit errors:  -1, Len 5775, Bits destuffed [503, 655, 719, 773, 793, 1344, 1361, 1570, 2298, 2833, 3190, 4239, 4389, 4701, 5370, 5450, 5501], Packet: -PPI
+, Split: 3788, Bits w. clipped peaks    0 
 2018-12-22 13:13:07 INFO decoder_process  run                   :  228 -- worker yass-UHF-C    bytes destuff 01 1E 71 69 B9 3C 48 66 32 B9 1E 33 0A E2 04 23 DE E6 AE C1 BB E3 DE 02 C9 00 14 63 89 A4 1E 0D 77 E2 92 F1 9B 98 A7 58 0C 9D 4E DE 60 7D 26 29 06 E8 8C 0B D3 02 1B 39 9A 01 B1 49 B9 BF D0 03 3E 8B D5 BB 41 15 AF 53 BF 4B 35 9A 40 97 E4 03 43 3F 07 CA 6A 1D 18 41 21 A1 30 04 0E 4E 6A 08 10 A8 84 71 60 CE 01 2D 53 ED DC 36 63 AF C3 5D D7 4D FF 5C 21 85 A4 00 6B BF B2 7F 9A 60 1C AA 21 44 4A 24 90 2C CD 90 02 23 79 FE C5 09 05 02 3B 34 75 B1 0B CB D7 DF B7 05 E7 00 A4 63 79 68 84 14 62 B9 74 2F 44 7A 90 34 64 BB B0 EC AC 9C 16 D8 57 E4 B9 4E 8C 20 B2 20 4B F5 2B 46 40 6D C2 2C 5D 88 46 3F 6A 34 04 33 0D 9D CD CA CB 68 0A 0E 84 D6 21 94 58 A1 04 73 95 A8 D0 F9 01 DD 7B 2B AB 50 F6 E8 D7 81 4C 4B AD 41 30 68 E3 95 73 AF 8A E0 94 05 10 81 13 23 A4 05 2D 0C 72 32 4A 43 16 6A 9D 14 A1 40 5A A5 29 C6 EA C7 16 61 0D D3 01 1D 90 9B 99 EE 41 CA D4 08 C6 58 AB EC 1A F6 02 6D E8 E5 80 47 42 09 0E E0 D6 A6 AD 76 9A 64 80 D3 98 42 8A E8 09 37 41 E3 22 23 C7 82 EA 78 19 E5 A4 A0 0A 4B A5 C6 22 95 91 A7 66 FB 32 E0 D6 75 E6 06 A4 C4 0A 09 85 00 48 A4 54 42 9D 57 C7 64 10 02 5D 6E 3C 71 E3 D6 19 8C 38 94 10 3D A4 A3 66 1C 01 A4 68 81 E2 A0 9F 5F 49 86 FD C2 CE 41 94 A6 28 94 72 A0 11 42 02 80 13 70 4F 54 12 A4 89 55 2B 15 22 03 32 27 00 02 60 04 84 40 00 84 14 C1 3D 46 CB 98 4E 88 31 83 38 B5 22 E2 C4 AB B2 18 65 D3 96 E2 80 FE 14 06 69 6D 9C AE 36 E9 62 97 52 0A 71 54 25 90 0C 06 C8 CE D9 1D CA 3B 02 C6 F6 3C 0E 7A 32 EF C7 90 00 26 60 46 80 5E E2 9C 41 B2 9E 3A 0C 02 59 72 07 31 0A CD 74 0B 38 86 38 41 E2 C4 EB 91 98 20 A1 7F A4 E5 78 95 87 1E 01 32 B0 37 21 45 59 3C 36 59 D0 F6 01 3B 15 E4 69 00 85 04 90 01 59 02 56 02 6D F3 DC 1C 62 90 44 01 2D 46 E0 82 AB A5 1F DD E8 2A D4 9B E8 00 A4 D9 FA E7 34 BA D6 24 52 DA 14 DD 08 63 0E C0 9C 04 40 C9 10 DA 48 3D 42 32 80 37 8E 81 10 8D 21 11 D2 A2 DC 7B A5 C7 32 2A 4F C8 90 34 28 9B 73 05 4B EE 15 41 68 87 75 0A 38 91 C3 69 6B 9D 66 E1 02 6E 88 70 DD 94 62 2A BC D5 4A A2 14 0B 19 A9 80 CA 42 B9 6F 54 18 11 31 64 5B 0E 83 C4 D7 48 81 C4 03 15 5F E8 D9 1A 40 A0 90 58 38 35 23 94 0A 85 C2 2A 07 24 10 13 06 40 1D 66 03 FC A6 14 89 D4 11 3F 3F D5
 2018-12-22 13:13:07 INFO decoder_process  run                   :  244 -- worker yass-UHF-C    packet Error, sending anyway
 2018-12-22 13:13:07 INFO decoder_process  run                   :  259 -- worker yass-UHF-C    sent to Spacelink

As can be seen in the unified diff output, the original log file contains some non-printable ascii characters resulting in the file being identified as binary rather than text. The strings output ignores the unprintable characters and places the next text field on a new line.

What are the non-printable characters?

We can use hexdump to view the hexadecimal and the ASCII side by side. And we know the problem areas occur just after the -PPI printable characters.

cat 2018_12_22_13_04_adfags-modem.log | hexdump -C |grep -A2 PPI

000908c0  6f 75 6e 64 20 70 61 63  6b 65 74 20 2d 50 50 49  |ound packet -PPI|
000908d0  00 65 1a 47 02 79 15 2e  40 18 09 42 69 74 20 65  |.e.G.y..@..Bit e|
000908e0  72 72 6f 72 73 3a 20 2d  31 0a 32 30 31 38 2d 31  |rrors: -1.2018-1|
--
000909d0  5d 2c 20 50 61 63 6b 65  74 3a 20 2d 50 50 49 00  |], Packet: -PPI.|
000909e0  65 1a 47 02 79 15 2e 40  18 2c 20 53 70 6c 69 74  |e.G.y..@., Split|
000909f0  3a 20 33 37 38 38 2c 20  42 69 74 73 20 77 2e 20  |: 3788, Bits w. |

This reveals the location of the mysterious NULLs and several non-printable characters in your original log file.

Upon inspection of the problem lines with an ASCII chart:

ascii

Dec Hex    Dec Hex    Dec Hex  Dec Hex  Dec Hex  Dec Hex   Dec Hex   Dec Hex  
  0 00 NUL  16 10 DLE  32 20    48 30 0  64 40 @  80 50 P   96 60 `  112 70 p
  1 01 SOH  17 11 DC1  33 21 !  49 31 1  65 41 A  81 51 Q   97 61 a  113 71 q
  2 02 STX  18 12 DC2  34 22 "  50 32 2  66 42 B  82 52 R   98 62 b  114 72 r
  3 03 ETX  19 13 DC3  35 23 #  51 33 3  67 43 C  83 53 S   99 63 c  115 73 s
  4 04 EOT  20 14 DC4  36 24 $  52 34 4  68 44 D  84 54 T  100 64 d  116 74 t
  5 05 ENQ  21 15 NAK  37 25 %  53 35 5  69 45 E  85 55 U  101 65 e  117 75 u
  6 06 ACK  22 16 SYN  38 26 &  54 36 6  70 46 F  86 56 V  102 66 f  118 76 v
  7 07 BEL  23 17 ETB  39 27 '  55 37 7  71 47 G  87 57 W  103 67 g  119 77 w
  8 08 BS   24 18 CAN  40 28 (  56 38 8  72 48 H  88 58 X  104 68 h  120 78 x
  9 09 HT   25 19 EM   41 29 )  57 39 9  73 49 I  89 59 Y  105 69 i  121 79 y
 10 0A LF   26 1A SUB  42 2A *  58 3A :  74 4A J  90 5A Z  106 6A j  122 7A z
 11 0B VT   27 1B ESC  43 2B +  59 3B ;  75 4B K  91 5B [  107 6B k  123 7B {
 12 0C FF   28 1C FS   44 2C ,  60 3C <  76 4C L  92 5C \  108 6C l  124 7C |
 13 0D CR   29 1D GS   45 2D -  61 3D =  77 4D M  93 5D ]  109 6D m  125 7D }
 14 0E SO   30 1E RS   46 2E .  62 3E >  78 4E N  94 5E ^  110 6E n  126 7E ~
 15 0F SI   31 1F US   47 2F /  63 3F ?  79 4F O  95 5F _  111 6F o  127 7F DEL

We can write out the problem line:

00   65  1a  47  02  79  15  2e  40  18
---  --- --- --- --- --- --- --- --- ---
NULL e   SUB G   STX y   NAK .   @   CAN

or:

\0 e ^Z G ^B y ^U . @ ^X

grep and NULL

To answer why grep doesn't work well with NULLs in an otherwise ASCII file, it's necessary to understand that strings in the C language are typically stored as linked lists and terminated with a NULL. So, removing the NULLs from the input into grep allows the algorithm to correctly process each line.

3

grep -a could work:

from man grep:

-a, --text equivalent to --binary-files=text

e.g. grep -a -n "demodulator_process" 2018_12_22_13_04_adfags-modem.log

Alternatively you could remove null characters prior to the search so that the file isn't treated as a binary file. (This won't modify the file, only modify the contents to be searched).

cat 2018_12_22_13_04_adfags-modem.log | tr -d '\000' | grep "demodulator_process"

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.