title: The loop does not iterate over the log file in bash
body: <p>Welcome everyone,</p>
  
  <p>Unfortunately, I have to ask for help.</p>
  
  <p>I am trying to write a simple script displaying the time of the procedure based on the log file. However, my loop does not work as it should.</p>
  
  <p>fun.sh</p>
  
  <pre><code>STARTPROCEDURES="START Search"
  ENDPROCEDURES="END Search"
  
  start() {
  start="$(grep "$STARTPROCEDURES" s.log | cut -d ' ' -f2)"
  
  hours="$(date -d $start '+%H')"
  minutes="$(date -d $start '+%M')"
  seconds="$(date -d $start '+%S')"
  milliseconds=$(($(date -d $start +%N  | sed 's/^0*//')/1000000))
  
  starttime=$(((hours * 360000000 + minutes * 60000 + seconds * 1000 + milliseconds)))
  
  echo "Begins: " $starttime
  }
  
  end() {
  end="$(grep "$ENDPROCEDURES" s.log | cut -d ' ' -f2)"
  
  hours="$(date -d $end '+%H')"
  minutes="$(date -d $end '+%M')"
  seconds="$(date -d $end '+%S')"
  milliseconds=$(($(date -d $end +%N  | sed 's/^0*//')/1000000))
  
  endtime=$(((hours * 360000000 + minutes * 60000 + seconds * 1000 + milliseconds)))
  
  echo "Ends: " $endtime
  }
  
  difference() {
  echo "DIFFERENCE -----"
  
  difference=$((endtime  - starttime))
  echo "The difference is" $difference "milliseconds"
  }
  
  calculate() {
  start
  end
  difference
  }
  
  while IFS= read -r line || [[ -n $line ]]; do
  calculate
  echo "-------"
  done &lt; s.log
  </code></pre>
  
  <p>s.log:</p>
  
  <pre><code>2019-02-22 06:27:06,857 INFO [ProcedureUtil] - (user1,14)  START Search
  2019-02-22 06:27:06,939 INFO [ProcedureUtil] - (user1,14)  END Search
  2019-02-22 07:28:16,088 INFO [ProcedureUtil] - (user1,67)  START Search
  2019-02-22 07:28:16,121 INFO [ProcedureUtil] - (user1,67)  END Search
  </code></pre>
  
  <p>bash fun.sh</p>
  
  <p>Houston, We Have A Problem.</p>
  
  <p>output of console:</p>
  
  <pre><code>date: extra operand ‘+%H’
  Try 'date --help' for more information.
  date: extra operand ‘+%M’
  Try 'date --help' for more information.
  date: extra operand ‘+%S’
  Try 'date --help' for more information.
  date: extra operand ‘+%N’
  Try 'date --help' for more information.
  fun.sh: line 21: /1000000: syntax error: operand expected (error token is "/1000000")
  </code></pre>
  
  <p>should be something like that</p>
  
  <pre><code>Begins:  2161626857
  Ends:  2161626939
  DIFFERENCE -----
  The difference is 82 milliseconds
  ------
  Begins:  216162343
  Ends:  216162355
  DIFFERENCE -----
  The difference is 162 milliseconds
  </code></pre>
  
  <p>if s.log is:</p>
  
  <pre><code>2019-02-22 06:27:06,857 INFO [ProcedureUtil] - (user1,14)  START Search
  2019-02-22 06:27:06,939 INFO [ProcedureUtil] - (user1,14)  END Search
  </code></pre>
  
  <p>output of console:</p>
  
  <pre><code>Begins:  2161626857
  Ends:  2161626939
  DIFFERENCE -----
  The difference is 82 milliseconds
  -------
  Begins:  2161626857
  Ends:  2161626939
  DIFFERENCE -----
  The difference is 82 milliseconds
  -------
  </code></pre>
  
  <p>twice to the same, and it should be once.</p>
  
  <p>I will be very graceful for help</p>
  
  <p><strong>I am considering a case:
  where s.log is:</strong></p>
  
  <pre><code>2019-02-22 06:27:06,857 INFO [ProcedureUtil] - (user1,14)  START Search
  2019-02-22 06:27:06,939 INFO [ProcedureUtil] - (user1,14)  END Search
  2019-02-22 07:28:16,088 INFO [ProcedureUtil] - (user1,67)  START Split
  2019-02-22 07:28:16,121 INFO [ProcedureUtil] - (user1,67)  END Split
  2019-02-22 07:28:16,088 INFO [ProcedureUtil] - (user1,67)  START Search
  2019-02-22 07:28:16,121 INFO [ProcedureUtil] - (user1,67)  END Search
  2019-02-25 20:59:59,999 INFO [ProcedureUtil] - (user1,17)  START Search
  2019-02-25 02:59:59,999 INFO [ProcedureUtil] - (user1,18)  START Search
  </code></pre>
  
  <p>bad solution:</p>
  
  <pre><code>COUNTER=0
  while IFS= read -r line || [[ -n $line ]]; do
  if [[ $line == *"START Search"* ]]; then
      start=$(time2millis "$line")
      echo "Begins: $start"
  
  elif [[ $line == *"END Search"* ]]; then 
      end=$(time2millis "$line")
      echo "Ends: $end"
  
      # Assume every END has a preceding START
      difference "$start" "$end"
  else
       COUNTER=$((COUNTER+1))
       echo "$COUNTER"
  fi     
  done &lt; s.log
  </code></pre>
  
  <p>output of console:</p>
  
  <pre><code>Begins: 23226857
  Ends: 23226939
  DIFFERENCE -----
  The difference is 82 milliseconds
  ------
  Begins: 26896088
  Ends: 26896121
  DIFFERENCE -----
  The difference is 33 milliseconds
  ------
  Begins: 75599999
  Begins: 10799999
  </code></pre>