Skip to content

logger: write thread id as part of log message#6978

Closed
carun wants to merge 1 commit intodlang:masterfrom
carun:log-threadid
Closed

logger: write thread id as part of log message#6978
carun wants to merge 1 commit intodlang:masterfrom
carun:log-threadid

Conversation

@carun
Copy link
Contributor

@carun carun commented Apr 26, 2019

Previous implementation had std.concurrency.Tid, which is simply a
wrapper around MessageBox and is not related to Thread ID in anyway.
It cannot be used in @safe code.

Instead this patch uses core.thread.ThreadID. It requires this and
it also locks mutex for every call. This patch caches the result in a
TLS to prevent unnecessary synchronization overhead.

@carun carun requested a review from burner as a code owner April 26, 2019 06:38
@dlang-bot
Copy link
Contributor

dlang-bot commented Apr 26, 2019

Thanks for your pull request and interest in making D better, @carun! We are looking forward to reviewing it, and you should be hearing from a maintainer soon.
Please verify that your PR follows this checklist:

  • My PR is fully covered with tests (you can see the coverage diff by visiting the details link of the codecov check)
  • My PR is as minimal as possible (smaller, focused PRs are easier to review than big ones)
  • I have provided a detailed rationale explaining my changes
  • New or modified functions have Ddoc comments (with Params: and Returns:)

Please see CONTRIBUTING.md for more information.


If you have addressed all reviews or aren't sure how to proceed, don't hesitate to ping us with a simple comment.

Bugzilla references

Your PR doesn't reference any Bugzilla issue.

If your PR contains non-trivial changes, please reference a Bugzilla issue or create a manual changelog.

Testing this PR locally

If you don't have a local development environment setup, you can use Digger to test this PR:

dub fetch digger
dub run digger -- build "master + phobos#6978"

@carun
Copy link
Contributor Author

carun commented Apr 29, 2019

Ping @burner @thewilsonator


import std.experimental.logger.filelogger;

extern (C) size_t syscall(int number, ...);
Copy link
Member

Choose a reason for hiding this comment

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

not sure if using this to get the tid is a good idea.
I think gettid should be placed in druntime.


import std.experimental.logger.filelogger;

extern (C) size_t syscall(int number, ...);
Copy link
Member

Choose a reason for hiding this comment

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

should be private at least

Copy link
Contributor Author

Choose a reason for hiding this comment

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

@burner Fixed it, please review.

Copy link
Member

Choose a reason for hiding this comment

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

I think I miss-communicated.
I meant

if(!betterSolutionToPlaceASyscallThanDefiningTheSyscallExternCFunction()) {
    makeItPrivate();
} else {
    implementBetterSolution();
}

I still consider this extern(C) to be a major code smell.

Copy link
Member

@Geod24 Geod24 left a comment

Choose a reason for hiding this comment

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

This is essentially re-doing what's in core.thread. If accessing the thread ID is expensive, then it should be fixed, rather than worked around.
In addition, using pthread_self (like core.thread) would probably be better than gettid, as it would support POSIX systems, not only Linux. It would also be more correct, as the result of gettid does not match the result of pthread_self, which is most likely what people will get when debugging.

@carun
Copy link
Contributor Author

carun commented Apr 29, 2019

@Geod24 Thanks for your comments.

This is essentially re-doing what's in core.thread. If accessing the thread ID is expensive, then it should be fixed, rather than worked around.

Fixing core.thread is not trivial without really understanding why synchronized has been put in first place. The objective of this PR is limited to the required functionality in logger.

using pthread_self (like core.thread) would probably be better than gettid, as it would support POSIX systems, not only Linux. It would also be more correct, as the result of gettid does not match the result of pthread_self, which is most likely what people will get when debugging.

If you look closer, you will see that gettid has been used only for Linux. Other platforms use the default.
pthread_t shall not be used, as it cannot be traced in a running process. It makes more sense to use gettid as that's what the kernel offers to the user space. It is visible in the proc filesystem. For instance do top -p <process-id> and type H or use ps -eLf | grep <multi-threaded-process-name> | grep <thread-id> and see how helpful it is to debug than with pthread_t.

The user can look at the log for some error, check the thread ID entry obtained via gettid, attach the corresponding thread via gdb and debugs it right there as required.

@Geod24
Copy link
Member

Geod24 commented May 2, 2019

If you look closer, you will see that gettid has been used only for Linux. Other platforms use the default.

Yep, I've seen. The point was more about providing platform-specific features. Ideally the feature set should be the same for all platform at the Phobos level. Some place just can't achieve that, but here it looked to me that we could.

pthread_t shall not be used, as it cannot be traced in a running process.

Good point, I did not consider the use case of live debugging. It would be nice to add a mention (comment) of why the tid is more useful than the pthread_t, as others might not see it either.

Also, this needs to be mentioned in the release notes. Some people might be relying on Tid being the ID for debugging, as Tid are associated with threads and fibers, but this changes it to only threads.

Last but not least, types are a bit messy in the patch: syscall returns long, so it should use c_long, not size_t. The return of syscall is assigned to a pthread_t (this is what ThreadID aliases to), which is even more messy.

@burner
Copy link
Member

burner commented May 24, 2019

@carun any updates?

@carun
Copy link
Contributor Author

carun commented Oct 6, 2019

@burner apparently, dlang/druntime#2820 brings in syscall changes, so I don't want to repeat the same changes here. Instead I've made this PR dependent on dlang/druntime#2820

@carun carun changed the title logger: log thread id as part of commit message logger: write thread id as part of log message Oct 6, 2019
Previous implementation had `std.concurrency.Tid`, which is simply a
wrapper around `MessageBox` and is not related to Thread ID in anyway.
It cannot be used in `@safe` code.

Instead this patch uses `core.thread.ThreadID`. Using it requires `this`
and it also locks mutex for every call. This patch also caches the
result in a TLS to prevent unnecessary synchronization overhead.
@burner
Copy link
Member

burner commented Oct 7, 2019

@carun sounds good, you properly should focus on getting the druntime thing in first though. IMHO that is the more controversial PR.

@mw66
Copy link

mw66 commented May 21, 2020

ping @carun what's the status of this PR? anytime soon to get it in?

Thanks.

@carun
Copy link
Contributor Author

carun commented May 28, 2020

@mingwugmail the situation is kinda complicated that this PR now depends on the druntime refactoring and anything that huge has the potential for a long wait or rejection. I don't intend to work on this anymore. D runtime is a pity, sadly.

@carun carun closed this May 28, 2020
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.

5 participants