diff --git a/src/ext/MemoryTracker.c b/src/ext/MemoryTracker.c index d3ad3cdfc..7e0886e76 100644 --- a/src/ext/MemoryTracker.c +++ b/src/ext/MemoryTracker.c @@ -66,9 +66,7 @@ typedef struct EmbeddedTrackingDataHeader EmbeddedTrackingDataHeader; struct DeserializedTrackingData { EmbeddedTrackingDataHeader* embedded; - void* stackTraceAddresses[ maxCaptureStackTraceDepth ]; - UInt32 suffixMagic; }; typedef struct DeserializedTrackingData DeserializedTrackingData; @@ -83,8 +81,9 @@ void constructMemoryTracker( MemoryTracker* memTracker ) memTracker->level = memoryTrackingLevel_all; memTracker->abortOnMemoryLeak = ELASTIC_APM_MEMORY_TRACKING_DEFAULT_ABORT_ON_MEMORY_LEAK; memTracker->allocatedPersistent = 0; + initIntrusiveDoublyLinkedList( &memTracker->allocatedPersistentBlocks ); memTracker->allocatedRequestScoped = 0; - initIntrusiveDoublyLinkedList( &memTracker->allocatedBlocks ); + initIntrusiveDoublyLinkedList( &memTracker->allocatedRequestScopedBlocks ); ELASTIC_APM_ASSERT_VALID_MEMORY_TRACKER( memTracker ); } @@ -138,6 +137,7 @@ void addToTrackedAllocatedBlocks( MemoryTracker* memTracker, const void* allocatedBlock, size_t originallyRequestedSize, + bool isPersistent, StringView filePath, UInt lineNumber, bool isString, @@ -146,8 +146,11 @@ void addToTrackedAllocatedBlocks( { EmbeddedTrackingDataHeader* trackingDataHeader = allocatedBlockToTrackingData( allocatedBlock, originallyRequestedSize ); ELASTIC_APM_ZERO_STRUCT( trackingDataHeader ); + UInt64* allocated = isPersistent ? &memTracker->allocatedPersistent : &memTracker->allocatedRequestScoped; + IntrusiveDoublyLinkedList* allocatedBlocks = isPersistent ? &memTracker->allocatedPersistentBlocks : &memTracker->allocatedRequestScopedBlocks; - addToIntrusiveDoublyLinkedListBack( &memTracker->allocatedBlocks, &trackingDataHeader->intrusiveNode ); + *allocated += originallyRequestedSize; + addToIntrusiveDoublyLinkedListBack( allocatedBlocks, &trackingDataHeader->intrusiveNode ); trackingDataHeader->prefixMagic = prefixMagicExpectedValue; trackingDataHeader->fileName = extractLastPartOfFilePathStringView( filePath ).begin; @@ -182,19 +185,19 @@ void memoryTrackerAfterAlloc( ELASTIC_APM_ASSERT_GE_UINT64( actuallyRequestedSize, originallyRequestedSize ); ELASTIC_APM_ASSERT_LE_UINT64( stackTraceAddressesCount, maxCaptureStackTraceDepth ); - UInt64* allocated = isPersistent ? &memTracker->allocatedPersistent : &memTracker->allocatedRequestScoped; - *allocated += originallyRequestedSize; - if ( actuallyRequestedSize > originallyRequestedSize ) + { addToTrackedAllocatedBlocks( memTracker, allocatedBlock, originallyRequestedSize, + isPersistent, filePath, lineNumber, isString, stackTraceAddresses, stackTraceAddressesCount ); + } ELASTIC_APM_ASSERT_VALID_MEMORY_TRACKER( memTracker ); } @@ -226,6 +229,7 @@ void removeFromTrackedAllocatedBlocks( MemoryTracker* memTracker, const void* allocatedBlock, size_t originallyRequestedSize, + IntrusiveDoublyLinkedList* allocatedBlocks, size_t* possibleActuallyRequestedSize ) { EmbeddedTrackingDataHeader* trackingDataHeader = allocatedBlockToTrackingData( allocatedBlock, originallyRequestedSize ); @@ -242,7 +246,7 @@ void removeFromTrackedAllocatedBlocks( memoryTrackerCalcSizeToAlloc(memTracker, originallyRequestedSize, trackingDataHeader->stackTraceAddressesCount ); removeCurrentNodeIntrusiveDoublyLinkedList( - nodeToIntrusiveDoublyLinkedListIterator( &memTracker->allocatedBlocks, &trackingDataHeader->intrusiveNode ) ); + nodeToIntrusiveDoublyLinkedListIterator( allocatedBlocks, &trackingDataHeader->intrusiveNode ) ); trackingDataHeader->prefixMagic = invalidMagicValue; memcpy( postHeader, &invalidMagicValue, ELASTIC_APM_FIELD_SIZEOF( DeserializedTrackingData, suffixMagic ) ); @@ -259,6 +263,7 @@ void memoryTrackerBeforeFree( ELASTIC_APM_ASSERT_VALID_PTR( possibleActuallyRequestedSize ); UInt64* allocated = isPersistent ? &memTracker->allocatedPersistent : &memTracker->allocatedRequestScoped; + IntrusiveDoublyLinkedList* allocatedBlocks = isPersistent ? &memTracker->allocatedPersistentBlocks : &memTracker->allocatedRequestScopedBlocks; ELASTIC_APM_ASSERT( *allocated >= originallyRequestedSize , "Attempting to free more %s memory than allocated. Allocated: %"PRIu64". Attempting to free: %"PRIu64 @@ -269,7 +274,7 @@ void memoryTrackerBeforeFree( // if the current level (i.e., at the moment of call to free()) includes tracking for each allocation // then the level at the moment of call to malloc() included tracking for each allocation as well if ( memTracker->level >= memoryTrackingLevel_eachAllocation ) - removeFromTrackedAllocatedBlocks( memTracker, allocatedBlock, originallyRequestedSize, possibleActuallyRequestedSize ); + removeFromTrackedAllocatedBlocks( memTracker, allocatedBlock, originallyRequestedSize, allocatedBlocks, possibleActuallyRequestedSize ); *allocated -= originallyRequestedSize; } @@ -357,10 +362,7 @@ String streamAllocCallStackTrace( } static -void reportAllocation( - const IntrusiveDoublyLinkedListNode* intrusiveListNode, - size_t allocationIndex, - size_t numberOfAllocations ) +void reportAllocation( const IntrusiveDoublyLinkedListNode* intrusiveListNode, size_t allocationIndex, size_t numberOfAllocations ) { const EmbeddedTrackingDataHeader* trackingDataHeader = fromIntrusiveNodeToTrackingData( intrusiveListNode ); @@ -387,9 +389,13 @@ void ELASTIC_APM_ON_MEMORY_LEAK_CUSTOM_FUNC(); static void verifyBalanceIsZero( const MemoryTracker* memTracker, String whenDesc, UInt64 allocated, bool isPersistent ) { - if ( allocated == 0 ) return; + if ( allocated == 0 ) + { + return; + } - const size_t numberOfAllocations = calcIntrusiveDoublyLinkedListSize( &memTracker->allocatedBlocks ); + const IntrusiveDoublyLinkedList* allocatedBlocks = isPersistent ? &memTracker->allocatedPersistentBlocks : &memTracker->allocatedRequestScopedBlocks; + const size_t numberOfAllocations = calcIntrusiveDoublyLinkedListSize( allocatedBlocks ); const size_t numberOfAllocationsToReport = ELASTIC_APM_MIN( numberOfAllocations, maxNumberOfLeakedAllocationsToReport ); const IntrusiveDoublyLinkedListNode* allocationsToReport[ maxNumberOfLeakedAllocationsToReport ]; @@ -397,7 +403,7 @@ void verifyBalanceIsZero( const MemoryTracker* memTracker, String whenDesc, UInt // because the code below might do more allocations { size_t allocationIndex = 0; - ELASTIC_APM_FOR_EACH_IN_INTRUSIVE_LINKED_LIST( allocationsIt, &memTracker->allocatedBlocks ) + ELASTIC_APM_FOR_EACH_IN_INTRUSIVE_LINKED_LIST( allocationsIt, allocatedBlocks ) { allocationsToReport[ allocationIndex++ ] = currentNodeIntrusiveDoublyLinkedList( allocationsIt ); if ( allocationIndex == numberOfAllocationsToReport ) break; @@ -417,7 +423,11 @@ void verifyBalanceIsZero( const MemoryTracker* memTracker, String whenDesc, UInt #ifdef ELASTIC_APM_ON_MEMORY_LEAK_CUSTOM_FUNC ELASTIC_APM_ON_MEMORY_LEAK_CUSTOM_FUNC(); #else - if ( memTracker->abortOnMemoryLeak ) elasticApmAbort(); + if ( memTracker->abortOnMemoryLeak ) + { + ELASTIC_APM_FORCE_LOG_CRITICAL("Aborting on memory leak..."); + elasticApmAbort(); + } #endif } diff --git a/src/ext/MemoryTracker.h b/src/ext/MemoryTracker.h index 66010fd53..40030c8b5 100644 --- a/src/ext/MemoryTracker.h +++ b/src/ext/MemoryTracker.h @@ -81,8 +81,9 @@ struct MemoryTracker bool abortOnMemoryLeak; UInt64 allocatedPersistent; + IntrusiveDoublyLinkedList allocatedPersistentBlocks; UInt64 allocatedRequestScoped; - IntrusiveDoublyLinkedList allocatedBlocks; + IntrusiveDoublyLinkedList allocatedRequestScopedBlocks; }; typedef struct MemoryTracker MemoryTracker; @@ -91,9 +92,9 @@ void assertValidMemoryTracker( MemoryTracker* memTracker ) { ELASTIC_APM_ASSERT_VALID_PTR( memTracker ); ELASTIC_APM_ASSERT_VALID_MEMORY_TRACKING_LEVEL( memTracker->level ); - ELASTIC_APM_ASSERT_VALID_INTRUSIVE_LINKED_LIST( &memTracker->allocatedBlocks ); + ELASTIC_APM_ASSERT_VALID_INTRUSIVE_LINKED_LIST( &memTracker->allocatedPersistentBlocks ); + ELASTIC_APM_ASSERT_VALID_INTRUSIVE_LINKED_LIST( &memTracker->allocatedRequestScopedBlocks ); } -ELASTIC_APM_SUPPRESS_UNUSED( assertValidMemoryTracker ); #define ELASTIC_APM_ASSERT_VALID_MEMORY_TRACKER( memTracker ) \ ELASTIC_APM_ASSERT_VALID_OBJ( assertValidMemoryTracker( memTracker ) ) \ diff --git a/src/ext/elastic_apm_API.c b/src/ext/elastic_apm_API.c index 80c0a3bd7..31ea04045 100644 --- a/src/ext/elastic_apm_API.c +++ b/src/ext/elastic_apm_API.c @@ -94,42 +94,121 @@ static CallToInterceptData g_functionsToInterceptData[maxFunctionsToIntercept]; static uint32_t g_interceptedCallInProgressRegistrationId = 0; +static +String buildFuncDescForInterceptRegistrationId( uint32_t interceptRegistrationId, TextOutputStream* txtOutStream ) +{ + ELASTIC_APM_ASSERT(interceptRegistrationId < g_nextFreeFunctionToInterceptId, + "interceptRegistrationId: %u, g_nextFreeFunctionToInterceptId: %u" + , (unsigned)interceptRegistrationId, (unsigned)g_nextFreeFunctionToInterceptId ); + + zend_function* funcEntry = g_functionsToInterceptData[ interceptRegistrationId ].funcEntry; + ELASTIC_APM_ASSERT(funcEntry != NULL, "interceptRegistrationId: %u", (unsigned)interceptRegistrationId); + + String funcName = ZSTR_VAL(funcEntry->internal_function.function_name); + zend_class_entry* classEntry = funcEntry->internal_function.scope; + String className = classEntry == NULL ? NULL : ZSTR_VAL(classEntry->name); + bool isStatic = (funcEntry->internal_function.fn_flags & ZEND_ACC_STATIC) != 0; + + return className == NULL ? funcName : streamPrintf(txtOutStream, "%s%s%s", className, isStatic ? "::" : "->", funcName); +} + +static +String findReasonCannotCallPhpCode() +{ + if (!EG(active)) + { + return "!EG(active)"; + } + + if (EG(exception) != NULL) + { + return "EG(exception)"; + } + + return NULL; +} + +static +String buildFuncExitDesc(zval* return_value, zend_object* exception, TextOutputStream* txtOutStream) +{ + if (exception == NULL) + { + return streamPrintf(txtOutStream, "exited with return value of type %s (%u)", zend_get_type_by_const(Z_TYPE_P(return_value)), Z_TYPE_P(return_value)); + } + + if ((exception->ce == NULL) || (exception->ce->name == NULL)) + { + return streamPrintf(txtOutStream, "thrown object of unknown type"); + } + + return streamPrintf(txtOutStream, "thrown object of type %s", ZSTR_VAL(exception->ce->name)); +} + static void internalFunctionCallInterceptingImpl( uint32_t interceptRegistrationId, zend_execute_data* execute_data, zval* return_value ) { ResultCode resultCode; + bool shouldCallPostHook; + char txtOutStreamBuf[ ELASTIC_APM_TEXT_OUTPUT_STREAM_ON_STACK_BUFFER_SIZE ]; + TextOutputStream txtOutStream = ELASTIC_APM_TEXT_OUTPUT_STREAM_FROM_STATIC_BUFFER( txtOutStreamBuf ); + String funcDesc = buildFuncDescForInterceptRegistrationId( interceptRegistrationId, &txtOutStream ); // We SHOULD NOT log before resetting state if forked because logging might be using thread synchronization // which might deadlock in forked child ELASTIC_APM_CALL_IF_FAILED_GOTO( elasticApmEnterAgentCode( __FILE__, __LINE__, __FUNCTION__ ) ); - ELASTIC_APM_LOG_TRACE_FUNCTION_ENTRY_MSG( "interceptRegistrationId: %u", interceptRegistrationId ); - - bool shouldCallPostHook; + ELASTIC_APM_LOG_TRACE_FUNCTION_ENTRY_MSG( "interceptRegistrationId: %u, funcDesc: %s", interceptRegistrationId, funcDesc ); if ( g_interceptedCallInProgressRegistrationId != 0 ) { - ELASTIC_APM_LOG_TRACE_FUNCTION_ENTRY_MSG( - "There's already an intercepted call in progress with interceptRegistrationId: %u." - "Nesting intercepted calls is not supported yet so invoking the original handler directly..." - , g_interceptedCallInProgressRegistrationId ); - g_functionsToInterceptData[ interceptRegistrationId ].originalHandler( execute_data, return_value ); + String inProgressFuncDesc = buildFuncDescForInterceptRegistrationId( g_interceptedCallInProgressRegistrationId, &txtOutStream ); + ELASTIC_APM_LOG_TRACE( + "There's already an intercepted call in progress with interceptRegistrationId: %u (%s)." + " New call interceptRegistrationId: %u (%s)." + " Nesting intercepted calls is not supported yet so invoking the original handler directly..." + , g_interceptedCallInProgressRegistrationId, inProgressFuncDesc + , interceptRegistrationId, funcDesc ); + g_functionsToInterceptData[ interceptRegistrationId ].originalHandler( execute_data, /* out */ return_value ); return; } g_interceptedCallInProgressRegistrationId = interceptRegistrationId; shouldCallPostHook = tracerPhpPartInterceptedCallPreHook( interceptRegistrationId, execute_data ); - g_functionsToInterceptData[ interceptRegistrationId ].originalHandler( execute_data, return_value ); + g_functionsToInterceptData[ interceptRegistrationId ].originalHandler( execute_data, /* out */ return_value ); + ELASTIC_APM_LOG_TRACE( + "Call to the original handler exited" + "; %s" + "; interceptRegistrationId: %u (%s)" + , buildFuncExitDesc(return_value, EG(exception), &txtOutStream) + , interceptRegistrationId, funcDesc ); if ( shouldCallPostHook ) { - tracerPhpPartInterceptedCallPostHook( interceptRegistrationId, return_value ); + String reasonCannotCallPhpCode = findReasonCannotCallPhpCode(); + if (reasonCannotCallPhpCode == NULL) + { + resultCode = tracerPhpPartInterceptedCallPostHook( return_value ); + if (resultCode != resultSuccess) + { + ELASTIC_APM_LOG_ERROR( "Post-hook call failed" + "; interceptRegistrationId: %u, funcDesc: %s, resultCode: %s (%d)" + , interceptRegistrationId, funcDesc + , resultCodeToString( resultCode ), resultCode ); + } + } + else + { + ELASTIC_APM_LOG_DEBUG( "Post-hook cannot be called" + "; reasonCannotCallPhpCode: %s; interceptRegistrationId: %u, funcDesc: %s" + , reasonCannotCallPhpCode, interceptRegistrationId, funcDesc ); + } } g_interceptedCallInProgressRegistrationId = 0; - ELASTIC_APM_LOG_TRACE_FUNCTION_EXIT_MSG( "interceptRegistrationId: %u", interceptRegistrationId ); resultCode = resultSuccess; finally: + ELASTIC_APM_LOG_TRACE_FUNCTION_EXIT_MSG( "resultCode: %s (%d), interceptRegistrationId: %u, funcDesc: %s", resultCodeToString( resultCode ), resultCode, interceptRegistrationId, funcDesc ); + ELASTIC_APM_UNUSED(resultCode); return; failure: @@ -201,7 +280,7 @@ ResultCode elasticApmInterceptCallsToInternalMethod( String className, String me finally: - ELASTIC_APM_LOG_DEBUG_RESULT_CODE_FUNCTION_EXIT(); + ELASTIC_APM_LOG_DEBUG_RESULT_CODE_FUNCTION_EXIT_MSG( "className: `%s'; methodName: `%s', interceptRegistrationId: %u", className, methodName, *interceptRegistrationId ); return resultCode; failure: @@ -231,7 +310,7 @@ ResultCode elasticApmInterceptCallsToInternalFunctionEx( String functionName, ui finally: - ELASTIC_APM_LOG_DEBUG_RESULT_CODE_FUNCTION_EXIT_MSG( "interceptRegistrationId: %u", *interceptRegistrationId ); + ELASTIC_APM_LOG_DEBUG_RESULT_CODE_FUNCTION_EXIT_MSG( "functionName: `%s', interceptRegistrationId: %u", functionName, *interceptRegistrationId ); return resultCode; failure: diff --git a/src/ext/lifecycle.c b/src/ext/lifecycle.c index 2bc96f108..9cb72f241 100644 --- a/src/ext/lifecycle.c +++ b/src/ext/lifecycle.c @@ -449,6 +449,7 @@ void setLastPhpErrorData( int type, const char* fileName, uint32_t lineNumber, c tempPhpErrorData.type = type; tempPhpErrorData.lineNumber = lineNumber; + freeAndZeroLastPhpErrorData( &g_lastPhpErrorData ); shallowCopyLastPhpErrorData( &tempPhpErrorData, &g_lastPhpErrorData ); zeroLastPhpErrorData( &tempPhpErrorData ); g_lastPhpErrorDataSet = true; diff --git a/src/ext/tracer_PHP_part.c b/src/ext/tracer_PHP_part.c index 4c447d21c..7bfd8ba10 100644 --- a/src/ext/tracer_PHP_part.c +++ b/src/ext/tracer_PHP_part.c @@ -159,11 +159,12 @@ bool tracerPhpPartInterceptedCallPreHook( uint32_t interceptRegistrationId, zend , interceptedCallArgsCount + 2 , phpPartArgs , /* out */ &preHookRetVal ) ); - ELASTIC_APM_LOG_TRACE( "Successfully finished call to PHP part. Return value type: %u", Z_TYPE_P( &preHookRetVal ) ); + ELASTIC_APM_LOG_TRACE( "Finished call to PHP part. Return value type: %s (%u)" + , zend_get_type_by_const(Z_TYPE(preHookRetVal)), Z_TYPE(preHookRetVal) ); if ( Z_TYPE( preHookRetVal ) != IS_FALSE && Z_TYPE( preHookRetVal ) != IS_TRUE ) { - ELASTIC_APM_LOG_ERROR( "Call to PHP part returned value that is not bool. Return value type: %u", Z_TYPE_P( &preHookRetVal ) ); + ELASTIC_APM_LOG_ERROR( "Call to PHP part returned value that is not bool. Return value type: %s (%u)", zend_get_type_by_const(Z_TYPE(preHookRetVal)), Z_TYPE(preHookRetVal) ); ELASTIC_APM_SET_RESULT_CODE_AND_GOTO_FAILURE(); } shouldCallPostHook = ( Z_TYPE( preHookRetVal ) == IS_TRUE ); @@ -181,10 +182,10 @@ bool tracerPhpPartInterceptedCallPreHook( uint32_t interceptRegistrationId, zend goto finally; } -void tracerPhpPartInterceptedCallPostHook( uint32_t dbgInterceptRegistrationId, zval* interceptedCallRetValOrThrown ) +ResultCode tracerPhpPartInterceptedCallPostHook( zval* interceptedCallRetValOrThrown ) { - ELASTIC_APM_LOG_TRACE_FUNCTION_ENTRY_MSG( "dbgInterceptRegistrationId: %u; interceptedCallRetValOrThrown type: %u" - , dbgInterceptRegistrationId, Z_TYPE_P( interceptedCallRetValOrThrown ) ); + ELASTIC_APM_LOG_TRACE_FUNCTION_ENTRY_MSG( "interceptedCallRetValOrThrown type: %s (%u)" + , zend_get_type_by_const( Z_TYPE_P( interceptedCallRetValOrThrown ) ), Z_TYPE_P( interceptedCallRetValOrThrown ) ); ResultCode resultCode; zval phpPartArgs[ 2 ]; @@ -206,10 +207,10 @@ void tracerPhpPartInterceptedCallPostHook( uint32_t dbgInterceptRegistrationId, finally: - ELASTIC_APM_LOG_TRACE_RESULT_CODE_FUNCTION_EXIT_MSG( "dbgInterceptRegistrationId: %u; interceptedCallRetValOrThrown type: %u." - , dbgInterceptRegistrationId, Z_TYPE_P( interceptedCallRetValOrThrown ) ); + ELASTIC_APM_LOG_TRACE_RESULT_CODE_FUNCTION_EXIT_MSG( "interceptedCallRetValOrThrown type: %s (%u)" + , zend_get_type_by_const( Z_TYPE_P( interceptedCallRetValOrThrown ) ), Z_TYPE_P( interceptedCallRetValOrThrown ) ); ELASTIC_APM_UNUSED( resultCode ); - return; + return resultCode; failure: goto finally; diff --git a/src/ext/tracer_PHP_part.h b/src/ext/tracer_PHP_part.h index 97323ced2..4f55549c3 100644 --- a/src/ext/tracer_PHP_part.h +++ b/src/ext/tracer_PHP_part.h @@ -28,6 +28,6 @@ void shutdownTracerPhpPart( const ConfigSnapshot* config ); bool tracerPhpPartInterceptedCallPreHook( uint32_t interceptRegistrationId, zend_execute_data* execute_data ); -void tracerPhpPartInterceptedCallPostHook( uint32_t dbgInterceptRegistrationId, zval* interceptedCallRetValOrThrown ); +ResultCode tracerPhpPartInterceptedCallPostHook( zval* interceptedCallRetValOrThrown ); void tracerPhpPartInterceptedCallEmptyMethod(); diff --git a/tests/ElasticApmTests/ComponentTests/Util/HttpServerStarter.php b/tests/ElasticApmTests/ComponentTests/Util/HttpServerStarter.php index e0117bd95..9d570ccaf 100644 --- a/tests/ElasticApmTests/ComponentTests/Util/HttpServerStarter.php +++ b/tests/ElasticApmTests/ComponentTests/Util/HttpServerStarter.php @@ -97,6 +97,14 @@ protected function startHttpServer(array $portsInUse, int $portsToAllocateCount $currentTryPorts = []; self::findFreePortsToListen($portsInUse, $portsToAllocateCount, $lastTriedPort, /* out */ $currentTryPorts); Assert::assertSame($portsToAllocateCount, count($currentTryPorts)); + /** + * We repeat $currentTryPorts type to fix PHPStan's + * "Unable to resolve the template type T in call to method static method" error + * + * @var int[] $currentTryPorts + * @noinspection PhpRedundantVariableDocTypeInspection + */ + $lastTriedPort = ArrayUtilForTests::getLastValue($currentTryPorts); $currentTrySpawnedProcessInternalId = InfraUtilForTests::generateSpawnedProcessInternalId(); $cmdLine = $this->buildCommandLine($currentTryPorts); $envVars = $this->buildEnvVars($currentTrySpawnedProcessInternalId, $currentTryPorts);