Take the 2-minute tour ×
Unix & Linux Stack Exchange is a question and answer site for users of Linux, FreeBSD and other Un*x-like operating systems.. It's 100% free, no registration required.

I am currently working on analyzing the performance of an application. I've starting by looking at the logs generated by our application and identifying the business logic tasks that are taking more than acceptable time to execute.

A snippet from the log file looks something like :

2014-07-02 18:03:20,269 INFO  [ROOT] - Task1. xmlRecord Id :35165 processed
2014-07-02 18:05:20,269 INFO  [ROOT] - Task1. xmlRecord Id :35162 processed
2014-07-02 18:15:20,269 INFO  [ROOT] - Task1. xmlRecord Id :35164 processed
2014-07-02 18:20:20,269 INFO  [ROOT] - Task2. xmlRecord Id :35165 processed

My requirement is to find the total amount of time spent on executing each task. For instance, the amount of time spent on Task2 for xmlRecord 35165 = End time for Task 2 for xmlRecord 35165 - End Time for Task 1 for xmlRecord 35165.

For this reason, I want a way to group all the log statements that have the same xmlRecord Id to be grouped together as shown below :

2014-07-02 18:03:20,269 INFO  [ROOT] - Task1. xmlRecord Id :35165 processed
2014-07-02 18:20:20,269 INFO  [ROOT] - Task2. xmlRecord Id :35165 processed
2014-07-02 18:05:20,269 INFO  [ROOT] - Task1. xmlRecord Id :35162 processed
2014-07-02 18:15:20,269 INFO  [ROOT] - Task1. xmlRecord Id :35164 processed

If I can group all the log statements as shown above, I will quickly be able to see that it took Task2 17 minutes to process xmlRecord 35165.

Note that the logs that I have shown here are not the exact logs that my application prints but just a sample. I want to be able to group all log statements such that logs for a particular XML id are always one after another.

I'm a bit rusty with the shell and would appreciate it if someone can point me to a one liner or a script that already does this so I don't waste time reinventing the wheel.

share|improve this question

2 Answers 2

As a starter, why not sort on the xmlRecord Id column? :-

sort -k 9 -o <out.log> <in.log>

That should group them together in numerical order. If you want to sort by Task too, then it will probably involve an awk script or similar.

How this works

The sort command can sort data in a variety of ways, in this case we're sorting it based on the value in the 9th column. It will use a standard alphanumeric sort unless otherwise directed.

.... -k 9 ....

The other arguments in the example are just to specify what input file to use (your log file) and a new file to output the results to, -o <out.log>.

share|improve this answer
    
I don't need the Task at the moment. The xmlRecord id should be sufficient for now. The example that I gave in my question is just a sample. If it is not too much to ask for, can you explain the one liner so I can tweak it the way I want and other community members can find this answer to be useful for them as well. –  bot Jul 3 at 9:32
1  
@slm - Thanks! You just beat me to it with the "How this works" –  garethTheRed Jul 3 at 9:38
    
@garethTheRed - feel free to change it, was just helping the OP out 8-) –  slm Jul 3 at 9:43

If you have enough memory to load the whole file, try:

$ perl -ane '
    push @h, [$F[1],(split(/:/,$F[8]))[1],$_];
    END {
        print map { $_->[2] }
              sort { $b->[1] <=> $a->[1]
                     ||
                     $a->[0] cmp $b->[0]
                   }
              @h;
    }
' file
2014-07-02 18:03:20,269 INFO  [ROOT] - Task1. xmlRecord Id :35165 processed
2014-07-02 18:20:20,269 INFO  [ROOT] - Task2. xmlRecord Id :35165 processed
2014-07-02 18:15:20,269 INFO  [ROOT] - Task1. xmlRecord Id :35164 processed
2014-07-02 18:05:20,269 INFO  [ROOT] - Task1. xmlRecord Id :35162 processed

Explanation

  • While processing the file, we create an array @h, each of its elements is an array ref. Each array ref contains three element:

    • The time appears in log file, like 18:03:20,269
    • The XML record ID
    • The whole log entry
  • Final, we print the result with the condition:

    • sort by XML record ID first $b->[1] <=> $a->[1], reversely
    • If ID is equal, we compare by the time appear in log $a->[0] cmp $b->[0]
share|improve this answer
    
I have enough memory to load the whole file but the example that I gave in my question is just a sample. If it is not too much to ask for, can you explain the script so I can tweak it the way I want and other community members can find this answer to be useful for them as well. –  bot Jul 3 at 9:29

Your Answer

 
discard

By posting your answer, you agree to the privacy policy and terms of service.

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