Skip to content

dtrace add prev method and prev class #10580

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

Open
wants to merge 3 commits into
base: master
Choose a base branch
from

Conversation

tombokombo
Copy link

Hi, we are playing around with coroutines etc.. we are using dtrace for debugging and we need to know the caller, so this PR extends existing dtrace probes.

@iluuu1994
Copy link
Member

I don't know dtrace, so somebody else should review this 🙂

@@ -68,20 +68,22 @@ ZEND_API void dtrace_execute_ex(zend_execute_data *execute_data)
if (DTRACE_FUNCTION_ENTRY_ENABLED() || DTRACE_FUNCTION_RETURN_ENABLED()) {
classname = get_active_class_name(&scope);
funcname = get_active_function_name();
prev_funcname = get_prev_active_function_name();
prev_classname = get_prev_active_class_name(&scope);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

question: would not it be better if it had its own scope data ?

Copy link
Author

@tombokombo tombokombo Feb 14, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You are so right, I was overriding it. Haven't noticed that, as scope is basically useless. Fixed.

@devnexen
Copy link
Member

I don't know dtrace, so somebody else should review this 🙂

Fair point 🙂 the Dtrace part looks ok if we want all in one probe that's the simplest way but less sure for the zend part.

@tombokombo
Copy link
Author

I don't know dtrace, so somebody else should review this slightly_smiling_face

Fair point slightly_smiling_face the Dtrace part looks ok if we want all in one probe that's the simplest way but less sure for the zend part.

In linear execution the probe provides enough info ( caller is known from previous probe call). With co-routines and context switching, you need some hints about caller. I would expect it in same probe, because it's one event (fn entry or return).

@devnexen
Copy link
Member

how does a typical line looks line with your change ?

@tombokombo
Copy link
Author

@devnexen what do you mean, output from tracing tool?

@devnexen
Copy link
Member

yes before and after the changes for example.

@tombokombo
Copy link
Author

tombokombo commented Feb 15, 2023

depend on tracing tool eg with stap https://www.php.net/manual/en/features.dtrace.systemtap.php , it depends on your chosen formatting, basically your are just extracting args

probe process("sapi/cli/php").provider("php").mark("function__entry") {
    printf("Probe function__entry\n");
    printf("  function_name %s\n", user_string($arg1));
    printf("  request_file %s\n", user_string($arg2));
    printf("  lineno %d\n", $arg3);
    printf("  classname %s\n", user_string($arg4));
    printf("  scope %s\n", user_string($arg5));

I'm tracing this probes with bpf, and trying to build callgrind, but for sake of example
before:

ENTRY    - test_ns\Foo.getdata [ /data/tom.php ]
ENTRY    - test_ns\Bar.get [ /data/tom.php ]
RETURN   - test_ns\Bar.get [ /data/tom.php ] spent 1063387247 ns
RETURN   - test_ns\Foo.getdata [ /data/tom.php ] spent 1217172339 ns

This is linear case, time spend is calculated as time between ENTRY and RETURN. You can clearly see call chain
main()->Foo.getData()->Bar.get()
after

ENTRY    test_ns\Foo.getdata [ /data/tom.php ] called by .main 
ENTRY    test_ns\Bar.get [ /data/tom.php ] called by test_ns\Foo.getdata
RETURN   test_ns\Bar.get [ /data/tom.php ] called by test_ns\Foo.getdata spent 1063387247 ns
RETURN   test_ns\Foo.getdata [ /data/tom.php ] called by .main spent 1217172339 ns

Little more complicated example with coroutine, one courutine is calling the same as before
c1 - main()->Foo.getData()->Bar.get()
second one just
c2-> main()->Bar.get()

ENTRY {closure} [ /data/tombo/tom.coroutine.php ] 
ENTRY {closure} [ /data/tombo/tom.coroutine.php ]
ENTRY Foo.getdata [ /data/tombo/tom.coroutine.php ] 
ENTRY {closure} [ /data/tombo/tom.coroutine.php ]
ENTRY Bar.get [ /data/tombo/tom.coroutine.php ] 
RETURN {closure} [ /data/tombo/tom.coroutine.php ]
ENTRY Bar.get [ /data/tombo/tom.coroutine.php ]
RETURN Bar.get [ /data/tombo/tom.coroutine.php ]
RETURN {closure} [ /data/tombo/tom.coroutine.php ]
RETURN Bar.get [ /data/tombo/tom.coroutine.php ]
RETURN Foo.getdata [ /data/tombo/tom.coroutine.php ]
RETURN {closure} [ /data/tombo/tom.coroutine.php ]

the problem is which Bar.get() entry belongs to which return from Bar.get(). But even with information about caller, the problem persist when you call main()->Bar.get() from n-coutroutines, this would need some kind of ID. But I'm creating callgrind and knowing that main called bar-get() n times, should be enough.
Coroutines with this patch

ENTRY {closure} [ /data/tombo/tom.coroutine.php ] called by 
ENTRY {closure} [ /data/tombo/tom.coroutine.php ] called by
ENTRY Foo.getdata [ /data/tombo/tom.coroutine.php ] called by {closure} 
ENTRY {closure} [ /data/tombo/tom.coroutine.php ] called by
ENTRY Bar.get [ /data/tombo/tom.coroutine.php ] called by {closure} 
RETURN {closure} [ /data/tombo/tom.coroutine.php ] called by
ENTRY Bar.get [ /data/tombo/tom.coroutine.php ] called by Foo.getdata 
RETURN Bar.get [ /data/tombo/tom.coroutine.php ] called by {closure} 
RETURN {closure} [ /data/tombo/tom.coroutine.php ] called by
RETURN Bar.get [ /data/tombo/tom.coroutine.php called ] by Foo.getdata 
RETURN Foo.getdata [ /data/tombo/tom.coroutine.php called ] by {closure} 
RETURN .{closure} [ /data/tombo/tom.coroutine.php called by

@devnexen
Copy link
Member

Thanks we can have an idea of the added value here indeed.

Comment on lines +380 to +382
ZEND_API const char *get_prev_active_class_name(const char **space);
ZEND_API const char *get_active_function_name(void);
ZEND_API const char *get_prev_active_function_name(void);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I wouldn't like to add these new function to public API.
I won't object of you move their implementation into zend_dtrace.c.

Copy link
Member

@dstogov dstogov left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sorry, it seems we missed this PR. Only few notes:

  • I wouldn't object if get_prev_active_class_name() and get_prev_active_function_name() implementation would be moved into zend_dtrace.c.
  • can we test this in some way?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants