DAOS-17607 bio: SPDK I/O monitor (#17071)

Monitor inflight SPDK I/Os, if any I/O isn't completed within
certain amount of time (120 seconds, configurable through env
var DAOS_SPDK_IO_TIMEOUT), we assume the SPDK I/O is
stalled due to hardware issue (or software bug), RAS event will
be raised and the corresponding device will be marked as faulty.

Signed-off-by: Niu Yawei <[email protected]>

Author: NiuYawei

src/bio/bio_buffer.c

@@ -280,6 +280,7 @@ bio_iod_alloc(struct bio_io_context *ctxt, struct umem_instance *umem,
 		return NULL;
 
 	D_ASSERT(type < BIO_IOD_TYPE_MAX);
+	bio_io_lug_init(&biod->bd_io_lug);
 	biod->bd_umem = umem;
 	biod->bd_ctxt = ctxt;
 	biod->bd_type = type;
@@ -336,6 +337,7 @@ bio_iod_free(struct bio_desc *biod)
 		bio_sgl_fini(&biod->bd_sgls[i]);
 
 	D_FREE(biod->bd_bulk_hdls);
+	bio_io_lug_fini(&biod->bd_io_lug);
 
 	D_FREE(biod);
 }
@@ -1041,8 +1043,7 @@ rw_completion(void *cb_arg, int err)
 
 	bxb = biod->bd_ctxt->bic_xs_blobstore;
 	D_ASSERT(bxb != NULL);
-	D_ASSERT(bxb->bxb_blob_rw > 0);
-	bxb->bxb_blob_rw--;
+	bio_io_lug_dequeue(bxb, &biod->bd_io_lug);
 
 	io_ctxt = biod->bd_ctxt;
 	D_ASSERT(io_ctxt != NULL);
@@ -1184,7 +1185,7 @@ nvme_rw(struct bio_desc *biod, struct bio_rsrvd_region *rg)
 
 		biod->bd_dma_issued = 1;
 		biod->bd_inflights++;
-		bxb->bxb_blob_rw++;
+		bio_io_lug_enqueue(xs_ctxt, bxb, &biod->bd_io_lug);
 		biod->bd_ctxt->bic_inflight_dmas++;
 
 		rw_cnt = (pg_cnt > bio_chk_sz) ? bio_chk_sz : pg_cnt;
@@ -1982,3 +1983,42 @@ bio_copy(struct bio_io_context *ioctxt, struct umem_instance *umem,
 
 	return rc;
 }
+
+#define IO_MONITOR_INTVL 1000000 /* us, 1 second */
+
+void
+bio_io_monitor(struct bio_xs_context *xs_ctxt, uint64_t now)
+{
+	enum smd_dev_type        st;
+	struct bio_xs_blobstore *bxb;
+	struct bio_io_lug       *io_lug;
+	struct media_error_msg  *mem;
+
+	if ((xs_ctxt->bxc_io_monitor_ts + IO_MONITOR_INTVL) > now)
+		return;
+
+	xs_ctxt->bxc_io_monitor_ts = now;
+
+	for (st = SMD_DEV_TYPE_DATA; st < SMD_DEV_TYPE_MAX; st++) {
+		bxb = xs_ctxt->bxc_xs_blobstores[st];
+
+		if (!bxb || d_list_empty(&bxb->bxb_pending_ios))
+			continue;
+
+		io_lug = d_list_entry(bxb->bxb_pending_ios.next, struct bio_io_lug, bil_link);
+		D_ASSERT(io_lug->bil_submit_ts != 0);
+
+		if ((io_lug->bil_submit_ts + bio_io_timeout) >= now)
+			continue;
+
+		D_ALLOC_PTR(mem);
+		if (mem == NULL) {
+			D_ERROR("Out of memory: NVMe stalled I/O report is skipped\n");
+			continue;
+		}
+		mem->mem_err_type = MET_IO_STALLED;
+		mem->mem_bs       = bxb->bxb_blobstore;
+		mem->mem_tgt_id   = xs_ctxt->bxc_tgt_id;
+		spdk_thread_send_msg(owner_thread(mem->mem_bs), bio_media_error, mem);
+	}
+}

src/bio/bio_context.c

@@ -13,6 +13,7 @@
 struct blob_cp_arg {
 	spdk_blob_id		 bca_id;
 	struct spdk_blob	*bca_blob;
+	struct bio_io_lug        bca_io_lug;
 	/*
 	 * Completion could run on different xstream when NVMe
 	 * device is shared by multiple xstreams.
@@ -36,6 +37,7 @@ blob_cp_arg_init(struct blob_cp_arg *ba)
 {
 	int	rc;
 
+	bio_io_lug_init(&ba->bca_io_lug);
 	rc = ABT_eventual_create(0, &ba->bca_eventual);
 	if (rc != ABT_SUCCESS)
 		return dss_abterr2der(rc);
@@ -46,6 +48,7 @@ blob_cp_arg_init(struct blob_cp_arg *ba)
 static inline void
 blob_cp_arg_fini(struct blob_cp_arg *ba)
 {
+	bio_io_lug_fini(&ba->bca_io_lug);
 	ABT_eventual_free(&ba->bca_eventual);
 }
 
@@ -164,8 +167,7 @@ blob_unmap_cb(void *arg, int rc)
 
 	bxb = bma->bma_ioc->bic_xs_blobstore;
 	D_ASSERT(bxb != NULL);
-	D_ASSERT(bxb->bxb_blob_rw > 0);
-	bxb->bxb_blob_rw--;
+	bio_io_lug_dequeue(bxb, &ba->bca_io_lug);
 
 	blob_common_cb(ba, rc);
 }
@@ -1232,7 +1234,7 @@ blob_unmap_sgl(struct bio_io_context *ioctxt, d_sg_list_t *unmap_sgl, uint32_t b
 		drain_inflight_ios(xs_ctxt, bxb);
 
 		ba->bca_inflights++;
-		bxb->bxb_blob_rw++;
+		bio_io_lug_enqueue(xs_ctxt, bxb, &ba->bca_io_lug);
 
 		pg_off = (uint64_t)unmap_iov->iov_buf;
 		pg_cnt = unmap_iov->iov_len;

src/bio/bio_internal.h

@@ -278,7 +278,7 @@ struct bio_dev_health {
 	void		       *bdh_intel_smart_buf; /*Intel SMART attributes*/
 	uint64_t		bdh_stat_age;
 	unsigned int		bdh_inflights;
-	unsigned int		bdh_stopping:1;
+	unsigned int             bdh_stopping : 1, bdh_io_stalled : 1;
 	uint16_t		bdh_vendor_id; /* PCI vendor ID */
 
 	/**
@@ -365,10 +365,21 @@ struct bio_blobstore {
 				 bb_faulty_done:1;	/* Faulty reaction is done */
 };
 
+struct bio_io_lug {
+	/* Link to bio_xs_blobstore::bxb_pending_ios */
+	d_list_t bil_link;
+	/* When the I/O is submitted */
+	uint64_t bil_submit_ts;
+	/* Reference count */
+	uint32_t bil_ref;
+};
+
 /* Per-xstream blobstore */
 struct bio_xs_blobstore {
 	/* In-flight blob read/write */
 	unsigned int		 bxb_blob_rw;
+	/* Pending I/Os */
+	d_list_t                 bxb_pending_ios;
 	/* spdk io channel */
 	struct spdk_io_channel	*bxb_io_channel;
 	/* per bio blobstore */
@@ -381,13 +392,60 @@ struct bio_xs_blobstore {
 /* Per-xstream NVMe context */
 struct bio_xs_context {
 	int			 bxc_tgt_id;
+	uint64_t                 bxc_io_monitor_ts;
 	struct spdk_thread	*bxc_thread;
 	struct bio_xs_blobstore	*bxc_xs_blobstores[SMD_DEV_TYPE_MAX];
 	struct bio_dma_buffer	*bxc_dma_buf;
 	unsigned int		 bxc_self_polling:1;	/* for standalone VOS */
 	unsigned int             bxc_skip_draining : 1;
 };
 
+static inline void
+bio_io_lug_init(struct bio_io_lug *io_lug)
+{
+	D_INIT_LIST_HEAD(&io_lug->bil_link);
+	io_lug->bil_submit_ts = 0;
+	io_lug->bil_ref       = 0;
+}
+
+static inline void
+bio_io_lug_fini(struct bio_io_lug *io_lug)
+{
+	D_ASSERT(io_lug->bil_ref == 0);
+	D_ASSERT(d_list_empty(&io_lug->bil_link));
+}
+
+static inline void
+bio_io_lug_dequeue(struct bio_xs_blobstore *bxb, struct bio_io_lug *io_lug)
+{
+	D_ASSERT(bxb->bxb_blob_rw > 0);
+	bxb->bxb_blob_rw--;
+
+	D_ASSERT(!d_list_empty(&io_lug->bil_link));
+	D_ASSERT(io_lug->bil_submit_ts != 0);
+	D_ASSERT(io_lug->bil_ref > 0);
+	io_lug->bil_ref--;
+	if (io_lug->bil_ref == 0)
+		d_list_del_init(&io_lug->bil_link);
+}
+
+static inline void
+bio_io_lug_enqueue(struct bio_xs_context *xs_ctxt, struct bio_xs_blobstore *bxb,
+		   struct bio_io_lug *io_lug)
+{
+	bxb->bxb_blob_rw++;
+	if (io_lug->bil_ref == 0) {
+		if (xs_ctxt->bxc_io_monitor_ts)
+			io_lug->bil_submit_ts = xs_ctxt->bxc_io_monitor_ts;
+		else
+			io_lug->bil_submit_ts = d_timeus_secdiff(0);
+
+		D_ASSERT(d_list_empty(&io_lug->bil_link));
+		d_list_add_tail(&io_lug->bil_link, &bxb->bxb_pending_ios);
+	}
+	io_lug->bil_ref++;
+}
+
 /* Per VOS instance I/O context */
 struct bio_io_context {
 	d_list_t		 bic_link; /* link to bxb_io_ctxts */
@@ -437,6 +495,7 @@ struct bio_rsrvd_dma {
 
 /* I/O descriptor */
 struct bio_desc {
+	struct bio_io_lug        bd_io_lug;
 	struct umem_instance	*bd_umem;
 	struct bio_io_context	*bd_ctxt;
 	/* DMA buffers reserved by this io descriptor */
@@ -546,6 +605,7 @@ extern unsigned int	bio_chk_cnt_max;
 extern unsigned int	bio_numa_node;
 extern unsigned int	bio_spdk_max_unmap_cnt;
 extern unsigned int	bio_max_async_sz;
+extern unsigned int                     bio_io_timeout;
 
 int xs_poll_completion(struct bio_xs_context *ctxt, unsigned int *inflights,
 		       uint64_t timeout);
@@ -583,6 +643,8 @@ int iod_add_region(struct bio_desc *biod, struct bio_dma_chunk *chk,
 		   uint64_t end, uint8_t media);
 int dma_buffer_grow(struct bio_dma_buffer *buf, unsigned int cnt);
 void iod_dma_wait(struct bio_desc *biod);
+void
+bio_io_monitor(struct bio_xs_context *xs_ctxt, uint64_t now);
 
 static inline struct bio_dma_buffer *
 iod_dma_buf(struct bio_desc *biod)

src/bio/bio_monitor.c

@@ -680,7 +680,8 @@ get_spdk_health_info_completion(struct spdk_bdev_io *bdev_io, bool success,
 static bool
 is_bbs_faulty(struct bio_blobstore *bbs)
 {
-	struct nvme_stats	*dev_stats = &bbs->bb_dev_health.bdh_health_state;
+	struct bio_dev_health *bdh       = &bbs->bb_dev_health;
+	struct nvme_stats     *dev_stats = &bdh->bdh_health_state;
 
 	/*
 	 * Used for DAOS NVMe Recovery Tests. Will trigger bs faulty reaction
@@ -708,6 +709,12 @@ is_bbs_faulty(struct bio_blobstore *bbs)
 		}
 	}
 
+	/* Auto-faulty for stalled I/O stalled is always enabled */
+	if (bdh->bdh_io_stalled) {
+		D_ERROR("I/O stalled on NVMe device " DF_UUID "\n", DP_UUID(bbs->bb_dev->bb_uuid));
+		return true;
+	}
+
 	if (!glb_criteria.fc_enabled)
 		return false;
 

src/bio/bio_recovery.c

@@ -697,11 +697,20 @@ bio_media_error(void *msg_arg)
 			 "Device: "DF_UUID" csum error logged from tgt_id:%d\n",
 			 DP_UUID(mem->mem_bs->bb_dev->bb_uuid), mem->mem_tgt_id);
 		break;
+	case MET_IO_STALLED:
+		/* I/O stalling has been reported for this device */
+		if (bdh->bdh_io_stalled)
+			goto out;
+		bdh->bdh_io_stalled = 1;
+		snprintf(err_str, DAOS_RAS_STR_FIELD_SIZE,
+			 "Device: " DF_UUID " stalled I/O logged from tgt_id:%d\n",
+			 DP_UUID(mem->mem_bs->bb_dev->bb_uuid), mem->mem_tgt_id);
+		break;
 	}
 
 	ras_notify_event(RAS_DEVICE_MEDIA_ERROR, err_str, RAS_TYPE_INFO, RAS_SEV_ERROR,
 			 NULL, NULL, NULL, NULL, NULL, NULL, NULL, NULL, NULL);
+out:
 	auto_faulty_detect(mem->mem_bs);
-
 	D_FREE(mem);
 }

src/bio/bio_xstream.c

@@ -62,6 +62,7 @@ unsigned int bio_spdk_subsys_timeout = 25000;	/* ms */
 /* How many blob unmap calls can be called in a row */
 unsigned int bio_spdk_max_unmap_cnt = 32;
 unsigned int bio_max_async_sz = (1UL << 15) /* 32k */;
+unsigned int        bio_io_timeout         = 120000000; /* us, 120 seconds */
 
 struct bio_nvme_data {
 	ABT_mutex		 bd_mutex;
@@ -219,7 +220,7 @@ bio_nvme_init_ext(const char *nvme_conf, int numa_node, unsigned int mem_size,
 {
 	char		*env;
 	int		 rc, fd;
-	unsigned int	 size_mb = BIO_DMA_CHUNK_MB;
+	unsigned int     size_mb = BIO_DMA_CHUNK_MB, io_timeout_secs = 0;
 
 	if (tgt_nr <= 0) {
 		D_ERROR("tgt_nr: %u should be > 0\n", tgt_nr);
@@ -277,6 +278,16 @@ bio_nvme_init_ext(const char *nvme_conf, int numa_node, unsigned int mem_size,
 	d_getenv_uint("DAOS_MAX_ASYNC_SZ", &bio_max_async_sz);
 	D_INFO("Max async data size is set to %u bytes\n", bio_max_async_sz);
 
+	d_getenv_uint("DAOS_SPDK_IO_TIMEOUT", &io_timeout_secs);
+	if (io_timeout_secs > 0) {
+		if (io_timeout_secs < 30 || io_timeout_secs > 300)
+			D_WARN("DAOS_SPDK_IO_TIMEOUT(%u) is invalid. Min:30,Max:300,Default:120\n",
+			       io_timeout_secs);
+		else
+			bio_io_timeout = io_timeout_secs * 1000000; /* convert to us */
+	}
+	D_INFO("SPDK IO timeout set to %u us\n", bio_io_timeout);
+
 	/* Hugepages disabled */
 	if (mem_size == 0) {
 		D_INFO("Set per-xstream DMA buffer upper bound to %u %uMB chunks\n",
@@ -1241,6 +1252,7 @@ alloc_xs_blobstore(void)
 	if (bxb == NULL)
 		return NULL;
 
+	D_INIT_LIST_HEAD(&bxb->bxb_pending_ios);
 	D_INIT_LIST_HEAD(&bxb->bxb_io_ctxts);
 
 	return bxb;
@@ -1761,8 +1773,10 @@ bio_nvme_ctl(unsigned int cmd, void *arg)
 static inline void
 reset_media_errors(struct bio_blobstore *bbs)
 {
-	struct nvme_stats	*dev_stats = &bbs->bb_dev_health.bdh_health_state;
+	struct bio_dev_health *bdh       = &bbs->bb_dev_health;
+	struct nvme_stats     *dev_stats = &bdh->bdh_health_state;
 
+	bdh->bdh_io_stalled       = 0;
 	dev_stats->bio_read_errs = 0;
 	dev_stats->bio_write_errs = 0;
 	dev_stats->bio_unmap_errs = 0;
@@ -1992,5 +2006,8 @@ bio_nvme_poll(struct bio_xs_context *ctxt)
 		bio_led_event_monitor(ctxt, now);
 	}
 
+	/* Detect stalled I/Os */
+	bio_io_monitor(ctxt, now);
+
 	return rc;
 }

src/engine/sched.c

@@ -1928,7 +1928,13 @@ need_nvme_poll(struct dss_xstream *dx, struct sched_cycle *cycle)
 
 	dmi = dss_get_module_info();
 	D_ASSERT(dmi != NULL);
-	return bio_need_nvme_poll(dmi->dmi_nvme_ctxt);
+	/*
+	 * If SPDK I/O stalls indefinitely due to a hardware fault (or software bug),
+	 * the resulting backlog of undrained I/Os will cause bio_need_nvme_poll() to
+	 * consistently return true. To prevent starvation and ensure system progress,
+	 * schedule the NVMe polling ULT and other ULTs intverleavingly.
+	 */
+	return !cycle->sc_age_nvme && bio_need_nvme_poll(dmi->dmi_nvme_ctxt);
 }
 
 static ABT_unit

src/include/daos_srv/daos_engine.h

@@ -739,10 +739,11 @@ enum dss_init_state {
 };
 
 enum dss_media_error_type {
-	MET_WRITE = 0,	/* write error */
-	MET_READ,	/* read error */
-	MET_UNMAP,	/* unmap error */
-	MET_CSUM	/* checksum error */
+	MET_WRITE = 0,  /* NVME write error */
+	MET_READ,       /* NVME read error */
+	MET_UNMAP,      /* NVME unmap error */
+	MET_CSUM,       /* Checksum error */
+	MET_IO_STALLED, /* NVMe I/O stalled */
 };
 
 void dss_init_state_set(enum dss_init_state state);