1

I guess that Java prints exceptions in some independent stream or thread, because when I use System.out.println() for writing debug information I get terrible mess where exception message is intermixed randomly into my debug output (see example below).

I would like:

  1. be sure that the error happen at the very end of the output. I worry that maybe the program somehow managed to continue to run a few operations after the exception happened. Which means that the very last debug output I wrote with System.out.println() is maybe not necessarily that one where the exception immediately happened.

  2. make sure that all the debug outputs ( including exception messages ) are written in the exactly same order as they happen in program. As if everything is running in serial way ( I do not work with threads ).

  3. I read answers to questions about java debugging and I realized that there are some specialized logger packages. Does this solve the problem? If it does I should probably start to use so which is by default part of JDK. However, still I would prefer to use System.out.println because I do not want to rewrite it everywhere in do code.

I'm using NetBeans 8.0.2 on Ubuntu 14.04 LTS 64bit ... if it matters

example of the mess:

dict: {Wood=Wood 1.0 2.0 0.1 1000.0, IronOre=IronOre 1.0 0.25 2.0 1000.0, Iron=Iron 1.0 0.128 10.0 1000.0, Steel=Steel 1.0 0.128 20.0 1000.0, Stone=Stone 1.0 0.5 0.2 1000.0, Food=Food 1.0 4.0 1.0 1000.0}
java.lang.NullPointerException
 item.getName(): >>Food<<Food 1.0 4.0 1.0 1000.0 {}
 Wood 100.0 5.0  
Wood|100.0|5.0
 item: Wood 100.0 5.0
 dict: {Wood=Wood 1.0 2.0 0.1 1000.0, IronOre=IronOre 1.0 0.25 2.0 1000.0, Iron=Iron 1.0 0.128 10.0 1000.0, Steel=Steel 1.0 0.128 20.0 1000.0, Stone=Stone 1.0 0.5 0.2 1000.0, Food=Food 1.0 4.0 1.0 1000.0}
 item.getName(): >>Wood<<Wood 1.0 2.0 0.1 1000.0 {Food 1.0 4.0 1.0 1000.0=Food 2.0 10.0}
    at BoC.Engine.Economy.ComodityManager.toString(ComodityManager.java:64)
 Stone  1.0  0.1
Stone|1.0|0.1
 item: Stone 1.0 0.1
 dict: {Wood=Wood 1.0 2.0 0.1 1000.0, IronOre=IronOre 1.0 0.25 2.0 1000.0, Iron=Iron 1.0 0.128 10.0 1000.0, Steel=Steel 1.0 0.128 20.0 1000.0, Stone=Stone 1.0 0.5 0.2 1000.0, Food=Food 1.0 4.0 1.0 1000.0}
 item.getName(): >>Stone<<Stone 1.0 0.5 0.2 1000.0 {Wood 1.0 2.0 0.1 1000.0=Wood 100.0 5.0, Food 1.0 4.0 1.0 1000.0=Food 2.0 10.0}
evalBlockParams: 3 8 6 64
reallocate: 4 4 32 32
WorldMap: 32 32 8
    at java.lang.String.valueOf(String.java:2982)
 =============== initCities() 
New_York  10 10 1000.0 5000.0
    at java.lang.StringBuilder.append(StringBuilder.java:131)
    at BoC.utils.FileSystem.MapFromString(FileSystem.java:46)
++++ >>;<< , >>    Wood 10000.0 0.1 ; Coal 10.0 0.5 ; IronOre 10.0 2.0 ; Iron 2.0 10.0<<
    at BoC.Engine.Globals.initCities(Globals.java:186)
    Wood 10000.0 0.1 
    at BoC.Engine.Globals.initGame(Globals.java:68)
ComodityManager.fromString:Wood 10000.0 0.1
    at BoC.Game.GameMain.start(GameMain.java:73)
    at BoC.Game.GameMain.main(GameMain.java:264)
java.lang.NullPointerException
    at BoC.Engine.Economy.ComodityManager.toString(ComodityManager.java:64ComodityManager.fromString:Wood;10000.0;0.1
)
 item: Wood 10000.0 0.1
    at java.lang.String.valueOf(String.java:2982)
    at java.lang.StringBuilder.append(StringBuilder.java:131)
    at BoC.utils.FileSystem.MapFromString(FileSystem.java:46)
    at BoC.Engine.Globals.initCities(Globals.java:186)
 dict: {Wood=Wood 1.0 2.0 0.1 1000.0, IronOre=IronOre 1.0 0.25 2.0 1000.0, Iron=Iron 1.0 0.128 10.0 1000.0, Steel=Steel 1.0 0.128 20.0 1000.0, Stone=Stone 1.0 0.5 0.2 1000.0, Food=Food 1.0 4.0 1.0 1000.0}
    at BoC.Engine.Globals.initGame(Globals.java:68)
    at BoC.Game.GameMain.start(GameMain.java:73)
 item.getName(): >>Wood<<Wood 1.0 2.0 0.1 1000.0 {}
    at BoC.Game.GameMain.main(GameMain.java:264)
 Coal 10.0 0.5 
java.lang.NullPointerException
ComodityManager.fromString:Coal 10.0 0.5
    at BoC.Engine.Economy.ComodityManager.toString(ComodityManager.java:64)
ComodityManager.fromString:Coal;10.0;0.5
    at java.lang.String.valueOf(String.java:2982)
London    10 20 2000.0 2000.0
    at java.lang.StringBuilder.append(StringBuilder.java:131)
    at BoC.utils.FileSystem.MapFromString(FileSystem.java:46)
++++ >>;<< , >>    Wood 5000.0 0.1 ; Coal 1000.0 0.5 ; IronOre 100.0 2.0 ; Iron 2.0 10.0<<
    at BoC.Engine.Globals.initCities(Globals.java:186)
    Wood 5000.0 0.1 
    at BoC.Engine.Globals.initGame(Globals.java:68)
ComodityManager.fromString:Wood 5000.0 0.1
    at BoC.Game.GameMain.start(GameMain.java:73)
    at BoC.Game.GameMain.main(GameMain.java:264)
ComodityManager.fromString:Wood;5000.0;0.1
java.lang.NullPointerException
 item: Wood 5000.0 0.1
    at BoC.Engine.Economy.ComodityManager.toString(ComodityManager.java:64)
    at java.lang.String.valueOf(String.java:2982)
    at java.lang.StringBuilder.append(StringBuilder.java:131)
 dict: {Wood=Wood 1.0 2.0 0.1 1000.0, IronOre=IronOre 1.0 0.25 2.0 1000.0, Iron=Iron 1.0 0.128 10.0 1000.0, Steel=Steel 1.0 0.128 20.0 1000.0, Stone=Stone 1.0 0.5 0.2 1000.0, Food=Food 1.0 4.0 1.0 1000.0}
    at BoC.utils.FileSystem.MapFromString(FileSystem.java:46)
    at BoC.Engine.Globals.initCities(Globals.java:186)
 item.getName(): >>Wood<<Wood 1.0 2.0 0.1 1000.0 {}
    at BoC.Engine.Globals.initGame(Globals.java:68)
 Coal 1000.0 0.5 
    at BoC.Game.GameMain.start(GameMain.java:73)
ComodityManager.fromString:Coal 1000.0 0.5
    at BoC.Game.GameMain.main(GameMain.java:264)
ComodityManager.fromString:Coal;1000.0;0.5
Paris     20 10 500.0 1000.0
++++ >>;<< , >>    Wood 2000.0 0.1 ; Coal 10.0 0.6 ; IronOre 100.0 2.0 ; Iron 1.0 10.0<<
    Wood 2000.0 0.1 
ComodityManager.fromString:Wood 2000.0 0.1
ComodityManager.fromString:Wood;2000.0;0.1
 item: Wood 2000.0 0.1
 dict: {Wood=Wood 1.0 2.0 0.1 1000.0, IronOre=IronOre 1.0 0.25 2.0 1000.0, Iron=Iron 1.0 0.128 10.0 1000.0, Steel=Steel 1.0 0.128 20.0 1000.0, Stone=Stone 1.0 0.5 0.2 1000.0, Food=Food 1.0 4.0 1.0 1000.0}
 item.getName(): >>Wood<<Wood 1.0 2.0 0.1 1000.0 {}
 Coal 10.0 0.6 
ComodityManager.fromString:Coal 10.0 0.6
ComodityManager.fromString:Coal;10.0;0.6
Prague    20 20 500.0 300.0 
++++ >>;<< , >>    Wood 1000.0 0.1 ; Coal 10.0 0.4 ; IronOre 100.0 2.0 ; Iron 1.0 10.0<<
    Wood 1000.0 0.1 
ComodityManager.fromString:Wood 1000.0 0.1
ComodityManager.fromString:Wood;1000.0;0.1
 item: Wood 1000.0 0.1
 dict: {Wood=Wood 1.0 2.0 0.1 1000.0, IronOre=IronOre 1.0 0.25 2.0 1000.0, Iron=Iron 1.0 0.128 10.0 1000.0, Steel=Steel 1.0 0.128 20.0 1000.0, Stone=Stone 1.0 0.5 0.2 1000.0, Food=Food 1.0 4.0 1.0 1000.0}
 item.getName(): >>Wood<<Wood 1.0 2.0 0.1 1000.0 {}
 Coal 10.0 0.4 
ComodityManager.fromString:Coal 10.0 0.4
ComodityManager.fromString:Coal;10.0;0.4
BUILD SUCCESSFUL (total time: 0 seconds)
Thomas Dickey
  • 51,086
  • 7
  • 70
  • 105
Prokop Hapala
  • 2,424
  • 2
  • 30
  • 59

1 Answers1

1

I guess that Java prints exceptions in some independent stream or threat, because when I use System.out.println() for writing debug information I get terrible mess where exception message is intermixed randomly into my debug output (see example below).

Yes, they print on System.err instead of System.out. And since System.out is not auto-flushed, the System.err may overtake System.out.

be sure that the error happen at the very end of the output. I worry that maybe the program somehow managed to continue to run a few operation after the exception happened. Which means that the very last debug output I wrote with System.out.println() is maybe not necessarily that one where the exception immediately happened.

That's extremely unlikely, unless you somehow catch the exception, keep running, and then re-throw the exception.

An other option is to muck up multi-threading, but in that case you should expect that one thread is not directly influenced by the other. The only option in that case it to handle the operations one by one and block until the other thread finishes.

make sure that all the debug outputs ( including exception messages ) are written in the exactly same order as they happen in program. As if everything is running in serial way ( I do not work with threads ).

As a stopgap measure you could map the standard error stream onto the standard output stream. The problem should not occur when both System.out and System.err are identical:

System.setErr(System.out);
// to test: throw new RuntimeException("Ooops");
// should show black instead of red in your favorite IDE

Also note that the output stream is only flushed on newlines, so you may want to make sure you call println when printing out values. That should of course not affect the ordering of the printout, it should only affect the moment the printout becomes available.

I read answers to questions about java debugging and I realized that there are some specialized logger packages. Does this solve the problem? If it does I should probably start to use so which is by default part of JDK. However, still I would prefer to use System.out.println because I do not want to rewrite it everywhere in do code.

There's no question in the above statement, but yes, using logging packages should be considered mandatory for software running in a production environment. Doubly so when it's a service.

Community
  • 1
  • 1
Maarten Bodewes
  • 90,524
  • 13
  • 150
  • 263
  • But note: if there is something annoying then it's a library where somebody left `System.out` statements in, or prints to `System.err`, e.g. by using `printStackTrace`. If you do that you may be stringed up by your colleagues - or worse, not get any coffee. – Maarten Bodewes Dec 20 '15 at 12:56
  • Thanks. aha, that is why NetBeans does not like my `catch (Exception e){e.printStackTrace();}`. Currently I do this java programing just for myself, I will remember your words for time when I will do it in collaboration. ... in the mean time i will try your `System.setErr(System.out);` – Prokop Hapala Dec 20 '15 at 19:46
  • aha, so even better solution is to use `System.err.println( )` instead of `System.out.println( item_str )` ... Thank you again, I didn't realized that. – Prokop Hapala Dec 20 '15 at 19:50
  • Another very important issue with `catch (Exception e){e.printStackTrace()}` is that it doesn't stop the execution even though an exception has just occurred. This is why I immediate replace the `printStackTraces` templates within the IDE with `throw new IllegalStateException("Unhandled exception", e)`. You don't have to catch runtime exceptions, so the code is now OK, and at least stops when required. Normally preceded with a `// TODO handle exception` of course. This also helps with variable assignment; you don't have to initialize all your variables. Try it, highly recommended. – Maarten Bodewes Dec 20 '15 at 21:38