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

Support logging of GC invocations and methods enter / leave to ftrace. #52

Merged
merged 1 commit into from
Dec 16, 2023

Conversation

gofman
Copy link

@gofman gofman commented Dec 8, 2023

This is an example of how it may look like in gpuvis:
1

This requires some manual setup of ftrace filesystem so trace_marker file is available to the process (which file is specified with WINE_FTRACE_FILE which, if successfully open, triggers recording of markers). E. g., like this:

sudo mkdir ~/tracing
sudo mount -t tracefs nodev ~/tracing
sudo chmod a+rx ~/tracing
sudo chmod a+rw ~/tracing/trace_marker

and then running with WINE_FTRACE_FILE=~/tracing/trace_marker

The part related to method leave / enter is a bit challenging to use OOTB as by default there are way too many events and that is not feasible to handle in gpuvis currently. Also reporting that as interval is complicated (needs tracking the context and unwinds). Yet if it is possible to reasonably limit the amount of logged methods that might work too.

@madewokherd
Copy link
Owner

One thing that confuses me: it seems like the writes don't have a null terminator or delimiter of any sort. How does the other side know where each record ends?

Also, is WINE_FTRACE_FILE a wine path, or a unix path? I'm surprised no conversion is needed.

It's definitely possible to limit the output of WINE_MONO_TRACE, especially if you select individual methods or types.

If we want to save contexts for method traces, I think we need 2 things:

  • The JIT needs to be modified to add an extra local in case of tracing, and pass its address to mono_trace_enter_method and mono_trace_leave_method, so that the ctx can be stored.
  • A "finally" block needs to be added to the traced methods so that the "exited by exception" case is logged. I think this would be a good thing for debugging regardless, it's often confusing when an exception crosses traced frames.

Does that make sense to you? I might work on that as a further enhancement if so.

I think this is ready as long as there isn't a need for a delimiter.

@gofman
Copy link
Author

gofman commented Dec 11, 2023

One thing that confuses me: it seems like the writes don't have a null terminator or delimiter of any sort. How does the other side know where each record ends?

This is a special file handled in kernel. Once we write to it, the write handler is invoked and I think it just treats single write as single event. There is also no zero or other delimiter in gpuvis sample trace marker implementation (https://github.com/mikesart/gpuvis/blob/97136bd35ecd7e7b1b6c7403e8525bb8a5b67eae/sample/gpuvis_trace_utils.h#L482C1-L482C1).

Also, is WINE_FTRACE_FILE a wine path, or a unix path? I'm surprised no conversion is needed.

It is supposed to be Unix path. That works because Wine's CreateFileW (specifically, dos to Unix path conversion in ntdll/unix/file.c:get_full_path_helper() and then file name handling in NtCreateFile) handles Unix paths starting with '/'. So probably we don't need a separate Wine specific wine_get_dos_file_name()?

It's definitely possible to limit the output of WINE_MONO_TRACE, especially if you select individual methods or types.

If we want to save contexts for method traces, I think we need 2 things:

  • The JIT needs to be modified to add an extra local in case of tracing, and pass its address to mono_trace_enter_method and mono_trace_leave_method, so that the ctx can be stored.
  • A "finally" block needs to be added to the traced methods so that the "exited by exception" case is logged. I think this would be a good thing for debugging regardless, it's often confusing when an exception crosses traced frames.

Does that make sense to you? I might work on that as a further enhancement if so.

Yes, sure. I am just a bit unsure if that worth such complications. If you think it is and find it useful, I would maybe suggest to consider completely decoupling that from mono trace enter / leave handlers as those take a long time to execute, it is probably possible to print method name on enter / leave to ftrace with much less overhead and thus make it more useful for perf issues analysis.

@madewokherd
Copy link
Owner

Also, is WINE_FTRACE_FILE a wine path, or a unix path? I'm surprised no conversion is needed.

It is supposed to be Unix path. That works because Wine's CreateFileW (specifically, dos to Unix path conversion in ntdll/unix/file.c:get_full_path_helper() and then file name handling in NtCreateFile) handles Unix paths starting with '/'. So probably we don't need a separate Wine specific wine_get_dos_file_name()?

I'm not sure if we should trust that that behavior will be preserved. Paths starting with / are valid on Windows and work in a different way.

Yes, sure. I am just a bit unsure if that worth such complications. If you think it is and find it useful, I would maybe suggest to consider completely decoupling that from mono trace enter / leave handlers as those take a long time to execute, it is probably possible to print method name on enter / leave to ftrace with much less overhead and thus make it more useful for perf issues analysis.

Good point, though that means we also need a way to turn off the enter/leave calls to avoid that overhead. And formatting a string requires an allocation as opposed to the unmanaged way which would be to put the string on the stack. Correctly generating a call to sprintf seems tricky to me so it might make more sense to use a different pair of icalls.

@gofman
Copy link
Author

gofman commented Dec 11, 2023

Also, is WINE_FTRACE_FILE a wine path, or a unix path? I'm surprised no conversion is needed.

It is supposed to be Unix path. That works because Wine's CreateFileW (specifically, dos to Unix path conversion in ntdll/unix/file.c:get_full_path_helper() and then file name handling in NtCreateFile) handles Unix paths starting with '/'. So probably we don't need a separate Wine specific wine_get_dos_file_name()?

I'm not sure if we should trust that that behavior will be preserved. Paths starting with / are valid on Windows and work in a different way.

Well, the other way is to use wine_get_dos_filename() if available, but in theory it can also change over the years to come, while should not for no reason. But all the same is true for Unix path handling, so I'd suggest to just rely on that for now on the basis that it is simpler. But if you feel strong about preferring something like wine_get_dos_filename at once please let me know, I will do it this way.

@madewokherd madewokherd merged commit 4ffb451 into madewokherd:develop Dec 16, 2023
4 checks passed
@madewokherd
Copy link
Owner

Given that this is a debugging feature, I guess it's fine if it briefly "breaks" requiring one to pass in a Windows path.

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.

2 participants