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

Instrumentation fixes for #176 and #181 #179

Merged
merged 12 commits into from
Jan 12, 2020
Merged

Instrumentation fixes for #176 and #181 #179

merged 12 commits into from
Jan 12, 2020

Conversation

0xworks
Copy link
Contributor

@0xworks 0xworks commented Nov 29, 2019

Describe the issue (if no issue has been made)

Some small tidy ups to Instrumentor:

  • Added mutex to Instrumentor to avoid jumbled output if profiling multiple threads.
  • Removed unused InstrumentationSession. Note that InstrumentationSession was also a potential memory leak if BeginSession()/EndSession() are not perfectly paired.
  • Used InstrumentationSession to ensure that new a BeginSession() will cleanly end any previously existing session.
  • Removed std::hash<> hack on ThreadId. The code is cleaner without it (and still works as far as I can tell)

PR impact

Fixes #176
Fixes #181

Additional context

  • There is still a memory leak if an instrumentation session is begun but not ended when app exits.
    This could be easily fixed (by making m_CurrentSession into a Hazel::Scope, but it comes at the cost of having to add a constructor for InstrumentationSession (Hazel::CreateScope({name}) will not work)

  • One could remove InstrumentationSession (this was my first idea), and use m_OutputStream.is_open() in place of checking for non-null m_CurrentSession. However, I've left InstrumentationSession in there as it could come in useful later (for example: If it is desired to create instrumentation sessions that only capture particular categories of profiling output - you will need to track which categories are active in the InstrumentationSession instance)

  • I have not addressed the concurrent start timestamp issue, as Cherno has said he is going to address it in an upcoming episode, and he probably has his own idea for how to fix it.
    (my suggestion would be a thread_local static counter that is incremented/decremented automatically via InstrumentationTimer RAII. Just add this counter on to the timestamp. (yes, it will result in timestamps that are a few ticks off, but a tick here is 0.001 of a millisecond... it shouldn't matter)

Reasons:
1) It isnt used anywhere
2) It is buggy (e.g. memory leak) if you were to BeginSession() another session (without EndSession(), or were to BeginSession() from differnet threads.
@WhoseTheNerd
Copy link
Contributor

Why does code commited have whitespace inconsistency?

@0xworks
Copy link
Contributor Author

0xworks commented Nov 29, 2019

There are some problems with BeginSession() / EndSession() as currently designed.

  1. If/when multiple threads are introduced then there will be no guarantee that Begin/End session calls are nicely paired up - there probably needs to be one instance of Instrumentor per thread (instead of global singleton).
  2. Even within one thread, there is nothing stopping someone from accidentally BeginSession()'ing without EndSession()'ing first... with the result that the output .json files are broken.

@0xworks
Copy link
Contributor Author

0xworks commented Nov 29, 2019

Why does code commited have whitespace inconsistency?

Whoops, sorry. I use spaces. Cherno uses tabs. Should there be a .editorconfig?

@WhoseTheNerd
Copy link
Contributor

WhoseTheNerd commented Nov 29, 2019

Doesn't .editorconfig do nothing?
Also you still didn't fix the white-space inconsistencies.

@Puddlestomper
Copy link
Contributor

Either way, we have noted in our contribution guidelines that we use tabs and not spaces.

@0xworks
Copy link
Contributor Author

0xworks commented Nov 29, 2019

Doesn't .editorconfig do nothing?

I was under the impression that it could be used to control things like indentation style.
I have not actually used one myself. EditorConfig

@Puddlestomper yes, I know. I missed that I'd used spaces. Sorry.
It was entirely my mistake that I used spaces instead of tabs... but see also PR #52 :-)

@0xworks
Copy link
Contributor Author

0xworks commented Nov 29, 2019

Doesn't .editorconfig do nothing?
Also you still didn't fix the white-space inconsistencies.

@WhoseTheNerd Didn't I? Can you give me a hint, because I'm not seeing it.

@Puddlestomper
Copy link
Contributor

We should consider leaving the InstrumentationSession struct in (even if we never use it). I think @TheCherno probably put it there in order to support multiple sessions in the future.

We definitely should fix the memory leak though. We can remove the code that uses the struct (as you did), or just delete the pointer it in the Instrumentor destructor if it's not a nullptr.

@0xworks
Copy link
Contributor Author

0xworks commented Nov 29, 2019

Yes, thinking about this some more, I agree that InstrumentationSession should be left in there, as it can be used for multiple session support. I will play around with this a bit more, and update the PR.

@WhoseTheNerd
Copy link
Contributor

Doesn't .editorconfig do nothing?
Also you still didn't fix the white-space inconsistencies.

@WhoseTheNerd Didn't I? Can you give me a hint, because I'm not seeing it.

Now it is fixed.

@0xworks
Copy link
Contributor Author

0xworks commented Dec 1, 2019

I think this is good to go now. I have updated the PR description to more accurately describe what I ended up doing.
It might all be a bit overkill actually, given that the profiling stuff is intended only for internal use by Hazel devs. We could just keep the Instrumentor simple, and mandate that Hazel devs don't do stupid stuff with Begin/End session. (the minimum that needs to be kept is the mutex in WriteProfile() - assuming that Hazel will be multi-threaded one day)

What do others think?

@0xworks 0xworks changed the title Instrumentation Instrumentation fixes for #176 and #181 Dec 1, 2019
@LovelySanta LovelySanta added the Impact:Bug Unintended behaviour label Dec 2, 2019
… under lock in WriteProfile().

Always write an initial comma when writing a proflie result (write an initial empty result in WriteHeader() so that the json is still properly formed)
@0xworks
Copy link
Contributor Author

0xworks commented Dec 5, 2019

@reductor Thanks, I missed that. Reason why code reviews are good.

@0xworks 0xworks closed this Dec 5, 2019
@0xworks 0xworks reopened this Dec 5, 2019
@LovelySanta
Copy link
Collaborator

Another thought of mine, shouldn't we split into .h and .cpp file as the file grows?

@Emilundpixeln
Copy link

I think there is a possibility this will try to write to an already closed stream.
For this thread 1 has to be writing a ProfileResult and be past the m_HasSession check while thread 2 calls EndSession, locks the mutex and closes m_OutputStream. Then thread 2 gets the mutex and tries to write to m_OutputStream, which has been closed.

… it has lock.

(otherwise other thread could potentially EndSession() after WriteProfile() has checked m_HasSession.
Removed m_HasSession since it is now pretty much redundant.
@0xworks
Copy link
Contributor Author

0xworks commented Dec 6, 2019

@Emilundpixeln Good catch, thanks. Need to check that there still is a session after getting the lock in WriteProfile(). After that it seems like the code is a bit cleaner to just check m_CurrentSession and not bother with the atomic m_HasSession at all - so I've stripped that out. It means that if one thread is still profiling when another thread has ended the session, then the still-profiling thread will waste a bit of time formatting json which is then never used. I don't think we should get too hung up on that - its kind of an edge case error situation anyway.

@0xworks
Copy link
Contributor Author

0xworks commented Dec 6, 2019

Another thought of mine, shouldn't we split into .h and .cpp file as the file grows?

I've left as-is for now. Hopefully the file wont get any bigger for a while (maybe some day when a better profiling sub system is needed).

@LovelySanta LovelySanta merged commit 3531a50 into TheCherno:master Jan 12, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Impact:Bug Unintended behaviour
Projects
None yet
6 participants