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] > <javascript:>> 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] <javascript:>. > > 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.
