6

I have a multi-threaded Java application that will output information about a message it receives to the console for debugging purposes. Each time the application receives a message, it will call a System.out.println(String) on the message.

The problem that I am having is that if the application gets flooded with messages, System.out.println() prints erroneous information (like old buffer information). This is leading me to wonder if there is a threading issue where multiple threads are calling the println function at one time, and not properly flushing the buffer.

In my main program (thread), I have something to the effect of:

while(iterator.hasNext())
{
    SelectionKey key = iterator.next();

    channel.receive(buffer);     // The buffer is a ByteBuffer.
    buffer.flip();

    new Thread(new ThreadToPrintTheMessage(buffer)).start();

    buffer.clear();

    iterator.remove();
}

In my thread, I have something to the effect of:

@Override
public void run()
{
    System.out.println(message);
    System.out.flush();   // I have better results with this.  But, it doesn't
                          // fully resolve the issue.
}

Is there a simple way for me to have multiple threads print out to the console at one time without the buffers containing old information?

Thanks

EDIT: updated the code in the main thread to be more representative of what my program is doing.

Phanto
  • 1,147
  • 5
  • 16
  • 19
  • 2
    Can you show some of the "old buffer information". `System.out.println` is synchronized so you shouldn't get "old" information. – Gray Feb 27 '12 at 15:42
  • multiple threads print out to the console at one time? you mean each thread at a time? – kosa Feb 27 '12 at 15:42
  • For example, if I am getting XML messages, you would have something like: >/tag> – Phanto Feb 27 '12 at 15:48
  • I think the problem lies outside of println issue. You need to check that your app is not reading/generating old messages. – Sam Goldberg Feb 27 '12 at 15:49
  • @thinksteep Each spawned thread is calling the `println` method. – Phanto Feb 27 '12 at 15:55
  • @SamGoldberg If I send messages one at a time, there is no problem. It's only a problem when I send many at a time, which is why I'm wondering if there conflict between the `println` and `flush`. – Phanto Feb 27 '12 at 15:56
  • 1
    @Phanto: this looks like you have 2 threads writing to the same variable/field somewhere, and they are overwriting each other. – Sam Goldberg Feb 27 '12 at 15:57
  • @SamGoldberg I am going to update my main post with more of the actual code. – Phanto Feb 27 '12 at 15:59
  • 2
    @Phanto: it looks like you are sharing the buffer object with multiple threads. That won't work. Each thread needs its own separate buffer object, or the main thread needs to convert the buffer to a local string variable, and then pass the string to the thread. – Sam Goldberg Feb 27 '12 at 16:07
  • 1
    @Phanto: so, you are trying to asynchronously handle a buffer that is cleared immediately after the asynchronous call has been made (or even written to)? That's not going to work, you should pass a copy of `buffer` into the `ThreadToPrintTheMessage()` ctor (unless you make a copy inside the constructor yourself.) – Alexander Pavlov Feb 27 '12 at 16:08
  • @AlexanderPavlov in my thread's constructor, I have a `private ByteBuffer` object declared, and the constructor does a: `this.buffer = buffer`. I assumed that Java does pass by value and therefore makes a copy (unless this is wrong). – Phanto Feb 27 '12 at 17:33
  • This is wrong. Objects in Java are always passed by reference. The accepted answer does exactly what is necessary to avoid improper used of a buffer shared among multiple threads. – Alexander Pavlov Feb 27 '12 at 19:03

4 Answers4

2
synchronized (System.out) {
    System.out.println(message);
    System.out.flush();
}
Alexander Pavlov
  • 31,598
  • 5
  • 67
  • 93
2

You should be using Java.util.logging or some other logging framework for this purpose.

http://docs.oracle.com/javase/1.4.2/docs/api/java/util/logging/Logger.html

import java.util.logging.Logger;
....
Logger log = Logger.getLogger("com.something.something");
....
log.log(Level.Info, "Message");
Usman Ismail
  • 17,999
  • 14
  • 83
  • 165
2

Here might be some sample code to fix the problem:

while(iterator.hasNext())
{
    SelectionKey key = iterator.next();

    channel.receive(buffer);     // The buffer is a ByteBuffer.
    buffer.flip();
    byte[] bytes = new byte[buffer.limit()];  // copy buffer contents to an array
    buffer.get(bytes);
    // thread will convert byte array to String
    new Thread(new ThreadToPrintTheMessage(bytes)).start();

    buffer.clear();

    iterator.remove();
}
Sam Goldberg
  • 6,711
  • 8
  • 52
  • 85
  • This did it! You and Alexander Pavlov identified what the problem was... I was trying to print a buffer that was being shared and modified by a different resource. – Phanto Feb 27 '12 at 17:43
2

I haven't got time to check println source be be sure it's thread safe always (you could, if you wanted to), but are you sure that your println is wrong? It may well be that code is running at a very different times than you think. Threads often get hung up on locks or just get forgotten by the scheduler, so what you think should run A, B, C, D can run B, C, D, A. Then you wonder why println is messed up, printing last what you think ran first. And this is a really simple example. The difference between what you expect to happen with multi-threading and what does happen can be truly astounding. Generally, the higher the thread-to-core ratio, the worse it is. Single core machines always do everything the opposite of what you would expect.

And you don't even need multiple threads to have this problem. My first jolts came with event queues (on Windows 3.1), which did not share my views on when things should run. It took me a while to figure out that the messages were scrambled because the OS had a much different idea of how they should run than I did.

There may well be some subtleties with System.out.println and flush that I don't know about, but even when you get all that working, be aware that those threads have rather contrary minds of their own. Even Logger won't solve all your problems.

RalphChapin
  • 3,108
  • 16
  • 18