Drive emulation should not help. Internally all writes/reads etc are handled by the same code. We had sent an email regarding the next steps, please try that out.
On Sat, Mar 17, 2018 at 7:16 PM, Milan Stubniak <[email protected]> wrote: > Hi, > running specific scsi command couldn`t be a problem, but > i don`t think there are exact scsi command in the logs. I can`t find them. > What do you suggest? > > > What do you think about changing emulation type of drive? Could it helps? > > > > Thanks for response. > > > at 7:44:55 PM UTC+1, quadstor wrote: > > We probably to have to run a few commands with the tape mounted. Do >> you have the exact SCSI command sent somewhere in the logs ? >> >> On Thu, Mar 15, 2018 at 4:53 PM, Milan Stubniak <[email protected]> >> wrote: >> > Hello, >> > i would like to ask about write error in TSM (Spectrum protect). Whe >> have >> > quadstor vtl server (3.0.25), which is destination library for >> TSM(Spectrum >> > protect for virtual enviroments- proxy backup for VM). >> > Sometimes (two times a week ) during backup from VM nodes to VTL (this >> > backup is performed by TSMforVirtualEnviroment Server) , we see TSM >> error >> > (below). Backup of VM failed. TSM marks this tape as read-only. >> > >> > 03/13/18 22:08:49 ANR8302E (Session: 838432, Origin: >> WBBHVN04_STA) >> > I/O >> > >> > error on drive DRV43 (mt2.9.0.1) with volume >> > B10001L5 >> > >> > (OP=LOCATE, Error Number=1104, CC=0, rc = >> 2865, >> > KEY= 08, >> > >> > ASC=00, ASCQ= 05, >> > SENSE=70.00.08.00.00.00.00.0A.00.00.00- >> > >> > .00.00.05.00.00.00, Description=An >> undetermined >> > error >> > >> > has occurred). Refer to the IBM Spectrum >> Protect >> > >> > documentation on I/O error code descriptions. >> > (SESSION: >> > >> > 838432) >> > >> > 1797225) >> > >> > 03/13/18 22:08:51 ANR0408I (Session: 838432, Origin: >> WBBHVN04_STA) >> > Session >> > >> > 28353 started for server BKPAPS1 (AIX) >> (Tcp/Ip) >> > for >> > >> > library sharing. (SESSION: 838432) >> > >> > 03/13/18 22:08:51 ANR0409I (Session: 838432, Origin: >> WBBHVN04_STA) >> > Session >> > >> > 28353 ended for server BKPAPS1 (AIX). >> (SESSION: >> > 838432) >> > >> > 03/13/18 22:08:51 ANR0523W (Session: 838432, Origin: >> WBBHVN04_STA) >> > >> > Transaction failed for session 28349 for node >> > >> > HYPERV_2012R2 (TDP HyperV) - error on output >> > storage >> > >> > device. (SESSION: 838432) >> > >> > 03/13/18 22:08:51 ANR0523W Transaction failed for session >> 1797219 for >> > node >> > >> > HYPERV_2012R2 (TDP HyperV) - error on output >> > storage >> > >> > device. (SESSION: 1797219) >> > >> > In VTL log we see only "standard" warnning: >> > >> > 13 22:08:04 oscsvtl1 kernel: WARN: __tdrive_cmd_validate_write:2316 >> VTL >> > obpds drive 3 validate write failed with error Operator selected write >> > protect >> > >> > After backup task from VM environment to VTL is done, we have scheduled >> job >> > to copy VTL storage pool to Physical tape. (from VTL to Physical tape - >> this >> > is done by TSM server). Operation failed with errors in TSM. >> > >> > >> > >> > 03/14/18 01:36:56 ANR9999D_0252090925 >> > NtpValidateComBlockHdr(pvrntp.c:6123) >> > >> > Thread<3631258>: Invalid block header read >> from >> > NTP >> > >> > drive DRV42 (/dev/rmt-vtl22). >> (magic=5A4D4E50, >> > ver=5, >> > >> > Hdr blk=11610832 <expected 11610832>, >> > dbytes=262096 >> > >> > <231220>) (SESSION: 1798707, PROCESS: 2009) >> > >> > 03/14/18 01:36:56 ANR9999D Thread<3631258> issued message 9999 >> from: >> > >> > (SESSION: 1798707, PROCESS: 2009) >> > >> > 03/14/18 01:36:56 ANR9999D Thread<3631258> 0x0000000100031254 >> > StdPutText >> > >> > (SESSION: 1798707, PROCESS: 2009) >> > >> > 03/14/18 01:36:56 ANR9999D Thread<3631258> 0x0000000100031e58 >> > >> > OutDiagToCons (SESSION: 1798707, PROCESS: >> 2009) >> > >> > 03/14/18 01:36:56 ANR9999D Thread<3631258> 0x000000010000adf4 >> > outDiagfExt >> > >> > (SESSION: 1798707, PROCESS: 2009) >> > >> > 03/14/18 01:36:56 ANR9999D Thread<3631258> 0x0000000100ade958 >> > >> > IPRA.$FetchBlock (SESSION: 1798707, PROCESS: >> > 2009) >> > >> > 03/14/18 01:36:56 ANR9999D Thread<3631258> 0x0000000100ae05d4 >> > NtpReadNC >> > >> > (SESSION: 1798707, PROCESS: 2009) >> > >> > 03/14/18 01:36:56 ANR9999D Thread<3631258> 0x0000000100b1dab0 >> > LtoReadNC >> > >> > (SESSION: 1798707, PROCESS: 2009) >> > >> > 03/14/18 01:36:56 ANR9999D Thread<3631258> 0x0000000100720dd8 >> > AgentThread >> > >> > (SESSION: 1798707, PROCESS: 2009) >> > >> > 03/14/18 01:36:56 ANR9999D Thread<3631258> 0x000000010000e300 >> > StartThread >> > >> > more... (<ENTER> to continue, 'C' to cancel) >> > >> > >> > >> > (SESSION: 1798707, PROCESS: 2009) >> > >> > 03/14/18 01:36:56 ANR1218E BACKUP STGPOOL: Process 2009 >> terminated - >> > >> > excessive read errors encountered. (SESSION: >> > 1798707, >> > >> > PROCESS: 2009) >> > >> > 03/14/18 01:36:56 ANR0986I Process 2009 for BACKUP STORAGE POOL >> > running in >> > >> > the BACKGROUND processed 63,319 items for a >> total >> > of >> > >> > 466,828,716,893 bytes with a completion state >> of >> > FAILURE >> > >> > at 01:36:56. (SESSION: 1798707, PROCESS: >> 2009) >> > >> > 03/14/18 01:36:56 ANR1893E Process 2009 for BACKUP STORAGE POOL >> > completed >> > >> > with a completion state of FAILURE. (SESSION: >> > 1798707, >> > >> > PROCESS: 2009) >> > >> > 03/14/18 01:36:56 ANR0514I Session 1798707 closed volume >> B10001L5. >> > >> > (SESSION: 1798707) >> > >> > >> > In VTL library log we see: >> > >> > >> > Mar 14 01:36:56 oscsvtl1 kernel: Warning at blk_map.c:blk_map_read:1974 >> > Mar 14 01:36:56 oscsvtl1 kernel: ------------[ cut here ]------------ >> > Mar 14 01:36:56 oscsvtl1 kernel: WARNING: at >> > /quadstorvtl/src/export/core_linux.c:336 debug_check+0x1a/0x20 >> [vtlcore]() >> > (Tainted: G W -- ------------ ) >> > Mar 14 01:36:56 oscsvtl1 kernel: Hardware name: ProLiant BL460c Gen8 >> > Mar 14 01:36:56 oscsvtl1 kernel: Modules linked in: ch osst st >> iscsit(U) >> > vtldev(U) vtlcore(U) autofs4 cpufreq_ondemand freq_table pcc_cpufreq >> bonding >> > iptable_filter ip_tables ip6t_REJECT nf_conntrack_ipv6 nf_defrag_ipv >> > 6 xt_state nf_conntrack ip6table_filter ip6_tables ipv6 video output >> > microcode power_meter acpi_ipmi ipmi_si ipmi_msghandler iTCO_wdt >> > iTCO_vendor_support hpilo hpwdt sg serio_raw lpc_ich mfd_core ioatdma >> dca >> > shpchp ext >> > 4 jbd2 mbcache dm_round_robin sd_mod crc_t10dif qla2xxx(U) >> scsi_transport_fc >> > scsi_tgt hpsa be2net dm_multipath dm_mirror dm_region_hash dm_log >> dm_mod >> > [last unloaded: scsi_wait_scan] >> > Mar 14 01:36:56 oscsvtl1 kernel: Pid: 6170, comm: tdrv00102 Tainted: G >> > W -- ------------ 2.6.32-642.13.1.el6.x86_64 #1 >> > Mar 14 01:36:56 oscsvtl1 kernel: Call Trace: >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffff8107c6f1>] ? >> > warn_slowpath_common+0x91/0xe0 >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffff8107c75a>] ? >> > warn_slowpath_null+0x1a/0x20 >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffffa045598a>] ? >> > debug_check+0x1a/0x20 [vtlcore] >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffffa0477c4a>] ? >> > blk_map_read+0xeaa/0x15e0 [vtlcore] >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffff81064855>] ? >> > find_busiest_group+0x9d5/0xa50 >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffff8106be68>] ? >> > load_balance_fair+0x208/0x300 >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffff8117ecbc>] ? >> > transfer_objects+0x5c/0x80 >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffff8117f76b>] ? >> > cache_alloc_refill+0x15b/0x240 >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffff8113a573>] ? >> __rmqueue+0xc3/0x490 >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffff810657e0>] ? >> > __dequeue_entity+0x30/0x50 >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffff81151319>] ? >> > zone_statistics+0x99/0xc0 >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffff8113dea9>] ? >> > __alloc_pages_nodemask+0x129/0x950 >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffff8100bc0e>] ? >> > apic_timer_interrupt+0xe/0x20 >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffffa010e02c>] ? >> > ctio_sglist_map+0x4c/0x140 [qla2xxx] >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffff8106b2a3>] ? >> > perf_event_task_sched_out+0x33/0x70 >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffffa04c105f>] ? >> > tape_partition_read+0x11f/0x130 [vtlcore] >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffffa04bc33c>] ? >> > tape_cmd_read+0x9c/0xd0 [vtlcore] >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffffa04c828a>] ? >> > tdrive_wait_for_write_queue+0x6a/0x80 [vtlcore] >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffffa04cce6f>] ? >> > __tdrive_cmd_read+0x16f/0x510 [vtlcore] >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffff8106b2a3>] ? >> > perf_event_task_sched_out+0x33/0x70 >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffff8100969d>] ? >> > __switch_to+0x7d/0x340 >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffffa04d029f>] ? >> > tdrive_proc_cmd+0xbff/0x1d80 [vtlcore] >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffff81548a1e>] ? >> schedule+0x3ee/0xb70 >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffff810a6c9c>] ? >> > remove_wait_queue+0x3c/0x50 >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffffa045616a>] ? >> > __wait_on_chan_sig+0x9a/0xc0 [vtlcore] >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffff810a68a0>] ? >> > autoremove_wake_function+0x0/0x40 >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffffa049226b>] ? >> > devq_thread+0xab/0x130 [vtlcore] >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffffa04921c0>] ? >> > devq_thread+0x0/0x130 [vtlcore] >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffff810a640e>] ? >> kthread+0x9e/0xc0 >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffff8100c28a>] ? >> child_rip+0xa/0x20 >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffff810a6370>] ? >> kthread+0x0/0xc0 >> > Mar 14 01:36:56 oscsvtl1 kernel: [<ffffffff8100c280>] ? >> child_rip+0x0/0x20 >> > Mar 14 01:36:56 oscsvtl1 kernel: ---[ end trace 7186d29d5e453da0 ]--- >> > Mar 14 01:36:56 oscsvtl1 kernel: WARN: blk_map_read:1988 Incomplete >> read >> > block(s) encountered read size 262144 todo 30876 fixed 0 num blocks 1 >> data >> > blocks 1 ili block size 0 >> > >> > This failed tape(VTL) we can move to another tape , but we have some >> damaged >> > - unrecoverable files on tape. >> > >> > >> > This behaviour is the same on our second quadstor server. We tried to >> > eliminate HW issues of VTL server. In VTL log we don`t see errors (VTL >> > errors) but in TSM are present: >> > >> > Backup from VTL to TSM server: >> > >> > >> > 03/13/18 09:31:25 ANR8337I LTO volume D00007L6 mounted in drive >> DRV62 >> > >> > (/dev/rmt1). (SESSION: 1786097, PROCESS: >> 1999) >> > >> > 03/13/18 09:31:25 ANR0512I Process 1999 opened input volume >> D00007L6. >> > >> > (SESSION: 1786097, PROCESS: 1999) >> > >> > 03/13/18 09:31:42 ANR8302E I/O error on drive DRV62 (/dev/rmt1) >> with >> > volume >> > >> > D00007L6 (OP=READ, Error Number=5, CC=0, rc = >> > 2865, KEY= >> > >> > 08, ASC=00, ASCQ= 05, >> > SENSE=F0.00.08.00.04.00.00.0A.00.0- >> > >> > 0.00.00.00.05.00.00.00.00, Description=An >> > undetermined >> > >> > error has occurred). Refer to the IBM >> Spectrum >> > Protect >> > >> > documentation on I/O error code descriptions. >> > (SESSION: >> > >> > 1786097, PROCESS: 1999) >> > >> > 03/13/18 09:31:42 ANR9999D_2412546014 NtpReadNC(pvrntp.c:3266) >> > >> > Thread<3606553>: Next block is unknown for >> volume >> > >> > D00007L6. (SESSION: 1786097, PROCESS: 1999) >> > >> > 03/13/18 09:31:42 ANR9999D Thread<3606553> issued message 9999 >> from: >> > >> > (SESSION: 1786097, PROCESS: 1999) >> > >> > 03/13/18 09:31:42 ANR9999D Thread<3606553> 0x0000000100031254 >> > StdPutText >> > >> > (SESSION: 1786097, PROCESS: 1999) >> > >> > 03/13/18 09:31:42 ANR9999D Thread<3606553> 0x0000000100031e58 >> > >> > OutDiagToCons (SESSION: 1786097, PROCESS: >> 1999) >> > >> > 03/13/18 09:31:42 ANR9999D Thread<3606553> 0x000000010000adf4 >> > outDiagfExt >> > >> > (SESSION: 1786097, PROCESS: 1999) >> > >> > 03/13/18 09:31:42 ANR9999D Thread<3606553> 0x0000000100ae0810 >> > NtpReadNC >> > >> > (SESSION: 1786097, PROCESS: 1999) >> > >> > 03/13/18 09:31:42 ANR9999D Thread<3606553> 0x0000000100b1dab0 >> > LtoReadNC >> > >> > (SESSION: 1786097, PROCESS: 1999) >> > >> > 03/13/18 09:31:42 ANR9999D Thread<3606553> 0x0000000100720dd8 >> > AgentThread >> > >> > (SESSION: 1786097, PROCESS: 1999) >> > >> > 03/13/18 09:31:42 ANR9999D Thread<3606553> 0x000000010000e300 >> > StartThread >> > >> > (SESSION: 1786097, PROCESS: 1999) >> > >> > 03/13/18 09:31:42 ANR1330E The server has detected possible >> > corruption in >> > >> > an object that is being restored or moved. >> The >> > actual values for the incorrect frame are: >> magic >> > 53454652 hdr >> > >> > version 2 hdr length 32 sequence number >> > 86 >> > >> > data length 3FFB0 server ID 0 >> segment ID >> > >> > 594476150 crc 0. (SESSION: 1786097, >> > PROCESS: >> > >> > 1999) >> > >> > 03/13/18 09:31:42 ANR1331E Invalid frame detected. Expected >> magic >> > 53454652 >> > >> > sequence number 88 server id 0 >> > segment id >> > >> > 594476150. (SESSION: 1786097, PROCESS: >> 1999) >> > >> > 03/13/18 09:31:44 ANR8302E I/O error on drive DRV62 (/dev/rmt1) >> with >> > volume >> > >> > D00007L6 (OP=LOCATE, Error Number=5, CC=0, rc >> = >> > 2865, >> > >> > KEY= 08, ASC=00, ASCQ= 05, >> > SENSE=70.00.08.00.00.00.00.0A- >> > >> > .00.00.00.00.00.05.00.00.00.00, >> Description=An >> > >> > undetermined error has occurred). Refer to >> the IBM >> > >> > Spectrum Protect documentation on I/O error >> code >> > >> > descriptions. (SESSION: 1786097, PROCESS: >> 1999) >> > >> > 03/13/18 09:31:44 ANR1218E BACKUP STGPOOL: Process 1999 >> terminated - >> > >> > excessive read errors encountered. (SESSION: >> > 1786097, >> > >> > PROCESS: 1999) >> > >> > 03/13/18 09:31:44 ANR0985I Process 1999 for BACKUP STORAGE POOL >> > running in >> > >> > the BACKGROUND completed with completion >> state >> > FAILURE >> > >> > at 09:31:44. (SESSION: 1786097, PROCESS: >> 1999) >> > >> > 03/13/18 09:31:44 ANR1893E Process 1999 for BACKUP STORAGE POOL >> > completed >> > >> > with a completion state of FAILURE. (SESSION: >> > 1786097, >> > >> > PROCESS: 1999) >> > >> > 03/13/18 09:31:44 ANR0514I Session 1786097 closed volume >> D00007L6. >> > >> > (SESSION: 1786097) >> > >> > 03/13/18 09:31:44 ANR0514I Session 1786097 closed volume >> A00065L7. >> > >> > (SESSION: 1786097) >> > >> > 03/13/18 09:31:44 ANR1214I The backup of the TAPE_BKPTPL16 >> primary >> > storage >> > >> > pool to the COPY_BKPTPL16 copy storage pool >> is >> > complete. >> > >> > Number of files backed up: 0. Number of bytes >> > backed up: >> > >> > 0. Deduplicated bytes backed up: 0. >> Unreadable >> > files: 1. >> > >> > Unreadable bytes: 607139076487. (SESSION: >> 1786097) >> > >> > 03/13/18 09:31:44 ANR8468I LTO volume D00007L6 dismounted from >> drive >> > DRV62 >> > >> > (/dev/rmt1) in library BKPTPL16. (SESSION: >> > 1786097, >> > >> > PROCESS: 1999 >> > >> > next day we have damaged files on VTL library: >> > >> > 03/14/18 09:30:10 ANR1257W Storage pool backup skipping damaged >> file >> > on >> > >> > volume D00007L6: Node PPSDAT1V_ORA, Type >> Backup, >> > File >> > >> > space /oracledb, fsId 2, File name >> > >> > //pps_db<pps_34349706144541>.dbf. (SESSION: >> > 1804482, >> > >> > PROCESS: 2024) >> > >> > Could you help us with that problem? >> > >> > Should we try a different type of tape device emulation. (Do you have >> > preffered one?) >> > >> > >> > Thanks for reply. >> > >> > >> > Milan. >> > >> > >> > >> > -- >> > You received this message because you are subscribed to the Google >> Groups >> > "QUADStor VTL" group. >> > To unsubscribe from this group and stop receiving emails from it, send >> an >> > email to [email protected]. >> > For more options, visit https://groups.google.com/d/optout. >> > -- > You received this message because you are subscribed to the Google Groups > "QUADStor VTL" group. > To unsubscribe from this group and stop receiving emails from it, send an > email to [email protected]. > For more options, visit https://groups.google.com/d/optout. > -- You received this message because you are subscribed to the Google Groups "QUADStor VTL" group. To unsubscribe from this group and stop receiving emails from it, send an email to [email protected]. For more options, visit https://groups.google.com/d/optout.
