Please use the Apache issue tracking system for new NetBeans issues (https://issues.apache.org/jira/projects/NETBEANS0/issues) !!
Bug 197600 - System.err stops going to messages.log and console after running debugger
System.err stops going to messages.log and console after running debugger
Status: RESOLVED FIXED
Product: platform
Classification: Unclassified
Component: -- Other --
7.0
PC Windows XP
: P3 (vote)
: 7.0.1
Assigned To: Martin Entlicher
issues@platform
: REGRESSION
Depends on:
Blocks: 179047
  Show dependency treegraph
 
Reported: 2011-04-11 00:08 UTC by err
Modified: 2011-06-20 14:23 UTC (History)
3 users (show)

See Also:
Issue Type: DEFECT
:


Attachments
A sketch of script to convert (some) System.err.println to jvi's DebugOption.println. (975 bytes, application/octet-stream)
2011-06-07 15:51 UTC, Jan Lahoda
Details

Note You need to log in before you can comment on or make changes to this bug.
Description err 2011-04-11 00:08:28 UTC
I start up netbeans with "--console new" and -J-Dnetbeans.logger.console=true

The System.err output from my module gets output ok after starting the IDE. Then, after starting the debugger on a POJ project, the output stops.


Product Version: NetBeans IDE 7.0 RC2 (Build 201104070802)
Java: 1.6.0_23; Java HotSpot(TM) Client VM 19.0-b09
System: Windows XP version 5.1 running on x86; Cp1252; en_US (nb)
Userdir: C:\Documents and Settings\erra\.netbeans\7.0rc2
Comment 1 err 2011-04-15 01:30:08 UTC
I now discover that System.err also stops going to messages.log.

I've updated the summary and the priority.

I'm stuck trying to debug a problem with my modules and want to see this information. Suggestions?
Comment 2 Antonin Nebuzelsky 2011-05-23 14:41:18 UTC
Works for me with

Product Version: NetBeans IDE Dev (Build 201105190400)
Java: 1.6.0_16; Java HotSpot(TM) Client VM 14.2-b01
System: Windows XP version 5.1 running on x86; Cp1252; en_US (nb)

Can you provide more information and exact steps to reproduce?

I started the IDE with the parameters "--console new -J-Dnetbeans.logger.console=true", created an AnagramGame project, started a debugger and stopped on a breakpoint in the project. The ouput in the console of the NetBeans process is still working.
Comment 3 err 2011-05-23 15:37:04 UTC
- started 7.0 with empty userdir.
- new standalone NB module
- new action, put a button into toolbar for it
  actionPerformed: System.err.println("SYSTEM ERR OUTPUT");
- Install/Reload in target IDE (button in toolbar, pressing no output)

- restart IDE
- press button, see output in console

- new java desktop application with main method; set as main project
- add a few lines in main, set a breakpoint in main
- start debugging main
- get the breakpoint
- press button in IDE
observe: no more output to console, no more output to messages.log


Product Version: NetBeans IDE 7.0 (Build 201104080000)
Java: 1.6.0_23; Java HotSpot(TM) Client VM 19.0-b09
System: Windows XP version 5.1 running on x86; Cp1252; en_US (nb)
Userdir: C:\Documents and Settings\erra\.netbeans\TEST
Comment 4 Antonin Nebuzelsky 2011-05-30 12:51:07 UTC
"Install/Reload in Target IDE" is unavailable for standalone module project, but using "Run" for the module project and doing the rest how described (starting debugging against a different project, e.g. AnagramGame sample), stops the output.
Comment 5 Martin Entlicher 2011-05-30 13:30:25 UTC
This has nothing to do with debugger, it's a bug of TopLogging class.

Initially the standard out and err streams are directly TopLogging$LgStream streams and all works well.
After something is executed externally, they become org.netbeans.core.execution.WriterPrintStream
The org.netbeans.core.execution.OutputStreamWriter for some strange reason *copies* the string into a character array and writes the characters. This should be submitted as a separate performance issue, since in case that the whole string is printed (the majority of cases) this is not necessary.

However, this translation of String into char[] uncovers a defect in TopLogging$LgStream.print(), which for some very strange reason flushes the output only when !Thread.holdsLock(this). But the current thread will always hold the lock, since it's called from java.io.PrintStream.write(PrintStream.java:505), which acquires the lock.

IMHO the simplest fix is to remove the if (!Thread.holdsLock(this)) condition, since it has no sense and seems to be some relict.
Comment 6 Martin Entlicher 2011-05-30 13:31:02 UTC
I do not know what's the proper category for TopLogging.
Comment 7 Martin Entlicher 2011-05-30 13:36:01 UTC
FYI: bug #199001 is submitted for the performance inefficiency.
Comment 8 Martin Entlicher 2011-05-30 14:13:20 UTC
I've fixed bug #199001 and that means that this bug can not be reproduced this way any more.

Please use System.err.print("Char array to stderr.\n".toCharArray()); instead. This does not produce any output.
Comment 9 Jaroslav Tulach 2011-05-30 19:10:16 UTC
> Please use System.err.print("Char array to stderr.\n".toCharArray()); instead.
> This does not produce any output.

Sure it does. Just with 5s delay before the output is flushed.
Comment 10 Martin Entlicher 2011-05-31 08:13:57 UTC
Can you please explain me the mechanism which flushes the output after 5s? I did not experience anything like that, nor anyone else did.
Comment 11 err 2011-05-31 14:27:25 UTC
> not experience anything like that, nor anyone else did
Also restore priority.
Comment 12 Jaroslav Tulach 2011-06-01 09:01:53 UTC
I've re-read comment #5 and yes, I understand the problem now. I'll do something with it. But the problem does not deserve P2 priority. It does not affect production. Anyway consider using Logger instead of System.err.
Comment 13 err 2011-06-01 14:29:01 UTC
(In reply to comment #12)
> the problem does not deserve P2 priority. It does not
> affect production.

This regression affects my production and I hope this can be fixed in 7.0.1.

The plugin I'm working with has a table of over a dozen debug flags which control thousands of output statements. When problems show up in the field it is not uncommon to ask a user to turn on some flag (through a UI) and send the messages.log file.

>  Anyway consider using Logger instead of System.err.

I have, there's a plan; the project pre-dates Logger and it is quite a task.
Comment 14 Jaroslav Tulach 2011-06-01 20:48:52 UTC
I am sure Jan can donate a Jackpot rule to convert all System.err to Logger.fine...
Comment 15 err 2011-06-01 21:17:01 UTC
(In reply to comment #14)
> I am sure Jan can donate a Jackpot rule to convert all System.err to
> Logger.fine...

Thanks for the thought. I use jackpot3.0 once and a while...

To this point I've extended my DebugOption class to be based on Logger Levels (as seen in the UI) and added some print methods to it.

In general I need to turn stuff like
            if(G.someDebugOption.getBoolean()) {
                debug only stuff;
                System.err.println(arg);
                debug only stuff;
                System.err.println(arg);
                debug only stuff;
            }
into something like
            if(G.someDebugOption.getBoolean()) {
                debug only stuff;
                G.someDebugOption.println(arg);
                debug only stuff;
                G.someDebugOption.println(arg);
                debug only stuff;
            }

Haven't given much thought to jackpot rules that might pick out System.err usage when in selected blocks. I wonder if it can be done without custom jackpot code/extensions? I wonder if something like the following can be adapted to multiple System.err scattered through the block?
    if(G.$debug_option.getBoolean()) {
        $stmnts1$
        G.$debug_option.println($arg);
        $stmnts2$
    }
Comment 16 Jan Lahoda 2011-06-07 15:48:40 UTC
(In reply to comment #15)
> (In reply to comment #14)
> > I am sure Jan can donate a Jackpot rule to convert all System.err to
> > Logger.fine...
> 
> Thanks for the thought. I use jackpot3.0 once and a while...
> 
> To this point I've extended my DebugOption class to be based on Logger Levels
> (as seen in the UI) and added some print methods to it.
> 
> In general I need to turn stuff like
>             if(G.someDebugOption.getBoolean()) {
>                 debug only stuff;
>                 System.err.println(arg);
>                 debug only stuff;
>                 System.err.println(arg);
>                 debug only stuff;
>             }
> into something like
>             if(G.someDebugOption.getBoolean()) {
>                 debug only stuff;
>                 G.someDebugOption.println(arg);
>                 debug only stuff;
>                 G.someDebugOption.println(arg);
>                 debug only stuff;
>             }
> 
> Haven't given much thought to jackpot rules that might pick out System.err
> usage when in selected blocks. I wonder if it can be done without custom
> jackpot code/extensions? I wonder if something like the following can be
> adapted to multiple System.err scattered through the block?
>     if(G.$debug_option.getBoolean()) {
>         $stmnts1$
>         G.$debug_option.println($arg);
>         $stmnts2$
>     }

It would be nice if something like this would work, but it does not (for several reasons). I will however attach a script that seems to work reasonably for jvi, although it is not really nice. Notes:
-the wrappedWith is a custom condition. Currently it checks only the System.err.println's parent and its parent, but maybe it should look at the parents in a loop?
-currently, the release701 branch of Jackpot 3.0 needs to be used in combination with a release701 NB build. I currently do not have a binary Jackpot build from this branch, will try to make one.
-the second fix solves a problem where sometimes the queried option is not a DebugOption - the fix can be removed, the Apply Pattern refactoring will just warn about "warnings" which have no fixes (safe to ignore - nothing will happen).
-sadly, there appears to be a problem in Jackpot's indexing, so I would suggest to start with empty var/cache/index before applying the changes. I will take a look on this.
Comment 17 Jan Lahoda 2011-06-07 15:51:11 UTC
Created attachment 108782 [details]
A sketch of script to convert (some) System.err.println to jvi's DebugOption.println.
Comment 18 err 2011-06-10 21:36:26 UTC
(In reply to comment #17)
> A sketch of script to convert (some) System.err.println to jvi's
> DebugOption.println.

Jan,

Wow. Many thanks for this. I've been wanting to dig deeper into Jackpot and I'm sure there will be many hours of joyful discovery (and some cursing) as I learn the exact meaning of every last character in the hint :-)

I'll give it a try after this next jVi release; the window split/move/resize commands are almost ready to put out there.
Comment 19 Martin Entlicher 2011-06-16 00:05:46 UTC
Unfortunately, the fix of bug #199001 did not solve this problem, since I've applied additional change http://hg.netbeans.org/main/rev/7bf3ac9904d3 that adds synchronization and thus Thread.holdsLock(this) returns true again in the TopLogging class and no output is flushed.

For me this is really quite annoying that I can not use Thread.dumpStack() to debug some problems in the code. I really do not want to bother with loggers for temporary debug constructions. And I believe that I'm not the only one.

This is a regression and it should be fixed. I do not see a point in the
if (!Thread.holdsLock(this)) condition, therefore I'm going to remove it.
Comment 20 Martin Entlicher 2011-06-16 00:20:40 UTC
Fixed by changeset:   195891:ca8d5f2870f4
http://hg.netbeans.org/main/rev/ca8d5f2870f4

Merged into release701 as changeset:   201056:43298c1e0f78
Comment 21 Quality Engineering 2011-06-16 19:57:56 UTC
Integrated into 'main-golden'
Changeset: http://hg.netbeans.org/main-golden/rev/ca8d5f2870f4
User: mentlicher@netbeans.org
Log: #197600 Removing an unnecessary condition, which breaks logging.
Comment 22 Quality Engineering 2011-06-17 04:52:11 UTC
Integrated into 'releases'
Changeset: http://hg.netbeans.org/releases/rev/43298c1e0f78
User: mentlicher@netbeans.org
Log: #197600 Removing an unnecessary condition, which breaks logging.
(transplanted from ca8d5f2870f410978aa9445020571e0952d3dab3)
Comment 23 Jaroslav Tulach 2011-06-20 14:23:25 UTC
I take this as a request to change ownership of TopLogging class. May I assign remaining issue to you as well?


By use of this website, you agree to the NetBeans Policies and Terms of Use. © 2014, Oracle Corporation and/or its affiliates. Sponsored by Oracle logo