Log Exception in tracing span when throwed. (#75)
diff --git a/src/plugin/mod.rs b/src/plugin/mod.rs index 8826c2b..f564d2e 100644 --- a/src/plugin/mod.rs +++ b/src/plugin/mod.rs
@@ -24,6 +24,8 @@ use crate::execute::{AfterExecuteHook, BeforeExecuteHook}; use once_cell::sync::Lazy; +use phper::{eg, objects::ZObj}; +use skywalking::trace::span::Span; // Register plugins here. static PLUGINS: Lazy<Vec<Box<DynPlugin>>> = Lazy::new(|| { @@ -74,3 +76,29 @@ selected_plugin.map(AsRef::as_ref) } + +fn log_exception(span: &mut Span) { + let ex = unsafe { ZObj::try_from_mut_ptr(eg!(exception)) }; + if let Some(ex) = ex { + let mut span_object = span.span_object_mut(); + span_object.is_error = true; + + let mut logs = Vec::new(); + if let Ok(class_name) = ex.get_class().get_name().to_str() { + logs.push(("error.kind", class_name.to_owned())); + } + if let Some(message) = ex.get_property("message").as_z_str() { + if let Ok(message) = message.to_str() { + logs.push(("message", message.to_owned())); + } + } + if let Ok(stack) = ex.call("getTraceAsString", []) { + if let Some(stack) = stack.as_z_str().and_then(|s| s.to_str().ok()) { + logs.push(("stack", stack.to_owned())); + } + } + if !logs.is_empty() { + span_object.add_log(logs); + } + } +}
diff --git a/src/plugin/plugin_amqplib.rs b/src/plugin/plugin_amqplib.rs index e6065a8..9016a72 100644 --- a/src/plugin/plugin_amqplib.rs +++ b/src/plugin/plugin_amqplib.rs
@@ -13,11 +13,11 @@ // See the License for the specific language governing permissions and // limitations under the License. -use super::Plugin; +use super::{log_exception, Plugin}; use crate::{ component::COMPONENT_AMQP_PRODUCER_ID, context::{RequestContext, SW_HEADER}, - execute::{get_this_mut, validate_num_args, AfterExecuteHook, BeforeExecuteHook, Noop}, + execute::{get_this_mut, validate_num_args, AfterExecuteHook, BeforeExecuteHook}, tag::{TAG_MQ_BROKER, TAG_MQ_QUEUE, TAG_MQ_TOPIC}, }; use anyhow::Context; @@ -99,7 +99,11 @@ Ok(Box::new(span)) }), - Noop::noop(), + Box::new(move |_, span, _, _| { + let mut span = span.downcast::<Span>().unwrap(); + log_exception(&mut span); + Ok(()) + }), ) }
diff --git a/src/plugin/plugin_curl.rs b/src/plugin/plugin_curl.rs index 7ca08f5..0f06a0c 100644 --- a/src/plugin/plugin_curl.rs +++ b/src/plugin/plugin_curl.rs
@@ -13,7 +13,7 @@ // See the License for the specific language governing permissions and // limitations under the License. -use super::Plugin; +use super::{log_exception, Plugin}; use crate::{ component::COMPONENT_PHP_CURL_ID, context::{RequestContext, SW_HEADER}, @@ -442,6 +442,7 @@ .and_then(|code| code.as_long()) .context("Call curl_getinfo, http_code is null")?; span.add_tag("status_code", &*http_code.to_string()); + if http_code == 0 { let result = call("curl_error", &mut [ch.clone()])?; let curl_error = result @@ -456,6 +457,9 @@ } else { span.span_object_mut().is_error = false; } + + log_exception(span); + Ok(()) } }
diff --git a/src/plugin/plugin_memcached.rs b/src/plugin/plugin_memcached.rs index 48f4cf6..2744cfb 100644 --- a/src/plugin/plugin_memcached.rs +++ b/src/plugin/plugin_memcached.rs
@@ -15,7 +15,7 @@ use std::{any::Any, collections::HashMap}; -use super::Plugin; +use super::{log_exception, Plugin}; use crate::{ component::COMPONENT_PHP_MEMCACHED_ID, context::RequestContext, @@ -306,6 +306,7 @@ _: Option<i64>, span: Box<dyn Any>, execute_data: &mut ExecuteData, return_value: &mut ZVal, ) -> crate::Result<()> { let mut span = span.downcast::<Span>().expect("Downcast to Span failed"); + if let Some(b) = return_value.as_bool() { if !b { span.span_object_mut().is_error = true; @@ -330,6 +331,9 @@ } } } + + log_exception(&mut span); + Ok(()) }
diff --git a/src/plugin/plugin_mysqli.rs b/src/plugin/plugin_mysqli.rs index b3f1dfc..40bf8bb 100644 --- a/src/plugin/plugin_mysqli.rs +++ b/src/plugin/plugin_mysqli.rs
@@ -13,11 +13,11 @@ // See the License for the specific language governing permissions and // limitations under the License. -use super::Plugin; +use super::{log_exception, Plugin}; use crate::{ component::COMPONENT_PHP_MYSQLI_ID, context::RequestContext, - execute::{get_this_mut, AfterExecuteHook, BeforeExecuteHook, Noop}, + execute::{get_this_mut, AfterExecuteHook, BeforeExecuteHook}, }; use anyhow::Context; use dashmap::DashMap; @@ -60,7 +60,7 @@ impl MySQLImprovedPlugin { fn hook_mysqli_construct(&self) -> (Box<BeforeExecuteHook>, Box<AfterExecuteHook>) { ( - Box::new(|_, execute_data| { + Box::new(|request_id, execute_data| { let this = get_this_mut(execute_data)?; let handle = this.handle(); hack_dtor(this, Some(mysqli_dtor)); @@ -89,10 +89,17 @@ info.port = port } + let span = create_mysqli_exit_span(request_id, "mysqli", "__construct", &info)?; + MYSQL_MAP.insert(handle, info); - Ok(Box::new(())) + + Ok(Box::new(span)) }), - Noop::noop(), + Box::new(move |_, span, _, _| { + let mut span = span.downcast::<Span>().unwrap(); + log_exception(&mut span); + Ok(()) + }), ) } @@ -119,7 +126,11 @@ Ok(Box::new(span) as _) }), - Noop::noop(), + Box::new(move |_, span, _, _| { + let mut span = span.downcast::<Span>().unwrap(); + log_exception(&mut span); + Ok(()) + }), ) } }
diff --git a/src/plugin/plugin_pdo.rs b/src/plugin/plugin_pdo.rs index bbedfa3..d1af7ba 100644 --- a/src/plugin/plugin_pdo.rs +++ b/src/plugin/plugin_pdo.rs
@@ -13,11 +13,11 @@ // See the License for the specific language governing permissions and // limitations under the License. -use super::Plugin; +use super::{log_exception, Plugin}; use crate::{ component::COMPONENT_PHP_PDO_ID, context::RequestContext, - execute::{get_this_mut, validate_num_args, AfterExecuteHook, BeforeExecuteHook, Noop}, + execute::{get_this_mut, validate_num_args, AfterExecuteHook, BeforeExecuteHook}, tag::{TAG_DB_STATEMENT, TAG_DB_TYPE}, }; use anyhow::Context; @@ -83,7 +83,7 @@ impl PdoPlugin { fn hook_pdo_construct(&self) -> (Box<BeforeExecuteHook>, Box<AfterExecuteHook>) { ( - Box::new(|_, execute_data| { + Box::new(|request_id, execute_data| { validate_num_args(execute_data, 1)?; let this = get_this_mut(execute_data)?; @@ -97,11 +97,17 @@ let dsn: Dsn = dsn.parse()?; debug!(?dsn, "parse PDO dsn"); + let span = create_exit_span_with_dsn(request_id, "PDO", "__construct", &dsn)?; + DSN_MAP.insert(handle, dsn); - Ok(Box::new(())) + Ok(Box::new(span)) }), - Noop::noop(), + Box::new(move |_, span, _, _| { + let mut span = span.downcast::<Span>().unwrap(); + log_exception(&mut span); + Ok(()) + }), ) } @@ -191,12 +197,11 @@ fn after_hook( _: Option<i64>, span: Box<dyn Any>, execute_data: &mut ExecuteData, return_value: &mut ZVal, ) -> crate::Result<()> { + let mut span = span.downcast::<Span>().unwrap(); + if let Some(b) = return_value.as_bool() { if !b { - return after_hook_when_false( - get_this_mut(execute_data)?, - &mut span.downcast::<Span>().unwrap(), - ); + return after_hook_when_false(get_this_mut(execute_data)?, &mut span); } } else if let Some(obj) = return_value.as_mut_z_obj() { let cls = obj.get_class(); @@ -209,6 +214,8 @@ } } + log_exception(&mut span); + Ok(()) }
diff --git a/src/plugin/plugin_predis.rs b/src/plugin/plugin_predis.rs index 0b643d6..b486ed5 100644 --- a/src/plugin/plugin_predis.rs +++ b/src/plugin/plugin_predis.rs
@@ -18,6 +18,7 @@ component::COMPONENT_PHP_PREDIS_ID, context::RequestContext, execute::{get_this_mut, validate_num_args, AfterExecuteHook, BeforeExecuteHook}, + plugin::log_exception, tag::{TAG_CACHE_CMD, TAG_CACHE_KEY, TAG_CACHE_OP, TAG_CACHE_TYPE}, }; use once_cell::sync::Lazy; @@ -238,6 +239,8 @@ span.span_object_mut().is_error = true; } + log_exception(&mut span); + Ok(()) }), )
diff --git a/src/plugin/plugin_redis.rs b/src/plugin/plugin_redis.rs index 3db2ddf..df22fe1 100644 --- a/src/plugin/plugin_redis.rs +++ b/src/plugin/plugin_redis.rs
@@ -13,7 +13,7 @@ // See the License for the specific language governing permissions and // limitations under the License. -use super::Plugin; +use super::{log_exception, Plugin}; use crate::{ component::COMPONENT_PHP_REDIS_ID, context::RequestContext, @@ -24,7 +24,6 @@ use dashmap::DashMap; use once_cell::sync::Lazy; use phper::{ - eg, objects::ZObj, sys, values::{ExecuteData, ZVal}, @@ -360,24 +359,7 @@ ) -> crate::Result<()> { let mut span = span.downcast::<Span>().unwrap(); - let ex = unsafe { ZObj::try_from_mut_ptr(eg!(exception)) }; - if let Some(ex) = ex { - let mut span_object = span.span_object_mut(); - span_object.is_error = true; - - let mut logs = Vec::new(); - if let Ok(class_name) = ex.get_class().get_name().to_str() { - logs.push(("Exception Class", class_name.to_owned())); - } - if let Some(message) = ex.get_property("message").as_z_str() { - if let Ok(message) = message.to_str() { - logs.push(("Exception Message", message.to_owned())); - } - } - if !logs.is_empty() { - span_object.add_log(logs); - } - } + log_exception(&mut span); Ok(()) }
diff --git a/tests/data/expected_context.yaml b/tests/data/expected_context.yaml index bc3470c..ea1bd78 100644 --- a/tests/data/expected_context.yaml +++ b/tests/data/expected_context.yaml
@@ -428,7 +428,7 @@ - { key: http.status_code, value: "200" } - segmentId: "not null" spans: - - operationName: PDO->exec + - operationName: PDO->__construct parentSpanId: 0 spanId: 1 spanLayer: Database @@ -443,31 +443,27 @@ - { key: db.type, value: mysql } - { key: db.data_source, + value: dbname=skywalking;host=127.0.0.1;port=3306, + } + - operationName: PDO->exec + parentSpanId: 0 + spanId: 2 + spanLayer: Database + startTime: gt 0 + endTime: gt 0 + componentId: 8003 + isError: false + spanType: Exit + peer: 127.0.0.1:3306 + skipAnalysis: false + tags: + - { key: db.type, value: mysql } + - { + key: db.data_source, value: "dbname=skywalking;host=127.0.0.1;port=3306", } - { key: db.statement, value: SELECT 1 } - - operationName: PDO->prepare - parentSpanId: 0 - spanId: 2 - spanLayer: Database - startTime: gt 0 - endTime: gt 0 - componentId: 8003 - isError: false - spanType: Exit - peer: 127.0.0.1:3306 - skipAnalysis: false - tags: - - { key: db.type, value: mysql } - - { - key: db.data_source, - value: "dbname=skywalking;host=127.0.0.1:3306", - } - - { - key: db.statement, - value: "SELECT * FROM `mysql`.`user` WHERE `User` = :user", - } - - operationName: PDOStatement->execute + - operationName: PDO->__construct parentSpanId: 0 spanId: 3 spanLayer: Database @@ -484,11 +480,7 @@ key: db.data_source, value: "dbname=skywalking;host=127.0.0.1:3306", } - - { - key: db.statement, - value: "SELECT * FROM `mysql`.`user` WHERE `User` = :user", - } - - operationName: PDOStatement->fetchAll + - operationName: PDO->prepare parentSpanId: 0 spanId: 4 spanLayer: Database @@ -509,7 +501,7 @@ key: db.statement, value: "SELECT * FROM `mysql`.`user` WHERE `User` = :user", } - - operationName: PDO->prepare + - operationName: PDOStatement->execute parentSpanId: 0 spanId: 5 spanLayer: Database @@ -523,6 +515,65 @@ tags: - { key: db.type, value: mysql } - { + key: db.data_source, + value: "dbname=skywalking;host=127.0.0.1:3306", + } + - { + key: db.statement, + value: "SELECT * FROM `mysql`.`user` WHERE `User` = :user", + } + - operationName: PDOStatement->fetchAll + parentSpanId: 0 + spanId: 6 + spanLayer: Database + startTime: gt 0 + endTime: gt 0 + componentId: 8003 + isError: false + spanType: Exit + peer: 127.0.0.1:3306 + skipAnalysis: false + tags: + - { key: db.type, value: mysql } + - { + key: db.data_source, + value: "dbname=skywalking;host=127.0.0.1:3306", + } + - { + key: db.statement, + value: "SELECT * FROM `mysql`.`user` WHERE `User` = :user", + } + - operationName: PDO->__construct + parentSpanId: 0 + spanId: 7 + spanLayer: Database + startTime: gt 0 + endTime: gt 0 + componentId: 8003 + isError: false + spanType: Exit + peer: 127.0.0.1:3306 + skipAnalysis: false + tags: + - { key: db.type, value: mysql } + - { + key: db.data_source, + value: "dbname=skywalking;host=127.0.0.1:3306;", + } + - operationName: PDO->prepare + parentSpanId: 0 + spanId: 8 + spanLayer: Database + startTime: gt 0 + endTime: gt 0 + componentId: 8003 + isError: false + spanType: Exit + peer: 127.0.0.1:3306 + skipAnalysis: false + tags: + - { key: db.type, value: mysql } + - { key: db.data_source, value: "dbname=skywalking;host=127.0.0.1:3306;", } @@ -532,7 +583,7 @@ } - operationName: PDOStatement->execute parentSpanId: 0 - spanId: 6 + spanId: 9 spanLayer: Database startTime: gt 0 endTime: gt 0 @@ -553,7 +604,7 @@ } - operationName: PDOStatement->fetchAll parentSpanId: 0 - spanId: 7 + spanId: 10 spanLayer: Database startTime: gt 0 endTime: gt 0 @@ -572,9 +623,26 @@ key: db.statement, value: "SELECT * FROM `mysql`.`user` WHERE `User` = :user", } + - operationName: PDO->__construct + parentSpanId: 0 + spanId: 11 + spanLayer: Database + startTime: gt 0 + endTime: gt 0 + componentId: 8003 + isError: false + spanType: Exit + peer: 127.0.0.1:3306 + skipAnalysis: false + tags: + - { key: db.type, value: mysql } + - { + key: db.data_source, + value: dbname=skywalking;host=127.0.0.1;port=3306, + } - operationName: PDO->prepare parentSpanId: 0 - spanId: 8 + spanId: 12 spanLayer: Database startTime: gt 0 endTime: gt 0 @@ -595,7 +663,7 @@ } - operationName: PDOStatement->execute parentSpanId: 0 - spanId: 9 + spanId: 13 spanLayer: Database startTime: gt 0 endTime: gt 0 @@ -715,7 +783,7 @@ - { key: http.status_code, value: "200" } - segmentId: 'not null' spans: - - operationName: mysqli->query + - operationName: mysqli->__construct parentSpanId: 0 spanId: 1 spanLayer: Database @@ -727,14 +795,40 @@ peer: 127.0.0.1:3306 skipAnalysis: false tags: + - { key: db.type, value: mysql } + - operationName: mysqli->query + parentSpanId: 0 + spanId: 2 + spanLayer: Database + startTime: gt 0 + endTime: gt 0 + componentId: 8004 + isError: false + spanType: Exit + peer: 127.0.0.1:3306 + skipAnalysis: false + tags: - {key: db.type, value: mysql} - { key: db.statement, value: "SELECT 1", } + - operationName: mysqli->__construct + parentSpanId: 0 + spanId: 3 + spanLayer: Database + startTime: gt 0 + endTime: gt 0 + componentId: 8004 + isError: false + spanType: Exit + peer: 127.0.0.1:3306 + skipAnalysis: false + tags: + - { key: db.type, value: mysql } - operationName: mysqli->query parentSpanId: 0 - spanId: 2 + spanId: 4 spanLayer: Database startTime: gt 0 endTime: gt 0 @@ -1005,11 +1099,9 @@ - { key: cache.key, value: foo } logs: - logEvent: - - { key: Exception Class, value: RedisException } - - { - key: Exception Message, - value: NOAUTH Authentication required., - } + - { key: error.kind, value: RedisException } + - { key: message, value: NOAUTH Authentication required. } + - { key: stack, value: not null } - operationName: GET:/redis.fail.php parentSpanId: -1 spanId: 0 @@ -1300,7 +1392,7 @@ - { key: http.status_code, value: "200" } - segmentId: "not null" spans: - - operationName: PDO->exec + - operationName: PDO->__construct parentSpanId: 0 spanId: 1 spanLayer: Database @@ -1317,6 +1409,23 @@ key: db.data_source, value: dbname=skywalking;host=127.0.0.1;port=3306, } + - operationName: PDO->exec + parentSpanId: 0 + spanId: 2 + spanLayer: Database + startTime: gt 0 + endTime: gt 0 + componentId: 8003 + isError: false + spanType: Exit + peer: 127.0.0.1:3306 + skipAnalysis: false + tags: + - { key: db.type, value: mysql } + - { + key: db.data_source, + value: dbname=skywalking;host=127.0.0.1;port=3306, + } - { key: db.statement, value: SELECT 1 } - operationName: GET:/pdo parentSpanId: -1 @@ -1335,7 +1444,7 @@ - { key: http.status_code, value: "200" } - segmentId: "not null" spans: - - operationName: mysqli->query + - operationName: mysqli->__construct parentSpanId: 0 spanId: 1 spanLayer: Database @@ -1348,6 +1457,19 @@ skipAnalysis: false tags: - { key: db.type, value: mysql } + - operationName: mysqli->query + parentSpanId: 0 + spanId: 2 + spanLayer: Database + startTime: gt 0 + endTime: gt 0 + componentId: 8004 + isError: false + spanType: Exit + peer: 127.0.0.1:3306 + skipAnalysis: false + tags: + - { key: db.type, value: mysql } - { key: db.statement, value: SELECT 1 } - operationName: GET:/mysqli parentSpanId: -1