0

I'm currently trying to use awk to grab items from massive log files matching specific criteria. Essentially, I need to be able to pull the entire command, marked by a transaction ID, based on information contained within the command (which can be and regularly is in a different place on the command). Example log below (highly condensed). Note that the sent command can either be a one liner, or spread across many lines (as in 00001 and 00002), and the commands aren't necessarily grouped together, there can be other IDs interspersed between:

(NAME, 486, 00001) <xml><command:name>target</command:name></xml>
(NAME, 486, 00001)   <response>
(NAME, 486, 00001)     <result code="200">
(NAME, 486, 00001)       <msg>Command failed</msg>
(NAME, 486, 00001)     </result>
(NAME, 486, 00001)  </response>
(FOO, 486, 00002) <xml>
(FOO, 486, 00002) <differentCommand:name>This is another sent command</differentCommand:name></xml>
(FOO, 486, 00002) </xml>
(FOO, 486, 00002)   <response>
(FOO, 486, 00002)     <result code="400">
(FOO, 486, 00002)       <msg>Command completed successfully</msg>
(FOO, 486, 00002)     </result>
(FOO, 486, 00002)  </response>
(ANOTHERNAME, 486, 00003) <xml><command:name>target</command:name></xml>
(ANOTHERNAME, 486, 00003)   <response>
(ANOTHERNAME, 486, 00003)     <result code="400">
(ANOTHERNAME, 486, 00003)       <msg>Command completed successfully</msg>
(ANOTHERNAME, 486, 00003)     </result>
(ANOTHERNAME, 486, 00003)   </response>
(FOO, 486, 00004) <xml>
(FOO, 486, 00004) <command:name>This is another sent command</command:name></xml>
(FOO, 486, 00004) </xml>
(FOO, 486, 00004)   <response>
(FOO, 486, 00004)     <result code="400">
(FOO, 486, 00004)       <msg>Command completed successfully</msg>
(FOO, 486, 00004)     </result>
(FOO, 486, 00004)  </response>

Essentially, I'd want to return the entirety of command:name inclusive of the response (the 5 digit number in parens is the transaction ID), but only where it was successful (result code="400").

This is what I have so far:

BEGIN { FS="[(,)]"; }
$4 ~ "<command:name" { id[$3] = $3 }

{ for (i in id) {
        if ($3 == i) {
                if ($5 ~ "Command completed success")
                        success[i] = i;
                }
        }
}

$4 in success { print $0 }

But obviously this won't go back up to grab the rest of the entry once it finds a success. It only returns:

(ANOTHERNAME, 486, 00003)       <msg>Command completed successfully</msg>
(ANOTHERNAME, 486, 00003)     </result>
(ANOTHERNAME, 486, 00003)   </response>
(FOO, 486, 00004)       <msg>Command completed successfully</msg>
(FOO, 486, 00004)     </result>
(FOO, 486, 00004)  </response>

I tried putting a loop in the BEGIN statement, but it takes a very long time, and I run into memory issues trying to use an array of the size it becomes (these files are over 1 GB).

What I'm hoping to return would be:

(ANOTHERNAME, 486, 00003) <xml><command:name>target</command:name></xml>
(ANOTHERNAME, 486, 00003)   <response>
(ANOTHERNAME, 486, 00003)     <result code="400">
(ANOTHERNAME, 486, 00003)       <msg>Command completed successfully</msg>
(ANOTHERNAME, 486, 00003)     </result>
(ANOTHERNAME, 486, 00003)   </response>
(FOO, 486, 00004) <xml>
(FOO, 486, 00004) <command:name>This is another sent command</command:name></xml>
(FOO, 486, 00004) </xml>
(FOO, 486, 00004)   <response>
(FOO, 486, 00004)     <result code="400">
(FOO, 486, 00004)       <msg>Command completed successfully</msg>
(FOO, 486, 00004)     </result>
(FOO, 486, 00004)  </response>

I wonder if what I'm trying is even possible in awk? I've been trying to figure out which tool to use for this task for some time now, and awk certainly seems the best as far as I can tell (short of having to use Python). Speed is my main concern, only today's files are available in plain text format (so those are fast enough), but the rest are gzipped (so I'm doing zcat filename | awk -f test.awk) - I'm trying to avoid having to read the file multiple times, and they're too big to be stored in memory.

7
  • 1
    FYI: python is a much better and faster language than shell for processing text (shell shouldn't be used at all for that job), but both awk and perl are far better choices than python - both will be many times faster than python (typically at least 10 or 20 times faster, depending on algorithm).
    – cas
    Commented Nov 3, 2022 at 0:48
  • 1
    How commonly is XML in use as a logfile format? Do you have raw logfiles you can parse instead? (Thinking here you might be have an option of tackling a smaller file...). Commented Nov 3, 2022 at 1:51
  • @cas that's good to know, thanks - I've started learning Perl (this isn't the only parsing of these files I need to do)
    – Brickscrap
    Commented Nov 9, 2022 at 13:47
  • 1
    @jubilatious1 these are raw log files, there aren't smaller files I can deal with unfortunately
    – Brickscrap
    Commented Nov 9, 2022 at 13:47
  • Thanks. I know Raku has a streaming JSON parser (JSON::Stream), but I don't know if it has a streaming XML parser. Commented Nov 10, 2022 at 5:48

1 Answer 1

0

You can use </response> as the end-of-record marker. For example:

$ awk -F'[ )]' '{record[$3] = record[$3] "\n" $0};

                /<\/response>/ {
                  if (record[$3] ~ /completed successfully/) {
                    # optional: remove leading newline if you don't want
                    # a blank line before each output record:
                    # sub(/\n/,"",record[$3])

                    print record[$3]
                  };
                  delete record[$3]
                }' input.log 

(FOO, 486, 00002) <xml>
(FOO, 486, 00002) <differentCommand:name>This is another sent command</differentCommand:name></xml>
(FOO, 486, 00002) </xml>
(FOO, 486, 00002)   <response>
(FOO, 486, 00002)     <result code="400">
(FOO, 486, 00002)       <msg>Command completed successfully</msg>
(FOO, 486, 00002)     </result>
(FOO, 486, 00002)  </response>

(ANOTHERNAME, 486, 00003) <xml><command:name>target</command:name></xml>
(ANOTHERNAME, 486, 00003)   <response>
(ANOTHERNAME, 486, 00003)     <result code="400">
(ANOTHERNAME, 486, 00003)       <msg>Command completed successfully</msg>
(ANOTHERNAME, 486, 00003)     </result>
(ANOTHERNAME, 486, 00003)   </response>

(FOO, 486, 00004) <xml>
(FOO, 486, 00004) <command:name>This is another sent command</command:name></xml>
(FOO, 486, 00004) </xml>
(FOO, 486, 00004)   <response>
(FOO, 486, 00004)     <result code="400">
(FOO, 486, 00004)       <msg>Command completed successfully</msg>
(FOO, 486, 00004)     </result>
(FOO, 486, 00004)  </response>

This works similarly to the sed+perl & sed+awk versions below, but it constructs each record itself by appending each line (preceded by a newline) to the appropriate element (i.e. the id number) of an array called record. When it sees a </response> line, it prints the element if it matches "completed successfully" and then deletes that element.

This will be a fair bit slower than the sed + awk or sed + perl versions (because it has to append each input line to an element of the array - which uses significantly more CPU power than sed just inserting a blank line every so often), and use a little more memory (because each record stays in memory until there is a </response> line for it), but not excessively so....it keeps each record in memory only as long as needed and then deletes it.

This version should, however, work even if the records for any given id are interleaved with records for other ids.

Here's a perl equivalent:

perl -F'[\h)]' -e '
  $record{$F[2]} .= $_;

  if (/<\/response>/) {
    if ($record{$F[2]} =~ /completed successfully/) {
      # print blank line between records
      print "\n" if $not_first_record++;

      print $record{$F[2]}
    }
    delete $record{$F[2]};
  }' input.log

My testing (with a 120 MB input file containing 100,000 copies of your sample data) indicates that the awk version is almost twice as fast. The awk version ran in around 4.6 seconds on my test system (an ancient AMD Phenom II 1090T), while the perl version took about 7.4 seconds.

Update

Here's an optimised perl version:

Instead of using a regex matching either horizontal whitespace or a close-parenthesis ([\h)]) as the field separator, it uses the perl default of white-space separation. It extracts the key for each record from the third field and then chops off the last character (the )).

This version runs in about 3.9 seconds, almost twice as fast - showing that there's a huge performance penalty when using a regex for the -F auto-split pattern.

BTW, I tried using an indexed array for the record instead of an associative array (i.e. @record with numeric indices rather than %record with string keys) but it made no noticeable difference in performance. I also tried using the index() function instead of a regex match (index($record{$key},"completed successfully") instead of $record{$F[2]} =~ /completed successfully/) but this made no noticeable performance difference, either.

perl -ane '
  chop($key = $F[2]);
  $record{$key} .= $_;

  if (/<\/response>/) {
    if ($record{$key} =~ /completed successfully/) {
      print "\n" if $not_first_record++;
      print $key, $record{$key};
    }
    delete $record{$key}
  }' input.log

The same optimisation improves awk's performance too, although not as dramatically.

awk doesn't have a chop() function but substr() can be used to do the same thing.

awk '{
       key = substr($3, 1, length($3)-1);
       record[key] = record[key] "\n" $0
     };

     /<\/response>/ {
       if (record[key] ~ /completed successfully/) {
         sub(/^\n/,"",record[key])
         print record[key]
       };
       delete record[key]
     }' input.log

This version runs in about 3.5 seconds (about 30% faster than the previous awk version's 4.6 seconds).

Overall, the updated awk and perl versions are much closer in performance, but awk is still around 12% faster.

Small changes to the code can make very large differences in performance.


Alternatively:

Are your log entries always neatly separated by id like that or are they interleaved with other ids?

If they are neatly separated, one of the easiest methods is to use sed to break it up into "paragraphs" (i.e. separated by one or more blank lines) by inserting a blank line BEFORE each <xml> line.

Then pipe sed's output into either awk or perl to read the log in "paragraph mode". For awk, set RS="" in the BEGIN block (or with the -v option), in perl use the -00 command-line option. Then your awk or perl script only has to check if the record contains "completed successfully". If it does, print the record:

This should run noticeably faster and use less memory than the awk-only version above...but only works corrrectly if the records aren't interleaved with other records.

$ sed '/) <xml>/i\\n' input.log |
    perl -00 -ne 'print if /completed successfully/m'
(FOO, 486, 00002) <xml>
(FOO, 486, 00002) <differentCommand:name>This is another sent command</differentCommand:name></xml>
(FOO, 486, 00002) </xml>
(FOO, 486, 00002)   <response>
(FOO, 486, 00002)     <result code="400">
(FOO, 486, 00002)       <msg>Command completed successfully</msg>
(FOO, 486, 00002)     </result>
(FOO, 486, 00002)  </response>

(ANOTHERNAME, 486, 00003) <xml><command:name>target</command:name></xml>
(ANOTHERNAME, 486, 00003)   <response>
(ANOTHERNAME, 486, 00003)     <result code="400">
(ANOTHERNAME, 486, 00003)       <msg>Command completed successfully</msg>
(ANOTHERNAME, 486, 00003)     </result>
(ANOTHERNAME, 486, 00003)   </response>

(FOO, 486, 00004) <xml>
(FOO, 486, 00004) <command:name>This is another sent command</command:name></xml>
(FOO, 486, 00004) </xml>
(FOO, 486, 00004)   <response>
(FOO, 486, 00004)     <result code="400">
(FOO, 486, 00004)       <msg>Command completed successfully</msg>
(FOO, 486, 00004)     </result>
(FOO, 486, 00004)  </response>

Or using awk:

sed '/) <xml>/i\\n' input.log | awk -v RS='' '/completed successfully/'

The output from this version is almost the same, but without a blank line between each output record.

Personally, I find the blank line between each output record to be useful, because it makes it easier to further process the output if necessary, as it's already in "paragraph mode". Of course this is just a subjective preference.


9
  • So the records are mostly together, but the server is load-balanced, and the log file is usually split across multiple files, and they're not necessarily in order (currently I just zcat for the filename across multiple folders). I meant to mention the order in my original question, will update it
    – Brickscrap
    Commented Nov 2, 2022 at 13:45
  • Using the closing response tag as the end marker is a great idea though, and likely something I can work with. Think I still run into issues where records are interspersed with each other though, or where they're spread across multiple files (though the latter here I'm not overly concerned about)
    – Brickscrap
    Commented Nov 2, 2022 at 13:51
  • You can always give multiple filenames to awk, it will just process them one after another. or pipe from zcat, or find ... -exec zcat -f {} + | awk '...', and awk will process one continuous stream of stdin (BTW, with -f, zcat acts like plain cat for any uncompressed files). Interleaved records shouldn't be a problem even with multiple input files, each record will be held in memory (in the records array) until a </response> line is seen for that record id - that won't change just because a record happens to begin in one input file and end in another.
    – cas
    Commented Nov 3, 2022 at 0:18
  • I've just tried the first suggestion here, and it works perfectly, I can filter down on the results of this further, thank you!
    – Brickscrap
    Commented Nov 9, 2022 at 14:07
  • Is there a faster way to do the awk-only version entirely in Perl? I've used a2p and tweaked the script to function basically identically, but it actually appears to be slower than just straight awk...
    – Brickscrap
    Commented Dec 8, 2022 at 15:26

You must log in to answer this question.

Not the answer you're looking for? Browse other questions tagged .