Skip to content

Commit bf5ae50

Browse files
authored
DAOS-17353 object: reduce noisy warning for DTX refresh (#16184)
When process IO on DTX non-leader target, if hit prepared DTX, related retry logic may generate warning message for reminder before refresh related DTX. That is not fatal but some noisy. This patch controls such warning message rate to avoid flood in log: one warning message per about 10 seconds. Signed-off-by: Fan Yong <fan.yong@hpe.com>
1 parent 367d266 commit bf5ae50

File tree

5 files changed

+68
-33
lines changed

5 files changed

+68
-33
lines changed

src/object/cli_obj.c

Lines changed: 12 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
/**
22
* (C) Copyright 2016-2024 Intel Corporation.
33
* (C) Copyright 2025 Google LLC
4+
* (C) Copyright 2025 Hewlett Packard Enterprise Development LP
45
*
56
* SPDX-License-Identifier: BSD-2-Clause-Patent
67
*/
@@ -1775,8 +1776,18 @@ obj_retry_cb(tse_task_t *task, struct dc_object *obj,
17751776
}
17761777

17771778
if (!pmap_stale) {
1779+
uint32_t now = daos_gettime_coarse();
1780+
17781781
delay = dc_obj_retry_delay(task, result, &obj_auxi->retry_cnt,
17791782
&obj_auxi->inprogress_cnt, obj_auxi->max_delay);
1783+
if (result == -DER_INPROGRESS &&
1784+
((obj_auxi->retry_warn_ts == 0 && obj_auxi->inprogress_cnt >= 10) ||
1785+
(obj_auxi->retry_warn_ts > 0 && obj_auxi->retry_warn_ts + 10 < now))) {
1786+
obj_auxi->retry_warn_ts = now;
1787+
obj_auxi->flags |= ORF_MAYBE_STARVE;
1788+
D_WARN("The task %p has been retried for %u times, maybe starve\n",
1789+
task, obj_auxi->inprogress_cnt);
1790+
}
17801791
}
17811792

17821793
rc = tse_task_reinit_with_delay(task, delay);
@@ -4698,6 +4709,7 @@ obj_comp_cb(tse_task_t *task, void *data)
46984709
obj_auxi->csum_retry = 0;
46994710
obj_auxi->tx_uncertain = 0;
47004711
obj_auxi->nvme_io_err = 0;
4712+
obj_auxi->flags &= ~ORF_MAYBE_STARVE;
47014713

47024714
rc = obj_comp_cb_internal(obj_auxi);
47034715
if (rc != 0 || obj_auxi->result) {

src/object/obj_internal.h

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -486,6 +486,8 @@ struct obj_auxi_args {
486486
uint32_t flags;
487487
uint16_t retry_cnt;
488488
uint16_t inprogress_cnt;
489+
/* Last timestamp (in second) when report retry warning message. */
490+
uint32_t retry_warn_ts;
489491
struct obj_req_tgts req_tgts;
490492
d_sg_list_t *sgls_dup;
491493
crt_bulk_t *bulks;

src/object/obj_rpc.h

Lines changed: 5 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,6 @@
11
/**
22
* (C) Copyright 2016-2024 Intel Corporation.
3+
* (C) Copyright 2025 Hewlett Packard Enterprise Development LP
34
*
45
* SPDX-License-Identifier: BSD-2-Clause-Patent
56
*/
@@ -131,6 +132,7 @@ obj_opc_to_str(crt_opcode_t opc)
131132
return "unknown";
132133
}
133134

135+
/* clang-format off */
134136
enum obj_rpc_flags {
135137
ORF_BULK_BIND = (1 << 0),
136138
/** It is a resent RPC. */
@@ -167,8 +169,8 @@ enum obj_rpc_flags {
167169
ORF_CREATE_MAP_DETAIL = (1 << 13),
168170
/* For data migration. */
169171
ORF_FOR_MIGRATION = (1 << 14),
170-
/* Force DTX refresh if hit non-committed DTX on non-leader. Out-of-date DAOS-7878. */
171-
ORF_DTX_REFRESH = (1 << 15),
172+
/* Retried IO for too many times, maybe starve. */
173+
ORF_MAYBE_STARVE = (1 << 15),
172174
/* for EC aggregate (to bypass read perm check related with RF) */
173175
ORF_FOR_EC_AGG = (1 << 16),
174176
/* for EC data recovery */
@@ -190,6 +192,7 @@ enum obj_rpc_flags {
190192
/* The CPD RPC only contains read-only transaction. */
191193
ORF_CPD_RDONLY = (1 << 25),
192194
};
195+
/* clang-format on */
193196

194197
/* common for update/fetch */
195198
#define DAOS_ISEQ_OBJ_RW /* input fields */ \

src/object/obj_tx.c

Lines changed: 22 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,6 @@
11
/**
22
* (C) Copyright 2020-2024 Intel Corporation.
3+
* (C) Copyright 2025 Hewlett Packard Enterprise Development LP
34
*
45
* SPDX-License-Identifier: BSD-2-Clause-Patent
56
*/
@@ -80,14 +81,10 @@ struct dc_tx {
8081
tse_task_t *tx_orig_task;
8182
/** Transaction flags (DAOS_TF_RDONLY, DAOS_TF_ZERO_COPY, etc.) */
8283
uint64_t tx_flags;
83-
uint32_t tx_fixed_epoch:1, /** epoch is specified. */
84-
tx_retry:1, /** Retry the commit RPC. */
85-
tx_set_resend:1, /** Set 'resend' flag. */
86-
tx_for_convert:1,
87-
tx_has_cond:1,
88-
tx_renew:1,
89-
tx_closed:1,
90-
tx_reintegrating:1;
84+
uint32_t tx_fixed_epoch : 1, /** epoch is specified. */
85+
tx_retry : 1, /** Retry the commit RPC. */ tx_set_resend : 1, /** Set 'resend' flag. */
86+
tx_for_convert : 1, tx_has_cond : 1, tx_renew : 1, tx_closed : 1, tx_reintegrating : 1,
87+
tx_maybe_starve : 1;
9188
/** Transaction status (OPEN, COMMITTED, etc.), see dc_tx_status. */
9289
enum dc_tx_status tx_status;
9390
/** The rank for the server on which the TX leader resides. */
@@ -106,6 +103,8 @@ struct dc_tx {
106103

107104
uint16_t tx_retry_cnt;
108105
uint16_t tx_inprogress_cnt;
106+
/* Last timestamp (in second) when report retry warning message. */
107+
uint32_t tx_retry_warn_ts;
109108
/** Pool map version when trigger first IO. */
110109
uint32_t tx_pm_ver;
111110
/** Reference the pool. */
@@ -994,6 +993,8 @@ dc_tx_commit_cb(tse_task_t *task, void *data)
994993

995994
D_MUTEX_LOCK(&tx->tx_lock);
996995

996+
tx->tx_maybe_starve = 0;
997+
997998
if (rc == 0) {
998999
uint64_t *sub_epochs = oco->oco_sub_epochs.ca_arrays;
9991000

@@ -1091,7 +1092,18 @@ dc_tx_commit_cb(tse_task_t *task, void *data)
10911092
locked = false;
10921093

10931094
if (rc != -DER_TX_RESTART) {
1095+
uint32_t now = daos_gettime_coarse();
1096+
10941097
delay = dc_obj_retry_delay(task, rc, &tx->tx_retry_cnt, &tx->tx_inprogress_cnt, 0);
1098+
if (rc == -DER_INPROGRESS &&
1099+
((tx->tx_retry_warn_ts == 0 && tx->tx_inprogress_cnt >= 10) ||
1100+
(tx->tx_retry_warn_ts > 0 && tx->tx_retry_warn_ts + 10 < now))) {
1101+
tx->tx_retry_warn_ts = now;
1102+
tx->tx_maybe_starve = 1;
1103+
D_WARN("The dist TX task %p has been retried for %u times, maybe starve\n",
1104+
task, tx->tx_inprogress_cnt);
1105+
}
1106+
10951107
rc1 = tse_task_reinit_with_delay(task, delay);
10961108
if (rc1 != 0) {
10971109
D_ERROR("Failed to reinit task %p: %d, %d\n", task, rc1, rc);
@@ -2308,6 +2320,8 @@ dc_tx_commit_trigger(tse_task_t *task, struct dc_tx *tx, daos_tx_commit_t *args)
23082320
oci->oci_flags = ORF_LEADER;
23092321
if (tx->tx_set_resend && !tx->tx_renew)
23102322
oci->oci_flags |= ORF_RESEND;
2323+
if (tx->tx_maybe_starve)
2324+
oci->oci_flags |= ORF_MAYBE_STARVE;
23112325
tx->tx_renew = 0;
23122326
if (tx->tx_reintegrating)
23132327
oci->oci_flags |= ORF_REINTEGRATING_IO;

src/object/srv_obj.c

Lines changed: 27 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -2031,25 +2031,24 @@ obj_local_rw_internal_wrap(crt_rpc_t *rpc, struct obj_io_context *ioc, struct dt
20312031
static int
20322032
obj_local_rw(crt_rpc_t *rpc, struct obj_io_context *ioc, struct dtx_handle *dth)
20332033
{
2034+
struct obj_rw_in *orw = crt_req_get(rpc);
20342035
struct dtx_share_peer *dsp;
20352036
uint32_t retry = 0;
20362037
int rc;
20372038

20382039
again:
20392040
rc = obj_local_rw_internal_wrap(rpc, ioc, dth);
20402041
if (dth != NULL && obj_dtx_need_refresh(dth, rc)) {
2041-
if (unlikely(++retry % 10 == 9)) {
2042-
dsp = d_list_entry(dth->dth_share_tbd_list.next, struct dtx_share_peer,
2043-
dsp_link);
2044-
D_WARN("DTX refresh for "DF_DTI" because of "DF_DTI" (%d) for %d times, "
2045-
"maybe starve\n", DP_DTI(&dth->dth_xid), DP_DTI(&dsp->dsp_xid),
2046-
dth->dth_share_tbd_count, retry);
2047-
}
2048-
2049-
if (!obj_rpc_is_fetch(rpc) || retry < 30) {
2042+
if (++retry < 3) {
20502043
rc = dtx_refresh(dth, ioc->ioc_coc);
20512044
if (rc == -DER_AGAIN)
20522045
goto again;
2046+
} else if (orw->orw_flags & ORF_MAYBE_STARVE) {
2047+
dsp = d_list_entry(dth->dth_share_tbd_list.next, struct dtx_share_peer,
2048+
dsp_link);
2049+
D_WARN(
2050+
"DTX refresh for " DF_DTI " because of " DF_DTI " (%d), maybe starve\n",
2051+
DP_DTI(&dth->dth_xid), DP_DTI(&dsp->dsp_xid), dth->dth_share_tbd_count);
20532052
}
20542053
}
20552054

@@ -3565,12 +3564,16 @@ obj_local_punch(struct obj_punch_in *opi, crt_opcode_t opc, uint32_t shard_nr, u
35653564
}
35663565

35673566
if (obj_dtx_need_refresh(dth, rc)) {
3568-
if (unlikely(++retry % 10 == 9)) {
3569-
dsp = d_list_entry(dth->dth_share_tbd_list.next,
3570-
struct dtx_share_peer, dsp_link);
3571-
D_WARN("DTX refresh for "DF_DTI" because of "DF_DTI" (%d) for %d "
3572-
"times, maybe starve\n", DP_DTI(&dth->dth_xid),
3573-
DP_DTI(&dsp->dsp_xid), dth->dth_share_tbd_count, retry);
3567+
if (++retry >= 3) {
3568+
if (opi->opi_flags & ORF_MAYBE_STARVE) {
3569+
dsp = d_list_entry(dth->dth_share_tbd_list.next,
3570+
struct dtx_share_peer, dsp_link);
3571+
D_WARN("DTX refresh for " DF_DTI " because of " DF_DTI
3572+
" (%d), maybe starve\n",
3573+
DP_DTI(&dth->dth_xid), DP_DTI(&dsp->dsp_xid),
3574+
dth->dth_share_tbd_count);
3575+
}
3576+
goto out;
35743577
}
35753578

35763579
rc = dtx_refresh(dth, ioc->ioc_coc);
@@ -4955,24 +4958,25 @@ ds_cpd_handle_one_wrap(crt_rpc_t *rpc, struct daos_cpd_sub_head *dcsh,
49554958
struct daos_cpd_disp_ent *dcde, struct daos_cpd_sub_req *dcsrs,
49564959
struct obj_io_context *ioc, struct dtx_handle *dth)
49574960
{
4961+
struct obj_cpd_in *oci = crt_req_get(rpc);
49584962
struct dtx_share_peer *dsp;
49594963
uint32_t retry = 0;
49604964
int rc;
49614965

49624966
again:
49634967
rc = ds_cpd_handle_one(rpc, dcsh, dcde, dcsrs, ioc, dth);
49644968
if (obj_dtx_need_refresh(dth, rc)) {
4965-
if (unlikely(++retry % 10 == 9)) {
4969+
if (++retry < 3) {
4970+
rc = dtx_refresh(dth, ioc->ioc_coc);
4971+
if (rc == -DER_AGAIN)
4972+
goto again;
4973+
} else if (oci->oci_flags & ORF_MAYBE_STARVE) {
49664974
dsp = d_list_entry(dth->dth_share_tbd_list.next,
49674975
struct dtx_share_peer, dsp_link);
4968-
D_WARN("DTX refresh for "DF_DTI" because of "DF_DTI" (%d) for %d "
4969-
"times, maybe starve\n", DP_DTI(&dth->dth_xid),
4970-
DP_DTI(&dsp->dsp_xid), dth->dth_share_tbd_count, retry);
4976+
D_WARN(
4977+
"DTX refresh for " DF_DTI " because of " DF_DTI " (%d), maybe starve\n",
4978+
DP_DTI(&dth->dth_xid), DP_DTI(&dsp->dsp_xid), dth->dth_share_tbd_count);
49714979
}
4972-
4973-
rc = dtx_refresh(dth, ioc->ioc_coc);
4974-
if (rc == -DER_AGAIN)
4975-
goto again;
49764980
}
49774981

49784982
return rc;

0 commit comments

Comments
 (0)