[ARVADOS] updated: afca15637ba53e38238405afb2e14342cca33052

Git user git at public.curoverse.com
Mon Feb 29 18:45:51 EST 2016


Summary of changes:
 services/api/lib/crunch_dispatch.rb            | 17 +++++---
 services/api/test/unit/crunch_dispatch_test.rb | 59 ++++++++++++++++++++++++++
 2 files changed, 69 insertions(+), 7 deletions(-)

       via  afca15637ba53e38238405afb2e14342cca33052 (commit)
      from  f5c622f3018c7282375f5a0dca26e64c9ea8d982 (commit)

Those revisions listed above that are new to this repository have
not appeared on any other notification email; so we list those
revisions in full, below.


commit afca15637ba53e38238405afb2e14342cca33052
Author: radhika <radhika at curoverse.com>
Date:   Mon Feb 29 18:45:17 2016 -0500

    7399: added test for partial line segment throttling.

diff --git a/services/api/lib/crunch_dispatch.rb b/services/api/lib/crunch_dispatch.rb
index cbdd04e..1017895 100644
--- a/services/api/lib/crunch_dispatch.rb
+++ b/services/api/lib/crunch_dispatch.rb
@@ -429,7 +429,7 @@ class CrunchDispatch
         log_throttle_bytes_so_far: 0,
         log_throttle_lines_so_far: 0,
         log_throttle_bytes_skipped: 0,
-        log_throttle_partial_line_last_at: 0,
+        log_throttle_partial_line_last_at: Time.new(0),
         log_throttle_first_partial_line: true,
       }
       i.close
@@ -447,10 +447,11 @@ class CrunchDispatch
     if running_job[:log_throttle_is_open]
       partial_line = false
       skip_counts = false
-      if line.start_with?('[...]') and line.end_with?('[...]')
+      line_splits = line.split('stderr ')
+      if line_splits[1].andand.start_with?('[...]') and line_splits[1].end_with?('[...]')
         partial_line = true
-        if Time.now > j[:log_throttle_partial_line_last_at] + Rails.configuration.crunch_log_partial_line_throttle_period
-          j[:log_throttle_partial_line_last_at] = Time.now
+        if Time.now > running_job[:log_throttle_partial_line_last_at] + Rails.configuration.crunch_log_partial_line_throttle_period
+          running_job[:log_throttle_partial_line_last_at] = Time.now
         else
           skip_counts = true
         end
@@ -480,8 +481,8 @@ class CrunchDispatch
         message = "Exceeded rate #{Rails.configuration.crunch_log_throttle_lines} lines per #{Rails.configuration.crunch_log_throttle_period} seconds (crunch_log_throttle_lines), logging will be silenced for the next #{remaining_time.round} seconds."
         running_job[:log_throttle_is_open] = false
 
-      elsif partial_line and j[:log_throttle_first_partial_line]
-        j[:log_throttle_first_partial_line] = false
+      elsif partial_line and running_job[:log_throttle_first_partial_line]
+        running_job[:log_throttle_first_partial_line] = false
         message = "Rate-limiting partial segments of long lines to one every #{Rails.configuration.crunch_log_partial_line_throttle_period} seconds."
       end
     end
@@ -497,6 +498,8 @@ class CrunchDispatch
       message += " A complete log is still being written to Keep, and will be available when the job finishes.\n"
       line.replace message
       true
+    elsif partial_line
+      false
     else
       running_job[:log_throttle_is_open]
     end
@@ -521,7 +524,7 @@ class CrunchDispatch
         j[:log_throttle_lines_so_far] = 0
         j[:log_throttle_bytes_skipped] = 0
         j[:log_throttle_is_open] = true
-        j[:log_throttle_partial_line_last_at] = 0
+        j[:log_throttle_partial_line_last_at] = Time.new(0)
         j[:log_throttle_first_partial_line] = true
       end
 
diff --git a/services/api/test/unit/crunch_dispatch_test.rb b/services/api/test/unit/crunch_dispatch_test.rb
index 09f4af6..04b06d7 100644
--- a/services/api/test/unit/crunch_dispatch_test.rb
+++ b/services/api/test/unit/crunch_dispatch_test.rb
@@ -116,4 +116,63 @@ class CrunchDispatchTest < ActiveSupport::TestCase
       return f.flock(File::LOCK_EX|File::LOCK_NB)
     end
   end
+
+  test 'rate limit of partial line segments' do
+    act_as_system_user do
+      Rails.configuration.crunch_log_partial_line_throttle_period = 1
+
+      job = {}
+      job[:bytes_logged] = 0
+      job[:log_throttle_bytes_so_far] = 0
+      job[:log_throttle_lines_so_far] = 0
+      job[:log_throttle_bytes_skipped] = 0
+      job[:log_throttle_is_open] = true
+      job[:log_throttle_partial_line_last_at] = Time.new(0)
+      job[:log_throttle_first_partial_line] = true
+
+      dispatch = CrunchDispatch.new
+
+      line = "first log line"
+      limit = dispatch.rate_limit(job, line)
+      assert_equal true, limit
+      assert_equal "first log line", line
+      assert_equal 1, job[:log_throttle_lines_so_far]
+
+      # first partial line segment is skipped and counted towards skipped lines
+      now = Time.now
+      line = "#{Time.now} stderr [...] this is first partial line segment [...]"
+      limit = dispatch.rate_limit(job, line)
+      assert_equal true, limit
+      assert_includes line, "Rate-limiting partial segments of long lines", line
+      assert_equal 2, job[:log_throttle_lines_so_far]
+
+      # next partial line segment within throttle interval is skipped but not counted towards skipped lines
+      line = "#{Time.now} stderr [...] second partial line segment within the interval [...]"
+      limit = dispatch.rate_limit(job, line)
+      assert_equal false, limit
+      assert_equal 2, job[:log_throttle_lines_so_far]
+
+      # next partial line after interval is counted towards skipped lines
+      sleep(1)
+      line = "#{Time.now} stderr [...] third partial line segment after the interval [...]"
+      limit = dispatch.rate_limit(job, line)
+      assert_equal false, limit
+      assert_equal 3, job[:log_throttle_lines_so_far]
+
+      now = Time.now
+      # this is not a valid line segment
+      line = "#{now} stderr [...] does not end with [...] and is not a partial segment"
+      limit = dispatch.rate_limit(job, line)
+      assert_equal true, limit
+      assert_equal "#{now} stderr [...] does not end with [...] and is not a partial segment", line
+      assert_equal 4, job[:log_throttle_lines_so_far]
+
+      # this also is not a valid line segment
+      line = "#{now} stderr does not start correctly but ends with [...]"
+      limit = dispatch.rate_limit(job, line)
+      assert_equal true, limit
+      assert_equal "#{now} stderr does not start correctly but ends with [...]", line
+      assert_equal 5, job[:log_throttle_lines_so_far]
+    end
+  end
 end

-----------------------------------------------------------------------


hooks/post-receive
-- 




More information about the arvados-commits mailing list