diff --git a/ext/otel_observer.c b/ext/otel_observer.c index b1c693a..c2bff26 100644 --- a/ext/otel_observer.c +++ b/ext/otel_observer.c @@ -14,6 +14,14 @@ typedef struct otel_observer { zend_llist post_hooks; } otel_observer; +typedef struct otel_exception_state { + zend_object *exception; + zend_object *prev_exception; + const zend_op *opline_before_exception; + bool has_opline; + const zend_op *opline; +} otel_exception_state; + static inline void func_get_this_or_called_scope(zval *zv, zend_execute_data *execute_data) { if (execute_data->func->op_array.scope) { @@ -187,6 +195,83 @@ static inline bool is_valid_signature(zend_fcall_info fci, return true; } +static void exception_isolation_start(otel_exception_state *save_state) { + save_state->exception = EG(exception); + save_state->prev_exception = EG(prev_exception); + save_state->opline_before_exception = EG(opline_before_exception); + + EG(exception) = NULL; + EG(prev_exception) = NULL; + EG(opline_before_exception) = NULL; + + // If the hook handler throws an exception, the execute_data of the outer + // frame may have its opline set to an exception handler too. This is done + // before the chance to clear the exception, so opline has to be restored + // to original value. + zend_execute_data *execute_data = EG(current_execute_data); + if (execute_data != NULL) { + save_state->has_opline = true; + save_state->opline = execute_data->opline; + } else { + save_state->has_opline = false; + } +} + +static zend_object *exception_isolation_end(otel_exception_state *save_state) { + zend_object *suppressed = EG(exception); + // NULL this before call to zend_clear_exception, as it would try to jump + // to exception handler then. + EG(exception) = NULL; + + // this clears prev_exception if it was set for any reason + zend_clear_exception(); + + EG(exception) = save_state->exception; + EG(prev_exception) = save_state->prev_exception; + EG(opline_before_exception) = save_state->opline_before_exception; + + zend_execute_data *execute_data = EG(current_execute_data); + if (execute_data != NULL && save_state->has_opline) { + execute_data->opline = save_state->opline; + } + + return suppressed; +} + +static const char *zval_get_chars(zval *zv) { + if (zv != NULL && Z_TYPE_P(zv) == IS_STRING) { + return Z_STRVAL_P(zv); + } + return "null"; +} + +static void exception_isolation_handle_exception(zend_object *suppressed, + zval *class_name, + zval *function_name, + const char *type) { + if (suppressed == NULL) { + return; + } + + zend_class_entry *exception_base = zend_get_exception_base(suppressed); + zval return_value; + zval *message = + zend_read_property_ex(exception_base, suppressed, + ZSTR_KNOWN(ZEND_STR_MESSAGE), 1, &return_value); + + php_error_docref(NULL, E_WARNING, + "OpenTelemetry: %s threw exception," + " class=%s function=%s message=%s", + type, zval_get_chars(class_name), + zval_get_chars(function_name), zval_get_chars(message)); + + if (message != NULL) { + ZVAL_DEREF(message); + } + + OBJ_RELEASE(suppressed); +} + static void observer_begin(zend_execute_data *execute_data, zend_llist *hooks) { if (!zend_llist_count(hooks)) { return; @@ -229,9 +314,8 @@ static void observer_begin(zend_execute_data *execute_data, zend_llist *hooks) { continue; } - zend_exception_save(); - zend_object *exception = EG(prev_exception); - EG(prev_exception) = NULL; + otel_exception_state save_state; + exception_isolation_start(&save_state); if (zend_call_function(&fci, &fcc) == SUCCESS) { if (Z_TYPE(ret) == IS_ARRAY && @@ -280,9 +364,9 @@ static void observer_begin(zend_execute_data *execute_data, zend_llist *hooks) { } } - zend_exception_restore(); - EG(prev_exception) = exception; - zend_exception_restore(); + zend_object *suppressed = exception_isolation_end(&save_state); + exception_isolation_handle_exception(suppressed, ¶ms[2], ¶ms[3], + "pre hook"); zval_dtor(&ret); } @@ -353,9 +437,8 @@ static void observer_end(zend_execute_data *execute_data, zval *retval, continue; } - zend_exception_save(); - zend_object *exception = EG(prev_exception); - EG(prev_exception) = NULL; + otel_exception_state save_state; + exception_isolation_start(&save_state); if (zend_call_function(&fci, &fcc) == SUCCESS) { /* TODO rather than ignoring return value if post callback doesn't @@ -375,20 +458,9 @@ static void observer_end(zend_execute_data *execute_data, zval *retval, } } - if (UNEXPECTED(EG(exception))) { - // do not release params[3] if exit was called - if (exception && !zend_is_unwind_exit(exception)) { - OBJ_RELEASE(Z_OBJ(params[3])); - } - if (exception) { - OBJ_RELEASE(exception); - } - ZVAL_OBJ_COPY(¶ms[3], EG(exception)); - } - - zend_exception_restore(); - EG(prev_exception) = exception; - zend_exception_restore(); + zend_object *suppressed = exception_isolation_end(&save_state); + exception_isolation_handle_exception(suppressed, ¶ms[4], ¶ms[5], + "post hook"); zval_dtor(&ret); } diff --git a/ext/package.xml b/ext/package.xml index 15f72ef..0abc2ac 100644 --- a/ext/package.xml +++ b/ext/package.xml @@ -61,12 +61,13 @@ + + - diff --git a/ext/tests/hooks_throw_exception.phpt b/ext/tests/hooks_throw_exception.phpt new file mode 100644 index 0000000..4b825b3 --- /dev/null +++ b/ext/tests/hooks_throw_exception.phpt @@ -0,0 +1,28 @@ +--TEST-- +Check if exceptions thrown in hooks are isolated and logged +--EXTENSIONS-- +opentelemetry +--FILE-- + throw new Exception('thrown in pre'), post: fn() => throw new Exception('thrown in post')); + +function helloWorld() { + var_dump('function'); + throw new Exception('original'); +} + +try { + helloWorld(); +} catch (Exception $e) { + var_dump($e->getMessage()); + var_dump($e->getPrevious()); +} +?> +--EXPECTF-- + +Warning: helloWorld(): OpenTelemetry: pre hook threw exception, class=null function=helloWorld message=thrown in pre in %s +string(8) "function" + +Warning: helloWorld(): OpenTelemetry: post hook threw exception, class=null function=helloWorld message=thrown in post in %s +string(8) "original" +NULL \ No newline at end of file diff --git a/ext/tests/hooks_throw_exception_for_failed_call.phpt b/ext/tests/hooks_throw_exception_for_failed_call.phpt new file mode 100644 index 0000000..a763d86 --- /dev/null +++ b/ext/tests/hooks_throw_exception_for_failed_call.phpt @@ -0,0 +1,32 @@ +--TEST-- +Check if exceptions thrown in hooks interfere with internal exceptions +--EXTENSIONS-- +opentelemetry +--FILE-- + +--EXPECTF-- + +Warning: helloWorld(): OpenTelemetry: pre hook threw exception, class=null function=helloWorld message=pre in %s + +Warning: helloWorld(): OpenTelemetry: post hook threw exception, class=null function=helloWorld message=post in %s + +Fatal error: Uncaught ArgumentCountError: Too few arguments to function helloWorld(), 0 passed in %s +Stack trace: +#0 %s: helloWorld() +#1 {main} + thrown in %s diff --git a/ext/tests/multiple_hooks_modify_exception.phpt b/ext/tests/multiple_hooks_modify_exception.phpt deleted file mode 100644 index 509611e..0000000 --- a/ext/tests/multiple_hooks_modify_exception.phpt +++ /dev/null @@ -1,21 +0,0 @@ ---TEST-- -Check if hooks receive modified exception ---EXTENSIONS-- -opentelemetry ---FILE-- - throw new Exception(previous: $throwable)); -\OpenTelemetry\Instrumentation\hook(null, 'helloWorld', post: fn(mixed $object, array $params, mixed $return, Exception $throwable) => throw new Exception(previous: $throwable)); - -function helloWorld() { - throw new Exception('original'); -} - -try { - helloWorld(); -} catch (Exception $e) { - var_dump($e->getPrevious()?->getPrevious()?->getMessage()); -} -?> ---EXPECT-- -string(8) "original" diff --git a/ext/tests/post_hook_throws_exception.phpt b/ext/tests/post_hook_throws_exception.phpt index 198f64b..3bcab17 100644 --- a/ext/tests/post_hook_throws_exception.phpt +++ b/ext/tests/post_hook_throws_exception.phpt @@ -22,6 +22,7 @@ try { helloWorld(); } catch(Exception) {} ---EXPECT-- +--EXPECTF-- string(3) "pre" +Warning: helloWorld(): OpenTelemetry: post hook threw exception, class=null function=helloWorld message=error in %s \ No newline at end of file