Remedy fetches information from it's data dictionary (e.g., field_disp_prop, field, etc.), then processes it in chunks of 100, 500, or 1000. So if you have a table field_dispprop that has 120k records and 500 records are processed at a time, 15 seconds per chunk, you end up with a start time that totals 3600 seconds (for that part of the startup).
If you add a -t parameter to arserverd in the armonitor.conf file, a special startup log file is created. The log file will look something like this: Jul 09 2007 18:29:06.6577 <Startup> <TID:3086968512> Set up thread control block with key = 0 Jul 09 2007 18:29:06.6582 <Startup> <TID:3086968512> Initialize thread local storage block Jul 09 2007 18:29:06.6583 <Startup> <TID:3086968512> Initialize mutiple-byte environment Jul 09 2007 18:29:06.6585 <Startup> <TID:3086968512> InstallDir = /u01/arsystem/arsdev Jul 09 2007 18:29:06.6587 <Startup> <TID:3086968512> Initialize Server utility Jul 09 2007 18:29:06.6599 <Startup> <TID:3086968512> Initialize License Library Jul 09 2007 18:29:06.6602 <Startup> <TID:3086968512> LicenseFilename = /etc/arsystem/arsdev/arsystem.lic Jul 09 2007 18:29:06.6603 <Startup> <TID:3086968512> Initialize Language setting and locale Jul 09 2007 18:29:06.6610 <Startup> <TID:3086968512> Initialize the Decimal Math libray Jul 09 2007 18:29:06.6610 <Startup> <TID:3086968512> Open shared catalog Jul 09 2007 18:29:06.6648 <Startup> <TID:3086968512> Load encryption shared library Jul 09 2007 18:29:06.6653 <Startup> <TID:3086968512> Load encryption static functions Jul 09 2007 18:29:06.6654 <Startup> <TID:3086968512> Initialize default configuration information Jul 09 2007 18:29:06.6654 <Startup> <TID:3086968512> Create Mutexes Jul 09 2007 18:29:06.6655 <Startup> <TID:3086968512> Initialize parse environment Jul 09 2007 18:29:06.6657 <Startup> <TID:3086968512> Initialize date time information Jul 09 2007 18:29:06.6659 <Startup> <TID:3086968512> Initialize notification strings Jul 09 2007 18:29:06.6659 <Startup> <TID:3086968512> Initialize RPC queue type strings Jul 09 2007 18:29:06.6660 <Startup> <TID:3086968512> Initialize filter strings Jul 09 2007 18:29:06.6662 <Startup> <TID:3086968512> Initialize escalation strings Jul 09 2007 18:29:06.6662 <Startup> <TID:3086968512> Load system configuration file Jul 09 2007 18:29:06.6669 <Startup> <TID:3086968512> arsCodeSet=windows-1252[0] arDbCodeSet=windows-1252[0] Jul 09 2007 18:29:06.6670 <Startup> <TID:3086968512> Initialize pending lists Jul 09 2007 18:29:06.6671 <Startup> <TID:3086968512> Create cache read write lock Jul 09 2007 18:29:06.6671 <Startup> <TID:3086968512> Create full text status read write lock Jul 09 2007 18:29:06.6672 <Startup> <TID:3086968512> Initialize fork proxy Jul 09 2007 18:29:06.6672 <Startup> <TID:3086968512> Check licensing Jul 09 2007 18:29:06.6693 <Startup> <TID:3086968512> Initialize user cache Jul 09 2007 18:29:06.6707 <Startup> <TID:3086968512> Open log file Jul 09 2007 18:29:06.6745 <Startup> <TID:3086968512> Initialize XML parser Jul 09 2007 18:29:06.6782 <Startup> <TID:3086968512> Initialize thread list Jul 09 2007 18:29:06.6784 <Startup> <TID:3086968512> Check multiple servers Jul 09 2007 18:29:06.6787 <Startup> <TID:3086968512> Initialize dead thread list Jul 09 2007 18:29:06.6790 <Startup> <TID:3086968512> Initialize timed calls Jul 09 2007 18:29:06.6792 <Startup> <TID:3086968512> CreateRPCQueue(min=1, max=1, rpc=390600) Jul 09 2007 18:29:06.6793 <Startup> <TID:3086968512> Await cache ready... Jul 09 2007 18:29:06.8988 <Startup> <TID:0030571424> InitializeServerCache: LoadInitialSchemaInfo Begin Jul 09 2007 18:29:11.7241 <Startup> <TID:0030571424> Begin LoadDisplayInfoList Jul 09 2007 18:29:25.6076 <Startup> <TID:0030571424> LoadDisplayInfoList: 500 rows Jul 09 2007 18:29:42.7008 <Startup> <TID:0030571424> LoadDisplayInfoList: 1000 rows If you then review the sql that is sent to the db while the server is unavailable, you will see this statement, followed by silence: SELECT schemaId,fieldId,vuiId,propShort,propLong FROM field_dispprop ORDER BY 1 ASC, 2 ASC, 3 ASC What is happening here is that arserverd fetches the field display property info, then processes it 500 records at a time. Depending on the size of your server (number of forms, views, fields, etc), there may be a couple of sql statements that are followed by a pause. What is happening internally is anyone's guess; I would guess that they are processing X rows at a time to operate within certain memory constraints, and 'maybe' in a horribly inefficient way. Some things are for certain though; (1) a lot of data is transferred from the db to the arserver. My test server, which has 3293 rows in field_dispprop (pretty much a base arserver install) sends 411K of data over the wire. (2) the field_dispprop data is processed in chunks of 500 (at least on Linux). Axton Grams On 7/9/07, Andrew Hicox <[EMAIL PROTECTED]> wrote:
** Hello everyone: I've managed to get through the (incredibly flawed) solaris 10 arsystem 7 install. This is 7.0.01 patch 2. I'm using oracle 10G client library with a remote database on an oracle 10 Rapid Application Cluster. So ... now the server is INCREDIBLY slow to start. The server is configured to run on a TCP port (10000). When I issue the 'arsystem start' command, I get the usual output on the console indicating that the server has started. However, the TCP port is not listening, and of course, no clients can connect to the server. If I wait (approx 7 minutes), I will see the following output on the console: (ARNOTE 0) Server indicates that it's up. (ARNOTE 0) ARMonitor child process (pid:29595) started. ./arplugin Action Request System(R) Fork Daemon Version 7.0.01 patch 002 200704021644 Copyright (c) 2000 - 2006 BMC Software, Inc. All rights reserved. Action Request System(R) Plug-In Server Version 7.0.01 patch 002 200704021644 Copyright (c) 2001 - 2006 BMC Software, Inc. All rights reserved. Loaded Web Services plugin properly After the above, the TCP port opens up and clients can connect, and it seems to work well enough. What I presume is happening here is that arserverd must issue some sort of indication that it's completed start up so that arforkd and armonitor can do their thing and start listeners and plugins, and that arserverd is for some reason taking on average 7 minutes to do that. I can't manage to get ANY sort of logging during the 7 minutes of mystery. is there some way to figgure out what the heck is going on durring this period of time (is it timing out DNS? is the db slow to respond? is it waiting on disk access? what is it doing?). We have an identical set up in our dev lab, with the exception that the database server is not a RAC and it's installed on the same machine. The startup is quite snappy on that setup. There don't appear to be any issues with network latency between the remedy server and the RAC. Anyone ever seen this before? Any suggestions? thanks, Andrew
_______________________________________________________________________________ UNSUBSCRIBE or access ARSlist Archives at www.arslist.org ARSlist:"Where the Answers Are"
