Bug 2112116

commit 667ce638454d0995170dd8e6e0668ada733d72e7
Author: Attila Kovacs <attila.kovacs.edu>
Date:   Thu Jul 28 09:14:24 2022 -0400

    SUNRPC: mutexed access blacklist_read state variable.

commit 3f2a5459fb00c2f529d68a4a0fd7f367a77fa65a
Author: Attila Kovacs <attila.kovacs.edu>
Date:   Tue Jul 26 15:24:01 2022 -0400

    thread safe clnt destruction.

commit 7a6651a31038cb19807524d0422e09271c5ffec9
Author: Attila Kovacs <attila.kovacs.edu>
Date:   Tue Jul 26 15:20:05 2022 -0400

    clnt_dg_freeres() uncleared set active state may deadlock.


Author: Attila Kovacs <attila.kovacs.edu>
Date:   Wed Jul 20 17:03:28 2022 -0400

    Eliminate deadlocks in connects with an MT environment

(In reply to Attila Kovacs from comment #0)
> ...
> 
> How reproducible:
> 
> Making clnt_create calls on a multi-core system in parallel threads will
> produce the deadlock sooner or later. In our case on a 4-core x86_64 VM,
> with 8 parallel threads calling clnt_create() nearly simultaneously to 8
> different RPC hosts, the deadlock typically occurs after a few dozen
> attempts.

I have just tried this in a machine with 32 core-cpu (with 8x threads) 100 attempts but didn't trigger the hang.

I.e.
#define NFS_PROGRAM    (100003)
int main() {
    int i;
    for (i = 1; i<=256; i++) {
        char hostname[40];
        sprintf(hostname, "server%d", i);
        clnt_create(hostname, NFS_PROGRAM, 4, "tcp");
    }
}

However, I just added this scenario as our regression testcase.

(In reply to Yongcheng Yang from comment #2)
> (In reply to Attila Kovacs from comment #0)
> > ...
> > 
> > How reproducible:
> > 
> > Making clnt_create calls on a multi-core system in parallel threads will
> > produce the deadlock sooner or later. In our case on a 4-core x86_64 VM,
> > with 8 parallel threads calling clnt_create() nearly simultaneously to 8
> > different RPC hosts, the deadlock typically occurs after a few dozen
> > attempts.
> 
> I have just tried this in a machine with 32 core-cpu (with 8x threads) 100
> attempts but didn't trigger the hang.
> 
> I.e.
> #define NFS_PROGRAM    (100003)
> int main() {
>     int i;
>     for (i = 1; i<=256; i++) {
>         char hostname[40];
>         sprintf(hostname, "server%d", i);
>         clnt_create(hostname, NFS_PROGRAM, 4, "tcp");
>     }
> }
> 
> However, I just added this scenario as our regression testcase.

I assume you had server1 through server256 running NFS for the test... How did you then parallelize the above test case (the quoted test code does not have an OMP pragma -- so it seems sequential by design)?

(In reply to Attila Kovacs from comment #3)
> (In reply to Yongcheng Yang from comment #2)
> 
> I assume you had server1 through server256 running NFS for the test... How
> did you then parallelize the above test case (the quoted test code does not
> have an OMP pragma -- so it seems sequential by design)?

TBH I don't know the mean of "OMP pragma".

From my understanding it parallelize as run clnt_create() from server1 to server256. And I execute this reproducer many times sequentially then.

Am I misunderstanding?

Well without OpenMP converting the 'for' loop to a parallel execution with the:

  #pragma omp parallel for

directive directly above the 'for' statement, the loop body  is going to be executed sequentially. In that case, the clnt_create() calls in the body have no chance for racing against one another. Perhaps it's better to make the threading more explicit with pthreads. (OMP is great for quick and dirty multithreading, but it's harder to be sure that the threading actually happens, since the program will compile file even if the #pragma is not actually being used.). So here is the explicily threaded version of the test:

#define NFS_PROGRAM    (100003)
#define N_SERVERS      (256)

static void *connect_thread(void *arg) {
    return (void *) clnt_create((char *) arg, NFS_PROGRAM, 4, "tcp");
}

int main() {
     char hostname[N_SERVERS][40];
     pthread_t tid[N_SERVERS];
     int i;
 
     // Set up the server node names first...
     for (i = 1; i <= N_SERVERS; i++)
         sprintf(hostname[i], "server%d", i);

     // Create RPC clients in parallel...
     for (i = 1; i <= N_SERVERS; i++) 
         pthread_create(&tid[i], NULL, connect_thread, (void *) hostname[i]);

     // Wait for the clients to be created and check that they are valid...
     for (i = 1; i <= N_SERVERS; i++) {
         CLIENT *cl;
         pthread_join(tid[i], (void *) &cl);
         if (cl == NULL)
             fprintf(stderr, "WARNING! Client creation to %s failed.\n", hostname[i]); 
     }
}

Also, coming to think of it, server response times and/or DNS lookup times probably matter too, since they affect how long steps of the client creation take or block. In our case round-trips to the server nodes are longish, typically 2--3 ms. Perhaps that plays a role in the reproducibility. There may be other factors also... On our end the hangs are fairly commonly reproducible, but there might not be an easy way to set up a universal test that works reliably in all environments.

-- A.

Many thanks to Attila for the explanation and the pthread approach!
I can understand it now.

But looks like the response time does matter as both reproducers can't trigger the hangs in our environment.

Anyway this is a great test scenario and thank you for providing it.

I just noticed that in the pthread example, you'll need to size the arrays to [N_SERVERS+1] instead of [N_SERVERS] given the way I set up the for loops with indices starting at 1...

Also, thank you for the quick turnaround!

-- A.

This patch is also needed:

commit fa153d634228216fc162e5d6583a7035af2c40ba (HEAD -> master, tag: libtirpc-1-3-3-rc5)
Author: Attila Kovacs <attila.kovacs.edu>
Date:   Mon Aug 1 11:28:43 2022 -0400

    SUNRPC: MT-safe overhaul of address cache management in rpcb_clnt.c

https://gitlab.com/steved92/nfs-utils/-/merge_requests/new?merge_request%5B
(In reply to Steve Dickson from comment #1)
> commit 667ce638454d0995170dd8e6e0668ada733d72e7
> Author: Attila Kovacs <attila.kovacs.edu>
> Date:   Thu Jul 28 09:14:24 2022 -0400
> 
>     SUNRPC: mutexed access blacklist_read state variable.
> 
> commit 3f2a5459fb00c2f529d68a4a0fd7f367a77fa65a
> Author: Attila Kovacs <attila.kovacs.edu>
> Date:   Tue Jul 26 15:24:01 2022 -0400
> 
>     thread safe clnt destruction.
> 
> commit 7a6651a31038cb19807524d0422e09271c5ffec9
> Author: Attila Kovacs <attila.kovacs.edu>
> Date:   Tue Jul 26 15:20:05 2022 -0400
> 
>     clnt_dg_freeres() uncleared set active state may deadlock.
> 
> 
> Author: Attila Kovacs <attila.kovacs.edu>
> Date:   Wed Jul 20 17:03:28 2022 -0400
> 
>     Eliminate deadlocks in connects with an MT environment

I just wanted to confirm that with the 5 patches above, the deadlocks have stopped occurring on our systems. From my point of view, the patches constitute a 'fix' that is good to go... 

If I find the time, I may poke around looking for further MT flaws lurking in libtirpc. (Given that I found a few in the source code used by clnt_create(), there is probably room for further improvements, but that's beyond the scope of this particular bug..)

Thanks to all for being very responsive. It's been a pleasure to work with you, and I learnt a lot in the process too. To be continued...

-- A.

Hello

(In reply to Attila Kovacs from comment #9)
> I just wanted to confirm that with the 5 patches above, the deadlocks have
> stopped occurring on our systems. From my point of view, the patches
> constitute a 'fix' that is good to go... 
> 
> If I find the time, I may poke around looking for further MT flaws lurking
> in libtirpc. (Given that I found a few in the source code used by
> clnt_create(), there is probably room for further improvements, but that's
> beyond the scope of this particular bug..)
> 
> Thanks to all for being very responsive. It's been a pleasure to work with
> you, and I learnt a lot in the process too. To be continued...

I'm wondering if you might want take an additional step.... 

This RHEL8 rpm contains those five patches along with a few
patches make things apply cleanly.

https://people.redhat.com/steved/.bz2112116/libtirpc-1.1.4-8.el8.x86_64.rpm

If you would not mind throwing this rpm into your environment to
insure we have plugged all the wholes... 

Please Note: this is a per-released rpm so it is not supported... yet!
Just looking to get some additional testing we are not able to do.

tia!

Hi Steve!

Your RHEL8 test RPM is looking great from my perspective.

I ran my test a few thousand times on our 'over-sensitive' system. It seems to be working very reliably.

(And, just to be sure, I have also run the current release 1.1.4-6.el8 back-to-back -- and that one was still hanging reliably after a few dozen tries every time, just as expected).

So, it all checks out. 

Thanks again,

-- A.

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (libtirpc bug fix and enhancement update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2022:7740