A method of ‘masking’ an OpenRC service (NetworkManager, in this case)

A Gentoo Linux user with an installation using OpenRC recently asked in the Gentoo Forums how to either a) disable NetworkManager so that it would not interfere with his netifrc configuration to give his installation a static IP address, or b) configure NetworkManager to use a static IP address (see the thread NetworkManager and static IP [SOLVED! THANKYOU]). In the end he solved the problem by uninstalling NetworkManager, the cleanest solution in his case given that his desktop machine is always in the same location and he does not need the features NetworkManager provides.

Now, although I use NetworkManager instead of netifrc, what intrigued me is that disabling the NetworkManager service using the standard command below does not stop the NetworkManager init script from running at boot-up:

root # rc-update delete NetworkManager default

Despite using the above command, following a reboot the NetworkManager service is still started and becomes active, and the NetworkManager daemon is running. Web browsers and other applications requiring network access still work. In order to stop the service running immediately so that his netifrc static IP address configuration could work, the aforementioned Gentoo user had to stop the NetworkManager service as follows:

root # /etc/init.d/NetworkManager stop

(The command ‘rc-service NetworkManager stop‘ does the same thing.)

The behaviour is the same on my laptop running Gentoo with OpenRC 0.22.4 and NetworkManager installed by networkmanager-1.4.0-r1 ebuild (with the upstream patch and necessary edit to the init script mentioned in Gentoo Bug Report No. 595806 – net-misc/networkmanager-1.4.0-r1[consolekit]: doesn’t automatically activate connections marked with "Automatically connect to this network when it’s available").

So two questions arose: What launches the NetworkManager init script when it has not been added to a runlevel? What needs to be done to stop this from happening? My curiosity was piqued.

As it happens, a somewhat similar situation exists when using systemd rather than OpenRC, as explained in Arch Linux Forums thread [SOLVED] NetworkManager auto restart even though I stop it. and Red Hat Bugzilla Report No. 815243 – Even though NetworkManager was manually stopped, it gets restarted automatically via D-Bus, although those were primarily concerned with how to prevent NetworkManager being restarted during the same session, i.e. without having rebooted.

The following systemd commands are needed to stop immediately the NetworkManager service and keep it from being restarted subsequently during the current session and after rebooting:

root # systemctl mask NetworkManager
root # systemctl stop NetworkManager
root # systemctl disable NetworkManager

Unfortunately there is no equivalent mask command for an OpenRC service. The equivalent OpenRC commands for the second and third commands above are:

root # rc-service NetworkManager stop
root # rc-update delete NetworkManager default

However, as I pointed out earlier, for some reason the latter command does not stop OpenRC running the NetworkManager init script at boot.

I wondered how I could ‘mask’ the NetworkManager service in OpenRC. I asked myself what the systemd mask command actually does. Well, it simply creates a symlink from /etc/systemd/system/NetworkManager.service to /dev/null so that there is no longer a real unit file for systemd to use, and therefore systemd can no longer launch the service. So why not do something similar in OpenRC. I hit upon the idea of telling the NetworkManager init script it needs a non-existent service in order to start, thus preventing OpenRC from starting the NetworkManager service:

root # echo 'rc_need="non-existent_service"' >> /etc/conf.d/NetworkManager # (Or just edit the file manually.)

That is all there is to it. When booting, OpenRC now displays the messages shown below:

* ERROR: NetworkManager needs service(s) non-existent_service
* ERROR: cannot start netmount as NetworkManager would not start
* ERROR: cannot start samba as NetworkManager would not start

As shown below, now the service is not started, so the NetworkManager daemon is never launched:

root # rc-status
Runlevel: default
 dbus                                                  [  started  ]
 syslog-ng                                             [  started  ]
 consolekit                                            [  started  ]
 netmount                                              [  stopped  ]
 cupsd                                                 [  started  ]
 samba                                                 [  stopped  ]
 cronie                                                [  started  ]
 clamd                                                 [  started  ]
 bluetooth                                             [  started  ]
 xdm                                                   [  started  ]
 cups-browsed                                          [  started  ]
 sshd                                                  [  started  ]
 local                                                 [  started  ]
Dynamic Runlevel: hotplugged
Dynamic Runlevel: needed/wanted
 modules-load                                          [  started  ]
 xdm-setup                                             [  started  ]
 avahi-daemon                                          [  started  ]
Dynamic Runlevel: manual
root # ps -ef | grep -v grep | grep -i network
root #

As expected, given that the netmount service and samba service depend on the NetworkManager service starting, neither of those services were able to start either.

Furthermore, because I masked the service, if I attempt to start it manually:

root # rc-service NetworkManager restart
 * ERROR: NetworkManager needs service(s) non-existent_service

To unmask the service in OpenRC, all that is needed is:

root # sed -i '/rc_need="non-existent_service"/d' /etc/conf.d/NetworkManager # (Or just edit the file manually.)

Note that, instead of “non-existent_service” I could have written “fubar”, “null” or any other string that is not the name of an actual service. But “non-existent_service” is more meaningful and less likely to confuse me when viewing system messages and contents of the service configuration file.

In summary…

Why does OpenRC run the NetworkManager service init script when it is not in any runlevel?

I have no idea!

I wondered if the D-Bus service does it. The Arch Wiki article on NetworkManager claims this is the case (see the section titled Disable NetworkManager). However, my attempts at preventing D-Bus doing anything to NetworkManager did not stop the NetworkManager init script from being run at boot. I deleted /etc/dbus-1/system.d/org.freedesktop.NetworkManager.conf and /etc/dbus-1/system.d/nm-dispatcher.conf but that did not help. Neither did creating an appropriate /etc/dbus-1/system.d/org.freedesktop.NetworkManager.conf or /etc/dbus-1/system-local.conf. There is no /usr/share/dbus-1/system-services/org.freedesktop.NetworkManager.service file in my Gentoo installation using OpenRC, but creating one did not help either. So, if you know what runs the OpenRC NetworkManager init script when it is not in any runlevel, please post a comment.

Anyway, I now know how to prevent it happening, so I have satisfied my curiosity. Below I list the commands I actually used in a Gentoo Linux installation (amd64, OpenRC) and a Sabayon Linux installation (~amd64, systemd) to check the functionality.

OpenRC

The following two (optionally three) commands are needed to stop immediately the NetworkManager service and prevent it being restarted subsequently during this session and after rebooting:

root # rc-service NetworkManager stop
root # echo 'rc_need="non-existent_service"' >> /etc/conf.d/NetworkManager
root # rc-update del NetworkManager default # (Optional.)

The following two (optionally three) commands are needed to unmask the NetworkManager service and start it immediately, and make it start automatically after rebooting:

root # sed -i '/rc_need="non-existent_service"/d' /etc/conf.d/NetworkManager
root # rc-service NetworkManager restart
root # rc-update add NetworkManager default # Only needed if I earlier deleted the service from the default runlevel.

systemd

The following three commands are needed to stop immediately the NetworkManager service and prevent it being restarted subsequently during this session and after rebooting:

root # systemctl mask NetworkManager
root # systemctl stop NetworkManager
root # systemctl disable NetworkManager

The following three systemd commands are needed to unmask the NetworkManager service and start it immediately, and also make it start automatically after rebooting:

root # systemctl unmask NetworkManager
root # systemctl enable NetworkManager
root # systemctl start NetworkManager
Advertisements

Getting KDE Plasma 5 to work with the NVIDIA closed-source driver in Gentoo Linux

Up until a few days ago I had avoided migrating from KDE 4 to KDE Plasma 5, Frameworks 5 and Applications 5 — I’ll refer to the latter three package categories collectively as ‘KDE:5’ — on my main laptop, a Clevo W230SS with NVIDIA Optimus hardware and Gentoo Linux Stable Branch installed. My reluctance to migrate to KDE:5 was because of various problems I experience in KDE:5 on my Compal NBLB2 laptop, which has Gentoo Testing Branch installed (currently Plasma 5.7.1, which you would expect to be less buggy than Plasma 5.5.5 in the Gentoo Stable Branch).

Recently the maintainers of Gentoo’s KDE ebuilds removed some of the KDE 4 ebuilds and made some of the other ebuilds dependent on KDE:5. It became more complicated and convoluted to keep KDE 4 going, so I reluctantly threw in the towel and migrated to KDE:5 on my main laptop. I wish I could have kept KDE 4 on that machine, as KDE 4 worked extremely well (and looked great too).

My first problem after migrating was the infamous black screen in X Windows at start-up. Trying the various suggestions in the Gentoo Wiki did not help and, for the first time since I’ve owned the Clevo laptop, I was glad it has NVIDIA Optimus hardware as I was able to change from using nvidia-drivers to using xf86-video-intel, which got me to a usable Desktop after I switched desktop managers from SDDM (see the system log file error messages below) to LightDM.

Jul 17 04:32:37 clevow230ss sddm-helper[3245]: PAM unable to dlopen(/lib64/security/pam_systemd.so): /lib64/security/pam_systemd.so: cannot open shared object file: No such file or directory
Jul 17 04:32:37 clevow230ss sddm-helper[3245]: PAM adding faulty module: /lib64/security/pam_systemd.so

Although I had merged x11-misc/sddm with USE="-systemd" because my installation uses OpenRC, the above error messages made me suspect that something is wrong with the sddm-0.13.0-r3 ebuild, which is why I switched to LightDM.

However, using solely the Intel driver is not a long-term solution for me because DraftSight CAD software is slower with the Intel driver, so I was keen to get Plasma 5 working with the closed-source NVIDIA driver (I do not want to use Bumblebee).

I managed to get LightDM and Plasma 5 working with nvidia-drivers by doing the following:

  1. Merge x11-misc/lightdm.
  2. Re-merge kde-plasma/plasma-meta with USE="-sddm".
  3. Remove the x11-misc/sddm package and kde-plasma/sddm-kcm package by using the command ‘emerge --ask --depclean‘.
  4. Edit the file /etc/lightdm/lightdm.conf to add the line ‘greeter-session=lightdm-kde-greeter‘ as specified in Gentoo Wiki article LightDM.
  5. Edit the file /etc/lightdm/lightdm.conf to add the line ‘display-setup-script=/etc/X11/Sessions/plasma‘ (any file name would do).
  6. Create the above-mentioned Bash script /etc/X11/Sessions/plasma containing the following:
#!/bin/bash
GPU=`eselect opengl list | grep \* | awk '{ print $2 }'`
if [ "$GPU" = "nvidia" ]; then
    xrandr --setprovideroutputsource modesetting NVIDIA-0
    xrandr --auto
fi

I can now switch between the NVIDIA closed-source driver and the Intel open-source driver using the method described in an earlier post: Switching between Intel and NVIDIA graphics processors on a laptop with NVIDIA Optimus hardware running Gentoo Linux.

NetworkManager: Failed to activate – The name org.freedesktop.NetworkManager was not provided by any .service files

Because I need to connect quickly and easily to numerous wired and wireless networks (DHCP or static IP addressing), I use NetworkManager in my Gentoo Linux amd64 installation running OpenRC and KDE 4. My Clevo W230SS laptop has an Intel Dual Band Wireless-AC 7260 Plus Bluetooth adapter card, and my installation uses the iwlwifi module:

# lspci -knn | grep Net -A2
03:00.0 Network controller [0280]: Intel Corporation Wireless 7260 [8086:08b1] (rev bb)
        Subsystem: Intel Corporation Dual Band Wireless-AC 7260 [8086:4070]
        Kernel driver in use: iwlwifi
# lsmod | grep iwl
iwlmvm                143919  0
iwlwifi                75747  1 iwlmvm

As I am using NetworkManager instead of netifrc, in accordance with the instructions in the Gentoo Wiki article on NetworkManager I do not have any net.* services enabled (not even net.lo):

# rc-update show -v
       NetworkManager |      default                 
                acpid |                              
            alsasound |                              
         avahi-daemon |                              
       avahi-dnsconfd |                              
               binfmt | boot                         
            bluetooth |      default                 
             bootmisc | boot                         
         busybox-ntpd |                              
     busybox-watchdog |                              
                clamd |                              
          consolefont |                              
           consolekit |      default                 
               cronie |      default                 
         cups-browsed |      default                 
                cupsd |      default                 
                 dbus |      default                 
                devfs |                       sysinit
               dhcpcd |                              
                dhcpd |                              
             dhcrelay |                              
            dhcrelay6 |                              
                dmesg |                       sysinit
              dropbox |                              
           fancontrol |                              
                 fsck | boot                         
                 fuse |                              
           git-daemon |                              
                  gpm |                              
              hddtemp |                              
             hostname | boot                         
              hwclock | boot                         
            ip6tables |                              
             iptables |                              
              keymaps | boot                         
            killprocs |              shutdown        
    kmod-static-nodes |                       sysinit
           lm_sensors |                              
                local |      default                 
           localmount | boot                         
             loopback | boot                         
      mit-krb5kadmind |                              
          mit-krb5kdc |                              
       mit-krb5kpropd |                              
              modules | boot                         
             mount-ro |              shutdown        
                 mtab | boot                         
                mysql |                              
                  nas |                              
         net.enp4s0f1 |                              
               net.lo |                              
             netmount |      default                 
           ntp-client |                              
                 ntpd |                              
           nullmailer |                              
              numlock |                              
  nvidia-persistenced |                              
           nvidia-smi |                              
              osclock |                              
              pciparm |                              
               procfs | boot                         
              pwcheck |                              
            pydoc-2.7 |                              
            pydoc-3.4 |                              
               rfcomm |                              
                 root | boot                         
               rsyncd |                              
            s6-svscan |                              
                samba |      default                 
                saned |                              
            saslauthd |                              
            savecache |              shutdown        
                 sntp |                              
                 sshd |      default                 
             svnserve |                              
                 swap | boot                         
            swapfiles | boot                         
              swclock |                              
               sysctl | boot                         
                sysfs |                       sysinit
            syslog-ng |      default                 
        teamviewerd10 |                              
         termencoding | boot                         
             timidity |                              
         tmpfiles.dev |                       sysinit
       tmpfiles.setup | boot                         
               twistd |                              
                 udev |                       sysinit
                  ufw | boot                         
              urandom | boot                         
       wpa_supplicant |                              
                  xdm |      default                 
            xdm-setup |

I have left the netmount service enabled in case I want to use network-attached file shares at home or in one of the various office locations where I work.

Networking works fine on my laptop with the many wired and wireless networks I have used except for one particular public wireless network (it is in an airport, has multiple Access Points, and its Access Points only support 802.11a/b/g, which may or may not be relevant) for which the following message would usually appear in a pop-up window when I tried to connect to the network from the KDE network management GUI after start-up:

Failed to activate
The name org.freedesktop.NetworkManager was not provided by any .service files

Error message displayed by KDE when trying to connect to one specific network

Error message displayed by KDE when trying to connect to one specific network


This occurred with both networkmanager-1.0.2-r1 and networkmanager-1.0.6, the two Stable Branch releases of NetworkManager currently available in Gentoo Linux.

The wireless network is not the only network at that particular location, and the ‘Failed to activate’ message occurred whichever network (wireless or wired) I tried to access at that location. When this problem occurred, it transpired that the NetworkManager service was not running (it had crashed):

$ nmcli d
Error: NetworkManager is not running.
$ rc-status
Runlevel: default
 dbus                   [  started  ]
 NetworkManager         [  crashed  ]
 netmount               [  started  ]
 syslog-ng              [  started  ]
 cupsd                  [  started  ]
 samba                  [  crashed  ]
 consolekit             [  started  ]
 cronie                 [  started  ]
 bluetooth              [  started  ]
 xdm                    [  started  ]
 cups-browsed           [  started  ]
 sshd                   [  started  ]
 local                  [  started  ]
Dynamic Runlevel: hotplugged
Dynamic Runlevel: needed
 xdm-setup              [  started  ]
 avahi-daemon           [  started  ]
Dynamic Runlevel: manual

(I am not bothered that Samba crashes in that particular location. It crashes even if a connection is established, because the public wireless network does not provide network file systems. Samba works fine when I connect the laptop to an office network or to my home network.)

Even if the ‘Failed to activate’ message occurred, sometimes (but not always) the laptop could still connect to networks after I restarted the NetworkManager service (albeit sometimes it was necessary to restart it more than once):

# /etc/init.d/NetworkManager restart

When it is possible to connect to networks, the NetworkManager service is of course running:

$ nmcli d
DEVICE    TYPE      STATE        CONNECTION           
sit0      sit       connected    sit0                 
wlp3s0    wifi      connected    Free_Airport_Internet
enp4s0f1  ethernet  unavailable  --                   
lo        loopback  unmanaged    --        
$ rc-status
Runlevel: default
 dbus                   [  started  ]
 NetworkManager         [  started  ]
 netmount               [  started  ]
 syslog-ng              [  started  ]
 cupsd                  [  started  ]
 samba                  [  crashed  ]
 consolekit             [  started  ]
 cronie                 [  started  ]
 bluetooth              [  started  ]
 xdm                    [  started  ]
 cups-browsed           [  started  ]
 sshd                   [  started  ]
 local                  [  started  ]
Dynamic Runlevel: hotplugged
Dynamic Runlevel: needed
 xdm-setup              [  started  ]
 avahi-daemon           [  started  ]
Dynamic Runlevel: manual

I searched the Web for the error message and, based on a recommendation on the Web page ‘nm-applet gives errors‘ claiming the problem is due to the iwlwifi driver when used with an Intel 7260 controller, I created a file /etc/modprobe.d/iwlwifi.conf containing the following line, and rebooted:

options iwlwifi power_save=0

However, the error message still occurred. So I changed the iwlwifi module options line to the following, as also recommended on that page, and rebooted:

options iwlwifi 11n_disable=1 power_save=0

However, the error message still occurred.

The default value for OpenRC’s rc_depend_strict variable is YES if rc_depend_strict is not declared in the file /etc/rc.conf, but I do not think that is the cause of the problem:

# Do we allow any started service in the runlevel to satisfy the dependency
# or do we want all of them regardless of state? For example, if net.eth0
# and net.eth1 are in the default runlevel then with rc_depend_strict="NO"
# both will be started, but services that depend on 'net' will work if either
# one comes up. With rc_depend_strict="YES" we would require them both to
# come up.
#rc_depend_strict="YES"

As already mentioned, sometimes just restarting the NetworkManager service once or more did enable the laptop to connect to the network. This made me wonder whether the problem had something to do either with the timing of the launch of the NetworkManager service or with the timing of the service establishing a connection. As netmount is the only other network-related service enabled at start-up, I checked the netmount service’s configuration file /etc/conf.d/netmount to see what it contained (it’s the same in both the latest stable openrc-0.17 and the latest testing openrc-0.18.2):

# You will need to set the dependencies in the netmount script to match
# the network configuration tools you are using. This should be done in
# this file by following the examples below, and not by changing the
# service script itself.
#
# Each of these examples is meant to be used separately. So, for
# example, do not set rc_need to something like "net.eth0 dhcpcd".
#
# If you are using newnet and configuring your interfaces with static
# addresses with the network script, you  should use this setting.
#
#rc_need="network"
#
# If you are using oldnet, you must list the specific net.* services you
# need.
#
# This example assumes all of your netmounts can be reached on
# eth0.
#
#rc_need="net.eth0"
#
# This example assumes some of your netmounts are on eth1 and some
# are on eth2.
#
#rc_need="net.eth1 net.eth2"
#
# If you are using a dynamic network management tool like
# networkmanager, dhcpcd in standalone mode, wicd, badvpn-ncd, etc, to
# manage the network interfaces with the routes to your netmounts, you
# should list that tool.
#
#rc_need="networkmanager"
#rc_need="dhcpcd"
#rc_need="wicd"
#
# The default setting is designed to be backward compatible with our
# current setup, but you are highly discouraged from using this. In
# other words, please change it to be more suited to your system.
#
rc_need="net"

As I am using NetworkManager rather than netifrc, I followed the instructions in the file’s comments and changed the file’s contents from:

rc_need="net"

to:

rc_need="networkmanager"

After making the above change, the console messages at boot-up included a new message:

* ERROR: netmount needs service(s) networkmanager

That message made sense: rc_need had been set to "networkmanager" and, obviously, netmount can only do its job if NetworkManager is running (AND a network connection has been established). However, notice that the name of the NetworkManager service initscript is /etc/init.d/NetworkManager, not /etc/init.d/networkmanager. In other words, the instructions in /etc/conf.d/netmount are wrong: the name of the service is actually ‘NetworkManager‘, not ‘networkmanager‘. So I changed /etc/conf.d/netmount to contain rc_need="NetworkManager" instead of rc_need="networkmanager" and, unsurprisingly, the above-mentioned error message no longer occurs. I have filed Gentoo Bugzilla Bug Report No. 564846 requesting that the comment in the configuration file be changed.

Nevertheless, the ‘Failed to activate’ message still occurred when I tried to connect to any network at that location by using the DE’s network management GUI, and therefore I still needed to restart the NetworkManager service manually in order to be able to connect to any network there. Although I am not yet sure of the root cause and solution, I have found a work-around which avoids me having to manually restart the NetworkManager service, as explained below.

Although OpenRC correctly launches the NetworkManager service, that service remains inactive until it actually establishes a network connection. This is not a bug, it is the way OpenRC and NetworkManager work (see the explanation in the Gentoo Forums thread NetworkManager has started, but is inactive). This is why the following console message appears during boot-up:

* WARNING: NetworkManager has already started, but is inactive

If you did not configure NetworkManager to connect automatically to a network, after logging-in to the DE you will need to use the DE’s network management GUI (plasma-nm in the case if KDE, nm-applet in the case of e.g. Xfce) to tell NetworkManager to connect to the desired network. However, I found that waiting that long before trying to connect is too late to avoid the ‘Failed to activate’ problem, i.e. NetworkManager crashes after a while. I do not know why this happens, but it usually happens only when I am at the location covered by one specific wireless network (which is why I wonder if the problem is a result of that network only supporting 802.11a/b/g). By configuring NetworkManager to connect automatically to the wireless network which seemed to trigger the problem, the NetworkManager service tries to connect earlier. It is possible to configure NetworkManager to do this either by using the DE network GUI and ticking ‘Automatically connect to this network when it is available’ for the relevant network connection, or by directly editing the relevant connection’s file in the directory /etc/NetworkManager/system-connections/.

Of the various wired and wireless connections I had configured on the laptop, I had named the problematic wireless network’s connection ‘Free_Airport_Internet’. So I edited the file /etc/NetworkManager/system-connections/Free_Airport_Internet and deleted the line ‘autoconnect=false‘ in the [connections] section of the file (the default value of the autoconnect variable is TRUE – see man nm-settings). I could instead have done this by using the DE’s network manager GUI and ticking ‘Automatically connect to this network when it is available’ for that network connection. Now, when the laptop boots, NetworkManager tries to connect to that network and the ‘Failed to activate’ problem is avoided. This works with or without the iwlwifi driver options I mentioned above, so, despite the claim on the Web page I referenced above, the root cause of the problem does not appear to be the iwlwifi driver. What I don’t understand is why the problem only seems to occur with one particular network (a public wireless network which happens to only support 802.11a/b/g), i.e. even if none of the NetworkManager connection files in my installation have been configured to try to establish a connection automatically, with all the other wireless networks I have used in other locations (I believe those all support at least 802.11a/b/g/n) I have been able to establish a connection manually by using the DE’s network management GUI.

The bottom line

If your installation uses NetworkManager and you experience the ‘Failed to activate’ message when trying to connect to networks from the DE’s network management GUI, check if the NetworkManager service is running. You can check by using the command ‘nmcli d‘ in a console. If it is not running, try to restart the NetworkManager service from the command line. If the connection is not already configured to start automatically, configure it to start automatically in order to try to make NetworkManager become active at an early stage.

POSTSCRIPT (November 6, 2015)

The two links below are to old bug reports regarding earlier versions of NetworkManager having trouble using wireless networks with multiple Access Points. I wonder if the problem I saw with NetworkManager crashing when not configured to connect automatically to the specific network I mentioned above is somehow related to those problems:

background scanning causes drivers to disassociate – WiFi roaming causes NetworkManager to lose routing

network-manager roams to (none) ((none)) – background scanning

Roaming to BSSID “(none)” certainly happens with this particular network too, as shown by the messages in the laptop’s system log from yesterday when I was using the laptop with that network (the laptop was stationary the whole time):

# cat /var/log/messages | grep "Nov  5 11" | grep NetworkManager | grep \(none\)
Nov  5 11:01:22 clevow230ss NetworkManager[2459]:   (wlp3s0): roamed from BSSID 04:C5:A4:C3:F9:EE (Free_Airport_Internet) to (none) ((none))
Nov  5 11:01:22 clevow230ss NetworkManager[2459]:   (wlp3s0): roamed from BSSID (none) ((none)) to B8:BE:BF:69:89:6E (Free_Airport_Internet)
Nov  5 11:13:23 clevow230ss NetworkManager[2459]:   (wlp3s0): roamed from BSSID B8:BE:BF:69:89:6E (Free_Airport_Internet) to (none) ((none))
Nov  5 11:13:23 clevow230ss NetworkManager[2459]:   (wlp3s0): roamed from BSSID (none) ((none)) to 04:C5:A4:C3:F9:EE (Free_Airport_Internet)
Nov  5 11:15:23 clevow230ss NetworkManager[2459]:   (wlp3s0): roamed from BSSID 04:C5:A4:C3:F9:EE (Free_Airport_Internet) to (none) ((none))
Nov  5 11:15:23 clevow230ss NetworkManager[2459]:   (wlp3s0): roamed from BSSID (none) ((none)) to B8:BE:BF:69:89:6E (Free_Airport_Internet)
Nov  5 11:19:22 clevow230ss NetworkManager[2459]:   (wlp3s0): roamed from BSSID B8:BE:BF:69:89:6E (Free_Airport_Internet) to (none) ((none))
Nov  5 11:19:23 clevow230ss NetworkManager[2459]:   (wlp3s0): roamed from BSSID (none) ((none)) to B8:BE:BF:69:89:6E (Free_Airport_Internet)
Nov  5 11:49:50 clevow230ss NetworkManager[2459]:   (wlp3s0): roamed from BSSID B8:BE:BF:69:89:6E (Free_Airport_Internet) to (none) ((none))
Nov  5 11:49:50 clevow230ss NetworkManager[2459]:   (wlp3s0): roamed from BSSID (none) ((none)) to 68:BC:0C:A1:3C:DE (Free_Airport_Internet)
Nov  5 11:51:51 clevow230ss NetworkManager[2459]:   (wlp3s0): roamed from BSSID 68:BC:0C:A1:3C:DE (Free_Airport_Internet) to (none) ((none))
Nov  5 11:51:51 clevow230ss NetworkManager[2459]:   (wlp3s0): roamed from BSSID (none) ((none)) to B8:BE:BF:69:89:6E (Free_Airport_Internet)

Today I’m using a hotel network in my hotel room, and that does not roam to BSSID “(none)”, but I don’t know if my room is within range of more than one Access Point:

# cat /var/log/messages | grep "Nov  6" | grep NetworkManager | grep \(none\)
#

Anyway, with the work-around described in this post I have not had any further trouble accessing the particular network, but it would be interesting to know the root cause.

Gentoo Linux: Run a script at shutdown, but not when rebooting

In Gentoo Linux it is straightforward to run scripts automatically when the OS starts (boots) and stops (either shutting down or rebooting). You simply need to place an executable script file in the directory /etc/local.d/ with the suffix ‘.start‘ or ‘.stop‘, depending on whether you want the script to run at the beginning or end of your Linux session. The file /etc/local.d/README (complete with ‘sequentially’ misspelt) explains it better:

This directory should contain programs or scripts which are to be run
when the local service is started or stopped.

If a file in this directory is executable and it has a .start extension,
it will be run when the local service is started. If a file is
executable and it has a .stop extension, it will be run when the local
service is stopped.

All files are processed in lexical order.

Keep in mind that files in this directory are processed sequencially,
and the local service is not considered started or stopped until
everything is processed, so if you have a process which takes a long
time to run, it can delay your boot or shutdown processing.

Scripts with a ‘.stop‘ suffix are launched both when you shutdown your Linux installation and when you reboot it. However, sometimes you may not want to run a script when you reboot your installation. A typical example would be a script to backup your hard drive; you would probably only want it to run when you have finished for the day and you are shutting down and powering off your machine. So, how do you achieve that? I initially thought I would be able to use the ‘runlevel‘ command or the RUNLEVEL environment variable in a script (see man runlevel regarding both). But I could not get my script /etc/local.d/10-run_on_shutdown.stop to work using either. However, the command ‘who -r‘ (‘who --runlevel‘) does work for me in Gentoo Linux with OpenRC:

$ cat /etc/local.d/10-run_on_shutdown.stop
#!/bin/bash
if [ `who -r | awk '{print $2}'` = "0" ]; then
  echo "shutting down" >> /home/fitzcarraldo/test.txt
  date >> /home/fitzcarraldo/test.txt
elif [ `who -r | awk '{print $2}'` = "6" ]; then
  echo "rebooting" >> /home/fitzcarraldo/test.txt
  date >> /home/fitzcarraldo/test.txt
else
  echo "neither rebooting nor shutting down" >> /home/fitzcarraldo/test.txt
  date >> /home/fitzcarraldo/test.txt
fi
$

After rebooting, then shutting down and booting, then rebooting again, the contents of the file test.txt show that the above-mentioned simple script works as intended:

$ cat test.txt
rebooting
Sun  6 Sep 12:42:11 BST 2015
shutting down
Sun  6 Sep 12:46:04 BST 2015
rebooting
Sun  6 Sep 12:49:31 BST 2015
$

So the following script /etc/local.d/10-run_on_shutdown.stop will do the desired job:

$ cat /etc/local.d/10-run_on_shutdown.stop
#!/bin/bash
if [ `who -r | awk '{print $2}'` = "0" ]; then
  ######################################################################
  # Put Bash commands here to be executed on shutdown but not on reboot.
  ######################################################################
fi
$

Don’t forget to make the script executable:

# chmod +x /etc/local.d/10-run_on_shutdown.stop

NetworkManager creating a new connection ‘eth0’ that does not work, Part 4

Further to my previous post, this is to report the result of another experiment. By doing all the following I can stop NetworkManager creating an invalid second eth0 connection:

  • Enable IPv6 system-wide in /etc/modprobe.d/aliases.conf by commenting-out ‘alias net-pf-10 off‘.
  • Disable use of IPv6 by the Avahi daemon in /etc/avahi/avahi-daemon.conf (see the four additional lines given in my previous post).
  • Use plasma-nm to edit the connection profile for ‘eth0’ that I had already created. Click on the IPv6 tab and ensure ‘Method: Ignored‘ is selected. Click on the IPv4 tab and ensure ‘Method: Automatic‘ is selected and ‘IPv4 is required for this connection‘ is ticked. Ticking ‘IPv4 is required for this connection‘ adds the line ‘may-fail=false‘ in the [ipv4] section in the file /etc/NetworkManager/system-connections/eth0 (the default value for may-fail is ‘true‘ if the box has not been ticked and may-fail has not been assigned in the file).

The various experiments I have conducted are summarised in the following table:

Laptop WiFi switch off off off off off on
IPv6 enabled in aliases.conf yes no yes yes yes yes
IPv6 enabled in avahi-daemon.conf yes yes no no yes yes
[ipv6] method= ignore ignore ignore ignore ignore ignore
[ipv4] method= auto auto auto auto auto auto
[ipv4] may-fail= true true true false false false
Invalid second eth0 created usually no usually no yes yes

As disabling IPv6 system-wide makes it impossible for NetworkManager to use IPv6, the above table can actually be written as follows:

Laptop WiFi switch off off off off off on
IPv6 enabled in aliases.conf yes no yes yes yes yes
IPv6 enabled in avahi-daemon.conf yes yes||no no no yes yes
[ipv6] method= ignore ignore ignore ignore ignore ignore
[ipv4] method= auto auto auto auto auto auto
[ipv4] may-fail= true true||false true false false false
Invalid second eth0 created usually no usually no yes yes

I still think there is a bug in NetworkManager. I would not have expected NetworkManager to create a second eth0 connection and make it an IPv6 Link-Local connection when all the following are true:

  • /etc/NetworkManager.conf has ‘no-auto-default=eth0‘ in the [main] section.
  • IPv4 is required for this connection‘ is not ticked in plasma-nm (i.e. the [ipv4] section in /etc/NetworkManager/system-connections/eth0 contains either the line ‘may-fail=true‘ or the line ‘may-fail=‘).
  • Method: Automatic‘ is selected for IPv4 (‘method=auto‘ under [ipv4] in /etc/NetworkManager/system-connections/eth0).
  • Method: Ignored‘ is selected for IPv6 (‘method=ignore‘ under [ipv6] in /etc/NetworkManager/system-connections/eth0) and the other fields on the IPv6 tab have been rendered unselectable as a result.

Anyway, I will keep IPv6 disabled in /etc/avahi/avahi-daemon.conf and IPv6 enabled system-wide. This seems to be the first thing to try if you’re experiencing the creation of an invalid additional eth0 connection with an IPv6 Link-Local address and you’re sure that none of the net.* services are running.

NetworkManager creating a new connection ‘eth0′ that does not work, Part 3

I’m even more convinced the problem discussed in my previous post is due to a bug in NetworkManager. I believe the issue with the Avahi daemon generating an IPv6 Link-Local address is a consequence of NetworkManager not always activating an interface and therefore not obtaining an IPv4 address, i.e. the IPv6 Link-Local address produced by the Avahi daemon is a side effect, not the root cause.

After my previous post I discovered that adding ‘use-ipv6=no‘ in /etc/avahi/avahi-daemon.conf (my Experiment 2) had not prevented avahi-daemon using IPv6. However, adding the following lines in /etc/avahi/avahi-daemon.conf defintely does prevent avahi-daemon from using IPv6 in my installation:

use-ipv4=yes
use-ipv6=no
publish-a-on-ipv6=no
publish-aaaa-on-ipv4=no

You can see in the message log below that the Avahi daemon is no longer generating an IPv6 Link-Local address. However, even with IPv6 disabled in avahi-daemon, an invalid second eth0 connection with an IPv6 Link-Local address still occurs in my installation. This indicates the problem is not caused by the Avahi daemon.

Mar 18 22:17:31 localhost syslog-ng[8316]: syslog-ng starting up; version='3.6.2'
Mar 18 22:17:32 localhost NetworkManager[8346]: <info>  NetworkManager (version 1.0.0) is starting...
Mar 18 22:17:32 localhost NetworkManager[8346]: <info>  Read config: /etc/NetworkManager/NetworkManager.conf
Mar 18 22:17:32 localhost NetworkManager[8346]: <info>  WEXT support is enabled
Mar 18 22:17:34 localhost kernel: fglrx_pci 0000:01:00.0: irq 34 for MSI/MSI-X
Mar 18 22:17:34 localhost kernel: <6>[fglrx] Firegl kernel thread PID: 8351
Mar 18 22:17:34 localhost kernel: <6>[fglrx] Firegl kernel thread PID: 8352
Mar 18 22:17:34 localhost kernel: <6>[fglrx] Firegl kernel thread PID: 8353
Mar 18 22:17:34 localhost kernel: <6>[fglrx] IRQ 34 Enabled
Mar 18 22:17:34 localhost kernel: <6>[fglrx] Reserved FB block: Shared offset:0, size:1000000 
Mar 18 22:17:34 localhost kernel: <6>[fglrx] Reserved FB block: Unshared offset:f7e2000, size:4000 
Mar 18 22:17:34 localhost kernel: <6>[fglrx] Reserved FB block: Unshared offset:f7e6000, size:51a000 
Mar 18 22:17:34 localhost kernel: <6>[fglrx] Reserved FB block: Unshared offset:3fff3000, size:d000 
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  Loaded plugin keyfile: (c) 2007 - 2013 Red Hat, Inc.  To report bugs please use the NetworkManager mailing list.
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  new connection /etc/NetworkManager/system-connections/Cisco00497
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  new connection /etc/NetworkManager/system-connections/eth0
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  new connection /etc/NetworkManager/system-connections/DIRECT-HeC460 Series
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  monitoring kernel firmware directory '/lib/firmware'.
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  rfkill0: found WiFi radio killswitch (at /sys/devices/pci0000:00/0000:00:1c.1/0000:03:00.0/ieee80211/phy0/rfkill0) (driver iwlwifi)
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  WiFi hardware radio set enabled
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  WWAN hardware radio set enabled
Mar 18 22:17:33 localhost /etc/init.d/NetworkManager[8326]: WARNING: NetworkManager has started, but is inactive
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  Loaded device plugin: /usr/lib64/NetworkManager/libnm-device-plugin-bluetooth.so
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  Loaded device plugin: /usr/lib64/NetworkManager/libnm-device-plugin-adsl.so
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  Loaded device plugin: /usr/lib64/NetworkManager/libnm-device-plugin-wwan.so
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  Loaded device plugin: /usr/lib64/NetworkManager/libnm-device-plugin-wifi.so
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  WiFi disabled by radio killswitch; enabled by state file
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  WWAN enabled by radio killswitch; enabled by state file
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  WiMAX enabled by radio killswitch; enabled by state file
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  Networking is enabled by state file
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (lo): link connected
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (lo): carrier is ON
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (lo): new Generic device (driver: 'unknown' ifindex: 1)
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (lo): exported as /org/freedesktop/NetworkManager/Devices/0
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (eth0): link connected
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (eth0): carrier is ON
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (eth0): new Ethernet device (driver: 'atl1c' ifindex: 2)
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (eth0): exported as /org/freedesktop/NetworkManager/Devices/1
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (eth0): device state change: unmanaged -> unavailable (reason 'connection-assumed') [10 20 41]
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (eth0): device state change: unavailable -> disconnected (reason 'connection-assumed') [20 30 41]
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  startup complete
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (eth0): Activation: starting connection 'eth0'
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (eth0): Activation: Stage 1 of 5 (Device Prepare) scheduled...
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (wlan0): using nl80211 for WiFi device control
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (wlan0): new 802.11 WiFi device (driver: 'iwlwifi' ifindex: 3)
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (wlan0): exported as /org/freedesktop/NetworkManager/Devices/2
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (wlan0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (wlan0): preparing device
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (eth0): Activation: Stage 1 of 5 (Device Prepare) started...
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (eth0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (eth0): Activation: Stage 2 of 5 (Device Configure) scheduled...
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (eth0): Activation: Stage 1 of 5 (Device Prepare) complete.
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (eth0): Activation: Stage 2 of 5 (Device Configure) starting...
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (eth0): device state change: prepare -> config (reason 'none') [40 50 0]
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (eth0): Activation: Stage 2 of 5 (Device Configure) successful.
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (eth0): Activation: Stage 3 of 5 (IP Configure Start) scheduled.
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (eth0): Activation: Stage 2 of 5 (Device Configure) complete.
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (eth0): Activation: Stage 3 of 5 (IP Configure Start) started...
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (eth0): device state change: config -> ip-config (reason 'none') [50 70 0]
Mar 18 22:17:33 localhost dbus[7763]: [system] Activating service name='org.freedesktop.ModemManager1' (using servicehelper)
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (eth0): Activation: Stage 5 of 5 (IPv6 Commit) scheduled...
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (eth0): Activation: Stage 3 of 5 (IP Configure Start) complete.
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (eth0): Activation: Stage 5 of 5 (IPv6 Commit) started...
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (eth0): device state change: ip-config -> ip-check (reason 'none') [70 80 0]
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (eth0): Activation: Stage 5 of 5 (IPv6 Commit) complete.
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (eth0): device state change: ip-check -> secondaries (reason 'none') [80 90 0]
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  (eth0): device state change: secondaries -> activated (reason 'none') [90 100 0]
Mar 18 22:17:33 localhost NetworkManager[8346]: <info>  NetworkManager state is now CONNECTED_LOCAL
Mar 18 22:17:33 localhost acpid[8386]: starting up with netlink and the input layer
Mar 18 22:17:33 localhost acpid[8386]: 6 rules loaded
Mar 18 22:17:33 localhost acpid[8386]: waiting for events: event logging is off
Mar 18 22:17:34 localhost ModemManager[8385]: <info>  ModemManager (version 1.4.2) starting in system bus...
Mar 18 22:17:34 localhost NetworkManager[8346]: <info>  (eth0): Activation: successful, device activated.
Mar 18 22:17:34 localhost dbus[7763]: [system] Activating service name='org.freedesktop.nm_dispatcher' (using servicehelper)
Mar 18 22:17:34 localhost dbus[7763]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Mar 18 22:17:34 localhost nm-dispatcher[8435]: Dispatching action 'up' for eth0
Mar 18 22:17:34 localhost rpc.statd[8451]: Version 1.3.2 starting
Mar 18 22:17:34 localhost rpc.statd[8451]: Flags: TI-RPC 
Mar 18 22:17:34 localhost /etc/init.d/NetworkManager[8457]: status: inactive
Mar 18 22:17:34 localhost rpc.statd[8451]: Running as root.  chown /var/lib/nfs to choose different user
Mar 18 22:17:34 localhost /etc/init.d/NetworkManager[8469]: status: inactive
Mar 18 22:17:34 localhost dbus[7763]: [system] Successfully activated service 'org.freedesktop.ModemManager1'
Mar 18 22:17:34 localhost NetworkManager[8346]: <info>  ModemManager disappeared from bus
Mar 18 22:17:34 localhost NetworkManager[8346]: <info>  ModemManager available in the bus
Mar 18 22:17:35 localhost sm-notify[8556]: Version 1.3.2 starting
Mar 18 22:17:35 localhost avahi-daemon[8585]: Found user 'avahi' (UID 108) and group 'avahi' (GID 444).
Mar 18 22:17:35 localhost avahi-daemon[8585]: Successfully dropped root privileges.
Mar 18 22:17:35 localhost avahi-daemon[8585]: avahi-daemon 0.6.31 starting up.
Mar 18 22:17:35 localhost avahi-daemon[8585]: Successfully called chroot().
Mar 18 22:17:35 localhost avahi-daemon[8585]: Successfully dropped remaining capabilities.
Mar 18 22:17:35 localhost avahi-daemon[8585]: Loading service file /services/sftp-ssh.service.
Mar 18 22:17:35 localhost avahi-daemon[8585]: Loading service file /services/ssh.service.
Mar 18 22:17:35 localhost avahi-daemon[8585]: Network interface enumeration completed.
Mar 18 22:17:35 localhost avahi-daemon[8585]: Registering HINFO record with values 'X86_64'/'LINUX'.
Mar 18 22:17:35 localhost avahi-daemon[8585]: Server startup complete. Host name is meshedgedx.local. Local service cookie is 3778762828.
Mar 18 22:17:35 localhost avahi-daemon[8585]: Service "meshedgedx" (/services/ssh.service) successfully established.
Mar 18 22:17:35 localhost avahi-daemon[8585]: Service "meshedgedx" (/services/sftp-ssh.service) successfully established.
Mar 18 22:17:35 localhost ntpd[8645]: ntpd 4.2.8@1.3265-o Wed  4 Mar 02:23:30 UTC 2015 (1): Starting
Mar 18 22:17:35 localhost ntpd[8645]: Command line: ntpd -g -q
Mar 18 22:17:35 localhost ntpd[8645]: proto: precision = 0.061 usec (-24)
Mar 18 22:17:35 localhost ntpd[8645]: Listen and drop on 0 v6wildcard [::]:123
Mar 18 22:17:35 localhost ntpd[8645]: Listen and drop on 1 v4wildcard 0.0.0.0:123
Mar 18 22:17:35 localhost ntpd[8645]: Listen normally on 2 lo 127.0.0.1:123
Mar 18 22:17:35 localhost ntpd[8645]: Listen normally on 3 lo [::1]:123
Mar 18 22:17:35 localhost ntpd[8645]: Listen normally on 4 eth0 [fe80::725a:b6ff:fe3e:c18a%2]:123
Mar 18 22:17:35 localhost ntpd[8645]: Listening on routing socket on fd #21 for interface updates
Mar 18 22:17:36 localhost kernel: fbcondecor: console 1 using theme 'Emergance'
Mar 18 22:17:37 localhost kernel: fbcondecor: switched decor state to 'on' on console 1
Mar 18 22:17:37 localhost kernel: fbcondecor: console 2 using theme 'Emergance'
Mar 18 22:17:37 localhost kernel: fbcondecor: switched decor state to 'on' on console 2
Mar 18 22:17:37 localhost kernel: fbcondecor: console 3 using theme 'Emergance'
Mar 18 22:17:37 localhost kernel: fbcondecor: switched decor state to 'on' on console 3
Mar 18 22:17:37 localhost kernel: fbcondecor: console 4 using theme 'Emergance'
Mar 18 22:17:37 localhost kernel: fbcondecor: switched decor state to 'on' on console 4
Mar 18 22:17:37 localhost kernel: fbcondecor: console 5 using theme 'Emergance'
Mar 18 22:17:37 localhost kernel: fbcondecor: switched decor state to 'on' on console 5
Mar 18 22:17:36 localhost bluetoothd[8787]: Bluetooth daemon 5.28
Mar 18 22:17:36 localhost bluetoothd[8787]: Starting SDP server
Mar 18 22:17:37 localhost kernel: Bluetooth: Core ver 2.19
Mar 18 22:17:37 localhost kernel: NET: Registered protocol family 31
Mar 18 22:17:37 localhost kernel: Bluetooth: HCI device and connection manager initialized
Mar 18 22:17:37 localhost kernel: Bluetooth: HCI socket layer initialized
Mar 18 22:17:37 localhost kernel: Bluetooth: L2CAP socket layer initialized
Mar 18 22:17:37 localhost kernel: Bluetooth: SCO socket layer initialized
Mar 18 22:17:38 localhost kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3
Mar 18 22:17:38 localhost kernel: Bluetooth: BNEP filters: protocol multicast
Mar 18 22:17:38 localhost kernel: Bluetooth: BNEP socket layer initialized
Mar 18 22:17:36 localhost bluetoothd[8787]: Bluetooth management interface 1.7 initialized
Mar 18 22:17:36 localhost NetworkManager[8346]: <info>  use BlueZ version 5
Mar 18 22:17:37 localhost ModemManager[8385]: <warn>  Couldn't find support for device at '/sys/devices/pci0000:00/0000:00:1c.1/0000:03:00.0': not supported by any plugin
Mar 18 22:17:37 localhost ModemManager[8385]: <warn>  Couldn't find support for device at '/sys/devices/pci0000:00/0000:00:1c.2/0000:04:00.0': not supported by any plugin
Mar 18 22:17:39 localhost dbus[7763]: [system] Activating service name='org.freedesktop.ColorManager' (using servicehelper)
Mar 18 22:17:39 localhost dbus[7763]: [system] Successfully activated service 'org.freedesktop.ColorManager'
Mar 18 22:17:41 localhost kernel: nf_conntrack: automatic helper assignment is deprecated and it will be removed soon. Use the iptables CT target to attach helpers instead.
Mar 18 22:17:43 localhost kernel: [UFW BLOCK] IN=eth0 OUT= MAC= SRC=fe80:0000:0000:0000:725a:b6ff:fe3e:c18a DST=ff02:0000:0000:0000:0000:0000:0000:0001 LEN=64 TC=0 HOPLIMIT=1 FLOWLBL=0 PROTO=UDP SPT=8612 DPT=8612 LEN=24 
Mar 18 22:17:43 localhost kernel: [UFW BLOCK] IN=eth0 OUT= MAC= SRC=fe80:0000:0000:0000:725a:b6ff:fe3e:c18a DST=ff02:0000:0000:0000:0000:0000:0000:0001 LEN=64 TC=0 HOPLIMIT=1 FLOWLBL=0 PROTO=UDP SPT=8612 DPT=8612 LEN=24 
Mar 18 22:17:43 localhost laptop-mode[8947]: Laptop mode 
Mar 18 22:17:43 localhost laptop-mode[8948]: enabled, not active
Mar 18 22:17:58 localhost kernel: Installing knfsd (copyright (C) 1996 okir@monad.swb.de).
Mar 18 22:17:58 localhost rpc.mountd[9741]: Version 1.3.2 starting
Mar 18 22:17:59 localhost kernel: NFSD: Using /var/lib/nfs/v4recovery as the NFSv4 state recovery directory
Mar 18 22:17:59 localhost kernel: NFSD: starting 90-second grace period (net ffffffff81c3d580)
Mar 18 22:17:58 localhost sm-notify[9760]: Version 1.3.2 starting
Mar 18 22:17:58 localhost sm-notify[9760]: Already notifying clients; Exiting!
Mar 18 22:18:00 localhost sshd[9816]: Server listening on 0.0.0.0 port 22.
Mar 18 22:18:00 localhost sshd[9816]: Server listening on :: port 22.
Mar 18 22:18:00 localhost cron[9870]: (CRON) STARTUP (V5.0)
Mar 18 22:18:00 localhost su[9899]: Successful su for fitzcarraldo by root
Mar 18 22:18:00 localhost su[9899]: + /dev/console root:fitzcarraldo
Mar 18 22:18:00 localhost su[9899]: pam_unix(su:session): session opened for user fitzcarraldo by (uid=0)
Mar 18 22:18:01 localhost dbus[7763]: [system] Activating service name='org.freedesktop.RealtimeKit1' (using servicehelper)
Mar 18 22:18:01 localhost dbus[7763]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1'
Mar 18 22:18:01 localhost rtkit-daemon[9906]: Successfully called chroot.
Mar 18 22:18:01 localhost rtkit-daemon[9906]: Successfully dropped privileges.
Mar 18 22:18:01 localhost rtkit-daemon[9906]: Successfully limited resources.
Mar 18 22:18:01 localhost rtkit-daemon[9906]: Running.
Mar 18 22:18:01 localhost rtkit-daemon[9906]: Watchdog thread running.
Mar 18 22:18:01 localhost rtkit-daemon[9906]: Canary thread running.
Mar 18 22:18:01 localhost kdm[8833]: :0[8833]: pam_unix(kde:session): session opened for user fitzcarraldo by (uid=0)
Mar 18 22:18:01 localhost kdm[8833]: :0[8833]: pam_ck_connector(kde:session): nox11 mode, ignoring PAM_TTY :0
Mar 18 22:18:03 localhost pulseaudio[9904]: [pulseaudio] sink.c: Default and alternate sample rates are the same.
Mar 18 22:18:03 localhost rtkit-daemon[9906]: Supervising 0 threads of 0 processes of 1 users.
Mar 18 22:18:03 localhost rtkit-daemon[9906]: Supervising 0 threads of 0 processes of 1 users.
Mar 18 22:18:03 localhost rtkit-daemon[9906]: Supervising 0 threads of 0 processes of 1 users.
Mar 18 22:18:03 localhost rtkit-daemon[9906]: Supervising 0 threads of 0 processes of 1 users.
Mar 18 22:18:03 localhost rtkit-daemon[9906]: Supervising 0 threads of 0 processes of 1 users.
Mar 18 22:18:03 localhost pulseaudio[9904]: [pulseaudio] source.c: Default and alternate sample rates are the same.
Mar 18 22:18:03 localhost rtkit-daemon[9906]: Supervising 0 threads of 0 processes of 1 users.
Mar 18 22:18:03 localhost rtkit-daemon[9906]: Supervising 0 threads of 0 processes of 1 users.
Mar 18 22:18:03 localhost rtkit-daemon[9906]: Supervising 0 threads of 0 processes of 1 users.
Mar 18 22:18:03 localhost rtkit-daemon[9906]: Supervising 0 threads of 0 processes of 1 users.
Mar 18 22:18:03 localhost rtkit-daemon[9906]: Supervising 0 threads of 0 processes of 1 users.
Mar 18 22:18:03 localhost pulseaudio[9904]: [pulseaudio] module-jackdbus-detect.c: Unable to contact D-Bus session bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11
Mar 18 22:18:03 localhost pulseaudio[9904]: [pulseaudio] module.c: Failed to load module "module-jackdbus-detect" (argument: "channels=2"): initialization failed.
Mar 18 22:18:04 localhost pulseaudio[9904]: [pulseaudio] main.c: Module load failed.
Mar 18 22:18:04 localhost pulseaudio[9904]: [pulseaudio] server-lookup.c: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11
Mar 18 22:18:04 localhost pulseaudio[9904]: [pulseaudio] main.c: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11
Mar 18 22:18:04 localhost su[9899]: pam_unix(su:session): session closed for user fitzcarraldo
Mar 18 22:18:04 localhost su[9964]: Successful su for fitzcarraldo by root
Mar 18 22:18:04 localhost su[9964]: + /dev/console root:fitzcarraldo
Mar 18 22:18:04 localhost su[9964]: pam_unix(su:session): session opened for user fitzcarraldo by (uid=0)
Mar 18 22:18:04 localhost su[9964]: pam_unix(su:session): session closed for user fitzcarraldo
Mar 18 22:18:04 localhost su[9966]: Successful su for fitzcarraldo by root
Mar 18 22:18:04 localhost su[9966]: + /dev/console root:fitzcarraldo
Mar 18 22:18:04 localhost su[9966]: pam_unix(su:session): session opened for user fitzcarraldo by (uid=0)
Mar 18 22:18:04 localhost su[9966]: pam_unix(su:session): session closed for user fitzcarraldo
Mar 18 22:18:04 localhost su[9968]: Successful su for fitzcarraldo by root
Mar 18 22:18:04 localhost su[9968]: + /dev/console root:fitzcarraldo
Mar 18 22:18:04 localhost su[9968]: pam_unix(su:session): session opened for user fitzcarraldo by (uid=0)
Mar 18 22:18:04 localhost su[9968]: pam_unix(su:session): session closed for user fitzcarraldo
Mar 18 22:18:15 localhost dbus[7763]: [system] Activating service name='org.freedesktop.UPower' (using servicehelper)
Mar 18 22:18:15 localhost dbus[7763]: [system] Successfully activated service 'org.freedesktop.UPower'
Mar 18 22:18:17 localhost dbus[7763]: [system] Activating service name='org.freedesktop.UDisks2' (using servicehelper)
Mar 18 22:18:17 localhost udisksd[10120]: udisks daemon version 2.1.4 starting
Mar 18 22:18:17 localhost dbus[7763]: [system] Successfully activated service 'org.freedesktop.UDisks2'
Mar 18 22:18:17 localhost udisksd[10120]: Acquired the name org.freedesktop.UDisks2 on the system message bus
Mar 18 22:18:19 localhost kernel: [UFW BLOCK] IN=eth0 OUT= MAC=01:00:5e:00:00:01:00:16:fa:25:28:01:08:00 SRC=0.0.0.0 DST=224.0.0.1 LEN=36 TOS=0x00 PREC=0xC0 TTL=1 ID=0 PROTO=2 
Mar 18 22:18:54 localhost hp-systray[10453]: hp-systray[10453]: error: option -s not recognized
Mar 18 22:18:55 localhost rtkit-daemon[9906]: Successfully made thread 10469 of process 10469 (/usr/bin/pulseaudio) owned by '1000' high priority at nice level -11.
Mar 18 22:18:55 localhost rtkit-daemon[9906]: Supervising 1 threads of 1 processes of 1 users.
Mar 18 22:18:55 localhost pulseaudio[10469]: [pulseaudio] pid.c: Daemon already running.
Mar 18 22:18:56 localhost rtkit-daemon[9906]: Successfully made thread 10485 of process 10485 (/usr/bin/pulseaudio) owned by '1000' high priority at nice level -11.
Mar 18 22:18:56 localhost rtkit-daemon[9906]: Supervising 1 threads of 1 processes of 1 users.
Mar 18 22:18:56 localhost pulseaudio[10485]: [pulseaudio] pid.c: Daemon already running.
Mar 18 22:19:04 localhost polkitd[7911]: Registered Authentication Agent for unix-session:/org/freedesktop/ConsoleKit/Session1 (system bus name :1.52 [/usr/lib64/kde4/libexec/polkit-kde-authentication-agent-1], object path /org/kde/PolicyKit1/AuthenticationAgent, locale en_GB.UTF-8)
Mar 18 22:19:10 localhost su[10569]: Successful su for root by fitzcarraldo
Mar 18 22:19:10 localhost su[10569]: + /dev/pts/0 fitzcarraldo:root
Mar 18 22:19:10 localhost su[10569]: pam_unix(su:session): session opened for user root by fitzcarraldo(uid=1000)
Mar 18 22:19:26 localhost pulseaudio[9904]: [alsa-sink-ALC272 Analog] alsa-sink.c: ALSA woke us up to write new data to the device, but there was actually nothing to write!
Mar 18 22:19:26 localhost pulseaudio[9904]: [alsa-sink-ALC272 Analog] alsa-sink.c: Most likely this is a bug in the ALSA driver 'snd_hda_intel'. Please report this issue to the ALSA developers.
Mar 18 22:19:26 localhost pulseaudio[9904]: [alsa-sink-ALC272 Analog] alsa-sink.c: We were woken up with POLLOUT set -- however a subsequent snd_pcm_avail() returned 0 or another value < min_avail.
Mar 18 22:20:01 localhost cron[10670]: (root) CMD (test -x /usr/sbin/run-crons && /usr/sbin/run-crons)

In the cases when NetworkManager activates a connection correctly and there is no invalid second eth0 connection, the log contains a message like the following:

Mar 16 22:23:47 localhost NetworkManager[6688]: <info>  Auto-activating connection 'eth0'.

Notice there is no such message in the message log above.

The only way I can be sure of preventing NetworkManager creating an invalid second eth0 connection is to disable IPv6 system-wide by uncommenting the line ‘alias net-pf-10 off‘ in the file /etc/modprobe.d/aliases.conf.

So, to me, this looks like a bug in NetworkManager 1.0.0 (I have been experiencing it since Version 0.9.10.0).

More on NetworkManager creating a new connection ‘eth0′ that does not work

In a previous post I described a problem I have been experiencing with NetworkManager since Version 0.9.10.0 (I am now using Version 1.0.0): sometimes, but not always, there is an invalid second eth0 connection when my laptop boots. This invalid second eth0 connection has only IPv6 Link-Local enabled (i.e. IPv4 and IPv6 are disabled) and is Active. As a result the existing eth0 connection for IPv4 I previously created is Available but unable to connect.

While on a work trip and using my laptop on an office network and an hotel network I made some changes to my installation (see the above-mentioned previous post) that seemed to fix this problem on those networks. However, on returning home and connecting my laptop to my home network, I found the problem still exists. This makes me wonder if a race condition is occurring, as network latency can differ between networks. Could it be that my home network takes longer to assign an IPv4 address than the office and hotel networks I used, which results in NetworkManager creating a second eth0 connection with IPv4 and IPv6 disabled? Or perhaps there is a race condition between services but network latency has nothing to do with it. In retrospect, I should have checked the contents of the log file /var/log/messages while on my work trip to see if those networks were providing my laptop with an IPv6 address in addition to an IPv4 address, i.e. check if the IPv6 address was not just a Link-Local address.

But why is NetworkManager creating any additional connection at all when NetworkManager.conf in my installation currently contains ‘no-auto-default=eth0‘? Surely this must be a bug in NetworkManager?

I have found virtually no mention of this behaviour on the Web. Debian bug report no. 755202 appears to describe the same problem. I started experiencing the problem in Gentoo Linux (~amd64 installation using OpenRC) after I upgraded NetworkManager to Version 0.9.10.0 too, and it has continued occurring up to the current version of NetworkManager (1.0.0). Fellow Gentoo Linux user Keivan Moradi’s fix (Message #79 in the aforementioned Debian bug report) did not cure the problem for me, and, anyway, my wired NIC uses a different driver (atl1c module) which appears to be stable in my installation.

CentOS bug report no. 0007435 also appears to report the same behaviour, but I’m not sure.

NetworkManager usually (but not always) creates an invalid second eth0 connection when my laptop boots and an Ethernet cable is connected to my home network. The second eth0 connection is shown as Active in plasma-nm (the KDE front-end for NetworkManager) but only has an IPv6 Link-Local connection configured (i.e. IPv4 is shown as Disabled). If I click on Disconnect in plasma-nm then this ‘rogue’ eth0 connection disappears from plasma-nm. Once the invalid IPv6 Link-Local connection has been disconnected, the valid IPv4 eth0 available connection can connect to the network and access the Internet.

I examined /var/log/messages when the invalid second eth0 connection occurs and when it doesn’t, and the invalid eth0 connection only seems to occur when NetworkManager appears to have first started earlier than syslog-ng began logging. When NetworkManager first starts after syslog-ng began logging, I can see it launches dhcpcd and acquires an IPv4 address. avahi-daemon does not seem to be the cause of the problem if I understand the log file correctly. Anyway, my experiments described below seem to exonerate the Avahi daemon. I could be misinterpreting what is going on, but that’s how it looks to my inexpert eyes. In Debian bug report no. 755202 some commenters refer to extra interfaces with names such as ‘eth0:avahi’ being listed by the ifconfig command when the problem occurs, but I wonder if that is just a side effect. Anyway, the ifconfig command does not list such interfaces in my case.

I tried the following experiments:

1. I commented out the entire contents of the file /etc/conf.d/net (the configuration file for initscripts /etc/init.d/net.*) — which I think is analogous to Debian’s /etc/network/interfaces file — but it did not stop the invalid second eth0 connection occurring.

2. I added ‘use-ipv6=no‘ and, later, ‘use-ipv4=no‘ in the file /etc/avahi/avahi-daemon.conf but they did not stop the invalid second eth0 connection occurring.

3. I added ‘deny-interfaces=eth0‘ in the file /etc/avahi/avahi-daemon.conf but it did not stop the invalid second eth0 connection occurring.

4. In my installation, the ‘local‘ service (launched by initscript /etc/init.d/local) has always been allocated to two runlevels: ‘default‘ and ‘nonetwork‘. I de-allocated the ‘local‘ service from the ‘nonetwork‘ runlevel but this did not stop the invalid second eth0 connection occurring.

5. In my installation, the ‘net.lo‘ service (launched by initscript /etc/init.d/net.lo) has always been allocated to the ‘boot‘ runlevel (the other net.* services, such as ‘net.eth0‘ and ‘net.wlan0‘, have never been allocated to a runlevel in my installation). I de-allocated ‘net.lo‘ from the ‘boot‘ runlevel but it did not stop the invalid eth0 connection occurring.

As experiments 4 and 5 did not stop the laptop accessing the Internet once I had deleted the invalid second eth0 connection, I have left the ‘local‘ service in the ‘default‘ runlevel only, and I have left the ‘net.lo‘ service unallocated to a runlevel.

6. Since the invalid eth0 connection is allocated an IPv6 Link-Local address rather than an IPv4 address on my home network, I tried a work-around: I disabled IPv6 system-wide by un-commenting the line ‘alias net-pf-10 off‘ in the file /etc/modprobe.d/aliases.conf. Now a second eth0 connection is no longer created, and the valid eth0 IPv4 connection I created previously connects automatically. I have not rebooted many times yet, so I don’t know if this work-around has eliminated the problem for good, but it looks promising.

Nevertheless I would like to find the root cause of the problem, rather than settling for a work-around of disabling IPv6 system-wide. Given that, when IPv6 is enabled, a second eth0 connection is sometimes not created and the ‘good’ IPv4 eth0 connection I created previously can connect, hopefully it should be possible somehow to have both IPv6 and IPv4 enabled system-wide without an invalid eth0 connection ever being created. Could NetworkManager be modified so that it does not create a connection if the DHCP client launched by NetworkManager does not obtain an IP address, for example?

This is not the end of the story, I’m sure.

For information, the services currently used are shown below:

meshedgedx fitzcarraldo # rc-status --all
Runlevel: nonetwork
Runlevel: shutdown
 killprocs                               [  stopped  ]
 savecache                               [  stopped  ]
 mount-ro                                [  stopped  ]
Runlevel: sysinit
 devfs                                   [  started  ]
 tmpfiles.dev                            [  started  ]
 sysfs                                   [  started  ]
 dmesg                                   [  started  ]
 udev                                    [  started  ]
Runlevel: boot
 hwclock                                 [  started  ]
 modules                                 [  started  ]
 device-mapper                           [  started  ]
 fsck                                    [  started  ]
 root                                    [  started  ]
 mtab                                    [  started  ]
 localmount                              [  started  ]
 sysctl                                  [  started  ]
 bootmisc                                [  started  ]
 termencoding                            [  started  ]
 keymaps                                 [  started  ]
 swapfiles                               [  started  ]
 ufw                                     [  started  ]
 procfs                                  [  started  ]
 dbus                                    [  started  ]
 tmpfiles.setup                          [  started  ]
 serial                                  [  started  ]
 hostname                                [  started  ]
 consolekit                              [  started  ]
 consolefont                             [  started  ]
 xdm                                     [  started  ]
 loopback                                [  started  ]
Runlevel: single
Runlevel: default
 swap                                    [  started  ]
 bluetooth                               [  started  ]
 syslog-ng                               [  started  ]
 sshd                                    [  started  ]
 fbcondecor                              [  started  ]
 atd                                     [  started  ]
 NetworkManager                          [  started  ]
 avahi-daemon                            [  started  ]
 cupsd                                   [  started  ]
 mdadm                                   [  started  ]
 acpid                                   [  started  ]
 nfsclient                               [  started  ]
 netmount                                [  started  ]
 alsasound                               [  started  ]
 laptop_mode                             [  started  ]
 cups-browsed                            [  started  ]
 hddtemp                                 [  started  ]
 mysql                                   [  started  ]
 nfs                                     [  started  ]
 samba                                   [  started  ]
 urandom                                 [  started  ]
 vixie-cron                              [  started  ]
 local                                   [  started  ]
Dynamic Runlevel: hotplugged
Dynamic Runlevel: needed
 rpcbind                                 [  started  ]
 rpc.statd                               [  started  ]
 rpc.pipefs                              [  started  ]
 rpc.idmapd                              [  started  ]
 xdm-setup                               [  started  ]
Dynamic Runlevel: manual
meshedgedx fitzcarraldo #

The allocations of services to runlevels are shown below:

meshedgedx fitzcarraldo # rc-update show -v
           NetworkManager |      default
 NetworkManagerDispatcher |
                    acpid |      default
                alsasound |      default
                  apache2 |
                      atd |      default
               atieventsd |
             avahi-daemon |      default
           avahi-dnsconfd |
                bluetooth |      default
                 bootmisc | boot
                   brltty |
             busybox-ntpd |
         busybox-watchdog |
                 cgconfig |
                    cgred |
                  cgroups |
                    clamd |
              consolefont | boot
               consolekit | boot
          courier-authlib |
                 cpupower |
             cups-browsed |      default
                    cupsd |      default
                     dbus | boot
                  deluged |
                    devfs |                                        sysinit
            device-mapper | boot
                      dgc |
                   dhcpcd |
                  dmcrypt |
                    dmesg |                                        sysinit
                 dmeventd |
                  dropbox |
                    eposd |
               fancontrol |
               fbcondecor |      default
                     fsck | boot
                     fuse |
               git-daemon |
                 gkrellmd |
                      gpm |
                     gpsd |
                  hddtemp |      default
                   hdparm |
          heimdal-kadmind |
              heimdal-kcm |
              heimdal-kdc |
         heimdal-kpasswdd |
                 hostname | boot
                   hsqldb |
                  hwclock | boot
                ip6tables |
                 iptables |
                   irexec |
                  keymaps | boot
                killprocs |                        shutdown
        kmod-static-nodes |
              laptop_mode |      default
                    lircd |
                   lircmd |
               lm_sensors |
                    local |      default
               localmount | boot
                 loopback | boot
                      lvm |
           lvm-monitoring |
                  lvmetad |
                    mdadm |      default
                   mdraid |
            microcode_ctl |
                  modules | boot
                 mount-ro |                        shutdown
                     mtab | boot
                multipath |
               multipathd |
                    mysql |      default
                      nas |
                  net.aol |
                 net.ath0 |
                 net.ath1 |
                 net.ath2 |
                 net.ath3 |
                 net.ath4 |
                 net.eth0 |
                 net.eth1 |
                 net.eth2 |
                 net.eth3 |
                 net.eth4 |
                 net.eth5 |
                 net.eth6 |
                 net.eth7 |
                 net.eth8 |
                   net.lo |
                 net.ppp0 |
                 net.ppp1 |
                 net.ppp2 |
                 net.ppp3 |
                  net.ra0 |
                  net.ra1 |
                  net.ra2 |
                  net.ra3 |
                  net.ra4 |
                  net.ra5 |
                net.wlan0 |
                net.wlan1 |
                net.wlan2 |
                net.wlan3 |
                 netmount |      default
                      nfs |      default
                nfsclient |      default
                 nfsmount |
               ntp-client |
  ntp-client.bak.20141013 |
                     ntpd |
                  numlock |
                  pciparm |
                  pktcdvd |
                   polipo |
                   procfs | boot
                  pwcheck |
                pydoc-2.7 |
                pydoc-3.2 |
                pydoc-3.3 |
                pydoc-3.4 |
              rename_ethX |
                   rfcomm |
                     root | boot
               rpc.idmapd |
               rpc.pipefs |
                rpc.statd |
                  rpcbind |
                rrdcached |
                   rsyncd |
                    samba |      default
                    saned |
                saslauthd |
                savecache |                        shutdown
                   serial | boot
                     slpd |
                   smartd |
                    snmpd |
                snmptrapd |
                     sntp |
                     sshd |      default
                 svnserve |
                     swap |      default
                swapfiles | boot
                  swclock |
                   sysctl | boot
                    sysfs |                                        sysinit
                syslog-ng |      default
    system-tools-backends |
             termencoding | boot
                 timidity |
             tmpfiles.dev |                                        sysinit
           tmpfiles.setup | boot
                      tor |
                   twistd |
                     udev |                                        sysinit
                      ufw | boot
                  urandom |      default
               vboxwebsrv |
               vixie-cron |      default
                     vpnc |
           wpa_supplicant |
                      xdm | boot
                xdm-setup |
                   xinetd |
meshedgedx fitzcarraldo #

My installation has the following six runlevels:

meshedgedx fitzcarraldo # ls /etc/runlevels
boot default nonetwork shutdown single sysinit

Installing and configuring the CUPS-PDF virtual printer driver

Some applications, such as LibreOffice, have built-in support for exporting their output to PDF files. For applications without built-in support for creating PDF files there may already be an installed ‘Print to File (PDF)’ driver in your installation that you can use. However, the Print to File (PDF) option does not appear in the list of available printers in all applications. Fortunately, CUPS has a driver named CUPS-PDF which you can install to create a virtual printer that will produce PDF files.

I install the package net-print/cups-pdf and use the CUPS Printer Manager in a browser to set up a virtual printer to ‘print’ PDF files. I use the driver in conjunction with a shell script that calls a utility to display a ‘Save As’ dialogue box so the user can specify the directory and name of the PDF file.

KDialog (KDE/Qt) and Zenity (GTK+) are two well-known dialogue box tools for use in shell scripts (see, for example, the Linux Magazine article Adding graphic elements to your scripts with Zenity and KDialog). However, although I use KDE on my main laptop, I was unable to get KDialog working properly in a shell script launched by the CUPS PDF driver, so I resorted to using Zenity, which I found simple to use and reliable. My shell script using Zenity is listed further down.

Although Zenity has performed this job perfectly for me in all releases of KDE since 2007, it rankled that I could not get KDialog to do the job. However, a couple of Gentoo users were able to use KDialog successfully with the CUPS PDF driver, each with a different approach to the other, but their approaches both consisted of two shell scripts. In contrast, a solution using Zenity uses only one shell script. You can see the KDialog solutions by the two users (Havin_it and sicvolo) in Gentoo Forums thread [TIP] CUPS-PDF “Save As” with kdialog. I was determined to have a single shell script using KDialog, and was able to conflate sicvolo‘s two-script solution. My thanks go to him for his clever code in his two shell scripts, as I would never have worked it out myself. My single shell script using KDialog is listed further down.

First I will explain how to install the CUPS PDF driver package, then how to use the CUPS Printer Manager to install the virtual printer, and finally how to use a shell script with either Zenity or KDialog in order to display a graphical dialogue box prompting you to specify the directory and file name for the PDF file to be created. I use Gentoo Linux, but the procedure will be similar in other distributions (package manager commands excepted).

1.0  Installation of the cups-pdf driver and virtual printer

1.1  Install the cups-pdf package:

# emerge cups-pdf

1.2  Launch a Web browser and enter http://localhost:631/ in the Address bar to display the CUPS Printer Manager.

1.3  Click on ‘Administration’ to call up the Administration page, then click ‘Add Printer’. If prompted, enter the username ‘root’ (without the quotes) and the root user’s password.

1.4  Select ‘CUPS-PDF (Virtual PDF Printer)’ in the list of local printers, and click ‘Continue’.

1.5  Enter a name, decription and location for the virtual printer. For example, I entered ‘Virtual_PDF_Printer’, ‘Virtual PDF Printer’ and ‘Mesh Edge DX’ (without the quotes), respectively. Then click ‘Continue’.

1.6  Select ‘Generic’ in the ‘Make:’ box, and click ‘Continue’.

1.7  Select ‘Generic CUPS-PDF Printer (w/ options) (en)’ in the ‘Model:’ box, and click ‘Add Printer’. The virtual printer should now be available for you to use.

1.8  When you come to print from an application, if you select Virtual_PDF_Printer from the list of available printers the PDF file will be saved in the directory /var/spool/cups-pdf/<your username>/. Note that the directory will be created automatically the first time you ‘print’ to PDF.

1.9  Optionally, you could create a shortcut (Desktop Config File) on your Desktop to open the directory mentioned in Step 1.8 above.

1.10 Optionally, instead of Step 1.9 you could edit the file /etc/cups/cups-pdf.conf as root user to get cups-pdf to ‘print’ PDF documents to your Desktop instead of in /var/spool/cups-pdf/<your username>/, by changing the line:

#Out /var/spool/cups-pdf/${USER}

to:

Out ${HOME}/Desktop


2.0  How to display a dialog box prompting for the directory and file name of the PDF file

If you prefer to be prompted for a file name so that you can save the PDF file wherever you want and give it any name you want, perform the steps below instead of Steps 1.9 or 1.10 above. Either perform the steps in 2.1 (Zenity) or the steps in 2.2 (KDialog). Then perform the steps in 2.3, which apply in both cases.

2.1   Zenity (GTK+)

2.1.1   Install Zenity:

# emerge zenity

2.1.2   Check it is installed:

# eix -I zenity
[I] gnome-extra/zenity
Available versions: 3.12.1 {debug libnotify test +webkit}
Installed versions: 3.12.1(13:49:47 04/12/14)(libnotify webkit -debug -test)
Homepage: https://wiki.gnome.org/Projects/Zenity
Description: Tool to display dialogs from the commandline and shell scripts

2.1.3   Using a text editor, create the following shell script in your home directory and give it a meaningful name, such as cups-pdf_script.sh:

#!/bin/bash
CURRENT_PDF="${1}"
CURRENT_USER="${2}"
DISPLAY=:0.0
export DISPLAY
XAUTHORITY=/home/${CURRENT_USER}/.Xauthority
export XAUTHORITY
PDFNAME=$(zenity --file-selection --save --confirm-overwrite)
mv "$CURRENT_PDF" "$PDFNAME"

2.2   KDialog (KDE/Qt)

2.2.1   Install KDialog:

# emerge kde-base/kdialog

2.2.2   Check it is installed:

# eix -I kde-base/kdialog
[I] kde-base/kdialog
Available versions: (4) 4.12.5(4/4.12) (~)4.14.2(4/4.14) (~)4.14.3(4/4.14)
{aqua debug}
Installed versions: 4.14.3(4)(00:56:36 04/12/14)(-aqua -debug)
Homepage: http://www.kde.org/
Description: KDialog can be used to show nice dialog boxes from shell scripts

2.2.3   Using a text editor, create the following shell script in your home directory and give it a meaningful name such as cups-pdf_script.sh:

#!/bin/bash

get_dbus()
{
if [ -z $1 ]; then
    echo "specify user" >> $HOME/cups-pdf_script.log
    return 1
fi
# Search these processes for the session variable (they are run as the current user and have the DBUS session variable set)
compatiblePrograms=( kdeinit kded4 pulseaudio trackerd )

# Attempt to get a program pid
for index in ${compatiblePrograms[@]}; do
   PID=$(ps -ef | grep $1 | grep ${index} | head -1 | awk '{print $2}')
   if [[ "${PID}" != "" ]]; then
      break
   fi
done
if [[ "${PID}" == "" ]]; then
   echo "Could not detect active login session" >> $HOME/cups-pdf_script.log
   return 1
fi
QUERY_ENVIRON="$(tr '\0' '\n' < /proc/${PID}/environ | grep "DBUS_SESSION_BUS_ADDRESS" | cut -d "=" -f 2-)"
if [[ "${QUERY_ENVIRON}" != "" ]]; then
#   echo ${QUERY_ENVIRON} >> $HOME/cups-pdf_script.log
   return 0
else
   echo "Could not find dbus session ID in user environment." >> $HOME/cups-pdf_script.log
   return 1
fi
}

CURRENT_PDF="$1"
CURRENT_USER="$2"

export DISPLAY=:0
export XAUTHORITY=/home/${CURRENT_USER}/.Xauthority
export HOME=/home/${CURRENT_USER}/
CONFIG_FILE="/home/${CURRENT_USER}/.pdf-writer.conf"
CANCELLED="No"

date > $HOME/cups-pdf_script.log

get_dbus ${CURRENT_USER}
if [ $? -eq 0 ]; then
   export DBUS_SESSION_BUS_ADDRESS=${QUERY_ENVIRON}
   while [ True ]; do
      CURDATE=$(/bin/date +%Y%m%d)
      CURNAME=$(/bin/cat "$CONFIG_FILE")
      BASENAME=$(basename $CURRENT_PDF)
      FILENAME=$(/usr/bin/kdialog --getsavefilename "$CURNAME$CURDATE-" "*.pdf" --title="Save PDF")
      if [ $? -eq 1 ]; then
         CANCELLED="Yes"
         break
      fi
      echo $FILENAME
      if [ ! "$FILENAME" = "" ]; then
         if [ -e "$FILENAME" ]; then
            /usr/bin/kdialog --warningcontinuecancel "File already exists"
            if [ $? -eq 1 ]; then
               continue;
            fi
         fi
         FILENAME=$(echo $FILENAME.pdf | sed -re "s/(\.pdf)+$/.pdf/g")
         break;
      else
         /usr/bin/kdialog --error "You must select a file or hit Cancel."
      fi
      break
   done
   if [ "${CANCELLED}" == "No" ]; then
      /bin/cp "${CURRENT_PDF}" "${FILENAME}"
      okular "${FILENAME}" &
   fi
   /bin/rm "${CURRENT_PDF}"
   echo "No errors encountered." >> $HOME/cups-pdf_script.log
   exit 0
else
   /bin/rm "${CURRENT_PDF}"
   echo "Errors encountered." >> $HOME/cups-pdf_script.log
   exit 1
fi

2.3   Whichever of the above two options (Zenity or KDialog) you chose, do the following:

2.3.1   Make the shell script file executable:

# chmod +x /home/<your username>/cups-pdf_script.sh

2.3.2   Edit the file /etc/cups/cups-pdf.conf, find the line starting with ‘#PostProcessing‘, and change it to:

PostProcessing /home/<your username>/cups-pdf_script.sh

2.3.3   Restart CUPS:

# /etc/init.d/cupsd restart # If your installation uses OpenRC.

# systemctl restart cups.service # If your installation uses systemd.

Now, when you select Virtual_PDF_Printer from your applications’ list of available printers and click ‘Print’, a pop-up window should appear, allowing you to select the target directory for the PDF file and enter a file name of your choice.

Fix for ALSA Speaker volume level resetting to zero at boot

Up until 2011 the problem of the volume level in ALSA resetting to zero at boot was a common occurrence in my Linux installations. Actually it was a common occurrence in Linux, full stop; search the Web using keywords such as “alsa reset volume” and you’ll find umpteen links. In 2012 the situation improved and I thought the problem had become a thing of the past, but it resurfaced in 2013 on my main laptop and has plagued me through every update since (well, apart from in one release of KDE). Every time I reboot, the ALSA Speaker channel’s volume is zero when I log-in to KDE. And, as KMix is a PulseAudio mixer by default these days, I have to launch ALSAMixer and raise the volume of the Speaker channel manually.

I don’t know if the source of the problem lies in KDE, PulseAudio or ALSA itself. It did disappear after one upgrade to KDE earlier this year (I don’t recall which release of KDE) but returned in the next KDE upgrade, so I suspect it is a KDE issue. In earlier days I could resolve the problem using the commands alsactrl store and alsactl restore and similar approaches. However, this time none of those fixes work for me. The problem never bothered me much, as I always connect external speakers to my laptop’s headphone socket when I’m at home, and I don’t want my laptop emitting sounds at the office. Nevertheless, the fact the problem exists niggled me, so I decided to try and fix it. Rather than expending any more effort trying to get the usual approaches to work (the Web is littered with suggested fixes over the years), I decided to reset the Speaker volume to the same level at each boot by using an automatically-launched shell script. The method I use is given below, and should work with either OpenRC or systemd in Gentoo Linux.

1. Create the file /etc/local.d/20set_alsa_volume.start containing the following:

#!/bin/bash
# Reset ALSA Speaker channel on the first sound card to 90% after booting.
su -c "amixer -c 0 -- sset Speaker playback 90%" -s /bin/sh fitzcarraldo

(Replace “fitzcarraldo” with your own user name, of course.)

2. Make the script executable:

# chmod +x 20set_alsa_volume.start

That’s all there is to it. The volume of the ALSA Speaker channel is always set to 90% after I reboot and login to the desktop environment. KMix remembers the PulseAudio volume setting from the previous session, so I can still avoid blasting the laptop’s speakers.

By the way, the manual pages for the amixer and alsamixer commands make useful reading:

$ man amixer
$ man alsamixer

For example, the first audio card (Card 0) in my main laptop has the following controls:

$ amixer -c 0 scontrols
Simple mixer control ‘Master’,0
Simple mixer control ‘Headphone’,0
Simple mixer control ‘Speaker’,0
Simple mixer control ‘PCM’,0
Simple mixer control ‘Mic’,0
Simple mixer control ‘Mic Boost’,0
Simple mixer control ‘Beep’,0
Simple mixer control ‘Capture’,0
Simple mixer control ‘Auto-Mute Mode’,0
Simple mixer control ‘Digital’,0
Simple mixer control ‘Internal Mic’,0
Simple mixer control ‘Internal Mic Boost’,0

Update (January 29, 2015): I found the cause of the problem: PulseAudio. I edited the file /usr/share/pulseaudio/alsa-mixer/paths/analog-output.conf as per user agmg‘s January 2013 post Re: [SOLVED] Problems with PulseAudio 3.0 in the PCLinuxOS Forums:

Again, I had to edit the file: /usr/share/pulseaudio/alsa-mixer/paths/analog-output.conf

and change this:

[Element Speaker]
switch = mute
volume = off

to this:

[Element Speaker]
switch = mute
volume = merge

I realized that editing the [Element Desktop Speaker] section of the above file, has no effect on the issue. Only the edit to [Element Speaker] is needed in my case.

In my case this change forces the ALSA Speaker channel volume to 100% after rebooting (irrespective of the volume levels I set via ALSAMixer and KMix before shutdown).

The contents of the file /usr/share/pulseaudio/alsa-mixer/paths/analog-output.conf also include the following comment:

; See analog-output.conf.common for an explanation on the directives

The contents of the file analog-output.conf.common include the following comment:

; volume = ignore | merge | off | zero | <volume step> # What to do with this volume: ignore it, merge it into the device
;                                                      # volume slider, always set it to the lowest value possible, or always
;                                                      # set it to 0 dB (for whatever that means), or always set it to
;                                                      # <volume step> (this only makes sense in path configurations where
;                                                      # the exact hardware and driver are known beforehand).

So I could have tried volume = <volume step> instead of volume = merge, although I have no idea what value <volume step> would need to be. Anyway, the Bash script /etc/local.d/20set_alsa_volume.start that I created does the job in a different way without me having to tinker with the troublesome PulseAudio, so I reverted to volume = off in the file analog-output.conf and reverted to using /etc/local.d/20set_alsa_volume.start as explained earlier.

Updating Intel CPU microcode from Gentoo Linux

Updates to CPU microcode have to be re-applied each time the computer is booted, because the memory updated is volatile (despite the term ‘firmware’ also being used for microcode). Below I describe two methods (there are others) of applying CPU microcode updates in Gentoo Linux. My main laptop has an Intel CPU so I focus here on Intel microcode updates. The procedure is almost the same for AMD CPUs, but the AMD CPU binary update file (‘binary blob’) is installed by the sys-kernel/linux-firmware package.

METHOD 1: Use an initscript in the boot runlevel with a kernel module

Until recently I was using an initscript named microcode_ctl, which uses a program (also named microcode_ctl) and a kernel module (microcode.ko) to update the Intel CPU microcode during boot. This was straightforward to set up in Gentoo Linux:

1. Build the kernel with CONFIG_MICROCODE=m and CONFIG_MICROCODE_INTEL=y.

This is what I configured in the kernel:

# grep -i microcode /usr/src/linux/.config
CONFIG_MICROCODE=m
CONFIG_MICROCODE_INTEL=y
# CONFIG_MICROCODE_AMD is not set
CONFIG_MICROCODE_OLD_INTERFACE=y
# CONFIG_MICROCODE_INTEL_EARLY is not set
# CONFIG_MICROCODE_AMD_EARLY is not set

2. Install two packages and add an OpenRC initscript to the boot runlevel:

# emerge microcode-data microcode-ctl
# rc-update add microcode_ctl boot

The initscript will re-update the CPU microcode every time the computer is rebooted.

Installing the package microcode-data downloads a compressed file (microcode-yyyymmdd.tgz) from the Intel Download Centre, extracts a text file named microcode.dat and parses the text in it to create a set of binary ‘blobs’ in the directory /lib/firmware/intel-ucode/ (one blob for each model of Intel CPU).

Before rebooting, check the revision of microcode in the CPU (the microcode revision is shown for each logical core):

# This is for the Core i7-720QM CPU in my Compal NBLB2 laptop.
# grep microcode /proc/cpuinfo
microcode : 0x3
microcode : 0x3
microcode : 0x3
microcode : 0x3
microcode : 0x3
microcode : 0x3
microcode : 0x3
microcode : 0x3

If I use this method of updating the microcode, the initscript runs after the message ‘Waiting for uevents to be processed ...‘ is displayed on VT1 while booting. After the module has performed the update, the microcode revision in the CPU’s logical cores has changed:

# grep microcode /proc/cpuinfo
microcode : 0x7
microcode : 0x7
microcode : 0x7
microcode : 0x7
microcode : 0x7
microcode : 0x7
microcode : 0x7
microcode : 0x7
# dmesg | grep microcode
[ 15.749533] microcode: CPU0 sig=0x106e5, pf=0x10, revision=0x3
[ 15.834790] microcode: CPU0 sig=0x106e5, pf=0x10, revision=0x3
[ 15.835530] microcode: CPU0 updated to revision 0x7, date = 2013-08-20
[ 15.835544] microcode: CPU1 sig=0x106e5, pf=0x10, revision=0x3
[ 15.835587] microcode: CPU1 sig=0x106e5, pf=0x10, revision=0x3
[ 15.836241] microcode: CPU1 updated to revision 0x7, date = 2013-08-20
[ 15.836257] microcode: CPU2 sig=0x106e5, pf=0x10, revision=0x3
[ 15.836299] microcode: CPU2 sig=0x106e5, pf=0x10, revision=0x3
[ 15.836953] microcode: CPU2 updated to revision 0x7, date = 2013-08-20
[ 15.837063] microcode: CPU3 sig=0x106e5, pf=0x10, revision=0x3
[ 15.837128] microcode: CPU3 sig=0x106e5, pf=0x10, revision=0x3
[ 15.837767] microcode: CPU3 updated to revision 0x7, date = 2013-08-20
[ 15.837857] microcode: CPU4 sig=0x106e5, pf=0x10, revision=0x3
[ 15.837968] microcode: CPU4 sig=0x106e5, pf=0x10, revision=0x3
[ 15.838605] microcode: CPU4 updated to revision 0x7, date = 2013-08-20
[ 15.838634] microcode: CPU5 sig=0x106e5, pf=0x10, revision=0x3
[ 15.838681] microcode: CPU5 sig=0x106e5, pf=0x10, revision=0x3
[ 15.839357] microcode: CPU5 updated to revision 0x7, date = 2013-08-20
[ 15.839390] microcode: CPU6 sig=0x106e5, pf=0x10, revision=0x3
[ 15.839453] microcode: CPU6 sig=0x106e5, pf=0x10, revision=0x3
[ 15.840121] microcode: CPU6 updated to revision 0x7, date = 2013-08-20
[ 15.840180] microcode: CPU7 sig=0x106e5, pf=0x10, revision=0x3
[ 15.840274] microcode: CPU7 sig=0x106e5, pf=0x10, revision=0x3
[ 15.840911] microcode: CPU7 updated to revision 0x7, date = 2013-08-20
[ 15.840997] microcode: Microcode Update Driver: v2.00 , Peter Oruba
[ 26.940662] microcode: Microcode Update Driver: v2.00 removed.

Notice that the microcode update occurred in the period from 15.749533 to 15.840997 seconds after the kernel started running, and the microcode was updated from revision 0x3 to 0x7.

METHOD 2: Use the kernel’s built-in Early Update driver

Although the initscript method works perfectly in my case and the update is complete by the time the laptop has finished booting, I wanted to update the CPU microcode earlier. Updating microcode early can fix CPU issues before they occur during kernel boot time. It is possible to configure the kernel to update microcode early by setting CONFIG_MICROCODE_EARLY and CONFIG_MICROCODE_INTEL_EARLY in the kernel. See /usr/src/linux/Documentation/x86/early-microcode.txt for details. That document only refers to initrd files, but, in fact, it also applies to initramfs files.

The Early Update kernel driver will align misaligned microcode data (see Notes on Intel Microcode Updates and [PATCH 7/8] x86, microcode, intel: guard against misaligned microcode data), but you can pre-align the data yourself if you wish by using a .padding file as explained on the latter page. However I did not bother doing that; I leave the Early Update kernel driver to take care of aligning the microcode, as the time penalty to align it is small compared to the overall update time.

It is possible to download the latest compressed Intel microcode data file yourself from the Intel Download Centre. The latest file released is microcode-20140913.tgz at the time of writing. It contains only a text file named microcode.dat, not the required binary blob. Actually, microcode.dat contains data in text format for several Intel CPU models. The microcode.dat file should reside in the directory /lib/firmware/. In the case of Gentoo it is a waste of time manually obtaining the microcode.dat file this way, as there is no tool in Gentoo specifically for creating a binary blob from the microcode.dat file. Therefore just install the Gentoo package sys-apps/microcode-data (which you would have done in any case if you were using the microcode_ctl initscript to load the microcode update to the CPU) and it will automatically download the compressed file from the Intel Web site, unpack it, copy the file microcode.dat to /lib/firmware/ and create the binary blobs in the directory /lib/firmware/intel-ucode/.

You may have read of a tool named intel-microcode2ucode used in other Linux distributions. Gentoo does not build intel-microcode2ucode (the source code of which is included in the Gentoo package sys-apps/microcode-data) as a stand-alone tool, but the act of installing microcode-data creates the required binary files in /lib/firmware/intel-ucode/. i.e. the following command does the complete job:

# emerge microcode-data

Check that the microcode files for the various CPU models were created when microcode-data was installed:

# ls /lib/firmware/intel-ucode/
06-03-02 06-05-03 06-06-0d 06-08-01 06-09-05 06-0b-04 06-0f-02 06-0f-0b 06-17-07 06-1c-02 06-1e-05 06-2a-07 06-3a-09 06-3e-07 0f-00-07 0f-02-05 0f-03-02 0f-04-03 0f-04-09 0f-06-05
06-05-00 06-06-00 06-07-01 06-08-03 06-0a-00 06-0d-06 06-0f-06 06-0f-0d 06-17-0a 06-1c-0a 06-25-02 06-2d-06 06-3c-03 06-3f-02 0f-00-0a 0f-02-06 0f-03-03 0f-04-04 0f-04-0a 0f-06-08
06-05-01 06-06-05 06-07-02 06-08-06 06-0a-01 06-0e-08 06-0f-07 06-16-01 06-1a-04 06-1d-01 06-25-05 06-2d-07 06-3e-04 06-45-01 0f-01-02 0f-02-07 0f-03-04 0f-04-07 0f-06-02
06-05-02 06-06-0a 06-07-03 06-08-0a 06-0b-01 06-0e-0c 06-0f-0a 06-17-06 06-1a-05 06-1e-04 06-26-01 06-2f-02 06-3e-06 06-46-01 0f-02-04 0f-02-09 0f-04-01 0f-04-08 0f-06-04

I looked in /proc/cpuinfo to confirm the model of CPU in my laptop:

$ grep model /proc/cpuinfo
model : 30
model name : Intel(R) Core(TM) i7 CPU Q 720 @ 1.60GHz
model : 30
model name : Intel(R) Core(TM) i7 CPU Q 720 @ 1.60GHz
model : 30
model name : Intel(R) Core(TM) i7 CPU Q 720 @ 1.60GHz
model : 30
model name : Intel(R) Core(TM) i7 CPU Q 720 @ 1.60GHz
model : 30
model name : Intel(R) Core(TM) i7 CPU Q 720 @ 1.60GHz
model : 30
model name : Intel(R) Core(TM) i7 CPU Q 720 @ 1.60GHz
model : 30
model name : Intel(R) Core(TM) i7 CPU Q 720 @ 1.60GHz
model : 30
model name : Intel(R) Core(TM) i7 CPU Q 720 @ 1.60GHz

I was able to find the CPUID and other data for that model from the Web site CPU World:

CPUID 106E5
Family 6 (06 hex)
Model 30 (1E hex)
Stepping 5 (05 hex)

Therefore the file /lib/firmware/intel-ucode/06-1e-05 (FamilyModelStepping in hexadecimal) is the binary blob for my specific CPU model.

First I used genkernel to rebuild the current kernel with CONFIG_MICROCODE_EARLY=y and CONFIG_MICROCODE_INTEL_EARLY=y.

# mount /dev/sda3 /boot # /boot is on a separate partition in my installation.

# Backup the files of the existing kernel image and initramfs:
# cp /boot/initramfs-genkernel-x86_64-3.17.1-gentoo-r1 /home/fitzcarraldo/initramfs-genkernel-x86_64-3.17.1-gentoo-r1.bak
# cp /boot/kernel-genkernel-x86_64-3.17.1-gentoo-r1 /home/fitzcarraldo/kernel-genkernel-x86_64-3.17.1-gentoo-r1.bak
# cp /boot/System.map-genkernel-x86_64-3.17.1-gentoo-r1 /home/fitzcarraldo/System.map-genkernel-x86_64-3.17.1-gentoo-r1.bak

# Now rebuild the kernel:
# zcat /proc/config.gz > /usr/src/config
# genkernel --kernel-config=/usr/src/config --menuconfig --splash=Emergance --disklabel all # Set CONFIG_MICROCODE_EARLY and CONFIG_MICROCODE_INTEL_EARLY.
# emerge @module-rebuild
# grub2-mkconfig -o /boot/grub/grub.cfg

This is what I have after rebuilding the kernel:

# grep -i microcode /usr/src/linux/.config
CONFIG_MICROCODE=y
CONFIG_MICROCODE_INTEL=y
# CONFIG_MICROCODE_AMD is not set
CONFIG_MICROCODE_OLD_INTERFACE=y
CONFIG_MICROCODE_INTEL_EARLY=y
# CONFIG_MICROCODE_AMD_EARLY is not set
CONFIG_MICROCODE_EARLY=y

Then I prepended the cpio file containing the binary blob to the initramfs file (see the instructions in /usr/src/linux/Documentation/x86/early-microcode.txt):

# mkdir -p /boot/initrd/kernel/x86/microcode
# cd /boot/initrd
# cp /lib/firmware/intel-ucode/06-1e-05 kernel/x86/microcode/GenuineIntel.bin
# find . | cpio -o -H newc >../ucode.cpio
# cd ..
# cp /boot/initramfs-genkernel-x86_64-3.17.1-gentoo-r1 /home/fitzcarraldo/initramfs-genkernel-x86_64-3.17.1-gentoo-r1.bak.early # Backup the recently-built initramfs first.
# cat ucode.cpio /boot/initramfs-genkernel-x86_64-3.17.1-gentoo-r1 >/boot/initramfs-genkernel-x86_64-3.17.1-gentoo-r1.ucode
# cp /boot/initramfs-genkernel-x86_64-3.17.1-gentoo-r1.ucode /boot/initramfs-genkernel-x86_64-3.17.1-gentoo-r1
# rm /boot/initramfs-genkernel-x86_64-3.17.1-gentoo-r1.ucode
# umount /boot
# rc-update del microcode_ctl boot # Disable the initscript so that microcode.ko will no longer be used when I reboot.

Reboot.

Use the following commands to check if the CPU microcode has been updated:

# grep microcode /proc/cpuinfo
# dmesg | grep microcode

There is no point looking in /var/log/messages, because syslog-ng has not started running when the early microcode update occurs.

# grep microcode /proc/cpuinfo
microcode : 0x7
microcode : 0x7
microcode : 0x7
microcode : 0x7
microcode : 0x7
microcode : 0x7
microcode : 0x7
microcode : 0x7
# dmesg | grep microcode
[ 0.252234] CPU1 microcode updated early to revision 0x7, date = 2013-08-20
[ 0.265389] CPU2 microcode updated early to revision 0x7, date = 2013-08-20
[ 0.278696] CPU3 microcode updated early to revision 0x7, date = 2013-08-20
[ 1.888471] microcode: CPU0 sig=0x106e5, pf=0x10, revision=0x7
[ 1.888481] microcode: CPU1 sig=0x106e5, pf=0x10, revision=0x7
[ 1.888491] microcode: CPU2 sig=0x106e5, pf=0x10, revision=0x7
[ 1.888498] microcode: CPU3 sig=0x106e5, pf=0x10, revision=0x7
[ 1.888506] microcode: CPU4 sig=0x106e5, pf=0x10, revision=0x7
[ 1.888515] microcode: CPU5 sig=0x106e5, pf=0x10, revision=0x7
[ 1.888523] microcode: CPU6 sig=0x106e5, pf=0x10, revision=0x7
[ 1.888534] microcode: CPU7 sig=0x106e5, pf=0x10, revision=0x7
[ 1.888597] microcode: Microcode Update Driver: v2.00 , Peter Oruba

Compare the update time in the dmesg output above with the update time in the dmesg output for an update done using the initscript (Method 1, further up). With the Early Update driver, the update was complete in 0.278696 seconds. With the initscript and kernel module, the update was complete in 15.840911 seconds. Quite a difference.

I do not know why the dmesg output does not have a message for Core 0 in the group of messages before 1.000000 second elapsed. The message at 1.888471 shows it was updated, so I assume the kernel ring buffer was not large enough and the message was overwritten. Cores 1, 2 and 3 were updated in the period between 0.252234 and 0.278696 seconds, and then all eight logical cores are listed in the period between 1.888471 and 1.888597 seconds. I’m not sure of the precise messages expected, but they look similar to the results obtained by users in other distributions, such as the following CrunchBang Linux output:

$ uname -a
Linux crunchbang 3.10-12.dmz.1-liquorix-amd64 #1 ZEN SMP PREEMPT Sun Sep 15 17:29:51 UTC 2013 x86_64 GNU/Linux
$ dmesg | grep microcode
CPU0 microcode updated early to revision 0x19, date = 2013-06-13
CPU1 microcode updated early to revision 0x19, date = 2013-06-13
CPU2 microcode updated early to revision 0x19, date = 2013-06-13
CPU3 microcode updated early to revision 0x19, date = 2013-06-13
microcode: CPU0 sig=0x306a9, pf=0x10, revision=0x19
microcode: CPU1 sig=0x306a9, pf=0x10, revision=0x19
microcode: CPU2 sig=0x306a9, pf=0x10, revision=0x19
microcode: CPU3 sig=0x306a9, pf=0x10, revision=0x19
microcode: CPU4 sig=0x306a9, pf=0x10, revision=0x19
microcode: CPU5 sig=0x306a9, pf=0x10, revision=0x19
microcode: CPU6 sig=0x306a9, pf=0x10, revision=0x19
microcode: CPU7 sig=0x306a9, pf=0x10, revision=0x19
microcode: Microcode Update Driver: v2.00 , Peter Oruba
$ cat /proc/cpuinfo | grep microcode | uniq
microcode : 0x19

Finally, I deleted the temporary work directory and files:

# mount /dev/sda3 /boot
# rm -rf /boot/initrd/
# rm /boot/ucode.cpio
# rm /home/fitzcarraldo/kernel-genkernel-x86_64-3.17.1-gentoo-r1.bak
# rm /home/fitzcarraldo/initramfs-genkernel-x86_64-3.17.1-gentoo-r1.bak
# rm /home/fitzcarraldo/System.map-genkernel-x86_64-3.17.1-gentoo-r1.bak

# Optional. Could keep the following file in case Intel issues a new microcode.dat file and I want to create a new concatenated initramfs file:
# rm /home/fitzcarraldo/initramfs-genkernel-x86_64-3.17.1-gentoo-r1.bak.early

Of course, you will need to repeat the whole process and create a new concatenated initramfs file in any of the following cases:

a) you build a new version of the kernel;

b) you rebuild the current version of the kernel with different configuration settings;

c) Intel releases a new version of the microcode (which does not happen often).

It seems the Early Update driver still has some bugs, so I expect the message output to change in future kernel releases. See e.g. [PATCH 0/8] x86, microcode, intel: fixes and enhancements, [PATCH 3/8] x86, microcode, intel: clarify log messages, Re: [PATCH 3/8] x86, microcode, intel: clarify log messages and a bunch of other very recent posts in the kernel mailing list regarding the Early Update driver and CPU microcode updates.

UPDATE (September 1, 2015): Since I wrote the above post, the use of a kernel module and initscript to update CPU microcode has been dropped (in Gentoo Linux, at least). This is because updating CPU microcode relatively late in the boot process may cause problems if some processes have started before the update has taken place. The only safe way to update CPU microcode is to use the kernel’s built-in Microcode Early Update driver (METHOD 2 above). New versions of the relevant Gentoo Linux ebuilds (microcode-ctl-1.28-r1, microcode-data-20150121-r1 and iucode_tool-1.3) have recently been released (see Gentoo Bug Report No. 528712). If a Gentoo Linux installation does not use an initramfs, the microcode-data ebuild now includes an ‘initramfs‘ USE flag which you can set in order to create a minimal initramfs to load the CPU microcode at boot (see my latest post for details).