Re: Wyland is a disaster

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



On 31 January 2018 at 09:37, Howard Howell <hlhowell@xxxxxxxxxxx> wrote:
[..] 
Well, Journalctl shows the following.
Jan 31 00:00:00 school evolution-alarm[2297]: /builddir/build/BUILD/evolution-3.24.6/src/calendar/alarm-notify/alarm.c:251:
Jan 31 00:19:56 school sol.desktop[24828]: xkbcommon: ERROR: Key "<CAPS>" added to modifier map for multiple modifiers; Usi
Jan 31 00:59:38 school gsd-housekeepin[2045]: Failed to enumerate children of /var/tmp/systemd-private-3d6dfe8707be46aa9187
Jan 31 00:59:38 school gsd-housekeepin[2045]: Failed to enumerate children of /var/tmp/systemd-private-3d6dfe8707be46aa9187
Jan 31 00:59:38 school gsd-housekeepin[2045]: Failed to enumerate children of /var/tmp/systemd-private-3d6dfe8707be46aa9187
Jan 31 00:59:38 school gsd-housekeepin[2045]: Failed to enumerate children of /var/tmp/systemd-private-3d6dfe8707be46aa9187
Jan 31 00:59:38 school gsd-housekeepin[2045]: Failed to enumerate children of /tmp/systemd-private-3d6dfe8707be46aa9187e85e
Jan 31 00:59:38 school gsd-housekeepin[2045]: Failed to enumerate children of /tmp/systemd-private-3d6dfe8707be46aa9187e85e
Jan 31 00:59:38 school gsd-housekeepin[2045]: Failed to enumerate children of /tmp/systemd-private-3d6dfe8707be46aa9187e85e
Jan 31 00:59:38 school gsd-housekeepin[2045]: Failed to enumerate children of /tmp/systemd-private-3d6dfe8707be46aa9187e85e
Jan 31 01:09:51 school org.gnome.Calculator.desktop[25129]: xkbcommon: ERROR: Key "<CAPS>" added to modifier map for multip
Jan 31 01:10:45 school gnome-calculato[25129]: gtk_container_remove: assertion 'GTK_IS_WIDGET (widget)' failed
Jan 31 01:14:08 school evolution-alarm[2297]: Error reading events from display: Broken pipe
Jan 31 01:14:08 school gnome-software[2301]: Error reading events from display: Broken pipe
Jan 31 01:14:08 school gnome-session-binary[1715]: WARNING: App 'org.gnome.Shell.desktop' exited with code 1
Jan 31 01:14:08 school gnome-session[1715]: gnome-session-binary[1715]: WARNING: App 'org.gnome.Shell.desktop' exited with 
Jan 31 01:14:08 school org.gnome.Shell.desktop[1785]: Window manager error: Could not find cursor. Perhaps set XCURSOR_PATH
Jan 31 01:14:08 school org.gnome.Shell.desktop[1785]: Fatal server error:
Jan 31 01:14:08 school org.gnome.Shell.desktop[1785]: (EE) failed to read Wayland events: Broken pipe
Jan 31 01:14:08 school org.gnome.Shell.desktop[1785]: (EE)
Jan 31 01:14:08 school gnome-session-binary[1715]: Unrecoverable failure in required component org.gnome.Shell.desktop
Jan 31 01:14:08 school org.gnome.SettingsDaemon.MediaKeys.desktop[2048]: xcb_connection_has_error() returned true
Jan 31 01:14:08 school gsd-housekeepin[2045]: gsd-housekeeping: Fatal IO error 11 (Resource temporarily unavailable) on X s
Jan 31 01:14:08 school gsd-print-notif[2013]: gsd-print-notifications: Fatal IO error 11 (Resource temporarily unavailable)
Jan 31 01:14:08 school at-spi-bus-launcher[1825]: XIO:  fatal IO error 11 (Resource temporarily unavailable) on X server ":
 ESCOC

This doesn't tell me anything, but I'll bet some of you systems guys can see through it to see the root cause, or at least a good trail to follow.

After update today to latest rawhide and reboot I'v decided to change GUI from X11 to Wyland.
In logs I see similar entries like above.

Additionally what I found so far after few hours:

1) sometimes pressing single key is causing to generate many keystrokes. Very annoying ..
  I had such effect at least 10 times in last hour. Looks like some libinput effect.

2) I have wireless Logitech mouse and when I'm moving mouse cursor after at least few seconds whole desktop stops for about 0.5 to less than second (with mouse cursor as well) and each time after this in dmesg I see sequence of lines like:

[26683.059926] [drm] PCIE gen 2 link speeds already enabled
[26683.069526] [drm] PCIE GART of 1024M enabled (table at 0x0000000000162000).
[26683.069637] radeon 0000:01:00.0: WB enabled
[26683.069642] radeon 0000:01:00.0: fence driver on ring 0 use gpu addr 0x0000000020000c00 and cpu addr 0x00000000d8c75981
[26683.069646] radeon 0000:01:00.0: fence driver on ring 3 use gpu addr 0x0000000020000c0c and cpu addr 0x000000001142ed24
[26683.070395] radeon 0000:01:00.0: fence driver on ring 5 use gpu addr 0x0000000000072118 and cpu addr 0x00000000095357f2
[26683.086835] [drm] ring test on 0 succeeded in 2 usecs
[26683.086851] [drm] ring test on 3 succeeded in 7 usecs
[26683.264201] [drm] ring test on 5 succeeded in 2 usecs
[26683.264214] [drm] UVD initialized successfully.
[26683.264346] [drm] ib test on ring 0 succeeded in 0 usecs
[26683.264481] [drm] ib test on ring 3 succeeded in 0 usecs
[26683.919712] [drm] ib test on ring 5 succeeded

Every few times of such sequence additionally I have:

[26815.820342] radeon 0000:01:00.0: swiotlb buffer is full (sz: 2097152 bytes)
[26815.820349] swiotlb: coherent allocation failed for device 0000:01:00.0 size=2097152
[26815.820355] CPU: 0 PID: 7813 Comm: kworker/0:2 Tainted: G        W        4.15.0-0.rc9.git4.1.fc28.x86_64 #1
[26815.820359] Hardware name: Sony Corporation VPCSB2M9E/VAIO, BIOS R2087H4 06/15/2012
[26815.820367] Workqueue: pm pm_runtime_work
[26815.820372] Call Trace:
[26815.820384]  dump_stack+0x85/0xbf
[26815.820392]  swiotlb_alloc_coherent+0xe0/0x150
[26815.820406]  ttm_dma_pool_get_pages+0x21b/0x620 [ttm]
[26815.820422]  ttm_dma_populate+0x24d/0x340 [ttm]
[26815.820434]  ttm_bo_move_memcpy+0x185/0x610 [ttm]
[26815.820444]  ? lock_acquire+0x9f/0x200
[26815.820450]  ? reservation_object_wait_timeout_rcu+0xb3/0x500
[26815.820500]  radeon_bo_move+0x1a7/0x220 [radeon]
[26815.820516]  ttm_bo_handle_move_mem+0x2a4/0x5d0 [ttm]
[26815.820532]  ttm_bo_evict+0x186/0x370 [ttm]
[26815.820552]  ttm_mem_evict_first+0x174/0x1d0 [ttm]
[26815.820565]  ttm_bo_force_list_clean+0x6d/0x130 [ttm]
[26815.820588]  radeon_suspend_kms+0x11e/0x3e0 [radeon]
[26815.820598]  ? vga_switcheroo_runtime_resume+0x60/0x60
[26815.820613]  radeon_pmops_runtime_suspend+0x54/0xc0 [radeon]
[26815.820619]  pci_pm_runtime_suspend+0x61/0x170
[26815.820625]  vga_switcheroo_runtime_suspend+0x24/0xa0
[26815.820630]  __rpm_callback+0xbc/0x1f0
[26815.820635]  ? vga_switcheroo_runtime_resume+0x60/0x60
[26815.820639]  rpm_callback+0x1f/0x70
[26815.820644]  ? vga_switcheroo_runtime_resume+0x60/0x60
[26815.820648]  rpm_suspend+0x12d/0x6e0
[26815.820655]  pm_runtime_work+0x73/0xb0
[26815.820661]  process_one_work+0x249/0x6b0
[26815.820670]  worker_thread+0x3a/0x390
[26815.820675]  ? process_one_work+0x6b0/0x6b0
[26815.820680]  kthread+0x121/0x140
[26815.820684]  ? kthread_create_worker_on_cpu+0x70/0x70
[26815.820691]  ret_from_fork+0x3a/0x50

4) Strange log entries like:

Jan 31 12:36:09 domek org.gnome.Shell.desktop[2153]: Window manager warning: last_user_time (26100487) is greater than comparison timestamp (26100483).  This most likely
 represents a buggy client sending inaccurate timestamps in messages such as _NET_ACTIVE_WINDOW.  Trying to work around...
Jan 31 12:36:09 domek org.gnome.Shell.desktop[2153]: Window manager warning: 0x2200001 (SysOps / D) appears to be one of the offending windows with a timestamp of 261004
87.  Working around...
Jan 31 12:36:09 domek org.gnome.Shell.desktop[2153]: Window manager warning: last_user_time (26100517) is greater than comparison timestamp (26100514).  This most likely
 represents a buggy client sending inaccurate timestamps in messages such as _NET_ACTIVE_WINDOW.  Trying to work around...
Jan 31 12:36:09 domek org.gnome.Shell.desktop[2153]: Window manager warning: 0x2200001 (SysOps / D) appears to be one of the offending windows with a timestamp of 261005
17.  Working around...

Repeated quite quickly up to ~15 times.

5) other sequence of log entries repeated many times (up to ~30 times in sequence)

Jan 31 12:40:21 domek org.gnome.Shell.desktop[2153]: Key repeat discarded, Wayland compositor doesn't seem to be processing events fast enough!
Jan 31 12:40:21 domek org.gnome.Shell.desktop[2153]: Key repeat discarded, Wayland compositor doesn't seem to be processing events fast enough!
Jan 31 12:40:21 domek org.gnome.Shell.desktop[2153]: Key repeat discarded, Wayland compositor doesn't seem to be processing events fast enough!

None of those effects is possible to observe under X11

Other strange looking things which I saw under X11:

1) VSZ of all evolution processes is ~100GB (one hundredth GB)

$  ps auxwf | grep evolu
tkloczko  2647  0.0  0.3 102237860 26316 tty2  Sl+  05:24   0:00              \_ /usr/libexec/evolution/evolution-alarm-notify
tkloczko  2313  0.0  0.3 102233120 26708 ?     SLsl 05:24   0:00  \_ /usr/libexec/evolution-source-registry
tkloczko  2404  0.0  0.6 101788284 52520 ?     Ssl  05:24   0:00  \_ /usr/libexec/evolution-calendar-factory
tkloczko  2496  0.0  0.8 102632304 65420 ?     Sl   05:24   0:01  |   \_ /usr/libexec/evolution-calendar-factory-subprocess --factory caldav --bus-name org.gnome.evolution.dataserver.Subprocess.Backend.Calendarx2404x2 --own-path /org/gnome/evolution/dataserver/Subprocess/Backend/Calendar/2404/2
tkloczko  2618  0.0  0.6 118691584 51864 ?     Sl   05:24   0:00  |   \_ /usr/libexec/evolution-calendar-factory-subprocess --factory contacts --bus-name org.gnome.evolution.dataserver.Subprocess.Backend.Calendarx2404x3 --own-path /org/gnome/evolution/dataserver/Subprocess/Backend/Calendar/2404/3
tkloczko  2694  0.0  0.6 101907300 51936 ?     Sl   05:24   0:00  |   \_ /usr/libexec/evolution-calendar-factory-subprocess --factory local --bus-name org.gnome.evolution.dataserver.Subprocess.Backend.Calendarx2404x4 --own-path /org/gnome/evolution/dataserver/Subprocess/Backend/Calendar/2404/4
tkloczko  3305  0.0  0.6 102061428 53176 ?     Sl   05:25   0:00  |   \_ /usr/libexec/evolution-calendar-factory-subprocess --factory gtasks --bus-name org.gnome.evolution.dataserver.Subprocess.Backend.Calendarx2404x5 --own-path /org/gnome/evolution/dataserver/Subprocess/Backend/Calendar/2404/5
tkloczko  2646  0.0  0.2 101740068 17236 ?     Ssl  05:24   0:00  \_ /usr/libexec/evolution-addressbook-factory
tkloczko  2728  0.0  0.2 101874972 18036 ?     Sl   05:24   0:00  |   \_ /usr/libexec/evolution-addressbook-factory-subprocess --factory local --bus-name org.gnome.evolution.dataserver.Subprocess.Backend.AddressBookx2646x2 --own-path /org/gnome/evolution/dataserver/Subprocess/Backend/AddressBook/2646/2

Quite often something like this happens when some files are opened in mmap mode and if current seek pos is quite big. I've been looking on list of opened files by those processes but so far was not able to find why VSZ is so big (RSS as it is possible to see is ~normal)

2) oneliner which allows retrieve 200-300MB RSS after login over GDM:

$ sudo pkill -u gdm

3) Under Weyland and X11 gnome-shell is core dumping:

(gdb) bt
#0  0x00007feacdef48d1 in _g_log_abort (breakpoint=1) at gmessages.c:583
#1  0x00007feacdef590c in g_log_default_handler (log_domain=<optimized out>, log_level=<optimized out>, message=<optimized out>, unused_data=<optimized out>)
    at gmessages.c:3104
#2  0x000055c78df89795 in default_log_handler (log_domain=log_domain@entry=0x7feacc4782be "mutter", log_level=log_level@entry=6, message=message@entry=0x55c790700760 "Connection to xwayland lost", data="" at ../src/main.c:311
#3  0x00007feacdef5b9d in g_logv (log_domain=0x7feacc4782be "mutter", log_level=G_LOG_LEVEL_ERROR, format=<optimized out>, args=args@entry=0x7ffcb7de0470)
    at gmessages.c:1370
#4  0x00007feacdef5d0f in g_log (log_domain=log_domain@entry=0x7feacc4782be "mutter", log_level=log_level@entry=G_LOG_LEVEL_ERROR, format=format@entry=0x7feacc48a790 "Connection to xwayland lost") at gmessages.c:1432
#5  0x00007feacc43796e in x_io_error (display=<optimized out>) at wayland/meta-xwayland.c:411
#6  0x00007feacab40ede in _XIOError (dpy=dpy@entry=0x55c7903cff10) at XlibInt.c:1469
#7  0x00007feacab3e76d in _XEventsQueued (dpy=dpy@entry=0x55c7903cff10, mode=mode@entry=2) at xcb_io.c:352
#8  0x00007feacab302bd in XPending (dpy=0x55c7903cff10) at Pending.c:55
#9  0x00007feacb695c81 in gdk_check_xpending (display=<optimized out>) at gdkeventsource.c:269
#10 0x00007feacb695c81 in gdk_event_source_check (source=0x55c78ff2b170) at gdkeventsource.c:306
#11 0x00007feacdeee969 in g_main_context_check (context=context@entry=0x55c78ff2e800, max_priority=0, fds=fds@entry=0x55c790629590, n_fds=n_fds@entry=17)
    at gmain.c:3736
#12 0x00007feacdeeeee0 in g_main_context_iterate (context=0x55c78ff2e800, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at gmain.c:3900
#13 0x00007feacdeef2d2 in g_main_loop_run (loop=0x55c79039b8d0) at gmain.c:4099
#14 0x00007feacc40319c in meta_run () at core/main.c:648
#15 0x000055c78df892b7 in main (argc=<optimized out>, argv=<optimized out>) at ../src/main.c:462

Especially #2 looks a bit odd ("Connection to xwayland lost")

kloczek
-- 
Tomasz Kłoczko | Tel: http://lnkd.in/FXPWxH
_______________________________________________
devel mailing list -- devel@xxxxxxxxxxxxxxxxxxxxxxx
To unsubscribe send an email to devel-leave@xxxxxxxxxxxxxxxxxxxxxxx

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
[Index of Archives]     [Fedora Announce]     [Fedora Kernel]     [Fedora Testing]     [Fedora Formulas]     [Fedora PHP Devel]     [Kernel Development]     [Fedora Legacy]     [Fedora Maintainers]     [Fedora Desktop]     [PAM]     [Red Hat Development]     [Gimp]     [Yosemite News]
  Powered by Linux