Hi folks,
I have an ITSM 703 p3 environment, freshly installed.
I am trying to patch it up to ITSM 703, p7, but can not get the patch
installer to go much far.
I have a VPN connection from my Windows PC to corporate network.
I have a ssh session (putty) from my PC to the ARS box (solaris). I
start the patch installer on the ars box on the putty window.
This installer has a GUI, so the though the installer is running on
the ars box (solaris), through a X windows session, the display comes
to my PC. I'm using Xming on my PC.
The installer's GUI gets to my PC ok, and I answer all the prompts.
Before the installation gets too far, I get an "alert" popup saying:
"Internal Error. Unable to build patch summary. Installation can not continue".
On clicking Ok, the installation bravely tries to continue, as if
unaware that there was any error.
After the screen that asks me to confirm my answers and clicking next,
it seems to do something for a min or two.
Then it says:
"An internal error has caused the installer to not complete successfully"
And the installation stops.
ARS 7.1 p2
SunoS 5.10
JRE 1.5.0 12_b04
Oracle 10g on a separate machine
Any ideas?
This is what logs show [ beware that I have log sections and my
comments that will keep you reading for a while :) ] -
------(1)-------------------------------------------------
I see in "bmc_installer.log" that, installer fired the API driver
program, and it errored out. See towards the end of this snippet.
--------------------
INFO: LOG EVENT {Description=[Command
array],Detail=[/tmp/915356.tmp/RIK/solaris/rik appinfo -x remserver001
-t 1050 -u Demo -l /tmp/915356.tmp -n defaultRikLogFile -f
IM00C04FA081BAUcxmQg[8XkEQmwAA -i DataLanguage -s 0 -o get -B -L -C]}
Aug 18, 2008 3:23:45 PM com.bmc.smbu.install.common.rule.engine.rik.RikCommand
INFO: LOG EVENT {Description=[Execution result
[resultType=COMPLETED,exitCode=12]]}
Aug 18, 2008 3:23:45 PM com.bmc.smbu.install.common.rule.engine.rik.RikCommand
INFO: LOG EVENT {Description=[Execution result
[resultType=COMPLETED,exitCode=12]]}
Aug 18, 2008 3:32:48 PM com.bmc.smbu.install.common.rule.engine.rik.RikCommand
INFO: LOG EVENT {Description=[Executing],Detail=[RIK command]}
Aug 18, 2008 3:32:48 PM com.bmc.smbu.install.common.rule.engine.rik.RikCommand
INFO: LOG EVENT {Description=[Command
array],Detail=[/tmp/915356.tmp/RIK/solaris/rik getsvrinfo -x
remserver001 -t 1050 -u Demo -l /tmp/915356.tmp -n defaultRikLogFile
-s 0 -o 89 -B -L -c]}
Aug 18, 2008 3:32:48 PM com.bmc.smbu.install.common.rule.engine.rik.RikCommand
INFO: LOG EVENT {Description=[Execution result
[resultType=COMPLETED,exitCode=0]]}
Aug 18, 2008 3:32:48 PM com.bmc.smbu.install.common.rule.engine.rik.RikCommand
INFO: LOG EVENT {Description=[Execution result
[resultType=COMPLETED,exitCode=0]]}
Aug 18, 2008 3:32:48 PM com.bmc.smbu.install.common.rule.engine.rik.RikCommand
INFO: LOG EVENT {Description=[Completed executing],Detail=[RIK command]}
Aug 18, 2008 3:33:31 PM
com.bmc.smbu.install.common.rule.engine.driver.DriverCommand
INFO: LOG EVENT {Description=[Executing Driver command]}
Aug 18, 2008 3:33:31 PM
com.bmc.smbu.install.common.rule.engine.driver.DriverCommand
INFO: LOG EVENT {Description=[Command array
/tmp/915356.tmp/RIK/solaris/driver -s remserver001 -u Demo -x
/tmp/915356.tmp/devCache.drm]}
Aug 18, 2008 3:33:31 PM
com.bmc.smbu.install.common.rule.engine.driver.DriverCommand
INFO: LOG EVENT {Description=[Execution result
[resultType=COMPLETED,exitCode=0]]}
Aug 18, 2008 3:33:31 PM
com.bmc.smbu.install.common.rule.engine.driver.DriverCommand
INFO: LOG EVENT {Description=[Execution result
[resultType=COMPLETED,exitCode=0]]}
Aug 18, 2008 3:34:46 PM
com.bmc.smbu.install.patch.installer.ia.ResetLogLocationAction
INFO: LOG EVENT {Description=[Build ID = 080129-102650],Detail=[]}
Aug 18, 2008 3:34:52 PM com.bmc.smbu.install.patch.installer.ia.CloseLogsAction
INFO: LOG EVENT {Description=[An internal error has caused the
installer to not complete successfully.],Detail=[]}
Aug 18, 2008 3:34:52 PM com.bmc.smbu.install.patch.installer.ia.CloseLogsAction
INFO: LOG EVENT {Description=[Installation completed in 23 minutes],Detail=[]}
----(2)------------------------------------------------------------------------------
Notice that the erring line was running "driver" program and having
it run the script on devCache.drm file. Contents of devCache.drm are:
init
gsi
1
208
term
cout
q
This sequence of commands makes the api driver program check the "Dev
Cache" mode on the server. Installer is perhaps trying to see if it's
on or not, so that it can turn it on if necessary.
----(3)-------------------------------------------------------------------------
Luckily, there's also a "devcache.log" file that shows what the script
was trying to do, basically what I said in (2) above, and you see that
it hit ARERR 90, i.e. couldn't connect to the AR server:
AR System API Driver
Active Link Escalation Filter Entry Entry
----------- ---------- ------ ----- -----
get (gal) get (ges) get (gf) get (ge) merge (me)
set (sal) set (ses) set (sf) set (se) stats (stat)
create (cal) create (ces) create (cf) create (ce) get BLOB (geb)
delete (dal) delete (des) delete (df) delete (de) getmult (gme)
getlist(glal) getlist(gles) getlist(glf) getlist (gle) getlistblk(gleb)
getmult(gmal) getmult(gmes) getmult(gmf) service (sve) getlistw/f(glewf)
Char Menu Schema License Schema Field VUI
--------- ------ ------- ------------ ---
get (gc) get (gs) val (vl) get (gsf) get (gv)
set (sc) set (ss) valmult(vml) set (ssf) set (sv)
create (cc) create (cs) create (cl) create (csf) create (cv)
delete (dc) delete (ds) delete (dl) delete (dsf) delete (dv)
getlist(glc) getlist(gls) getlist(gll) getlist (glsf) getlist(glsv)
getmult(gmc) gls w/a(glsa) import (iml) getmult (gmsf) getmult(gmv)
expand (ec) getmult(gms) export (exl) delmult (dmsf)
exp ssm(essm) getlist ext(glxsc) getmult ext cands(gmxfc)
Container Alert Info Control/Logging Thread/Timer
--------- ----- ---- --------------- ------------
get (gco) create (cae) get svr (gsi) record (rec) launch (lt)
set (sco) register (rfa) set svr (ssi) stop rec (srec) launch wait (lwt)
create (cco) deregistr(dfa) get FT (gft) open out (oout) release wait(rwt)
delete (dco) gla user (glau) set FT (sft) close out(cout) sleep (st)
getlist(glco) get count(gac) get stat(gss) execute (ex) random sleep(rst)
getmult(gmco) decode (dcam) srvr chr(gscs)bgn loop (bl) msec sleep (msst)
clnt chr(gccs)end loop (el)
Init/Term Encode/Decode Misc Lists Misc Misc
--------- ------------- ---------- ---- ----
init (init) enquery(ecqal) server(svr) ver user (ver) get file (gfl)
term (term) dequery(dcqal) group (glg) export (exp/f)set file (sfl)
help (h, ?) enassig(ecasn) user (glu) import (imp) get errmsg (gem)
exit (e, q) deassig(dcasn) sql (glsql) unimport (unimp)set logging(slog)
login (log) echstry(echst) sql al(sqlal) exec proc(proc) close conn (cnc)
dr ver (dver) ecdiary(ecdia) role (glr) exec p al(epal) valid cache(vfc)
bgntran(bbet) ecdate (ecdat) load qual(lqs) signal (sig)
endtran(ebet) dcdate (dcdat) set port (ssp) getmult ep (gmep)
imper user (imusr)
XML Session Config Localized Val App States Currency Ratio
------------- -------------- ------------- ---------- --------------
get (xmlge) get conf(gsc) get (glv) get (gas) getmult sets(gmcrs)
set (xmlse) set conf(ssc) getmult(gmlv) set (sas) get ratio (gcr)
create(xmlce) getlist (glas)
parse (xmlpd)
Command: INITIALIZATION
ARInitialization results
ReturnCode: OK
Status List : 0 items
Command: GET SERVER INFO
Number of server info operations (0): Operation (1-247) (1):
ARGetServerInfo results
ReturnCode: ERROR
Status List : 1 items
Status Struct :
Message type : ERROR
Message number : 90
Message: Cannot establish a network connection to the AR System server
Appended: remserver001 (0) : RPC: Program not registered
Command: TERMINATION
ARTermination results
ReturnCode: OK
Status List : 0 items
Command: **** Output to stdout; cannot close stdout file
Command:
Command:
------(4)--------------------------------
The "defaultRikLogFile.log" shows that the last thing that ran
successfully was the "rik getsvrinfo" command in the previous log, the
one right before the one that errored out. There's no log for the
actual error.
However, looking at this and other things installer was doing in the
logs above, we know that AR Server was up and responding right up to
the point before it hit this error.
[Mon Aug 18 15:32:48.785] rikMain- Log files created
[Mon Aug 18 15:32:48.786] rikMain- Version Info
rik utility 7.0 Drop 1; Mig 7.0; AR System API 7.0.01 Patch 005 200709130909;
[Mon Aug 18 15:32:48.786] rikMain- Subcommand is: getsvrinfo
[Mon Aug 18 15:32:48.786] rikMain- Following will show parameters as
received by rik
[Mon Aug 18 15:32:48.801] VerifyControl- AR User is valid
[Mon Aug 18 15:32:48.801] GetServerInfo- About to make an API call to
obtain Server info
[Mon Aug 18 15:32:48.803] GetServerInfo- Server param
AR_SERVER_INFO_VERSION(4) is: 7.1.00 Patch 002 200802011900
[Mon Aug 18 15:32:48.803] rikMain- Calling the subcommand: getsvrinfo
[Mon Aug 18 15:32:48.803] GetServerInfo- About to make an API call to
obtain Server info
[Mon Aug 18 15:32:48.805] GetServerInfo- Server param
AR_SERVER_INFO_SERVER_NAME(89) is: remserver001
[Mon Aug 18 15:32:48.805] rikMain- Writing server info param (89)
value (remserver001) to file
[Mon Aug 18 15:32:48.807] rikMain- ARTermination complete
[Mon Aug 18 15:32:48.807] rikMain- Returning 0 for command getsvrinfo
[Mon Aug 18 15:32:48.807] rikMain- Exit function. Closing global log
files and cleaning up
---------
Now, why is AR Server suddently not responding at this point in the
installation?
Random occurance?
But I tried the install many times and it errors out similarly at the
same point. I haven't analyzed other logs as thoroughly, but I am
guessing exactly the same sequnce of events leading to the same error.
I will double check on this.
Between the time the driver program started to run and finally errored
out ( 3:33:31 PM - 3:34:52 ), I see in SQL and API logs that an
entry(ies?) were being processed in Application Pending form, trying
up the Admin queue.
This shouldn't cause timeout, because we have many threads (for
example 2-6 for fast and list, separate RPC port for reconciliaiton
engine, nobody using the system).
<API > <TID: 0000000025> <RPC ID: 0000014653> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:03.7536 */+GLE ARGetListEntry --
schema Application Pending from Application Command Dispatcher
(protocol 13) at IP address 20.20.20.20
<SQL > <TID: 0000000025> <RPC ID: 0000014653> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:03.7548 */SELECT T8.C1 FROM T8 WHERE
(T8.C8 = 'Dispatch') ORDER BY 1 ASC
<SQL > <TID: 0000000025> <RPC ID: 0000014653> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:03.7589 */OK
<API > <TID: 0000000025> <RPC ID: 0000014653> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:03.7591 */-GLE OK
<API > <TID: 0000000025> <RPC ID: 0000014654> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:03.7599 */+GES ARGetEntryStatistics
-- schema Application Pending from Application Command Dispatcher
(protocol 13) at IP address 20.20.20.20
<SQL > <TID: 0000000025> <RPC ID: 0000014654> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:03.7605 */SELECT C8,COUNT(*) FROM T8
WHERE (T8.C7 = 0) GROUP BY C8 ORDER BY C8
<SQL > <TID: 0000000025> <RPC ID: 0000014654> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:03.7629 */OK
<API > <TID: 0000000025> <RPC ID: 0000014654> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:03.7720 */-GES OK
<API > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.0018 */+GLEWF
ARGetListEntryWithFields -- schema OBJSTR:Class from Unidentified
Client (protocol 12) at IP address
<SQL > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.0030 */SELECT T318.C1 FROM T318
WHERE (1 = 1) ORDER BY 1 ASC
<SQL > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.0063 */OK
<API > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.0133 */-GLEWF OK
<API > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.0140 */+GLEWF
ARGetListEntryWithFields -- schema OBJSTR:Class from Unidentified
Client (protocol 12) at IP address
<SQL > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.0151 */SELECT T318.C1,C6 FROM T318
WHERE ((T318.C400123100 = '0') AND (T318.C6 > 1218910011)) ORDER BY 1
ASC
<SQL > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.0180 */OK
<API > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.0182 */-GLEWF OK
<API > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.0184 */+GLEWF
ARGetListEntryWithFields -- schema
BMC.CORE.CONFIG:BMC_CIToConfigBaseRelationship from Unidentified
Client (protocol 12) at IP address
<SQL > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.0192 */SELECT T384.C1 FROM T384
WHERE (T384.C400079600 = 'BMC_FEDERATEDINTERFACELINK') ORDER BY 1 ASC
<SQL > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.0217 */OK
<API > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.0235 */-GLEWF OK
<API > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.0237 */+GLEWF
ARGetListEntryWithFields -- schema
BMC.CORE.CONFIG:BMC_CIToConfigBaseRelationship from Unidentified
Client (protocol 12) at IP address
<SQL > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.0246 */SELECT T384.C1,C6 FROM T384
WHERE (T384.C6 > 1219032188) ORDER BY 1 ASC
<SQL > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.0269 */OK
<API > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.0271 */-GLEWF OK
<API > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.0273 */+GLEWF
ARGetListEntryWithFields -- schema
BMC.CORE.CONFIG:BMC_ConfigBaseElement from Unidentified Client
(protocol 12) at IP address
<SQL > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.0281 */SELECT T342.C1 FROM T342
WHERE (T342.C400079600 = 'BMC_DATASET') ORDER BY 1 ASC
<SQL > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.0307 */OK
<API > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.0321 */-GLEWF OK
<API > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.0323 */+GLEWF
ARGetListEntryWithFields -- schema
BMC.CORE.CONFIG:BMC_ConfigBaseElement from Unidentified Client
(protocol 12) at IP address
<SQL > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.0332 */SELECT T342.C1,C6 FROM T342
WHERE (T342.C6 > 1218917699) ORDER BY 1 ASC
<SQL > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.0359 */OK
<API > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.0383 */-GLEWF OK
<API > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9202 */+GLEWF
ARGetListEntryWithFields -- schema BMC.CORE.CONFIG:BMC_Dataset from
Unidentified Client (protocol 12) at IP address
<SQL > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9218 */SELECT
T405.C1,C530007500,C530007600,C530007700,C530007800,C200000020,C530008000,C6
FROM T405 WHERE (1 = 1) ORDER BY 1 ASC
<SQL > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9261 */OK
<API > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9281 */-GLEWF OK
<API > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9285 */+GLEWF
ARGetListEntryWithFields -- schema OBJSTR:Class from Unidentified
Client (protocol 12) at IP address
<SQL > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9293 */SELECT T318.C1 FROM T318
WHERE (1 = 1) ORDER BY 1 ASC
<SQL > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9314 */OK
<API > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9378 */-GLEWF OK
<API > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9384 */+GLEWF
ARGetListEntryWithFields -- schema OBJSTR:Class from Unidentified
Client (protocol 12) at IP address
<SQL > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9396 */SELECT T318.C1,C6 FROM T318
WHERE ((T318.C400123100 = '0') AND (T318.C6 > 1218910011)) ORDER BY 1
ASC
<SQL > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9423 */OK
<API > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9425 */-GLEWF OK
<API > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9426 */+GLEWF
ARGetListEntryWithFields -- schema
BMC.CORE.CONFIG:BMC_CIToConfigBaseRelationship from Unidentified
Client (protocol 12) at IP address
<SQL > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9435 */SELECT T384.C1 FROM T384
WHERE (T384.C400079600 = 'BMC_FEDERATEDINTERFACELINK') ORDER BY 1 ASC
<SQL > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9459 */OK
<API > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9479 */-GLEWF OK
<API > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9481 */+GLEWF
ARGetListEntryWithFields -- schema
BMC.CORE.CONFIG:BMC_CIToConfigBaseRelationship from Unidentified
Client (protocol 12) at IP address
<SQL > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9489 */SELECT T384.C1,C6 FROM T384
WHERE (T384.C6 > 1219032188) ORDER BY 1 ASC
<SQL > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9513 */OK
<API > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9515 */-GLEWF OK
<API > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9516 */+GLEWF
ARGetListEntryWithFields -- schema
BMC.CORE.CONFIG:BMC_ConfigBaseElement from Unidentified Client
(protocol 12) at IP address
<SQL > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9525 */SELECT T342.C1 FROM T342
WHERE (T342.C400079600 = 'BMC_DATASET') ORDER BY 1 ASC
<SQL > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9551 */OK
<API > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9567 */-GLEWF OK
<API > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9568 */+GLEWF
ARGetListEntryWithFields -- schema
BMC.CORE.CONFIG:BMC_ConfigBaseElement from Unidentified Client
(protocol 12) at IP address
<SQL > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9577 */SELECT T342.C1,C6 FROM T342
WHERE (T342.C6 > 1218917699) ORDER BY 1 ASC
<SQL > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9605 */OK
<API > <TID: 0000000004> <RPC ID: 0000000000> <Queue: Admin >
<Client-RPC: 999999 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:33:32.9630 */-GLEWF OK
<API > <TID: 0000000006> <RPC ID: 0000014655> <Queue: Fast >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7125 */+GSI ARGetServerInfo --
as user Remedy Application Service from Unidentified Client (protocol
13) at IP address 20.20.20.20
<API > <TID: 0000000006> <RPC ID: 0000014655> <Queue: Fast >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7127 */-GSI OK
<API > <TID: 0000000025> <RPC ID: 0000014656> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7137 */+EXEC ARExecuteProcess --
Application-Command Dispatch Register-Category -s"Assignment Engine"
-tAE-CHK-CONFIG -o"araps_ae.lck"
-l"31:remserver001.company.com:/usr/ar/arserver/confRemedyAssignEngSigUsr1Event"
from Unidentified Client (protocol 13) at IP address 20.20.20.20
<SQL > <TID: 0000000025> <RPC ID: 0000014656> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7147 */UPDATE arschema SET nextId =
nextId + 1 WHERE schemaId = 8
<SQL > <TID: 0000000025> <RPC ID: 0000014656> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7174 */OK
<SQL > <TID: 0000000025> <RPC ID: 0000014656> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7175 */SELECT nextId FROM arschema
WHERE schemaId = 8
<SQL > <TID: 0000000025> <RPC ID: 0000014656> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7197 */OK
<SQL > <TID: 0000000025> <RPC ID: 0000014656> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7200 */INSERT INTO T8
(C2,C7,C502,C503,C8,C501,C504,C508,C3,C5,C6,C1) VALUES ('Remedy
Application Service',0,'Assignment
Engine',NULL,'Dispatch','Register-Category','AE-CHK-CONFIG','araps_ae.lck',1219088043,'Remedy
Application Service',1219088043,'000000000001767')
<SQL > <TID: 0000000025> <RPC ID: 0000014656> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7225 */OK
<SQL > <TID: 0000000025> <RPC ID: 0000014656> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7227 */UPDATE T8 SET C509 =
EMPTY_CLOB() WHERE C1 = '000000000001767'
<SQL > <TID: 0000000025> <RPC ID: 0000014656> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7248 */OK
<SQL > <TID: 0000000025> <RPC ID: 0000014656> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7249 */SELECT C509 FROM T8 WHERE C1
= '000000000001767' FOR UPDATE
<SQL > <TID: 0000000025> <RPC ID: 0000014656> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7271 */OK
<SQL > <TID: 0000000025> <RPC ID: 0000014656> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7272 */Set LOB into the above row
...
<SQL > <TID: 0000000025> <RPC ID: 0000014656> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7585 */OK
<SQL > <TID: 0000000025> <RPC ID: 0000014656> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7588 */COMMIT WORK
<API > <TID: 0000000025> <RPC ID: 0000014656> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7708 */-EXEC OK
<API > <TID: 0000000006> <RPC ID: 0000014657> <Queue: Fast >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7716 */+GSI ARGetServerInfo --
as user Remedy Application Service from Application Command Dispatcher
(protocol 13) at IP address 20.20.20.20
<API > <TID: 0000000006> <RPC ID: 0000014657> <Queue: Fast >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7717 */-GSI OK
<API > <TID: 0000000025> <RPC ID: 0000014658> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7718 */+EXEC ARExecuteProcess --
Application-Command Dispatch Register-Category -s"Assignment Engine"
-tAE-ASSIGN -o"araps_ae.lck"
-l"31:remserver001.company.com:/usr/ar/arserver/confRemedyAssignEngSigEvent"
from Unidentified Client (protocol 13) at IP address 20.20.20.20
<API > <TID: 0000000010> <RPC ID: 0000014659> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7726 */+GLE ARGetListEntry --
schema Application Pending from Application Command Dispatcher
(protocol 13) at IP address 20.20.20.20
<SQL > <TID: 0000000025> <RPC ID: 0000014658> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7728 */UPDATE arschema SET nextId =
nextId + 1 WHERE schemaId = 8
<SQL > <TID: 0000000010> <RPC ID: 0000014659> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7736 */SELECT T8.C1 FROM T8 WHERE
(T8.C8 = 'Dispatch') ORDER BY 1 ASC
<SQL > <TID: 0000000025> <RPC ID: 0000014658> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7750 */OK
<SQL > <TID: 0000000025> <RPC ID: 0000014658> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7751 */SELECT nextId FROM arschema
WHERE schemaId = 8
<SQL > <TID: 0000000010> <RPC ID: 0000014659> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7762 */OK
<SQL > <TID: 0000000025> <RPC ID: 0000014658> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7772 */OK
<API > <TID: 0000000010> <RPC ID: 0000014659> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7774 */-GLE OK
<SQL > <TID: 0000000025> <RPC ID: 0000014658> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7775 */INSERT INTO T8
(C2,C7,C502,C503,C8,C501,C504,C508,C3,C5,C6,C1) VALUES ('Remedy
Application Service',0,'Assignment
Engine',NULL,'Dispatch','Register-Category','AE-ASSIGN','araps_ae.lck',1219088043,'Remedy
Application Service',1219088043,'000000000001768')
<API > <TID: 0000000006> <RPC ID: 0000014660> <Queue: Fast >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7783 */+GE ARGetEntry -- schema
Application Pending entryId 000000000001767 from Application Command
Dispatcher (protocol 13) at IP address 20.20.20.20
<SQL > <TID: 0000000006> <RPC ID: 0000014660> <Queue: Fast >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7792 */SELECT
C1,C2,C3,C4,C5,C6,C7,C8,0,C501,C502,C503,C504,C505,C506,C507,C508,C509
FROM T8 WHERE C1 = '000000000001767'
<SQL > <TID: 0000000025> <RPC ID: 0000014658> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7801 */OK
<SQL > <TID: 0000000025> <RPC ID: 0000014658> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7803 */UPDATE T8 SET C509 =
EMPTY_CLOB() WHERE C1 = '000000000001768'
<SQL > <TID: 0000000025> <RPC ID: 0000014658> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7823 */OK
<SQL > <TID: 0000000025> <RPC ID: 0000014658> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7824 */SELECT C509 FROM T8 WHERE C1
= '000000000001768' FOR UPDATE
<SQL > <TID: 0000000006> <RPC ID: 0000014660> <Queue: Fast >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7832 */OK
<SQL > <TID: 0000000025> <RPC ID: 0000014658> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7846 */OK
<SQL > <TID: 0000000025> <RPC ID: 0000014658> <Queue: List >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7847 */Set LOB into the above row
...
<FLTR> <TID: 0000000006> <RPC ID: 0000014660> <Queue: Fast >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7916 */ Start filter processing
(phase 1) -- Operation - GET on Application Pending - 000000000001767
<FLTR> <TID: 0000000006> <RPC ID: 0000014660> <Queue: Fast >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7917 */ End of filter
processing (phase 1) -- Operation - GET on Application Pending -
000000000001767
<API > <TID: 0000000006> <RPC ID: 0000014660> <Queue: Fast >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7922 */-GE OK
<API > <TID: 0000000006> <RPC ID: 0000014661> <Queue: Fast >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7931 */+DE ARDeleteEntry --
schema Application Pending entry 000000000001767 from Application
Command Dispatcher (protocol 13) at IP address 20.20.20.20
<FLTR> <TID: 0000000006> <RPC ID: 0000014661> <Queue: Fast >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7941 */ Start filter processing
(phase 1) -- Operation - DELETE on Application Pending -
000000000001767
<FLTR> <TID: 0000000006> <RPC ID: 0000014661> <Queue: Fast >
<Client-RPC: 390620 > <USER: Remedy Application Service
> /* Mon Aug 18 2008 15:34:03.7942 */ End of filter
processing (phase 1) -- Operation - DELETE on Application Pending -
000000000001767
----
So I "analyzed" the logs, but can't come up with any root cause. What
do you think?
_______________________________________________________________________________
UNSUBSCRIBE or access ARSlist Archives at www.arslist.org
Platinum Sponsor: www.rmsportal.com ARSlist: "Where the Answers Are"
