From 444efd15f53b17e3351d2b1120420f7c12878b6b Mon Sep 17 00:00:00 2001 From: ibnjunaid Date: Sat, 17 Aug 2024 03:49:46 +0530 Subject: [PATCH 1/6] Fix issue: Wrong duration for DB transaction event on ROR 7.1 #92 --- lib/aws-xray-sdk/facets/rails/active_record.rb | 10 ++++++++-- lib/aws-xray-sdk/utils/math_utils.rb | 5 +++++ 2 files changed, 13 insertions(+), 2 deletions(-) create mode 100644 lib/aws-xray-sdk/utils/math_utils.rb diff --git a/lib/aws-xray-sdk/facets/rails/active_record.rb b/lib/aws-xray-sdk/facets/rails/active_record.rb index d5b8732..420fbd9 100644 --- a/lib/aws-xray-sdk/facets/rails/active_record.rb +++ b/lib/aws-xray-sdk/facets/rails/active_record.rb @@ -1,4 +1,5 @@ require 'active_record' +require 'aws-xray-sdk/utils/math_utils' module XRay module Rails @@ -27,9 +28,14 @@ def record(transaction) subsegment = XRay.recorder.begin_subsegment name, namespace: 'remote' # subsegment is nil in case of context missing return if subsegment.nil? - subsegment.start_time = transaction.time.to_f + + # X-Ray SDK expects time in seconds with up to nanosecond precision. + exponent = get_exponent(transaction.time.to_f) + division_factor = 10 ** (exponent - 9) + + subsegment.start_time = transaction.time.to_f / division_factor subsegment.sql = sql - XRay.recorder.end_subsegment end_time: transaction.end.to_f + XRay.recorder.end_subsegment end_time: transaction.end.to_f / division_factor end private diff --git a/lib/aws-xray-sdk/utils/math_utils.rb b/lib/aws-xray-sdk/utils/math_utils.rb new file mode 100644 index 0000000..94e1509 --- /dev/null +++ b/lib/aws-xray-sdk/utils/math_utils.rb @@ -0,0 +1,5 @@ +def get_exponent(num) + return 0 if num == 0 + exp = Math.log10(num.abs).floor + num.negative? ? exp - 1 : exp +end \ No newline at end of file From 9b5b66d726dfd0b95b2e31739a4728d9b2751864 Mon Sep 17 00:00:00 2001 From: ibnjunaid Date: Sat, 17 Aug 2024 04:52:23 +0530 Subject: [PATCH 2/6] Added unit tests and restructured the code --- lib/aws-xray-sdk/facets/rails/active_record.rb | 8 ++------ lib/aws-xray-sdk/utils/math_utils.rb | 7 +++++++ test/aws-xray-sdk/tc_time_conversion.rb | 13 +++++++++++++ 3 files changed, 22 insertions(+), 6 deletions(-) create mode 100644 test/aws-xray-sdk/tc_time_conversion.rb diff --git a/lib/aws-xray-sdk/facets/rails/active_record.rb b/lib/aws-xray-sdk/facets/rails/active_record.rb index 420fbd9..ca4073a 100644 --- a/lib/aws-xray-sdk/facets/rails/active_record.rb +++ b/lib/aws-xray-sdk/facets/rails/active_record.rb @@ -28,14 +28,10 @@ def record(transaction) subsegment = XRay.recorder.begin_subsegment name, namespace: 'remote' # subsegment is nil in case of context missing return if subsegment.nil? - - # X-Ray SDK expects time in seconds with up to nanosecond precision. - exponent = get_exponent(transaction.time.to_f) - division_factor = 10 ** (exponent - 9) - subsegment.start_time = transaction.time.to_f / division_factor + subsegment.start_time = convert_time_in_seconds(transaction.time.to_f) subsegment.sql = sql - XRay.recorder.end_subsegment end_time: transaction.end.to_f / division_factor + XRay.recorder.end_subsegment end_time: convert_time_in_seconds(transaction.end.to_f) end private diff --git a/lib/aws-xray-sdk/utils/math_utils.rb b/lib/aws-xray-sdk/utils/math_utils.rb index 94e1509..f9dc2eb 100644 --- a/lib/aws-xray-sdk/utils/math_utils.rb +++ b/lib/aws-xray-sdk/utils/math_utils.rb @@ -2,4 +2,11 @@ def get_exponent(num) return 0 if num == 0 exp = Math.log10(num.abs).floor num.negative? ? exp - 1 : exp +end + +# X-Ray SDK expects time in seconds with nanosecond precision. +def convert_time_in_seconds(time_float) + exponent = get_exponent(time_float) + division_factor = 10 ** (exponent - 9) + time_float / division_factor end \ No newline at end of file diff --git a/test/aws-xray-sdk/tc_time_conversion.rb b/test/aws-xray-sdk/tc_time_conversion.rb new file mode 100644 index 0000000..bb3d233 --- /dev/null +++ b/test/aws-xray-sdk/tc_time_conversion.rb @@ -0,0 +1,13 @@ +require 'aws-xray-sdk/utils/math_utils' + +class TestGetTimeInSeconds < Minitest::Test + def convert_time_from_milliseconds + time_in_seconds = convert_time_in_seconds 1.723627099460531E12 + assert_equal time_in_seconds 172362709.9460531 + end + + def convert_time_from_seconds + time_in_seconds = convert_time_in_seconds 1.7236270994659648E9 + assert_equal time_in_seconds 1.7236270994659648E9 + end +end \ No newline at end of file From cf11ea7dcca190360153338c53dcc1106bce2696 Mon Sep 17 00:00:00 2001 From: ibnjunaid Date: Sat, 17 Aug 2024 05:05:58 +0530 Subject: [PATCH 3/6] Fix unit tests --- test/aws-xray-sdk/tc_time_conversion.rb | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/aws-xray-sdk/tc_time_conversion.rb b/test/aws-xray-sdk/tc_time_conversion.rb index bb3d233..839c556 100644 --- a/test/aws-xray-sdk/tc_time_conversion.rb +++ b/test/aws-xray-sdk/tc_time_conversion.rb @@ -3,7 +3,7 @@ class TestGetTimeInSeconds < Minitest::Test def convert_time_from_milliseconds time_in_seconds = convert_time_in_seconds 1.723627099460531E12 - assert_equal time_in_seconds 172362709.9460531 + assert_equal time_in_seconds 1723627099.460531 end def convert_time_from_seconds From c5e7f56951754f4563552e9d075543a663341388 Mon Sep 17 00:00:00 2001 From: Lei Wang <66336933+wangzlei@users.noreply.github.com> Date: Sun, 18 Aug 2024 20:54:37 -0700 Subject: [PATCH 4/6] Update continuous-build.yml (#97) the latest macos-14 supports arm only. This PR using the previous version of macos image to unblock the release. --- .github/workflows/continuous-build.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.github/workflows/continuous-build.yml b/.github/workflows/continuous-build.yml index 072485e..788dc25 100644 --- a/.github/workflows/continuous-build.yml +++ b/.github/workflows/continuous-build.yml @@ -14,7 +14,7 @@ jobs: strategy: matrix: os: - - macos-latest + - macos-13 - ubuntu-latest ruby: - 2.4 From 373b1acc2dbaf2063df3029e1306ade5f36cf8f4 Mon Sep 17 00:00:00 2001 From: ibnjunaid Date: Wed, 21 Aug 2024 23:04:54 +0530 Subject: [PATCH 5/6] Worked on the jj22ee's comment and added logic that convert in seconds only for rails 7.1 versions. --- lib/aws-xray-sdk/facets/rails/active_record.rb | 5 ++--- 1 file changed, 2 insertions(+), 3 deletions(-) diff --git a/lib/aws-xray-sdk/facets/rails/active_record.rb b/lib/aws-xray-sdk/facets/rails/active_record.rb index ca4073a..9f7f2e3 100644 --- a/lib/aws-xray-sdk/facets/rails/active_record.rb +++ b/lib/aws-xray-sdk/facets/rails/active_record.rb @@ -28,10 +28,9 @@ def record(transaction) subsegment = XRay.recorder.begin_subsegment name, namespace: 'remote' # subsegment is nil in case of context missing return if subsegment.nil? - - subsegment.start_time = convert_time_in_seconds(transaction.time.to_f) + subsegment.start_time = (::Rails::VERSION::MAJOR == 7 and ::Rails::VERSION::MINOR == 1) ? convert_time_in_seconds(transaction.time.to_f) : transaction.time.to_f subsegment.sql = sql - XRay.recorder.end_subsegment end_time: convert_time_in_seconds(transaction.end.to_f) + XRay.recorder.end_subsegment end_time: (::Rails::VERSION::MAJOR == 7 and ::Rails::VERSION::MINOR == 1) ? convert_time_in_seconds(transaction.end.to_f) : transaction.end.to_f end private From 8d232b1172b08dec4accefeac5b495c4573bff77 Mon Sep 17 00:00:00 2001 From: ibnjunaid Date: Sat, 24 Aug 2024 00:45:38 +0530 Subject: [PATCH 6/6] Conditionally handle for ruby 7.1 --- lib/aws-xray-sdk/facets/rails/active_record.rb | 7 ++++--- lib/aws-xray-sdk/utils/math_utils.rb | 12 ------------ test/aws-xray-sdk/tc_time_conversion.rb | 13 ------------- 3 files changed, 4 insertions(+), 28 deletions(-) delete mode 100644 lib/aws-xray-sdk/utils/math_utils.rb delete mode 100644 test/aws-xray-sdk/tc_time_conversion.rb diff --git a/lib/aws-xray-sdk/facets/rails/active_record.rb b/lib/aws-xray-sdk/facets/rails/active_record.rb index 9f7f2e3..cc6a23a 100644 --- a/lib/aws-xray-sdk/facets/rails/active_record.rb +++ b/lib/aws-xray-sdk/facets/rails/active_record.rb @@ -1,5 +1,4 @@ require 'active_record' -require 'aws-xray-sdk/utils/math_utils' module XRay module Rails @@ -28,9 +27,11 @@ def record(transaction) subsegment = XRay.recorder.begin_subsegment name, namespace: 'remote' # subsegment is nil in case of context missing return if subsegment.nil? - subsegment.start_time = (::Rails::VERSION::MAJOR == 7 and ::Rails::VERSION::MINOR == 1) ? convert_time_in_seconds(transaction.time.to_f) : transaction.time.to_f + # Rails 7.1 introduced time measurement in milliseconds instead seconds of causing xray-sdk to report wrong duration for transaction calls. + # This is being handled in rails 7.2 and later. https://github.com/rails/rails/pull/50779 + subsegment.start_time = (::Rails::VERSION::MAJOR == 7 and ::Rails::VERSION::MINOR == 1) ? transaction.time.to_f/1000 : transaction.time.to_f subsegment.sql = sql - XRay.recorder.end_subsegment end_time: (::Rails::VERSION::MAJOR == 7 and ::Rails::VERSION::MINOR == 1) ? convert_time_in_seconds(transaction.end.to_f) : transaction.end.to_f + XRay.recorder.end_subsegment end_time: (::Rails::VERSION::MAJOR == 7 and ::Rails::VERSION::MINOR == 1) ? transaction.end.to_f/1000 : transaction.end.to_f end private diff --git a/lib/aws-xray-sdk/utils/math_utils.rb b/lib/aws-xray-sdk/utils/math_utils.rb deleted file mode 100644 index f9dc2eb..0000000 --- a/lib/aws-xray-sdk/utils/math_utils.rb +++ /dev/null @@ -1,12 +0,0 @@ -def get_exponent(num) - return 0 if num == 0 - exp = Math.log10(num.abs).floor - num.negative? ? exp - 1 : exp -end - -# X-Ray SDK expects time in seconds with nanosecond precision. -def convert_time_in_seconds(time_float) - exponent = get_exponent(time_float) - division_factor = 10 ** (exponent - 9) - time_float / division_factor -end \ No newline at end of file diff --git a/test/aws-xray-sdk/tc_time_conversion.rb b/test/aws-xray-sdk/tc_time_conversion.rb deleted file mode 100644 index 839c556..0000000 --- a/test/aws-xray-sdk/tc_time_conversion.rb +++ /dev/null @@ -1,13 +0,0 @@ -require 'aws-xray-sdk/utils/math_utils' - -class TestGetTimeInSeconds < Minitest::Test - def convert_time_from_milliseconds - time_in_seconds = convert_time_in_seconds 1.723627099460531E12 - assert_equal time_in_seconds 1723627099.460531 - end - - def convert_time_from_seconds - time_in_seconds = convert_time_in_seconds 1.7236270994659648E9 - assert_equal time_in_seconds 1.7236270994659648E9 - end -end \ No newline at end of file