More info, if it helps

==> APISQL.log.2018-01-29 <==

Adding transactional method 'initServerConfiguration' with attribute: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; '',-com.bmc.arsys.domain.etc.ARException

<SQL > <TID: 0000000077> <RPC ID: 0000000000> <Queue: Init      > <Client-RPC: 10       > <USER: ARSERVER                                     > <Overlay-Group: 1         > /* Tue Jan 30 2018 15:06:02.3730 */ BEGIN TRANSACTION

<SQL > <TID: 0000000077> <RPC ID: 0000000000> <Queue: Init      > <Client-RPC: 10       > <USER: ARSERVER                                     > <Overlay-Group: 1         > /* Tue Jan 30 2018 15:06:02.3740 */ ROLLBACK TRANSACTION

==> arerror.log <==

Tue Jan 30 15:06:02.377 2018 Tue Jan 30 15:06:02.376 2018 Error initializing AR Server: ERROR (8552): Message not in catalog; Message number = 8552

Also, the unique constraint errors doesn't make sense, since the installer or import is supposed to overwrite the existing metdata , instead of erroring out on duplicate rows (if any)

Thanks Mark!!

We literally corrected this last night.  Added Configuration-Name: to ar.conf and a different error pops up now & AR server is still not up.  We were back to the same error (from the previous install attempt)

<MNTR> <TNAME: Thread-3 > <INFO > <ProcessMonitor$1 > < ProcessMonitor.java:263 > /* Thu Feb 01 18 14:45:33.0196 */ org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'serverInitializer' defined in URL [bundleentry://162.fwk66233253/spring-context/application/domain/init_context.xml]: Invocation of init method failed; nested exception is ERROR (240): Message not in catalog; Message number = 240; @ : <1521>

Per the error message description, it suggests columns of length > 255 in a sort field.

ARERR 240   - Fields that have lengths over 255 bytes (including diary fields, unlimited length character fields, and the Status History field) cannot be specified as sort fields

Based on the prior install experience - Before the install, We did make sure that all such references have been deleted.

SQL> select a.schemaid, a.fieldid, b.MAXLENGTH from schema_sort a, field_char b where a.schemaid=b.schemaid and a.fieldid=b.fieldid and b.MAXLENGTH > 255;

no rows selected

SQL> select a.schemaid, a.fieldid, b.MAXLENGTH from schema_list_fields a, field_char b where a.schemaid=b.schemaid and a.fieldid=b.fieldid and b.MAXLENGTH > 255;

no rows selected

And there is no schema with 1521 schemaid

SQL> select name from arschema where schemaId=1521;

no rows selected

SQL> select name from arschema where schemaid in (select schemaid from field where fieldid=1521);

AR System Currency Codes

AR System Currency Label Catalog

AR System Currency Localized Labels

select maxlength from field_char where fieldid=1521;

         5

         5

         5

@Andreas Mitterdorfer - Will attach the latest logs in a short while.

LJ LongWing  - Nice catch!!

There are no sort fields of length 0, but there are some list fields, that too from system forms

SQL> select a.schemaid, a.fieldid, b.MAXLENGTH from schema_sort a, field_char b where a.schemaid=b.schemaid and a.fieldid=b.fieldid and b.MAXLENGTH = 0;

no rows selected

SQL>  select a.schemaid, a.fieldid, b.MAXLENGTH from schema_list_fields a, field_char b where a.schemaid=b.schemaid and a.fieldid=b.fieldid and b.MAXLENGTH = 0;

       976       6010          0

       985       6010          0

       977       6010          0

       978       6010          0

       979       6010          0

       980       6010          0

       982       6010          0

       981       6010          0

       983       6010          0

       984       6010          0

         1        156          0

      1224       6010          0

       974       8086          0

SQL> select name from arschema where schemaid in (select a.schemaid from schema_list_fields a, field_char b where a.schemaid=b.schemaid and a.fieldid=b.fieldid and b.MAXLENGTH = 0);

AR System Web Services Registry Query

AR System Log: ALL

AR System Log: API

AR System Log: Alert

AR System Log: Archive

AR System Log: Escalation

AR System Log: Filter

AR System Log: FullText Index

AR System Log: SQL

AR System Log: Server Group

AR System Log: Thread

AR System Log: User

AR System Message Catalog

13 rows selected.

I will try to restart the server, by deleting these references - if it helps.

Attaching the logs from recent restart attempt (after cleaning up more metadata references)

Thanks for Your suggestions  Andreas Mitterdorfer Ravindrakumar Rodge .

Apologies for the confusion.  Based on the interactions with BMC support, we tried few things to see if the server comes up

Earlier the start ups were failing with unique constraint violation errors.  Server tries to import the system forms, instead of overwriting it tries to INSERT new rows in field table for existing columns and gets the below error and (after 7-8 minutes)  fails with an initialization error. Neither We nor BMC have an explanation for this behavior.     

An example here.  Please note that this just for one of the forms and this error repeats for all almost all the system/install form imports (50+ forms) as part of the start up.

<SQL > <TID: 0000000077> <RPC ID: 0000000000> <Queue: Init > <Client-RPC: 10 > <USER: ARSERVER > <Overlay-Group: 0 > /* Fri Jan 05 2018 13:03:31.9780 */ INSERT INTO field (fieldId, schemaId, overlayGroup, changeDiary, createMode, defaultValue, fbOption, fieldType, fOption, helpText, lastChanged, fieldName, objProp, overlayProp, owner, recordId, resolvedfieldId, resolvedName, smObjProp, timestamp, datatype) VALUES (1, 3, '0', NULL, 2, NULL, 0, 1, 3, NULL, 'jbliss', 'Request ID', NULL, 0, 'ARSERVER', 0, 1, 'Request ID', NULL, 1157149850, 4)
<SQL > <TID: 0000000077> <RPC ID: 0000000000> <Queue: Init > <Client-RPC: 10 > <USER: ARSERVER > <Overlay-Group: 0 > /* Fri Jan 05 2018 13:03:32.0530 */ SELECT 1 FROM DUAL
<SQL > <TID: 0000000077> <RPC ID: 0000000000> <Queue: Init > <Client-RPC: 10 > <USER: ARSERVER > <Overlay-Group: 0 > /* Fri Jan 05 2018 13:03:32.0860 */ OK
<SQL > <TID: 0000000077> <RPC ID: 0000000000> <Queue: Init > <Client-RPC: 10 > <USER: ARSERVER > <Overlay-Group: 0 > /* Fri Jan 05 2018 13:03:32.0920 */ org.springframework.orm.jpa.JpaSystemException: Exception [EclipseLink-4002] (Eclipse Persistence Services - 2.4.2.v20130514-5956486): org.eclipse.persistence.exceptions.DatabaseException
Internal Exception: java.sql.SQLIntegrityConstraintViolationException: ORA-00001: unique constraint (ARADMIN.SYS_C00226017) violated


ARADMIN.SYS_C00226017 is composed of the following columns

SQL> SELECT column_name, position  FROM all_cons_columns WHERE constraint_name = 'SYS_C00226017';

SCHEMAID         1
FIELDID          2
OVERLAYGROUP     3

To isolate the root cause and in an attempt to get the server up

(1) BMC suggested to remove/rename the system & install forms so that installer can't find them to import.   Hence arerror.log reports since it can't find the def files, while the SQL log wont have any trace since the actual import did NOT happen

(2) Since we have so many group records, we suspected that could be another reason for the server to choke, so we cleaned up all custom group and just retained the bare minimum.   This caused the server to fail fast on start up ( instead of waiting for 7-8 mins)

(3) We ran the DB check and gave the logs ( Running the database consistency checker - Documentation for BMC Remedy Action Request System 9.1 - BMC Documentation  ) and BMC did not find any red flags. 

(4) Currently, start up logging is enabled as well  (arserver.jar -t -s)  , to get any clue for the start up failures.

And thanks for the hint on bundle cache, this is the error in see in the latest log under bundle cache

!ENTRY com.bmc.arsys.restapi 4 0 2018-02-02 10:40:21.886

!MESSAGE FrameworkEvent ERROR

!STACK 0

java.lang.NullPointerException

        at com.bmc.arsys.restapi.resourcemanager.RestfulConnector.removeResource(RestfulConnector.java:85)

        at com.bmc.arsys.restapi.resourcemanager.ResourceTracker.removedService(ResourceTracker.java:57)

        at org.osgi.util.tracker.ServiceTracker$Tracked.customizerRemoved(ServiceTracker.java:956)

        at org.osgi.util.tracker.ServiceTracker$Tracked.customizerRemoved(ServiceTracker.java:1)

        at org.osgi.util.tracker.AbstractTracked.untrack(AbstractTracked.java:341)

        at org.osgi.util.tracker.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:902)

        at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:107)

        at org.eclipse.osgi.framework.internal.core.BundleContextImpl.dispatchEvent(BundleContextImpl.java:861)

        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230)

        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148)

        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:819)

        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:771)

        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.unregister(ServiceRegistrationImpl.java:225)

        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.unregisterServices(ServiceRegistry.java:635)

        at org.eclipse.osgi.framework.internal.core.BundleContextImpl.close(BundleContextImpl.java:88)

        at org.eclipse.osgi.framework.internal.core.BundleHost.stopWorker(BundleHost.java:514)

        at org.eclipse.osgi.framework.internal.core.AbstractBundle.suspend(AbstractBundle.java:566)

        at org.eclipse.osgi.framework.internal.core.Framework.suspendBundle(Framework.java:1206)

        at org.eclipse.osgi.framework.internal.core.StartLevelManager.decFWSL(StartLevelManager.java:592)

        at org.eclipse.osgi.framework.internal.core.StartLevelManager.doSetStartLevel(StartLevelManager.java:257)

        at org.eclipse.osgi.framework.internal.core.StartLevelManager.shutdown(StartLevelManager.java:215)

        at org.eclipse.osgi.framework.internal.core.InternalSystemBundle.suspend(InternalSystemBundle.java:284)

        at org.eclipse.osgi.framework.internal.core.Framework.shutdown(Framework.java:692)

        at org.eclipse.osgi.framework.internal.core.Framework.close(Framework.java:600)

        at org.eclipse.osgi.framework.internal.core.InternalSystemBundle$1.run(InternalSystemBundle.java:261)

        at java.lang.Thread.run(Thread.java:748)

I will try to clear the bundle cache and rerun the db checker and see if i can find any more info.

On a different note, we have a weird confusion,    our DB character set is UTF8 and we store and some unicode chars as well,  but BMC thinks that we are non-unicode ( to decide which dbchecker has to be run, since unicode and nonunicode has different versions of checker).   Any inputs? 

ar.conf --->   Db-Character-Set: UTF-8

DB  -->   SQL> SELECT PARAMETER, VALUE FROM v$nls_parameters WHERE parameter LIKE '%CHARACTERSET';

NLS_CHARACTERSET
UTF8

NLS_NCHAR_CHARACTERSET
AL16UTF16

Just want to make sure that we are running the correct version of DB checker.

Restart after clearing bundle-cache ended up with same error  

Mon Feb 05 16:43:03.825 2018 Mon Feb 05 16:43:03.825 2018 Error initializing AR Server: ERROR (240): Message not in catalog; Message number = 240; @ : <1521>

One weird observation is -  i see the following SQL in the logs without any error.

```

<SQL > <TID: 0000000077> <RPC ID: 0000000000> <Queue: Init      > <Client-RPC: 10       > <USER: ARSERVER                                     > <Overlay-Group: 1         > /* Mon Feb 05 2018 16:39:52.9800 */ SELECT dbVersion, actlinkId, adminExtId, associationId, containerId, filterId, schemaId, imageId, charMenuId, prevDbVersion, relGenState, taskId, useSHA256 FROM control

<SQL > <TID: 0000000077> <RPC ID: 0000000000> <Queue: Init      > <Client-RPC: 10       > <USER: ARSERVER                                     > <Overlay-Group: 1         > /* Mon Feb 05 2018 16:39:52.9850 */ OK

```

But the control table doesn't have some of these columns (associationId, useSHA256 ) & there are no rollback statements as well - just to rule out that the control may have been altered but rolled back later.

from SQLPLUS

```

SQL>  SELECT dbVersion, actlinkId, adminExtId, associationId, containerId, filterId, schemaId, imageId, charMenuId, prevDbVersion, relGenState, taskId, useSHA256 FROM control;

                                                                                                                                                   *

ERROR at line 1:

ORA-00904: "USESHA256": invalid identifier

SQL> desc control;

Name                                      Null?    Type

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

DBVERSION                                 NOT NULL NUMBER(15)

SCHEMAID                                  NOT NULL NUMBER(15)

FILTERID                                  NOT NULL NUMBER(15)

SERVERID                                  NOT NULL NUMBER(15)

CONTAINERID                               NOT NULL NUMBER(15)

ACTLINKID                                 NOT NULL NUMBER(15)

ADMINEXTID                                NOT NULL NUMBER(15)

CHARMENUID                                NOT NULL NUMBER(15)

DBUPDATE                                           NUMBER(15)

IMAGEID                                   NOT NULL NUMBER(15)

RELGENSTATE                                        NUMBER(15)

TASKID                                    NOT NULL NUMBER(15)

INSTALLSTATE                              NOT NULL NUMBER(15)

INSTALLHOST                                        VARCHAR2(66)

```