Hi all,
we found a strange issue on webservice call.
Scenario:
- Windows Server 2003 R2 Enterprise Edition SP2
- IIS 6
- CF multiserver 9,0,0,251028 + chf9000001.jar
- java arguments in jvm.config:
java.args=-Xmx4096M -server -Dcom.sun.management.jmxremote
-Dcom.sun.management.jmxremote.port=7777
-Dcom.sun.management.jmxremote.authenticate=false
-Dcom.sun.management.jmxremote.ssl=false -XX:+PrintGCDetails
-XX:+PrintGCTimeStamps -XX:+PrintHeapAtGC -verbose:gc -Xloggc:PROD_GC.log
-Dsun.io.useCanonCaches=false -XX:MaxPermSize=512m -XX:+UseParallelGC -Xbatch
-Dcoldfusion.rootDir={application.home}/
-Djava.security.policy={application.home}/servers/cfusion/cfusion-ear/cfusion-war/WEB-INF/cfusion/lib/coldfusion.policy
-Djava.security.auth.policy={application.home}/servers/cfusion/cfusion-ear/cfusion-war/WEB-INF/cfusion/lib/neo_jaas.policy
- this CF instance is used only for webservices call and scheduled tasks
Up until some days ago we had 3 webservice installed and running fine.
Some days ago we installed the 4th webservice and after restarting ColdFusion
all was running fine.
>From that moment on, every morning we found a HTTP 500 error on IIS log for
>some of our webservice (not all).
We tried to call webservice from SoapUI and we get nullPointerException.
We analyzed IIS and CF log and found that some class related to webservice that
don't work are unloaded in the night.
Here below a log example:
from IIS log:
2013-01-14 20:45:10 W3SVC2119928668 10.31.2.59 POST
/webservices/productMasterData.cfc - 8080 my_user 151.99.151.4
BW-HTTPClient/5.4 200 0 0
...
from CF -out log:
01/14 21:15:00 Information [scheduler-0] - [my_scheduled_task] Rescheduling for
:Mon Jan 14 21:20:00 CET 2013 Now: Mon Jan 14 21:15:00 CET 2013
[Unloading class cfbasewebservice2ecfc759321327$funcINITPERSISTENTOBJECTS]
[Unloading class sun.reflect.GeneratedMethodAccessor753]
[Unloading class sun.reflect.GeneratedMethodAccessor747]
[Unloading class cfbasewebservice2ecfc759321327$funcCREATEDIRECTORY]
[Unloading class cfcBaseRequestBean2ecfc2095545564]
[Unloading class cfbasewebservice2ecfc759321327$funcSERIALIZETOFILE]
[Unloading class sun.reflect.GeneratedConstructorAccessor480]
[Unloading class cfcBaseRequestBean2ecfc2095545564$funcVALIDATE]
[Unloading class cfbasewebservice2ecfc759321327$funcWRITEPARAMS]
[Unloading class sun.reflect.GeneratedMethodAccessor749]
[Unloading class sun.reflect.GeneratedMethodAccessor751]
[Unloading class cfcGetLastUpdateResponse2ecfc1086528075]
[Unloading class cfbasewebservice2ecfc759321327]
[Unloading class sun.reflect.GeneratedConstructorAccessor484]
[Unloading class cfGetLastUpdate2ecfc91407093$funcINITPERSISTENTOBJECTS]
[Unloading class sun.reflect.GeneratedConstructorAccessor483]
[Unloading class cfbasewebservice2ecfc759321327$funcSENDMAIL]
[Unloading class cfbasewebservice2ecfc759321327$funcWRITELOGWS]
[Unloading class cfcGetLastUpdateRequest2ecfc1493867156]
[Unloading class sun.reflect.GeneratedMethodAccessor752]
[Unloading class sun.reflect.GeneratedMethodAccessor748]
[Unloading class cfbasewebservice2ecfc759321327$funcGETLOGTYPE]
[Unloading class sun.reflect.GeneratedConstructorAccessor485]
[Unloading class cfGetLastUpdate2ecfc91407093]
[Unloading class sun.reflect.GeneratedMethodAccessor750]
[Unloading class cfbasewebservice2ecfc759321327$funcINITLOCALVAR]
[Unloading class sun.reflect.GeneratedConstructorAccessor481]
[Unloading class cfGetLastUpdate2ecfc91407093$funcGETLASTUPDATE]
01/14 21:18:00 Information [scheduler-0] - [my_scheduled_task_2] Task did not
execute at Mon Jan 14 21:18:00 CET 2013 as the task is paused
...
01/14 22:00:00 Information [scheduler-1] - [NetMover Ediel - Importazione
Documenti] Rescheduling for :Tue Jan 15 07:00:00 CET 2013 Now: Mon Jan 14
22:00:00 CET 2013
[Unloading class sun.reflect.GeneratedMethodAccessor693]
[Unloading class sun.reflect.GeneratedMethodAccessor676]
[Unloading class sun.reflect.GeneratedMethodAccessor683]
[Unloading class sun.reflect.GeneratedMethodAccessor682]
[Unloading class cfcDeliveryResultUpdateRequest2ecfc2090630280$funcVALIDATE]
[Unloading class sun.reflect.GeneratedMethodAccessor675]
[Unloading class sun.reflect.GeneratedMethodAccessor685]
[Unloading class sun.reflect.GeneratedMethodAccessor680]
[Unloading class sun.reflect.GeneratedMethodAccessor672]
[Unloading class sun.reflect.GeneratedConstructorAccessor448]
[Unloading class sun.reflect.GeneratedMethodAccessor674]
[Unloading class sun.reflect.GeneratedMethodAccessor684]
[Unloading class sun.reflect.GeneratedMethodAccessor678]
[Unloading class sun.reflect.GeneratedMethodAccessor677]
[Unloading class cfcDeliveryResultUpdateResponse2ecfc538643978]
[Unloading class sun.reflect.GeneratedMethodAccessor679]
[Unloading class sun.reflect.GeneratedMethodAccessor694]
[Unloading class sun.reflect.GeneratedMethodAccessor692]
[Unloading class sun.reflect.GeneratedMethodAccessor690]
[Unloading class sun.reflect.GeneratedConstructorAccessor461]
[Unloading class sun.reflect.GeneratedMethodAccessor671]
[Unloading class sun.reflect.GeneratedMethodAccessor687]
[Unloading class sun.reflect.GeneratedMethodAccessor670]
[Unloading class sun.reflect.GeneratedMethodAccessor691]
[Unloading class sun.reflect.GeneratedMethodAccessor673]
[Unloading class cfcDeliveryResultUpdateRequest2ecfc2090630280]
01/14 22:32:04 Information [scheduler-3] - Run Client Storage Purge
[Unloading class sun.reflect.GeneratedMethodAccessor703]
[Unloading class cfcProductMasterDataUpdateRequest2ecfc730006885$funcVALIDATE]
[Unloading class sun.reflect.GeneratedConstructorAccessor468]
[Unloading class sun.reflect.GeneratedMethodAccessor698]
[Unloading class cfcProductMasterDataUpdateResponse2ecfc1005992327]
[Unloading class sun.reflect.GeneratedMethodAccessor712]
[Unloading class sun.reflect.GeneratedConstructorAccessor467]
[Unloading class sun.reflect.GeneratedConstructorAccessor466]
[Unloading class sun.reflect.GeneratedMethodAccessor706]
[Unloading class cfcProductMasterDataDetail2ecfc1807166497]
[Unloading class sun.reflect.GeneratedMethodAccessor714]
[Unloading class sun.reflect.GeneratedMethodAccessor701]
[Unloading class sun.reflect.GeneratedMethodAccessor705]
[Unloading class sun.reflect.GeneratedMethodAccessor699]
[Unloading class sun.reflect.GeneratedMethodAccessor704]
[Unloading class sun.reflect.GeneratedMethodAccessor702]
[Unloading class sun.reflect.GeneratedMethodAccessor707]
[Unloading class sun.reflect.GeneratedMethodAccessor697]
[Unloading class sun.reflect.GeneratedMethodAccessor700]
[Unloading class cfcProductMasterDataUpdateRequest2ecfc730006885]
[Unloading class sun.reflect.GeneratedMethodAccessor709]
[Unloading class cfcProductMasterDataDetail2ecfc1807166497$funcVALIDATE]
[Unloading class sun.reflect.GeneratedMethodAccessor708]
01/14 23:39:04 Information [scheduler-3] - Run Client Storage Purge
[Unloading class sun.reflect.GeneratedMethodAccessor787]
01/15 00:46:04 Information [scheduler-2] - Run Client Storage Purge
[Unloading class sun.reflect.GeneratedMethodAccessor754]
[Unloading class sun.reflect.GeneratedMethodAccessor755]
[Unloading class sun.reflect.GeneratedMethodAccessor756]
01/15 01:53:04 Information [scheduler-1] - Run Client Storage Purge
...
01/15 02:30:42 Information [scheduler-2] - [my_scheduled_task_3] Rescheduling
for :Wed Jan 16 02:30:00 CET 2013 Now: Tue Jan 15 02:30:42 CET 2013
...
from IIS log:
2013-01-15 03:00:51 W3SVC2119928668 10.31.2.59 POST
/webservices/productMasterData.cfc - 8080 my_user 151.99.151.4
BW-HTTPClient/5.4 500 0 0
As you can see between a successfull call (on 2013-01-14 20:45:10) and a failed
call (2013-01-15 03:00:51) there was these logs
[Unloading class cfcProductMasterDataUpdateRequest2ecfc730006885$funcVALIDATE]
[Unloading class cfcProductMasterDataUpdateResponse2ecfc1005992327]
[Unloading class cfcProductMasterDataDetail2ecfc1807166497]
[Unloading class cfcProductMasterDataUpdateRequest2ecfc730006885]
[Unloading class cfcProductMasterDataDetail2ecfc1807166497$funcVALIDATE]
related to the webservice that fail (ProductMasterDataUpdate.cfc)
Are these unload related to full gc?
Why CF (or java) is enable to reload classes at next webservice call?
Why in some case (i.e. GetLastUpdate.cfc webservice) after class unloading
webservice still work fine?
We tried to increase MaxPermSize to 512m but I don't know if this parameter is
related to our issue.
Thanks in advance for you help
Gualtiero
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~|
Order the Adobe Coldfusion Anthology now!
http://www.amazon.com/Adobe-Coldfusion-Anthology/dp/1430272155/?tag=houseoffusion
Archive:
http://www.houseoffusion.com/groups/cf-talk/message.cfm/messageid:353881
Subscription: http://www.houseoffusion.com/groups/cf-talk/subscribe.cfm
Unsubscribe: http://www.houseoffusion.com/groups/cf-talk/unsubscribe.cfm
