Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add observeAll() to make it possible to instrument all function calls #158

Open
wants to merge 15 commits into
base: main
Choose a base branch
from

Conversation

LionsAd
Copy link

@LionsAd LionsAd commented Jan 16, 2025

This adds an observeAll() function, which works in parallel to registered hooks.

I wanted to test what the overhead of a PHP based xhprof-compatible profiler would be in comparison to xhprof and xhprof without any processing (just the zend_execute_ex overhead).

Note: Claude 3.5 sonnet helped implement this.

--

Some notes

  • Several global observers can be active at a time
  • Passing null for both hooks disables all global observers

@LionsAd LionsAd requested a review from a team as a code owner January 16, 2025 23:29
@LionsAd
Copy link
Author

LionsAd commented Jan 16, 2025

Sorry for the mess with #157.

Here is a xhprof compatible profiler using this (unoptimized obviously):

<?php

class XhprofCompatProfiler {
    private static array $startTimes = [];
    private static array $data = [];
    private static array $callStack = ['main()'];
    private static float $profileStartTime;
    
    public static function start(): void {
        self::$profileStartTime = microtime(true);
        
        // Initialize main() entry
        self::$data['main()'] = [
            'ct' => 1,
            'wt' => 0,
        ];
        
        $preHook = function($object, $args, $scope, $function) {
            $startTime = microtime(true);
            
            $functionName = self::getFunctionName($object, $scope, $function);
            $parent = end(self::$callStack);
            $key = "$parent==>$functionName";
            
            // Push to call stack
            self::$callStack[] = $functionName;
            
            // Store start time and memory
            self::$startTimes[$key] = $startTime;
            
            // Initialize data structure if not exists
            if (!isset(self::$data[$key])) {
                self::$data[$key] = [
                    'ct' => 0,    // Call count
                    'wt' => 0,    // Wall time
                ];
            }
            
            // Increment call count
            self::$data[$key]['ct']++;
        };
        
        $postHook = function($class, array $params, $returnValue, ?Throwable $exception) {
            // The current function we're exiting
            $functionName = array_pop(self::$callStack);
    
            // The parent function that called it
            $parent = end(self::$callStack); // Last element without removing
    
            $endTime = microtime(true);
            
            $key = "$parent==>$functionName";
            
            // Update metrics
            if (isset(self::$startTimes[$key])) {
                $startTime = self::$startTimes[$key];
                
                // Wall time in microseconds
                $wallTime = ($endTime - $startTime) * 1000;
                
                // Update data
                self::$data[$key]['wt'] += (int)$wallTime;
                
                // Cleanup
                unset(self::$startTimes[$key]);
            }
        };
        
        \OpenTelemetry\Instrumentation\observeAll($preHook, $postHook);
    }
    
    public static function stop(): array {
        \OpenTelemetry\Instrumentation\observeAll();
        $endTime = microtime(true);
        
        // Update main() wall time
        self::$data['main()']['wt'] = (int)(($endTime - self::$profileStartTime) * 1000);
        
        return self::$data;
    }
    
    private static function getFunctionName($object, ?string $scope, string $function): string {
        if ($scope) {
            return "$scope::$function";
        }
        if ($object) {
            return get_class($object) . "::$function";
        }
        return $function;
    }
}

// Usage example:
// Start profiling
XhprofCompatProfiler::start();

// Your code here
function test() {
    static $rec = 0;
    if ($rec == 100) {
      return;
    }

    $rec++;
    test();
    $rec--;
    if ($rec == 0) {
      sleep(1);
    }
    return str_repeat('a', 1000000);
}
test();

// Stop profiling and get results
$data = XhprofCompatProfiler::stop();

// Print results
print_r($data);

@LionsAd LionsAd force-pushed the untracked--wildcard-observer branch from b8c6a58 to ebcd04b Compare January 17, 2025 04:00
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

1 participant