Hi all: When I try to view *any* crystal based report bundled with ITSM 7, through the "reporting console", using a browser, the report window opens and within seconds it shows this error: "Failed to process the request!!"
The URL of this error is, the following, coming from a Crystal box that is separate from the mid-tier: http://crystal_server001:8081/arreports/m11c23c11b16/313LJCYFfh98NpQhcthMhc3n1g0PV63LYg8sQ55v7n59JQY80LjC8874804361229084677350/null Makes me think all is well on mid-tier, but something in the crystal box is unhappy. On midtier log(detail at the bottom), I see this error: Exception while trying to find plugin "Report" in the server "remedy002" Throw Error - 9394 On ArWebReportviewer log (detail at the bottom), I see Dec 12, 2008 6:01:01 AM - FINE (com.remedy.log.REPORTING) : Opening Managed Report, name = remedy002-RRCSPORunReportbtnSM2100-1-Incident Details by Date Range Dec 12, 2008 6:01:02 AM - FINE (com.remedy.log.REPORTING) : Caught Exception There's nothing in plugin error log, arerror.log etc. All reports work fine through Remedy User. I have: -ARS 7.1 p2, ITSM 7.03 p007, Solaris 10 -Midtier 7.1 p5 with WebLogic Server 9.2 (separate box; don't ask why not apache), Solaris 10 -Crystal on separate Windows 2003 box, IIS 6, Tomcat 5.5. I think we have BOXI, not Crystal XI...as perthe RemWebReportViewer config tool -IE 7 Before I paste logs, here's the killer twist: If I close the report window with error... ...and back on "Report Console" (by the way, this is "IM Console->Reports")...simply click on "Run Report" button again, the report shows up fine. To make it more interesting, if I repeat the actions, clicking on "Run Report", waiting for a while, closing the windows that shows up and on..., it alternates between showing the error and showing the report. This alternating pattern mostly holds. For me and for other users. For any ITSM 7 Crystal based report. Through Remedy User, all reports run fine. What the hell is going on? The Crystal stuff was setup recently I am told and apperantly it has been like this from the beginning. SOME LOGS CAPTURING ONE ERROR AND ONE SUBSEQUENT SUCCESSFUL REPORT ARE BELOW. Note the java exception. Any thoughts?? ---ARWebReport log--- Dec 12, 2008 6:01:01 AM - FINE (com.remedy.log.REPORTING) : Opening Managed Report, name = remedy002-RRCSPORunReportbtnSM2100-1-Incident Details by Date Range Dec 12, 2008 6:01:02 AM - FINE (com.remedy.log.REPORTING) : Caught Exception Dec 12, 2008 6:01:31 AM - FINE (com.remedy.log.REPORTING) : Opening Managed Report, name = remedy002-RRCSPORunReportbtnSM2100-1-Incident Details by Date Range <<note the exception the first time, successful report the second time)>> ---Midtier log, note error about not finding Report plugin; but if appears the second time...on successful report as well!---- Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.stubs.GoatServlet postInternal GoatServlet: url=http://remedy-midtier.company.com:8003/arsys/BackChannel/?param=238%2FServerRunProcess%2F12%2Fremedy00228%2FRRC%3ASPO%3ARunReportbtn_SM2_1001%2F01%2F09%2F3006364002%2F0%2F2%2F0%2F2%2F0%2F24%2F2%2F9%2F4900011009%2F300144800105%2F2%2F13%2FHPD%3AHelp%20Desk84%2F('1000000560'%20%3E%3D%20%2212%2F5%2F2008%205%3A03%3A11%20AM%22%20AND%20'1000000560'%20%3C%3D%20%2212%2F12%2F2008%205%3A03%3A11%20AM%22)8%2F2%2F1%2F41%2F4 Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.stubs.GoatServlet postInternal cookie=IP-Restriction-GUID=607c0594f3c7d518:2c110e4f:11e13224d6a:-7ed9; JSESSIONID=zP7HJCzbFvBT0Tb2zXnfPW2ptB088X0RMz5NDZbx7jrpx160CQ0q!-887480436; PopBlock=0; GKW=%7B14%3A%7Bn%3A%22LASTID%22%2Ct%3A6%2Cv%3Anull%7D%2C15%3A%7Bn%3A%22LASTCOUNT%22%2Ct%3A7%2Cv%3A1%7D%7D; GF=%7B1714200%3A%7Bt%3A4%2Cv%3A%22BMC.ASSET%22%2Ca%3A%7B%7D%7D%2C1714600%3A%7Bt%3A4%2Cv%3A%22BMC.ASSET%22%2Ca%3A%7B%7D%7D%2C1714700%3A%7Bt%3A4%2Cv%3A%22BMC.ASSET.SANDBOX%22%2Ca%3A%7B%7D%7D%2C1714800%3A%7Bt%3A6%2Cv%3A%221%20No%22%2Ca%3A%7Bl%3A%22No%22%7D%7D%2C1715200%3A%7Bt%3A6%2Cv%3A%220%20Yes%22%2Ca%3A%7Bl%3A%22Yes%22%7D%7D%2C1000013%3A%7Bt%3A0%2Cv%3A%22%22%2Ca%3A%7B%7D%7D%2C1000031%3A%7Bt%3A6%2Cv%3A%222%20Reopen%20in%20Current%22%2Ca%3A%7Bl%3A%22Reopen%20in%20Current%22%7D%7D%7D Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.stubs.GoatServlet setupSessionData GoatServlet: SessionID=zP7HJCzbFvBT0Tb2zXnfPW2ptB088X0RMz5NDZbx7jrpx160CQ0q!-887480436!1229075227242 Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.PERFORMANCE) : (Thread 73) com.remedy.arsys.stubs.BackchannelServlet doRequest Backchannel start: ServerRunProcess Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.backchannel.NDXServerRunProcess mapProperties --> ServerRunProcess Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.backchannel.NDXServerRunProcess mapProperties mServer=remedy002 Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.backchannel.NDXServerRunProcess mapProperties mAlName=RRC:SPO:RunReportbtn_SM2_100 Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.backchannel.NDXServerRunProcess mapProperties mActIdx=0 Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.backchannel.NDXServerRunProcess mapProperties mTs=0 Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.backchannel.NDXServerRunProcess mapProperties mFid=300636400 Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.backchannel.NDXServerRunProcess mapProperties mKeywordIds= Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.backchannel.NDXServerRunProcess mapProperties mKeywordVals= Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.backchannel.NDXServerRunProcess mapProperties mKeywordTypes= Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.backchannel.NDXServerRunProcess mapProperties mFieldIds=490001100,300144800 Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.backchannel.NDXServerRunProcess mapProperties mFieldVals=HPD:Help Desk,('1000000560' >= "12/5/2008 5:03:11 AM" AND '1000000560' <= "12/12/2008 5:03:11 AM") Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.backchannel.NDXServerRunProcess mapProperties mFieldTypes=4,4 Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.PERFORMANCE) : (Thread 73) com.remedy.arsys.stubs.BackchannelServlet doRequest Backchannel end: ServerRunProcess: Process: 121; Send: 1; Chars: 96 Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.stubs.GoatServlet postInternal GoatServlet: url=http://remedy-midtier.company.com:8003/arsys/BackChannel/?param=224%2FCompileExternalQualification%2F12%2Fremedy00213%2FRRC%3AReporting18%2FDefault%20Admin%20View12%2Fremedy00213%2FHPD%3AHelp%20Desk12%2F5%5C300636400%5C13%2F1%2F9%2F30063640071%2F1%2F66%2F1%5C4%5C3%5C1%5C1000000560%5C2%5C7%5C1228471391%5C4%5C5%5C1%5C1000000560%5C2%5C7%5C1229076191%5C5%2F1%2F1%2F4 Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.stubs.GoatServlet postInternal cookie=IP-Restriction-GUID=607c0594f3c7d518:2c110e4f:11e13224d6a:-7ed9; JSESSIONID=zP7HJCzbFvBT0Tb2zXnfPW2ptB088X0RMz5NDZbx7jrpx160CQ0q!-887480436; PopBlock=0; GKW=%7B14%3A%7Bn%3A%22LASTID%22%2Ct%3A6%2Cv%3Anull%7D%2C15%3A%7Bn%3A%22LASTCOUNT%22%2Ct%3A7%2Cv%3A1%7D%7D; GF=%7B1714200%3A%7Bt%3A4%2Cv%3A%22BMC.ASSET%22%2Ca%3A%7B%7D%7D%2C1714600%3A%7Bt%3A4%2Cv%3A%22BMC.ASSET%22%2Ca%3A%7B%7D%7D%2C1714700%3A%7Bt%3A4%2Cv%3A%22BMC.ASSET.SANDBOX%22%2Ca%3A%7B%7D%7D%2C1714800%3A%7Bt%3A6%2Cv%3A%221%20No%22%2Ca%3A%7Bl%3A%22No%22%7D%7D%2C1715200%3A%7Bt%3A6%2Cv%3A%220%20Yes%22%2Ca%3A%7Bl%3A%22Yes%22%7D%7D%2C1000013%3A%7Bt%3A0%2Cv%3A%22%22%2Ca%3A%7B%7D%7D%2C1000031%3A%7Bt%3A6%2Cv%3A%222%20Reopen%20in%20Current%22%2Ca%3A%7Bl%3A%22Reopen%20in%20Current%22%7D%7D%7D Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.stubs.GoatServlet setupSessionData GoatServlet: SessionID=zP7HJCzbFvBT0Tb2zXnfPW2ptB088X0RMz5NDZbx7jrpx160CQ0q!-887480436!1229075227242 Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.PERFORMANCE) : (Thread 73) com.remedy.arsys.stubs.BackchannelServlet doRequest Backchannel start: CompileExternalQualification Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.backchannel.NDXCompileExternalQualification mapProperties --> CompileExternalQualification Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.backchannel.NDXCompileExternalQualification mapProperties mCurrentServer=remedy002 Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.backchannel.NDXCompileExternalQualification mapProperties mCurrentSchema=RRC:Reporting Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.backchannel.NDXCompileExternalQualification mapProperties mCurrentVui=Default Admin View Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.backchannel.NDXCompileExternalQualification mapProperties mRemoteServer=remedy002 Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.backchannel.NDXCompileExternalQualification mapProperties mRemoteSchema=HPD:Help Desk Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.backchannel.NDXCompileExternalQualification mapProperties mQualification=5\300636400\ Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.backchannel.NDXCompileExternalQualification mapProperties mQualFieldIds=300636400 Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.backchannel.NDXCompileExternalQualification mapProperties mQualFieldValues=1\4\3\1\1000000560\2\7\1228471391\4\5\1\1000000560\2\7\1229076191\ Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.SERVLET) : (Thread 73) com.remedy.arsys.backchannel.NDXCompileExternalQualification mapProperties mQualFieldTypes=4 Dec 12, 2008 6:00:03 AM - FINE (com.remedy.log.PERFORMANCE) : (Thread 73) com.remedy.arsys.stubs.BackchannelServlet doRequest Backchannel end: CompileExternalQualification: Process: 47; Send: 0; Chars: 102 Dec 12, 2008 6:00:04 AM - FINE (com.remedy.log.INTERNAL) : (Thread 73) com.remedy.arsys.goat.GoatException <init> Throw Error - 9391 Dec 12, 2008 6:00:04 AM - FINE (com.remedy.log.INTERNAL) : (Thread 73) com.remedy.arsys.goat.GoatException <init> Throw Error - 9394 Dec 12, 2008 6:00:04 AM - FINE (com.remedy.log.INTERNAL) : (Thread 73) com.remedy.arsys.goat.GoatException <init> Caused due to Throw Error - 9391 Dec 12, 2008 6:00:04 AM - FINE (com.remedy.log.DVMODULE) : (Thread 73) com.remedy.arsys.plugincontainer.impl.PluginFactory getInstance Exception while trying to find plugin "Report" in the server "remedy002" Throw Error - 9394 Dec 12, 2008 6:00:05 AM - FINE (com.remedy.log.PERFORMANCE) : (Thread 73) com.remedy.arsys.reporting.ReportFactory processRequest Plugin Report time = 1720 Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.stubs.GoatServlet postInternal GoatServlet: url=http://remedy-midtier.company.com:8003/arsys/BackChannel/?param=238%2FServerRunProcess%2F12%2Fremedy00228%2FRRC%3ASPO%3ARunReportbtn_SM2_1001%2F01%2F09%2F3006364002%2F0%2F2%2F0%2F2%2F0%2F24%2F2%2F9%2F4900011009%2F300144800105%2F2%2F13%2FHPD%3AHelp%20Desk84%2F('1000000560'%20%3E%3D%20%2212%2F5%2F2008%205%3A03%3A11%20AM%22%20AND%20'1000000560'%20%3C%3D%20%2212%2F12%2F2008%205%3A03%3A11%20AM%22)8%2F2%2F1%2F41%2F4 Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.stubs.GoatServlet postInternal cookie=IP-Restriction-GUID=607c0594f3c7d518:2c110e4f:11e13224d6a:-7ed9; JSESSIONID=zP7HJCzbFvBT0Tb2zXnfPW2ptB088X0RMz5NDZbx7jrpx160CQ0q!-887480436; PopBlock=0; GKW=%7B14%3A%7Bn%3A%22LASTID%22%2Ct%3A6%2Cv%3Anull%7D%2C15%3A%7Bn%3A%22LASTCOUNT%22%2Ct%3A7%2Cv%3A1%7D%7D; GF=%7B1714200%3A%7Bt%3A4%2Cv%3A%22BMC.ASSET%22%2Ca%3A%7B%7D%7D%2C1714600%3A%7Bt%3A4%2Cv%3A%22BMC.ASSET%22%2Ca%3A%7B%7D%7D%2C1714700%3A%7Bt%3A4%2Cv%3A%22BMC.ASSET.SANDBOX%22%2Ca%3A%7B%7D%7D%2C1714800%3A%7Bt%3A6%2Cv%3A%221%20No%22%2Ca%3A%7Bl%3A%22No%22%7D%7D%2C1715200%3A%7Bt%3A6%2Cv%3A%220%20Yes%22%2Ca%3A%7Bl%3A%22Yes%22%7D%7D%2C1000013%3A%7Bt%3A0%2Cv%3A%22%22%2Ca%3A%7B%7D%7D%2C1000031%3A%7Bt%3A6%2Cv%3A%222%20Reopen%20in%20Current%22%2Ca%3A%7Bl%3A%22Reopen%20in%20Current%22%7D%7D%7D Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.stubs.GoatServlet setupSessionData GoatServlet: SessionID=zP7HJCzbFvBT0Tb2zXnfPW2ptB088X0RMz5NDZbx7jrpx160CQ0q!-887480436!1229075227242 Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.PERFORMANCE) : (Thread 172) com.remedy.arsys.stubs.BackchannelServlet doRequest Backchannel start: ServerRunProcess Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.backchannel.NDXServerRunProcess mapProperties --> ServerRunProcess Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.backchannel.NDXServerRunProcess mapProperties mServer=remedy002 Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.backchannel.NDXServerRunProcess mapProperties mAlName=RRC:SPO:RunReportbtn_SM2_100 Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.backchannel.NDXServerRunProcess mapProperties mActIdx=0 Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.backchannel.NDXServerRunProcess mapProperties mTs=0 Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.backchannel.NDXServerRunProcess mapProperties mFid=300636400 Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.backchannel.NDXServerRunProcess mapProperties mKeywordIds= Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.backchannel.NDXServerRunProcess mapProperties mKeywordVals= Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.backchannel.NDXServerRunProcess mapProperties mKeywordTypes= Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.backchannel.NDXServerRunProcess mapProperties mFieldIds=490001100,300144800 Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.backchannel.NDXServerRunProcess mapProperties mFieldVals=HPD:Help Desk,('1000000560' >= "12/5/2008 5:03:11 AM" AND '1000000560' <= "12/12/2008 5:03:11 AM") Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.backchannel.NDXServerRunProcess mapProperties mFieldTypes=4,4 Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.PERFORMANCE) : (Thread 172) com.remedy.arsys.stubs.BackchannelServlet doRequest Backchannel end: ServerRunProcess: Process: 170; Send: 0; Chars: 96 Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.stubs.GoatServlet postInternal GoatServlet: url=http://remedy-midtier.company.com:8003/arsys/BackChannel/?param=224%2FCompileExternalQualification%2F12%2Fremedy00213%2FRRC%3AReporting18%2FDefault%20Admin%20View12%2Fremedy00213%2FHPD%3AHelp%20Desk12%2F5%5C300636400%5C13%2F1%2F9%2F30063640071%2F1%2F66%2F1%5C4%5C3%5C1%5C1000000560%5C2%5C7%5C1228471391%5C4%5C5%5C1%5C1000000560%5C2%5C7%5C1229076191%5C5%2F1%2F1%2F4 Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.stubs.GoatServlet postInternal cookie=IP-Restriction-GUID=607c0594f3c7d518:2c110e4f:11e13224d6a:-7ed9; JSESSIONID=zP7HJCzbFvBT0Tb2zXnfPW2ptB088X0RMz5NDZbx7jrpx160CQ0q!-887480436; PopBlock=0; GKW=%7B14%3A%7Bn%3A%22LASTID%22%2Ct%3A6%2Cv%3Anull%7D%2C15%3A%7Bn%3A%22LASTCOUNT%22%2Ct%3A7%2Cv%3A1%7D%7D; GF=%7B1714200%3A%7Bt%3A4%2Cv%3A%22BMC.ASSET%22%2Ca%3A%7B%7D%7D%2C1714600%3A%7Bt%3A4%2Cv%3A%22BMC.ASSET%22%2Ca%3A%7B%7D%7D%2C1714700%3A%7Bt%3A4%2Cv%3A%22BMC.ASSET.SANDBOX%22%2Ca%3A%7B%7D%7D%2C1714800%3A%7Bt%3A6%2Cv%3A%221%20No%22%2Ca%3A%7Bl%3A%22No%22%7D%7D%2C1715200%3A%7Bt%3A6%2Cv%3A%220%20Yes%22%2Ca%3A%7Bl%3A%22Yes%22%7D%7D%2C1000013%3A%7Bt%3A0%2Cv%3A%22%22%2Ca%3A%7B%7D%7D%2C1000031%3A%7Bt%3A6%2Cv%3A%222%20Reopen%20in%20Current%22%2Ca%3A%7Bl%3A%22Reopen%20in%20Current%22%7D%7D%7D Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.stubs.GoatServlet setupSessionData GoatServlet: SessionID=zP7HJCzbFvBT0Tb2zXnfPW2ptB088X0RMz5NDZbx7jrpx160CQ0q!-887480436!1229075227242 Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.PERFORMANCE) : (Thread 172) com.remedy.arsys.stubs.BackchannelServlet doRequest Backchannel start: CompileExternalQualification Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.backchannel.NDXCompileExternalQualification mapProperties --> CompileExternalQualification Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.backchannel.NDXCompileExternalQualification mapProperties mCurrentServer=remedy002 Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.backchannel.NDXCompileExternalQualification mapProperties mCurrentSchema=RRC:Reporting Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.backchannel.NDXCompileExternalQualification mapProperties mCurrentVui=Default Admin View Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.backchannel.NDXCompileExternalQualification mapProperties mRemoteServer=remedy002 Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.backchannel.NDXCompileExternalQualification mapProperties mRemoteSchema=HPD:Help Desk Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.backchannel.NDXCompileExternalQualification mapProperties mQualification=5\300636400\ Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.backchannel.NDXCompileExternalQualification mapProperties mQualFieldIds=300636400 Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.backchannel.NDXCompileExternalQualification mapProperties mQualFieldValues=1\4\3\1\1000000560\2\7\1228471391\4\5\1\1000000560\2\7\1229076191\ Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.SERVLET) : (Thread 172) com.remedy.arsys.backchannel.NDXCompileExternalQualification mapProperties mQualFieldTypes=4 Dec 12, 2008 6:00:53 AM - FINE (com.remedy.log.PERFORMANCE) : (Thread 172) com.remedy.arsys.stubs.BackchannelServlet doRequest Backchannel end: CompileExternalQualification: Process: 49; Send: 0; Chars: 102 Dec 12, 2008 6:00:54 AM - FINE (com.remedy.log.INTERNAL) : (Thread 172) com.remedy.arsys.goat.GoatException <init> Throw Error - 9391 Dec 12, 2008 6:00:54 AM - FINE (com.remedy.log.INTERNAL) : (Thread 172) com.remedy.arsys.goat.GoatException <init> Throw Error - 9394 Dec 12, 2008 6:00:54 AM - FINE (com.remedy.log.INTERNAL) : (Thread 172) com.remedy.arsys.goat.GoatException <init> Caused due to Throw Error - 9391 Dec 12, 2008 6:00:54 AM - FINE (com.remedy.log.DVMODULE) : (Thread 172) com.remedy.arsys.plugincontainer.impl.PluginFactory getInstance Exception while trying to find plugin "Report" in the server "remedy002" Throw Error - 9394 Dec 12, 2008 6:00:56 AM - FINE (com.remedy.log.PERFORMANCE) : (Thread 172) com.remedy.arsys.reporting.ReportFactory processRequest Plugin Report time = 2008 ----------The Crystal log is huge, and the timestamp on this is off by unknown number of hours, so I'm pasting a small chunk only-------------- [Fri Dec 12 11:01:31 2008] 2572 1204 trace message: [UID=0;USID=0;ID=12 ] DoneCallbacks(id=12,type=19,bef=true,aft=true,clus=false, ucode=2) [Fri Dec 12 11:01:31 2008] 2572 1204 trace message: CObjectSS::SetObjects: End [Fri Dec 12 11:01:31 2008] 2572 1204 trace message: METADATARECORDTAG: CSessionMgr::Logon(userId:12, authmethod:secEnterprise, aps:crystal_server001.cms) [Fri Dec 12 11:01:31 2008] 2572 1060 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=861 [Fri Dec 12 11:01:31 2008] 2572 1060 trace message: new a session info for : secEnterprise:Administrator:861JNI5YXarYJcdOZSX [Fri Dec 12 11:01:31 2008] 2572 1060 trace message: ServantObMgr::add_service(861JNI5YXarYJcdOZSX): service(0x2137695800) of (IDL:OSCA/OSCAs/SessionBatch:3.0) added to the list. refcount of 3 [Fri Dec 12 11:01:32 2008] 2572 4112 trace message: ServantObMgr::add_service(861JNI5YXarYJcdOZSX): service(0x2132186228) of (IDL:OCA/OCAi/InfoStoreEx3:3.0) added to the list. refcount of 3 [Fri Dec 12 11:01:32 2008] 2572 752 trace message: METADATARECORDTAG: CInfoStoreSubsystem::Query(proc=Select SI_ID, CREATION_TIME From CI_INFOOBJECTS Where SI_NAME = 'remedy002-RRCSPORunReportbtnSM2100-1-Incident Details by Date Range',chk=false,srv=true,qry=false): Start [Fri Dec 12 11:01:32 2008] 2572 752 trace message: Query(): Using cached query [Fri Dec 12 11:01:32 2008] 2572 752 trace message: ODBCDatabaseSubSystem::GetObjectIds: Start: Where((((dbo.CMS_InfoObjects5.ObjName = CAST('-M-K)GC/-!`|<!`|<!`|@!A|Z"KK-MGEKQCK1GEKO+OCMA!`|@!`|>!`|<!`|<!A|Z!`|>!A|Z"9C-9/1...@{/1O)9...@{+y!@{/)o...@{k)C51!;{H!D' as VARBINARY(255)))) AND ((((dbo.CMS_InfoObjects5.SI_TABLE = 0)) AND ((dbo.CMS_InfoObjects5.SI_HIDDEN_OBJECT != 1)))))) OrderBy(dbo.CMS_InfoObjects5.ObjectID ASC ) [Fri Dec 12 11:01:32 2008] 2572 752 trace message: PushToDB: ODBCDatabaseSubSystem::GetObjectIds: End: Count(1), Table(dbo.CMS_InfoObjects5), Where((((dbo.CMS_InfoObjects5.ObjName = CAST('-M-K)GC/-!`|<!`|<!`|@!A|Z"KK-MGEKQCK1GEKO+OCMA!`|@!`|>!`|<!`|<!A|Z!`|>!A|Z"9C-9/1...@{/1O)9...@{+y!@{/)o...@{k)C51!;{H!D' as VARBINARY(255)))) AND ((((dbo.CMS_InfoObjects5.SI_TABLE = 0)) AND ((dbo.CMS_InfoObjects5.SI_HIDDEN_OBJECT != 1)))))), OrderBy(dbo.CMS_InfoObjects5.ObjectID ASC ) [Fri Dec 12 11:01:32 2008] 2572 752 trace message: CInfoStoreSubsystem::Query(proc=SELECT SI_ID, CREATION_TIME From CI_INFOOBJECTS Where SI_NAME = 'remedy002-RRCSPORunReportbtnSM2100-1-Incident Details by Date Range',chk=false,srv=true,qry=false): End [Fri Dec 12 11:01:32 2008] 2572 752 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=553 [Fri Dec 12 11:01:32 2008] 2572 752 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=553 [Fri Dec 12 11:01:32 2008] 2572 752 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=12 [Fri Dec 12 11:01:32 2008] 2572 752 trace message: Security::IsAllowed( U=12,R=3,Ob=553,Own=12,T=2, bLogonFromServer=0 ) : hard-coded result=true [Fri Dec 12 11:01:32 2008] 2572 752 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=553 [Fri Dec 12 11:01:32 2008] 2572 816 trace message: METADATARECORDTAG: CInfoStoreSubsystem::Query(proc=SELECT SI_MACHINE, SI_MACHINECHOICE, SI_CUID from CI_INFOOBJECTS, CI_APPOBJECTS WHERE SI_ID=553,chk=false,srv=true,qry=false): Start [Fri Dec 12 11:01:32 2008] 2572 816 trace message: Query(): Using cached query [Fri Dec 12 11:01:32 2008] 2572 816 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=553 [Fri Dec 12 11:01:32 2008] 2572 816 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=553 [Fri Dec 12 11:01:32 2008] 2572 816 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=553 [Fri Dec 12 11:01:32 2008] 2572 816 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=553 [Fri Dec 12 11:01:32 2008] 2572 816 trace message: CInfoStoreSubsystem::Query(proc=SELECT SI_MACHINE, SI_MACHINECHOICE, SI_CUID from CI_INFOOBJECTS, CI_APPOBJECTS WHERE SI_ID=553,chk=false,srv=true,qry=false): End [Fri Dec 12 11:01:32 2008] 2572 816 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=553 [Fri Dec 12 11:01:32 2008] 2572 816 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=553 [Fri Dec 12 11:01:32 2008] 2572 816 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=12 [Fri Dec 12 11:01:32 2008] 2572 816 trace message: Security::IsAllowed( U=12,R=3,Ob=553,Own=12,T=2, bLogonFromServer=0 ) : hard-coded result=true [Fri Dec 12 11:01:32 2008] 2572 816 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=553 [Fri Dec 12 11:01:33 2008] 2572 304 trace message: ServantObMgr::add_service(861JNI5YXarYJcdOZSX): service(0x2144442084) of (IDL:OCA/OCAi/InfoStoreEx3:3.0) added to the list. refcount of 3 [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: METADATARECORDTAG: CInfoStoreSubsystem::Query(proc=SELECT SI_SERVER_NAME,SI_SERVER_KIND,SI_SERVER_IS_ALIVE,SI_SERVER_IOR,SI_TIMESTAMP,SI_DISABLED FROM CI_SYSTEMOBJS WHERE (SI_PARENTID=16 AND SI_SERVER_KIND = 'rptappserver') ORDER BY SI_NAME ASC,chk=false,srv=true,qry=false): Start [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: Query(): Using cached query [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: ODBCDatabaseSubSystem::GetObjectIds: Start: Where((((((((dbo.CMS_InfoObjects5.ParentID = 16)))))) AND ((((dbo.CMS_InfoObjects5.SI_TABLE = 2)) AND ((dbo.CMS_InfoObjects5.SI_HIDDEN_OBJECT != 1)))))) OrderBy(dbo.CMS_InfoObjects5.ObjName ASC , dbo.CMS_InfoObjects5.ObjectID ASC ) [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: PushToDB: ODBCDatabaseSubSystem::GetObjectIds: End: Count(11), Table(dbo.CMS_InfoObjects5), Where((((((((dbo.CMS_InfoObjects5.ParentID = 16)))))) AND ((((dbo.CMS_InfoObjects5.SI_TABLE = 2)) AND ((dbo.CMS_InfoObjects5.SI_HIDDEN_OBJECT != 1)))))), OrderBy(dbo.CMS_InfoObjects5.ObjName ASC , dbo.CMS_InfoObjects5.ObjectID ASC ) [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=249 [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=249 [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=250 [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=251 [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=252 [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=253 [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=254 [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=255 [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=256 [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=257 [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=258 [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=259 [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: CInfoStoreSubsystem::Query(proc=SELECT SI_SERVER_NAME,SI_SERVER_KIND,SI_SERVER_IS_ALIVE,SI_SERVER_IOR,SI_TIMESTAMP,SI_DISABLED FROM CI_SYSTEMOBJS WHERE (SI_PARENTID=16 AND SI_SERVER_KIND = 'rptappserver') ORDER BY SI_NAME ASC,chk=false,srv=true,qry=false): End [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=251 [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=251 [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=251 [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=12 [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: Security::IsAllowed( U=12,R=3,Ob=251,Own=10,T=16, bLogonFromServer=0 ) : hard-coded result=true [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: CObjectSS::GetObjectInternal: Object was found in cache. obj ID=251 [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: [UID=0;USID=0;ID=251] ** checking crystal_server001.RAS.rptappserver server is active. [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: CServerWatcher::IsKnownToBeDown: Doing a direct call to decide if 251 is down. Waiting for up to 2 seconds [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: [UID=0;USID=0;ID=251] ** checking crystal_server001.RAS.rptappserver server is active. [Fri Dec 12 11:01:33 2008] 2572 1276 trace message: [UID=0;USID=0;ID=251] ** double check crystal_server001.RAS.rptappserver server is active [Fri Dec 12 11:01:33 2008] 2572 1332 trace message: ServantObMgr::remove_service(861JNI5YXarYJcdOZSX) before: service(0x2144442084) of (IDL:OCA/OCAi/InfoStoreEx3:3.0) has refcount of 3 [Fri Dec 12 11:01:33 2008] 2572 1332 trace message: ServantObMgr::remove_service(861JNI5YXarYJcdOZSX) after: service(0x2144442084) of (IDL:OCA/OCAi/InfoStoreEx3:3.0) has refcount of 2. cleanup succeeded=true [Fri Dec 12 11:01:33 2008] 2572 2032 trace message: ServantObMgr::add_service(BYPASSSEC_HANDLE): service(0x2144442084) of (IDL:OCA/OCAi/InfoStoreEx3:3.0) added to the list. refcount of 3 [Fri Dec 12 11:01:33 2008] 2572 1368 trace message: METADATARECORDTAG: CInfoStoreSubsystem::Query(proc=,chk=false,srv=false,qry=false): Start [Fri Dec 12 11:01:33 2008] 2572 1368 trace message: Query(): Using cached query [Fri Dec 12 11:01:33 2008] 2572 4132 trace message: METADATARECORDTAG: CInfoStoreSubsystem::Query(proc=SELECT SI_SERVER_NAME,SI_CLUSTER_NAME,SI_SERVER_IS_ALIVE,SI_SERVER_IOR,SI_SYSTEM_INFO FROM CI_SYSTEMOBJS WHERE (SI_PARENTID = 16 AND SI_SERVER_KIND = 'aps') OR SI_ID = 4,chk=false,srv=false,qry=false): Start [Fri Dec 12 11:01:33 2008] 2572 4132 trace message: Query(): Using cached query _______________________________________________________________________________ UNSUBSCRIBE or access ARSlist Archives at www.arslist.org Platinum Sponsor: www.rmsportal.com ARSlist: "Where the Answers Are"

