Bug 45601
| Summary: | hangs on access to /etc/pve (freeze in pmxcfs) | ||
|---|---|---|---|
| Product: | Sisyphus | Reporter: | Vitaly Lipatov <lav> |
| Component: | pve-cluster | Assignee: | Alexey Shabalin <shaba> |
| Status: | CLOSED WORKSFORME | QA Contact: | qa-sisyphus |
| Severity: | normal | ||
| Priority: | P5 | CC: | darisishe, shaba, shrek |
| Version: | unstable | ||
| Hardware: | x86_64 | ||
| OS: | Linux | ||
It hangs on rrdcached access via rrd_client_update
(gdb) info threads
Id Target Id Frame
* 1 Thread 0x7f665918ba00 (LWP 3193) "pmxcfs" futex_abstimed_wait_cancelable (private=0, abstime=0x0, clockid=0, expected=0, futex_word=0x7ffe6657f8e0) at ../sysdeps/nptl/futex-internal.h:320
2 Thread 0x7f6659156640 (LWP 3194) "cfs_loop" 0x00007f665a089856 in epoll_wait (epfd=8, events=events@entry=0x7f6659155990, maxevents=maxevents@entry=12, timeout=timeout@entry=999)
at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
3 Thread 0x7f6658934640 (LWP 3318) "server" __libc_recv (flags=<optimized out>, len=4096, buf=0x7f665a1de290 <default_client+16>, fd=21) at ../sysdeps/unix/sysv/linux/recv.c:28
4 Thread 0x7f6653fff640 (LWP 3319) "pmxcfs" __libc_read (nbytes=135168, buf=0x7f6658112010, fd=7) at ../sysdeps/unix/sysv/linux/read.c:26
5 Thread 0x7f66537fe640 (LWP 3320) "pmxcfs" syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
(gdb) thread 3
[Switching to thread 3 (Thread 0x7f6658934640 (LWP 3318))]
#0 __libc_recv (flags=<optimized out>, len=4096, buf=0x7f665a1de290 <default_client+16>, fd=21) at ../sysdeps/unix/sysv/linux/recv.c:28
28 return SYSCALL_CANCEL (recvfrom, fd, buf, len, flags, NULL, NULL);
(gdb) bt
#0 __libc_recv (flags=<optimized out>, len=4096, buf=0x7f665a1de290 <default_client+16>, fd=21) at ../sysdeps/unix/sysv/linux/recv.c:28
#1 __libc_recv (fd=21, buf=buf@entry=0x7f665a1de290 <default_client+16>, len=len@entry=4096, flags=flags@entry=0) at ../sysdeps/unix/sysv/linux/recv.c:23
#2 0x00007f665a1b88bc in recv (__flags=0, __n=4096, __buf=0x7f665a1de290 <default_client+16>, __fd=<optimized out>) at /usr/include/bits/socket2.h:44
#3 recvline (client=client@entry=0x7f665a1de280 <default_client>, buf=buf@entry=0x7f66589306b0 "", n=4095) at rrd_client.c:526
#4 0x00007f665a1b8bd4 in recvline (n=4096, buf=0x7f66589306b0 "", client=0x7f665a1de280 <default_client>) at rrd_client.c:514
#5 response_read (client=client@entry=0x7f665a1de280 <default_client>, ret_response=ret_response@entry=0x7f6658931700) at rrd_client.c:588
#6 0x00007f665a1b9373 in request (buffer=0x7f6658931790 "update /var/lib/rrdcached/db/pve2-node/aspetos 1679411717:1.24:32:0:0:134163562496:1661198336:134179975168:0:1882764304384:12975132672:693041:297340\n", buffer_size=0,
ret_response=0x7f6658931788, client=0x7f665a1de280 <default_client>) at rrd_client.c:692
#7 request (client=client@entry=0x7f665a1de280 <default_client>,
buffer=buffer@entry=0x7f6658931790 "update /var/lib/rrdcached/db/pve2-node/aspetos 1679411717:1.24:32:0:0:134163562496:1661198336:134179975168:0:1882764304384:12975132672:693041:297340\n", buffer_size=<optimized out>,
ret_response=ret_response@entry=0x7f6658931788) at rrd_client.c:671
#8 0x00007f665a1b9c07 in rrd_client_update (client=client@entry=0x7f665a1de280 <default_client>, filename=filename@entry=0x7f664c005950 "/var/lib/rrdcached/db/pve2-node/aspetos", values_num=1486038928, values_num@entry=1,
values=values@entry=0x7f6658933800) at rrd_client.c:1090
#9 0x00007f665a1b9cb0 in rrdc_update (filename=0x7f664c005950 "/var/lib/rrdcached/db/pve2-node/aspetos", values_num=1, values=0x7f6658933800) at rrd_client.c:1109
#10 0x00005571d2457853 in update_rrd_data (len=<optimized out>, data=<optimized out>, key=<optimized out>) at status.c:1374
#11 rrdentry_hash_set (rrdhash=0x2, key=0x7f664c005950 "/var/lib/rrdcached/db/pve2-node/aspetos", data=0x7f66500cfe0c "1679411717:1.24:32:0:0:134163562496:1661198336:134179975168:0:1882764304384:12975132672:693041:297340",
len=140077549434880) at status.c:1523
#12 0x00005571d245ad16 in cfs_status_set (key=<optimized out>, data=0x7f66500cfe08, len=len@entry=106) at status.c:1697
#13 0x00005571d2455ef2 in s1_msg_process_fn (c=0x7f664c006900, data=<optimized out>, size=<optimized out>) at server.c:234
#14 0x00007f665a4af409 in _process_request_ (ms_timeout=10, c=0x7f664c006900) at ipcs.c:699
#15 qb_ipcs_dispatch_connection_request (fd=<optimized out>, revents=<optimized out>, data=0x7f664c006900) at ipcs.c:801
#16 0x00007f665a4ab5df in _poll_dispatch_and_take_back_ (item=0x7f664c0012e8, p=<optimized out>) at loop_poll.c:109
#17 0x00007f665a4ab3fc in qb_loop_run_level (level=<optimized out>) at loop.c:43
#18 qb_loop_run (lp=<optimized out>) at loop.c:211
#19 0x00005571d2455833 in worker_thread (data=<optimized out>) at server.c:592
#20 0x00007f665a3ea1cd in g_thread_proxy (data=0x5571d400d060) at ../glib/gthread.c:826
#21 0x00007f665a169eb0 in start_thread (arg=0x7f6658934640) at pthread_create.c:463
#22 0x00007f665a08952f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
Вроде как помогло выключение инициализации сервиса rrrdcached через сокет: # systemctl disable rrdcached.socket Removed /etc/systemd/system/sockets.target.wants/rrdcached.socket. И включение через rdcached.service (хотя и без него работает вроде как). rdcached нужен для pve, он в нем кэштрует графики загрузки процессора и т.п. при этом сами rrd лежат в /etc/pve. Вполне возможно, что есть гонка, кто-то рано стучится в сокет и запускается сервис раньше положенного. Если в этом и есть проблема, то можно вообще убрать socket файл из пакета. (Ответ для Alexey Shabalin на комментарий #3) > rdcached нужен для pve, он в нем кэштрует графики загрузки процессора и т.п. > при этом сами rrd лежат в /etc/pve. > Вполне возможно, что есть гонка, кто-то рано стучится в сокет и запускается > сервис раньше положенного. Если в этом и есть проблема, то можно вообще > убрать socket файл из пакета. Мы не могли воспроизвести проблему на тестовом стенде. Если проблема встречается, то проще убрать socket-файл и прописать обязательство запускать rrdcached явно. (Ответ для Vitaly Lipatov на комментарий #2) > Вроде как помогло выключение инициализации сервиса rrrdcached через сокет: > # systemctl disable rrdcached.socket > Removed /etc/systemd/system/sockets.target.wants/rrdcached.socket. Напоролся ещё раз на новой машине после очередной перезагрузки. Выключение инициализации через сокет помогло. |
Description
Vitaly Lipatov 2023-03-21 03:40:13 MSKSteps to reproduce on a machine with PVE installed: 0. Preparing # killall -9 pmxcfs # umount /etc/pve -l 1. Run pmxcfs manually: # pmxcfs -l -f -d 2. Access to /etc/pve: # ls /etc/pve last message on this access: [main] debug: enter cfs_plug_link_getattr (cfs-plug-link.c:58:cfs_plug_link_getattr) The code: static int cfs_plug_link_getattr(cfs_plug_t *plug, const char *path, struct stat *stbuf) { g_return_val_if_fail(plug != NULL, PARAM_CHECK_ERRNO); g_return_val_if_fail(plug->ops == &cfs_ops, PARAM_CHECK_ERRNO); g_return_val_if_fail(path != NULL, PARAM_CHECK_ERRNO); g_return_val_if_fail(stbuf != NULL, PARAM_CHECK_ERRNO); cfs_debug("enter cfs_plug_link_getattr %s", path); memset(stbuf, 0, sizeof(struct stat)); if (cfs_is_quorate()) { stbuf->st_mode = S_IFLNK | 0777; } else { stbuf->st_mode = S_IFLNK | 0555; } stbuf->st_nlink = 1; return 0; } gdb shows after install pve-cluster-debuginfo pmxcfs hungs on cfs_is_quorate() call 1948 gboolean 1949 cfs_is_quorate(void) 1950 { 1951 g_mutex_lock (&mutex); 1952 gboolean res = cfs_status.quorate; 1953 g_mutex_unlock (&mutex); 1954 1955 return res; 1951 g_mutex_lock (&mutex); (gdb) s g_mutex_lock (mutex=0x555555584a60 <mutex>) at ../glib/gthread-posix.c:1515 1515 if G_UNLIKELY (g_atomic_int_add (&mutex->i[0], 1) != 0) 1516 g_mutex_lock_slowpath (mutex); g_mutex_lock_slowpath (mutex=0x555555584a60 <mutex>) at ../glib/gthread-posix.c:1491 1491 while (exchange_acquire (&mutex->i[0], 2) != 0) 1492 syscall (__NR_futex, &mutex->i[0], (gsize) FUTEX_WAIT_PRIVATE, (gsize) 2, NULL); (hung)