Optirun seems to start, but no output

[poVoq]

Hello

I have the following problem with Bumblebee on my Asus N43sn running a fresh Mint Linux 12 (based on Ubuntu 11.10):

Bumblebee installed fine and Ironhide was working fine on a previous Ubuntu 11.10 install. However under settings: "restricted drivers" the nvidia drivers are not shown to be actived (even though synaptic shows them as installed).

Anyways this is what happens If I start "optirun glxspheres": Nothing seems to happen except for a blinking cursor (no error message what so ever), but the fan starts turning up. Then the only way to exit is via ctrl+c

Feb  1 22:36:27 krischan-N43SN kernel: [  189.230505] bbswitch: enabling discrete graphics
Feb  1 22:36:28 krischan-N43SN bumblebeed[1157]: The PCI config space could not be written fully at offset 0x1; 0 bytes have been written; error: Resource temporarily unavailable
Feb  1 22:36:28 krischan-N43SN kernel: [  189.879823] pci 0000:01:00.0: power state changed by ACPI to D0
Feb  1 22:36:28 krischan-N43SN kernel: [  189.879830] pci 0000:01:00.0: power state changed by ACPI to D0
Feb  1 22:36:28 krischan-N43SN kernel: [  189.879865] pci 0000:01:00.0: power state changed by ACPI to D0
Feb  1 22:36:28 krischan-N43SN kernel: [  189.879868] pci 0000:01:00.0: power state changed by ACPI to D0
Feb  1 22:36:28 krischan-N43SN kernel: [  189.879872] pci 0000:01:00.0: enabling device (0000 -> 0003)
Feb  1 22:36:28 krischan-N43SN kernel: [  189.879877] pci 0000:01:00.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
Feb  1 22:36:28 krischan-N43SN kernel: [  189.879882] pci 0000:01:00.0: setting latency timer to 64
Feb  1 22:36:28 krischan-N43SN kernel: [  190.129150] nvidia: module license 'NVIDIA' taints kernel.
Feb  1 22:36:28 krischan-N43SN kernel: [  190.129153] Disabling lock debugging due to kernel taint
Feb  1 22:36:28 krischan-N43SN kernel: [  190.488142] nvidia 0000:01:00.0: power state changed by ACPI to D0
Feb  1 22:36:28 krischan-N43SN kernel: [  190.488147] nvidia 0000:01:00.0: power state changed by ACPI to D0
Feb  1 22:36:28 krischan-N43SN kernel: [  190.488151] nvidia 0000:01:00.0: enabling device (0000 -> 0003)
Feb  1 22:36:28 krischan-N43SN kernel: [  190.488157] nvidia 0000:01:00.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
Feb  1 22:36:28 krischan-N43SN kernel: [  190.488164] nvidia 0000:01:00.0: setting latency timer to 64
Feb  1 22:36:28 krischan-N43SN kernel: [  190.488168] vgaarb: device changed decodes: PCI:0000:01:00.0,olddecodes=io+mem,decodes=none:owns=none
Feb  1 22:36:28 krischan-N43SN kernel: [  190.488277] NVRM: loading NVIDIA UNIX x86_64 Kernel Module  280.13  Wed Jul 27 16:53:56 PDT 2011
Feb  1 22:36:28 krischan-N43SN acpid: client connected from 1946[0:1001]
Feb  1 22:36:28 krischan-N43SN acpid: 1 client rule loaded
Feb  1 22:36:31 krischan-N43SN acpid: client connected from 1946[0:1001]
Feb  1 22:36:31 krischan-N43SN acpid: 1 client rule loaded
Feb  1 22:36:51 krischan-N43SN kernel: [  213.713431] NVRM: Xid (0000:01:00): 16, Head 00000000 Count 00000000
Feb  1 22:36:59 krischan-N43SN kernel: [  221.713352] NVRM: Xid (0000:01:00): 16, Head 00000000 Count 00000001
Feb  1 22:37:07 krischan-N43SN kernel: [  229.717242] NVRM: Xid (0000:01:00): 16, Head 00000000 Count 00000002
Feb  1 22:37:15 krischan-N43SN kernel: [  237.733151] NVRM: Xid (0000:01:00): 16, Head 00000000 Count 00000003
Feb  1 22:37:24 krischan-N43SN kernel: [  245.737032] NVRM: Xid (0000:01:00): 16, Head 00000000 Count 00000004
Feb  1 22:37:32 krischan-N43SN kernel: [  253.736921] NVRM: Xid (0000:01:00): 16, Head 00000000 Count 00000005
Feb  1 22:37:40 krischan-N43SN kernel: [  261.732811] NVRM: Xid (0000:01:00): 16, Head 00000000 Count 00000006
Feb  1 22:37:48 krischan-N43SN kernel: [  269.744700] NVRM: Xid (0000:01:00): 16, Head 00000000 Count 00000007
Feb  1 22:44:04 krischan-N43SN acpid: client 1194[0:0] has disconnected
Feb  1 22:44:04 krischan-N43SN acpid: client connected from 1194[0:0]
Feb  1 22:44:04 krischan-N43SN acpid: 1 client rule loaded

note: at 22:36 I started optirun at 22:44 I killed optirun via ctrl+c

Thanks for the help!

[derkling]

This is another "interesting" log, obtained by re-starting a CTRL-C terminated "optirun glxgears" since it was not starting because of the problem we are discussing:

Feb 26 19:26:33 graystar kernel: [  255.321939] bbswitch: disabling discrete graphics
Feb 26 19:26:33 graystar kernel: [  255.322528] bbswitch: Result of Optimus _DSM call: 11000059
Feb 26 19:26:33 graystar kernel: [  255.336035] pci 0000:01:00.0: Refused to change power state, currently in D0
Feb 26 19:26:33 graystar kernel: [  255.635609] pci 0000:01:00.0: power state changed by ACPI to D3

[derkling]

I've just noticed that, even if the "optirun glxgears" does not start, this task keeps 100% of a CPU. What is actually doing?!?! Actually I was thinking that fans start running faster because of the discrete GPU being powered-on... while now I have the suspect that this is due just to the optirun-related CPU load. Notice that a "glxgears" without optirun takes less the 4% CPU time on my machine.

Here the optirun log:

derkling@graystar:~$ optirun -vv glxgears 
[DEBUG]Reading file: /etc/bumblebee/bumblebee.conf
[DEBUG]Process /sbin/modinfo started, PID 2606.
[DEBUG]Hiding stderr for execution of /sbin/modinfo
[DEBUG]SIGCHILD received, but wait failed with No child processes
[DEBUG]Detected nvidia driver (module nvidia-current)
[DEBUG]Active configuration:
[DEBUG] bumblebeed config file: /etc/bumblebee/bumblebee.conf
[DEBUG] X display: :8
[DEBUG] LD_LIBRARY_PATH: /usr/lib/nvidia-current:/usr/lib32/nvidia-current
[DEBUG] Socket path: /var/run/bumblebee.socket
[DEBUG] VGL Compression: proxy
[DEBUG]optirun version 3.0 starting...

And this is the corresponding syslog:

Feb 26 19:30:51 graystar kernel: [  513.340581] bbswitch: enabling discrete graphics
Feb 26 19:30:52 graystar kernel: [  513.730008] pci 0000:01:00.0: power state changed by ACPI to D0
Feb 26 19:30:52 graystar kernel: [  513.730015] pci 0000:01:00.0: power state changed by ACPI to D0
Feb 26 19:30:52 graystar kernel: [  513.730038] pci 0000:01:00.0: restoring config space at offset 0x1 (was 0x100006, writing 0x100003)
Feb 26 19:30:52 graystar kernel: [  513.730050] pci 0000:01:00.0: power state changed by ACPI to D0
Feb 26 19:30:52 graystar kernel: [  513.730052] pci 0000:01:00.0: power state changed by ACPI to D0
Feb 26 19:30:52 graystar kernel: [  513.730060] pci 0000:01:00.0: found PCI INT A -> IRQ 11
Feb 26 19:30:52 graystar kernel: [  513.730067] pci 0000:01:00.0: sharing IRQ 11 with 0000:00:16.0
Feb 26 19:30:52 graystar kernel: [  513.730070] pci 0000:01:00.0: sharing IRQ 11 with 0000:00:1a.0
Feb 26 19:30:52 graystar kernel: [  513.730074] pci 0000:01:00.0: sharing IRQ 11 with 0000:00:1c.0
Feb 26 19:30:52 graystar kernel: [  513.730080] pci 0000:01:00.0: sharing IRQ 11 with 0000:00:1c.4
Feb 26 19:30:52 graystar kernel: [  513.730185] pci 0000:01:00.0: setting latency timer to 64
Feb 26 19:30:52 graystar kernel: [  513.777667] nvidia 0000:01:00.0: power state changed by ACPI to D0
Feb 26 19:30:52 graystar kernel: [  513.777672] nvidia 0000:01:00.0: power state changed by ACPI to D0
Feb 26 19:30:52 graystar kernel: [  513.777681] nvidia 0000:01:00.0: found PCI INT A -> IRQ 11
Feb 26 19:30:52 graystar kernel: [  513.777687] nvidia 0000:01:00.0: sharing IRQ 11 with 0000:00:16.0
Feb 26 19:30:52 graystar kernel: [  513.777691] nvidia 0000:01:00.0: sharing IRQ 11 with 0000:00:1a.0
Feb 26 19:30:52 graystar kernel: [  513.777696] nvidia 0000:01:00.0: sharing IRQ 11 with 0000:00:1c.0
Feb 26 19:30:52 graystar kernel: [  513.777704] nvidia 0000:01:00.0: sharing IRQ 11 with 0000:00:1c.4
Feb 26 19:30:52 graystar kernel: [  513.777812] nvidia 0000:01:00.0: setting latency timer to 64
Feb 26 19:30:52 graystar kernel: [  513.777816] vgaarb: device changed decodes: PCI:0000:01:00.0,olddecodes=none,decodes=none:owns=none
Feb 26 19:30:52 graystar kernel: [  513.777916] NVRM: loading NVIDIA UNIX x86_64 Kernel Module  295.20  Mon Feb  6 21:07:30 PST 2012

By running "strace optirun glxgears", the reason for the 100% CPU time utilization seem related to a "busy-loop" on a recvfrom which return with a "-1 EAGAIN (Resource temporarily unavailable)". This read target the bumblebee socket:

socket(PF_FILE, SOCK_STREAM, 0)         = 3
connect(3, {sa_family=AF_FILE, path="/var/run/bumblebee.socket"}, 110) = 0
fcntl(3, F_GETFL)                       = 0x2 (flags O_RDWR)
fcntl(3, F_SETFL, O_RDWR|O_NONBLOCK)    = 0
sendto(3, "Checking availability...\0", 25, MSG_NOSIGNAL, NULL, 0) = 25
recvfrom(3, 0x7fff2bb35df0, 1024, 0, 0, 0) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(3, 0x7fff2bb35df0, 1024, 0, 0, 0) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(3, 0x7fff2bb35df0, 1024, 0, 0, 0) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(3, 0x7fff2bb35df0, 1024, 0, 0, 0) = -1 EAGAIN (Resource temporarily unavailable)
[repeating endless]

Usually I stop this after 10-20 seconds with a CTRL-C and, after a while on syslog we can read:

Feb 26 19:40:20 graystar bumblebeed[2505]: X unresponsive after 10 seconds - aborting
Feb 26 19:40:20 graystar bumblebeed[2505]: Could not write data! Error: Broken pipe

However, the unresponsive X-Server seem to be running, indeed even after this notification on syslog I always have this tasks on my system:

root      2505  0.0  0.0  36052  1836 ?        Ss   19:26   0:00 /usr/sbin/bumblebeed --use-syslog
root      2792  0.2  0.4 130428 35256 ?        Ss   19:40   0:00 Xorg :8 -config /etc/bumblebee/xorg.conf.nvidia -sharevts -nolisten tcp -noreset -verbose 3 -isolateDevice PCI:01:00:0 -modulepath /usr/lib/nvidia-current/xorg,/usr/lib/xorg/modules

This X server is always there, even if a stop the bumblebeed service:

derkling@graystar:~$ sudo /etc/init.d/bumblebeed stop
Rather than invoking init scripts through /etc/init.d, use the service(8)
utility, e.g. service bumblebeed stop

Since the script you are attempting to invoke has been converted to an
Upstart job, you may also use the stop(8) utility, e.g. stop bumblebeed

bumblebeed stop/waiting
derkling@graystar:~$ ps aux | grep bumb
root      2849  0.8  0.4 130428 35256 ?        Ss   19:49   0:00 Xorg :8 -config /etc/bumblebee/xorg.conf.nvidia -sharevts -nolisten tcp -noreset -verbose 3 -isolateDevice PCI:01:00:0 -modulepath /usr/lib/nvidia-current/xorg,/usr/lib/xorg/modules

At this point, if a kill (-TERM) this Xorg instance and then restart the bumblebee daemon, on syslog I get:

Feb 26 19:52:57 graystar bumblebeed[2929]: /usr/sbin/bumblebeed 3.0 started
Feb 26 19:52:57 graystar kernel: [ 1837.210300] bbswitch: disabling discrete graphics
Feb 26 19:52:57 graystar kernel: [ 1837.210914] bbswitch: Result of Optimus _DSM call: 11000059
Feb 26 19:52:57 graystar kernel: [ 1837.224754] pci 0000:01:00.0: Refused to change power state, currently in D0
Feb 26 19:52:58 graystar kernel: [ 1837.524496] pci 0000:01:00.0: power state changed by ACPI to D3

The Xserver is not started, which AFAIK is ok, and an xxd on the PCI configuration reads 0xFF for each byte.

Again I start the "optirun glxgears"... and the problem is always the same:

• the optirun application loops on the recvfrom
• the syslog report the discrete card is powered on
• the Xorg server is started ... but nothing works! :-(

The question is: do you have any idea about where the problem could be? For example: A) is the bbswitch not actually swithing on the discrete card? B) is the PCI configuration loaded probably fault? C) is the Xorg server not properly responding (e.g. permissions) D) is the native NVIDIA driver: NVRM: loading NVIDIA UNIX x86_64 Kernel Module 295.20 Mon Feb 6 21:07:30 PST 2012 faulty?

And even more important, how could we support better on the investigation of this fault? Eventually I can also give you shell access to my machine if you want to conduct some tests.

[Lekensteyn]

Perhaps the device needs more time for becoming ready. Can you run apt-get source bumblebee and add a usleep(100000); after before return switcher->status(); (twice, one after switcher->off(); and one after switcher->on();) in src/switch/switching.c? On the top of the file (e.g. after other #includes), add #include <unistd.h> Get the build dependencies with sudo apt-get build-dep bumblebee, sudo apt-get install dpkg-dev and then rebuild the packages with dpkg-buildpackage -uc -us (within the bumblebee-3.0 directory).

[derkling]

Still no improvements even with this delays. I've also tried to re-install my distro from scratch, and this is the result: the discrete GPU initially worked and after few suspend/resume cycles I've got a "crash" of the nvidia driver while trying to start optirun. Now, the optirun has still the same problem.

An additional info I could add is that: I've noticed that, when I start optirun and the CPU consumption raise to 100% as previously reported, if I don't stop the application (with CTRL+C) after around 2mins I could see the Xorg log on syslog and, perhaps even more interesting, when then I stop the application the syslog report this:

Mar  3 23:00:33 graystar bumblebeed[1105]: [XORG] (==) RandR enabled
Mar  3 23:00:33 graystar bumblebeed[1105]: [XORG] (II) Initializing built-in extension Generic Event Extension
Mar  3 23:00:33 graystar bumblebeed[1105]: [XORG] (II) Initializing built-in extension SHAPE
Mar  3 23:00:33 graystar bumblebeed[1105]: [XORG] (II) Initializing built-in extension MIT-SHM
Mar  3 23:00:33 graystar bumblebeed[1105]: [XORG] (II) Initializing built-in extension XInputExtension
Mar  3 23:00:33 graystar bumblebeed[1105]: [XORG] (II) Initializing built-in extension XTEST
Mar  3 23:00:33 graystar rsyslogd-2177: imuxsock begins to drop messages from pid 1105 due to rate-limiting
Mar  3 23:00:54 graystar rsyslogd-2177: imuxsock lost 73 messages from pid 1105 due to rate-limiting
Mar  3 23:00:54 graystar bumblebeed[1105]: Socket closed.
Mar  3 23:00:55 graystar bumblebeed[1105]: Saving PCI configuration space...
Mar  3 23:00:55 graystar bumblebeed[1105]: Unloading nvidia driver
Mar  3 23:00:55 graystar bumblebeed[1105]: Process rmmod started, PID 20567.
Mar  3 23:00:55 graystar bumblebeed[1105]: Process with PID 20567 returned code 1
Mar  3 23:00:55 graystar bumblebeed[1105]: Unloading nvidia driver timed out.
Mar  3 23:00:55 graystar bumblebeed[1105]: Drivers are still loaded, unable to disable card

The "interesting point" is that the nvidia driver could not be removed. If it could be of interest, this is what lsmod reports:

bbswitch               13355  4217418550 [permanent]
nvidia              11709641  1251138119 [permanent]

[Lekensteyn]

Do you have more kernel logs? permanent means either that the kernel has crashed on this module or that the compiler used for building the module is different than the one used for the kernel.

[derkling]

There after some useful logs I was able to recover. Please note that:

1. I'm running Ubuntu 11.10 (Oneiric) but with an updated kernel, precisely the "3.2.7-030207-generic #201202201759" which is a pre-compiled kernel downloaded from the PPAs of Ubuntu 12.04 (Precise), i.e: http://kernel.ubuntu.com/~kernel-ppa/mainline/v3.2.7-precise/
2. actually the nvidia module has crashed at least one time, after hibernation or suspension, and since this time the unresponsiveness problem happened more frequently (almost always).

Here is the log of the aforementioned crash:

Mar  2 23:26:09 graystar kernel: [34448.825178] divide error: 0000 [#1] SMP 
Mar  2 23:26:09 graystar kernel: [34448.825200] CPU 0 
Mar  2 23:26:09 graystar kernel: [34448.825207] Modules linked in: snd_usb_audio usbhid snd_usbmidi_lib hidp hid rfcomm bnep bbswitch(O) parport_pc ppdev binfmt_misc snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_intel snd_hda_codec snd_hwdep nvidia(P) snd_pcm snd_seq_midi
 arc4 snd_rawmidi snd_seq_midi_event snd_seq snd_timer uvcvideo snd_seq_device videodev v4l2_compat_ioctl32 btusb i915 iwlwifi drm_kms_helper drm snd dell_wmi sparse_keymap i2c_algo_bit soundcore dell_laptop dcdbas video snd_page_alloc bluetooth wmi mei(C) mac_hid mac80211 p
smouse serio_raw cfg80211 lp parport atl1c
Mar  2 23:26:09 graystar kernel: [34448.825405] 
Mar  2 23:26:09 graystar kernel: [34448.825412] Pid: 17684, comm: Xorg Tainted: P         C O 3.2.7-030207-generic #201202201759 Dell Inc.          Dell System XPS 15Z/00WW5M
Mar  2 23:26:09 graystar kernel: [34448.825449] RIP: 0010:[<ffffffffa06b576b>]  [<ffffffffa06b576b>] _nv011231rm+0x148/0x2c2 [nvidia]
Mar  2 23:26:09 graystar kernel: [34448.825616] RSP: 0018:ffff880218cef9c8  EFLAGS: 00010296
Mar  2 23:26:09 graystar kernel: [34448.825631] RAX: 00000000ffffffff RBX: ffff88012a6e0000 RCX: 0000000000000015
Mar  2 23:26:09 graystar kernel: [34448.825651] RDX: 0000000000000000 RSI: 0000000000004075 RDI: ffff88012a6e002c
Mar  2 23:26:09 graystar kernel: [34448.825671] RBP: ffff88022171ae90 R08: ffff88022d737908 R09: 0000000000000001
Mar  2 23:26:09 graystar kernel: [34448.826857] R10: ffff88021d8df2a0 R11: 0000000000000000 R12: ffff88012ad40000
Mar  2 23:26:09 graystar kernel: [34448.828051] R13: 0000000000000000 R14: 000000000000ffff R15: ffff8802181f8000
Mar  2 23:26:09 graystar kernel: [34448.829244] FS:  00007ffe668e68a0(0000) GS:ffff88023e600000(0000) knlGS:0000000000000000
Mar  2 23:26:09 graystar kernel: [34448.830439] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Mar  2 23:26:09 graystar kernel: [34448.831631] CR2: 00007ffe6690e000 CR3: 000000022bd49000 CR4: 00000000000406f0
Mar  2 23:26:09 graystar kernel: [34448.832833] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Mar  2 23:26:09 graystar kernel: [34448.834031] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Mar  2 23:26:09 graystar kernel: [34448.835226] Process Xorg (pid: 17684, threadinfo ffff880218cee000, task ffff8801025196e0)
Mar  2 23:26:09 graystar kernel: [34448.836440] Stack:
Mar  2 23:26:09 graystar kernel: [34448.837630]  ffff88020d2a0840 ffff88015b64c800 ffff8802181f8000 ffff88012a6e0000
Mar  2 23:26:09 graystar kernel: [34448.838852]  ffff8801fa155000 ffffffffa06aba53 ffff88022d4ea000 ffff88012a6e0000
Mar  2 23:26:09 graystar kernel: [34448.840084]  ffff8802181f8000 ffff88022f5cf000 000000000000001e ffffffffa06d394a
Mar  2 23:26:09 graystar kernel: [34448.841329] Call Trace:
Mar  2 23:26:09 graystar kernel: [34448.842668]  [<ffffffffa06aba53>] ? _nv012035rm+0x537/0xfec [nvidia]
Mar  2 23:26:09 graystar kernel: [34448.844004]  [<ffffffffa06d394a>] ? _nv012592rm+0x80/0x265 [nvidia]
Mar  2 23:26:09 graystar kernel: [34448.845312]  [<ffffffffa074c29d>] ? _nv015073rm+0x8c/0x4c3 [nvidia]
Mar  2 23:26:09 graystar kernel: [34448.846590]  [<ffffffffa074aeeb>] ? _nv015366rm+0xe9/0x165 [nvidia]
Mar  2 23:26:09 graystar kernel: [34448.847781]  [<ffffffffa0335748>] ? _nv015546rm+0xd/0x12 [nvidia]
Mar  2 23:26:09 graystar kernel: [34448.848984]  [<ffffffffa0985e79>] ? _nv002297rm+0x19d/0x28a [nvidia]
Mar  2 23:26:09 graystar kernel: [34448.850166]  [<ffffffffa0986ee8>] ? _nv002291rm+0x4a5/0x684 [nvidia]
Mar  2 23:26:09 graystar kernel: [34448.851323]  [<ffffffffa098dc84>] ? rm_init_adapter+0x9e/0x1b6 [nvidia]
Mar  2 23:26:09 graystar kernel: [34448.852386]  [<ffffffff81168fa4>] ? kmem_cache_alloc_trace+0xc4/0x120
Mar  2 23:26:09 graystar kernel: [34448.853519]  [<ffffffffa09ad594>] ? nv_kern_open+0x414/0x7a0 [nvidia]
Mar  2 23:26:09 graystar kernel: [34448.854534]  [<ffffffff8118197a>] ? chrdev_open+0x10a/0x210
Mar  2 23:26:09 graystar kernel: [34448.855549]  [<ffffffff8117c283>] ? __dentry_open+0x243/0x350
Mar  2 23:26:09 graystar kernel: [34448.856551]  [<ffffffff81189d1b>] ? do_lookup+0x4b/0x390
Mar  2 23:26:09 graystar kernel: [34448.857539]  [<ffffffff81181870>] ? exact_lock+0x20/0x20
Mar  2 23:26:09 graystar kernel: [34448.858528]  [<ffffffff8117c491>] ? nameidata_to_filp+0x71/0x80
Mar  2 23:26:09 graystar kernel: [34448.859523]  [<ffffffff8118af98>] ? do_last+0x3d8/0x800
Mar  2 23:26:09 graystar kernel: [34448.860491]  [<ffffffff8118bd35>] ? path_openat+0xd5/0x3f0
Mar  2 23:26:09 graystar kernel: [34448.861461]  [<ffffffff81188f25>] ? putname+0x35/0x50
Mar  2 23:26:09 graystar kernel: [34448.862435]  [<ffffffff8118d763>] ? user_path_at_empty+0x63/0xa0
Mar  2 23:26:09 graystar kernel: [34448.863415]  [<ffffffff8118c169>] ? do_filp_open+0x49/0xa0
Mar  2 23:26:09 graystar kernel: [34448.864420]  [<ffffffff8131e2fa>] ? strncpy_from_user+0x4a/0x90
Mar  2 23:26:09 graystar kernel: [34448.865402]  [<ffffffff8164f5de>] ? _raw_spin_lock+0xe/0x20
Mar  2 23:26:09 graystar kernel: [34448.866383]  [<ffffffff81199b2a>] ? alloc_fd+0x10a/0x150
Mar  2 23:26:09 graystar kernel: [34448.867357]  [<ffffffff8117c677>] ? do_sys_open+0x107/0x1e0
Mar  2 23:26:09 graystar kernel: [34448.868334]  [<ffffffff8117c790>] ? sys_open+0x20/0x30
Mar  2 23:26:09 graystar kernel: [34448.869310]  [<ffffffff81657b02>] ? system_call_fastpath+0x16/0x1b
Mar  2 23:26:09 graystar kernel: [34448.870291] Code: 44 39 f0 76 05 45 89 74 24 38 be 75 40 00 00 48 89 df ff 93 98 00 00 00 85 c0 75 40 44 89 e8 41 03 44 24 38 ff c8 ba 00 00 00 00 <41> f7 f5 41 89 84 24 90 00 00 00 8b 45 10 0f af 45 14 41 0f af 
Mar  2 23:26:09 graystar kernel: [34448.871440] RIP  [<ffffffffa06b576b>] _nv011231rm+0x148/0x2c2 [nvidia]
Mar  2 23:26:09 graystar kernel: [34448.872655]  RSP <ffff880218cef9c8>
Mar  2 23:26:09 graystar kernel: [34448.933518] ---[ end trace 32b42aca460a81dc ]---
Mar  2 23:27:24 graystar kernel: Kernel logging (proc) stopped.

While you could find the log of the last reboot at this link: http://dl.dropbox.com/u/1036572/TMP/graystar_kern.log

[Lekensteyn]

The kernel that you are running is built with gcc 4.4 which does not match the compiler used by Oneiric: 4.6. Either build the kernel yourself or download the linux-image-3.2...-generic and linux-headers-3.2...-generic packages from http://packages.ubuntu.com/precise/linux-image

[derkling]

Ok. However, I've just rebooted with the official Ubuntu kernel:

[    0.000000] Linux version 3.0.0-16-generic (buildd@allspice) (gcc version 4.6.1 (Ubuntu/Linaro 4.6.1-9ubuntu3) ) #28-Ubuntu SMP Fri Jan 27 17:44:39 UTC 2012 (Ubuntu 3.0.0-16.28-generic 3.0.17)
[    0.000000] Command line: BOOT_IMAGE=/boot/vmlinuz-3.0.0-16-generic root=UUID=c639f650-96ce-4974-879d-40dd05598b79 ro pcie_aspm=force acpi=noirq i915.semaphores=1
....
[    7.671980] nvidia: module license 'NVIDIA' taints kernel.
[    7.671987] Disabling lock debugging due to kernel taint
[    8.006304] nvidia 0000:01:00.0: power state changed by ACPI to D0
[    8.006307] nvidia 0000:01:00.0: power state changed by ACPI to D0
[    8.006310] nvidia 0000:01:00.0: enabling device (0006 -> 0007)
[    8.006316] nvidia 0000:01:00.0: found PCI INT A -> IRQ 11
[    8.006321] nvidia 0000:01:00.0: sharing IRQ 11 with 0000:00:16.0
[    8.006324] nvidia 0000:01:00.0: sharing IRQ 11 with 0000:00:1a.0
[    8.006327] nvidia 0000:01:00.0: sharing IRQ 11 with 0000:00:1c.0
[    8.006333] nvidia 0000:01:00.0: sharing IRQ 11 with 0000:00:1c.4
[    8.006400] nvidia 0000:01:00.0: setting latency timer to 64
[    8.006403] vgaarb: device changed decodes: PCI:0000:01:00.0,olddecodes=io+mem,decodes=none:owns=none
[    8.006525] NVRM: loading NVIDIA UNIX x86_64 Kernel Module  280.13  Wed Jul 27 16:53:56 PDT 2011
[    8.036475] hda_codec: ALC269VB: BIOS auto-probing.

and the problem is still present... even if now the modules are not more marked as [permanent].

[juliotux]

This problem still present on 12.04, with the same Debug result. I'm testing it on the same N43SN.

[juliotux]

I found a solution changing 2 lines on configs:

In /etc/bumblebee/bumblebee.conf , on the section [bumblebeed], last line, set the driver to nvidia. The line will be: Driver=nvidia

In /etc/bumblebee/xorg.conf.nvidia , change the Option "ConnectedMonitor" "DFP" to Option "ConnectedMonitor" "CRT"

If you are using the Development ppa version, the config files will be in /usr/local/etc/bumblebee

May be needed restart bumblebee after change this: sudo stop bumblebeed sudo start bumblebeed

For general case, the discovery if the monitor is conected as CRT or DFP command is: /usr/lib/nvidia-current/bin/nvidia-xconfig --query-gpu-info --nvidia-cfg-path=/usr/lib/nvidia-current

[Lekensteyn]

Restarting bumblebeed is not necessary unless the Bumblebee X server is already running

[Gaugamela]

Hey!

I am also having this problem in a Asus N43SL model with Mint 12. Is there already a workaround for this or is it better to use Ironhide?

[Lekensteyn]

@Gaugamela Do you get the same errors as mentioned in the first post? There are a lot possibilities why "optirun seems to start, but no output".

[ArchangeGabriel]

@poVoq The solution to your issue is to set ConnectedMonitor to CRT instead of DFP in /etc/bumblebee/xorg.conf.nvidia.

[tomse]

seems I have the same issue. Trying setting connected monitor to crt gives this error message:

[ERROR]Cannot access secondary GPU - error: You need to change the ConnectedMonitor setting in /etc/bumblebee/xorg.conf.nvidia to DFP-0

#sudo bumblebeed -vv
[DEBUG]Reading file: /etc/bumblebee/bumblebee.conf
[DEBUG]Process /sbin/modinfo started, PID 3268.
[DEBUG]Hiding stderr for execution of /sbin/modinfo
[DEBUG]SIGCHILD received, but wait failed with No child processes
[DEBUG]Detected nvidia driver (module nvidia-current)
[DEBUG]bbswitch has been detected.
[INFO]Switching method 'bbswitch' is available and will be used.
[DEBUG]Active configuration:
[DEBUG] bumblebeed config file: /etc/bumblebee/bumblebee.conf
[DEBUG] X display: :8
[DEBUG] LD_LIBRARY_PATH: /usr/lib/nvidia-current:/usr/lib32/nvidia-current
[DEBUG] Socket path: /var/run/bumblebee.socket
[DEBUG] pidfile: /var/run/bumblebeed.pid
[DEBUG] xorg.conf file: /etc/bumblebee/xorg.conf.nvidia
[DEBUG] ModulePath: /usr/lib/nvidia-current/xorg,/usr/lib/xorg/modules
[DEBUG] GID name: bumblebee
[DEBUG] Power method: auto
[DEBUG] Stop X on exit: 1
[DEBUG] Driver: nvidia
[DEBUG] Driver module: nvidia-current
[DEBUG] Card shutdown state: 1
[DEBUG]Process /sbin/modinfo started, PID 3269.
[DEBUG]Hiding stderr for execution of /sbin/modinfo
[DEBUG]SIGCHILD received, but wait failed with No child processes
[DEBUG]Configuration test passed.
[INFO]bumblebeed 3.0 started
[DEBUG]Saving PCI configuration space...
[INFO]Unloading nvidia driver
[DEBUG]Process rmmod started, PID 3270.
[DEBUG]Process with PID 3270 returned code 0
[INFO]Switching dedicated card OFF [bbswitch]
[INFO]Initialization completed - now handling client requests
[DEBUG]Accepted new connection
[INFO]Switching dedicated card ON [bbswitch]
[DEBUG]Restoring PCI configuration space...
[INFO]Loading driver nvidia (module nvidia-current)
[DEBUG]Process modprobe started, PID 3275.
[DEBUG]Process with PID 3275 returned code 0
[INFO]Starting X server on display :8.
[DEBUG]Process Xorg started, PID 3276

and doing this will just get back to that optirun running in the background. I can hear the fan speedup when running optirun, so something is going on.

runnung kubuntu 12.04 amd64,

tomse@tomse-medion:~$ uname -a
Linux tomse-medion 3.2.0-24-generic #37-Ubuntu SMP Wed Apr 25 08:43:22 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux

tomse@tomse-medion:~$ for keyword in baseboard-manufacturer baseboard-product-name baseboard-version system-manufacturer system-product-name system-version bios-vendor bios-version bios-release-date; do
>     printf "%-22s: " "$keyword";
>     sudo dmidecode -s "$keyword";
> done
baseboard-manufacturer: MEDION         
baseboard-product-name: P7624          
baseboard-version     : To be filled by O.E.M.
system-manufacturer   : MEDION         
system-product-name   : P7624          
system-version        : To be filled by O.E.M.
bios-vendor           : American Megatrends Inc.
bios-version          : 0.49
bios-release-date     : 10/31/2011

tomse@tomse-medion:~$ optirun -V
optirun (Bumblebee) 3.0
Copyright (C) 2011 The Bumblebee Project
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>.
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.

[Lekensteyn]

@tomse Have you considered changing CRT to DFP-0 in xorg.conf.nvidia

[tomse]

I should have mentioned that I did make said change after the message appeared. The previous info is logged after changing to DFP-0.

[ArchangeGabriel]

The solution I've proposed is only for people seeing this error in kern.log : NVRM: Xid (0000:01:00): 16, Head 00000000 Count 00000000 NVRM: Xid (0000:01:00): 16, Head 00000000 Count 00000001 NVRM: Xid (0000:01:00): 16, Head 00000000 Count 00000002 NVRM: Xid (0000:01:00): 16, Head 00000000 Count 00000003 NVRM: Xid (0000:01:00): 16, Head 00000000 Count 00000004 NVRM: Xid (0000:01:00): 16, Head 00000000 Count 00000005 NVRM: Xid (0000:01:00): 16, Head 00000000 Count 00000006 NVRM: Xid (0000:01:00): 16, Head 00000000 Count 00000007

Which sould match this in Xorg.8.log : (EE) NVIDIA(GPU-0): WAIT: (E, 0, 0x857d)

[murinata]

Thank you ArchangeGabriel, after days of testing the bumblebee on my Asus N43SL with Nvidia 540M Changing the Option "ConnectedMonitor" "CRT" fixed the issue.

Thank you very much

[linduxed]

Changing to CRT fixed it for me too.

[poVoq]

Works now, with Mint Linux Maya and "CRT" Thanks for the help and great work on Bumblebee.