SEGFAULT on OVIS-4 head #408

morrone · 2020-09-22T19:47:22Z

I am trying to test OVIS-4 at commit 8f77cd1, and I'm getting a SEGFUALT in ldmsd as soon as I hit it the first time with ldms_ls.

This is on a ppc64le machine, using rdma transport. Running the ldmsd under gdb I see:

(gdb) run  -F -c /var/run/ldmsd/all-config.local -a ovis -A conf=/root/.ldmsauth.conf -r /var/run/ldmsd/ldmsd-local.pid -x rdma:411 -P 4 -v DEBUG
Starting program: /usr/sbin/ldmsd -F -c /var/run/ldmsd/all-config.local -a ovis -A conf=/root/.ldmsauth.conf -r /var/run/ldmsd/ldmsd-local.pid -x rdma:411 -P 4 -v DEBUG
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
[New Thread 0x200000dbf1b0 (LWP 118464)]
[New Thread 0x2000011cf1b0 (LWP 118465)]
[New Thread 0x2000015df1b0 (LWP 118466)]
[New Thread 0x2000019ef1b0 (LWP 118467)]
[New Thread 0x200001dff1b0 (LWP 118468)]
[New Thread 0x20000228f1b0 (LWP 118469)]
[New Thread 0x20000269f1b0 (LWP 118470)]
[New Thread 0x200002adf1b0 (LWP 118471)]
[New Thread 0x200002f1f1b0 (LWP 118472)]
Tue Sep 22 12:36:14 2020: DEBUG     : Checking for meminfo in /usr/lib64/ovis-ldms
Tue Sep 22 12:36:14 2020: DEBUG     : msg_no 0 flags 3 rec_len 28 rsp_err 0
Tue Sep 22 12:36:14 2020: DEBUG     : msg_no 1 flags 3 rec_len 28 rsp_err 0
Tue Sep 22 12:36:14 2020: DEBUG     : msg_no 2 flags 3 rec_len 28 rsp_err 0
Tue Sep 22 12:36:14 2020: INFO      : Processing the config file '/var/run/ldmsd/all-config.local' is done.
[New Thread 0x20000359f1b0 (LWP 118473)]
[New Thread 0x2000039af1b0 (LWP 118474)]
Tue Sep 22 12:36:14 2020: INFO      : meminfo: The job data set named, job_info, does not exist. Valid job data will not be associated with the metric values.
Tue Sep 22 12:36:15 2020: INFO      : Listening on rdma:411 using `rdma` transport and `ovis` authentication
Tue Sep 22 12:36:15 2020: INFO      : Enabling in-band config

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x2000015df1b0 (LWP 118466)]
__GI___pthread_mutex_lock (mutex=0x0) at ../nptl/pthread_mutex_lock.c:65
65        unsigned int type = PTHREAD_MUTEX_TYPE_ELISION (mutex);

Backtrace of thread 118466:

Thread 4 (Thread 0x2000015df1b0 (LWP 118466)):
#0  __GI___pthread_mutex_lock (mutex=0x0) at ../nptl/pthread_mutex_lock.c:65
#1  0x000020000039bb60 in pthread_mutex_lock (mutex=<optimized out>) at forward.c:192
#2  0x00002000001d23b0 in zap_event_thread_proc () from /lib64/libzap.so.0
#3  0x00002000007a8cd4 in start_thread (arg=0x2000015df1b0) at pthread_create.c:309
#4  0x0000200000387e14 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:104

The text was updated successfully, but these errors were encountered:

morrone · 2020-09-22T20:04:42Z

To elaborate, this is completely reproducible. It happens every time for me the first time that I run ldms_ls against the ldmsd.

Here is a little more info from another gdb session. I will include all of the threads' backtraces this time. Note that one of the other threads is always in write() under ibv_cmd_dereg_mr(). Maybe that is relevant?

Thread 12 (Thread 0x2000039af1b0 (LWP 120902)):
#0  0x00002000003889a8 in epoll_wait () at ../sysdeps/unix/syscall-template.S:81
#1  0x0000200002f64da0 in cm_thread_proc (arg=<optimized out>) at zap_rdma.c:1731
#2  0x00002000007a8cd4 in start_thread (arg=0x2000039af1b0) at pthread_create.c:309
#3  0x0000200000387e14 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:104

Thread 11 (Thread 0x20000359f1b0 (LWP 120901)):
#0  0x0000200000371698 in write () at ../sysdeps/unix/syscall-template.S:81
#1  0x0000200003027184 in ibv_cmd_dereg_mr () from /lib64/libibverbs.so.1
#2  0x0000200003f31054 in mlx5_dereg_mr () from /lib64/libmlx5-rdmav2.so
#3  0x0000200003f38704 in mlx5_exp_dereg_mr () from /lib64/libmlx5-rdmav2.so
#4  0x0000200003032204 in ibv_dereg_mr () from /lib64/libibverbs.so.1
#5  0x0000200002f65cb0 in __rdma_buffer_free (rbuf=0x2000080101c0) at zap_rdma.c:390
#6  process_send_wc (rep=0x200004004a60, wc=0x20000359e488, rb=0x2000080101c0) at zap_rdma.c:832
#7  cq_event_handler (cq=0x200008002c60, count=<optimized out>) at zap_rdma.c:1139
#8  0x0000200002f66628 in cq_thread_proc (arg=<optimized out>) at zap_rdma.c:1224
#9  0x00002000007a8cd4 in start_thread (arg=0x20000359f1b0) at pthread_create.c:309
#10 0x0000200000387e14 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:104

Thread 10 (Thread 0x200002f1f1b0 (LWP 120900)):
#0  0x00002000003889a8 in epoll_wait () at ../sysdeps/unix/syscall-template.S:81
#1  0x0000200000742614 in ovis_scheduler_loop (m=0x100951e0, return_on_empty=<optimized out>) at ovis_event.c:667
#2  0x000000001000bccc in event_proc (v=<optimized out>) at ldmsd.c:1433
#3  0x00002000007a8cd4 in start_thread (arg=0x200002f1f1b0) at pthread_create.c:309
#4  0x0000200000387e14 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:104

Thread 9 (Thread 0x200002adf1b0 (LWP 120899)):
#0  0x00002000003889a8 in epoll_wait () at ../sysdeps/unix/syscall-template.S:81
#1  0x0000200000742614 in ovis_scheduler_loop (m=0x10094930, return_on_empty=<optimized out>) at ovis_event.c:667
#2  0x000000001000bccc in event_proc (v=<optimized out>) at ldmsd.c:1433
#3  0x00002000007a8cd4 in start_thread (arg=0x200002adf1b0) at pthread_create.c:309
#4  0x0000200000387e14 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:104

Thread 8 (Thread 0x20000269f1b0 (LWP 120898)):
#0  0x00002000003889a8 in epoll_wait () at ../sysdeps/unix/syscall-template.S:81
#1  0x0000200000742614 in ovis_scheduler_loop (m=0x10094080, return_on_empty=<optimized out>) at ovis_event.c:667
#2  0x000000001000bccc in event_proc (v=<optimized out>) at ldmsd.c:1433
#3  0x00002000007a8cd4 in start_thread (arg=0x20000269f1b0) at pthread_create.c:309
#4  0x0000200000387e14 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:104

Thread 7 (Thread 0x20000228f1b0 (LWP 120897)):
#0  0x00002000003889a8 in epoll_wait () at ../sysdeps/unix/syscall-template.S:81
#1  0x0000200000742614 in ovis_scheduler_loop (m=0x100737c0, return_on_empty=<optimized out>) at ovis_event.c:667
#2  0x000000001000bccc in event_proc (v=<optimized out>) at ldmsd.c:1433
#3  0x00002000007a8cd4 in start_thread (arg=0x20000228f1b0) at pthread_create.c:309
#4  0x0000200000387e14 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:104

Thread 6 (Thread 0x200001dff1b0 (LWP 120896)):
#0  0x000020000033eb88 in nanosleep () at ../sysdeps/unix/syscall-template.S:81
#1  0x000020000033e8bc in __sleep (seconds=0) at ../sysdeps/unix/sysv/linux/sleep.c:137
#2  0x00002000000c8624 in delete_proc (arg=<optimized out>) at ldms.c:2665
#3  0x00002000007a8cd4 in start_thread (arg=0x200001dff1b0) at pthread_create.c:309
#4  0x0000200000387e14 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:104

Thread 5 (Thread 0x2000019ef1b0 (LWP 120895)):
#0  0x00002000007ae92c in __pthread_cond_wait (cond=0x10071860, mutex=0x10071838) at pthread_cond_wait.c:153
#1  0x000020000039b800 in __pthread_cond_wait (cond=<optimized out>, mutex=<optimized out>) at forward.c:149
#2  0x00002000001d22fc in zap_event_thread_proc (arg=0x10071828) at zap.c:692
#3  0x00002000007a8cd4 in start_thread (arg=0x2000019ef1b0) at pthread_create.c:309
#4  0x0000200000387e14 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:104

Thread 4 (Thread 0x2000015df1b0 (LWP 120894)):
#0  __GI___pthread_mutex_lock (mutex=0x0) at ../nptl/pthread_mutex_lock.c:65
#1  0x000020000039bb60 in pthread_mutex_lock (mutex=<optimized out>) at forward.c:192
#2  0x00002000001d23b0 in zap_event_thread_proc (arg=0x10071770) at zap.c:688
#3  0x00002000007a8cd4 in start_thread (arg=0x2000015df1b0) at pthread_create.c:309
#4  0x0000200000387e14 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:104

Thread 3 (Thread 0x2000011cf1b0 (LWP 120893)):
#0  0x00002000007ae92c in __pthread_cond_wait (cond=0x100716f0, mutex=0x100716c8) at pthread_cond_wait.c:153
#1  0x000020000039b800 in __pthread_cond_wait (cond=<optimized out>, mutex=<optimized out>) at forward.c:149
#2  0x00002000001d22fc in zap_event_thread_proc (arg=0x100716b8) at zap.c:692
#3  0x00002000007a8cd4 in start_thread (arg=0x2000011cf1b0) at pthread_create.c:309
#4  0x0000200000387e14 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:104

Thread 2 (Thread 0x200000dbf1b0 (LWP 120892)):
#0  0x00002000007ae92c in __pthread_cond_wait (cond=0x10071638, mutex=0x10071610) at pthread_cond_wait.c:153
#1  0x000020000039b800 in __pthread_cond_wait (cond=<optimized out>, mutex=<optimized out>) at forward.c:149
#2  0x00002000001d22fc in zap_event_thread_proc (arg=0x10071600) at zap.c:692
#3  0x00002000007a8cd4 in start_thread (arg=0x200000dbf1b0) at pthread_create.c:309
#4  0x0000200000387e14 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:104

Thread 1 (Thread 0x200000049b60 (LWP 120891)):
#0  0x000020000033eb88 in nanosleep () at ../sysdeps/unix/syscall-template.S:81
#1  0x000020000037ac78 in usleep (useconds=<optimized out>) at ../sysdeps/unix/sysv/linux/usleep.c:32
#2  0x000000001000ad38 in main (argc=<optimized out>, argv=<optimized out>) at ldmsd.c:2218

tom95858 · 2020-09-22T20:23:51Z

@narategithub could you please take a look at this. This logic is unchanged, but I don't think we have tested recently on a PPC machine. Absent memory corruption of some kind, it's not obvious how this is happening. The initialization code is here:

static void __attribute__ ((constructor)) cs_init(void)
{
	int i;
	int rc;
	pthread_atfork(NULL, NULL, cs_init);
	pthread_mutex_init(&zap_list_lock, 0);

	zap_event_workers = ZAP_ENV_INT(ZAP_EVENT_WORKERS);
	zap_event_qdepth = ZAP_ENV_INT(ZAP_EVENT_QDEPTH);

	zev_queue = malloc(zap_event_workers * sizeof(*zev_queue));
	assert(zev_queue);

	for (i = 0; i < zap_event_workers; i++) {
		zap_event_queue_init(&zev_queue[i], zap_event_qdepth);
		rc = pthread_create(&zev_queue[i].thread, NULL,
					zap_event_thread_proc, &zev_queue[i]);
		assert(rc == 0);
	}
}

Also, if the cs_init library function is not being called at fork-time, this could happen.

narategithub · 2020-09-23T04:15:45Z

I'm leaning towards memory corruption. The reason is that from the back trace, the pointer to the mutex supplied to pthread_mutex_lock() is NULL. I believe it comes from line 688 in zap.c https://github.com/ovis-hpc/ovis/blob/OVIS-4/lib/src/zap/zap.c#L688 pthread_mutex_lock(&q->mutex);. Even if q is NULL, &q->mutex won't because mutex is not the first field of struct zap_event_queue. I looked into glibc ntpl/forward.c and ntpl/pthread_mutex_lock.c (ver 2.17), the mutex parameter is the mutex pointer passed to pthread_mutex_lock(). So, &q->mutex must be NULL.

Do we have any PPC machine to test it out?

morrone · 2020-09-23T04:34:52Z

I can play testing monkey if you want to feed me patches with extra debugging or something.

tom95858 · 2020-09-30T00:06:59Z

Hi @morrone, I have compiled, built and tested OVIS-4 top of tree on:

Red Hat Enterprise Linux Server release 7.6 (Maipo)
Linux vortex60 4.14.0-115.21.2.1chaos.ch6a.ppc64le ldmsd: Unsupported sampler plugins #1 SMP Fri May 22 11:01:06 PDT 2020 ppc64le ppc64le ppc64le GNU/Linux

I cannot reproduce this problem, but will keep testing. Can you please send me your sampler config? I just loaded meminfo and ran ldms_ls against it.

BTW, one thing you might try is look at your LD_LIBRARY_PATH, LDMSD_PLUGIN_PATH, and ZAP_LIBPATH and make certain you are picking up the right code.

morrone · 2020-09-30T00:22:25Z

@tom95858 Same kernel version. I don't think paths are related, because the install was at the system level from a packaged rpm.

I believe that I was using auth_munge. I think I only had meminfo enabled, but I could be wrong. I was switching between alot of different configurations. I'll build and retest tomorrow with a new config I've finally eliminated the genders stuff today. I'll try with that when I restest.

morrone · 2020-09-30T02:13:54Z

@tom95858 well, now the problem is gone. There are a whole lot of parts that changed, so it is hard to say which part was the cause. This ticket might not have anywhere to go now, though.

tom95858 · 2020-10-20T01:51:52Z

@morrone, can we close this?

morrone · 2020-10-20T03:25:27Z

Yes, that is fine.

morrone closed this as completed Oct 20, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

SEGFAULT on OVIS-4 head #408

SEGFAULT on OVIS-4 head #408

morrone commented Sep 22, 2020

morrone commented Sep 22, 2020

tom95858 commented Sep 22, 2020

narategithub commented Sep 23, 2020

morrone commented Sep 23, 2020

tom95858 commented Sep 30, 2020

morrone commented Sep 30, 2020

morrone commented Sep 30, 2020 •

edited

Loading

tom95858 commented Oct 20, 2020

morrone commented Oct 20, 2020

SEGFAULT on OVIS-4 head #408

SEGFAULT on OVIS-4 head #408

Comments

morrone commented Sep 22, 2020

morrone commented Sep 22, 2020

tom95858 commented Sep 22, 2020

narategithub commented Sep 23, 2020

morrone commented Sep 23, 2020

tom95858 commented Sep 30, 2020

morrone commented Sep 30, 2020

morrone commented Sep 30, 2020 • edited Loading

tom95858 commented Oct 20, 2020

morrone commented Oct 20, 2020

morrone commented Sep 30, 2020 •

edited

Loading