This Bugzilla instance is a read-only archive of historic NetBeans bug reports. To report a bug in NetBeans please follow the project's instructions for reporting issues.
Here's what I did. This tutorial: http://www.netbeans.org/kb/articles/nb-profiler-tutor-8.html uses Tomcat for Exercises 2 and 3. The same program is used for both Exercises. It currently specifies Tomcat as its deployment server. I changed that in the project properties to SJS AS 8.2. Then I did a Clean and Build. Then I attempted to complete Exercises 2 and 3 in two different environments: SPARC/Solaris10 and x86/Solaris11 (Nevada build 33). In both environments I ran into a problem at the beginning of exercise 3: when I selected Profile > Profile Main Project and then clicked Yes to tell it to stop the current profiling session and restart, SJS AS 8.2 seemed to hang. In other words, it appears the Profiler could stop it without any problem but then the restart did not work. As a result, I couldn't complete exercise 3. At Ludo's request, I am opening this bug against the SJS AS 8.2 plugin. From Ludo's email: > I've seen this... The only way is to really stop the server...not to > unattach and reattach... > My theorie now is around the native launcher for AS 8.2... > I remember similar issue with the debugger and socket based debugging. > File a bug on the AS plugin, but I am afraid we can only fix it in 5.5
Can you try the workaround which is to stop the server via the runtime tab before doing a new profile session...?
Ludo, that approach certainly helps. I got quite a bit further into Exercise 3 if I used Stop from the runtime tab at the end of Exercise 2. Unfortunately, performance was *very* slow (compared to Tomcat) but I suspect that's just because of the number of objects SJS AS creates (as compared to Tomcat). I made it almost to the end of Exercise 3 and then the Profiler reported that SJS AS was no longer responding. If I can reproduce that problem, I will open an additional IZ.
I know it does not help you, ...but I tried the latest GlassFish build, with the latest NB 5.5 build and a 5.5 profiler build, and I can re-profile the same project over and over, so this bug is not appearing there. Not sure if this is GlassFish with it's java launcher mode by default, or the latest profiler code... We still need to fix this for Nb 5.0 and AS 8.2... Nor for per stuff, we need to find a way to filter what we can... Any fine tuning of class filtering we could do there? Can you try a few setting?
If the profiler is doing a system.exit() on the AS 8.2 VM, the Message Broker process is not killed or shutdown properly... Then at the next try to start the AS 8.2, AS 8.2 cannot start the broker, Greg : to comfirm, please see if the AS log has something like: "A conflict occured on port 3700 . Server is shutting down." or an equivalent message showing that the server cannot restart properly. In that case, the AS plugin is waiting 580000 milliseconds (almost 10 minutes) (I think this is way too much) to try to see if eventually the server can start, even if it cannot. Those 10 minutes give the impression every thing is locked... At least, this is my theory. Greg, if you confirm the theory, we need to work on a clean API from the profiler to shutdown cleanly the server, so that all the processes including the broker are correctly shutdown... Also, I need to fix the timeout and better detect this situation. Maybe we can do a patch for J1?
Regarding my latest tests, I did Nb5.5+latest profiler+AS 8.2 server... Sometimes, I now can re-attach to AS 8.2 so my theory may be valid sometimes, but not always... So Greg: if you have the time, can you try a latest 5.5+ profiler 5.5 and AS 8.2 conbination?
Hi Ludo. I see you've posted three comments. Let me address each with a separate comment, starting with Tue Apr 4 22:48:48 +0000 2006 ------- where you wrote: >Nor for per stuff, we need to find a way to filter what we can... Any fine >tuning of class filtering we could do there? >Can you try a few setting? I'm not sure I understand the phrase "Nor for per stuff," but I think it means: "Now for performance stuff." If so, the filtering issue is a bit of a problem because in Exercise 3 I'm doing memory profiling. Specifically, I'm looking for a memory leak, so I need to turn on the Profiler's gc tracking and allocation stack traces. As a result, the init. of SJS AS takes a *long* time compared to Tomcat. But if we can get all this other stuff resolved, I'll change the instructions in the tutorial. When the new profiling session starts, I'll select Monitoring instead of Memory Profiling. This has no overhead. Then click Run. Then let SJS AS intialize at full speed. Then choose Profile > Modify Profiling and select Memory Profiling. That should work better and would be more like a real-world situation anyway because unless you're trying to track a memory leak in the app. server itself, you wouldn't be interested in capturing all that startup information - you don't want information to be captured until the actual application starts running. As for the general issue of filtering while doing memory profiling, the NetBeans Profiler does have some capabilities today, but they are only available *after* the instrumentation of the classes has been performed. In other words, from the profiling results window you can pick one or more classes and tell the Profiler to stop profiling the allocation and gc'ing of those classes. But in the current version you cannot do the filtering up front (like you can with CPU Profiling). But that will get fixed - there is already an RFE: http://www.netbeans.org/issues/show_bug.cgi?id=55474 and it has been prioritized for 6.0.
>If the profiler is doing a system.exit() on the AS 8.2 VM, the Message Broker process is not killed or shutdown properly... >Then at the next try to start the AS 8.2, AS 8.2 cannot start the broker, >Greg : to comfirm, please see if the AS log has something like: I'm not seeing a message like that. I am instead seeing this: Profiler Agent: Initializing... Profiler Agent: Options: >/home/gs145266/tools/netbeans/5.0/ga/profiler1/lib,5140< Profiler Agent: Initialized succesfully Profiler Agent: Initializing... Profiler Agent: Options: >/home/gs145266/tools/netbeans/5.0/ga/profiler1/lib,5140< Profiler Agent: Initialized succesfully Profiler Agent: Waiting for connection on port 5140 (Protocol version: 2) Profiler Agent: Waiting for connection on port 5140 (Protocol version: 2) Profiler Agent Error: Exception when trying to establish connection with client: java.net.BindException: Address already in use Profiler Agent: Established local connection with the tool [#|2006-04-05T15:59:22.545-0500|INFO|sun-appserver-pe8.2|javax.enterprise.system.core|_ThreadID=10;|Instance not running.|#] [#|2006-04-05T15:59:22.545-0500|INFO|sun-appserver-pe8.2|javax.enterprise.system.core|_ThreadID=10;|Instance not running.|#] Profiler Agent: Connection with agent closed Profiler Agent: Connection with agent closed I have attached the full log file (although only the very end of it is interesting) as sjsas82.log
Created attachment 29649 [details] SJS AS 8.2 log file
>So Greg: if you have the time, can you try a latest 5.5+ profiler 5.5 and AS 8.2 conbination? On Solaris/SPARC I have just tried the daily build of 5.5 dated 2006-04-05 and the 20060306 Q-build of Profiler 5.5 with SJS AS 8.2. I get the same result as in my previous comment: java.net.BindException: Address already in use
I think the key is 'Profiler Agent Error: Exception when trying to establish connection with client: java.net.BindException: Address already in use' message. It tells that another Profiler agent is already running while starting a new one. As you can see, all Profiler debug messages are doubled, like two agents are starting at the same time. One connects (Established local connection with the tool), second has blocked port (Address already in use). Because of the blocked port, Profiler client (tool/GUI) finishes profiling session as unsuccessful, which disconnects the first (already connected) agent. Most likely this is a server configuration problem. Gregg, please try to profile fresh AS 8.2 installation manually according to Attach Wizard instructions for manual integration. This should definitely work and then we should be able to make diff and find the problem.
I installed a separate instance of SJS AS 8.2 for Solaris SPARC. As Jirka requested, I then followed the instructions for doing a manual Attach with the NB Profiler. Unfortunately, it does not work. The instructions indicate that I should use asadmin to start SJS AS. This is the command I am using: asadmin start-domain --verbose --domaindir /home/gs145266/tools/sjsas/8.2/ga/domains domain1 This is the initial output that I get: Starting Domain domain1, please wait. Starting Sun Java System Application Server Platform Edition 8.0.0_01 (build b08-fcs) ... java.util.logging.ErrorManager: 0: Error In getLogService java.util.logging.ErrorManager: 0: Error In getLogService recursive call into SystemOutandErrhandler java.lang.RuntimeException: recursivecall at com.sun.enterprise.server.logging.SystemOutandErrHandler$LoggingByteArrayOutputStream.flush(SystemOutandErrHandler.java:189) at java.io.PrintStream.write(PrintStream.java:260) at sun.nio.cs.StreamEncoder$CharsetSE.writeBytes(StreamEncoder.java:336) at sun.nio.cs.StreamEncoder$CharsetSE.implFlushBuffer(StreamEncoder.java:404) at sun.nio.cs.StreamEncoder.flushBuffer(StreamEncoder.java:115) at java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:169) at java.io.PrintStream.write(PrintStream.java:305) at java.io.PrintStream.print(PrintStream.java:448) at java.io.PrintStream.println(PrintStream.java:585) at com.sun.enterprise.server.logging.SystemOutandErrHandler$LoggingPrintStream.println(SystemOutandErrHandler.java:144) at java.util.logging.ErrorManager.error(ErrorManager.java:76) at com.sun.enterprise.server.logging.ServerLogManager.getLogService(ServerLogManager.java:284) at com.sun.enterprise.server.logging.FileandSyslogHandler.publish(FileandSyslogHandler.java:266) at java.util.logging.Logger.log(Logger.java:424) at java.util.logging.Logger.doLog(Logger.java:446) at java.util.logging.Logger.log(Logger.java:469) at com.sun.enterprise.server.logging.SystemOutandErrHandler$LoggingByteArrayOutputStream.flush(SystemOutandErrHandler.java:198) at java.io.PrintStream.write(PrintStream.java:260) at sun.nio.cs.StreamEncoder$CharsetSE.writeBytes(StreamEncoder.java:336) at sun.nio.cs.StreamEncoder$CharsetSE.implFlushBuffer(StreamEncoder.java:404) at sun.nio.cs.StreamEncoder.flushBuffer(StreamEncoder.java:115) at java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:169) at java.io.PrintStream.write(PrintStream.java:305) at java.io.PrintStream.print(PrintStream.java:448) at java.io.PrintStream.println(PrintStream.java:585) at com.sun.enterprise.server.logging.SystemOutandErrHandler$LoggingPrintStream.println(SystemOutandErrHandler.java:144) at java.util.logging.ErrorManager.error(ErrorManager.java:76) at com.sun.enterprise.server.logging.ServerLogManager.getLogService(ServerLogManager.java:284) at com.sun.enterprise.server.logging.ServerLogManager.reInitializeServerLoggers(ServerLogManager.java:468) at com.sun.enterprise.server.ApplicationServer.onInitialization(ApplicationServer.java:119) at com.sun.enterprise.server.PEMain.run(PEMain.java:210) at com.sun.enterprise.server.PEMain.main(PEMain.java:172) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:324) at org.apache.commons.launcher.ChildMain.run(ChildMain.java:269) java.util.logging.ErrorManager: 0: Error In getLogService java.util.logging.ErrorManager: 0: Error In getLogService java.util.logging.ErrorManager: 0: Error In getLogService java.util.logging.ErrorManager: 0: Error In getLogService java.util.logging.ErrorManager: 0: Error In getLogService java.util.logging.ErrorManager: 0: Error In getLogService com.sun.enterprise.config.ConfigException: Error refreshing ConfigContext:/home/gs145266/tools/sjsas/8.2/ga/domains/domain1/config/domain.xml cause: Failed to create the XML-DOM Document. Check your XML to make sure it is correct. Attribute "availability-enabled" must be declared for element type "j2ee-application". at com.sun.enterprise.config.ConfigContextImpl.refresh(ConfigContextImpl.java:315) at com.sun.enterprise.config.ConfigContextImpl.refresh(ConfigContextImpl.java:397) at com.sun.enterprise.config.ConfigContextImpl.getRootConfigBean(ConfigContextImpl.java:192) It then goes on and on and on... throwing exceptions repeatedly. It looks to me like the problem is that I just don't know enough about how to use asadmin. I'm guessing there are some additional parameters that I need to pass to it in order for it to work. Note that this install of SJS AS 8.2 will start fine from within the IDE's Runtime window. So until I can get SJS AS 8.2 to start correctly, I can't make progress on trying Jirka's suggested test case.
Type which asadmin to know is you are not using an ***old*** AS 8.0 installation with Solaris, If yes, you try to start an 8.2 domain with the 8.0 binary tools (asadmin, etc)... Of course, random things will happen in this unsupported case.
Sorry about the duplicated comment above.... >you try to start an 8.2 domain with the 8.0 binary tools (asadmin, etc)... Doh! That's exactly what I was doing. Forgot to put ./ in order to get the correct asadmin. I have verified that I can now use asadmin to successfully start SJS AS 8.2 from outside the IDE. I did this *without* the modification to the domain.xml file that is described in the NetBeans Profiler's manual attach instructions, just to make sure that it worked. Which it did, once I used the correct version of asadmin :-) So then I modified domain.xml and tried again. This is the error I got: ~/tools/sjsas/8.2/ga/bin$ ./asadmin start-domain --verbose --domaindir /home/gs145266/tools/sjsas/8.2/ga/domains domain1 Starting Domain domain1, please wait. com.sun.enterprise.config.ConfigException: Error refreshing ConfigContext:/home/gs145266/tools/sjsas/8.2/ga/domains/domain1/config/domain.xml cause: Failed to create the XML-DOM Document. Check your XML to make sure it is correct. The content of element type "profiler" must match "(jvm-options|property)*". at com.sun.enterprise.config.impl.ConfigContextImpl.refresh(ConfigContextImpl.java:368) at com.sun.enterprise.config.impl.ConfigContextImpl.refresh(ConfigContextImpl.java:450) at com.sun.enterprise.config.impl.ConfigContextImpl.getRootConfigBean(ConfigContextImpl.java:241) at com.sun.enterprise.config.serverbeans.ServerBeansFactory.getDomainBean(ServerBeansFactory.java:74) at com.sun.enterprise.config.serverbeans.ConfigAPIHelper.getDomainConfigBean(ConfigAPIHelper.java:57) at com.sun.enterprise.tools.launcher.ProcessLauncher.buildInternalCommand(ProcessLauncher.java:429) at com.sun.enterprise.tools.launcher.ProcessLauncher.buildCommand(ProcessLauncher.java:404) at com.sun.enterprise.tools.launcher.ProcessLauncher.process(ProcessLauncher.java:204) It looks like the XML elements specified by the NetBeans Profiler's Attach Wizard are not correct for SJS AS 8.2? So I can start SJS AS, but not with the appropriate values for it to wait for the NetBeans Profiler....
Vince, your solaris config is better to fully understand this bug. Stop by so I can give you some context. I think the issue is the profiler is killing the server when stopping instead of calling a clean shutdown (stop-domain), and some ports are still used when we restart... No sure, as many things are in the bug report. Contact Gregg as well for help. Profiler builds are under http://profiler.netbeans.org/download/55qbuild.html Start with 8.2, then move on 9.0
Findings to date: The profiler is calling StartSunServer.stopDeploymentManager(). The stop fires the launcher which starts with the profiler enabled. The profiler detects its NEW "target" (the launcher doing the STOP) and attaches to it. It ends pretty quickly. The server then starts up, with the profiler "enabled" but no client tries to attach to it. So, It just kinda waits for someone to notice... Since the profiler was attached to a running process (that finished) it doesn't connect automatically to the instance. It thinks it is done... It takes a while for the stop to complete, if the server was started with the profiler enabled. I put a sleep into the thread that fires off when stopDeploymentManager() is called. This resolves the problem (I can Profile Main Project repeatedly without issue), but I don't know why....
Comments to previous post: The Profiler itself doesn't call any start/stop server actions on any server. All these calls are performed from j2eeserver module based on commands from Runtime tab or via nbstartprofiledserver ant task. The only scenario where Profiler is involved in stopping the server is when server is started in profiling mode for direct attach - in this case the profiler stops the agent blocking server JVM and the JVM is then also stopped. Stopping the server from another (profiling) state is done by reqular stop action as the server is "normally" running and profiling is transparent to it. The problem seems to be somewhere in the stop launcher starting with profiler enabled. Do I understand correctly that for stopping the server domain.xml is used and the profiler agent is started for it? If so, thats definitely a problem. In fact there is no reason to profile stopping the server, domain.xml should be either cleaned up before stop launcher or the stop launcher should ignore profiler. The Profiler has no way to "detect new target starting" unless someone tells him, it can't attach to the stop launcher automatically. Instead, the JVM of the stop launcher is immediately blocked by profiler agent and waits forever for the startup because the Profiler never connects to it (unless starting new profiling session, in that case stop launcher would be the first target the Profiler connects to). Maybe the sleep you are writing about gives the serverplugin enough time to clean up domain.xml (disable profiling) before starting the stop launcher. This could be one of possible fixes but shouldn't rely on concrete time, but should be synchronous instead - first clean up domain.xml, then start the stop launcher.
Created attachment 33048 [details] first hack that seems to resolve issue
I have attached a first attempt at a patch for this issue. I have used it on sol 10, jdk 1.5.0-08, nb 5.5 personal build with profiler 5.5 (2006-08-16 nightly). Please try it out in a different environment. See if it breaks for you. Look the code over. I am not happy with it, but I doubt the profiler will every behave the way I would like it to; disconnecting from a process instead of killing it with System.exit().
Profile Main Project followed by Profile Main Project should now work as expected. Tested with 8.2 PE and GF V1 U1 B7. Checking in StartSunServer.java; /cvs/serverplugins/sun/appsrv81/src/org/netbeans/modules/j2ee/sun/ide/j2ee/StartSunServer.java,v <-- StartSunServer.java new revision: 1.4.4.6.2.16; previous revision: 1.4.4.6.2.15 done Checking in ConfigureProfiler.java; /cvs/serverplugins/sun/appsrv81/src/org/netbeans/modules/j2ee/sun/ide/j2ee/ConfigureProfiler.java,v <-- ConfigureProfiler.java new revision: 1.4.2.5.2.5; previous revision: 1.4.2.5.2.4 done Checking in OptionalFactory.java; /cvs/serverplugins/sun/appsrv81/src/org/netbeans/modules/j2ee/sun/ide/j2ee/OptionalFactory.java,v <-- OptionalFactory.java new revision: 1.1.16.2.2.4; previous revision: 1.1.16.2.2.3