Issue Details (XML | Word | Printable)

Key: GLASSFISH-19822
Type: Bug Bug
Status: Open Open
Priority: Major Major
Assignee: Daniel
Reporter: Architect.SoftWeb.ISD
Votes: 0
Watchers: 1
Operations

If you were logged in you would be able to see more operations.
glassfish

Multiple ClassNotFoundExceptions at server startup

Created: 11/Mar/13 03:09 PM   Updated: 04/Jul/13 09:42 AM
Component/s: web_container
Affects Version/s: 3.1.2.2
Fix Version/s: future release

Time Tracking:
Not Specified

Environment:

a. OS Windows7/ AIX5.3
b. java6 Oracle/IBM implementations


Tags:
Participants: Architect.SoftWeb.ISD and Daniel


 Description  « Hide

GF Multiple ClassNotFoundExceptions
1. Context

1. ISS-SWP-1353SC Migration To GlassFish
2. Description of software
a. OS Windows7/ AIX5.3
b. java6 Oracle/IBM implementations
c. GF 3.1.2.2
d. There is ear with 5 wars within.
i. 3 wars which includes JSF 1.2 (MyFaces1.2+RichFaces3.3.1) and custom jsf -components.
ii. The jsf-oriented wars have the following glassfish-web.xml

iii. The wars have the following amount of classes and interfaces (excluding third-party ones):
1. Jsf-oriented war1 - 1411 classes and interfaces
2. Jsf-oriented war2 - 2500 classes and interfaces
3. Jsf-oriented war3 - 1200 classes and interfaces
iv. jsf-oriented war3 along with JSF contains 22 JSP pages.
v. There are 2 non-jsf wars and one of them uses jersey1.14 which packaged within it.

2. Problem

2.1 Brief Description

1. There are multiple ClassNotFoundException (about SWP classes) exceptions which lead to creation of multiple gf server log files and at the end there are several GF threads blocked with java.util.logging.ConsoleHandler.
2. The multiple exceptions and their consequent logging slowdown start of ear application (which under WLS starts in 3 minutes) to 9 minutes and time to time it simply hangs.
3. GF has correspondent issues assigned (and still unresolved):
a. JSF oriented http://java.net/jira/browse/JAVASERVERFACES-1995
b. Jersey oriented http://java.net/jira/browse/GLASSFISH-16937
c. Another one http://java.net/jira/browse/GLASSFISH-19017
4. As workaround to the issue we up level of javax.enterprise.system.container.web logger level to SEVERE.

2.2 Complete Description

1. During researching of the problem by debugging/performance measurement correspondent GF sources the following facts were identified (see figure below):
a. ClassNotFoundException is result of asking WebappClassLoader to load class which belongs to other WebappClassLoader - but it is impossimble by javaee spec.
b. Wrong request to load unreachable class to WebappClassLoader is result of sharing by certain instance of org.glassfish.hk2.classmodel.reflect.Type knowledge (instances of org.glassfish.hk2.classmodel.reflect.ClassModel) about classes which belongs to different WebappClassLoader.
c. The steps which lead to the issue are part of GF internal activity to identify managed beans (JSF-Components, Jersey-Components and so on) of certain server initializers. The org.glassfish.web.loader.ServletContainerInitializerUtil class is part of the GF internal activity.
d. The Log Record 4 (see Appendix 3.1 chapter) shows that JSF-Components were searching even in context of non-jsf wars (all jsf-oriented wars contain RichFaces within their WEB-INF\lib).
e. Each cycle of "failed class loading and then logging" takes ~0.0006sec but amount of "failed" cycles is about hundred thousand times and in turn leads to losing of minutes (see some details here (see Appendix 3.2 chapter)).

3. Appendix
3.1 Examples of WEB9052 log records

1. [#|2013-03-05T10:29:43.180+0200|WARNING|glassfish3.1.2|javax.enterprise.system.container.web.org.glassfish.web.loader|_ThreadID=17;_ThreadName=Thread-2;|WEB9052: Unable to load class com.softcomputer.softweb.pl.webuipl.softweb.component.sdc.businessobject.requisitiondetailseditor.impl.RequisitionDetailsEditorModelViewConverter$BillingMethodConverter, reason: java.lang.ClassNotFoundException: com.softcomputer.softweb.pl.webuipl.softweb.component.sdc.businessobject.requisitiondetailseditor.impl.RequisitionDetailsEditorModelViewConverter$BillingMethodConverter|#]

2. [#|2013-03-05T10:29:43.463+0200|WARNING|glassfish3.1.2|javax.enterprise.system.container.web.org.glassfish.web.loader|_ThreadID=17;_ThreadName=Thread-2;|WEB9052: Unable to load class com.softcomputer.softweb.pl.webuipl.softweb.component.renderkit.standard.sdc.businessobject.authenticationeditor.impl.AuthenticationEditorUIComponentRenderer, reason: java.lang.ClassNotFoundException: com.softcomputer.softweb.pl.webuipl.softweb.component.renderkit.standard.sdc.businessobject.authenticationeditor.impl.AuthenticationEditorUIComponentRenderer|#]

3. [#|2013-03-05T10:29:44.393+0200|WARNING|glassfish3.1.2|javax.enterprise.system.container.web.org.glassfish.web.loader|_ThreadID=17;_ThreadName=Thread-2;|WEB9052: Unable to load class com.softcomputer.softweb.pl.webuipl.softweb.component.sdc.businessobject.collectspecimenseditor.impl.CollectSpecimensEditorUIComponent, reason: java.lang.ClassNotFoundException: com.softcomputer.softweb.pl.webuipl.softweb.component.sdc.businessobject.collectspecimenseditor.impl.CollectSpecimensEditorUIComponent|#]

4. [#|2013-03-06T11:50:39.123+0200|WARNING|glassfish3.1.2|javax.enterprise.system.container.web.org.glassfish.web.loader|_ThreadID=17;_ThreadName=Thread-2;|WEB9052: Unable to load class org.richfaces.component.html.HtmlDataFilterSlider, reason: java.lang.ClassNotFoundException: org.richfaces.component.html.HtmlDataFilterSlider|#]

3.2 Cycle of "failed class loading and then logging" performance measurement

The table depicts time consumption by related to "GF Multiple ClassNotFoundExceptions " issue code.
Note1: the measurement is done till the moment the GF hangs.
Note2: the table does not show all details of the measurement but depicts integral view and several rows of basic measurement:

ID of checkAgainst
InterestList() call ID of Fail within checkAgainst
InterestList() method Total Duration for failed class loading, (nsec) Total Duration for the fail Logging, (nsec) Total Duration spent for fail class loading and then logging, (nsec) Amount of failed class loading iterations
32,676,850,933 24,956,173,812 57,633,024,745 139,056
3 92787 299347 61439
3 92788 278525 68266
3 92789 285352 46079
3 92790 409938 64852
3 92791 316754 62122
3 92792 301735 45056
3 92793 250536 38912
3 92794 323240 55978
3 92795 264873 42666
3 92796 249512 40277
3 92797 262141 43690
3 92798 250195 40960
3 92799 237224 39595
3 92800 231080 39936
3 92801 218793 38570
3 92802 242003 38570
3 92803 255656 39253
3 92804 238590 39253
3 92805 232105 38229
3 92806 237224 38912



Architect.SoftWeb.ISD added a comment - 11/Mar/13 03:32 PM

1. Pls give me correspondent permissions in order to attach:
1.1. description picture
1.2. test case for the issue (sample ear with several wars)


Daniel added a comment - 25/Jun/13 11:13 PM

You should be able to attach files to this issue, there are several operation links on the left side.
If you still can not, please let me know.

BTW, if you are running on GF4, remember to update web.xml, use org.glassfish.jersey.servlet.ServletContainer API instead.


Architect.SoftWeb.ISD added a comment - 01/Jul/13 09:51 AM

It looks like I can't still attach the files.
All that I see on the left side in section "Operations" are "Go to Planning Board", "Go to Task Board", "Clone this issue", "Comment on this issue", "Create sub-task", "Voting", "Watching" and last "You don't have permission to work on this issue."
I suppose there should present something like "Attach file to this issue" but I don't see it unfortunately.


Daniel added a comment - 01/Jul/13 05:48 PM

Could you please send me by email?
daniel.guo@oracle.com

Thanks


Daniel added a comment - 03/Jul/13 11:03 PM

I got the ear file you sent to me. And trying to deploy on GF4. I got some SEVERE logging message during deployment. Did you get those? Since this is not mentioned in your issue description.

--------------------------------------------------------------------------

[2013-07-03T11:59:13.863-0700] [glassfish 4.0] [SEVERE] [] [] [tid: _ThreadID=40 _ThreadName=Thread-8] [timeMillis: 1372877953863] [levelValue: 1000] [[
log4j:WARN No appenders could be found for logger (org.apache.myfaces.shared_impl.webapp.webxml.WebXmlParser).]]

[2013-07-03T11:59:13.863-0700] [glassfish 4.0] [SEVERE] [] [] [tid: _ThreadID=40 _ThreadName=Thread-8] [timeMillis: 1372877953863] [levelValue: 1000] [[
log4j:WARN Please initialize the log4j system properly.]]

[2013-07-03T11:59:14.182-0700] [glassfish 4.0] [SEVERE] [] [javax.faces] [tid: _ThreadID=40 _ThreadName=admin-listener(1)] [timeMillis: 1372877954182] [levelValue: 1000] [[
Unable to obtain InjectionProvider from init time FacesContext. Does this container implement the Mojarra Injection SPI?]]

[2013-07-03T11:59:14.192-0700] [glassfish 4.0] [SEVERE] [] [javax.faces] [tid: _ThreadID=40 _ThreadName=admin-listener(1)] [timeMillis: 1372877954192] [levelValue: 1000] [[
Unable to inject org.springframework.faces.webflow.FlowApplicationFactory@60e5618f because no InjectionProvider can be found. Does this container implement the Mojarra Injection SPI?]]

[2013-07-03T11:59:14.216-0700] [glassfish 4.0] [INFO] [AS-WEB-GLUE-00172] [javax.enterprise.web] [tid: _ThreadID=40 _ThreadName=admin-listener(1)] [timeMillis: 1372877954216] [levelValue: 800] [[
Loading application gf_multipleCNFEs#jsf-oriented1.war at [/jsf-oriented1]]]

[2013-07-03T11:59:14.665-0700] [glassfish 4.0] [SEVERE] [] [javax.faces] [tid: _ThreadID=40 _ThreadName=admin-listener(1)] [timeMillis: 1372877954665] [levelValue: 1000] [[
Unable to obtain InjectionProvider from init time FacesContext. Does this container implement the Mojarra Injection SPI?]]

[2013-07-03T11:59:14.672-0700] [glassfish 4.0] [SEVERE] [] [javax.faces] [tid: _ThreadID=40 _ThreadName=admin-listener(1)] [timeMillis: 1372877954672] [levelValue: 1000] [[
Unable to inject org.springframework.faces.webflow.FlowApplicationFactory@9bde349 because no InjectionProvider can be found. Does this container implement the Mojarra Injection SPI?]]


Architect.SoftWeb.ISD added a comment - 04/Jul/13 09:25 AM - edited

We did not try to start the ear under GF4 unfortunately.
Even starting of our product under GF3 was a big challenge for us because we had a lot of non-recent libs like MyFaces 1.2.6 (implementation of JSF 1.2) and because of inability to use something like <prefer-application-packages> from weblogic-application.xml like in case of WebLogic to replace default implementation of JSF with ours.

Concerning the messages I have such supposals:
1).No appenders could be found for logger
It looks like log4j need to be configured.
We usually set system variable -Dlog4j.configuration
I tried to start the ear under GF3.1.2 without log4j configured and got similar traces
[#|2013-07-04T12:35:01.979+0300|SEVERE|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=17;_ThreadName=Thread-2;|log4j:WARN No appenders could be found for logger (org.apache.myfaces.shared_impl.webapp.webxml.WebXmlParser).|#]
[#|2013-07-04T12:35:01.980+0300|SEVERE|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=17;_ThreadName=Thread-2;|log4j:WARN Please initialize the log4j system properly.|#]

2)."Does this container implement the Mojarra Injection SPI" and "Unable to inject org.springframework.faces.webflow.FlowApplicationFactory"
I suppose these messages concern usage of MyFaces 1.2.6 (JSF 1.2) inside the ear and so the conflict with Mojarra implementation of JSF provided with GF.
These ones do not appear under GF3.1.2.

So in case "ClassNotFoundException" messages appear anyway and deployment does not fail I suppose the ones stated by you may be ignored.