Bug 758302 – After monitor hotplug, keybindings stop working

After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.

Bug 758302 - After monitor hotplug, keybindings stop working


Summary:	After monitor hotplug, keybindings stop working


Status:	RESOLVED FIXED

Product:	gnome-settings-daemon
Classification:	Core
Component:	media-keys
Version:	3.18.x
Hardware:	Other Linux

Importance:	Normal normal
Target Milestone:	---
Assigned To:	gnome-settings-daemon-maint
QA Contact:	gnome-settings-daemon-maint

URL:
Whiteboard:

Duplicates:	765339 773005 773406 (view as bug list)
Depends on:
Blocks:

Reported:	2015-11-18 18:06 UTC by Andreas Kloeckner
Modified:	2017-02-14 16:21 UTC

See Also:
GNOME target:	---
GNOME version:	---

Attachments
Log output showing entering/returning from standby breaks shortcuts (658.16 KB, text/plain) 2016-12-30 14:14 UTC, Matthijs Kooijman		Details
*Log output showing entering/returning from standby does not* break** (202.25 KB, text/plain) 2016-12-30 14:15 UTC, Matthijs Kooijman		Details
media-keys: Avoid multiple grab/ungrab pairs on custom binding changes (1.87 KB, patch) 2017-02-13 16:06 UTC, Rui Matos	committed	Details \| Review
media-keys: Reference count MediaKey struct instances (2.51 KB, patch) 2017-02-13 21:02 UTC, Rui Matos	committed	Details \| Review
media-keys: Avoid using free'd memory (1.26 KB, patch) 2017-02-13 21:02 UTC, Rui Matos	committed	Details \| Review
media-keys: Avoid leaking grabbed bindings (2.51 KB, patch) 2017-02-13 21:02 UTC, Rui Matos	committed	Details \| Review
media-keys: Handle binding grabs when there's already one pending (4.30 KB, patch) 2017-02-13 21:03 UTC, Rui Matos	committed	Details \| Review

Description Andreas Kloeckner 2015-11-18 18:06:24 UTC

I have a number of key bindings to run scripts that I rely on heavily.

(E.g. "Win+t" to run a script to configure my Wacom tablet.)

When I hotplug a screen (which I do often--I use my laptop as my main computer, and I plug it into a big monitor at work and at home), there's a certain likelihood (>50% perceived) that my custom keyboard shortcuts stop working. Notably, the built-in keyboard shortcuts still work, but my custom ones do not. "Alt+f2" and running "r" to restart the shell restores them to working order.

-- System Information:
Debian Release: stretch/sid
  APT prefers testing
  APT policy: (990, 'testing'), (500, 'stable-updates'), (500, 'unstable'), (500, 'stable'), (1, 'experimental')
Architecture: amd64 (x86_64)
Foreign Architectures: i386

Kernel: Linux 4.3.0-trunk-amd64 (SMP w/4 CPU cores)
Locale: LANG=de_DE.utf8, LC_CTYPE=de_DE.utf8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)

Versions of packages gnome-shell depends on:
ii  dconf-gsettings-backend [gsettings-backend]  0.24.0-2
ii  evolution-data-server                        3.18.1-1
ii  gir1.2-accountsservice-1.0                   0.6.40-3
ii  gir1.2-atspi-2.0                             2.18.3-1
ii  gir1.2-caribou-1.0                           0.4.19-1
ii  gir1.2-clutter-1.0                           1.24.2-1
ii  gir1.2-freedesktop                           1.46.0-2
ii  gir1.2-gcr-3                                 3.18.0-1
ii  gir1.2-gdesktopenums-3.0                     3.18.1-1
ii  gir1.2-gdm3                                  3.18.0-2
ii  gir1.2-gkbd-3.0                              3.6.0-1
ii  gir1.2-glib-2.0                              1.46.0-2
ii  gir1.2-gnomebluetooth-1.0                    3.18.1-1
ii  gir1.2-gnomedesktop-3.0                      3.18.2-1
ii  gir1.2-gtk-3.0                               3.18.5-1
ii  gir1.2-gweather-3.0                          3.18.1-1
ii  gir1.2-ibus-1.0                              1.5.10-1
ii  gir1.2-mutter-3.0                            3.18.2-1
ii  gir1.2-networkmanager-1.0                    1.0.6-1
ii  gir1.2-nmgtk-1.0                             1.0.6-2
ii  gir1.2-pango-1.0                             1.38.1-1
ii  gir1.2-polkit-1.0                            0.113-1
ii  gir1.2-soup-2.4                              2.52.1-1
ii  gir1.2-telepathyglib-0.12                    0.24.1-1.1
ii  gir1.2-telepathylogger-0.2                   0.8.2-1
ii  gir1.2-upowerglib-1.0                        0.99.3-1+b2
ii  gjs                                          1.43.3-2
ii  gnome-backgrounds                            3.18.0-1
ii  gnome-icon-theme-symbolic                    3.12.0-1
ii  gnome-settings-daemon                        3.18.2-1
ii  gnome-shell-common                           3.18.3-1
ii  gsettings-desktop-schemas                    3.18.1-1
ii  libatk-bridge2.0-0                           2.18.1-1
ii  libatk1.0-0                                  2.18.0-1
ii  libc6                                        2.19-22
ii  libcairo2                                    1.14.4-1
ii  libcanberra-gtk3-0                           0.30-2.1
ii  libcanberra0                                 0.30-2.1
ii  libclutter-1.0-0                             1.24.2-1
ii  libcogl-pango20                              1.22.0-1
ii  libcogl20                                    1.22.0-1
ii  libcroco3                                    0.6.9-1
ii  libdbus-glib-1-2                             0.102-1
ii  libecal-1.2-19                               3.18.1-1
ii  libedataserver-1.2-21                        3.18.1-1
ii  libgcr-base-3-1                              3.18.0-1
ii  libgdk-pixbuf2.0-0                           2.32.2-1
ii  libgirepository-1.0-1                        1.46.0-2
ii  libgjs0e [libgjs0-libmozjs-24-0]             1.44.0-1
ii  libglib2.0-0                                 2.46.2-1
ii  libgstreamer1.0-0                            1.6.1-1
ii  libgtk-3-0                                   3.18.5-1
ii  libical1a                                    1.0.1-0.1
ii  libjson-glib-1.0-0                           1.0.4-2
ii  libmozjs-24-0                                24.2.0-3
ii  libmutter0g                                  3.18.2-1
ii  libnm-glib4                                  1.0.6-1
ii  libnm-util2                                  1.0.6-1
ii  libpango-1.0-0                               1.38.1-1
ii  libpangocairo-1.0-0                          1.38.1-1
ii  libpolkit-agent-1-0                          0.113-1
ii  libpolkit-gobject-1-0                        0.113-1
ii  libpulse-mainloop-glib0                      7.1-2
ii  libpulse0                                    7.1-2
ii  libsecret-1-0                                0.18.3-1
ii  libstartup-notification0                     0.12-4
ii  libsystemd0                                  227-2
ii  libtelepathy-glib0                           0.24.1-1.1
ii  libx11-6                                     2:1.6.3-1
ii  libxfixes3                                   1:5.0.1-2+b2
ii  mutter                                       3.18.2-1
ii  python3                                      3.5.0-2
ii  telepathy-mission-control-5                  1:5.16.3-1

Versions of packages gnome-shell recommends:
ii  gdm3                        3.18.0-2
ii  gkbd-capplet                3.6.0-1
ii  gnome-contacts              3.18.1-1
ii  gnome-control-center        1:3.18.2-1
ii  gnome-themes-standard-data  3.18.0-1
ii  gnome-user-guide            3.18.1-1
ii  iio-sensor-proxy            1.1-1
ii  unzip                       6.0-20

Comment 1 Bastien Nocera 2015-11-19 11:06:25 UTC

Did anything crash? If custom shortcuts don't work, do others work (like, say, Volume buttons or Print Screen)?

Comment 2 Andreas Kloeckner 2015-11-19 16:29:19 UTC

Volume buttons and Alt+F2 still work even when custom keybindings have stopped working. How would I tell whether something has crashed?

Comment 3 Bastien Nocera 2015-11-19 16:32:58 UTC

(In reply to Andreas Kloeckner from comment #2)
> Volume buttons and Alt+F2 still work even when custom keybindings have
> stopped working. How would I tell whether something has crashed?

There's usually a print out in the "dmesg" output, or the OS will tell you about it. You should also be able to see whether something output any debugging information in the output of "journalctl -b".

Comment 4 Andreas Kloeckner 2015-11-19 17:15:09 UTC

This output of 'journalctl -b' covers at least one hotplug period after which
the hotkeys stopped working. I don't see any evidence of a crash--but maybe you
see something there:

Nov 19 11:11:15 bolt gnome-session[1298]: Window manager warning: Failed to read EDID of output DisplayPort40: Datei oder Verzeichnis nicht gefunden
Nov 19 11:11:15 bolt /usr/lib/gdm3/gdm-x-session[1438]: (II) intel(0): resizing framebuffer to 2560x1440
Nov 19 11:11:15 bolt gnome-session[1298]: Window manager warning: Failed to read EDID of output DisplayPort40: Datei oder Verzeichnis nicht gefunden
Nov 19 11:11:15 bolt /usr/lib/gdm3/gdm-x-session[1438]: (II) intel(0): switch to mode 2560x1440@60.0 on DP1 using pipe 0, position (0, 0), rotation normal, reflection none
Nov 19 11:11:16 bolt gnome-session[1298]: (gnome-settings-daemon:1377): color-plugin-WARNING **: failed to get edid: EDID length is too small
Nov 19 11:11:16 bolt gnome-session[1298]: (gnome-settings-daemon:1377): color-plugin-WARNING **: failed to create device: failed to obtain org.freedesktop.color-manager.create-device auth
Nov 19 11:11:16 bolt gnome-session[1298]: (gnome-settings-daemon:1377): color-plugin-WARNING **: could not find device: property match 'XRANDR_name'='DisplayPort40' does not exist
Nov 19 11:11:16 bolt gnome-session[1451]: Gjs-Message: JS LOG: Added: 3
Nov 19 11:11:16 bolt icedove.desktop[2869]: *** BUG ***
Nov 19 11:11:16 bolt icedove.desktop[2869]: In pixman_region32_fini: Malformed region region
Nov 19 11:11:16 bolt icedove.desktop[2869]: Set a breakpoint on '_pixman_log_error' to debug
Nov 19 11:11:16 bolt gnome-session[1298]: (gnome-settings-daemon:1377): color-plugin-WARNING **: no xrandr-Dell Inc.-DELL U2713HM-7JNY5375343S device found: Failed to find output xrandr-Dell Inc.-DELL U2713HM-7JNY5375343S
Nov 19 11:11:28 bolt org.gnome.evolution.dataserver.Calendar7[1449]: ** (evolution-calendar-factory-subprocess:1857): WARNING **: Error setting property 'ConnectionStatus' on interface org.gnome.evolution.dataserver.Source: Zeitüberschreitung wurde erreicht (g-io-error-quark, 24)
Nov 19 11:11:28 bolt org.gnome.evolution.dataserver.Calendar7[1449]: ** (evolution-calendar-factory-subprocess:1857): WARNING **: Error setting property 'ConnectionStatus' on interface org.gnome.evolution.dataserver.Source: Zeitüberschreitung wurde erreicht (g-io-error-quark, 24)
Nov 19 11:11:29 bolt org.gnome.evolution.dataserver.Calendar7[1449]: ** (evolution-calendar-factory-subprocess:1857): WARNING **: Error setting property 'ConnectionStatus' on interface org.gnome.evolution.dataserver.Source: Zeitüberschreitung wurde erreicht (g-io-error-quark, 24)
Nov 19 11:11:29 bolt org.gnome.evolution.dataserver.Calendar7[1449]: ** (evolution-calendar-factory-subprocess:1857): WARNING **: Error setting property 'ConnectionStatus' on interface org.gnome.evolution.dataserver.Source: Zeitüberschreitung wurde erreicht (g-io-error-quark, 24)
Nov 19 11:11:35 bolt wpa_supplicant[1265]: wlan0: CTRL-EVENT-SIGNAL-CHANGE above=0 signal=-87 noise=9999 txrate=240000
Nov 19 11:11:37 bolt gnome-session[1451]: (gnome-terminal:5806): GLib-GObject-CRITICAL **: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
Nov 19 11:11:43 bolt wpa_supplicant[1265]: wlan0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-49 noise=9999 txrate=240000
Nov 19 11:11:45 bolt sudo[5841]:  andreas : TTY=pts/3 ; PWD=/home/andreas ; USER=root ; COMMAND=/bin/journalctl -b
Nov 19 11:11:45 bolt sudo[5841]: pam_unix(sudo:session): session opened for user root by (uid=0)
Nov 19 11:11:50 bolt sudo[5841]: pam_unix(sudo:session): session closed for user root
Nov 19 11:11:50 bolt wpa_supplicant[1265]: wlan0: CTRL-EVENT-SIGNAL-CHANGE above=0 signal=-74 noise=9999 txrate=240000
Nov 19 11:11:51 bolt wpa_supplicant[1265]: wlan0: SME: Trying to authenticate with 00:0c:e6:9a:97:66 (SSID='IllinoisNet' freq=2412 MHz)
Nov 19 11:11:51 bolt kernel: wlan0: authenticate with 00:0c:e6:9a:97:66
Nov 19 11:11:51 bolt NetworkManager[852]: <info>  (wlan0): roamed from BSSID 00:0C:E6:9A:26:BB (IllinoisNet) to (none) ((none))
Nov 19 11:11:51 bolt kernel: wlan0: send auth to 00:0c:e6:9a:97:66 (try 1/3)
Nov 19 11:11:51 bolt NetworkManager[852]: <info>  (wlan0): supplicant interface state: completed -> authenticating
Nov 19 11:11:51 bolt gnome-session[1451]: Gjs-Message: JS LOG: An active wireless connection, in infrastructure mode, involves no access point?
Nov 19 11:11:51 bolt gnome-session[1298]: Gjs-Message: JS LOG: An active wireless connection, in infrastructure mode, involves no access point?
Nov 19 11:11:52 bolt wpa_supplicant[1265]: wlan0: Trying to associate with 00:0c:e6:9a:97:66 (SSID='IllinoisNet' freq=2412 MHz)
Nov 19 11:11:52 bolt kernel: wlan0: authenticated
Nov 19 11:11:52 bolt kernel: wlan0: associate with 00:0c:e6:9a:97:66 (try 1/3)
Nov 19 11:11:52 bolt NetworkManager[852]: <info>  (wlan0): supplicant interface state: authenticating -> associating
Nov 19 11:11:52 bolt kernel: wlan0: RX AssocResp from 00:0c:e6:9a:97:66 (capab=0x411 status=0 aid=106)
Nov 19 11:11:52 bolt kernel: wlan0: associated
Nov 19 11:11:52 bolt wpa_supplicant[1265]: wlan0: Associated with 00:0c:e6:9a:97:66
Nov 19 11:11:52 bolt NetworkManager[852]: <info>  (wlan0): supplicant interface state: associating -> associated
Nov 19 11:11:52 bolt wpa_supplicant[1265]: wlan0: CTRL-EVENT-EAP-STARTED EAP authentication started
Nov 19 11:11:55 bolt NetworkManager[852]: <info>  (wlan0): roamed from BSSID (none) ((none)) to 00:0C:E6:9A:97:66 (IllinoisNet)
Nov 19 11:12:00 bolt sudo[5944]:  andreas : TTY=pts/3 ; PWD=/home/andreas ; USER=root ; COMMAND=/bin/journalctl -b
Nov 19 11:12:00 bolt sudo[5944]: pam_unix(sudo:session): session opened for user root by (uid=0)
Nov 19 11:12:01 bolt sudo[5944]: pam_unix(sudo:session): session closed for user root
Nov 19 11:12:11 bolt sudo[6106]:  andreas : TTY=pts/3 ; PWD=/home/andreas ; USER=root ; COMMAND=/bin/journalctl -b
Nov 19 11:12:11 bolt sudo[6106]: pam_unix(sudo:session): session opened for user root by (uid=0)

Comment 5 Bastien Nocera 2015-11-20 15:06:19 UTC

Could you please run:
gsettings set org.gnome.settings-daemon.plugins.media-keys active false
Followed by:
/usr/libexec/gsd-test-media-keys
(this file might be in a different location depending on the distribution)
Reproduce the problem, and attach the results here.

Comment 6 Andreas Kloeckner 2016-02-24 20:11:52 UTC

Here's what gsd-test-media-keys says:

Then I hit, say Super+B (which I've got bound to starting a new terminal), and nothing happens. gsd-test-media-keys also produces no new output at thtat point.

To deactivate:
	gsettings set org.gnome.settings-daemon.plugins.media-keys active false
To reactivate:
	gsettings set org.gnome.settings-daemon.plugins.media-keys active true
(gsd-test-media-keys:15795): media-keys-plugin-DEBUG: Adding system inhibitors for power keys
(gsd-test-media-keys:15795): media-keys-plugin-DEBUG: System inhibitor fd is 13
(gsd-test-media-keys:15795): media-keys-plugin-DEBUG: Starting media_keys manager
(gsd-test-media-keys:15795): media-keys-plugin-DEBUG: Starting mpris controller
(gsd-test-media-keys:15795): Gvc-DEBUG: get server info
(gsd-test-media-keys:15795): Gvc-DEBUG: update server
(gsd-test-media-keys:15795): Gvc-DEBUG: Udpating card alsa_card.pci-0000_00_03.0 (index: 0 driver: module-alsa-card.c):
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Profile 'output:hdmi-stereo': 0 sources 1 sinks (Current)
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Profile 'output:hdmi-surround': 0 sources 1 sinks
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Profile 'output:hdmi-surround71': 0 sources 1 sinks
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Profile 'output:hdmi-stereo-extra1': 0 sources 1 sinks
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Profile 'output:hdmi-surround-extra1': 0 sources 1 sinks
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Profile 'output:hdmi-surround71-extra1': 0 sources 1 sinks
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Profile 'output:hdmi-stereo-extra2': 0 sources 1 sinks
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Profile 'output:hdmi-surround-extra2': 0 sources 1 sinks
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Profile 'output:hdmi-surround71-extra2': 0 sources 1 sinks
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Profile 'off': 0 sources 0 sinks
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'alsa.card' = '0'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'alsa.card_name' = 'HDA Intel HDMI'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'alsa.long_card_name' = 'HDA Intel HDMI at 0xe1230000 irq 49'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'alsa.driver_name' = 'snd_hda_intel'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.bus_path' = 'pci-0000:00:03.0'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'sysfs.path' = '/devices/pci0000:00/0000:00:03.0/sound/card0'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.bus' = 'pci'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.vendor.id' = '8086'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.vendor.name' = 'Intel Corporation'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.product.id' = '160c'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.product.name' = 'Broadwell-U Audio Controller'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.form_factor' = 'internal'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.string' = '0'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.description' = 'Internes Audio'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'module-udev-detect.discovered' = '1'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.icon_name' = 'audio-card-pci'
(gsd-test-media-keys:15795): Gvc-DEBUG: 3 profiles supported on port HDMI / DisplayPort
(gsd-test-media-keys:15795): Gvc-DEBUG: 3 profiles supported on port HDMI / DisplayPort 2
(gsd-test-media-keys:15795): Gvc-DEBUG: 3 profiles supported on port HDMI / DisplayPort 3
(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - card: 0x1986e40

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - card port name: hdmi-output-2

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - 1st line: HDMI / DisplayPort 3

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - 2nd line: Internes Audio

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - port available 0, value passed in 0 

(gsd-test-media-keys:15795): Gvc-DEBUG: Set profiles for 'HDMI / DisplayPort 3'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:hdmi-surround-extra2' is 'output:hdmi-surround-extra2'
(gsd-test-media-keys:15795): Gvc-DEBUG: Adding profile to combobox: 'output:hdmi-surround-extra2' - 'Digital Surround 5.1 (HDMI 3) Output'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:hdmi-surround71-extra2' is 'output:hdmi-surround71-extra2'
(gsd-test-media-keys:15795): Gvc-DEBUG: Adding profile to combobox: 'output:hdmi-surround71-extra2' - 'Digital Surround 7.1 (HDMI 3) Output'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:hdmi-stereo-extra2' is 'output:hdmi-stereo-extra2'
(gsd-test-media-keys:15795): Gvc-DEBUG: Adding profile to combobox: 'output:hdmi-stereo-extra2' - 'Digital Stereo (HDMI 3) Output'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:hdmi-surround-extra2' is 'output:hdmi-surround-extra2'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:hdmi-surround71-extra2' is 'output:hdmi-surround71-extra2'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:hdmi-stereo-extra2' is 'output:hdmi-stereo-extra2'
(gsd-test-media-keys:15795): Gvc-DEBUG: create_ui_device_from_port, direction 1, description 'HDMI / DisplayPort 3', origin 'Internes Audio', port available 0
(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - card: 0x1986e40

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - card port name: hdmi-output-1

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - 1st line: HDMI / DisplayPort 2

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - 2nd line: Internes Audio

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - port available 0, value passed in 0 

(gsd-test-media-keys:15795): Gvc-DEBUG: Set profiles for 'HDMI / DisplayPort 2'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:hdmi-surround-extra1' is 'output:hdmi-surround-extra1'
(gsd-test-media-keys:15795): Gvc-DEBUG: Adding profile to combobox: 'output:hdmi-surround-extra1' - 'Digital Surround 5.1 (HDMI 2) Output'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:hdmi-surround71-extra1' is 'output:hdmi-surround71-extra1'
(gsd-test-media-keys:15795): Gvc-DEBUG: Adding profile to combobox: 'output:hdmi-surround71-extra1' - 'Digital Surround 7.1 (HDMI 2) Output'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:hdmi-stereo-extra1' is 'output:hdmi-stereo-extra1'
(gsd-test-media-keys:15795): Gvc-DEBUG: Adding profile to combobox: 'output:hdmi-stereo-extra1' - 'Digital Stereo (HDMI 2) Output'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:hdmi-surround-extra1' is 'output:hdmi-surround-extra1'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:hdmi-surround71-extra1' is 'output:hdmi-surround71-extra1'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:hdmi-stereo-extra1' is 'output:hdmi-stereo-extra1'
(gsd-test-media-keys:15795): Gvc-DEBUG: create_ui_device_from_port, direction 1, description 'HDMI / DisplayPort 2', origin 'Internes Audio', port available 0
(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - card: 0x1986e40

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - card port name: hdmi-output-0

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - 1st line: HDMI / DisplayPort

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - 2nd line: Internes Audio

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - port available 1, value passed in 1 

(gsd-test-media-keys:15795): Gvc-DEBUG: Set profiles for 'HDMI / DisplayPort'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:hdmi-surround' is 'output:hdmi-surround'
(gsd-test-media-keys:15795): Gvc-DEBUG: Adding profile to combobox: 'output:hdmi-surround' - 'Digital Surround 5.1 (HDMI) Output'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:hdmi-surround71' is 'output:hdmi-surround71'
(gsd-test-media-keys:15795): Gvc-DEBUG: Adding profile to combobox: 'output:hdmi-surround71' - 'Digital Surround 7.1 (HDMI) Output'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:hdmi-stereo' is 'output:hdmi-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: Adding profile to combobox: 'output:hdmi-stereo' - 'Digital Stereo (HDMI) Output'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:hdmi-surround' is 'output:hdmi-surround'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:hdmi-surround71' is 'output:hdmi-surround71'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:hdmi-stereo' is 'output:hdmi-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: create_ui_device_from_port, direction 1, description 'HDMI / DisplayPort', origin 'Internes Audio', port available 1
(gsd-test-media-keys:15795): Gvc-DEBUG: Udpating card alsa_card.pci-0000_00_1b.0 (index: 1 driver: module-alsa-card.c):
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Profile 'input:analog-stereo': 1 sources 0 sinks
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Profile 'output:analog-stereo': 0 sources 1 sinks
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Profile 'output:analog-stereo+input:analog-stereo': 1 sources 1 sinks (Current)
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Profile 'output:analog-surround-40': 0 sources 1 sinks
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Profile 'output:analog-surround-40+input:analog-stereo': 1 sources 1 sinks
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Profile 'off': 0 sources 0 sinks
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'alsa.card' = '1'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'alsa.card_name' = 'HDA Intel PCH'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'alsa.long_card_name' = 'HDA Intel PCH at 0xe1234000 irq 48'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'alsa.driver_name' = 'snd_hda_intel'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.bus_path' = 'pci-0000:00:1b.0'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'sysfs.path' = '/devices/pci0000:00/0000:00:1b.0/sound/card1'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.bus' = 'pci'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.vendor.id' = '8086'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.vendor.name' = 'Intel Corporation'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.product.id' = '9ca0'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.product.name' = 'Wildcat Point-LP High Definition Audio Controller'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.form_factor' = 'internal'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.string' = '1'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.description' = 'Internes Audio'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'module-udev-detect.discovered' = '1'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.icon_name' = 'audio-card-pci'
(gsd-test-media-keys:15795): Gvc-DEBUG: 3 profiles supported on port Internes Mikrofon
(gsd-test-media-keys:15795): Gvc-DEBUG: 3 profiles supported on port Docking Station Mikrofon
(gsd-test-media-keys:15795): Gvc-DEBUG: 3 profiles supported on port Mikrofon
(gsd-test-media-keys:15795): Gvc-DEBUG: 4 profiles supported on port Speakers
(gsd-test-media-keys:15795): Gvc-DEBUG: 2 profiles supported on port Analoge Kopfhörer
(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - card: 0x1913970

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - card port name: analog-output-headphones

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - 1st line: Analoge Kopfhörer

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - 2nd line: Internes Audio

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - port available 0, value passed in 0 

(gsd-test-media-keys:15795): Gvc-DEBUG: Set profiles for 'Analoge Kopfhörer'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:analog-stereo' is 'output:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: Adding profile to combobox: 'output:analog-stereo' - 'Analog Stereo Output'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:analog-stereo+input:analog-stereo' is 'output:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:analog-stereo' is 'output:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:analog-stereo+input:analog-stereo' is 'output:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: create_ui_device_from_port, direction 1, description 'Analoge Kopfhörer', origin 'Internes Audio', port available 0
(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - card: 0x1913970

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - card port name: analog-output-speaker

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - 1st line: Speakers

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - 2nd line: Internes Audio

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - port available 1, value passed in 1 

(gsd-test-media-keys:15795): Gvc-DEBUG: Set profiles for 'Speakers'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:analog-surround-40' is 'output:analog-surround-40'
(gsd-test-media-keys:15795): Gvc-DEBUG: Adding profile to combobox: 'output:analog-surround-40' - 'Analog Surround 4.0 Output'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:analog-surround-40+input:analog-stereo' is 'output:analog-surround-40'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:analog-stereo' is 'output:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: Adding profile to combobox: 'output:analog-stereo' - 'Analog Stereo Output'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:analog-stereo+input:analog-stereo' is 'output:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:analog-surround-40' is 'output:analog-surround-40'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:analog-surround-40+input:analog-stereo' is 'output:analog-surround-40'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:analog-stereo' is 'output:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:analog-stereo+input:analog-stereo' is 'output:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: create_ui_device_from_port, direction 1, description 'Speakers', origin 'Internes Audio', port available 1
(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - card: 0x1913970

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - card port name: analog-input-mic

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - 1st line: Mikrofon

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - 2nd line: Internes Audio

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - port available 0, value passed in 0 

(gsd-test-media-keys:15795): Gvc-DEBUG: Set profiles for 'Mikrofon'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'input:analog-stereo' is 'input:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: Adding profile to combobox: 'input:analog-stereo' - 'Analog Stereo Input'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:analog-surround-40+input:analog-stereo' is 'input:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:analog-stereo+input:analog-stereo' is 'input:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'input:analog-stereo' is 'input:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:analog-surround-40+input:analog-stereo' is 'input:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:analog-stereo+input:analog-stereo' is 'input:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: create_ui_device_from_port, direction 0, description 'Mikrofon', origin 'Internes Audio', port available 0
(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - card: 0x1913970

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - card port name: analog-input-dock-mic

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - 1st line: Docking Station Mikrofon

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - 2nd line: Internes Audio

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - port available 0, value passed in 0 

(gsd-test-media-keys:15795): Gvc-DEBUG: Set profiles for 'Docking Station Mikrofon'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'input:analog-stereo' is 'input:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: Adding profile to combobox: 'input:analog-stereo' - 'Analog Stereo Input'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:analog-surround-40+input:analog-stereo' is 'input:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:analog-stereo+input:analog-stereo' is 'input:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'input:analog-stereo' is 'input:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:analog-surround-40+input:analog-stereo' is 'input:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:analog-stereo+input:analog-stereo' is 'input:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: create_ui_device_from_port, direction 0, description 'Docking Station Mikrofon', origin 'Internes Audio', port available 0
(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - card: 0x1913970

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - card port name: analog-input-internal-mic

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - 1st line: Internes Mikrofon

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - 2nd line: Internes Audio

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - port available 1, value passed in 1 

(gsd-test-media-keys:15795): Gvc-DEBUG: Set profiles for 'Internes Mikrofon'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'input:analog-stereo' is 'input:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: Adding profile to combobox: 'input:analog-stereo' - 'Analog Stereo Input'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:analog-surround-40+input:analog-stereo' is 'input:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:analog-stereo+input:analog-stereo' is 'input:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'input:analog-stereo' is 'input:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:analog-surround-40+input:analog-stereo' is 'input:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'output:analog-stereo+input:analog-stereo' is 'input:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: create_ui_device_from_port, direction 0, description 'Internes Mikrofon', origin 'Internes Audio', port available 1
(gsd-test-media-keys:15795): Gvc-DEBUG: Udpating card alsa_card.usb-046d_0821_A9E30B90-00 (index: 2 driver: module-alsa-card.c):
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Profile 'input:analog-stereo': 1 sources 0 sinks (Current)
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Profile 'off': 0 sources 0 sinks
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'alsa.card' = '2'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'alsa.card_name' = 'USB Device 0x46d:0x821'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'alsa.long_card_name' = 'USB Device 0x46d:0x821 at usb-0000:00:14.0-1.1, high speed'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'alsa.driver_name' = 'snd_usb_audio'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.bus_path' = 'pci-0000:00:14.0-usb-0:1.1:1.0'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'sysfs.path' = '/devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1.1/1-1.1:1.0/sound/card2'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'udev.id' = 'usb-046d_0821_A9E30B90-00'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.bus' = 'usb'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.vendor.id' = '046d'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.vendor.name' = 'Logitech, Inc.'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.product.id' = '0821'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.product.name' = 'HD Webcam C910'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.serial' = '046d_0821_A9E30B90'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.form_factor' = 'webcam'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.string' = '2'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.description' = 'HD Webcam C910'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'module-udev-detect.discovered' = '1'
(gsd-test-media-keys:15795): Gvc-DEBUG: 	Property: 'device.icon_name' = 'camera-web-usb'
(gsd-test-media-keys:15795): Gvc-DEBUG: 1 profiles supported on port Mikrofon
(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - card: 0x1a5b850

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - card port name: analog-input-mic

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - 1st line: Mikrofon

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - 2nd line: HD Webcam C910

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - port available 1, value passed in 1 

(gsd-test-media-keys:15795): Gvc-DEBUG: Set profiles for 'Mikrofon'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'input:analog-stereo' is 'input:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: Adding profile to combobox: 'input:analog-stereo' - 'Analog Stereo Input'
(gsd-test-media-keys:15795): Gvc-DEBUG: The canonical name for 'input:analog-stereo' is 'input:analog-stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: create_ui_device_from_port, direction 0, description 'Mikrofon', origin 'HD Webcam C910', port available 1
(gsd-test-media-keys:15795): Gvc-DEBUG: Updating client: index=0 name='Login Session 1'
(gsd-test-media-keys:15795): Gvc-DEBUG: Updating client: index=5 name='XSMP Session on gnome-session as 10795a9fbb41197352145632581564957200000018880031'
(gsd-test-media-keys:15795): Gvc-DEBUG: Updating client: index=9 name='gnome-settings-daemon'
(gsd-test-media-keys:15795): Gvc-DEBUG: Updating client: index=11 name='Icedove'
(gsd-test-media-keys:15795): Gvc-DEBUG: Updating client: index=93 name='GNOME Shell'
(gsd-test-media-keys:15795): Gvc-DEBUG: Updating client: index=94 name='GNOME Shell Volume Control'
(gsd-test-media-keys:15795): Gvc-DEBUG: Updating client: index=96 name='CubebUtils'
(gsd-test-media-keys:15795): Gvc-DEBUG: Updating client: index=103 name='GNOME Volume Control Media Keys'
(gsd-test-media-keys:15795): Gvc-DEBUG: Updating sink: index=0 name='alsa_output.pci-0000_00_03.0.hdmi-stereo' description='Internes Audio Digital Stereo (HDMI)' map='front-left,front-right'
(gsd-test-media-keys:15795): Gvc-DEBUG: update sink - is new
(gsd-test-media-keys:15795): Gvc-DEBUG: Attempt to match_stream update_with_existing_outputs - Try description : 'Speakers', origin : 'Internes Audio', device port name : 'analog-output-speaker', card : 0x1913970, AGAINST stream port: 'hdmi-output-0', sink card id 0
(gsd-test-media-keys:15795): Gvc-DEBUG: Attempt to match_stream update_with_existing_outputs - Try description : 'Analoge Kopfhörer', origin : 'Internes Audio', device port name : 'analog-output-headphones', card : 0x1913970, AGAINST stream port: 'hdmi-output-0', sink card id 0
(gsd-test-media-keys:15795): Gvc-DEBUG: Attempt to match_stream update_with_existing_outputs - Try description : 'HDMI / DisplayPort', origin : 'Internes Audio', device port name : 'hdmi-output-0', card : 0x1986e40, AGAINST stream port: 'hdmi-output-0', sink card id 0
(gsd-test-media-keys:15795): Gvc-DEBUG: Match device with stream: We have a match with description: 'HDMI / DisplayPort', origin: 'Internes Audio', cached already with device id 3, so set stream id to 1
(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - sink/source id: 1

(gsd-test-media-keys:15795): Gvc-DEBUG: Updating sink: index=1 name='alsa_output.pci-0000_00_1b.0.analog-stereo' description='Internes Audio Analog Stereo' map='front-left,front-right'
(gsd-test-media-keys:15795): Gvc-DEBUG: update sink - is new
(gsd-test-media-keys:15795): Gvc-DEBUG: Attempt to match_stream update_with_existing_outputs - Try description : 'Speakers', origin : 'Internes Audio', device port name : 'analog-output-speaker', card : 0x1913970, AGAINST stream port: 'analog-output-headphones', sink card id 1
(gsd-test-media-keys:15795): Gvc-DEBUG: Attempt to match_stream update_with_existing_outputs - Try description : 'Analoge Kopfhörer', origin : 'Internes Audio', device port name : 'analog-output-headphones', card : 0x1913970, AGAINST stream port: 'analog-output-headphones', sink card id 1
(gsd-test-media-keys:15795): Gvc-DEBUG: Match device with stream: We have a match with description: 'Analoge Kopfhörer', origin: 'Internes Audio', cached already with device id 4, so set stream id to 2
(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - sink/source id: 2

(gsd-test-media-keys:15795): Gvc-DEBUG: Attempt to match_stream update_with_existing_outputs - Try description : 'Speakers', origin : 'Internes Audio', device port name : 'analog-output-speaker', card : 0x1913970, AGAINST stream port: 'analog-output-speaker', sink card id 1
(gsd-test-media-keys:15795): Gvc-DEBUG: Match device with stream: We have a match with description: 'Speakers', origin: 'Internes Audio', cached already with device id 5, so set stream id to 2
(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - sink/source id: 2

(gsd-test-media-keys:15795): Gvc-DEBUG: lookup-device-from-stream found device: device description 'Speakers', device port = 'analog-output-speaker', device stream id 2 AND stream port = 'analog-output-speaker' stream id '2' and stream description 'Internes Audio Analog Stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: gvc_mixer_control_lookup_device_from_stream - Could not find a device for stream 'Internes Audio Analog Stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: active_sink change
(gsd-test-media-keys:15795): Gvc-DEBUG: Updating sink: index=2 name='upnp' description='DLNA/UPnP Streaming' map='front-left,front-right'
(gsd-test-media-keys:15795): Gvc-DEBUG: update sink - is new
(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - sink/source id: 3

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - 1st line: DLNA/UPnP Streaming

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - 2nd line: 

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - card port name: (null)

(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - port available 1, value passed in 1 

(gsd-test-media-keys:15795): Gvc-DEBUG: Updating source: index=0 name='alsa_output.pci-0000_00_03.0.hdmi-stereo.monitor' description='Monitor of Internes Audio Digital Stereo (HDMI)'
(gsd-test-media-keys:15795): Gvc-DEBUG: Updating source: index=1 name='alsa_output.pci-0000_00_1b.0.analog-stereo.monitor' description='Monitor of Internes Audio Analog Stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: Updating source: index=2 name='alsa_input.pci-0000_00_1b.0.analog-stereo' description='Internes Audio Analog Stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: update source
(gsd-test-media-keys:15795): Gvc-DEBUG: Attempt to match_stream update_with_existing_outputs - Try description : 'Mikrofon', origin : 'Internes Audio', device port name : 'analog-input-mic', card : 0x1913970, AGAINST stream port: 'analog-input-dock-mic', sink card id 1
(gsd-test-media-keys:15795): Gvc-DEBUG: Attempt to match_stream update_with_existing_outputs - Try description : 'Mikrofon', origin : 'HD Webcam C910', device port name : 'analog-input-mic', card : 0x1a5b850, AGAINST stream port: 'analog-input-dock-mic', sink card id 1
(gsd-test-media-keys:15795): Gvc-DEBUG: Attempt to match_stream update_with_existing_outputs - Try description : 'Internes Mikrofon', origin : 'Internes Audio', device port name : 'analog-input-internal-mic', card : 0x1913970, AGAINST stream port: 'analog-input-dock-mic', sink card id 1
(gsd-test-media-keys:15795): Gvc-DEBUG: Attempt to match_stream update_with_existing_outputs - Try description : 'Docking Station Mikrofon', origin : 'Internes Audio', device port name : 'analog-input-dock-mic', card : 0x1913970, AGAINST stream port: 'analog-input-dock-mic', sink card id 1
(gsd-test-media-keys:15795): Gvc-DEBUG: Match device with stream: We have a match with description: 'Docking Station Mikrofon', origin: 'Internes Audio', cached already with device id 7, so set stream id to 4
(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - sink/source id: 4

(gsd-test-media-keys:15795): Gvc-DEBUG: Attempt to match_stream update_with_existing_outputs - Try description : 'Mikrofon', origin : 'Internes Audio', device port name : 'analog-input-mic', card : 0x1913970, AGAINST stream port: 'analog-input-mic', sink card id 1
(gsd-test-media-keys:15795): Gvc-DEBUG: Match device with stream: We have a match with description: 'Mikrofon', origin: 'Internes Audio', cached already with device id 6, so set stream id to 4
(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - sink/source id: 4

(gsd-test-media-keys:15795): Gvc-DEBUG: Attempt to match_stream update_with_existing_outputs - Try description : 'Mikrofon', origin : 'Internes Audio', device port name : 'analog-input-mic', card : 0x1913970, AGAINST stream port: 'analog-input-internal-mic', sink card id 1
(gsd-test-media-keys:15795): Gvc-DEBUG: Attempt to match_stream update_with_existing_outputs - Try description : 'Mikrofon', origin : 'HD Webcam C910', device port name : 'analog-input-mic', card : 0x1a5b850, AGAINST stream port: 'analog-input-internal-mic', sink card id 1
(gsd-test-media-keys:15795): Gvc-DEBUG: Attempt to match_stream update_with_existing_outputs - Try description : 'Internes Mikrofon', origin : 'Internes Audio', device port name : 'analog-input-internal-mic', card : 0x1913970, AGAINST stream port: 'analog-input-internal-mic', sink card id 1
(gsd-test-media-keys:15795): Gvc-DEBUG: Match device with stream: We have a match with description: 'Internes Mikrofon', origin: 'Internes Audio', cached already with device id 8, so set stream id to 4
(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - sink/source id: 4

(gsd-test-media-keys:15795): Gvc-DEBUG: lookup-device-from-stream found device: device description 'Internes Mikrofon', device port = 'analog-input-internal-mic', device stream id 4 AND stream port = 'analog-input-internal-mic' stream id '4' and stream description 'Internes Audio Analog Stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: gvc_mixer_control_lookup_device_from_stream - Could not find a device for stream 'Internes Audio Analog Stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: Updating source: index=3 name='upnp.monitor' description='Monitor of DLNA/UPnP Streaming'
(gsd-test-media-keys:15795): Gvc-DEBUG: Updating source: index=4 name='alsa_input.usb-046d_0821_A9E30B90-00.analog-stereo' description='HD Webcam C910 Analog Stereo'
(gsd-test-media-keys:15795): Gvc-DEBUG: update source
(gsd-test-media-keys:15795): Gvc-DEBUG: Attempt to match_stream update_with_existing_outputs - Try description : 'Mikrofon', origin : 'Internes Audio', device port name : 'analog-input-mic', card : 0x1913970, AGAINST stream port: 'analog-input-mic', sink card id 2
(gsd-test-media-keys:15795): Gvc-DEBUG: Attempt to match_stream update_with_existing_outputs - Try description : 'Mikrofon', origin : 'HD Webcam C910', device port name : 'analog-input-mic', card : 0x1a5b850, AGAINST stream port: 'analog-input-mic', sink card id 2
(gsd-test-media-keys:15795): Gvc-DEBUG: Match device with stream: We have a match with description: 'Mikrofon', origin: 'HD Webcam C910', cached already with device id 9, so set stream id to 5
(gsd-test-media-keys:15795): Gvc-DEBUG: gvc-mixer-output-set-property - sink/source id: 5

(gsd-test-media-keys:15795): media-keys-plugin-DEBUG: Setting up custom keybinding /org/gnome/settings-daemon/plugins/media-keys/custom-keybindings/custom0/
(gsd-test-media-keys:15795): media-keys-plugin-DEBUG: media_key_new_for_path: /org/gnome/settings-daemon/plugins/media-keys/custom-keybindings/custom0/
(gsd-test-media-keys:15795): media-keys-plugin-DEBUG: Setting up custom keybinding /org/gnome/settings-daemon/plugins/media-keys/custom-keybindings/custom1/
(gsd-test-media-keys:15795): media-keys-plugin-DEBUG: media_key_new_for_path: /org/gnome/settings-daemon/plugins/media-keys/custom-keybindings/custom1/
(gsd-test-media-keys:15795): media-keys-plugin-DEBUG: Setting up custom keybinding /org/gnome/settings-daemon/plugins/media-keys/custom-keybindings/custom3/
(gsd-test-media-keys:15795): media-keys-plugin-DEBUG: media_key_new_for_path: /org/gnome/settings-daemon/plugins/media-keys/custom-keybindings/custom3/
(gsd-test-media-keys:15795): media-keys-plugin-DEBUG: Setting up custom keybinding /org/gnome/settings-daemon/plugins/media-keys/custom-keybindings/custom2/
(gsd-test-media-keys:15795): media-keys-plugin-DEBUG: media_key_new_for_path: /org/gnome/settings-daemon/plugins/media-keys/custom-keybindings/custom2/
(gsd-test-media-keys:15795): media-keys-plugin-DEBUG: Setting up custom keybinding /org/gnome/settings-daemon/plugins/media-keys/custom-keybindings/custom4/
(gsd-test-media-keys:15795): media-keys-plugin-DEBUG: media_key_new_for_path: /org/gnome/settings-daemon/plugins/media-keys/custom-keybindings/custom4/
(gsd-test-media-keys:15795): media-keys-plugin-DEBUG: Setting up custom keybinding /org/gnome/settings-daemon/plugins/media-keys/custom-keybindings/custom5/
(gsd-test-media-keys:15795): media-keys-plugin-DEBUG: media_key_new_for_path: /org/gnome/settings-daemon/plugins/media-keys/custom-keybindings/custom5/
(gsd-test-media-keys:15795): media-keys-plugin-DEBUG: Setting up custom keybinding /org/gnome/settings-daemon/plugins/media-keys/custom-keybindings/custom6/
(gsd-test-media-keys:15795): media-keys-plugin-DEBUG: media_key_new_for_path: /org/gnome/settings-daemon/plugins/media-keys/custom-keybindings/custom6/
(gsd-test-media-keys:15795): media-keys-plugin-DEBUG: Setting up custom keybinding /org/gnome/settings-daemon/plugins/media-keys/custom-keybindings/custom7/
(gsd-test-media-keys:15795): media-keys-plugin-DEBUG: media_key_new_for_path: /org/gnome/settings-daemon/plugins/media-keys/custom-keybindings/custom7/
(gsd-test-media-keys:15795): media-keys-plugin-DEBUG: Setting up custom keybinding /org/gnome/settings-daemon/plugins/media-keys/custom-keybindings/custom8/
(gsd-test-media-keys:15795): media-keys-plugin-DEBUG: media_key_new_for_path: /org/gnome/settings-daemon/plugins/media-keys/custom-keybindings/custom8/
(gsd-test-media-keys:15795): media-keys-plugin-DEBUG: Setting up custom keybinding /org/gnome/settings-daemon/plugins/media-keys/custom-keybindings/custom9/
(gsd-test-media-keys:15795): media-keys-plugin-DEBUG: media_key_new_for_path: /org/gnome/settings-daemon/plugins/media-keys/custom-keybindings/custom9/

Comment 7 Bastien Nocera 2016-02-25 14:30:18 UTC

Could you please run:
dbus-monitor --session "type='signal',sender='org.gnome.Shell',member='AcceleratorActivated'"

And try one of your custom keybindings? It will tell us whether gnome-shell is sending the events as expected (and therefore the bug lives in gnome-settings-daemon) or if it doesn't, and the problem is therefore in gnome-shell.

Comment 8 Andreas Kloeckner 2016-02-25 21:55:50 UTC

Tried. It does send AcceleratorActivated events. I can't show you the output (yet) because I ran itno display driver issues that led to me having to reboot--but I did see them. I'll paste the output next time I run into this.

Comment 9 Andreas Kloeckner 2016-02-28 23:22:34 UTC

Here's some sample output:

signal time=1456701628.150219 sender=:1.201 -> destination=:1.18 serial=372 path=/org/gnome/Shell; interface=org.gnome.Shell; member=AcceleratorActivated
   uint32 162
   array [
      dict entry(
         string "device-id"
         variant             uint32 3
      )
      dict entry(
         string "timestamp"
         variant             uint32 29141127
      )
      dict entry(
         string "action-mode"
         variant             uint32 1
      )
   ]
signal time=1456701628.756742 sender=:1.201 -> destination=:1.18 serial=373 path=/org/gnome/Shell; interface=org.gnome.Shell; member=AcceleratorActivated
   uint32 162
   array [
      dict entry(
         string "device-id"
         variant             uint32 3
      )
      dict entry(
         string "timestamp"
         variant             uint32 29141735
      )
      dict entry(
         string "action-mode"
         variant             uint32 1
      )
   ]

Comment 10 Bastien Nocera 2016-03-03 13:58:26 UTC

(In reply to Andreas Kloeckner from comment #9)
> Here's some sample output:

And that's when it's not working?

I've added 2 more commits to gnome-settings-daemon master that should make it easier to debug the problem. Please ask your distribution to prepare debug packages with gnome-settings-daemon 3.18.2 and those 2 patches and attach the same data as requested in comment 5.

commit a09ae56c360852da60d4f5b5c155b0b461a4a62d
Author: Bastien Nocera <hadess@hadess.net>
Date:   Thu Mar 3 14:38:05 2016 +0100

    media-keys: Add more debug when receiving accel from shell
    
    Some more code to help out with the debugging of hard to reproduce
    disappearing custom accelerators.

commit 5f016430eaf38a74b839df0a182d0aa35726bb9d
Author: Bastien Nocera <hadess@hadess.net>
Date:   Thu Mar 3 14:27:57 2016 +0100

    media-keys: Add more debug output when D-Bus calls fail
    
    This might help us root-cause a few hard to debug problems losing the
    ability to handle custom shortcuts.

Comment 11 Andreas Kloeckner 2016-03-03 15:05:23 UTC

Yep, that's when it's not working. I'll follow up with someone in Debian about including those.

Comment 12 Bastien Nocera 2016-03-03 15:47:43 UTC

You'll also want to pick:
commit dc13b2de39631d2b56d8a1aae8bcbfb8313cd181
Author: Bastien Nocera <hadess@hadess.net>
Date:   Thu Feb 25 11:10:16 2016 +0100

    media-keys: Add some debug when capturing media keys
    
    When failing to capture media-keys or retrying, print out some debug,
    otherwise it's hard to see what's happening.

Comment 13 Andreas Kloeckner 2016-03-04 20:36:09 UTC

I rebuilt g-s-d with those patches applied. They didn't apply cleanly to 3.18.2, so I had
to do some hacking to clean up the conflicts. This is the diff I ended up with:

https://tiker.net/tmp/gsd.diff

Long story short, this stops working again (in a session with the patched
g-s-d). I run

gsettings set org.gnome.settings-daemon.plugins.media-keys active false

and

/usr/lib/gnome-settings-daemon/gsd-test-media-keys

It spews a ton of stuff on startup:

https://gist.github.com/inducer/48d91af3591704741461

But there's no longer any output for each pressed accelerator key.

Comment 14 Andreas Kloeckner 2016-03-28 16:32:09 UTC

So I've updated to Gnome 3.20 in the hope that this might make things better, but, unfortunately, not so. In fact, this appears to happen after essentially every single monitor hotplug. Further, restarting the shell now seems to have a very low probability of reviving the accelerators. In addition, I've recently started using "Shellshape", which is great, but it occasionally crashes the shell on restart. Since I need to restart the shell ~10 times to revive the accelerators, I'm effectively guaranteed a crashed desktop session and a forced logout if I'd like to have working accelerators.

In addition, third-party tools like xbindkeys don't seem able to pick up key bindings with the Windows key in them, so I can't easily replace this functionality either.

Help?

Comment 15 Rui Matos 2016-03-29 20:17:47 UTC

Can you reproduce this with a different computer? Can you try to reproduce on a live USB system like Fedora 24 ?

Comment 16 Andreas Kloeckner 2016-03-29 21:34:53 UTC

Just spotted that these messages have started showing up in the log whenever I press an accelerator key which ends up having no effect:

Mar 29 16:18:03 bolt gnome-settings-daemon.desktop[2159]: (gnome-settings-daemon:2159): media-keys-plugin-WARNING **: Could not find accelerator for accel id 219
Mar 29 16:18:03 bolt gnome-settings-daemon.desktop[2159]: (gnome-settings-daemon:2159): media-keys-plugin-WARNING **: Could not find accelerator for accel id 219
Mar 29 16:18:04 bolt gnome-settings-daemon.desktop[2159]: (gnome-settings-daemon:2159): media-keys-plugin-WARNING **: Could not find accelerator for accel id 219
Mar 29 16:18:04 bolt gnome-settings-daemon.desktop[2159]: (gnome-settings-daemon:2159): media-keys-plugin-WARNING **: Could not find accelerator for accel id 219
Mar 29 16:18:04 bolt gnome-settings-daemon.desktop[2159]: (gnome-settings-daemon:2159): media-keys-plugin-WARNING **: Could not find accelerator for accel id 219
Mar 29 16:18:04 bolt gnome-settings-daemon.desktop[2159]: (gnome-settings-daemon:2159): media-keys-plugin-WARNING **: Could not find accelerator for accel id 219

Comment 17 Andreas Kloeckner 2016-03-30 04:39:35 UTC

This Ubuntu bug seems related:

https://bugs.launchpad.net/ubuntu-gnome/+bug/1427877

I'll also note that I have a Wacom tablet.

Comment 18 Andreas Kloeckner 2016-03-30 13:13:14 UTC

Noticed something else: As of GNOME 3.20, two issues appear to co-occur at the same times:

(1) My session loses contact with its (seahorse-provided) SSH agent
(2) The keybindings stop working

I.e. one is broken if and only if the other is broken.

Comment 19 Bastien Nocera 2016-04-18 11:42:55 UTC

(In reply to Andreas Kloeckner from comment #18)
> Noticed something else: As of GNOME 3.20, two issues appear to co-occur at
> the same times:
> 
> (1) My session loses contact with its (seahorse-provided) SSH agent

I think a crash in gnome-settings-daemon can cause that, in some cases.

Try running:
gsettings set org.gnome.settings-daemon.plugins.smartcard active false

I think it's related to:
https://bugzilla.gnome.org/show_bug.cgi?id=765203

> (2) The keybindings stop working
> 
> I.e. one is broken if and only if the other is broken.

Looks like that if gnome-settings-daemon crashes, depending on when it crashes, we might end up with gnome-shell sending us keyboard accelerators we haven't registered.

Comment 20 Bastien Nocera 2016-04-18 11:55:37 UTC

If gnome-shell sends us accelerator that we haven't requested, then it's likely a problem with gnome-shell not monitoring our existence properly.

Comment 21 Andreas Kloeckner 2016-04-20 03:22:59 UTC

I can't be entirely sure (since it's intermittent), but it's looking promising. At least for now the smartcard disable line seems to have gone a long way. The issue hasn't recurred in a half day, when it typically would have, many times.

Thank you so much for tracking this down (hopefully)!

Comment 22 Andreas Kloeckner 2016-04-20 03:23:56 UTC

Marking fixed for now.

Comment 23 Andreas Kloeckner 2016-04-20 16:36:40 UTC

Argh. Spoke too soon. It feels like the rate of incidence is reduced by the smartcard thing, but I *am* still seeing this issue. (And in a sense, maybe, that's consistent with the race condition thing you point out in 
https://bugzilla.gnome.org/show_bug.cgi?id=765203 ?)

Comment 24 Bastien Nocera 2016-04-20 17:02:04 UTC

(In reply to Andreas Kloeckner from comment #23)
> Argh. Spoke too soon. It feels like the rate of incidence is reduced by the
> smartcard thing, but I *am* still seeing this issue. (And in a sense, maybe,
> that's consistent with the race condition thing you point out in 
> https://bugzilla.gnome.org/show_bug.cgi?id=765203 ?)

See comment 20.

There's 2 problems, gnome-settings-daemon crashing, and when that happens, gnome-shell sending accelerators we didn't request.

You'll need to file a new bug against gnome-settings-daemon when you can gather a backtrace of the crash. Fixing that crash will make the gnome-shell problem less frequent, but we'll still need to fix gnome-shell eventually.

Comment 25 Andreas Kloeckner 2016-04-20 18:45:35 UTC

Done:

https://bugzilla.gnome.org/show_bug.cgi?id=765339

How would I collect a backtrace of a g-s-d crash?

Comment 26 Florian Müllner 2016-04-20 19:07:01 UTC

(In reply to Bastien Nocera from comment #20)
> If gnome-shell sends us accelerator that we haven't requested, then it's
> likely a problem with gnome-shell not monitoring our existence properly.

We are supposed to ungrab accelerators when the grabbing bus name goes away[0] - there's nothing that looks immediately wrong there :-(

[0] https://git.gnome.org/browse/gnome-shell/tree/js/ui/shellDBus.js#n237

Comment 27 Andreas Kloeckner 2016-04-20 20:07:46 UTC

*** Bug 765339 has been marked as a duplicate of this bug. ***

Comment 28 Andreas Kloeckner 2016-04-20 20:10:38 UTC

Corresponding g-s-d bug:

https://bugzilla.gnome.org/show_bug.cgi?id=765347

Comment 29 Rui Matos 2016-05-24 12:00:49 UTC

Can you check if this mutter patch fixes the issue ?

https://git.gnome.org/browse/mutter/commit/?id=e160babe3f3d82718f1d015db3e07b469f731aff

Comment 30 Andreas Kloeckner 2016-06-02 15:40:27 UTC

Thanks for the patch. Unfortunately, it doesn't seem to help. I built it last night (by patching Debian's 3.20.2-1 mutter package), installed the modified packages, rebooted my computer. The problem recurred this morning when I woke my computer from standby. On the other hand, it at least doesn't seem to hurt anything.

Interestingly, some form of monitor hotplug now also seems to be occurring whenever my screen turns itself off for powersaving, without putting the computer to sleep. That makes occurrences of this bug a whole lot more frequent and aggravating.

Once again, thanks for putting together the patch, and sorry that I don't have better news!

Comment 31 Andreas Kloeckner 2016-06-02 15:44:57 UTC

Whoops. I overlooked the libmutter*.deb packages and the corresponding GIR packages. Will report back.

Comment 32 Andreas Kloeckner 2016-06-06 16:28:54 UTC

Just rebooted with everything correctly installed, and the bug recurred on the first screen sleep thereafter. So, in other words, no, it doesn't seem like that patch helps much.

Comment 33 Rui Matos 2016-06-06 16:36:46 UTC

Do you still get these messages:

media-keys-plugin-WARNING **: Could not find accelerator for accel id 219

?

Comment 34 Andreas Kloeckner 2016-06-06 17:24:15 UTC

Some potentially incriminating messages from the log:

Jun 06 10:49:20 bolt org.gnome.Shell.desktop[2329]: ** (gnome-shell:2329): CRITICAL **: remove_mnemonics: assertion 'label != NULL' failed

Jun 06 11:04:34 bolt gnome-settings-daemon.desktop[2227]: (gnome-settings-daemon:2227): media-keys-plugin-WARNING **: Could not find accelerator for accel id 219
Jun 06 11:04:35 bolt gnome-settings-daemon.desktop[2227]: (gnome-settings-daemon:2227): media-keys-plugin-WARNING **: Could not find accelerator for accel id 219
Jun 06 11:04:35 bolt gnome-settings-daemon.desktop[2227]: (gnome-settings-daemon:2227): media-keys-plugin-WARNING **: Could not find accelerator for accel id 219
Jun 06 11:04:35 bolt gnome-settings-daemon.desktop[2227]: (gnome-settings-daemon:2227): media-keys-plugin-WARNING **: Could not find accelerator for accel id 219

Jun 06 11:04:38 bolt org.gnome.Shell.desktop[2329]: (gnome-shell:2329): Gjs-WARNING **: JS ERROR: could not get remote objects for service org.gnome.SettingsDaemon.Smartcard path /org/gnome/SettingsDaemon/Smartcard: Gio.DBusError: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name
Jun 06 11:04:38 bolt org.gnome.Shell.desktop[2329]: _proxyInvoker/asyncCallback@resource:///org/gnome/gjs/modules/overrides/Gio.js:83

I restarted gnome-shell several times (Alt-F2, r) until everything started working again. Full logs here:

https://tiker.net/tmp/gnome.log

Comment 35 Rui Matos 2016-06-06 17:46:59 UTC

This is what I'd expect without that mutter patch. Are you 100% sure that the libmutter.so that you're running includes the patch? If you're rebuilding the .deb locally, are you sure the patch is being applied?

Comment 36 Andreas Kloeckner 2016-06-26 20:17:47 UTC

Yeah, I'm sure it's applied. I built the .deb with a different package epoch and that's what's installed.

Comment 37 Bastien Nocera 2016-10-10 21:25:52 UTC

I've reproduced this locally, although, very helpfully, it runs fine if you restart the media-keys plugin.

Oct 10 20:27:02 classic gsd-media-keys[3443]: Could not find accelerator for accel id 135

Next time it happens, I'll try to double-check that gnome-shell is sending the right information, and that we're checking against correct information.

Comment 38 Andreas Kloeckner 2016-10-10 21:52:35 UTC

Comment 39 Bastien Nocera 2016-10-16 00:48:15 UTC

*** Bug 773005 has been marked as a duplicate of this bug. ***

Comment 40 Bastien Nocera 2016-10-24 08:54:21 UTC

*** Bug 773406 has been marked as a duplicate of this bug. ***

Comment 41 Christian Stadelmann 2016-10-24 18:30:03 UTC

Can anybody confirm this was working with 3.22.0? See bug #773005

Comment 42 Andreas Kloeckner 2016-10-24 18:39:43 UTC

I still occasionally have this issue with 3.22.1, although it does appear that the rate of incidence is greatly reduced. The bug itself is much older--definitely in 3.20, likely also in 3.18.

Comment 43 Christian Stadelmann 2016-10-26 16:40:38 UTC

(In reply to Andreas Kloeckner from comment #42)
> I still occasionally have this issue with 3.22.1, although it does appear
> that the rate of incidence is greatly reduced. The bug itself is much
> older--definitely in 3.20, likely also in 3.18.

Looks the same for me too. I've run into it yesterday and don't see this issue today despite some reboots on the same machine.

Comment 44 Matthias Runge 2016-12-19 08:24:13 UTC

This issue suddenly appeared for me with custom keyboard shortcuts.
gnome-shell-3.22.2-2.fc25.x86_64

When pressing my custom shortcut, I see in logs
Dec 19 09:22:09 sofja journal: Could not find accelerator for accel id 152
Dec 19 09:22:12 sofja journal: Could not find accelerator for accel id 152

Comment 45 Matthijs Kooijman 2016-12-30 14:14:16 UTC

Created attachment 342625 [details]
Log output showing entering/returning from standby breaks shortcuts

Comment 46 Matthijs Kooijman 2016-12-30 14:15:23 UTC

Created attachment 342626 [details]
Log output showing entering/returning from standby does *not* break

Comment 47 Matthijs Kooijman 2016-12-30 14:16:04 UTC

I've also seen this (or a similar problem) occuring, now running 3.22.2 on Debian. I mostly noticed the hotkeys breaking when returning from standby, but it might very well be that it was triggered by a change in my monitor setup due to dock/undock, or perhaps even from the standby itself.

Yesterday, I could reproduce this problem multiple times by putting my laptop in standby, see the attached log for one such session. Today, I added some extra debug logging (most notably the "Have accel" lines in the second attachment) in g-s-d, but I cannot reproduce the problem anymore.

One difference is that in the problematic log, there is a lot of extra stuff happening after return from standby. I've marked this block in the attachment. it seems the same or similar log output is repeated 6 times, consisting of different kinds of output, but these lines look like they might related to this problem:

gnome-settings-[21212]: Removing custom key binding /org/gnome/settings-daemon/plugins/media-keys/custom-keybindings/custom0/
gnome-settings-[21212]: media_key_new_for_path: /org/gnome/settings-daemon/plugins/media-keys/custom-keybindings/custom0/
gnome-settings-[21212]: Adding new custom key binding /org/gnome/settings-daemon/plugins/media-keys/custom-keybindings/custom0/

These lines are repeated twice for every custom keybinding and are present in the problematic log output, but not in the working log output.

In both log outputs, you can pinpoint the standby moment by the first line after returning from standby, which is "systemd[3202]: Time has been changed".

Comment 48 Bastien Nocera 2016-12-30 15:30:05 UTC

(In reply to Matthijs Kooijman from comment #47)
> I've also seen this (or a similar problem) occuring, now running 3.22.2 on
> Debian. I mostly noticed the hotkeys breaking when returning from standby,
> but it might very well be that it was triggered by a change in my monitor
> setup due to dock/undock, or perhaps even from the standby itself.
> 
> Yesterday, I could reproduce this problem multiple times by putting my
> laptop in standby, see the attached log for one such session. Today, I added
> some extra debug logging (most notably the "Have accel" lines in the second
> attachment) in g-s-d, but I cannot reproduce the problem anymore.
> 
> One difference is that in the problematic log, there is a lot of extra stuff
> happening after return from standby. I've marked this block in the
> attachment. it seems the same or similar log output is repeated 6 times,
> consisting of different kinds of output, but these lines look like they
> might related to this problem:

I think this might be related to dconf:

It detects the power management settings have changed:
Dec 29 11:07:03 grubby gnome-settings-[21212]: setting up sleep callback 3600s

The XSettings have changed:
Dec 29 11:07:03 grubby gnome-settings-[21212]: xft_settings_set_xresources: orig res '*customization:        -color

The a11y settings have changed:
Dec 29 11:07:03 grubby gnome-settings-[21212]: screen reader or OSK enablement changed

The automatic timezone settings have changed:
Dec 29 11:07:03 grubby gnome-settings-[21212]: Automatic timezone disabled

The keyboard settings have changed:
Dec 29 11:07:03 grubby gnome-settings-[21212]: Remember Num-Lock state 'remember-numlock-state' changed, applying num-lock settings

The custom keybindings have changed:
Dec 29 11:07:03 grubby gnome-settings-[21212]: Removing custom key binding /org/gnome/settings-daemon/plugins/media-keys/custom-keybindings/custom0/

And all those in a loop.

Anything weird in ~/.config/dconf/ ? Maybe a user.XXX file with a timestamp that matches the "not working" case?

This also can't be good:
Dec 29 11:06:05 grubby gnome-settings-[21212]: media_key_new_for_path: /org/gnome/settings-daemon/plugins/media-keys/custom-keybindings/custom0/
Dec 29 11:06:05 grubby gnome-settings-[21212]: Adding new custom key binding /org/gnome/settings-daemon/plugins/media-keys/custom-keybindings/custom0/
Dec 29 11:06:05 grubby gnome-settings-[21212]: g_dbus_proxy_call_internal: assertion 'G_IS_DBUS_PROXY (proxy)' failed

And this also cannot be good:
Dec 29 11:06:06 grubby gnome-shell[21182]: g_signal_handler_disconnect: assertion 'handler_id > 0' failed
Dec 29 11:06:06 grubby gnome-shell[21182]: /build/glib2.0-YqrQRU/glib2.0-2.50.2/./gobject/gsignal.c:2641: instance '0x55fe81188540' has no handler with id '8256'
Dec 29 11:06:06 grubby gnome-shell[21182]: JS LOG: [pixel-saver]: 'appmenu' is not a valid button.
Dec 29 11:06:06 grubby org.gnome.Shell.desktop[21182]: Window manager warning: Trying to re-add keybinding "switch-window-next-workspace".
Dec 29 11:06:06 grubby org.gnome.Shell.desktop[21182]: Window manager warning: Trying to re-add keybinding "switch-window-prev-workspace".
Dec 29 11:06:06 grubby gnome-shell[21182]: g_signal_handler_disconnect: assertion 'handler_id > 0' failed
Dec 29 11:06:06 grubby gnome-shell[21182]: /build/glib2.0-YqrQRU/glib2.0-2.50.2/./gobject/gsignal.c:2641: instance '0x55fe80fd3050' has no handler with id '14839'

Are you also really running all those extensions? Because this:
Dec 29 11:06:11 grubby gnome-shell[21182]: JS ERROR: TypeError: boxes[0] is undefined
createButtons/<@/home/matthijs/.local/share/gnome-shell/extensions/pixel-saver@deadalnix.me/buttons.js:86

Followed by this:
Dec 29 11:06:13 grubby gnome-shell[21182]: Attempting to remove actor of type 'ShellTrayIcon' from group of class 'StButton', but the container is not the actor's parent.
Dec 29 11:06:13 grubby org.gnome.Shell.desktop[21182]: **
Dec 29 11:06:13 grubby org.gnome.Shell.desktop[21182]: St:ERROR:st/st-bin.c:186:st_bin_dispose: assertion failed: (priv->child == NULL)
Dec 29 11:06:13 grubby gnome-session[21084]: gnome-session-binary[21084]: WARNING: Application 'org.gnome.Shell.desktop' killed by signal 6

means that I won't be looking at this problem until you can assure me that you can reproduce the problem without those extensions.

Comment 49 Andreas Kloeckner 2017-02-12 19:31:37 UTC

Keyboard shortcuts have started crashing my X session instead of not working. This is getting irritating...

Comment 50 Andreas Kloeckner 2017-02-12 19:33:55 UTC

Although the "not working" failure mode also still exists. So it's not clear that the session crashes are really the same thing. There doesn't seem to be much in terms of incriminating information in the logs...

Comment 51 Matthijs Kooijman 2017-02-12 21:17:12 UTC

I've since done a bit more debugging, but I didn't post yet because I have yet to try without extensions. However, since what I've found doesn't point to any extension, I'll share it here anyway.

What seems to happen is:
 - custom_binding_changed is called with settings_key=binding for the custom shortcut.
 - update_custom_binding is called, which removes the binding and adds a new one.
 - Before the addition completes, custom_binding_changed is called again for settings_key=command.
 - update_custom_binding is called again, which removes the binding again and adds it again.
 - Then, the first addition completes, with a valid accelerator id.
 - Then, the second addition completes, with an accelerator id of 0 (presumably because the key is already bound by the first call). This 0 then overwrites the previously succesful binding, subsequently breaking the keybinding.

Regardless of what *caused* this extra settings changes (which might be an extension, dunno), it seems that gsd has a race condition here. To fix it, I can imagine something like:
 - keep a flag for each keybinding, to track if an addition for it is currently in progress.
 - When something changes, but an addition is already is progress, set a second "dirty" flag.
 - When addition completes, but the dirty flag is set, trigger another remove-add cycle.

Not being too familiar with the codebase, there might be easier or better solutions, though.

Comment 52 Rui Matos 2017-02-13 16:06:12 UTC

Created attachment 345639 [details] [review]
media-keys: Avoid multiple grab/ungrab pairs on custom binding changes

If there are gsettings changes to a custom binding's gsettings we
could end up calling update_custom_binding() twice in a row: one for
the 'binding' setting and one for the 'command' setting. This means
that we would add the same binding twice and the second addition would
fail resulting in key->accel_id being set to 0, preventing us from
handling the binding when it gets activated.

Since we're only interested in changes to the 'binding' setting, we
can prevent this problem and the extra work we always do by ignoring
changes to any other setting keys.

Comment 53 Bastien Nocera 2017-02-13 16:55:10 UTC

Review of attachment 345639 [details] [review]:

Yep, go for it. And please cherry-pick it as well.

Comment 54 Rui Matos 2017-02-13 21:02:05 UTC

Created attachment 345670 [details] [review]
media-keys: Reference count MediaKey struct instances

--

This and the next few patches should prevent any other issues with
our grab bookkeeping AFAICT.

Comment 55 Rui Matos 2017-02-13 21:02:23 UTC

Created attachment 345671 [details] [review]
media-keys: Avoid using free'd memory

If a MetaKey instance is removed from the array and free'd after we
call grab_media_key() but before the dbus reply comes in, we end up
writing over free'd memory (&key->accel_id).

Comment 56 Rui Matos 2017-02-13 21:02:41 UTC

Created attachment 345672 [details] [review]
media-keys: Avoid leaking grabbed bindings

If a binding definition changes again before we get the dbus reply for
the previous change we'd never ungrab the previous accel id.

Comment 57 Rui Matos 2017-02-13 21:03:02 UTC

Created attachment 345673 [details] [review]
media-keys: Handle binding grabs when there's already one pending

Since grabbing is asynchronous, we might end up with requests to grab
a binding combo while we already have a pending grab for that same
combo. If this happens, the last request should win, so keep track of
it to re-try when we get the reply for the pending grab.

Comment 58 Bastien Nocera 2017-02-14 02:08:54 UTC

Review of attachment 345670 [details] [review]:

Looks good otherwise.

::: plugins/media-keys/gsd-media-keys-manager.c
@@ +245,3 @@
         if (key == NULL)
                 return;
+        if (--key->ref_count > 0)

I would prefer g_atomic_int_dec_and_test()

@@ +255,3 @@
+media_key_ref (MediaKey *key)
+{
+        ++key->ref_count;

And g_atomic_int_inc()

Comment 59 Bastien Nocera 2017-02-14 02:09:39 UTC

Review of attachment 345671 [details] [review]:

Sure.

Comment 60 Bastien Nocera 2017-02-14 02:18:29 UTC

Review of attachment 345672 [details] [review]:

Sure.

Comment 61 Bastien Nocera 2017-02-14 02:20:24 UTC

Review of attachment 345673 [details] [review]:

Looks fine as well.

Comment 62 Matthijs Kooijman 2017-02-14 11:15:00 UTC

Review of attachment 345673 [details] [review]:

::: plugins/media-keys/gsd-media-keys-manager.c
@@ +515,2 @@
+	binding = get_key_string (manager, key);
+        if (g_hash_table_lookup (manager->priv->keys_pending_grab, binding)) {

There is a indentation inconsistency here: The rest of this function seems to use tabs for indent, but this if (and the g_free further down) uses spaces.

Comment 63 Matthijs Kooijman 2017-02-14 12:09:08 UTC

I'm now running with all patches applies, except for the first one (since that masks the race condition). So far everything seems to work, though I probably haven't triggered the original problem yet (it was quite erratic). I did find that changing a keybinding using the Gnome settings dialog also triggers the same condition, and some added debug output shows that the new machinery works properly in this case.

Comment 64 Rui Matos 2017-02-14 15:09:55 UTC

Pushing all, using glib atomic int ops as suggested.

   347b872..558c703  gnome-3-22 -> gnome-3-22
   c09ee2a..2600ac4  master -> master

Matthijs, thank's for debugging and clearly pointing out the problem!

Attachment 345639 [details] pushed as 8966dd9 - media-keys: Avoid multiple grab/ungrab pairs on custom binding changes
Attachment 345670 [details] pushed as 7d15e66 - media-keys: Reference count MediaKey struct instances
Attachment 345671 [details] pushed as e980c09 - media-keys: Avoid using free'd memory
Attachment 345672 [details] pushed as 61be0fa - media-keys: Avoid leaking grabbed bindings
Attachment 345673 [details] pushed as 2600ac4 - media-keys: Handle binding grabs when there's already one pending