1

I am currently trying to build a script that reads all relevant lines from a ( or better, several) server logs and presents them in order. I am new to shell scripting and therefore make a lot of mistakes but now I am getting to a point where my script is so slow that it is not functional.

Here is my problem. I am first identifying a number of records by an errorcode. The line with that errorcode is a unstructured xml. In order to get the other lines associated with that error, I need to find another tag in the XML which holds an ID. That ID is matched on another line which has a timestamp and a thread or task number associated. And with those two values I could theoretically get all lines associated with my error, by looking for all lines with my thread number that are in "proximity" to my error message. In theory, as the file is 150MB large.

I have therefore build code that looks like this :

grep -c to get the number of errors; grep every line that has that error in it, write it in a file with sed, go over that file and find the ID, write it in an array.

Then I will do a for loop over the IDs and

  • find the line with the ID, the task and a timestamp using grep over the initial file
  • save task and timeline into variables
  • and then loop again with read over the original file to find every line with my task and a timestamp that is close in seconds to my reference.

...and here it simply dies of slowness.

Doing seds in a loop of greps seems to not be ideal but i haven't found a tool to read a file from a specific point, say, only use lines x-y or something similar.

As the relevant lines do not start with either the line with my Errorcode or the line with my ID and Task, and several not relevant lines could be within them, I feel like I have to find them all using some form of grep. I know the text of the first and the last line but I have not found a way to use that to my advantage either.

Any help is appreciated, thanks.

Edit: Yes, sorry, was a bit too vague. I have now increased the performance significantly by reducing the number of external program calls. What I did before was something like:

while read Buffer; do

  TimeStamp=$(echo $Buffer | sed 's/blabla(Timestamp)blabla/\1/g')
  [ TimeStamp -ge CompareStamp ] || continue
  echo $Buffer >>./mylog
done

So, I was looking into every line and checked the timestamp in that line whether it was close in relation to my saved timestamp. That is ridiculously slow. I substituted that code with 3 greps that only compare the timestamp part of the line and see if it fits the second of my reference or the second before or after. This works, it's just super ugly. Plus I cannot guarantee that I find just lines for my reference, as the server could process more then one case with that task in 3 seconds.

My logs look like this:

timestamp first entry task blabla
timestamp blabla task blabla
timestamp blabla task blabla
timestamp blabla task reference
timestamp blabla task blabla
timestamp blabla task blabla
<xml><error>error</error></error>
timestamp blabla task blabla
timestamp last entry task blabla

I know what last and first entry is, so I could search for it. Those blocks with identical tasks are repeated before and after this one in the logfile and lines of other tasks could be within that block as well. So my first step is to get all lines with that task into a separate file, to grep less data and to not worry about other tasks.

So in normal programming, I would now read line by line and check if it is a first entry, and always save the position of my last first entry, then upon finding my reference I would now go back to the position I saved and read every line until I would find the last entry. Is there a way to do something to that effect with shell without slowing the script down to human speed again?

Edit2: Okay, here is most of it, i have just removed the regular expressions and searchstrings:

grep 'Errorcode' logfile >> ./grablog
NumOfErrors=$(grep -c 'Errorcode' grablog)

AllPrimaryReferences=($(sed -r 's/^.*(<Referencetag>)([^<]*)(<\/Referencetag>).*$/\2/g' grablog))  

j=0
for ((i=0;i<NumOfErrors;i=i+2))
do

    Reference=$(grep  'blablablabla = '${AllPrimaryRefernces[i]} logfile)
    TimeStamp=$(echo "$Reference" | sed -r 's/^ganze Zeile/timestamp/g')

    AllTasks[j]=$(echo "$Reference" | sed -r 's/ganze Zeile/Reference/g')

    grep "${AllTasks[j]}" logfile >>./tempfile


    CompTimeStamp=$(date -d "$TimeStamp" +%Y-%m-%d' '%X)
    grep 'CompTimeStamp' tempfile >>./output


    rm tempfile
    let j++
done

rm grablog
´´´
15
  • 3
    Your question is very vague and I don't think it is answerable at all without some sample input and expected output. Please try to update the question to address a very specific problem and include the actual code you are using.
    – jesse_b
    Nov 14 '19 at 16:13
  • Very wild guess would be to look into logtail or equivalents. As a "tool to read a file from a specific point", assuming that you want a cursor pointing to the last read offset. Or, assuming you just want to process from line N to line Q, you can probably use some combination of tail -$Q | head -$N | <your-code>.
    – SYN
    Nov 14 '19 at 16:30
  • Although there are quite a few options to improve shell scripting performance (like e.g. doing most things in a single (or a few) awk invocations which in turn do not call commands for the string processing for instance :) ), large files with XML are really not a recommendable use-case for shell scripting. Consider advancing to another scripting language outside the classical "shell script" e.g. Perl. For processing large XMLs I have also made very good experiences with Java+SAX.
    – linux-fan
    Nov 14 '19 at 21:02
  • If there already is a program and/or library that knows how to parse that log format, I'd suggest you go with that. Otherwise, I wouldn't parse logs with shell scripting if my life depended on it. As said before, use a programming language of your choice, you will be a happier person.
    – schaiba
    Nov 15 '19 at 8:59
  • 1
    Your example input doesn't seem to show these lines grouped by ID that you mention. We can't help if we're working from an incorrect data structure. Please provide a sample of input that matches your real world environment. Change the text of the messages by all means but please show the correct structure and layout.
    – roaima
    Nov 15 '19 at 13:32
0

There are a few parts of your script that seem wasteful, and could be rearranged in the name of efficiency:

Building an array

grep 'Errorcode' logfile >> ./grablog
NumOfErrors=$(grep -c 'Errorcode' grablog)

AllPrimaryReferences=($(sed -r 's/^.*(<Referencetag>)([^<]*)(<\/Referencetag>).*$/\2/g' grablog))  

You've used that "NumOfErrors" later as the end-condition, with a +=2, while looping through the array. You could instead access the array's length directly via ${#arrayname[@]}.

That means you'd only have to read grablog once, or even better, can read from a pipeline, eliminating the temporary file:

AllPrimaryReferences=( $(grep 'Errorcode' logfile | sed -r '...' | uniq ) )
NumOfRefs=${#AllPrimaryReferences[@]}

The uniq should remove the duplicate entries, instead of using +=2 to skip them. I'm assuming they're always paired up next to each other (which I can't confirm as I can't see the log file). If not, you could add a sort before the uniq, but that's also going to be slow if there are many entries.

The part of the script inside the loop is where more attention should be focused, though.

Extracting variables with sed

You're concerned that running sed twice every loop is slow. Some ways you might avoid this are:

Combining into one sed

Can you pipe the whole line through a single sed command, that extracts both variables, into an array?

ts_task=( $(echo "$Reference" | sed 's/\(timestamp_regex\).*\(task_regex\)/\1 \2/' ) )
timestamp="${ts_task[0]}"
task="${ts_task[1]}"

Using bash substitutions

Perhaps you don't need sed at all, and can extract the substrings you need from $References with parameter expansion. eg. to extract everything before the first space:

timestamp=${References%% *}

Using a named pipe

If you're concerned that starting sed is the slow bit, you could start it in the background, before the loop starts, and used named pipes to communicate with the main loop. This can get fiddly, as you need to remember which processes are hanging on read/write and background them or wait for them appropriately.

Reading the entire input file, twice, each time round the loop

This is likely to be the slowest part, and where there is the most potential for improvement.

Extracting the details from the Reference

You mention, in comments, that there's only one blablabla line per reference. That means that the first grep is looking through the whole input file, and stopping at the match; then next time round, starting from the beginning again to find the next one.

If there's only one such line for each Reference, perhaps the whole "building an array" step was unnecessary, and you can feed the loop directly:

grep 'blablablabla = ' logfile | # match each line that defines a primary reference
  sed '...' |                    # command to extract just the timestamp and taskname
  while read ts task ; do        # assign the two required variables

    # use ts and task to extract everything as before

  done

This means that the first of those two greps is now outside the loop, so it only runes once.

Filtering the results

You're dumping a subset of lines to tempfile, then running a second grep over the results. As before, you can avoid using temporary files by combining both steps into a pipeline.

grep "$task" logfile | grep "$timestamp" >> output

or if you know enough about the full line's format

grep "$timestamp <match other part of line> $task" logfile >> output

The whole algorithm

Even with all these improvements, the bottleneck is likely to be that you're rereading the whole logfile, and examining every line in it again, for every reference/task. That's appropriate when the required lines can appear anywhere in the logfile, in any order -- it's a brute-force approach to finding every line, so it's going to take a long time.

But you've hinted that there are structures and context("the first and the last line", "first entry") that would allow a smarter approach. If you know something more about the structure/order of the input file, you can probably take further shortcuts to avoid the duplicated effort.

You asked how to "save the position" and "go back to the position I saved". grep -n will report the line number of each match, and the tail(1) command can skip a number of lines from the beginning of a file, though it will still need to reread the file to find the linebreaks. Perhaps the whole file can instead be handled in a single while read loop?

4
  • I've used a lot of "perhaps", and some non-functional code snippets, because I still don't have much information about the input format.
    – JigglyNaga
    Nov 19 '19 at 12:49
  • Oh, that is a lot of suggestion. I will look through it all and see if i can increase performance with it. Thanks for your invested time. I am sure there is a lot of improvement in terms of performance and i will report back once i've implemented improvements. Currently my script takes around 6 seconds to get all lines for one error, it has to find a lot more though, including searching for secondary references in even more logs. Longest part by far seems to be the actual grepping of the whole files, which are even bigger than the first. So i'll start there. Nov 20 '19 at 15:59
  • Getting the length of the array with # is a great thing, this of course means that i can get rid of one grep. The file will be needed though, as i need to print the whole line anyway and won't find it with any other search. uniq works very well as well, thanks for that. Combining seds is currently not needed anymore as i am not checking for the timestamp anymore, The timestamp was only a workaround to get the lines. I am now using grep -A100 -B100 to find alle lines surrounding the reference and then i filter for the task. not sure if it's faster, but it's correct and not too slow. Nov 20 '19 at 16:57
  • As to the rest, i will try to experiment with some of the ideas, especially the part about putting the grep outside a while loop. This could be impactful. Nov 20 '19 at 17:31

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.