__lll_lock_wait allowing only one thread to work

Could you provide some more details about your application?

Is there only one thread that uses the optimizer or is the optimizer used from many threads?

Do the threads frequently create and destroy optimizer problems? Is the solution time of a problem small when compared to the problem creation time?

Several threads build their problem and optimize them in a concurrent fashion. While each of the threads do create and destroy several problems, a comparison with an open source solver that's also integrated with the application yields a CPU usage 30 times higher and much faster execution times.

The debug clearly shows threads are waiting for a mutex. There must be a bug in the program for sure, I just need to figure out why XPRESS would wrap destroyprob around a mutex and why I am hitting it as it would make sense that such operation could be done in parallel.

See the following GDB output:

(gdb) thread 50
 
[Switching to thread 50 (Thread 0x7fff2bbfe700 (LWP 2011467))]
 
#0 0x00007ffff7bc175d in __lll_lock_wait () from /lib64/libpthread.so.0
 
(gdb) frame 5
 
#5 0x00000000004c0d0a in RESOLVER (this=0x7fff205890b8) at ../../rchlib/mat/umipsimplex_xprs.pas:829
 
829      XPRSdestroyprob(pxprs);
 
(gdb) print @pxprs
 
warning: can't find linker symbol for virtual table for `TMIPSIMPLEX_XPRS' value
 
$6 = (^XPRSPROB) 0x7fff205891c0
 
(gdb) thread 49
 
[Switching to thread 49 (Thread 0x7fff2bfff700 (LWP 2011466))]
 
#0 0x00007ffff7bc175d in __lll_lock_wait () from /lib64/libpthread.so.0
 
(gdb) frame 5
 
#5 0x00000000004c0d0a in RESOLVER (this=0x7fff1c5640e8) at ../../rchlib/mat/umipsimplex_xprs.pas:829
 
829      XPRSdestroyprob(pxprs);
 
(gdb) print @pxprs
 
warning: can't find linker symbol for virtual table for `TMIPSIMPLEX_XPRS' value
 
$7 = (^XPRSPROB) 0x7fff1c5641f0

Both threads are waiting on XPRSdestroyprob and I understand that both problems appear to be in different memory positions (which is to be expected, but this is a confirmation).

I don't think there is a bug in your code. I checked the Xpress source code and the whole XPRSdestroyprob() function is indeed guarded by a global lock. I am investigating whether this can be relaxed but at the moment I don't think there is anything you can do to avoid this lock.

One option might be to not destroy problems on a thread but instead reuse them as much as possible without explicitly destroying them. For example, you could store the problem instance in a thread-local variable. Then, at the time you would call XPRScreateprob() you check whether the thread-local instance is non-NULL, you reuse that instance. Otherwise you create a new instance (and store it in the thread-local variable for later use). At the end of the thread you check whether the thread local variable is non-NULL and if so you destroy the respective problem instance.

Another option would be to use a problem pool and instead of XPRSdestroyprob() but problems into that pool. That may however cause unwanted inter-thread-dependencies in your application.

One question that is still open: are your threads hammering on XPRSdestroyprob()? This function should usually be reasonably fast but if there are many threads that call this frequently or at the same time then I can see how you can observe the slowdown you report.

Your suggestion makes sense. CPU usage went up considerably, but still lower than expected and still displaying most threads waiting. Have a look at this:

(gdb) thread 45
[Switching to thread 45 (Thread 0x7fff693f4700 (LWP 2016384))]
#0  0x00007ffff7bc175d in __lll_lock_wait () from /lib64/libpthread.so.0
(gdb) frame 14
#14 0x00000000004c1959 in RESOLVER (this=0x7fff38562bb8) at ../../rchlib/mat/umipsimplex_xprs.pas:964
964         xprserrCode:=XPRSmipoptimize(pxprs,'d');
(gdb) print @pxprs
warning: can't find linker symbol for virtual table for `TMIPSIMPLEX_XPRS' value
$1 = (^XPRSPROB) 0x7fff38562cc0
(gdb) thread 46
[Switching to thread 46 (Thread 0x7fff68ff3700 (LWP 2016385))]
#0  0x00007ffff7bc175d in __lll_lock_wait () from /lib64/libpthread.so.0
(gdb) frame 14
#14 0x00000000004c1959 in RESOLVER (this=0x7fff2c649218) at ../../rchlib/mat/umipsimplex_xprs.pas:964
964         xprserrCode:=XPRSmipoptimize(pxprs,'d');
(gdb) print @pxprs
warning: can't find linker symbol for virtual table for `TMIPSIMPLEX_XPRS' value
$2 = (^XPRSPROB) 0x7fff2c649320

The problems are being created once, i.e. no XPRScreateprob and XPRSdestroyprob everytime.

This is the full stack, if it is of any help. The issue regarding the mutex is now in XPRSmipoptimize.

#0  0x00007ffff7bc175d in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x00007ffff7bbab44 in pthread_mutex_lock () from /lib64/libpthread.so.0
#2  0x00007ffff62981c1 in ?? () from /opt/xpressmp/lib/libxprs.so.41
#3  0x00007ffff5353605 in ?? () from /opt/xpressmp/lib/libxprs.so.41
#4  0x00007ffff6b608c8 in ?? () from /opt/xpressmp/lib/libxprs.so.41
#5  0x00007ffff6b6007a in ?? () from /opt/xpressmp/lib/libxprs.so.41
#6  0x00007ffff6b5ffcc in ?? () from /opt/xpressmp/lib/libxprs.so.41
#7  0x00007ffff556e680 in ?? () from /opt/xpressmp/lib/libxprs.so.41
#8  0x00007ffff50036b2 in ?? () from /opt/xpressmp/lib/libxprs.so.41
#9  0x00007ffff555efb0 in ?? () from /opt/xpressmp/lib/libxprs.so.41
#10 0x00007ffff555f4cd in ?? () from /opt/xpressmp/lib/libxprs.so.41
#11 0x00007ffff555fdd1 in XPRSmaxim_internal () from /opt/xpressmp/lib/libxprs.so.41
#12 0x00007ffff555f7bd in XPRSmipoptimize_internal () from /opt/xpressmp/lib/libxprs.so.41
#13 0x00007ffff48a711d in XPRSmipoptimize () from /opt/xpressmp/lib/libxprs.so.41
#14 0x00000000004c1959 in RESOLVER (this=0x7fff2c649218) at ../../rchlib/mat/umipsimplex_xprs.pas:964

Also:

$ optimizer --version
FICO Xpress Solver 64bit v9.0.2 Jan 13 2023
(c) Copyright Fair Isaac Corporation 1983-2023. All rights reserved
 Optimizer v41.01.03    [/opt/xpressmp/lib/libxprs.so.41.01.03]

It is hard to tell what exactly is happening here. Could you provide more details about your code or maybe a code sample? I would have to try to reproduce the behavior here to see where and why the probs are still acquiring global locks.

Just to be sure: in each of the threads you explicitly set the XPRS_THREADS control to 1? Otherwise you may end up with a multi-threaded solve in each thread and that may result in quite some oversubscription of your CPUs.

Quick update, I wasn't setting the XPRS_THREADS to 1, now I am doing it like this:

XPRSsetintcontrol(pxprs, XPRS_THREADS, 1);

The value of XPRS_THREADS being set is 8278:

But I appear to have broken something as I am getting this written to the log (this is a log for a specific XPRSmipoptimize for a specific thread, i.e. no output from mixed sources):

Reading Problem MipSimplex
Problem Statistics
          33 (      0 spare) rows
         162 (      0 spare) structural columns
         251 (      0 spare) non-zero elements
MIP Entity Statistics
           5 entities        0 sets        0 set members
FICO Xpress v9.0.2, Hyper, solve started 10:11:31, Apr 13, 2023
Heap usage: 185KB (peak 2946KB, 70MB system)
Maximizing MILP MipSimplex using 1 thread and up to 125GB memory, with these control settings:
THREADS = 1
Original problem has:
        33 rows          162 cols          251 elements         5 entities
Presolved problem has:
        17 rows           80 cols          113 elements         4 entities
Presolve finished in 0 seconds
Heap usage: 233KB (peak 2946KB, 70MB system)
 
Coefficient range                    original                 solved
  Coefficients   [min,max] : [ 1.12e-02,  1.43e+02] / [ 6.25e-02,  2.00e+00]
  RHS and bounds [min,max] : [ 4.37e-10,  8.21e+07] / [ 7.66e-02,  1.18e+03]
  Objective      [min,max] : [ 1.00e-02,  1.29e+05] / [ 1.00e-02,  4.30e+05]
Autoscaling applied standard scaling
 
?9999 Error: Unexpected system error (code 24) while Opening /proc/meminfo
?9999 Error: An error occurred within the Xpress solver (RETURN_STATUS_UNKNOWN)
 *** Search unfinished ***    Time:     0.03 Nodes:          0
  Solution time / primaldual integral :      0.03s/ 100.000000%
  Number of solutions found / nodes   :         0 /         0

(Note the log showing THREADS set to 1)

I will be looking into it.

Thank you!

Also, while I'm not denying that oversubscription may be occurring, I do still have to insist on the fact that the GDB debugger shows threads as being waiting on the mutex lock.

I am not denying that there is bottleneck with the mutexes. I am trying to understand what causes this bottleneck and what are the situations in which multiple threads would acquire a global lock.

I don't think you broke anything by switching to single-threaded. Xpress parses /proc/meminfo. If this happens from many different threads at the same time, then it is not out of question that you get an EMFILE (24, "too many open files") error. It seems that now many threads attempt to access this file simultaneously and hit this limit. Would it be an option to increase the limit on open files to work around this problem?

Alternatively, could you set the TREEMEMORYLIMIT control (see https://www.fico.com/fico-xpress-optimization/docs/latest/solver/optimizer/HTML/TREEMEMORYLIMIT.html)? That should cut back on the reading of /proc/meminfo.