You are not logged in.
Hi there everyone,
I am currently running arch on my thinkpad and am very happy! However, since a couple of days / weeks I am now facing two strange problems:
(1) my X server crashes from time to time without any recognizable pattern and
(2) colord-sane is crashing multiple times per hour with a buffer overflow.
I am only mentioning (1) here since I am not sure whether both problems are unrelated and thought that it would be better to add this information. However, I wasn't able to identify any pattern between the colord-sane behavior and the crashing of my X server. That is why I assume that both problems are unrelated.
First of all some basic information wrt my laptop:
> dmidecode -t system | grep Version
Version: ThinkPad X1 Carbon 6thIt is completely up to date by running
> pacman -SyuNow, when I run
> journalctl -u colordI receive the following output since my last reboot:
-- Reboot --
May 17 11:11:56 zeus systemd[1]: Starting Manage, Install and Generate Color Profiles...
May 17 11:11:56 zeus systemd[1]: Started Manage, Install and Generate Color Profiles.
May 17 11:11:59 zeus colord[38351]: *** buffer overflow detected ***: terminated
May 17 11:26:40 zeus colord[44393]: *** buffer overflow detected ***: terminated
May 17 11:32:39 zeus colord[46839]: *** buffer overflow detected ***: terminated
May 17 14:47:23 zeus colord[53272]: *** buffer overflow detected ***: terminated
May 17 15:06:50 zeus colord[60917]: *** buffer overflow detected ***: terminated
May 17 18:52:54 zeus colord[72730]: *** buffer overflow detected ***: terminated
May 17 18:52:56 zeus colord[72749]: *** buffer overflow detected ***: terminated
May 17 18:52:59 zeus colord[72775]: *** buffer overflow detected ***: terminated
May 17 20:02:01 zeus colord[106489]: *** buffer overflow detected ***: terminated
May 17 20:20:03 zeus colord[114068]: *** buffer overflow detected ***: terminated
May 17 20:53:32 zeus colord[129883]: *** buffer overflow detected ***: terminated
May 17 21:01:14 zeus colord[138580]: *** buffer overflow detected ***: terminated
May 17 21:41:24 zeus colord[155353]: *** buffer overflow detected ***: terminated
May 17 22:23:29 zeus colord[175535]: *** buffer overflow detected ***: terminatedHaving noticed this behavior I felt that this isn't normal and did some research. I began by checking the package's bug tracker and found the following bug FS#54205 which looks relatively similar to my problem. Following heftig's comments, I found the following issue openssl/openssl/issues/#3584 as well as some extended discussion at openssl/openssl/issues/#8384.
These two issues as well as heftig's comments in FS#54205 explained that the issue isn't caused by colord-sane itself but stems from openssl. The corresponding, flawed openssl version is 1.1.0.f. However, checking my current openssl version yields
> openssl version
OpenSSL 1.1.1g 21 Apr 2020which is newer than the previously mentioned one. Hence, I am no longer so sure whether my problem is caused by the same bug as the one mentioned in FS#54205.
Afterwards, I ran journalctl and checked one of the buffer overflows for further information. That is what I got:
May 17 22:23:29 zeus colord[175535]: *** buffer overflow detected ***: terminated
May 17 22:23:29 zeus audit[175535]: ANOM_ABEND auid=4294967295 uid=979 gid=979 ses=4294967295 pid=175535 comm="colord-sane" exe="/usr/lib/colord-sane" sig=6 res=1
May 17 22:23:29 zeus kernel: audit: type=1701 audit(1589747009.050:342): auid=4294967295 uid=979 gid=979 ses=4294967295 pid=175535 comm="colord-sane" exe="/usr/lib/colord-sane" sig=6 res=1
May 17 22:23:29 zeus kernel: audit: type=1334 audit(1589747009.064:343): prog-id=60 op=LOAD
May 17 22:23:29 zeus kernel: audit: type=1334 audit(1589747009.064:344): prog-id=61 op=LOAD
May 17 22:23:29 zeus audit: AUDIT1334 prog-id=60 op=LOAD
May 17 22:23:29 zeus audit: AUDIT1334 prog-id=61 op=LOAD
May 17 22:23:29 zeus systemd[1]: Started Process Core Dump (PID 175555/UID 0).
-- Subject: A start job for unit systemd-coredump@17-175555-0.service has finished successfully
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- A start job for unit systemd-coredump@17-175555-0.service has finished successfully.
--
-- The job identifier is 2963.
May 17 22:23:29 zeus audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-coredump@17-175555-0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
May 17 22:23:29 zeus kernel: audit: type=1130 audit(1589747009.067:345): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-coredump@17-175555-0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
May 17 22:23:29 zeus systemd-coredump[175556]: Process 175535 (colord-sane) of user 979 dumped core.
Stack trace of thread 175535:
#0 0x00007fc351f2e2e5 raise (libc.so.6 + 0x3c2e5)
#1 0x00007fc351f17853 abort (libc.so.6 + 0x25853)
#2 0x00007fc351f71808 __libc_message (libc.so.6 + 0x7f808)
#3 0x00007fc35200181a __fortify_fail (libc.so.6 + 0x10f81a)
#4 0x00007fc3520000a4 __chk_fail (libc.so.6 + 0x10e0a4)
#5 0x00007fc351fff976 __strcpy_chk (libc.so.6 + 0x10d976)
#6 0x00007fc33facb043 n/a (libsane-epson2.so.1 + 0x17043)
#7 0x00007fc33facb3c3 n/a (libsane-epson2.so.1 + 0x173c3)
#8 0x00007fc351cbb3a3 sanei_configure_attach (libsane.so.1 + 0x53a3)
#9 0x00007fc33facb58b sane_epson2_get_devices (libsane-epson2.so.1 + 0x1758b)
#10 0x00007fc351cbd4f7 sane_dll_get_devices (libsane.so.1 + 0x74f7)
#11 0x000055a10c1ea55b n/a (colord-sane + 0x255b)
#12 0x00007fc351bbb654 n/a (libgio-2.0.so.0 + 0xba654)
#13 0x00007fc351bc0a27 n/a (libgio-2.0.so.0 + 0xbfa27)
#14 0x00007fc351ed88c3 n/a (libcolord.so.2 + 0x388c3)
#15 0x00007fc351bbb654 n/a (libgio-2.0.so.0 + 0xba654)
#16 0x00007fc351bc0a27 n/a (libgio-2.0.so.0 + 0xbfa27)
#17 0x00007fc351b61afd n/a (libgio-2.0.so.0 + 0x60afd)
#18 0x00007fc351bbb654 n/a (libgio-2.0.so.0 + 0xba654)
#19 0x00007fc351bc0a27 n/a (libgio-2.0.so.0 + 0xbfa27)
#20 0x00007fc351b703a0 n/a (libgio-2.0.so.0 + 0x6f3a0)
#21 0x00007fc351bbb654 n/a (libgio-2.0.so.0 + 0xba654)
#22 0x00007fc351bbb689 n/a (libgio-2.0.so.0 + 0xba689)
#23 0x00007fc351d3a58f g_main_context_dispatch (libglib-2.0.so.0 + 0x6b58f)
#24 0x00007fc351d3c531 n/a (libglib-2.0.so.0 + 0x6d531)
#25 0x00007fc351d3d543 g_main_loop_run (libglib-2.0.so.0 + 0x6e543)
#26 0x000055a10c1ea093 n/a (colord-sane + 0x2093)
#27 0x00007fc351f19002 __libc_start_main (libc.so.6 + 0x27002)
#28 0x000055a10c1ea0fe n/a (colord-sane + 0x20fe)
Stack trace of thread 175538:
#0 0x00007fc351fec6ad syscall (libc.so.6 + 0xfa6ad)
#1 0x00007fc351cec13b g_cond_wait_until (libglib-2.0.so.0 + 0x1d13b)
#2 0x00007fc351d6b7d3 n/a (libglib-2.0.so.0 + 0x9c7d3)
#3 0x00007fc351d6b9c4 g_async_queue_timeout_pop (libglib-2.0.so.0 + 0x9c9c4)
#4 0x00007fc351d1252a n/a (libglib-2.0.so.0 + 0x4352a)
#5 0x00007fc351d185b1 n/a (libglib-2.0.so.0 + 0x495b1)
#6 0x00007fc35191b422 start_thread (libpthread.so.0 + 0x9422)
#7 0x00007fc351ff1b83 __clone (libc.so.6 + 0xffb83)
Stack trace of thread 175539:
#0 0x00007fc351fe6fef __poll (libc.so.6 + 0xf4fef)
#1 0x00007fc351d3c4a0 n/a (libglib-2.0.so.0 + 0x6d4a0)
#2 0x00007fc351d3d543 g_main_loop_run (libglib-2.0.so.0 + 0x6e543)
#3 0x00007fc351b5adf8 n/a (libgio-2.0.so.0 + 0x59df8)
#4 0x00007fc351d185b1 n/a (libglib-2.0.so.0 + 0x495b1)
#5 0x00007fc35191b422 start_thread (libpthread.so.0 + 0x9422)
#6 0x00007fc351ff1b83 __clone (libc.so.6 + 0xffb83)
Stack trace of thread 175540:
#0 0x00007fc351fe6fef __poll (libc.so.6 + 0xf4fef)
#1 0x00007fc3517d9803 n/a (libusb-1.0.so.0 + 0x11803)
#2 0x00007fc35191b422 start_thread (libpthread.so.0 + 0x9422)
#3 0x00007fc351ff1b83 __clone (libc.so.6 + 0xffb83)
Stack trace of thread 175537:
#0 0x00007fc351fe6fef __poll (libc.so.6 + 0xf4fef)
#1 0x00007fc351d3c4a0 n/a (libglib-2.0.so.0 + 0x6d4a0)
#2 0x00007fc351d3c571 g_main_context_iteration (libglib-2.0.so.0 + 0x6d571)
#3 0x00007fc351d3c5c2 n/a (libglib-2.0.so.0 + 0x6d5c2)
#4 0x00007fc351d185b1 n/a (libglib-2.0.so.0 + 0x495b1)
#5 0x00007fc35191b422 start_thread (libpthread.so.0 + 0x9422)
#6 0x00007fc351ff1b83 __clone (libc.so.6 + 0xffb83)
-- Subject: Process 175535 (colord-sane) dumped core
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- Documentation: man:core(5)
--
-- Process 175535 (colord-sane) crashed and dumped core.
--
-- This usually indicates a programming error in the crashing program and
-- should be reported to its vendor as a bug.
May 17 22:23:29 zeus systemd[1]: systemd-coredump@17-175555-0.service: Succeeded.
-- Subject: Unit succeeded
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- The unit systemd-coredump@17-175555-0.service has successfully entered the 'dead' state.
May 17 22:23:29 zeus audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-coredump@17-175555-0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=successUnfortunately, I don't really know what to do next in order to identify the cause of this problem. Instead of simply opening a bug for colord-sane, I'd like to dick a little bit deeper and probably identify the cause of the problem. Therefore, I'd like to ask you whether you have any ideas where to look next or what logs to check?
Cheers and thanks in advance for your help
mr.buffed
Offline
Some paths of investigation you could pursue:
Use the ALA to restore the system to a previous date to locate which update triggered the issue and what was present in that update.
Build a debug version of sane which would add function calls to:
#6 0x00007fc33facb043 n/a (libsane-epson2.so.1 + 0x17043)
#7 0x00007fc33facb3c3 n/a (libsane-epson2.so.1 + 0x173c3)Offline
Thanks for the answer and the heads-up with the debug version!
I also looked into the ALA to restore my system to a previous date. However, after checking since when these crashes are occurring by running
coredumpctl list | grep 'colord',I noticed that these crashes are happening regularly since 19.11.2019. Thus, I guess it would be "insane" to roll back my complete system to this date, wouldn't it?
Unfortunately, I haven't had the time yet to build a debug version of sane. But I'll do so during the week and post my findings here!
Having compiled a debug version of sane I monitored coredumpctl for a new core dump of colord. Below is the latest core dump from colord. This time, I guess, one can see where the crash comes from. I'll look into the corresponding sources during the week and will try to write down my findings here.
PID: 98500 (colord-sane)
UID: 979 (colord)
GID: 979 (colord)
Signal: 6 (ABRT)
Timestamp: Tue 2020-05-26 XX:YY:ZZ CEST (56min ago)
Command Line: /usr/lib/colord-sane
Executable: /usr/lib/colord-sane
Control Group: /system.slice/colord.service
Unit: colord.service
Slice: system.slice
Boot ID: 8e1a09df814448349be8db5d90212be0
Machine ID: a3d7b3483e0e4deeb29ec75ec799e2fb
Hostname: COMPUTER
Storage: /var/lib/systemd/coredump/core.colord-sane.979.8e1a09df814448349be8db5d90212be0.98500.1590497866000000000000.lz4
Message: Process 98500 (colord-sane) of user 979 dumped core.
Stack trace of thread 98500:
#0 0x00007fd9debb7355 raise (libc.so.6 + 0x3c355)
#1 0x00007fd9deba0853 abort (libc.so.6 + 0x25853)
#2 0x00007fd9debfa878 __libc_message (libc.so.6 + 0x7f878)
#3 0x00007fd9dec8a88a __fortify_fail (libc.so.6 + 0x10f88a)
#4 0x00007fd9dec89114 __chk_fail (libc.so.6 + 0x10e114)
#5 0x00007fd9dec889e6 __strcpy_chk (libc.so.6 + 0x10d9e6)
#6 0x00007fd9d8969eb6 strcat (libsane-epson2.so.1 + 0x16eb6)
#7 0x00007fd9d896a2ab attach_one_config (libsane-epson2.so.1 + 0x172ab)
#8 0x00007fd9ded473a3 sanei_configure_attach (libsane.so.1 + 0x53a3)
#9 0x00007fd9d896a3fc probe_devices (libsane-epson2.so.1 + 0x173fc)
#10 0x00007fd9ded494e7 sane_dll_get_devices (libsane.so.1 + 0x74e7)
#11 0x000055839777c55b n/a (colord-sane + 0x255b)
#12 0x00007fd9dea5f844 n/a (libgio-2.0.so.0 + 0x9e844)
#13 0x00007fd9dea63b87 n/a (libgio-2.0.so.0 + 0xa2b87)
#14 0x00007fd9def3ed2e n/a (libcolord.so.2 + 0x18d2e)
#15 0x00007fd9dea5f844 n/a (libgio-2.0.so.0 + 0x9e844)
#16 0x00007fd9dea63b87 n/a (libgio-2.0.so.0 + 0xa2b87)
#17 0x00007fd9deac6fad n/a (libgio-2.0.so.0 + 0x105fad)
#18 0x00007fd9dea5f844 n/a (libgio-2.0.so.0 + 0x9e844)
#19 0x00007fd9dea63b87 n/a (libgio-2.0.so.0 + 0xa2b87)
#20 0x00007fd9deab7060 n/a (libgio-2.0.so.0 + 0xf6060)
#21 0x00007fd9dea5f844 n/a (libgio-2.0.so.0 + 0x9e844)
#22 0x00007fd9dea5f879 n/a (libgio-2.0.so.0 + 0x9e879)
#23 0x00007fd9dedad340 g_main_context_dispatch (libglib-2.0.so.0 + 0x52340)
#24 0x00007fd9dedfafa9 n/a (libglib-2.0.so.0 + 0x9ffa9)
#25 0x00007fd9dedabc03 g_main_loop_run (libglib-2.0.so.0 + 0x50c03)
#26 0x000055839777c093 n/a (colord-sane + 0x2093)
#27 0x00007fd9deba2002 __libc_start_main (libc.so.6 + 0x27002)
#28 0x000055839777c0fe n/a (colord-sane + 0x20fe)
Stack trace of thread 98501:
#0 0x00007fd9dec7005f __poll (libc.so.6 + 0xf505f)
#1 0x00007fd9dedfaf38 n/a (libglib-2.0.so.0 + 0x9ff38)
#2 0x00007fd9dedac221 g_main_context_iteration (libglib-2.0.so.0 + 0x51221)
#3 0x00007fd9dedac272 n/a (libglib-2.0.so.0 + 0x51272)
#4 0x00007fd9dedd5511 n/a (libglib-2.0.so.0 + 0x7a511)
#5 0x00007fd9de7db422 start_thread (libpthread.so.0 + 0x9422)
#6 0x00007fd9dec7abf3 __clone (libc.so.6 + 0xffbf3)
Stack trace of thread 98504:
#0 0x00007fd9dec7005f __poll (libc.so.6 + 0xf505f)
#1 0x00007fd9de699803 n/a (libusb-1.0.so.0 + 0x11803)
#2 0x00007fd9de7db422 start_thread (libpthread.so.0 + 0x9422)
#3 0x00007fd9dec7abf3 __clone (libc.so.6 + 0xffbf3)
Stack trace of thread 98502:
#0 0x00007fd9dec7571d syscall (libc.so.6 + 0xfa71d)
#1 0x00007fd9dedf57ab g_cond_wait_until (libglib-2.0.so.0 + 0x9a7ab)
#2 0x00007fd9ded7d803 n/a (libglib-2.0.so.0 + 0x22803)
#3 0x00007fd9ded7d994 g_async_queue_timeout_pop (libglib-2.0.so.0 + 0x22994)
#4 0x00007fd9dedd9caa n/a (libglib-2.0.so.0 + 0x7ecaa)
#5 0x00007fd9dedd5511 n/a (libglib-2.0.so.0 + 0x7a511)
#6 0x00007fd9de7db422 start_thread (libpthread.so.0 + 0x9422)
#7 0x00007fd9dec7abf3 __clone (libc.so.6 + 0xffbf3)
Stack trace of thread 98503:
#0 0x00007fd9dec7005f __poll (libc.so.6 + 0xf505f)
#1 0x00007fd9dedfaf38 n/a (libglib-2.0.so.0 + 0x9ff38)
#2 0x00007fd9dedabc03 g_main_loop_run (libglib-2.0.so.0 + 0x50c03)
#3 0x00007fd9deac11a8 n/a (libgio-2.0.so.0 + 0x1001a8)
#4 0x00007fd9dedd5511 n/a (libglib-2.0.so.0 + 0x7a511)
#5 0x00007fd9de7db422 start_thread (libpthread.so.0 + 0x9422)
#6 0x00007fd9dec7abf3 __clone (libc.so.6 + 0xffbf3)Just to double check, the relevant lines to do further research on are these, aren't they?
#6 0x00007fd9d8969eb6 strcat (libsane-epson2.so.1 + 0x16eb6)
#7 0x00007fd9d896a2ab attach_one_config (libsane-epson2.so.1 + 0x172ab)
#8 0x00007fd9ded473a3 sanei_configure_attach (libsane.so.1 + 0x53a3)
#9 0x00007fd9d896a3fc probe_devices (libsane-epson2.so.1 + 0x173fc)
#10 0x00007fd9ded494e7 sane_dll_get_devices (libsane.so.1 + 0x74e7)Again, thanks for your help Ioqs and cheers
mr.buffed
Last edited by mr.buffed (2020-05-26 14:25:12)
Offline