Isolate exception state for hooks (#118)

* Isolate exception state for hooks * Consistent naming. * Fix formatting and test typo * Fixed test list in PECL package.xml * Save and restore execute_data->opline
open-telemetry · Jan 22, 2024 · d4e11b6 · d4e11b6
1 parent 745fe0c
commit d4e11b6
Show file tree

Hide file tree

Showing 6 changed files with 159 additions and 46 deletions.
diff --git 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, &params[2], &params[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(&params[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, &params[4], &params[5],
+                                             "post hook");
 
         zval_dtor(&ret);
     }

diff --git a/ext/package.xml b/ext/package.xml
@@ -61,12 +61,13 @@
         <file name="function_closure.phpt" role="test"/>
         <file name="function_first_class_callable.phpt" role="test"/>
         <file name="function_internal.phpt" role="test"/>
+        <file name="hooks_throw_exception.phpt" role="test"/>
+        <file name="hooks_throw_exception_for_failed_call.phpt" role="test"/>
         <file name="invalid_post_callback_signature.phpt" role="test"/>
         <file name="invalid_pre_callback_signature.phpt" role="test"/>
         <file name="invalid_pre_callback_signature_with_function.phpt" role="test"/>
         <file name="modify_named_params.phpt" role="test"/>
         <file name="modify_params.phpt" role="test"/>
-        <file name="multiple_hooks_modify_exception.phpt" role="test"/>
         <file name="multiple_hooks_modify_params.phpt" role="test"/>
         <file name="multiple_hooks_modify_returnvalue.phpt" role="test"/>
         <file name="post_hook_return_ignored_without_type.phpt" role="test"/>

diff --git a/ext/tests/hooks_throw_exception.phpt 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--
+<?php
+\OpenTelemetry\Instrumentation\hook(null, 'helloWorld', pre: fn() => 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
diff --git a/ext/tests/hooks_throw_exception_for_failed_call.phpt 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--
+<?php
+function helloWorld($argument) {
+    var_dump('inside');
+}
+\OpenTelemetry\Instrumentation\hook(
+    null,
+    'helloWorld',
+    pre: static function () : void {
+        throw new \Exception('pre');
+    },
+    post: static function () : void {
+        throw new \Exception('post');
+    }
+);
+helloWorld();
+?>
+--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
diff --git 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