Bug 1794964 - [abrt] ModemManager: linux_pthread_proxy(): ModemManager killed by SIGTRAP
Summary: [abrt] ModemManager: linux_pthread_proxy(): ModemManager killed by SIGTRAP
Keywords:
Status: CLOSED EOL
Alias: None
Product: Fedora
Classification: Fedora
Component: glib2
Version: 32
Hardware: x86_64
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Lubomir Rintel
QA Contact: Fedora Extras Quality Assurance
URL: https://retrace.fedoraproject.org/faf...
Whiteboard: abrt_hash:ab327d7240c836e8e74feb57a6c...
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2020-01-25 21:06 UTC by Matt Fagnani
Modified: 2021-05-25 15:17 UTC (History)
12 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2021-05-25 15:17:56 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)
File: backtrace (17.82 KB, text/plain)
2020-01-25 21:06 UTC, Matt Fagnani
no flags Details
File: core_backtrace (6.61 KB, text/plain)
2020-01-25 21:06 UTC, Matt Fagnani
no flags Details
File: cpuinfo (2.26 KB, text/plain)
2020-01-25 21:06 UTC, Matt Fagnani
no flags Details
File: dso_list (2.60 KB, text/plain)
2020-01-25 21:06 UTC, Matt Fagnani
no flags Details
File: environ (190 bytes, text/plain)
2020-01-25 21:06 UTC, Matt Fagnani
no flags Details
File: limits (1.29 KB, text/plain)
2020-01-25 21:06 UTC, Matt Fagnani
no flags Details
File: maps (17.12 KB, text/plain)
2020-01-25 21:06 UTC, Matt Fagnani
no flags Details
File: mountinfo (3.14 KB, text/plain)
2020-01-25 21:06 UTC, Matt Fagnani
no flags Details
File: open_fds (399 bytes, text/plain)
2020-01-25 21:06 UTC, Matt Fagnani
no flags Details
File: proc_pid_status (1.29 KB, text/plain)
2020-01-25 21:06 UTC, Matt Fagnani
no flags Details
File: var_log_messages (272 bytes, text/plain)
2020-01-25 21:06 UTC, Matt Fagnani
no flags Details

Description Matt Fagnani 2020-01-25 21:06:42 UTC
Description of problem:
I ran sudo dnf upgrade --refresh on the Rawhide KDE Plasma spin on 2020-1-25. The upgrade included about ~300 rpms including glib2-2.63.4-1.fc32.x86_64, gcc-10.0.1-0.5.fc32.x86_64, sssd-2.2.2-5.fc32.x86_64, annobin-9.01-2.fc32.x86_64, binutils-2.33.1-12.fc32.x86_64, colord-1.4.4-3.fc32.x86_64, elfutils-0.178-8.fc32.x86_64. I rebooted. The plymouth output showed lines like 
Failed to start ModemManager 
Failed to start Accounts Service

The journal and audit logs had denials of ModemManager using setsched on a process with modemmanager_t possibly itself repeated many times. ModemManager restarted and was sent the trap signal. ModemManager crashed 9 times in total.
I reported the ModemManager setsched denials at https://bugzilla.redhat.com/show_bug.cgi?id=1794958

There were also denials of accounts-daemon using setsched and sysnice followed by accounts-daemon getting the trap signal and crashing once. https://bugzilla.redhat.com/show_bug.cgi?id=1794959
colord was denied setsched and crashed with the trap signal also. https://bugzilla.redhat.com/show_bug.cgi?id=1794961 So the denials might be due to a change in a package that ModemManager, accounts-daemon, and colord were all using. glib2-2.63.4-1.fc32.x86_64 is in the traces of the crashing threads of each of them so glib might be involved. The same denials and crashes happened on 3 consecutive boots.
sudo coredumpctl gdb showed that the ModemManager crashes involved errors like "Failed to set scheduler settings: Permission denied"  in frame 1 at ../glib/gmessages.c:3123 in glib2-2.63.4-1.fc32.x86_64 and in frame 3. Those errors might be due to the setsched denials

Core was generated by `/usr/sbin/ModemManager'.
 ModemManager-1.10.8-1.fc32.x86_64

Program terminated with signal SIGTRAP, Trace/breakpoint trap.
#0  _g_log_abort (breakpoint=1) at ../glib/gmessages.c:554
554         G_BREAKPOINT ();
[Current thread is 1 (Thread 0x7f7affb0f700 (LWP 944))]
(gdb) bt
#0  _g_log_abort (breakpoint=1) at ../glib/gmessages.c:554
#1  0x00007f7b009b1e89 in g_log_default_handler
    (log_domain=log_domain@entry=0x7f7b009f900e "GLib", log_level=log_level@entry=6, message=message@entry=0x7f7af0001b90 "Failed to set scheduler settings: Permission denied", unused_data=unused_data@entry=0x0) at ../glib/gmessages.c:3123
#2  0x00007f7b009b20bb in g_logv
    (log_domain=0x7f7b009f900e "GLib", log_level=G_LOG_LEVEL_ERROR, format=<optimized out>, args=args@entry=0x7f7affb0ec90) at ../glib/gmessages.c:1350
#3  0x00007f7b009b22a3 in g_log
    (log_domain=log_domain@entry=0x7f7b009f900e "GLib", log_level=log_level@entry=G_LOG_LEVEL_ERROR, format=format@entry=0x7f7b00a5ee70 "Failed to set scheduler settings: %s") at ../glib/gmessages.c:1415
#4  0x00007f7b009f752b in linux_pthread_proxy (data=0x55e6a392c060) at ../glib/gthread-posix.c:1238
#5  0x00007f7b0093a432 in start_thread (arg=<optimized out>) at pthread_create.c:477
#6  0x00007f7b00862873 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Version-Release number of selected component:
ModemManager-1.10.8-1.fc32

Additional info:
reporter:       libreport-2.11.3
backtrace_rating: 4
cgroup:         0::/system.slice/ModemManager.service
cmdline:        /usr/sbin/ModemManager
crash_function: linux_pthread_proxy
executable:     /usr/sbin/ModemManager
journald_cursor: s=f9ee00d7d07147028db696ea8bf93f0d;i=56f2e;b=29bef6f9f3cb4b8aabbf0202e8371dfe;m=41e7481;t=59cfbe7a609c7;x=9cb77adb9fa64445
kernel:         5.5.0-0.rc6.git3.1.fc32.x86_64
rootdir:        /
runlevel:       N 5
type:           CCpp
uid:            0

Comment 1 Matt Fagnani 2020-01-25 21:06:44 UTC
Created attachment 1655321 [details]
File: backtrace

Comment 2 Matt Fagnani 2020-01-25 21:06:45 UTC
Created attachment 1655322 [details]
File: core_backtrace

Comment 3 Matt Fagnani 2020-01-25 21:06:46 UTC
Created attachment 1655323 [details]
File: cpuinfo

Comment 4 Matt Fagnani 2020-01-25 21:06:47 UTC
Created attachment 1655324 [details]
File: dso_list

Comment 5 Matt Fagnani 2020-01-25 21:06:48 UTC
Created attachment 1655325 [details]
File: environ

Comment 6 Matt Fagnani 2020-01-25 21:06:49 UTC
Created attachment 1655326 [details]
File: limits

Comment 7 Matt Fagnani 2020-01-25 21:06:50 UTC
Created attachment 1655327 [details]
File: maps

Comment 8 Matt Fagnani 2020-01-25 21:06:51 UTC
Created attachment 1655328 [details]
File: mountinfo

Comment 9 Matt Fagnani 2020-01-25 21:06:52 UTC
Created attachment 1655329 [details]
File: open_fds

Comment 10 Matt Fagnani 2020-01-25 21:06:53 UTC
Created attachment 1655330 [details]
File: proc_pid_status

Comment 11 Matt Fagnani 2020-01-25 21:06:54 UTC
Created attachment 1655331 [details]
File: var_log_messages

Comment 12 Matt Fagnani 2020-01-26 01:09:37 UTC
I downgraded to glib2-2.63.3-1.fc32 from koji. No denials or crashes involving ModemManager, accounts-daemon, colord happened on the next 2 boots with glib2-2.63.3-1. I upgraded to glib2-2.63.4-1.fc32, and the denials and crashes started again on the next boot.

The accounts-daemon and colord crashes also had the error "Failed to set scheduler settings: Permission denied" in g_logv at ../glib/gmessages.c:1350 in glib2-2.63.4-1. The error message seems to start from frame 4 in linux_pthread_proxy at ../glib/gthread-posix.c:1238 in all the crashes.

Core was generated by `/usr/libexec/accounts-daemon'.
Program terminated with signal SIGTRAP, Trace/breakpoint trap.
 accountsservice-0.6.55-1.fc32.x86_64
--Type <RET> for more, q to quit, c to continue without paging--
Missing separate debuginfos, use: dnf debuginfo-install
#0  _g_log_abort (breakpoint=1) at ../glib/gmessages.c:554
554         G_BREAKPOINT ();
[Current thread is 1 (Thread 0x7fc6ef9bf700 (LWP 999))]

(gdb) bt full
#0  _g_log_abort (breakpoint=1) at ../glib/gmessages.c:554
        debugger_present = 1
#1  0x00007fc6fd911e89 in g_log_default_handler
    (log_domain=<optimized out>, log_level=<optimized out>, message=<optimized out>, unused_data=<optimized out>) at ../glib/gmessages.c:3123
        fields = 
            {{key = 0x7fc6fd963666 "GLIB_OLD_LOG_API", value = 0x7fc6fd9bc850, length = -1}, {key = 0x7fc6fd9635a1 "MESSAGE", value = 0x7fc6e0002b30, length = -1}, {key = 0x7fc6fd9635b4 "PRIORITY", value = 0x7fc6fd963462, length = -1}, {key = 0x7fc6fd96360e "GLIB_DOMAIN", value = 0x7fc6fd95900e, length = -1}}
        n_fields = <optimized out>
#2  0x00007fc6fd9120bb in g_logv
    (log_domain=0x7fc6fd95900e "GLib", log_level=G_LOG_LEVEL_ERROR, format=<optimized out>, args=args@entry=0x7fc6ef9bec90) at ../glib/gmessages.c:1350
        domain = 0x0
        data = 0x0
        depth = 1
        log_func = 0x560e68cd65d0 <log_handler>
        domain_fatal_mask = <optimized out>
        masquerade_fatal = 0
        test_level = 6
        was_fatal = 0
        was_recursion = 0
        msg = 0x7fc6e0002b30 "Failed to set scheduler settings: Permission denied"
        msg_alloc = 0x7fc6e0002b30 "Failed to set scheduler settings: Permission denied"
--Type <RET> for more, q to quit, c to continue without paging--c
        i = 2
#3  0x00007fc6fd9122a3 in g_log (log_domain=log_domain@entry=0x7fc6fd95900e "GLib", log_level=log_level@entry=G_LOG_LEVEL_ERROR, format=format@entry=0x7fc6fd9bee70 "Failed to set scheduler settings: %s") at ../glib/gmessages.c:1415
        args = {{gp_offset = 32, fp_offset = 48, overflow_arg_area = 0x7fc6ef9bed70, reg_save_area = 0x7fc6ef9becb0}}
#4  0x00007fc6fd95752b in linux_pthread_proxy (data=0x560e69e67060) at ../glib/gthread-posix.c:1238
        tid = <optimized out>
        flags = 0
        res = <optimized out>
        thread = 0x560e69e67060
#5  0x00007fc6fd5aa432 in start_thread (arg=<optimized out>) at pthread_create.c:477
        ret = <optimized out>
        pd = <optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140492400228096, -7997416898972201573, 140731737061774, 140731737061775, 140731737061920, 140492400228096, 7966490075805404571, 7966459850453175707}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
        not_first_call = 0
#6  0x00007fc6fd7a2873 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Core was generated by `/usr/libexec/colord'.
Program terminated with signal SIGTRAP, Trace/breakpoint trap.
 colord-1.4.4-3.fc32.x86_64
#0  _g_log_abort (breakpoint=1) at ../glib/gmessages.c:554
554         G_BREAKPOINT ();
[Current thread is 1 (Thread 0x7f6cff0c7700 (LWP 1189))]

(gdb) bt full 
#0  _g_log_abort (breakpoint=1) at ../glib/gmessages.c:554
        debugger_present = 1
#1  0x00007f6d0d2a1e89 in g_log_default_handler
    (log_domain=log_domain@entry=0x7f6d0d2e900e "GLib", log_level=log_level@entry=6, message=message@entry=0x7f6cf8002b30 "Failed to set scheduler settings: Permission denied", unused_data=unused_data@entry=0x0) at ../glib/gmessages.c:3123
        fields = 
            {{key = 0x7f6d0d2f3666 "GLIB_OLD_LOG_API", value = 0x7f6d0d34c850, length = -1}, {key = 0x7f6d0d2f35a1 "MESSAGE", value = 0x7f6cf8002b30, length = -1}, {key = 0x7f6d0d2f35b4 "PRIORITY", value = 0x7f6d0d2f3462, length = -1}, {key = 0x7f6d0d2f360e "GLIB_DOMAIN", value = 0x7f6d0d2e900e, length = -1}}
        n_fields = <optimized out>
#2  0x00007f6d0d2a20bb in g_logv
    (log_domain=0x7f6d0d2e900e "GLib", log_level=G_LOG_LEVEL_ERROR, format=<optimized out>, args=args@entry=0x7f6cff0c6c90) at ../glib/gmessages.c:1350
        domain = 0x0
        data = 0x0
        depth = 1
        log_func = 0x7f6d0d2a1dd0 <g_log_default_handler>
        domain_fatal_mask = <optimized out>
        masquerade_fatal = 0
        test_level = 6
        was_fatal = 0
        was_recursion = 0
        msg = 0x7f6cf8002b30 "Failed to set scheduler settings: Permission denied"
--Type <RET> for more, q to quit, c to continue without paging--c
        msg_alloc = 0x7f6cf8002b30 "Failed to set scheduler settings: Permission denied"
        i = 2
#3  0x00007f6d0d2a22a3 in g_log (log_domain=log_domain@entry=0x7f6d0d2e900e "GLib", log_level=log_level@entry=G_LOG_LEVEL_ERROR, format=format@entry=0x7f6d0d34ee70 "Failed to set scheduler settings: %s") at ../glib/gmessages.c:1415
        args = {{gp_offset = 32, fp_offset = 48, overflow_arg_area = 0x7f6cff0c6d70, reg_save_area = 0x7f6cff0c6cb0}}
#4  0x00007f6d0d2e752b in linux_pthread_proxy (data=0x55c7fcb58060) at ../glib/gthread-posix.c:1238
        tid = <optimized out>
        flags = 0
        res = <optimized out>
        thread = 0x55c7fcb58060
#5  0x00007f6d0cb62432 in start_thread (arg=<optimized out>) at pthread_create.c:477
        ret = <optimized out>
        pd = <optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140106112202496, -6989725718632123761, 140731841648430, 140731841648431, 140731841648576, 140106112202496, 6928365149271437967, 6928110803516600975}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
        not_first_call = 0
#6  0x00007f6d0cf82873 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95


The part around ../glib/gthread-posix.c:1238 is as follows. 

(gdb) l ../glib/gthread-posix.c:1238
1233
1234          tid = (pid_t) syscall (SYS_gettid);
1235          res = syscall (SYS_sched_setattr, tid, thread->scheduler_settings->attr, flags);
1236          errsv = errno;
1237          if (res == -1)
1238            g_error ("Failed to set scheduler settings: %s", g_strerror (errsv));
1239        }
1240
1241      return thread->proxy (data);
1242    }

This section appears to have been added in the commit 8aeca4fa "GThreadPool - Don't inherit thread priorities when creating new threads" included in glib 2.63.4 at https://gitlab.gnome.org/GNOME/glib/commit/8aeca4fa647bfd0f35c4a86b1e6ca6e955519ca5#note_686823

I ran setroubleshoot GUI's suggestions to allow the accesses
sudo ausearch -c 'ModemManager' --raw | audit2allow -M my-ModemManager
sudo semodule -X 300 -i my-ModemManager.pp
sudo ausearch -c 'accounts-daemon' --raw | audit2allow -M my-accountsdaemon
sudo semodule -X 300 -i my-accountsdaemon.pp
sudo ausearch -c 'colord' --raw | audit2allow -M my-colord
sudo semodule -X 300 -i my-colord.pp

No denials or crashes happened when booting after running those commands which added the following rules in the local policy modules.
allow modemmanager_t self:process setsched;
allow accountsd_t self:capability sys_nice;
allow accountsd_t self:process setsched;
allow colord_t self:process setsched;

Comment 13 Ben Cotton 2020-02-11 17:20:52 UTC
This bug appears to have been reported against 'rawhide' during the Fedora 32 development cycle.
Changing version to 32.

Comment 14 Fedora Program Management 2021-04-29 16:02:42 UTC
This message is a reminder that Fedora 32 is nearing its end of life.
Fedora will stop maintaining and issuing updates for Fedora 32 on 2021-05-25.
It is Fedora's policy to close all bug reports from releases that are no longer
maintained. At that time this bug will be closed as EOL if it remains open with a
Fedora 'version' of '32'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 32 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 15 Ben Cotton 2021-05-25 15:17:56 UTC
Fedora 32 changed to end-of-life (EOL) status on 2021-05-25. Fedora 32 is
no longer maintained, which means that it will not receive any further
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.


Note You need to log in before you can comment on or make changes to this bug.