Unsolved
This post is more than 5 years old
1 Message
0
1045
August 30th, 2012 15:00
Centera CBRM Issue
Hello all,
Running JCASScript I am able to query and see all the clips, as well as store clips on a file. I am using Centera Backup and Recovery Module 2.2, running CentraStar 4.1.0-3343-0-0. But when using Centera Backup and Recovery Module with NetBackup 6.5/7.5(I have tried both and am at 7.5 currently) to backup data I receive the follow error in NetBackup:
8/30/2012 2:39:20 PM - Info ndmpagent(pid=5184) cafreps102.ca.pdl.com: L: Querying Centera (Wed Nov 01 09:10:00 2006 to Wed Nov 01 09:20:00 2006)
8/30/2012 2:39:50 PM - Info ndmpagent(pid=5184) cafreps102.ca.pdl.com: L: Querying Centera (Wed Nov 01 09:10:00 2006 to Wed Nov 01 09:20:00 2006)
8/30/2012 2:40:20 PM - Info ndmpagent(pid=5184) cafreps102.ca.pdl.com: L: Querying Centera (Wed Nov 01 09:10:00 2006 to Wed Nov 01 09:20:00 2006)
8/30/2012 2:40:50 PM - Info ndmpagent(pid=5184) cafreps102.ca.pdl.com: L: Querying Centera (Wed Nov 01 09:10:00 2006 to Wed Nov 01 09:20:00 2006)
8/30/2012 2:41:20 PM - Info ndmpagent(pid=5184) cafreps102.ca.pdl.com: L: Querying Centera (Wed Nov 01 09:10:00 2006 to Wed Nov 01 09:20:00 2006)
8/30/2012 2:41:51 PM - Info ndmpagent(pid=5184) cafreps102.ca.pdl.com: L: Querying Centera (Wed Nov 01 09:10:00 2006 to Wed Nov 01 09:20:00 2006)
8/30/2012 2:41:51 PM - Info ndmpagent(pid=5184) cafreps102.ca.pdl.com: E: ******************************************************************
8/30/2012 2:41:51 PM - Info ndmpagent(pid=5184) cafreps102.ca.pdl.com: E: ------ E R R O R -------
8/30/2012 2:41:52 PM - Info ndmpagent(pid=5184) cafreps102.ca.pdl.com: E: Max Query Retry Reached, Aborting Backup.
8/30/2012 2:41:52 PM - Info ndmpagent(pid=5184) cafreps102.ca.pdl.com: E: ******************************************************************
I have changed the date several times, to include short spans of time and large spans of time (i.e. 1990-August2012, etc) and this does not help. All nodes are online, with 3 disk failures. However, this issue only came up after switching NetBackup from an older server to a new one. But after the failed attempts, I tried to go back to the old server to run the job and it failed even over there. The PEA file is functioning correctly and logging in to the Centera ok, and has all of the appropriate permissions. I have tried raising this issue with EMC, but since I have Gen3 Centera and CBRM, I have received little help since both are end of support life. I was hoping someone may have some insight or ideas? Below are the SDK logs and ndmp logs.If different parts of the log will help let me know.
CBRM Log:
NET_VERSION type=integer value=3 NET_MESSAGEID type=integer value=53 AUTH_CR_OPCODE type=integer value=3
1346362974913 2012-08-30 21:42:54.913 [DEBUG] 3196 [TRANSACTION] Auth Chall Ack cafreps102/39/AUTH
1346362974913 2012-08-30 21:42:54.913 [DEBUG] 3196 [TRANSACTION] Query Request cafreps102/37/QUERY
1346362974913 2012-08-30 21:42:54.913 [DEBUG] 3196 [PACKET] send SmartPacket
NET_SYSTEMID type=string value=cafreps102
NET_TRANSACTIONID type=string value=cafreps102/37/QUERY
NET_VERSION type=integer value=3 HPP_CLIENT_VERSION type=integer value=131328 NET_MESSAGEID type=integer value=48 HPP_VERSION type=integer value=1 HPP_CONTROL type=integer value=0 QUERY_OPCODE type=integer value=1 QUERY_START_TIMESTAMP type=long value=-1563937216 QUERY_STOP_TIMESTAMP type=long value=-1563337216 QUERY_QUERY_STRING type=string value=
1346362974913 2012-08-30 21:42:54.913 [DEBUG] 3196 [API] End FPPoolQuery_Open(-,-)
1346362974913 2012-08-30 21:42:54.913 [DEBUG] 3196 [API] Start FPPool_GetLastError()
1346362974913 2012-08-30 21:42:54.913 [DEBUG] 3196 [API] End FPPool_GetLastError()
1346362974913 2012-08-30 21:42:54.913 [DEBUG] 3196 [API] Start FPQueryResult_Close(-)
1346362974913 2012-08-30 21:42:54.913 [DEBUG] 3196 [API] End FPQueryResult_Close(-)
1346362974913 2012-08-30 21:42:54.913 [DEBUG] 3196 [API] Start FPPoolQuery_FetchResult(-,-1)
1346362974913 2012-08-30 21:42:54.913 [DEBUG] 3196 [TRANSACTION] Query Reply cafreps102/37/QUERY
1346362975023 2012-08-30 21:42:55.23 [DEBUG] 3196 [EXCEPTION] In 'O:\viewstore\falloj_U05_DEV_FARO_INT_V3.0.414\CTA_SDK\filepoollib\src_win32\natives\lib\FPSmartPacket.cpp' at line 251: Exception
error=-10152
syserror=0
message=field id=107 missing
trace=FPSmartPacket.setFetchCursor(107)
1346362975023 2012-08-30 21:42:55.23 [DEBUG] 3196 [EXCEPTION] In 'O:\viewstore\falloj_U05_DEV_FARO_INT_V3.0.414\CTA_SDK\filepoollib\src_win32\natives\lib\FPSmartPacket.cpp' at line 251: Exception
error=-10152
syserror=0
message=field id=105 missing
trace=FPSmartPacket.setFetchCursor(105)
1346362975023 2012-08-30 21:42:55.23 [DEBUG] 3196 [EXCEPTION] In 'O:\viewstore\falloj_U05_DEV_FARO_INT_V3.0.414\CTA_SDK\filepoollib\src_win32\natives\lib\FPSmartPacket.cpp' at line 251: Exception
error=-10152
syserror=0
message=field id=113 missing
trace=FPSmartPacket.setFetchCursor(113)
1346362975023 2012-08-30 21:42:55.23 [DEBUG] 3196 [API] End FPPoolQuery_FetchResult(-,-1)
1346362975023 2012-08-30 21:42:55.23 [DEBUG] 3196 [API] Start FPPool_GetLastError()
1346362975023 2012-08-30 21:42:55.23 [DEBUG] 3196 [API] End FPPool_GetLastError()
1346362975023 2012-08-30 21:42:55.23 [DEBUG] 3196 [API] Start FPQueryResult_GetResultCode(-)
1346362975023 2012-08-30 21:42:55.23 [DEBUG] 3196 [API] End FPQueryResult_GetResultCode(-) -> 99
1346362975023 2012-08-30 21:42:55.23 [DEBUG] 3196 [API] Start FPQueryResult_GetClipID(-,-)
1346362975023 2012-08-30 21:42:55.23 [DEBUG] 3196 [API] End FPQueryResult_GetClipID(-,)
1346362975023 2012-08-30 21:42:55.23 [DEBUG] 3196 [API] Start FPQueryResult_GetTimestamp(-)
1346362975023 2012-08-30 21:42:55.23 [DEBUG] 3196 [API] End FPQueryResult_GetTimestamp(-) -> 1162372800000
1346362975023 2012-08-30 21:42:55.23 [DEBUG] 3196 [API] Start FPQueryResult_Close(-)
1346362975023 2012-08-30 21:42:55.23 [DEBUG] 3196 [API] End FPQueryResult_Close(-)
1346362975023 2012-08-30 21:42:55.23 [DEBUG] 3196 [API] Start FPPoolQuery_FetchResult(-,-1)
1346362975023 2012-08-30 21:42:55.23 [DEBUG] 3196 [TRANSACTION] Query Reply cafreps102/37/QUERY
NDMP logs:
L00 [3804](:CenteraStorageSubSystem.cpp:1207) 08/30/12 14:40:53> Connected to the Centera (10.27.138.23?C:\cbrm.pea)
Lui [3804](:CenteraStorageSubSystem.cpp:1224) 08/30/12 14:40:53> Centera Time: 2012.08.31 13:25:42 GMT
Lui [3804](:CenteraStorageSubSystem.cpp:1235) 08/30/12 14:40:53> Centera FPLibrary Version: 3.0.414
Lui [3804](:CenteraStorageSubSystem.cpp:1252) 08/30/12 14:40:53> Centera poolInfoVersion = 2
Lui [3804](:CenteraStorageSubSystem.cpp:1254) 08/30/12 14:40:53> Centera capacity = 20731402907648
Lui [3804](:CenteraStorageSubSystem.cpp:1255) 08/30/12 14:40:53> Centera freeSpace = 15920519901352
Lui [3804](:CenteraStorageSubSystem.cpp:1260) 08/30/12 14:40:53> Centera clusterID = 43c53c0c-1dd2-11b2-8c16-ee7cad82116b
Lui [3804](:CenteraStorageSubSystem.cpp:1261) 08/30/12 14:40:53> Centera clusterName = CAFRE-B2C0-CENTERA-1
Lui [3804](:CenteraStorageSubSystem.cpp:1262) 08/30/12 14:40:53> Centera version = 4.1.0-3343-0-0
Lui [3804](:CenteraStorageSubSystem.cpp:1263) 08/30/12 14:40:53> Centera replicaAddress =
Lui [3804](:CenteraStorageSubSystem.cpp:1449) 08/30/12 14:40:53> Centera read Allowed: true
Lui [3804](:CenteraStorageSubSystem.cpp:1449) 08/30/12 14:40:53> Centera write Allowed: false
Lui [3804](:CenteraStorageSubSystem.cpp:1449) 08/30/12 14:40:53> Centera clip-enumeration Allowed: true
L00 [3804](:CenteraStorageSubSystem.cpp:531) 08/30/12 14:40:53> BEGIN_DATE specified, Performing Time Range Backup with specified END_DATE.
L00 [3804](:CenteraStorageSubSystem.cpp:1143) 08/30/12 14:40:53> Querying Centera (Wed Nov 01 09:10:00 2006 to Wed Nov 01 09:20:00 2006)
Lus [3804] (:Backup.cpp:269) 08/30/12 14:40:53> requestedThreadCount = 1
Ldi [3804] (:Thread.cpp:264) 08/30/12 14:40:53> SaveStream thread starting.
Ldi [3804] (:TapeBlockQueue.cpp:212) 08/30/12 14:40:53> TapeBlockQueue 0: Wait On condQueueNotEmpty
Lui [3196](:CenteraStorageSubSystem.cpp:730) 08/30/12 14:40:53> Query In Progress
Lui [3196](:CenteraStorageSubSystem.cpp:748) 08/30/12 14:40:53> Query Result Code 1 (retry 1 of 5)
Lui [3196](:CenteraStorageSubSystem.cpp:1132) 08/30/12 14:40:53> Closing Last Query Expression
Lui [3196](:CenteraStorageSubSystem.cpp:1137) 08/30/12 14:40:53> Closing Last Query
Ldd [2616](ndmp:NdmpConnection.cpp:298) 08/30/12 14:41:02> NdmpConnection::processRequests
Lds [2616](ndmp:NdmpConnection.cpp:922) 08/30/12 14:41:02> NdmpConnection::processMessages: reply_expected:FALSE
Ldd [2616](ndmp:NdmpConnection.cpp:775) 08/30/12 14:41:02> NdmpConnection::recvMsg
Ldd [2616](ndmp:NdmpConnection.cpp:667) 08/30/12 14:41:02> NdmpConnection::readIt: len:4000
Ldd [2616](ndmp:NdmpConnection.cpp:1010) 08/30/12 14:41:02> NdmpConnection::processMessages: received request: 0x400
Lds [2616](ndmp:NdmpdDataGetStateMH.cpp:97) 08/30/12 14:41:02> NdmpdDataGetStateMH:
Ldd [2616](ndmp:NdmpConnection.cpp:476) 08/30/12 14:41:02> NdmpConnection::sendReply: message:0x400
Ldd [2616](ndmp:NdmpConnection.cpp:728) 08/30/12 14:41:02> NdmpConnection::writeIt: len:104
Lds [2616](ndmp:NdmpConnection.cpp:535) 08/30/12 14:41:02> NdmpConnection::freeMessage: message:0x400
Ldd [2616](ndmp:NdmpConnection.cpp:1023) 08/30/12 14:41:02> NdmpConnection::processMessages: no more messages in stream buffer
L00 [3196](:CenteraStorageSubSystem.cpp:1143) 08/30/12 14:41:23> Querying Centera (Wed Nov 01 09:10:00 2006 to Wed Nov 01 09:20:00 2006)
Lui [3196](:CenteraStorageSubSystem.cpp:730) 08/30/12 14:41:24> Query In Progress
Lui [3196](:CenteraStorageSubSystem.cpp:748) 08/30/12 14:41:24> Query Result Code 1 (retry 2 of 5)
Lui [3196](:CenteraStorageSubSystem.cpp:1132) 08/30/12 14:41:24> Closing Last Query Expression
Lui [3196](:CenteraStorageSubSystem.cpp:1137) 08/30/12 14:41:24> Closing Last Query
Ldd [2616](ndmp:NdmpConnection.cpp:298) 08/30/12 14:41:32> NdmpConnection::processRequests