Forum Discussion

Pavan_Sudheer's avatar
Pavan_Sudheer
Level 3
10 years ago

Import failing

Import failing with error 85, please see job details as given below.

 

05/13/2015 18:58:23 - begin Import
05/13/2015 18:58:36 - Info bptm (pid=8730) start
05/13/2015 18:58:37 - started process bptm (pid=8730)
05/13/2015 18:58:45 - requesting resource XXXXL4
05/13/2015 18:58:46 - Info bptm (pid=8730) Waiting for mount of media id XXXXL4 (copy 1) on server <Media_Server_Name>.
05/13/2015 18:58:46 - started process bptm (pid=8730)
05/13/2015 18:58:46 - mounting XXXXL4
05/13/2015 18:58:46 - Info bptm (pid=8730) INF - Waiting for mount of media id XXXXL4 on server <Media_Server_Name> for reading.
05/13/2015 18:58:46 - granted resource  XXXXL4
05/13/2015 18:58:46 - granted resource  <Drive_Name>
05/13/2015 18:59:18 - mounted XXXXL4; mount time: 0:00:32
05/13/2015 18:59:18 - Warning bptm (pid=8730) read error on media id XXXXL4, drive index 13 reading header block, I/O error
05/13/2015 18:59:20 - Info bptm (pid=8730) EXITING with status 85 <----------
05/13/2015 18:59:20 - Error bpimport (pid=29610) Status = media read error.
05/13/2015 18:59:20 - end Import; elapsed time 0:00:57
media read error  (85)

7.5
Backup and Recovery
Error messages
NetBackup
  • mnolan's avatar
    mnolan
    10 years ago

    Hardware level encrypted tapes could also cause this as encrypting the headers is usually an option.

8 Replies

Sort By
  • sdo's avatar
    sdo
    Moderator
    10 years ago

    You need to investigate the bptm logs?  Or post a relevant extract from the bptm logs here for someone to browse/check?  Or post, as a '.txt' file attachment, a complete (but short) bptm log for someone to browse/check?

  • Pavan_Sudheer's avatar
    Pavan_Sudheer
    Level 3
    10 years ago

     

    Hi,

    I have tryed on other drives too, but import failing with error code 85. Please find bptm logs for the same time is

     

     

    10:58:37.725 [7050] <2> bptm: EXITING with status 0 <----------
    11:01:03.215 [7627] <2> bptm: INITIATING (VERBOSE = 0): -delete_all_expired
    11:01:03.216 [7627] <8> vnet_same_host_and_update: [vnet_addrinfo.c:2829] name2 is empty 0 0x0
    11:01:03.217 [7627] <4> bptm: emmserver_name = <Master_Server_Name>
    11:01:03.217 [7627] <4> bptm: emmserver_port = 1556
    11:01:03.262 [7627] <2> emmlib_initialize: (-) Connection attempt #<0>
    11:01:03.262 [7627] <2> emmlib_initializeEx: (-) Connecting to the Server <<Master_Server_Name>> Port <1556>, App <bptm> OrbOpt <No extra otions>
    11:01:03.293 [7627] <2> Orb::init: Enabling ORBNativeCharCodeSet UTF-8(Orb.cpp:604)
    11:01:03.299 [7627] <2> Orb::init: initializing ORB EMMlib_Orb with: bptm -ORBSvcConfDirective "-ORBDottedDecimalAddresses 0" -ORBSvcConfDirective "static Resource_Factory '-ORB
    NativeCharCodeSet UTF-8'" -ORBSvcConfDirective "static PBXIOP_Factory '-enable_keepalive'" -ORBSvcConfDirective "static EndpointSelectorFactory ''" -ORBSvcConfDirective "static
    Resource_Factory '-ORBProtocolFactory PBXIOP_Factory'" -ORBSvcConfDirective "static Resource_Factory '-ORBProtocolFactory IIOP_Factory'" -ORBDefaultInitRef '' -ORBSvcConfDirecti
    ve "static PBXIOP_Evaluator_Factory '-orb EMMlib_Orb'" -ORBSvcConfDirective "static Resource_Factory '-ORBConnectionCacheMax 1024 '" -ORBSvcConf /dev/null -ORBSvcConfDirective "
    static Server_Strategy_Factory '-ORBMaxRecvGIOPPayloadSize 268435456'"  -ORBDebug  -ORBDebugLevel 1(Orb.cpp:842)
    11:01:03.308 [7627] <2> TAO: starting up daemon bptm
    11:01:03.308 [7627] <2> TAO: destroying TAO_POA, flags = 3
    11:01:03.310 [7627] <2> TAO: Service_Config::process_directive - static Resource_Factory '-ORBNativeCharCodeSet UTF-8'
    11:01:03.311 [7627] <2> TAO: opening static service Resource_Factory
    11:01:03.312 [7627] <2> TAO: did static on Resource_Factory, error = 0
    11:01:03.312 [7627] <2> TAO: Service_Config::process_directive - static PBXIOP_Factory '-enable_keepalive'
    11:01:03.313 [7627] <2> TAO: opening static service PBXIOP_Factory
    11:01:03.314 [7627] <2> TAO: did static on PBXIOP_Factory, error = 0
    11:01:03.314 [7627] <2> TAO: Service_Config::process_directive - static EndpointSelectorFactory ''
    11:01:03.314 [7627] <2> TAO: opening static service EndpointSelectorFactory
    11:01:03.314 [7627] <2> TAO: did static on EndpointSelectorFactory, error = 0
    11:01:03.314 [7627] <2> TAO: Service_Config::process_directive - static Resource_Factory '-ORBProtocolFactory PBXIOP_Factory'
    11:01:03.314 [7627] <2> TAO: opening static service Resource_Factory
    11:01:03.315 [7627] <2> TAO: did static on Resource_Factory, error = 0
    11:01:03.315 [7627] <2> TAO: Service_Config::process_directive - static Resource_Factory '-ORBProtocolFactory IIOP_Factory'
    11:01:03.315 [7627] <2> TAO: opening static service Resource_Factory
    11:01:03.315 [7627] <2> TAO: did static on Resource_Factory, error = 0
    11:01:03.316 [7627] <2> TAO: Service_Config::process_directive - static PBXIOP_Evaluator_Factory '-orb EMMlib_Orb'
    11:01:03.316 [7627] <2> TAO: opening static service PBXIOP_Evaluator_Factory
    11:01:03.316 [7627] <2> TAO: did static on PBXIOP_Evaluator_Factory, error = 0
    11:01:03.316 [7627] <2> TAO: Service_Config::process_directive - static Resource_Factory '-ORBConnectionCacheMax 1024 '
    11:01:03.317 [7627] <2> TAO: opening static service Resource_Factory
    11:01:03.317 [7627] <2> TAO: did static on Resource_Factory, error = 0
    11:01:03.317 [7627] <2> TAO: Service_Config::process_directive - static Server_Strategy_Factory '-ORBMaxRecvGIOPPayloadSize 268435456'
    11:01:03.317 [7627] <2> TAO: opening static service Server_Strategy_Factory
    11:01:03.317 [7627] <2> TAO: did static on Server_Strategy_Factory, error = 0
    11:01:03.324 [7627] <2> TAO: ACE_Select_Reactor_Notify::open: notification pipe successfully opened with read_handle=258, write_handle=259
    11:01:03.325 [7627] <2> TAO: TAO (7627|1) Loaded protocol <PBXIOP_Factory>
    11:01:03.325 [7627] <2> TAO: TAO (7627|1) Loaded protocol <IIOP_Factory>
    11:01:03.330 [7627] <2> Orb::init: caching EndpointSelectorFactory(Orb.cpp:857)
    11:01:03.334 [7627] <2> Orb::setOrbConnectTimeout: timeout seconds: 60(Orb.cpp:1498)
    11:01:03.334 [7627] <2> emmlib_initializeEx: (-) Setting connect timeout to <60> sec
    11:01:03.334 [7627] <2> Orb::setOrbRequestTimeout: timeout seconds: 1800(Orb.cpp:1507)
    11:01:03.334 [7627] <2> emmlib_initializeEx: (-) Setting request timeout to <1800> sec
    11:01:03.342 [7627] <2> TAO: TAO (7627|1) RT Timeout is <1800000>
    11:01:03.347 [7627] <2> TAO: TAO (7627|1) Connection Timeout is <0>
    11:01:03.348 [7627] <2> TAO: TAO (7627|1) - Transport_Cache_Manager::fill_set_i, current_size = 0, cache_maximum = 1024
    11:01:03.349 [7627] <2> TAO: PBXIOP (7627|1) PBXIOP_Connector::make_local_address using local addr [0.0.0.0]:0
    11:01:03.350 [7627] <2> TAO: (7627|1) PBXIOP_Connector::make_connection, attempting local bind to 0
    11:01:03.354 [7627] <2> TAO: PBXIOP (7627|1) PBXIOP connection to peer <[10.75.4.35]:1556> on 260
    11:01:03.356 [7627] <2> TAO: TAO (7627|1) - Transport_Cache_Manager::bind_i, 0x7fff9830 -> 0xa7b910 Transport[260]
    11:01:03.360 [7627] <2> TAO: TAO (7627|1) - Synch_Invocation::invoke_i, timeout on recv is <1799983>
    11:01:03.364 [7627] <2> TAO: TAO (7627|1) Synch_Invocation::invoke_i, timeout after recv is <1799977> status <1>
    11:01:03.368 [7627] <2> TAO: TAO (7627|1) Connection Timeout is <0>
    11:01:03.368 [7627] <2> TAO: TAO (7627|1) - Transport_Cache_Manager::is_entry_idle_i, state is [0]
    11:01:03.368 [7627] <2> TAO: TAO (7627|1) - Synch_Invocation::invoke_i, timeout on recv is <1799975>
    11:01:03.369 [7627] <2> TAO: TAO (7627|1) Synch_Invocation::invoke_i, timeout after recv is <1799975> status <1>
    11:01:03.370 [7627] <2> TAO: TAO (7627|1) RT Timeout is <1800000>
    11:01:03.370 [7627] <2> TAO: TAO (7627|1) Connection Timeout is <0>
    11:01:03.370 [7627] <2> TAO: TAO (7627|1) - Transport_Cache_Manager::is_entry_idle_i, state is [0]
    11:01:03.371 [7627] <2> TAO: TAO (7627|1) - Synch_Invocation::invoke_i, timeout on recv is <1799999>
    11:01:03.371 [7627] <2> TAO: TAO (7627|1) Synch_Invocation::invoke_i, timeout after recv is <1799998> status <1>
    11:01:03.372 [7627] <4> CreateConnectionID: (-) Using existing uninitialized Connection ID 0
    11:01:03.372 [7627] <4> emmlib_initializeEx: (0) Successfully initialized EMM session
    11:01:03.373 [7627] <2> TAO: TAO (7627|1) RT Timeout is <1800000>
    11:01:03.374 [7627] <2> TAO: TAO (7627|1) Connection Timeout is <0>
    11:01:03.374 [7627] <2> TAO: TAO (7627|1) - Transport_Cache_Manager::is_entry_idle_i, state is [0]
    11:01:03.374 [7627] <2> TAO: TAO (7627|1) - Synch_Invocation::invoke_i, timeout on recv is <1799999>
    11:01:03.376 [7627] <2> TAO: TAO (7627|1) Synch_Invocation::invoke_i, timeout after recv is <1799996> status <1>
    11:01:03.377 [7627] <2> TAO: TAO (7627|1) RT Timeout is <1800000>
    11:01:03.377 [7627] <2> TAO: TAO (7627|1) Connection Timeout is <0>
    11:01:03.378 [7627] <2> TAO: TAO (7627|1) - Transport_Cache_Manager::is_entry_idle_i, state is [0]
    11:01:03.378 [7627] <2> TAO: TAO (7627|1) - Synch_Invocation::invoke_i, timeout on recv is <1799999>
    11:01:05.609 [7627] <2> TAO: TAO (7627|1) Synch_Invocation::invoke_i, timeout after recv is <1795537> status <1>
    11:01:05.609 [7627] <4> emmlib_DeleteExpiredMedia: (0) changeMediaDBDeleteExpiredMedia returned 0
    11:01:05.611 [7627] <4> delete_expired_media: (-) Translating EMM_ERROR_Success(0) to 0 in the NetBackup context
    11:01:05.611 [7627] <2> bptm: EXITING with status 0 <----------
    11:08:37.658 [8878] <2> bptm: INITIATING (VERBOSE = 0): -rptdrv -jobid -1430337040 -jm
    11:08:37.661 [8878] <2> drivename_open: Called with Create 0, file IBM.ULT3580-TD4.017
    11:08:37.661 [8878] <2> drivename_checklock: Called
    11:08:37.661 [8878] <2> report_drives: DRIVE = IBM.ULT3580-TD4.017 LOCK = FALSE CURTIME = 1431581917
    11:08:37.663 [8878] <2> report_drives: MODE = 1
    11:08:37.663 [8878] <2> report_drives: TIME = 1398644396
    11:08:37.663 [8878] <2> report_drives: MASTER = <Master_Server_Name>
    11:08:37.663 [8878] <2> report_drives: SR_KEY = 0 1
    11:08:37.663 [8878] <2> report_drives: PATH = /dev/rmt/1cbn
    11:08:37.663 [8878] <2> report_drives: MEDIA = CLNU14
    11:08:37.663 [8878] <2> report_drives: REQID = -1396989160
    11:08:37.663 [8878] <2> report_drives: ALOCID = 53927

     

     

    I w't find anything in these too.

     

     

  • Marianne's avatar
    Marianne
    Level 6
    10 years ago
    You need bptm log on the media server where import is attempted. The log above does not seem to be from the media server as there is no evidence of import attempt or tape mount. Increase logging level for bptm on media server to 5 before you try again. Please copy bptm log to bptm.txt and upload as File attachment. (Please do not copy entire log file into a forum post. )
  • Marianne's avatar
    Marianne
    Level 6
    10 years ago
    The tape seems to be faulty - the media header cannot be read. If you get the same error on more than one tape drive and more than one media server, we can conclude that the tape is faulty. Hopefully you have another copy of the data?
  • Marianne's avatar
    Marianne
    Level 6
    10 years ago
    Another thought.... compare firmware and drivers of hba and tape drive where tape was originally written with current environment. Older drivers and/or firmware on import media server could also cause this.
  • mnolan's avatar
    mnolan
    Level 6
    10 years ago

    Hardware level encrypted tapes could also cause this as encrypting the headers is usually an option.