[LU-15115] ptlrpc resend on EINPROGRESS timeouts can be not correct

• Type: Bug
• Resolution: Fixed
• Priority: Major
• Fix Version/s: Lustre 2.15.0
• Severity: 3
• Assignee: Alexander Zarochentsev
• Reporter: Alexander Zarochentsev

Description

It appears request resend on EINPROGRESS reply may happen not early than the request expires:

00000100:00100000:2.0:1630664693.569340:0:2236:0:(client.c:1461:after_reply()) @@@ Resending request on EINPROGRESS  req@ffff9873c9fb6300 x1709875676995456/t0(0) o36->lustre-MDT0000-mdc-ffff9873b91a8800@0@lo:12/10 lens 496/456 e 0 to 0 dl 1630664736 ref 2 fl Rpc:R/0/0 rc 0/-115 job:'unlinkmany.0'

...

00000100:00100000:2.0:1630664735.433532:0:2236:0:(niobuf.c:757:ptl_send_rpc()) @@@ Allocating new xid for resend on EINPROGRESS  req@ffff9873c9fb6300 x1709875677015680/t0(0) o36->lustre-MDT0000-mdc-ffff9873b91a8800@0@lo:12/10 lens 496/456 e 0 to 0 dl 1630664736 ref 2 fl Rpc:RS/0/0 rc 0/-115 job:'unlinkmany.0'

as you can see above, the resend is in 40 sec after getting -EINPROGRESS reply.

at the same time, after_reply() has a code snippet with another logic:

        /* retry indefinitely on EINPROGRESS */
        if (lustre_msg_get_status(req->rq_repmsg) == -EINPROGRESS &&
            ptlrpc_no_resend(req) == 0 && !req->rq_no_retry_einprogress) {
                time64_t now = ktime_get_real_seconds();

                DEBUG_REQ(req->rq_nr_resend > 0 ? D_ERROR : D_RPCTRACE, req,
                          "Resending request on EINPROGRESS");
                spin_lock(&req->rq_lock);
                req->rq_resend = 1;
                req->rq_deadline = now;
                spin_unlock(&req->rq_lock);
                req->rq_nr_resend++;

                /* Readjust the timeout for current conditions */
                ptlrpc_at_set_req_timeout(req);
                /* delay resend to give a chance to the server to get ready.
                 * The delay is increased by 1s on every resend and is capped to
                 * the current request timeout (i.e. obd_timeout if AT is off,
                 * or AT service time x 125% + 5s, see at_est2timeout) */
                if (req->rq_nr_resend > req->rq_timeout)
                        req->rq_sent = now + req->rq_timeout;
                else
                        req->rq_sent = now + req->rq_nr_resend;

Issue Links

• is related to: LU-15114 ASSERTION( atomic_read(&d->opd_sync_changes) > 0