Sun Storage 7000 Unified Storage System: Possible causes of unexpected disk I/O activity

Asset ID:	1-72-1543331.1
Update Date:	2018-01-05
Keywords:

Solution Type Problem Resolution Sure

Solution 1543331.1 : Sun Storage 7000 Unified Storage System: Possible causes of unexpected disk I/O activity

Applies to:

Sun ZFS Storage 7420 - Version All Versions to Not Applicable [Release All Releases to N/A]
Sun ZFS Storage 7120 - Version All Versions to Not Applicable [Release All Releases to N/A]
Sun Storage 7110 Unified Storage System - Version All Versions to Not Applicable [Release All Releases to N/A]
Sun Storage 7210 Unified Storage System - Version All Versions to Not Applicable [Release All Releases to N/A]
Sun Storage 7310 Unified Storage System - Version All Versions to Not Applicable [Release All Releases to N/A]
Information in this document applies to any platform.

Symptoms

To discuss this information further with Oracle experts and industry peers, we encourage you to review, join or start a discussion in the My Oracle Support Community - Disk Storage ZFS Storage Appliance

Only another ZFS Appliance can be used as a replication target.

The replication schedule in this particular instance is continuous. Disk activity seems to be quite high on the replication 'destination' (target) - though disk activity due to replication on the source side is not equivalent :

zfssa-target-side cli> status activity show

Activity:
CPU 1 %util Sunny
FTP 0 bytes/sec Sunny
Disk 1625 ops/sec Partly Cloudy
iSCSI 0 ops/sec Sunny
NFSv3 0 ops/sec Sunny
NFSv4 0 ops/sec Sunny
Network 530K bytes/sec Sunny
SMB 0 ops/sec Sunny

Cause

IO activity is due to replication.

There are less IOPs related to replication on the source node because this is a continuous replication.
This means the data to be replicated is already in cache on the source side, so we need almost no disk IOs to send the replication data.

On the replication target side, we have nothing in cache, we need to write all the data. Hence, we see I/O write activity.

IO writes activity on target node is due to the following 2 threads :
::stacks -m zfs
...

fffff600118c5420 SLEEP CV 2
  swtch+0x150
  cv_wait+0x61
  txg_wait_synced+0x7c
  dsl_sync_task_group_wait+0xee
  dsl_sync_task_do+0x65
  dmu_recv_existing_end+0xa3
  dmu_recv_end+0x1e
  zfs_ioc_recv+0x7cd
  zfsdev_ioctl+0x15e
  cdev_ioctl+0x6c
  spec_ioctl+0x5a
  fop_ioctl+0xd0
  ioctl+0x18e
  _sys_sysenter_post_swapgs+0x149

fffff60011e51860 SLEEP CV 1
  swtch+0x150
  cv_wait+0x61
  txg_wait_synced+0x7c
  dsl_sync_task_group_wait+0xee
  dsl_dataset_destroy+0x305
  dmu_recv_existing_end+0xe8
  dmu_recv_end+0x1e
  zfs_ioc_recv+0x7cd
  zfsdev_ioctl+0x15e
  cdev_ioctl+0x6c
  spec_ioctl+0x5a
  fop_ioctl+0xd0
  ioctl+0x18e
  _sys_sysenter_post_swapgs+0x149

+ 1st thread is receiving some replication traffic

  [ ffffff002fb117d0 _resume_from_idle+0xf4() ]
  ffffff002fb11800 swtch+0x150()
  ffffff002fb11830 cv_wait+0x61(fffff6000f479b72, fffff6000f479b38)
  ffffff002fb11880 txg_wait_synced+0x7c(fffff6000f479980, 6ab6b97)
  ffffff002fb118c0 dsl_sync_task_group_wait+0xee(fffff605e3d99f10)
  ffffff002fb11940 dsl_sync_task_do+0x65(fffff6000f479980, fffffffff79d6530, fffffffff79d6560, fffff6004bc62600, ffffff002fb11950, 3)
  ffffff002fb11990 dmu_recv_existing_end+0xa3(ffffff002fb11b80)
  ffffff002fb119b0 dmu_recv_end+0x1e(ffffff002fb11b80)
  ffffff002fb11bf0 zfs_ioc_recv+0x7cd(fffff6040fa0e000)
  ffffff002fb11c70 zfsdev_ioctl+0x15e(7500000000, 5a1b, f41e4d20, 100003, fffff6000dbd8518, ffffff002fb11de4)
  ffffff002fb11cf0 cdev_ioctl+0x6c(7500000000, 5a1b, f41e4d20, 100003, fffff6000dbd8518, ffffff002fb11de4)
  ffffff002fb11d30 spec_ioctl+0x5a(fffff6000f476b80, 5a1b, f41e4d20, 100003, fffff6000dbd8518, ffffff002fb11de4, 0)
  ffffff002fb11dc0 fop_ioctl+0xd0(fffff6000f476b80, 5a1b, f41e4d20, 100003, fffff6000dbd8518, ffffff002fb11de4, 0)
  ffffff002fb11ec0 ioctl+0x18e(161, 5a1b, f41e4d20)
  ffffff002fb11f10 _sys_sysenter_post_swapgs+0x149()

  > fffff6040fa0e000::print -t zfs_cmd_t zc_name zc_begin_record.drr_toname
  char [1024] zc_name = [ "POOL_DATA/nas-rr-f81066d9-badd-6863-a4fd-cd7a81738722/Backups/Replications" ]
  char [256] zc_begin_record.drr_toname = [ "POOL_DATA/local/Backups/Replications@.rr-f81066d9-badd-6863-a4fd-cd7a81738722-78a61" ]

+ 2nd thread is receiving some replication traffic and destroying a replication snapshot :

  > fffff60011e51860::findstack -v
  stack pointer for thread fffff60011e51860: ffffff002fb05530
  [ ffffff002fb05530 _resume_from_idle+0xf4() ]
  ffffff002fb05560 swtch+0x150()
  ffffff002fb05590 cv_wait+0x61(fffff6000f479b72, fffff6000f479b38)
  ffffff002fb055e0 txg_wait_synced+0x7c(fffff6000f479980, 6ab6b97)
  ffffff002fb05620 dsl_sync_task_group_wait+0xee(fffff60052e97d58)
  ffffff002fb05940 dsl_dataset_destroy+0x305(fffff60011e42640, fffffffff7a78620, 0)
  ffffff002fb05990 dmu_recv_existing_end+0xe8(ffffff002fb05b80)
  ffffff002fb059b0 dmu_recv_end+0x1e(ffffff002fb05b80)
  ffffff002fb05bf0 zfs_ioc_recv+0x7cd(fffff609a324d000)
  ffffff002fb05c70 zfsdev_ioctl+0x15e(7500000000, 5a1b, f43e2d20, 100003, fffff6000dbd8518, ffffff002fb05de4)
  ffffff002fb05cf0 cdev_ioctl+0x6c(7500000000, 5a1b, f43e2d20, 100003, fffff6000dbd8518, ffffff002fb05de4)
  ffffff002fb05d30 spec_ioctl+0x5a(fffff6000f476b80, 5a1b, f43e2d20, 100003, fffff6000dbd8518, ffffff002fb05de4, 0)
  ffffff002fb05dc0 fop_ioctl+0xd0(fffff6000f476b80, 5a1b, f43e2d20, 100003, fffff6000dbd8518, ffffff002fb05de4, 0)
  ffffff002fb05ec0 ioctl+0x18e(164, 5a1b, f43e2d20)
  ffffff002fb05f10 _sys_sysenter_post_swapgs+0x149()

  > fffff609a324d000::print -t zfs_cmd_t zc_name zc_begin_record.drr_toname
  char [1024] zc_name = [ "POOL_DATA/nas-rr-5d998806-bcf6-648e-f8bc-b142c2e4c39b/Shares/BaeApps" ]
  char [256] zc_begin_record.drr_toname = [ "POOL_DATA/local/Shares/BaeApps@.rr-5d998806-bcf6-648e-f8bc-b142c2e4c39b-532af" ]

So, replication is still running for POOL_DATA

Solution

Replication might lead to more IOs on the target (destination) node than on the source node. This is an expected behavior, as data is already in cache on the source node.

Another source of "unexpected" disk IOPs can be due to the "/usr/lib/fs/nfs/nfsfind" process - which runs from the crontab - it checks (and removes) .nfs* files that are older than a week.

For detailed information regarding performance, see also Document 1213714.1 Sun ZFS Storage Appliance: Performance clues and considerations

References

<NOTE:1397959.1> - Sun Storage 7000 Unified Storage System: How to Troubleshoot Replication Issues

Attachments

This solution has no attachment