2 java processing hanging for about 2.8s












0















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?










share|improve this question

























  • 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
















0















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?










share|improve this question

























  • 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














0












0








0








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?










share|improve this question
















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






share|improve this question















share|improve this question













share|improve this question




share|improve this question








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



















  • 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










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
});


}
});














draft saved

draft discarded


















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
















draft saved

draft discarded




















































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.




draft saved


draft discarded














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





















































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







Popular posts from this blog

How to reconfigure Docker Trusted Registry 2.x.x to use CEPH FS mount instead of NFS and other traditional...

is 'sed' thread safe

How to make a Squid Proxy server?