System.out versus stdout output order

classic Classic list List threaded Threaded
5 messages Options
Reply | Threaded
Open this post in threaded view
|

System.out versus stdout output order

David Holmes
I have a Java test that calls a native method with uses printf (in a
second thread which is started and joined by the original method), and
then the subsequent Java code uses System.out. What I see in the .jtr
file is that the C printf output always comes after the System.out
output, even though the code in question had to be executed before it.
Is this just some quirk of how jtreg collects process output for logging?

Thanks,
David
Reply | Threaded
Open this post in threaded view
|

Re: System.out versus stdout output order

roger riggs
Hi David,

stdout and system.out are buffered, so you might need to look at when/if
flush is called.

$.02, Roger


On 7/5/2018 10:02 PM, David Holmes wrote:
> I have a Java test that calls a native method with uses printf (in a
> second thread which is started and joined by the original method), and
> then the subsequent Java code uses System.out. What I see in the .jtr
> file is that the C printf output always comes after the System.out
> output, even though the code in question had to be executed before it.
> Is this just some quirk of how jtreg collects process output for logging?
>
> Thanks,
> David

Reply | Threaded
Open this post in threaded view
|

Re: System.out versus stdout output order

Martin Buchholz-3


On Fri, Jul 6, 2018 at 6:44 AM, Roger Riggs <[hidden email]> wrote:
Hi David,

stdout and system.out are buffered, so you might need to look at when/if flush is called.

More to the point, they use independent buffers.
See also Java Puzzler 81 Charred Beyond Recognition
 
Reply | Threaded
Open this post in threaded view
|

Re: System.out versus stdout output order

David Holmes
Hi Martin, Roger,

On 7/07/2018 12:55 AM, Martin Buchholz wrote:
>
>
> On Fri, Jul 6, 2018 at 6:44 AM, Roger Riggs <[hidden email]
> <mailto:[hidden email]>> wrote:
>
>     Hi David,
>
>     stdout and system.out are buffered, so you might need to look at
>     when/if flush is called.

Newlines trigger flushing and that occurs in both cases.

> More to the point, they use independent buffers.
> See also Java Puzzler 81 Charred Beyond Recognition
> https://books.google.com/books?id=RM9sLE0ntQ0C&pg=RA1-PT231&dq=Java+Puzzler+81+Charred+Beyond+Recognition&hl=en&sa=X&ved=0ahUKEwiboLSw3YrcAhXIslQKHZeVDtcQ6AEIKTAA#v=onepage&q=Java%20Puzzler%2081%20Charred%20Beyond%20Recognition&f=false

I can't see the solution to Puzzler 81 but am assuming it just relates
to buffering. I can't see how it relates to "independent buffers" ??

AFAIK System.out is connected to stdout for the process, and C printf
also writes to stdout, hence I would have expected, in the normal case
that I would see the output in the correct temporal order. And indeed
when run directly that is the case:

/export/users/dh198349/jdk11/open/test/hotspot/jtreg >
../../../../build/linux-x64-debug/images/jdk/bin/java -cp
./JTwork/classes/runtime/jni/terminatedThread/TestTerminatedThread.d/
-Djava.library.path=/export/users/dh198349/jdk11/build/linux-x64-debug/images/test/hotspot/jtreg/native/
TestTerminatedThread
Native thread is running and attaching as daemon ...
Native thread terminating
Working with thread: Thread[Thread-0,5,main],  in state: RUNNABLE
Calling suspend ...
Calling resume ...
Calling getStackTrace ...
...

So the difference is with how jtreg is intercepting/redirecting the
different streams from the process.

Not a problem, just something I noticed and wanted to double-check.

Cheers,
David
Reply | Threaded
Open this post in threaded view
|

Re: System.out versus stdout output order

Martin Buchholz-3
Ahhh, OK, jtreg is using System.setOut(out); which is how the java and C++ output ends up in different destinations.  So yes, nothing to do with buffering.  I'll update my internal mental model of how jtreg works.  It would be nice if jtreg could capture both together, but that might take a lot of non-java plumbing.

On Sun, Jul 8, 2018 at 7:05 PM, David Holmes <[hidden email]> wrote:
Hi Martin, Roger,

On 7/07/2018 12:55 AM, Martin Buchholz wrote:


On Fri, Jul 6, 2018 at 6:44 AM, Roger Riggs <[hidden email] <mailto:[hidden email]>> wrote:

    Hi David,

    stdout and system.out are buffered, so you might need to look at
    when/if flush is called.

Newlines trigger flushing and that occurs in both cases.

More to the point, they use independent buffers.
See also Java Puzzler 81 Charred Beyond Recognition
https://books.google.com/books?id=RM9sLE0ntQ0C&pg=RA1-PT231&dq=Java+Puzzler+81+Charred+Beyond+Recognition&hl=en&sa=X&ved=0ahUKEwiboLSw3YrcAhXIslQKHZeVDtcQ6AEIKTAA#v=onepage&q=Java%20Puzzler%2081%20Charred%20Beyond%20Recognition&f=false

I can't see the solution to Puzzler 81 but am assuming it just relates to buffering. I can't see how it relates to "independent buffers" ??

AFAIK System.out is connected to stdout for the process, and C printf also writes to stdout, hence I would have expected, in the normal case that I would see the output in the correct temporal order. And indeed when run directly that is the case:

/export/users/dh198349/jdk11/open/test/hotspot/jtreg > ../../../../build/linux-x64-debug/images/jdk/bin/java -cp ./JTwork/classes/runtime/jni/terminatedThread/TestTerminatedThread.d/ -Djava.library.path=/export/users/dh198349/jdk11/build/linux-x64-debug/images/test/hotspot/jtreg/native/ TestTerminatedThread
Native thread is running and attaching as daemon ...
Native thread terminating
Working with thread: Thread[Thread-0,5,main],  in state: RUNNABLE
Calling suspend ...
Calling resume ...
Calling getStackTrace ...
...

So the difference is with how jtreg is intercepting/redirecting the different streams from the process.

Not a problem, just something I noticed and wanted to double-check.

Cheers,
David