On 31 January 2018 at 09:37, Howard Howell <hlhow...@pacbell.net> 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=data@entry=0x0) 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 <http://lnkd.in/FXPWxH>*
_______________________________________________
devel mailing list -- devel@lists.fedoraproject.org
To unsubscribe send an email to devel-le...@lists.fedoraproject.org
