search

Askannz / optimus-manager

A Linux program to handle GPU switching on Optimus laptops.
MIT License
2.3k stars 170 forks source link

Switching to Nvidia not working #287

Closed marcosh closed 4 months ago

marcosh commented 4 years ago

Describe the bug One I try to run optimus-manager --switch nvidia and I confirm the operation, the system restarts and I get a blank screen. The only action at that point is a hard reboot, after which I'm back at intel GPU mode

System info distribution: Manjaro 20 desktop manager: KDE Plasma display manager: I guess SDDM, anyway the default laptop model: ThinkPad X1 Extreme (Gen 2) optimus-manager version: 1.3

Logs The last log from /var/log/optimus-manager/switch is

[18] INFO: # Xorg pre-start hook
[18] INFO: Requested mode is: intel
[18] INFO: Checking for GDM display servers
[397] INFO: Available modules: ['nouveau', 'nvidia', 'nvidia_drm', 'nvidia_modeset', 'nvidia_uvm']
[397] INFO: Unloading modules ['nvidia_drm', 'nvidia_modeset', 'nvidia_uvm', 'nvidia'] (if loaded)
[419] INFO: Loaded extra Intel Xorg options (0 lines)
[419] INFO: Loaded extra Intel Xorg options (0 lines)
[419] INFO: Writing to /etc/X11/xorg.conf.d/10-optimus-manager.conf
[419] INFO: Writing state {'type': 'pending_post_xorg_start', 'switch_id': '20200708T001006', 'requested_mode': 'intel'}
[419] INFO: Xorg pre-start hook completed successfully.
[2] INFO: # Xorg post-start hook
[2] INFO: Running /etc/optimus-manager/xsetup-intel.sh
[8] INFO: Writing state {'type': 'done', 'switch_id': '20200708T001006', 'current_mode': 'intel'}
[9] INFO: Xorg post-start hook completed successfully.

The last log from /var/log/optimus-manager/daemon is

[39] INFO: # Daemon pre-start hook
[40] INFO: Removing /etc/X11/xorg.conf.d/10-optimus-manager.conf (if present)
[43] INFO: Startup mode is: intel
[43] INFO: Writing state {'type': 'pending_pre_xorg_start', 'requested_mode': 'intel', 'current_mode': None}
[43] INFO: Daemon pre-start hook completed successfully.
[43] INFO: Calling Xorg pre-start hook.
[1] INFO: # Commands daemon
[1] INFO: Opening UNIX socket
[1] INFO: Awaiting commands
Ann1kaB commented 4 years ago

Can you provide a nvidia switch log?

Askannz commented 4 years ago

The logs that you provided are from the current intel mode, not the failed switch to nvidia.

Once you got that blank screen and have rebooted to intel, do not get the latest /var/log/optimus-manager/switch log but the one just before that.

marcosh commented 4 years ago

sorry for the late reply, I was on vacation...

the nvidia switch log looks like

[7] INFO: # Xorg pre-start hook
[7] INFO: Previous state was: {'type': 'pending_pre_xorg_start', 'requested_mode': 'nvidia', 'current_mode': 'intel'}
[7] INFO: Requested mode is: nvidia
[8] INFO: Checking for GDM display servers
[186] INFO: Available modules: ['nouveau', 'nvidia', 'nvidia_drm', 'nvidia_modeset', 'nvidia_uvm']
[186] INFO: Unloading modules ['nouveau'] (if loaded)
[1453] INFO: Loading module nvidia
[1455] INFO: Loading module nvidia_drm
[2129] INFO: Loaded extra Intel Xorg options (0 lines)
[2129] INFO: Loaded extra Intel Xorg options (0 lines)
[2130] INFO: Writing to /etc/X11/xorg.conf.d/10-optimus-manager.conf
[2130] INFO: Writing state {'type': 'pending_post_xorg_start', 'switch_id': '20200803T121219', 'requested_mode': 'nvidia'}
[2130] INFO: Xorg pre-start hook completed successfully.
[3] INFO: # Xorg post-start hook
[3] INFO: Running xrandr commands
[452] INFO: Running /etc/optimus-manager/xsetup-nvidia.sh
[503] INFO: Writing state {'type': 'done', 'switch_id': '20200803T121219', 'current_mode': 'nvidia'}
[505] INFO: Xorg post-start hook completed successfully.
marcosh commented 4 years ago

These are the logs for a switch coming from journalctl

ago 03 15:33:41 marcoshoisy python3[872]: [10816335] INFO: Received command : {
ago 03 15:33:41 marcoshoisy python3[872]:     "args": {
ago 03 15:33:41 marcoshoisy python3[872]:         "mode": "nvidia"
ago 03 15:33:41 marcoshoisy python3[872]:     },
ago 03 15:33:41 marcoshoisy python3[872]:     "type": "switch"
ago 03 15:33:41 marcoshoisy python3[872]: }
ago 03 15:33:41 marcoshoisy python3[872]: [10816335] INFO: Writing requested GPU mode nvidia
ago 03 15:33:41 marcoshoisy python3[872]: [10816335] INFO: Writing state {'type': 'pending_pre_xorg_start', 'requested_mode': 'nvidia', 'current_mode': 'intel'}
ago 03 15:33:41 marcoshoisy dbus-daemon[1328]: [session uid=1000 pid=1328] Activating service name='org.kde.Shutdown' requested by ':1.17' (uid=1000 pid=1438 comm="/usr/bin/ksmserver " label="unconfined")
ago 03 15:33:41 marcoshoisy dbus-daemon[1328]: [session uid=1000 pid=1328] Successfully activated service 'org.kde.Shutdown'
ago 03 15:33:41 marcoshoisy msm_kde_notifier[1507]: Shutting down MSM Notifier...
ago 03 15:33:41 marcoshoisy polkit-kde-authentication-agent-1[1454]: Destroying listener
ago 03 15:33:41 marcoshoisy polkit-kde-authentication-agent-1[1454]: Removing listener  PolkitQt1::Agent::Listener(0x5645408490a0)
ago 03 15:33:41 marcoshoisy kded5[1403]: Service  ":1.34" unregistered
ago 03 15:33:41 marcoshoisy kded5[1403]: Service  ":1.31" unregistered
ago 03 15:33:41 marcoshoisy polkitd[503]: Unregistered Authentication Agent for unix-session:2 (system bus name :1.31, object path /org/kde/PolicyKit1/AuthenticationAgent, locale en_GB.UTF-8)
ago 03 15:33:41 marcoshoisy kwin_x11[1407]: qt.qpa.xcb: QXcbConnection: XCB error: 3 (BadWindow), sequence: 52638, resource id: 39845893, major code: 18 (ChangeProperty), minor code: 0
ago 03 15:33:41 marcoshoisy kwin_x11[1407]: qt.qpa.xcb: QXcbConnection: XCB error: 3 (BadWindow), sequence: 52642, resource id: 48234530, major code: 18 (ChangeProperty), minor code: 0
ago 03 15:33:41 marcoshoisy kwin_x11[1407]: qt.qpa.xcb: QXcbConnection: XCB error: 3 (BadWindow), sequence: 52646, resource id: 41943045, major code: 18 (ChangeProperty), minor code: 0
ago 03 15:33:41 marcoshoisy kwin_x11[1407]: qt.qpa.xcb: QXcbConnection: XCB error: 3 (BadWindow), sequence: 52650, resource id: 10485765, major code: 18 (ChangeProperty), minor code: 0
ago 03 15:33:41 marcoshoisy sddm[1320]: kwalletd5: Checking for pam module
ago 03 15:33:41 marcoshoisy sddm[1320]: kwalletd5: Got pam-login param
ago 03 15:33:41 marcoshoisy sddm[1320]: kwalletd5: Waiting for hash on 7-
ago 03 15:33:41 marcoshoisy sddm[1320]: kwalletd5: waitingForEnvironment on: 3
ago 03 15:33:41 marcoshoisy sddm[1320]: kwalletd5: client connected
ago 03 15:33:41 marcoshoisy sddm[1320]: kwalletd5: client disconnected
ago 03 15:33:41 marcoshoisy systemd[1306]: apps-msm_kde_notifier-2b2698ef67a8485397ccfae5253da235.scope: Succeeded.
ago 03 15:33:41 marcoshoisy kwin_x11[1407]: qt.qpa.xcb: QXcbConnection: XCB error: 3 (BadWindow), sequence: 52654, resource id: 25165829, major code: 18 (ChangeProperty), minor code: 0
ago 03 15:33:41 marcoshoisy kwin_x11[1407]: qt.qpa.xcb: QXcbConnection: XCB error: 3 (BadWindow), sequence: 52662, resource id: 23068693, major code: 18 (ChangeProperty), minor code: 0
ago 03 15:33:41 marcoshoisy systemd[1306]: apps-optimus\x2dmanager\x2dqt-a89394acb5ea4a3a981500686e54ce77.scope: Succeeded.
ago 03 15:33:41 marcoshoisy sddm-helper[1303]: [PAM] Closing session
ago 03 15:33:41 marcoshoisy sddm-helper[1303]: pam_unix(sddm:session): session closed for user marcosh
ago 03 15:33:41 marcoshoisy sddm-helper[1303]: pam_kwallet5(sddm:session): pam_kwallet5: pam_sm_close_session
ago 03 15:33:41 marcoshoisy audit[1303]: USER_END pid=1303 uid=0 auid=1000 ses=2 subj==unconfined msg='op=PAM:session_close grantors=pam_loginuid,pam_keyinit,pam_limits,pam_unix,pam_permit,pam_mail,pam_systemd,pam_env,pam_kwallet5 acct="marcosh" exe="/usr/lib/sddm/sddm-helper" hostname=? addr=? terminal=:0 res=success'
ago 03 15:33:41 marcoshoisy audit[1303]: CRED_DISP pid=1303 uid=0 auid=1000 ses=2 subj==unconfined msg='op=PAM:setcred grantors=pam_tally2,pam_shells,pam_unix,pam_permit acct="marcosh" exe="/usr/lib/sddm/sddm-helper" hostname=? addr=? terminal=:0 res=success'
ago 03 15:33:41 marcoshoisy sddm-helper[1303]: pam_kwallet5(sddm:setcred): pam_kwallet5: pam_sm_setcred
ago 03 15:33:41 marcoshoisy sddm-helper[1303]: [PAM] Ended.
ago 03 15:33:41 marcoshoisy sddm[875]: Auth: sddm-helper exited successfully
ago 03 15:33:41 marcoshoisy sddm[875]: Socket server stopping...
ago 03 15:33:41 marcoshoisy sddm[875]: Socket server stopped.
ago 03 15:33:41 marcoshoisy sddm[875]: Display server stopping...
ago 03 15:33:41 marcoshoisy kded5[1403]: The X11 connection broke (error 1). Did the X11 server die?
ago 03 15:33:41 marcoshoisy kwin_x11[1407]: The X11 connection broke (error 1). Did the X11 server die?
ago 03 15:33:41 marcoshoisy kernel: audit: type=1106 audit(1596461621.362:95): pid=1303 uid=0 auid=1000 ses=2 subj==unconfined msg='op=PAM:session_close grantors=pam_loginuid,pam_keyinit,pam_limits,pam_unix,pam_permit,pam_mail,pam_systemd,pam_env,pam_kwallet5 acct="marcosh" exe="/usr/lib/sddm/sddm-helper" hostname=? addr=? terminal=:0 res=success'
ago 03 15:33:41 marcoshoisy kernel: audit: type=1104 audit(1596461621.362:96): pid=1303 uid=0 auid=1000 ses=2 subj==unconfined msg='op=PAM:setcred grantors=pam_tally2,pam_shells,pam_unix,pam_permit acct="marcosh" exe="/usr/lib/sddm/sddm-helper" hostname=? addr=? terminal=:0 res=success'
ago 03 15:33:41 marcoshoisy systemd[1]: Stopping Session 2 of user marcosh.
ago 03 15:33:41 marcoshoisy NetworkManager[497]: <info>  [1596461621.3684] device (wlp82s0): state change: activated -> deactivating (reason 'connection-removed', sys-iface-state: 'managed')
ago 03 15:33:41 marcoshoisy NetworkManager[497]: <info>  [1596461621.3687] manager: NetworkManager state is now DISCONNECTING
ago 03 15:33:41 marcoshoisy dbus-daemon[494]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.3' (uid=0 pid=497 comm="/usr/bin/NetworkManager --no-daemon " label="unconfined")
ago 03 15:33:41 marcoshoisy systemd[1]: Starting Network Manager Script Dispatcher Service...
ago 03 15:33:41 marcoshoisy kactivitymanagerd[1429]: The X11 connection broke (error 1). Did the X11 server die?
ago 03 15:33:41 marcoshoisy at-spi-bus-launcher[1668]: X connection to :0 broken (explicit kill or server shutdown).
ago 03 15:33:41 marcoshoisy kscreen_backend_launcher[1515]: The X11 connection broke (error 1). Did the X11 server die?
ago 03 15:33:41 marcoshoisy xdg-desktop-portal-kde[1701]: The X11 connection broke (error 1). Did the X11 server die?
ago 03 15:33:41 marcoshoisy kglobalaccel5[1424]: The X11 connection broke (error 1). Did the X11 server die?
ago 03 15:33:41 marcoshoisy dbus-daemon[494]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
ago 03 15:33:41 marcoshoisy systemd[1]: Started Network Manager Script Dispatcher Service.
ago 03 15:33:41 marcoshoisy audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
ago 03 15:33:41 marcoshoisy kernel: audit: type=1130 audit(1596461621.375:97): pid=1 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
ago 03 15:33:41 marcoshoisy kernel: wlp82s0: deauthenticating from b8:d5:26:3a:a6:e7 by local choice (Reason: 3=DEAUTH_LEAVING)
ago 03 15:33:41 marcoshoisy audit[1407]: ANOM_ABEND auid=1000 uid=1000 gid=1000 ses=2 subj==unconfined pid=1407 comm="kwin_x11" exe="/usr/bin/kwin_x11" sig=6 res=1
ago 03 15:33:41 marcoshoisy kernel: audit: type=1701 audit(1596461621.382:98): auid=1000 uid=1000 gid=1000 ses=2 subj==unconfined pid=1407 comm="kwin_x11" exe="/usr/bin/kwin_x11" sig=6 res=1
ago 03 15:33:41 marcoshoisy systemd[1]: Created slice system-systemd\x2dcoredump.slice.
ago 03 15:33:41 marcoshoisy audit: BPF prog-id=15 op=LOAD
ago 03 15:33:41 marcoshoisy kernel: audit: type=1334 audit(1596461621.388:99): prog-id=15 op=LOAD
ago 03 15:33:41 marcoshoisy audit: BPF prog-id=16 op=LOAD
ago 03 15:33:41 marcoshoisy systemd[1]: Started Process Core Dump (PID 16730/UID 0).
ago 03 15:33:41 marcoshoisy kernel: audit: type=1334 audit(1596461621.388:100): prog-id=16 op=LOAD
ago 03 15:33:41 marcoshoisy audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='unit=systemd-coredump@0-16730-0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
ago 03 15:33:41 marcoshoisy kernel: audit: type=1130 audit(1596461621.392:101): pid=1 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='unit=systemd-coredump@0-16730-0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
ago 03 15:33:41 marcoshoisy wpa_supplicant[1139]: wlp82s0: CTRL-EVENT-DISCONNECTED bssid=b8:d5:26:3a:a6:e7 reason=3 locally_generated=1
ago 03 15:33:41 marcoshoisy wpa_supplicant[1139]: wlp82s0: CTRL-EVENT-SIGNAL-CHANGE above=0 signal=0 noise=9999 txrate=0
ago 03 15:33:41 marcoshoisy NetworkManager[497]: <info>  [1596461621.4049] device (wlp82s0): supplicant interface state: completed -> disconnected
ago 03 15:33:41 marcoshoisy NetworkManager[497]: <info>  [1596461621.4049] device (p2p-dev-wlp82s0): supplicant management interface state: completed -> disconnected
ago 03 15:33:41 marcoshoisy NetworkManager[497]: <info>  [1596461621.4049] device (wlp82s0): state change: deactivating -> disconnected (reason 'connection-removed', sys-iface-state: 'managed')
ago 03 15:33:41 marcoshoisy avahi-daemon[492]: Withdrawing address record for fe80::3b21:2ad6:2a4d:3464 on wlp82s0.
ago 03 15:33:41 marcoshoisy avahi-daemon[492]: Leaving mDNS multicast group on interface wlp82s0.IPv6 with address fe80::3b21:2ad6:2a4d:3464.
ago 03 15:33:41 marcoshoisy avahi-daemon[492]: Interface wlp82s0.IPv6 no longer relevant for mDNS.
ago 03 15:33:41 marcoshoisy bluetoothd[1208]: Endpoint unregistered: sender=:1.39 path=/MediaEndpoint/A2DPSink/sbc
ago 03 15:33:41 marcoshoisy bluetoothd[1208]: Endpoint unregistered: sender=:1.39 path=/MediaEndpoint/A2DPSource/sbc
ago 03 15:33:41 marcoshoisy systemd[1306]: pulseaudio.service: Succeeded.
ago 03 15:33:41 marcoshoisy NetworkManager[497]: <info>  [1596461621.4277] dhcp4 (wlp82s0): canceled DHCP transaction
ago 03 15:33:41 marcoshoisy NetworkManager[497]: <info>  [1596461621.4278] dhcp4 (wlp82s0): state changed bound -> done
ago 03 15:33:41 marcoshoisy avahi-daemon[492]: Interface wlp82s0.IPv4 no longer relevant for mDNS.
ago 03 15:33:41 marcoshoisy avahi-daemon[492]: Leaving mDNS multicast group on interface wlp82s0.IPv4 with address 192.168.1.195.
ago 03 15:33:41 marcoshoisy avahi-daemon[492]: Withdrawing address record for 192.168.1.195 on wlp82s0.
ago 03 15:33:41 marcoshoisy NetworkManager[497]: <info>  [1596461621.4290] device (wlp82s0): set-hw-addr: set MAC address to 3A:6F:89:B2:6F:5A (scanning)
ago 03 15:33:41 marcoshoisy avahi-daemon[492]: Joining mDNS multicast group on interface wlp82s0.IPv4 with address 192.168.1.195.
ago 03 15:33:41 marcoshoisy avahi-daemon[492]: New relevant interface wlp82s0.IPv4 for mDNS.
ago 03 15:33:41 marcoshoisy avahi-daemon[492]: Registering new address record for 192.168.1.195 on wlp82s0.IPv4.
ago 03 15:33:41 marcoshoisy avahi-daemon[492]: Withdrawing address record for 192.168.1.195 on wlp82s0.
ago 03 15:33:41 marcoshoisy avahi-daemon[492]: Leaving mDNS multicast group on interface wlp82s0.IPv4 with address 192.168.1.195.
ago 03 15:33:41 marcoshoisy avahi-daemon[492]: Interface wlp82s0.IPv4 no longer relevant for mDNS.
ago 03 15:33:41 marcoshoisy NetworkManager[497]: <info>  [1596461621.4313] manager: NetworkManager state is now DISCONNECTED
ago 03 15:33:42 marcoshoisy sddm[875]: Display server stopped.
ago 03 15:33:42 marcoshoisy sddm[875]: Running display stop script  "/sbin/prime-switch"
ago 03 15:33:42 marcoshoisy kernel: IPMI message handler: version 39.2
ago 03 15:33:42 marcoshoisy kernel: ipmi device interface
ago 03 15:33:42 marcoshoisy kernel: nvidia: loading out-of-tree module taints kernel.
ago 03 15:33:42 marcoshoisy kernel: nvidia: module license 'NVIDIA' taints kernel.
ago 03 15:33:42 marcoshoisy kernel: Disabling lock debugging due to kernel taint
ago 03 15:33:42 marcoshoisy kernel: nvidia: module verification failed: signature and/or required key missing - tainting kernel
ago 03 15:33:42 marcoshoisy kernel: nvidia-nvlink: Nvlink Core is being initialized, major device number 236
ago 03 15:33:42 marcoshoisy kernel: nvidia 0000:01:00.0: enabling device (0002 -> 0003)
ago 03 15:33:42 marcoshoisy kernel: nvidia 0000:01:00.0: vgaarb: changed VGA decodes: olddecodes=io+mem,decodes=none:owns=none
ago 03 15:33:42 marcoshoisy kernel: NVRM: loading NVIDIA UNIX x86_64 Kernel Module  440.100  Fri May 29 08:45:51 UTC 2020
ago 03 15:33:42 marcoshoisy kernel: nvidia-modeset: Loading NVIDIA Kernel Mode Setting Driver for UNIX platforms  440.100  Fri May 29 08:14:04 UTC 2020
ago 03 15:33:42 marcoshoisy kernel: [drm] [nvidia-drm] [GPU ID 0x00000100] Loading driver
ago 03 15:33:43 marcoshoisy systemd-coredump[16731]: Core file was truncated to 2147483648 bytes.
ago 03 15:33:43 marcoshoisy systemd-coredump[16731]: Process 1407 (kwin_x11) of user 1000 dumped core.

                                                     Stack trace of thread 1407:
                                                     #0  0x00007efde2474355 n/a (n/a + 0x0)
-- Reboot --
nwildner commented 4 months ago

Hello @marcosh . Is this still reproducible on a modern distribution with updated linux kernel, nvidia driver version and using the optimus-manager-git package? The project is facing a revamp so, please stick with the -git version of this package.

Let me know if this issue is still relevant to you ok?

Have a nice week.

marcosh commented 4 months ago

@nwildner thanks for asking, the issue is not relevant to me anymore