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

8268425: Show decimal nid of OSThread instead of hex format one #4449

Closed
wants to merge 5 commits into from

Conversation

y1yang0
Copy link
Member

@y1yang0 y1yang0 commented Jun 10, 2021

From users' perspective, we can find corresponding os thread via top directly, otherwise, we must convert hex format based nid to an integer, and find that thread via top -pid <pid>. This slightly facilitates our debugging process, but would obviously break some existing jstack analysis tool.

Jstack Before:

"ParGC Thread#7" os_prio=0 cpu=103260.18ms elapsed=5255043.58s tid=0x00007f967000b000 nid=0x12e67 runnable

"ParGC Thread#8" os_prio=0 cpu=104818.76ms elapsed=5255043.58s tid=0x00007f967000c000 nid=0x12e68 runnable

"ParGC Thread#9" os_prio=0 cpu=102164.69ms elapsed=5255043.58s tid=0x00007f967000e000 nid=0x12e69 runnable

Jstack After:
"G1 Conc#0" os_prio=0 cpu=0.03ms elapsed=1295.27s tid=0x00007f99dc096490 nid=117707 runnable

"G1 Refine#0" os_prio=0 cpu=0.06ms elapsed=1295.22s tid=0x00007f99dc2cad20 nid=117708 runnable

"G1 Service" os_prio=0 cpu=87.05ms elapsed=1295.22s tid=0x00007f99dc2cc140 nid=117709 runnable

Top:
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
49083 tianxia+ 20 0 32.8g 594148 10796 S 103.3 0.1 0:10.05 java
71291 qingfen+ 20 0 39.3g 26.7g 18312 S 100.7 5.3 16861:35 jhsdb
50407 tianxia+ 20 0 32.5g 32796 9768 S 100.3 0.0 0:05.80 java
107429 maolian+ 20 0 11.4g 1.1g 10956 S 100.3 0.2 20173:52 java
99923 root 10 -10 288520 163228 5088 S 5.9 0.0 6463:53 AliYunDun


Progress

  • Change must not contain extraneous whitespace
  • Commit message must refer to an issue
  • Change must be properly reviewed

Issue

  • JDK-8268425: Show decimal nid of OSThread instead of hex format one

Reviewers

Reviewing

Using git

Checkout this PR locally:
$ git fetch https://git.openjdk.java.net/jdk pull/4449/head:pull/4449
$ git checkout pull/4449

Update a local copy of the PR:
$ git checkout pull/4449
$ git pull https://git.openjdk.java.net/jdk pull/4449/head

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 4449

View PR using the GUI difftool:
$ git pr show -t 4449

Using diff file

Download this PR as a diff file:
https://git.openjdk.java.net/jdk/pull/4449.diff

@bridgekeeper
Copy link

bridgekeeper bot commented Jun 10, 2021

👋 Welcome back yyang! A progress list of the required criteria for merging this PR into master will be added to the body of your pull request. There are additional pull request commands available for use with this pull request.

@openjdk openjdk bot added the rfr Pull request is ready for review label Jun 10, 2021
@openjdk
Copy link

openjdk bot commented Jun 10, 2021

@kelthuzadx The following label will be automatically applied to this pull request:

  • hotspot-runtime

When this pull request is ready to be reviewed, an "RFR" email will be sent to the corresponding mailing list. If you would like to change these labels, use the /label pull request command.

@openjdk openjdk bot added the hotspot-runtime hotspot-runtime-dev@openjdk.org label Jun 10, 2021
@mlbridge
Copy link

mlbridge bot commented Jun 10, 2021

Webrevs

@y1yang0
Copy link
Member Author

y1yang0 commented Jun 16, 2021

/label add hotspot

@openjdk openjdk bot added the hotspot hotspot-dev@openjdk.org label Jun 16, 2021
@openjdk
Copy link

openjdk bot commented Jun 16, 2021

@kelthuzadx
The hotspot label was successfully added.

@y1yang0
Copy link
Member Author

y1yang0 commented Jun 18, 2021

Do you think this would facilitate debugging process? And is it acceptable? Any feedback is appreciated!

@y1yang0
Copy link
Member Author

y1yang0 commented Jun 18, 2021

/label add serviceability

@openjdk openjdk bot added the serviceability serviceability-dev@openjdk.org label Jun 18, 2021
@openjdk
Copy link

openjdk bot commented Jun 18, 2021

@kelthuzadx
The serviceability label was successfully added.

@y1yang0 y1yang0 changed the title 8268425: Show integer nid of OSThread instead of hex format one 8268425: Show decimal nid of OSThread instead of hex format one Jun 18, 2021
@@ -38,18 +38,18 @@ OSThread::~OSThread() {

// Printing
void OSThread::print_on(outputStream *st) const {
st->print("nid=0x%x ", thread_id());
st->print("nid=%d ", thread_id());
Copy link
Member

Choose a reason for hiding this comment

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

thread_id is of an opaque type (eg pthread_t). I think we can reasonably assume its numeric, but I would print it as an unsigned 64bit int just in case.

Copy link
Member Author

Choose a reason for hiding this comment

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

Hi Thomas, we can not use other format specifiers (%ld,%llu) after my practice, because it can not compile on my mac:

/home/qingfeng.yy/jdktip/src/hotspot/share/runtime/osThread.cpp:41:21: error: format '%llu' expects argument of type 'long long unsigned int', but argument 3 has type 'OSThread::thread_id_t' {aka 'int'} [-Werror=format=]
   41 |   st->print("nid=%llu ", thread_id());
      |                  ~~~^    ~~~~~~~~~~~
      |                     |             |
      |                     |             OSThread::thread_id_t {aka int}
      |                     long long unsigned int
      |                  %u

/home/qingfeng.yy/jdktip/src/hotspot/share/runtime/osThread.cpp:41:20: error: format '%ld' expects argument of type 'long int', but argument 3 has type 'OSThread::thread_id_t' {aka 'int'} [-Werror=format=]
   41 |   st->print("nid=%ld ", thread_id());
      |                  ~~^    ~~~~~~~~~~~
      |                    |             |
      |                    long int      OSThread::thread_id_t {aka int}
      |                  %d
cc1plus: all warnings being treated as errors

After a quick search, I find many occurrences that using %d as a format specifier, so it looks ok.

(Conversions looks redundant)

st->print("[%ld] ", (long) Thread::current()->osthread()->thread_id());

st->print("[%ld] ", (long) Thread::current()->osthread()->thread_id());

tty->print_cr(" Thread = " INTPTR_FORMAT ", thread ID = %d", p2i(thread), thread->osthread()->thread_id());

st->print_cr("Thread: " INTPTR_FORMAT
" [0x%2x] State: %s _at_poll_safepoint %d",
p2i(_thread), _thread->osthread()->thread_id(), s, _at_poll_safepoint);

uintptr_t SafepointMechanism::compute_poll_word(bool armed, uintptr_t stack_watermark) {
if (armed) {
log_debug(stackbarrier)("Computed armed for tid %d", Thread::current()->osthread()->thread_id());
return _poll_word_armed_value;
}
if (stack_watermark == 0) {
log_debug(stackbarrier)("Computed disarmed for tid %d", Thread::current()->osthread()->thread_id());
return _poll_word_disarmed_value;
}
log_debug(stackbarrier)("Computed watermark for tid %d", Thread::current()->osthread()->thread_id());
return stack_watermark;
}

log_info(stackbarrier)("Processing whole stack for tid %d",
_jt->osthread()->thread_id());

log_info(stackbarrier)("Starting stack processing for tid %d",
_jt->osthread()->thread_id());

log_info(stackbarrier)("Finished stack processing iteration for tid %d",
_jt->osthread()->thread_id());

st->print(" [id=%d]", osthread()->thread_id());

st->print(", id=%d", osthread()->thread_id());

st->print_cr("JavaThread " PTR_FORMAT " (nid = %d) was being processed", p2i(jt), jt->osthread()->thread_id());

Copy link
Member

Choose a reason for hiding this comment

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

You'd do:

print("nid: " UINT64_FORMAT, (uint64_t) id):;

thread_t is, among other things, pthread_t, which is opaque. Any current code treating that as signed int is incorrect too.

switch (_state) {
case ALLOCATED: st->print("allocated "); break;
case INITIALIZED: st->print("initialized "); break;
case RUNNABLE: st->print("runnable "); break;
case MONITOR_WAIT: st->print("waiting for monitor entry "); break;
case CONDVAR_WAIT: st->print("waiting on condition "); break;
case OBJECT_WAIT: st->print("in Object.wait() "); break;
case BREAKPOINTED: st->print("at breakpoint"); break;
Copy link
Member

Choose a reason for hiding this comment

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

These cleanups don't seem to have anything to do with this change.

Copy link
Member Author

Choose a reason for hiding this comment

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

Restored.

@kevinjwalls
Copy link

Hi,
If you attach WinDbg on Windows to a JVM, you might be glad of the nid=0x... format as that is its choice of base for the thread ids.
So this depends on your tools. Maybe frustrated top users outnumber happy WinDbg users for the JVM, and maybe they don't. Maybe this change delights some users and frustrates others.

@tstuefe
Copy link
Member

tstuefe commented Jun 28, 2021

Hi,
If you attach WinDbg on Windows to a JVM, you might be glad of the nid=0x... format as that is its choice of base for the thread ids.
So this depends on your tools. Maybe frustrated top users outnumber happy WinDbg users for the JVM, and maybe they don't. Maybe this change delights some users and frustrates others.

Why not do it platform dependent then? This would make sense especially since the type is opaque. Let each platform handling printing. Windows can hex-print its DWORD thread id. Linux can print its kernel LWP. And platforms where the thread id is 64bit, or a structure, can print that.

For now default implementations could live in os::Windows::print_thread_id(thread_t) and os::Posix::print_thread_id(thread_t), respectively.

@kevinjwalls
Copy link

Why not do it platform dependent then? ...

Checked Visual Studio, and that goes with decimal for thread IDs. 8-)

It's the tools rather than the platform. But yes, hex for thread IDs seems to be in the minority. (I have occasionally found this annoying.)

@mlbridge
Copy link

mlbridge bot commented Jun 28, 2021

Mailing list message from David Holmes on hotspot-dev:

On 28/06/2021 6:49 pm, Thomas Stuefe wrote:

On Mon, 28 Jun 2021 07:37:10 GMT, Yi Yang <yyang at openjdk.org> wrote:

src/hotspot/share/runtime/osThread.cpp line 41:

39: // Printing
40: void OSThread::print_on(outputStream *st) const {
41: st->print("nid=%d ", thread_id());

thread_id is of an opaque type (eg pthread_t). I think we can reasonably assume its numeric, but I would print it as an unsigned 64bit int just in case.

Hi Thomas, we can not use other format specifiers (`%ld`,`%llu`) after my practice, because it can not compile on my mac:

You'd do:

print("nid: " UINT64_FORMAT, (uint64_t) id):;

thread_t is, among other things, pthread_t, which is opaque. Any current code treating that as signed int is incorrect too.

If it is opaque then I don't see how signed or unsigned makes any
difference. You are assuming it can just be treated as a 64-bit value;
whether you interpret that as a signed or unsigned value just changes
how you print it. I agree printing only positive values is nicer visually.

David

1 similar comment
@mlbridge
Copy link

mlbridge bot commented Jun 28, 2021

Mailing list message from David Holmes on hotspot-dev:

On 28/06/2021 6:49 pm, Thomas Stuefe wrote:

On Mon, 28 Jun 2021 07:37:10 GMT, Yi Yang <yyang at openjdk.org> wrote:

src/hotspot/share/runtime/osThread.cpp line 41:

39: // Printing
40: void OSThread::print_on(outputStream *st) const {
41: st->print("nid=%d ", thread_id());

thread_id is of an opaque type (eg pthread_t). I think we can reasonably assume its numeric, but I would print it as an unsigned 64bit int just in case.

Hi Thomas, we can not use other format specifiers (`%ld`,`%llu`) after my practice, because it can not compile on my mac:

You'd do:

print("nid: " UINT64_FORMAT, (uint64_t) id):;

thread_t is, among other things, pthread_t, which is opaque. Any current code treating that as signed int is incorrect too.

If it is opaque then I don't see how signed or unsigned makes any
difference. You are assuming it can just be treated as a 64-bit value;
whether you interpret that as a signed or unsigned value just changes
how you print it. I agree printing only positive values is nicer visually.

David

@kevinjwalls
Copy link

Do you think this would facilitate debugging process? And is it acceptable? Any feedback is appreciated!

My first comments were to say that this makes things better for some people, but a little worse for others.
Maybe overall this looks like it makes things better for most people. 8-)

If so (and if we don't discover more tools that prefer hex for thread IDs!), then we want to be consistent, so in addition to the native/built in implementation, we should also update:

src/jdk.hotspot.agent/share/classes/sun/jvm/hotspot/runtime/JavaThread.java
..to keep the SA implementation in sync. It would be odd to have thread dumps looking more different depending on what generated them.

And if changing that, also change:
test/hotspot/jtreg/serviceability/sa/JhsdbThreadInfoTest.java

I don't see other tests that parse this information.

@tstuefe
Copy link
Member

tstuefe commented Jun 28, 2021

You'd do:
print("nid: " UINT64_FORMAT, (uint64_t) id):;
thread_t is, among other things, pthread_t, which is opaque. Any current code treating that as signed int is incorrect too.

If it is opaque then I don't see how signed or unsigned makes any
difference. You are assuming it can just be treated as a 64-bit value;
whether you interpret that as a signed or unsigned value just changes
how you print it. I agree printing only positive values is nicer visually.

David

My signed in comment was referring to the existing use of %d in the code base. I'm more concerned with the 32bit range of int than the signedness (though I never saw an OS tool displaying negative numbers for thread ids).

@y1yang0
Copy link
Member Author

y1yang0 commented Jun 29, 2021

If so (and if we don't discover more tools that prefer hex for thread IDs!), then we want to be consistent, so in addition to the native/built in implementation, we should also update:

src/jdk.hotspot.agent/share/classes/sun/jvm/hotspot/runtime/JavaThread.java
..to keep the SA implementation in sync. It would be odd to have thread dumps looking more different depending on what generated them.

And if changing that, also change:
test/hotspot/jtreg/serviceability/sa/JhsdbThreadInfoTest.java

Thanks for the comments! I will change the corresponding SA implementation and tests.

Hi,
If you attach WinDbg on Windows to a JVM, you might be glad of the nid=0x... format as that is its choice of base for the thread ids.
So this depends on your tools. Maybe frustrated top users outnumber happy WinDbg users for the JVM, and maybe they don't. Maybe this change delights some users and frustrates others.

Why not do it platform dependent then? This would make sense especially since the type is opaque. Let each platform handling printing. Windows can hex-print its DWORD thread id. Linux can print its kernel LWP. And platforms where the thread id is 64bit, or a structure, can print that.

For now default implementations could live in os::Windows::print_thread_id(thread_t) and os::Posix::print_thread_id(thread_t), respectively.

Will it be too heavy to add a platform-dependent implementation for this small function? As Kevin said, maybe this change delights some users and frustrates others. But since POSIX is the vast majority of users, it may be a better choice to adapt to them. Just IMHO..

@kevinjwalls
Copy link

Maybe we can't make everybody happy, but what we have now is a good improvement (for many/most).
I tested with the SA change, the test passes, and manually on Windows I ran jstack and jhsdb jstack, jhsdb clhsdb.

Will it be too heavy to add a platform-dependent implementation for this small function?...
I think so.
I think this looks good now.

I don't think it's a change we should backport, or at least not quickly, out of concern for people/tools who might be parsing this output.

@@ -38,7 +38,7 @@ OSThread::~OSThread() {

// Printing
void OSThread::print_on(outputStream *st) const {
st->print("nid=%d ", thread_id());

Choose a reason for hiding this comment

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

Just update the (C) year above from 2019 to 2021.
JhsdbThreadInfoTest.java has it already in the latest revision.

Copy link
Member Author

Choose a reason for hiding this comment

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

Updated in both osThread.cpp and test file.

Copy link
Member

@tstuefe tstuefe left a comment

Choose a reason for hiding this comment

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

LGTM

out.shouldMatch("\".+\" #\\d+ daemon prio=\\d+ tid=0x[0-9a-f]+ nid=0x[0-9a-f]+ .+ \\[0x[0-9a-f]+]");
out.shouldMatch("\"main\" #\\d+ prio=\\d+ tid=0x[0-9a-f]+ nid=0x[0-9a-f]+ .+ \\[0x[0-9a-f]+]");
out.shouldMatch("\".+\" #\\d+ daemon prio=\\d+ tid=0x[0-9a-f]+ nid=[0-9]+ .+ \\[0x[0-9a-f]+]");
out.shouldMatch("\"main\" #\\d+ prio=\\d+ tid=0x[0-9a-f]+ nid=[0-9]+ .+ \\[0x[0-9a-f]+]");
Copy link
Member

Choose a reason for hiding this comment

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

small nit, instead of [0-9] you could use \d, and to match a hex number \p{XDigit} could be used. But since you just follow the existing pattern, I leave it up to you whether you want to change this.

Copy link
Member Author

Choose a reason for hiding this comment

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

Good catch! \p{XDigit} seems a standard/better way to match any hexadecimal character than [0-9a-fA-F]+

@openjdk
Copy link

openjdk bot commented Jun 30, 2021

@kelthuzadx This change now passes all automated pre-integration checks.

ℹ️ This project also has non-automated pre-integration requirements. Please see the file CONTRIBUTING.md for details.

After integration, the commit message for the final commit will be:

8268425: Show decimal nid of OSThread instead of hex format one

Reviewed-by: stuefe, kevinw

You can use pull request commands such as /summary, /contributor and /issue to adjust it as needed.

At the time when this comment was updated there had been 363 new commits pushed to the master branch:

  • 3ad20fc: 8269571: NMT should print total malloc bytes and invocation count
  • b969136: 8245877: assert(_value != __null) failed: resolving NULL _value in JvmtiExport::post_compiled_method_load
  • ee526a2: Merge
  • 0d745ae: 8269034: AccessControlException for SunPKCS11 daemon threads
  • d042029: 8269529: javax/swing/reliability/HangDuringStaticInitialization.java fails in Windows debug build
  • 401cb0a: 8269232: assert(!is_jweak(handle)) failed: wrong method for detroying jweak
  • b8a16e9: 8268884: C2: Compile::remove_speculative_types must iterate top-down
  • 25f9f19: 8249646: Runtime.exec(String, String[], File) documentation contains literal {@link ...}
  • 0d83dc2: 8268699: Shenandoah: Add test for JDK-8268127
  • 7010dfd: 8269517: compiler/loopopts/TestPartialPeelingSinkNodes.java crashes with -XX:+VerifyGraphEdges
  • ... and 353 more: https://git.openjdk.java.net/jdk/compare/042f0bdb3568edab4f96b9f7c83cbb0f90db7f18...master

As there are no conflicts, your changes will automatically be rebased on top of these commits when integrating. If you prefer to avoid this automatic rebasing, please check the documentation for the /integrate command for further details.

➡️ To integrate this PR with the above commit message to the master branch, type /integrate in a new comment.

@openjdk openjdk bot added the ready Pull request is ready to be integrated label Jun 30, 2021
@y1yang0
Copy link
Member Author

y1yang0 commented Jul 6, 2021

@dholmes-ora David, can you please take a look at the latest versions. Thanks!

@@ -38,7 +38,7 @@ OSThread::~OSThread() {

// Printing
void OSThread::print_on(outputStream *st) const {
st->print("nid=0x%x ", thread_id());
st->print("nid=" UINT64_FORMAT " ", (uint64_t)thread_id());
Copy link
Member

Choose a reason for hiding this comment

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

Why are you forcing this to be a 64-bit type?

Copy link
Member Author

@y1yang0 y1yang0 Jul 6, 2021

Choose a reason for hiding this comment

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

IMHO, I prefer using %d since a large portion of existing code using %d. Thomas suggests using UINT64_FORMAT rather than %d:

You'd do:

print("nid: " UINT64_FORMAT, (uint64_t) id):;

thread_t is, among other things, pthread_t, which is opaque. Any current code treating that as signed int is incorrect too.

There is no uniform format for the formatted output of thread_id in hotspot. As far as I can see, %ld %d and UINTX_FORMAT are used, so I want to left the decision to reviewers.

@y1yang0
Copy link
Member Author

y1yang0 commented Jul 7, 2021

/integrate

@openjdk
Copy link

openjdk bot commented Jul 7, 2021

Going to push as commit a9e2010.
Since your change was applied there have been 459 commits pushed to the master branch:

  • 01c29d8: 8266407: remove jdk.internal.javac.PreviewFeature.Feature.SEALED_CLASSES
  • 7a4f08a: Merge
  • 0d1cd3a: 8269825: [TESTBUG] Missing testing for x86 KNL platforms
  • e0c130f: 8269955: ProblemList compiler/vectorapi/VectorCastShape[64|128]Test.java tests on x86
  • 1166ef2: 8268966: AArch64: 'bad AD file' in some vector conversion tests
  • 3a69024: 8225667: Clarify the behavior of System::gc w.r.t. reference processing
  • 2b20778: 8269568: JVM crashes when running VectorMask query tests
  • 0f4e07b: 8269661: JNI_GetStringCritical does not lock char array
  • df1364b: 8269575: C2: assert(false) failed: graph should be schedulable after JDK-8252372
  • 6d8fc72: 8268883: C2: assert(false) failed: unscheduable graph
  • ... and 449 more: https://git.openjdk.java.net/jdk/compare/042f0bdb3568edab4f96b9f7c83cbb0f90db7f18...master

Your commit was automatically rebased without conflicts.

@openjdk openjdk bot closed this Jul 7, 2021
@openjdk openjdk bot added integrated Pull request has been integrated and removed ready Pull request is ready to be integrated rfr Pull request is ready for review labels Jul 7, 2021
@openjdk
Copy link

openjdk bot commented Jul 7, 2021

@kelthuzadx Pushed as commit a9e2010.

💡 You may see a message that your pull request was closed with unmerged commits. This can be safely ignored.

@y1yang0 y1yang0 deleted the osthread_nid branch July 7, 2021 01:40
@mlbridge
Copy link

mlbridge bot commented Jul 8, 2021

Mailing list message from David Holmes on hotspot-dev:

On 6/07/2021 1:25 pm, Yi Yang wrote:

On Tue, 6 Jul 2021 03:08:42 GMT, David Holmes <dholmes at openjdk.org> wrote:

Yi Yang has updated the pull request incrementally with one additional commit since the last revision:

use \p{XDigit}

src/hotspot/share/runtime/osThread.cpp line 41:

39: // Printing
40: void OSThread::print_on(outputStream *st) const {
41: st->print("nid=" UINT64_FORMAT " ", (uint64_t)thread_id());

Why are you forcing this to be a 64-bit type?

IMHO, I prefer using `%d` since a large portion of existing code using `%d`. Thomas suggests using UINT64_FORMAT rather than `%d`:

You'd do:

print("nid: " UINT64_FORMAT, (uint64_t) id):;

thread_t is, among other things, pthread_t, which is opaque. Any current code treating that as signed int is incorrect too.

There is no uniform format for the formatted output of thread_id in hotspot. As far as I can see, `%ld` `%d` and `UINTX_FORMAT` are used, so I want to left the decision to reviewers.

Okay. This is a mess but that's not your issue. At least a 64-bit
decimal value won't show any leading zeroes so it doesn't really matter.

If Thomas and Keven are happy with the latest changes then that is fine.

Thanks,
David

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
hotspot hotspot-dev@openjdk.org hotspot-runtime hotspot-runtime-dev@openjdk.org integrated Pull request has been integrated serviceability serviceability-dev@openjdk.org
4 participants