Re: RFR 8064441: java/lang/management/ThreadMXBean/Locks.java fails intermittently, blocked on wrong object
On 12/05/2014 02:19 AM, David Holmes wrote: On 3/12/2014 1:51 AM, Jaroslav Bachorik wrote: On 12/02/2014 10:37 AM, David Holmes wrote: On 1/12/2014 7:16 PM, Jaroslav Bachorik wrote: On 11/27/2014 09:33 AM, Jaroslav Bachorik wrote: On 11/27/2014 01:43 AM, David Holmes wrote: On 26/11/2014 10:57 PM, Jaroslav Bachorik wrote: Please, review the following test change Issue : https://bugs.openjdk.java.net/browse/JDK-8064441 Webrev: http://cr.openjdk.java.net/~jbachorik/8064441/webrev.00 The test fails because of System.out.println() may induce unexpected locking. The solution is to use an already existing LockFreeLogManager library class to collect the logs in the lock-free manner and print the logs only after all the test code has been run. I seem to remember spending a lot of time on this test in the past, where the phaser usage was intended to ensure that we could not be seen to be blocking on the internal locks associated with the println. Where has this gone wrong? The remaining problem is the usage of System.out.print[ln]() inside the test threads. System.out.print[ln]() might involve blocking the calling thread and eg. create false positives when the test is waiting for a thread to enter the blocked state. What are the semantics of the lockfreelogger? When will we see its output? It is using thread local lists of the logging records. Each logging record has an id which is unique and monotonous over all the threads - an AtomicInteger instance is used to achieve this. You can retrieve the log output (ordered by the log record id) by calling LockFreeLogManager.toString(). Review for the LockFreeLogManager is available here [http://mail.openjdk.java.net/pipermail/serviceability-dev/2014-November/015848.html] David, are you ok with this change then? I guess so. Still not sure why we see the println problem though - but don't have time to delve into it. Thanks! PrintStream and Writer are full of synchronized blocks. When on use them in multithreaded environment an occasional blocking might occur. For example, in Locks.java, 'LockAThread' and 'LockBThread' threads run concurrently, both of them outputting some log info via System.out. So it may happen that when asserting the 'LockAThread' thread state in 'checkBlockedObject' the thread is in blocked state thanks to blocking on the output stream internals rather than on the test monitor. Yes but that is what the Phaser is supposed to prevent - the logging occurs prior to the phaser actions. I would be lying if I told I knew exactly where the contention was happening. But when I removed the logging completely I wasn't able to reproduce the failure in 500 subsequent runs (usually it took up to 100 runs to encounter the failure) and from that and the fact that there is no other place the contention could take place, short of the Phaser itself, I deduced that the logging was the culprit. With the new collecting (lock-free) logger the test also runs without the failure in 500 runs so I suppose it was the logging. -JB- David I hope this clarifies the problem a bit. -JB- Thanks, David Thanks, -JB- -JB- Thanks, David Thanks, -JB-
Re: RFR 8064441: java/lang/management/ThreadMXBean/Locks.java fails intermittently, blocked on wrong object
On 3/12/2014 1:51 AM, Jaroslav Bachorik wrote: On 12/02/2014 10:37 AM, David Holmes wrote: On 1/12/2014 7:16 PM, Jaroslav Bachorik wrote: On 11/27/2014 09:33 AM, Jaroslav Bachorik wrote: On 11/27/2014 01:43 AM, David Holmes wrote: On 26/11/2014 10:57 PM, Jaroslav Bachorik wrote: Please, review the following test change Issue : https://bugs.openjdk.java.net/browse/JDK-8064441 Webrev: http://cr.openjdk.java.net/~jbachorik/8064441/webrev.00 The test fails because of System.out.println() may induce unexpected locking. The solution is to use an already existing LockFreeLogManager library class to collect the logs in the lock-free manner and print the logs only after all the test code has been run. I seem to remember spending a lot of time on this test in the past, where the phaser usage was intended to ensure that we could not be seen to be blocking on the internal locks associated with the println. Where has this gone wrong? The remaining problem is the usage of System.out.print[ln]() inside the test threads. System.out.print[ln]() might involve blocking the calling thread and eg. create false positives when the test is waiting for a thread to enter the blocked state. What are the semantics of the lockfreelogger? When will we see its output? It is using thread local lists of the logging records. Each logging record has an id which is unique and monotonous over all the threads - an AtomicInteger instance is used to achieve this. You can retrieve the log output (ordered by the log record id) by calling LockFreeLogManager.toString(). Review for the LockFreeLogManager is available here [http://mail.openjdk.java.net/pipermail/serviceability-dev/2014-November/015848.html] David, are you ok with this change then? I guess so. Still not sure why we see the println problem though - but don't have time to delve into it. Thanks! PrintStream and Writer are full of synchronized blocks. When on use them in multithreaded environment an occasional blocking might occur. For example, in Locks.java, 'LockAThread' and 'LockBThread' threads run concurrently, both of them outputting some log info via System.out. So it may happen that when asserting the 'LockAThread' thread state in 'checkBlockedObject' the thread is in blocked state thanks to blocking on the output stream internals rather than on the test monitor. Yes but that is what the Phaser is supposed to prevent - the logging occurs prior to the phaser actions. David I hope this clarifies the problem a bit. -JB- Thanks, David Thanks, -JB- -JB- Thanks, David Thanks, -JB-
Re: RFR 8064441: java/lang/management/ThreadMXBean/Locks.java fails intermittently, blocked on wrong object
On 1/12/2014 7:16 PM, Jaroslav Bachorik wrote: On 11/27/2014 09:33 AM, Jaroslav Bachorik wrote: On 11/27/2014 01:43 AM, David Holmes wrote: On 26/11/2014 10:57 PM, Jaroslav Bachorik wrote: Please, review the following test change Issue : https://bugs.openjdk.java.net/browse/JDK-8064441 Webrev: http://cr.openjdk.java.net/~jbachorik/8064441/webrev.00 The test fails because of System.out.println() may induce unexpected locking. The solution is to use an already existing LockFreeLogManager library class to collect the logs in the lock-free manner and print the logs only after all the test code has been run. I seem to remember spending a lot of time on this test in the past, where the phaser usage was intended to ensure that we could not be seen to be blocking on the internal locks associated with the println. Where has this gone wrong? The remaining problem is the usage of System.out.print[ln]() inside the test threads. System.out.print[ln]() might involve blocking the calling thread and eg. create false positives when the test is waiting for a thread to enter the blocked state. What are the semantics of the lockfreelogger? When will we see its output? It is using thread local lists of the logging records. Each logging record has an id which is unique and monotonous over all the threads - an AtomicInteger instance is used to achieve this. You can retrieve the log output (ordered by the log record id) by calling LockFreeLogManager.toString(). Review for the LockFreeLogManager is available here [http://mail.openjdk.java.net/pipermail/serviceability-dev/2014-November/015848.html] David, are you ok with this change then? I guess so. Still not sure why we see the println problem though - but don't have time to delve into it. Thanks, David Thanks, -JB- -JB- Thanks, David Thanks, -JB-
Re: RFR 8064441: java/lang/management/ThreadMXBean/Locks.java fails intermittently, blocked on wrong object
On 12/02/2014 10:37 AM, David Holmes wrote: On 1/12/2014 7:16 PM, Jaroslav Bachorik wrote: On 11/27/2014 09:33 AM, Jaroslav Bachorik wrote: On 11/27/2014 01:43 AM, David Holmes wrote: On 26/11/2014 10:57 PM, Jaroslav Bachorik wrote: Please, review the following test change Issue : https://bugs.openjdk.java.net/browse/JDK-8064441 Webrev: http://cr.openjdk.java.net/~jbachorik/8064441/webrev.00 The test fails because of System.out.println() may induce unexpected locking. The solution is to use an already existing LockFreeLogManager library class to collect the logs in the lock-free manner and print the logs only after all the test code has been run. I seem to remember spending a lot of time on this test in the past, where the phaser usage was intended to ensure that we could not be seen to be blocking on the internal locks associated with the println. Where has this gone wrong? The remaining problem is the usage of System.out.print[ln]() inside the test threads. System.out.print[ln]() might involve blocking the calling thread and eg. create false positives when the test is waiting for a thread to enter the blocked state. What are the semantics of the lockfreelogger? When will we see its output? It is using thread local lists of the logging records. Each logging record has an id which is unique and monotonous over all the threads - an AtomicInteger instance is used to achieve this. You can retrieve the log output (ordered by the log record id) by calling LockFreeLogManager.toString(). Review for the LockFreeLogManager is available here [http://mail.openjdk.java.net/pipermail/serviceability-dev/2014-November/015848.html] David, are you ok with this change then? I guess so. Still not sure why we see the println problem though - but don't have time to delve into it. Thanks! PrintStream and Writer are full of synchronized blocks. When on use them in multithreaded environment an occasional blocking might occur. For example, in Locks.java, 'LockAThread' and 'LockBThread' threads run concurrently, both of them outputting some log info via System.out. So it may happen that when asserting the 'LockAThread' thread state in 'checkBlockedObject' the thread is in blocked state thanks to blocking on the output stream internals rather than on the test monitor. I hope this clarifies the problem a bit. -JB- Thanks, David Thanks, -JB- -JB- Thanks, David Thanks, -JB-
Re: RFR 8064441: java/lang/management/ThreadMXBean/Locks.java fails intermittently, blocked on wrong object
On 11/27/2014 09:33 AM, Jaroslav Bachorik wrote: On 11/27/2014 01:43 AM, David Holmes wrote: On 26/11/2014 10:57 PM, Jaroslav Bachorik wrote: Please, review the following test change Issue : https://bugs.openjdk.java.net/browse/JDK-8064441 Webrev: http://cr.openjdk.java.net/~jbachorik/8064441/webrev.00 The test fails because of System.out.println() may induce unexpected locking. The solution is to use an already existing LockFreeLogManager library class to collect the logs in the lock-free manner and print the logs only after all the test code has been run. I seem to remember spending a lot of time on this test in the past, where the phaser usage was intended to ensure that we could not be seen to be blocking on the internal locks associated with the println. Where has this gone wrong? The remaining problem is the usage of System.out.print[ln]() inside the test threads. System.out.print[ln]() might involve blocking the calling thread and eg. create false positives when the test is waiting for a thread to enter the blocked state. What are the semantics of the lockfreelogger? When will we see its output? It is using thread local lists of the logging records. Each logging record has an id which is unique and monotonous over all the threads - an AtomicInteger instance is used to achieve this. You can retrieve the log output (ordered by the log record id) by calling LockFreeLogManager.toString(). Review for the LockFreeLogManager is available here [http://mail.openjdk.java.net/pipermail/serviceability-dev/2014-November/015848.html] David, are you ok with this change then? Thanks, -JB- -JB- Thanks, David Thanks, -JB-
Re: RFR 8064441: java/lang/management/ThreadMXBean/Locks.java fails intermittently, blocked on wrong object
On 11/27/2014 01:43 AM, David Holmes wrote: On 26/11/2014 10:57 PM, Jaroslav Bachorik wrote: Please, review the following test change Issue : https://bugs.openjdk.java.net/browse/JDK-8064441 Webrev: http://cr.openjdk.java.net/~jbachorik/8064441/webrev.00 The test fails because of System.out.println() may induce unexpected locking. The solution is to use an already existing LockFreeLogManager library class to collect the logs in the lock-free manner and print the logs only after all the test code has been run. I seem to remember spending a lot of time on this test in the past, where the phaser usage was intended to ensure that we could not be seen to be blocking on the internal locks associated with the println. Where has this gone wrong? The remaining problem is the usage of System.out.print[ln]() inside the test threads. System.out.print[ln]() might involve blocking the calling thread and eg. create false positives when the test is waiting for a thread to enter the blocked state. What are the semantics of the lockfreelogger? When will we see its output? It is using thread local lists of the logging records. Each logging record has an id which is unique and monotonous over all the threads - an AtomicInteger instance is used to achieve this. You can retrieve the log output (ordered by the log record id) by calling LockFreeLogManager.toString(). Review for the LockFreeLogManager is available here [http://mail.openjdk.java.net/pipermail/serviceability-dev/2014-November/015848.html] -JB- Thanks, David Thanks, -JB-
RFR 8064441: java/lang/management/ThreadMXBean/Locks.java fails intermittently, blocked on wrong object
Please, review the following test change Issue : https://bugs.openjdk.java.net/browse/JDK-8064441 Webrev: http://cr.openjdk.java.net/~jbachorik/8064441/webrev.00 The test fails because of System.out.println() may induce unexpected locking. The solution is to use an already existing LockFreeLogManager library class to collect the logs in the lock-free manner and print the logs only after all the test code has been run. Thanks, -JB-
Re: RFR 8064441: java/lang/management/ThreadMXBean/Locks.java fails intermittently, blocked on wrong object
Looks good! Erik Jaroslav Bachorik skrev 2014-11-26 13:57: Please, review the following test change Issue : https://bugs.openjdk.java.net/browse/JDK-8064441 Webrev: http://cr.openjdk.java.net/~jbachorik/8064441/webrev.00 The test fails because of System.out.println() may induce unexpected locking. The solution is to use an already existing LockFreeLogManager library class to collect the logs in the lock-free manner and print the logs only after all the test code has been run. Thanks, -JB-
Re: RFR 8064441: java/lang/management/ThreadMXBean/Locks.java fails intermittently, blocked on wrong object
Jaroslav, The fix looks good. Thanks, Serguei On 11/26/14 4:57 AM, Jaroslav Bachorik wrote: Please, review the following test change Issue : https://bugs.openjdk.java.net/browse/JDK-8064441 Webrev: http://cr.openjdk.java.net/~jbachorik/8064441/webrev.00 The test fails because of System.out.println() may induce unexpected locking. The solution is to use an already existing LockFreeLogManager library class to collect the logs in the lock-free manner and print the logs only after all the test code has been run. Thanks, -JB-
