2 java processing hanging for about 2.8s
I have 2 processes running on a VMWare server on the same vm. Centos 6.x
I ran strace on both processes and saved the output
6970 14:04:09.643295 futex(0x7f47d8027754, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f47d8027750, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
6969 14:04:09.643304 futex(0x7f47d8027754, FUTEX_WAIT_PRIVATE, 54869, NULL <unfinished ...>
6971 14:04:09.643353 futex(0x7f47d802b128, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
6970 14:04:09.643363 <... futex resumed> ) = 0 <0.000063>
6969 14:04:09.643372 <... futex resumed> ) = -1 EAGAIN (Resource temporarily unavailable) <0.000063>
6971 14:04:09.643411 <... futex resumed> ) = 0 <0.000052>
6969 14:04:09.643420 futex(0x7f47d8027728, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
6971 14:04:09.643459 futex(0x7f47d8030854, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f47d8030850, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
6969 14:04:09.643469 <... futex resumed> ) = 0 <0.000044>
6971 14:04:09.643501 <... futex resumed> ) = 1 <0.000037>
6974 14:04:09.650775 <... futex resumed> ) = 0 <0.511421>
17035 14:04:12.446009 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <2.902876>
17009 14:04:12.446112 <... poll resumed> ) = 1 ([{fd=271, revents=POLLIN}]) <3.742208>
17008 14:04:12.446131 <... poll resumed> ) = 1 ([{fd=193, revents=POLLIN}]) <3.747483>
24085 14:04:12.446144 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <2.822784>
24082 14:04:12.446157 <... poll resumed> ) = 1 ([{fd=300, revents=POLLIN}]) <4.404341>
6416 14:04:12.446172 <... poll resumed> ) = 1 ([{fd=187, revents=POLLIN}]) <3.557929>
18296 14:04:12.446189 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <2.822459>
18295 14:04:12.446201 <... poll resumed> ) = 1 ([{fd=290, revents=POLLIN}]) <3.518658>
the key component is
6974 14:04:09.650775 <... futex resumed> ) = 0 <0.511421>
17035 14:04:12.446009 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <2.902876>
the other process strace is
7510 14:04:09.622601 futex(0x7f8874033728, FUTEX_WAKE_PRIVATE, 1) = 0 <0.000024>
7510 14:04:09.622698 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={72, 763938}, ru_stime={3, 512466}, ...}) = 0 <0.000023>
7510 14:04:09.622761 futex(0x7f8874033754, FUTEX_WAIT_BITSET_PRIVATE, 1, {162879, 332257449}, ffffffff <unfinished ...>
7543 14:04:09.644930 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <0.050089>
7543 14:04:09.644991 futex(0x7f88757c9128, FUTEX_WAKE_PRIVATE, 1) = 0 <0.000039>
7543 14:04:09.645091 futex(0x7f88757c9154, FUTEX_WAIT_BITSET_PRIVATE, 1, {162879, 104576419}, ffffffff <unfinished ...>
7766 14:04:09.671201 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <0.100101>
17254 14:04:12.445858 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <2.859094>
24083 14:04:12.446056 <... poll resumed> ) = 1 ([{fd=277, revents=POLLIN}]) <4.404263>
key bit is
7766 14:04:09.671201 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <0.100101>
17254 14:04:12.445858 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <2.859094>
roughly the same time both java process stopped and them timed out.
Now I have other logs that show stuff happened in that time - I believe.
How can I track down what the futex was? Or how can I find more info / what more data can I grab to diagnose this issue?
linux centos java strace
add a comment |
I have 2 processes running on a VMWare server on the same vm. Centos 6.x
I ran strace on both processes and saved the output
6970 14:04:09.643295 futex(0x7f47d8027754, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f47d8027750, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
6969 14:04:09.643304 futex(0x7f47d8027754, FUTEX_WAIT_PRIVATE, 54869, NULL <unfinished ...>
6971 14:04:09.643353 futex(0x7f47d802b128, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
6970 14:04:09.643363 <... futex resumed> ) = 0 <0.000063>
6969 14:04:09.643372 <... futex resumed> ) = -1 EAGAIN (Resource temporarily unavailable) <0.000063>
6971 14:04:09.643411 <... futex resumed> ) = 0 <0.000052>
6969 14:04:09.643420 futex(0x7f47d8027728, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
6971 14:04:09.643459 futex(0x7f47d8030854, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f47d8030850, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
6969 14:04:09.643469 <... futex resumed> ) = 0 <0.000044>
6971 14:04:09.643501 <... futex resumed> ) = 1 <0.000037>
6974 14:04:09.650775 <... futex resumed> ) = 0 <0.511421>
17035 14:04:12.446009 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <2.902876>
17009 14:04:12.446112 <... poll resumed> ) = 1 ([{fd=271, revents=POLLIN}]) <3.742208>
17008 14:04:12.446131 <... poll resumed> ) = 1 ([{fd=193, revents=POLLIN}]) <3.747483>
24085 14:04:12.446144 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <2.822784>
24082 14:04:12.446157 <... poll resumed> ) = 1 ([{fd=300, revents=POLLIN}]) <4.404341>
6416 14:04:12.446172 <... poll resumed> ) = 1 ([{fd=187, revents=POLLIN}]) <3.557929>
18296 14:04:12.446189 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <2.822459>
18295 14:04:12.446201 <... poll resumed> ) = 1 ([{fd=290, revents=POLLIN}]) <3.518658>
the key component is
6974 14:04:09.650775 <... futex resumed> ) = 0 <0.511421>
17035 14:04:12.446009 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <2.902876>
the other process strace is
7510 14:04:09.622601 futex(0x7f8874033728, FUTEX_WAKE_PRIVATE, 1) = 0 <0.000024>
7510 14:04:09.622698 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={72, 763938}, ru_stime={3, 512466}, ...}) = 0 <0.000023>
7510 14:04:09.622761 futex(0x7f8874033754, FUTEX_WAIT_BITSET_PRIVATE, 1, {162879, 332257449}, ffffffff <unfinished ...>
7543 14:04:09.644930 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <0.050089>
7543 14:04:09.644991 futex(0x7f88757c9128, FUTEX_WAKE_PRIVATE, 1) = 0 <0.000039>
7543 14:04:09.645091 futex(0x7f88757c9154, FUTEX_WAIT_BITSET_PRIVATE, 1, {162879, 104576419}, ffffffff <unfinished ...>
7766 14:04:09.671201 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <0.100101>
17254 14:04:12.445858 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <2.859094>
24083 14:04:12.446056 <... poll resumed> ) = 1 ([{fd=277, revents=POLLIN}]) <4.404263>
key bit is
7766 14:04:09.671201 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <0.100101>
17254 14:04:12.445858 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <2.859094>
roughly the same time both java process stopped and them timed out.
Now I have other logs that show stuff happened in that time - I believe.
How can I track down what the futex was? Or how can I find more info / what more data can I grab to diagnose this issue?
linux centos java strace
Possibly a Linux kernel bug. See here.
– xenoid
Feb 1 at 8:29
@xenoid This was 2015 - any kernel from that time would be very unsecure to run today (pre-spectre etc.).
– Eugen Rieck
Feb 1 at 8:37
I saw that kernel bug but as point it out it's fairly old
– Keyzer Suze
Feb 5 at 7:46
I'm running latest centos 6.x
– Keyzer Suze
Feb 5 at 7:47
add a comment |
I have 2 processes running on a VMWare server on the same vm. Centos 6.x
I ran strace on both processes and saved the output
6970 14:04:09.643295 futex(0x7f47d8027754, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f47d8027750, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
6969 14:04:09.643304 futex(0x7f47d8027754, FUTEX_WAIT_PRIVATE, 54869, NULL <unfinished ...>
6971 14:04:09.643353 futex(0x7f47d802b128, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
6970 14:04:09.643363 <... futex resumed> ) = 0 <0.000063>
6969 14:04:09.643372 <... futex resumed> ) = -1 EAGAIN (Resource temporarily unavailable) <0.000063>
6971 14:04:09.643411 <... futex resumed> ) = 0 <0.000052>
6969 14:04:09.643420 futex(0x7f47d8027728, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
6971 14:04:09.643459 futex(0x7f47d8030854, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f47d8030850, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
6969 14:04:09.643469 <... futex resumed> ) = 0 <0.000044>
6971 14:04:09.643501 <... futex resumed> ) = 1 <0.000037>
6974 14:04:09.650775 <... futex resumed> ) = 0 <0.511421>
17035 14:04:12.446009 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <2.902876>
17009 14:04:12.446112 <... poll resumed> ) = 1 ([{fd=271, revents=POLLIN}]) <3.742208>
17008 14:04:12.446131 <... poll resumed> ) = 1 ([{fd=193, revents=POLLIN}]) <3.747483>
24085 14:04:12.446144 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <2.822784>
24082 14:04:12.446157 <... poll resumed> ) = 1 ([{fd=300, revents=POLLIN}]) <4.404341>
6416 14:04:12.446172 <... poll resumed> ) = 1 ([{fd=187, revents=POLLIN}]) <3.557929>
18296 14:04:12.446189 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <2.822459>
18295 14:04:12.446201 <... poll resumed> ) = 1 ([{fd=290, revents=POLLIN}]) <3.518658>
the key component is
6974 14:04:09.650775 <... futex resumed> ) = 0 <0.511421>
17035 14:04:12.446009 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <2.902876>
the other process strace is
7510 14:04:09.622601 futex(0x7f8874033728, FUTEX_WAKE_PRIVATE, 1) = 0 <0.000024>
7510 14:04:09.622698 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={72, 763938}, ru_stime={3, 512466}, ...}) = 0 <0.000023>
7510 14:04:09.622761 futex(0x7f8874033754, FUTEX_WAIT_BITSET_PRIVATE, 1, {162879, 332257449}, ffffffff <unfinished ...>
7543 14:04:09.644930 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <0.050089>
7543 14:04:09.644991 futex(0x7f88757c9128, FUTEX_WAKE_PRIVATE, 1) = 0 <0.000039>
7543 14:04:09.645091 futex(0x7f88757c9154, FUTEX_WAIT_BITSET_PRIVATE, 1, {162879, 104576419}, ffffffff <unfinished ...>
7766 14:04:09.671201 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <0.100101>
17254 14:04:12.445858 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <2.859094>
24083 14:04:12.446056 <... poll resumed> ) = 1 ([{fd=277, revents=POLLIN}]) <4.404263>
key bit is
7766 14:04:09.671201 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <0.100101>
17254 14:04:12.445858 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <2.859094>
roughly the same time both java process stopped and them timed out.
Now I have other logs that show stuff happened in that time - I believe.
How can I track down what the futex was? Or how can I find more info / what more data can I grab to diagnose this issue?
linux centos java strace
I have 2 processes running on a VMWare server on the same vm. Centos 6.x
I ran strace on both processes and saved the output
6970 14:04:09.643295 futex(0x7f47d8027754, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f47d8027750, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
6969 14:04:09.643304 futex(0x7f47d8027754, FUTEX_WAIT_PRIVATE, 54869, NULL <unfinished ...>
6971 14:04:09.643353 futex(0x7f47d802b128, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
6970 14:04:09.643363 <... futex resumed> ) = 0 <0.000063>
6969 14:04:09.643372 <... futex resumed> ) = -1 EAGAIN (Resource temporarily unavailable) <0.000063>
6971 14:04:09.643411 <... futex resumed> ) = 0 <0.000052>
6969 14:04:09.643420 futex(0x7f47d8027728, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
6971 14:04:09.643459 futex(0x7f47d8030854, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f47d8030850, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
6969 14:04:09.643469 <... futex resumed> ) = 0 <0.000044>
6971 14:04:09.643501 <... futex resumed> ) = 1 <0.000037>
6974 14:04:09.650775 <... futex resumed> ) = 0 <0.511421>
17035 14:04:12.446009 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <2.902876>
17009 14:04:12.446112 <... poll resumed> ) = 1 ([{fd=271, revents=POLLIN}]) <3.742208>
17008 14:04:12.446131 <... poll resumed> ) = 1 ([{fd=193, revents=POLLIN}]) <3.747483>
24085 14:04:12.446144 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <2.822784>
24082 14:04:12.446157 <... poll resumed> ) = 1 ([{fd=300, revents=POLLIN}]) <4.404341>
6416 14:04:12.446172 <... poll resumed> ) = 1 ([{fd=187, revents=POLLIN}]) <3.557929>
18296 14:04:12.446189 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <2.822459>
18295 14:04:12.446201 <... poll resumed> ) = 1 ([{fd=290, revents=POLLIN}]) <3.518658>
the key component is
6974 14:04:09.650775 <... futex resumed> ) = 0 <0.511421>
17035 14:04:12.446009 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <2.902876>
the other process strace is
7510 14:04:09.622601 futex(0x7f8874033728, FUTEX_WAKE_PRIVATE, 1) = 0 <0.000024>
7510 14:04:09.622698 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={72, 763938}, ru_stime={3, 512466}, ...}) = 0 <0.000023>
7510 14:04:09.622761 futex(0x7f8874033754, FUTEX_WAIT_BITSET_PRIVATE, 1, {162879, 332257449}, ffffffff <unfinished ...>
7543 14:04:09.644930 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <0.050089>
7543 14:04:09.644991 futex(0x7f88757c9128, FUTEX_WAKE_PRIVATE, 1) = 0 <0.000039>
7543 14:04:09.645091 futex(0x7f88757c9154, FUTEX_WAIT_BITSET_PRIVATE, 1, {162879, 104576419}, ffffffff <unfinished ...>
7766 14:04:09.671201 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <0.100101>
17254 14:04:12.445858 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <2.859094>
24083 14:04:12.446056 <... poll resumed> ) = 1 ([{fd=277, revents=POLLIN}]) <4.404263>
key bit is
7766 14:04:09.671201 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <0.100101>
17254 14:04:12.445858 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) <2.859094>
roughly the same time both java process stopped and them timed out.
Now I have other logs that show stuff happened in that time - I believe.
How can I track down what the futex was? Or how can I find more info / what more data can I grab to diagnose this issue?
linux centos java strace
linux centos java strace
edited Feb 1 at 8:36
Mr Shunz
1,82512017
1,82512017
asked Feb 1 at 7:44
Keyzer SuzeKeyzer Suze
1
1
Possibly a Linux kernel bug. See here.
– xenoid
Feb 1 at 8:29
@xenoid This was 2015 - any kernel from that time would be very unsecure to run today (pre-spectre etc.).
– Eugen Rieck
Feb 1 at 8:37
I saw that kernel bug but as point it out it's fairly old
– Keyzer Suze
Feb 5 at 7:46
I'm running latest centos 6.x
– Keyzer Suze
Feb 5 at 7:47
add a comment |
Possibly a Linux kernel bug. See here.
– xenoid
Feb 1 at 8:29
@xenoid This was 2015 - any kernel from that time would be very unsecure to run today (pre-spectre etc.).
– Eugen Rieck
Feb 1 at 8:37
I saw that kernel bug but as point it out it's fairly old
– Keyzer Suze
Feb 5 at 7:46
I'm running latest centos 6.x
– Keyzer Suze
Feb 5 at 7:47
Possibly a Linux kernel bug. See here.
– xenoid
Feb 1 at 8:29
Possibly a Linux kernel bug. See here.
– xenoid
Feb 1 at 8:29
@xenoid This was 2015 - any kernel from that time would be very unsecure to run today (pre-spectre etc.).
– Eugen Rieck
Feb 1 at 8:37
@xenoid This was 2015 - any kernel from that time would be very unsecure to run today (pre-spectre etc.).
– Eugen Rieck
Feb 1 at 8:37
I saw that kernel bug but as point it out it's fairly old
– Keyzer Suze
Feb 5 at 7:46
I saw that kernel bug but as point it out it's fairly old
– Keyzer Suze
Feb 5 at 7:46
I'm running latest centos 6.x
– Keyzer Suze
Feb 5 at 7:47
I'm running latest centos 6.x
– Keyzer Suze
Feb 5 at 7:47
add a comment |
0
active
oldest
votes
Your Answer
StackExchange.ready(function() {
var channelOptions = {
tags: "".split(" "),
id: "3"
};
initTagRenderer("".split(" "), "".split(" "), channelOptions);
StackExchange.using("externalEditor", function() {
// Have to fire editor after snippets, if snippets enabled
if (StackExchange.settings.snippets.snippetsEnabled) {
StackExchange.using("snippets", function() {
createEditor();
});
}
else {
createEditor();
}
});
function createEditor() {
StackExchange.prepareEditor({
heartbeatType: 'answer',
autoActivateHeartbeat: false,
convertImagesToLinks: true,
noModals: true,
showLowRepImageUploadWarning: true,
reputationToPostImages: 10,
bindNavPrevention: true,
postfix: "",
imageUploader: {
brandingHtml: "Powered by u003ca class="icon-imgur-white" href="https://imgur.com/"u003eu003c/au003e",
contentPolicyHtml: "User contributions licensed under u003ca href="https://creativecommons.org/licenses/by-sa/3.0/"u003ecc by-sa 3.0 with attribution requiredu003c/au003e u003ca href="https://stackoverflow.com/legal/content-policy"u003e(content policy)u003c/au003e",
allowUrls: true
},
onDemand: true,
discardSelector: ".discard-answer"
,immediatelyShowMarkdownHelp:true
});
}
});
Sign up or log in
StackExchange.ready(function () {
StackExchange.helpers.onClickDraftSave('#login-link');
});
Sign up using Google
Sign up using Facebook
Sign up using Email and Password
Post as a guest
Required, but never shown
StackExchange.ready(
function () {
StackExchange.openid.initPostLogin('.new-post-login', 'https%3a%2f%2fsuperuser.com%2fquestions%2f1400884%2f2-java-processing-hanging-for-about-2-8s%23new-answer', 'question_page');
}
);
Post as a guest
Required, but never shown
0
active
oldest
votes
0
active
oldest
votes
active
oldest
votes
active
oldest
votes
Thanks for contributing an answer to Super User!
- Please be sure to answer the question. Provide details and share your research!
But avoid …
- Asking for help, clarification, or responding to other answers.
- Making statements based on opinion; back them up with references or personal experience.
To learn more, see our tips on writing great answers.
Sign up or log in
StackExchange.ready(function () {
StackExchange.helpers.onClickDraftSave('#login-link');
});
Sign up using Google
Sign up using Facebook
Sign up using Email and Password
Post as a guest
Required, but never shown
StackExchange.ready(
function () {
StackExchange.openid.initPostLogin('.new-post-login', 'https%3a%2f%2fsuperuser.com%2fquestions%2f1400884%2f2-java-processing-hanging-for-about-2-8s%23new-answer', 'question_page');
}
);
Post as a guest
Required, but never shown
Sign up or log in
StackExchange.ready(function () {
StackExchange.helpers.onClickDraftSave('#login-link');
});
Sign up using Google
Sign up using Facebook
Sign up using Email and Password
Post as a guest
Required, but never shown
Sign up or log in
StackExchange.ready(function () {
StackExchange.helpers.onClickDraftSave('#login-link');
});
Sign up using Google
Sign up using Facebook
Sign up using Email and Password
Post as a guest
Required, but never shown
Sign up or log in
StackExchange.ready(function () {
StackExchange.helpers.onClickDraftSave('#login-link');
});
Sign up using Google
Sign up using Facebook
Sign up using Email and Password
Sign up using Google
Sign up using Facebook
Sign up using Email and Password
Post as a guest
Required, but never shown
Required, but never shown
Required, but never shown
Required, but never shown
Required, but never shown
Required, but never shown
Required, but never shown
Required, but never shown
Required, but never shown
Possibly a Linux kernel bug. See here.
– xenoid
Feb 1 at 8:29
@xenoid This was 2015 - any kernel from that time would be very unsecure to run today (pre-spectre etc.).
– Eugen Rieck
Feb 1 at 8:37
I saw that kernel bug but as point it out it's fairly old
– Keyzer Suze
Feb 5 at 7:46
I'm running latest centos 6.x
– Keyzer Suze
Feb 5 at 7:47