Real-World Searching

This chapter uses nothing new. It takes everything so far and shows how it is actually used, on three jobs you will meet: reading a server log, hunting through a codebase, and auditing configuration files. In each, the work goes the same way: look at the data, ask a narrow question, read the answer, refine the question. The pipelines get long, but each stage is a single idea from an earlier chapter.

The Practice Data

Paste this into an empty folder. It makes a request log (service.log, plus one rotated and compressed older log), a small project folder (repo) and a few configuration files (etc).

The project folder looks like this:

Job 1: Reading a Server Log

Each line of service.log has a date, a time, a level, a request id (req=...), the request, a status, how long it took and sometimes a message. The first question is always “what is in here?”:

Eleven INFO, six ERROR and three WARN. (-o, sort, uniq -c, Chapter 4.) Now the questions you would actually ask.

What went wrong between 09:15 and 09:18?

Because the time is written in a fixed-width form, a window can be a pattern. Minutes 15 to 18 are 1[5-8]:

That works when the window lines up with the digits. For an awkward one, such as 09:17:30 to 09:21:10, a pattern gets ugly and awk is better, because fixed-width times compare correctly as text. Here the same answer both ways:

Both depend on every line having the same layout. A line with a different date format would slip through either one without a warning.

Follow one request

The request id ties lines together. Request f6a8 failed, was retried and failed again:

Note the retry line, which says INFO even though it belongs to a failing request: searching only for ERROR would have missed that context. When ids could be prefixes of longer ids, use -w.

What kinds of thing fail?

Take only the error lines, keep just method, path, status, and count:

Two logins failing with 500, two checkouts with 500 and two 404s. The two kinds of 500 matter more than the 404s, and now they are visible at a glance.

What was slow?

Pull out the number after took=, keep those over a second, and sort (the \K trick from Chapter 5):

Without -P, a time of four or more digits is a time of a second or more, and you can see the whole line:

(cut -c1-80 shortens long lines to fit.) Both agree there are five slow requests.

The rotated logs

Old logs are compressed. zgrep is grep for .gz files: it reads the compressed file without unpacking it, and takes the same options. (It was present on both machines.)

The first counts the errors in yesterday's log. The second searches the current and the rotated log together: seven errors in all. -h keeps the file name from being added when there are two files.

Job 2: Hunting Through a Codebase

Searching a project has two problems the log did not: most of the files are not yours (vendored libraries, build output, .git) and some of them are not text. First, the search with no restrictions, with the lines cut short:

Eight hits for TODO. Four are the team's own notes in the source and the tests; the other four are noise: the .git folder, third-party code in node_modules, a binary file and the generated bundle in dist. (Under 3.11 the binary line reads grep: repo/assets/logo.bin: binary file matches and comes first, because it is on standard error.) Apply the habits from Chapter 2 (-I, --exclude-dir) and look for the markers as whole words:

The first line is the minified file in dist: it is generated, it is one huge line, and it is not worth reading. (This is why cut is at the end of the pipeline: without it that single line would fill the screen.) Exclude the build folder as well:

Six notes (four TODO, one FIXME and one HACK) in four files. Count them by kind, and by file:

When every line is long, -o with a bounded tail shows the note and a little after it. .\{0,15\} means “up to 15 more characters”:

Looking for secrets

A search for secrets finds candidates, not proof. Every search below prints only file and line (cut -d: -f1,2 removes the rest of the line), so the secret itself never lands on your screen or in your shell history's output. A known key format first, an AWS access key id (AKIA and sixteen capitals and digits):

Then the shape of an assignment, password = "something" or secret_key = '...', in either kind of quote, any case:

Four hits, and they are not equally interesting. settings.py is a real candidate. db.py too, though its other line reads the host from the environment, which is the right pattern and does not match. The one in tests is probably a harmless test value, and the one in dist is the minified bundle again. Someone has to look at each. The pattern also misses a password built another way, so finding nothing proves nothing.

A private key announces itself with a header line. It starts with dashes, so the pattern must be given with -e (Chapter 1), and -l is enough since you want to know which file:

Who still uses the old function?

Before removing legacyParse, find every use. Whole word, only JavaScript files, and not the vendored code:

One call in app.js and three mentions in util.js (the comment, the definition and the export), so only one real caller remains. The count per file gets you a to-do list for the clean-up.

Job 3: Auditing Configuration Files

Configuration files are mostly comments and blank lines, and the setting you care about may appear in a comment, in a different file or not at all. First, the file as the program sees it: no comments, no blank lines.

[[:space:]]* allows indentation before the comment mark, and the second pattern adds ; because that file uses semicolons for comments. Notice that the inline comment on the PasswordAuthentication line survived: only lines that start with a comment are removed.

Find a setting everywhere

Anchor at the start of the line (so a comment does not count) and ignore case (the keys are not case-sensitive):

Both are set to yes, which is the opposite of what you want on a server.

Which files do not set it?

-L lists the files with no match (Chapter 2). The obvious try is misleading:

It lists only sshd_config, but app.dev.ini does not set debug either: it merely contains the word, in log_level = debug. A search for the setting has to say it is the start of a line and followed by an equals sign:

The same idea with -c gives a count per file, which is the quickest overview (1, 1 and 0):

And the files where it is set to something dangerous:

An audit you can run again

Put the rule in a function and the expectations in a list. For each setting there are three outcomes, and they are different problems: it is right, it is set to the wrong value, or it is not set at all (the default applies):

Read the result carefully. PermitEmptyPasswords is MISSING because the only line for it is commented out, and the audit says so rather than passing it. The debug setting passes in production, fails in staging, and is missing in development. A function like this is the start of a real configuration check, and because it uses grep -q (Chapter 1) it also works in a script: it can count the FAIL lines and exit with a status.

$2 and $3 are put into the pattern as they are, which is fine for simple names and values, and wrong for anything with regular-expression characters in it. (Chapter 6: text and patterns are different things.)

Habits That Carried Through All Three

• Build the pipeline one stage at a time. Run the grep, read its output, then add the next stage. A long pipeline that does not work is much harder to debug than a short one that does.
• Narrow the data before narrowing the pattern. --exclude-dir, -I, --include and anchoring at the start of the line removed more noise than any clever pattern did.
• Count, then look. uniq -c and -c tell you whether a problem is one line or two hundred before you read any of them.
• Treat the result as candidates. Searches find what they are told to find. The test-file password and the minified bundle were both “correct” hits and neither was a problem.
• Keep secrets off the screen. Print where, not what.
• Save what worked. The audit function is more useful as a file in your scripts folder than as something you will retype next month.

Hands-On Exercises