ACSLS - ACSLS service is not coming online

(Doc ID 1931333.1)

Last updated on FEBRUARY 27, 2017

Applies to:

Sun StorageTek Auto Cartridge Sys Lib SW (ACSLS) - Version 8.3 to 8.4 [Release 8.0]
Information in this document applies to any platform.

Symptoms

ACSLS is not coming online:
--------------------------------
bash-3.2$ acsss status
Copyright 1989, 2013 Oracle and/or its affiliates. All Rights Reserved.

  weblogic: online
  rmi-registry: online
  surrogate: online
  acsdb: online
  acsls: offline* <----------------------------------


acsss_event.log does not show any obvious error message:
----------------------------------------------------------------------------
ss_main: Initiation started, Oracle ACSLS (Automated Cartridge System Library
Software) 8.3.0

2014-09-23 20:15:04 ACSSA[0]:
1439 N sa_demux.c 1 296
Server system recovery started.

2014-09-23 20:15:04 CSI[0]:
935 N csi_mt_init.c 1 162
ONC RPC: csi_mt_init(): Initiation Started

2014-09-23 20:15:04 CSI[0]:
964 N csi_rpcuinit.c 1 236
ONC RPC: csi_rpcuinit(): Unmapped previously registered RPC service.

2014-09-23 20:15:04 CSI[0]:
964 N csi_rpcuinit.c 1 236
ONC RPC: csi_rpcuinit(): Unmapped previously registered RPC service.

2014-09-23 20:15:04 CSI[0]:
964 N csi_rpctinit.c 1 371
ONC RPC: csi_rpctinit(): Unmapped previously registered RPC service.

2014-09-23 20:15:04 CSI[0]:
964 N csi_rpctinit.c 1 371
ONC RPC: csi_rpctinit(): Unmapped previously registered RPC service.

2014-09-23 20:15:04 CSI[0]:
938 N csi_mt_init.c 1 281
ONC RPC: csi_mt_init(): Initiation Completed

2014-09-23 20:15:05 ACSLM[0]:
37 N lm_msg_hdlr.c 1 1071
lm_msg_hdlr: LMU READY received for ACS Identifier 0

2014-09-23 20:15:05 ACSSA[0]:
1434 N sa_demux.c 1 296
ACS 0: Online.

2014-09-23 20:15:06 ACSLH[0]:
2551 I Co_status.C 2 1356
Checking for LSM 0,0 status ...

2014-09-23 20:15:07 storage server[0]:
351 N ss_main.c 4 810
ss_main: Initiation completed

2014-09-23 20:15:23 ACSLH[0]:
2552 I Co_status.C 2 3079
LSM 0,0 status Ready, on-line,door closed.
  hand-0 operative, empty.

2014-09-23 20:15:26 ACSLH[0]:
2551 I Co_status.C 2 1356
Checking for LSM 0,0 status ...

2014-09-23 20:15:43 ACSLH[0]:
2552 I Co_status.C 2 3079
LSM 0,0 status Ready, on-line,door closed.
  hand-0 operative, empty.

                                                           <<<<<< Just a 6-minute gap between attempting to vary the LSM and terminating

2014-09-23 20:21:56 storage server[0]:
356 N ss_main.c 4 1129
ss_main: Termination invoked, STATUS_TERMINATED

2014-09-23 20:21:56 ACSSA[0]:
1458 N sa_demux.c 1 296
Server system terminated.

2014-09-23 20:21:56 CSI[0]:
969 N csi_mt_shutdown.c 1 141
ONC RPC: csi_mt_shutdown(): Termination Started

2014-09-23 20:21:56 CSI[0]:
970 N csi_mt_shutdown.c 1 188
ONC RPC: csi_mt_shutdown(): Termination Completed

2014-09-23 20:22:02 acsss_ctl.sh:
SMF startup time limit: 7:39




ACSLH trace shows the process caught in a loop of Catalog Subpanel requests from location 00,80,00 to 00,00,00
--------------------------------------------------------------------------------------------------
2014-09-23 20:15:45 ACS 0: PSPAPI-CTWTLD1:50001 send 01081 PART-000 TRANSACTION
  Priority: 25 01072 REQUEST CAP Status LSM: 00 CAP: 06
 2014-09-23 20:15:45 ACS 0: PSPAPI-CTWTLD1:50001 recv 01081 PART-000 ACKNOWLEDGEMENT ACK OK. Single_LMU Single_LMU Single_LMU/Standby Reserved Byte: 1 Compat23
 2014-09-23 20:15:45 ACS 0: PSPAPI-CTWTLD1:50001 recv 01303 PART-000 TRANSACTION
  Priority: 25 01072 FINAL RESPONSE CAP Status ZE010100001011026000025001301
 2014-09-23 20:15:45 ACS 0: PSPAPI-CTWTLD1:50001 send 01303 PART-000 ACKNOWLEDGEMENT ACK OK. Single_LMU Single_LMU Single_LMU/Standby Compat22
 2014-09-23 20:15:45 ACS 0: PSPAPI-CTWTLD1:50001 send 01082 PART-000 TRANSACTION
  Priority: 25 01073 REQUEST Catalog Subpanel in LSM 10 from 00,80,00 to 00,00,00                  <<<---
 2014-09-23 20:15:45 ACS 0: PSPAPI-CTWTLD1:50001 recv 01082 PART-000 ACKNOWLEDGEMENT ACK OK. Single_LMU Single_LMU Single_LMU/Standby Reserved Byte: 1 Compat23
 2014-09-23 20:15:45 ACS 0: PSPAPI-CTWTLD1:50001 recv 01304 PART-000 TRANSACTION
  Priority: 25 01073 FINAL RESPONSE Catalog response #00, starting at 08,00,00 :
 2014-09-23 20:15:45 ACS 0: PSPAPI-CTWTLD1:50001 send 01304 PART-000 ACKNOWLEDGEMENT ACK OK. Single_LMU Single_LMU Single_LMU/Standby Compat22
 2014-09-23 20:15:45 ACS 0: PSPAPI-CTWTLD1:50001 send 01083 PART-000 TRANSACTION
  Priority: 25 01074 REQUEST Catalog Subpanel in LSM 10 from 00,80,00 to 00,00,00                  <<<---
 2014-09-23 20:15:45 ACS 0: PSPAPI-CTWTLD1:50001 recv 01083 PART-000 ACKNOWLEDGEMENT ACK OK. Single_LMU Single_LMU Single_LMU/Standby Reserved Byte: 1 Compat23
 2014-09-23 20:15:46 ACS 0: PSPAPI-CTWTLD1:50001 recv 01305 PART-000 TRANSACTION
  Priority: 25 01074 FINAL RESPONSE Catalog response #00, starting at 08,00,00 :
 2014-09-23 20:15:46 ACS 0: PSPAPI-CTWTLD1:50001 send 01305 PART-000 ACKNOWLEDGEMENT ACK OK. Single_LMU Single_LMU Single_LMU/Standby Compat22
 2014-09-23 20:15:46 ACS 0: PSPAPI-CTWTLD1:50001 send 01084 PART-000 TRANSACTION
  Priority: 25 01075 REQUEST Catalog Subpanel in LSM 10 from 00,80,00 to 00,00,00                 <<<---
..
..



Earlier, start up and audit error messages refer to the same cell location of 0,0,8,0,0 as "inaccessible" or "not specified" :
--------------------------------------------
2014-09-09 18:32:52 ACSLH[0]:
2552 I Co_status.C 2 3079
LSM 0,0 status Ready, on-line,door closed.
  hand-0 operative, empty.

2014-09-09 18:32:55 VARY[2]:
1292 N va_itc_reco.c 3 556
va_itc_recovery: Volume L50610: Found in recovery cell: recovered

2014-09-09 18:32:55 ACSLH[0]:
2378 N Co_ProcessResponses.C 1 1374
ACS: 0; LC/LMU error: Co_4400:st_parse_error:
Error: 0113 - LMU parameter error: No cell at the specified address
Request: Move
Volser: L50610, media domain: L, media type: 5
Source: Recov Cell 0,0,0
Destination: Cell 0,0,8,0,0

2014-09-09 18:32:55 VARY[2]:
546 N cl_log_lh_er.c 1 99
cl_sm_response: LH error type = LH_ERR_ADDR_INACCESSIBLE

2014-09-09 18:32:55 ACSSA[2]:
1422 N sa_demux.c 1 296
Library configuration error.

2014-09-09 18:32:56 RECOVERY[0]:
90 N re_vary_lsm.c 2 298
re_vary_lsm: Vary response count mismatch: expected 1, got 0

2014-09-09 18:32:56 ACSSA[0]:
1437 N sa_demux.c 1 296
Server system recovery failed.


-----
2014-09-15 13:16:01 AUDIT[80]:
187 N au_initiate.c 1 143
au_initiate: audit started

2014-09-15 13:16:06 AUDIT[80]:
60 N au_cel_reco.c 1 1969
au_cel_reconcile(1): Cell 0, 0, 8, 0, 0 - Undefined stimulus =
STATUS_VOLUME_BEING_RECOVERED, state = 2, table = inaccessible

2014-09-15 13:16:06 AUDIT[80]:
239 N au_log_error.c 1 116
au_pnl_reconcile(1): subpanel 0, 0, 8, 0, 0,51, 5, au_cel_reconcile()
unexpected status = STATUS_PROCESS_FAILURE

2014-09-15 13:16:06 AUDIT[80]:
239 N au_log_error.c 1 116
au_lsm_reconcile(1): subpanel 0, 0, 8, 0, 0,51, 5, au_pnl_reconcile()
unexpected status = STATUS_PROCESS_FAILURE

2014-09-15 13:16:06 AUDIT[80]:
239 N au_log_error.c 1 116
au_reconcile(1): LSM 0, 0, au_lsm_reconcile() unexpected status =
STATUS_PROCESS_FAILURE

Changes

New SL3000 and ACSLS installation

Cause

Sign In with your My Oracle Support account

Don't have a My Oracle Support account? Click to get started

My Oracle Support provides customers with access to over a
Million Knowledge Articles and hundreds of Community platforms