Package: wpasupplicant
Version: 2.3-1+deb8u4
Severity: important
Tags: patch

Hi.

When verbose output is enabled:

    # grep VERBOSE /etc/default/networking
    VERBOSE=yes

`networking.service` fails to bring up wlan network interface, which uses
`wpa_action` (but `wpa_action` is not essential here):


    # cat /etc/network/interfaces

    # The loopback network interface
    auto lo
    iface lo inet loopback

    auto wlan0
    iface wlan0 inet manual
            wpa-roam /etc/wpa_supplicant.conf

    iface sgf.un inet static
            address 192.168.2.7
            netmask 255.255.255.0
            network 192.168.2.0
            broadcast 192.168.2.255
            gateway 192.168.2.9


Let's start with:

    # ip link show wlan0
    3: wlan0: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc mq state DOWN 
mode DEFAULT group default qlen 1000
        link/ether e8:de:27:e8:47:b1 brd ff:ff:ff:ff:ff:ff

    # ps -f -C wpa_supplicant
    UID        PID  PPID  C STIME TTY          TIME CMD

    # systemctl status networking.service
    ● networking.service - LSB: Raise network interfaces.
       Loaded: loaded (/etc/init.d/networking)
      Drop-In: /run/systemd/generator/networking.service.d
               └─50-insserv.conf-$network.conf
            /lib/systemd/system/networking.service.d
               └─network-pre.conf
       Active: inactive (dead) since Sun 2016-09-18 22:03:38 MSK; 44s ago
      Process: 29629 ExecStop=/etc/init.d/networking stop (code=exited, 
status=0/SUCCESS)
      Process: 26386 ExecStart=/etc/init.d/networking start (code=exited, 
status=0/SUCCESS)

    Sep 18 22:03:38 reiji.sgf.un wpa_supplicant[26407]: wlan0: 
CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
    Sep 18 22:03:38 reiji.sgf.un systemd[1]: Stopped LSB: Raise network 
interfaces..
    Sep 18 22:03:38 reiji.sgf.un networking[29629]: wpa_supplicant: terminating 
wpa_supplicant daemon vi...pid
    Sep 18 22:03:38 reiji.sgf.un networking[29629]: Stopped 
/sbin/wpa_supplicant (pid 26407).
    Sep 18 22:03:38 reiji.sgf.un networking[29629]: run-parts --verbose 
/etc/network/if-post-down.d
    Sep 18 22:03:38 reiji.sgf.un networking[29629]: run-parts: executing 
/etc/network/if-post-down.d/ava...mon
    Sep 18 22:03:38 reiji.sgf.un networking[29629]: run-parts: executing 
/etc/network/if-post-down.d/wir...ols
    Sep 18 22:03:38 reiji.sgf.un networking[29629]: run-parts: executing 
/etc/network/if-post-down.d/wpa...ant
    Sep 18 22:03:38 reiji.sgf.un networking[29629]: done.
    Sep 18 22:03:38 reiji.sgf.un wpa_supplicant[26407]: wlan0: 
CTRL-EVENT-TERMINATING
    Hint: Some lines were ellipsized, use -l to show in full.

Then

    # systemctl start networking.service

    # journalctl -f _SYSTEMD_UNIT=networking.service
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: Configuring network 
interfaces...run-parts --exit-on-error --verbose /etc/network/if-pre-up.d
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: run-parts: executing 
/etc/network/if-pre-up.d/wireless-tools
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: run-parts: executing 
/etc/network/if-pre-up.d/wpasupplicant
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: Configuring interface 
wlan0=wlan0 (inet)
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: run-parts --exit-on-error 
--verbose /etc/network/if-pre-up.d
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: run-parts: executing 
/etc/network/if-pre-up.d/wireless-tools
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: run-parts: executing 
/etc/network/if-pre-up.d/wpasupplicant
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: 
/etc/network/if-pre-up.d/wpasupplicant: 112: 
/etc/network/if-pre-up.d/wpasupplicant: cannot create /dev/stdout: No such 
device or address
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: 
/etc/network/if-pre-up.d/wpasupplicant: 112: 
/etc/network/if-pre-up.d/wpasupplicant: cannot create /dev/stdout: No such 
device or address
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: 
/etc/network/if-pre-up.d/wpasupplicant: 112: 
/etc/network/if-pre-up.d/wpasupplicant: cannot create /dev/stdout: No such 
device or address
    Sep 18 22:05:27 reiji.sgf.un wpa_supplicant[30182]: Successfully 
initialized wpa_supplicant
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: 
/etc/network/if-pre-up.d/wpasupplicant: 112: 
/etc/network/if-pre-up.d/wpasupplicant: cannot create /dev/stdout: No such 
device or address
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: 
/etc/network/if-pre-up.d/wpasupplicant: 112: 
/etc/network/if-pre-up.d/wpasupplicant: cannot create /dev/stdout: No such 
device or address
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: run-parts: 
/etc/network/if-pre-up.d/wpasupplicant exited with return code 1
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: run-parts --exit-on-error 
--verbose /etc/network/if-up.d
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: Failed to bring up wlan0.
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: run-parts: executing 
/etc/network/if-up.d/000resolvconf
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: run-parts: executing 
/etc/network/if-up.d/avahi-daemon
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: run-parts: executing 
/etc/network/if-up.d/bind9
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: run-parts: executing 
/etc/network/if-up.d/mountnfs
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: run-parts: executing 
/etc/network/if-up.d/ntpdate
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: run-parts: executing 
/etc/network/if-up.d/openssh-server
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: run-parts: executing 
/etc/network/if-up.d/upstart
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: run-parts: executing 
/etc/network/if-up.d/wpasupplicant
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: done.

Note the errors:

    Sep 18 22:05:27 reiji.sgf.un networking[30162]: 
/etc/network/if-pre-up.d/wpasupplicant: 112: 
/etc/network/if-pre-up.d/wpasupplicant: cannot create /dev/stdout: No such 
device or address
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: run-parts: 
/etc/network/if-pre-up.d/wpasupplicant exited with return code 1
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: run-parts --exit-on-error 
--verbose /etc/network/if-up.d
    Sep 18 22:05:27 reiji.sgf.un networking[30162]: Failed to bring up wlan0.

They're happening, because /dev/stdout is a socket (to journald, i suppose),
but shell (/bin/sh, i think) tries to open it like:

    open("/proc/self/fd/1", O_WRONLY|O_CREAT|O_TRUNC, 0666) = -1 ENXIO (No such 
device or address)
    write(2, "sh: 1: sh: ", 11)             = 11
    write(2, "cannot create /proc/self/fd/1: N"..., 56) = 56
    write(2, "\n", 1)                       = 1
    exit_group(2)                           = ?

which is not possible [1]. The fix is to remove '>/dev/stdout' and use '1>&2'
instead of '>/dev/stderr' in '/etc/wpa_supplicant/functions.sh'. Let's try
again after the patch. Stop the service and kill wpa_supplicant process:

    # systemctl stop networking.service
    # systemctl status networking.service
    ● networking.service - LSB: Raise network interfaces.
       Loaded: loaded (/etc/init.d/networking)
      Drop-In: /run/systemd/generator/networking.service.d
               └─50-insserv.conf-$network.conf
            /lib/systemd/system/networking.service.d
               └─network-pre.conf
       Active: inactive (dead) since Sun 2016-09-18 22:09:07 MSK; 7s ago
      Process: 31104 ExecStop=/etc/init.d/networking stop (code=exited, 
status=0/SUCCESS)
      Process: 30162 ExecStart=/etc/init.d/networking start (code=exited, 
status=0/SUCCESS)

    Sep 18 22:09:07 reiji.sgf.un networking[31104]: run-parts: executing 
/etc/network/if-down.d/bind9
    Sep 18 22:09:07 reiji.sgf.un networking[31104]: run-parts: executing 
/etc/network/if-down.d/resolvconf
    Sep 18 22:09:07 reiji.sgf.un networking[31104]: run-parts: executing 
/etc/network/if-down.d/upstart
    Sep 18 22:09:07 reiji.sgf.un networking[31104]: run-parts: executing 
/etc/network/if-down.d/wpasupplicant
    Sep 18 22:09:07 reiji.sgf.un networking[31104]: run-parts --verbose 
/etc/network/if-post-down.d
    Sep 18 22:09:07 reiji.sgf.un networking[31104]: run-parts: executing 
/etc/network/if-post-down.d/ava...mon
    Sep 18 22:09:07 reiji.sgf.un networking[31104]: run-parts: executing 
/etc/network/if-post-down.d/wir...ols
    Sep 18 22:09:07 reiji.sgf.un systemd[1]: Stopped LSB: Raise network 
interfaces..
    Sep 18 22:09:07 reiji.sgf.un networking[31104]: run-parts: executing 
/etc/network/if-post-down.d/wpa...ant
    Sep 18 22:09:07 reiji.sgf.un networking[31104]: done.
    Hint: Some lines were ellipsized, use -l to show in full.

    # ps -f -C wpa_supplicant
    UID        PID  PPID  C STIME TTY          TIME CMD
    root     30183     1  0 22:05 ?        00:00:00 /sbin/wpa_supplicant -s -B 
-P /run/wpa_supplicant.wlan0.pid -i wlan0 -W -D nl80211,wext -c 
/etc/wpa_supplicant.conf
    # pkill wpa_supplicant
    # ps -f -C wpa_supplicant
    UID        PID  PPID  C STIME TTY          TIME CMD

    # ip link show wlan0
    3: wlan0: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc mq state DOWN 
mode DORMANT group default qlen 1000
        link/ether e8:de:27:e8:47:b1 brd ff:ff:ff:ff:ff:ff


then start again:

    # systemctl start networking.service
    # systemctl status networking.service
    ● networking.service - LSB: Raise network interfaces.
       Loaded: loaded (/etc/init.d/networking)
      Drop-In: /run/systemd/generator/networking.service.d
               └─50-insserv.conf-$network.conf
            /lib/systemd/system/networking.service.d
               └─network-pre.conf
       Active: active (running) since Sun 2016-09-18 22:10:46 MSK; 48s ago
      Process: 31104 ExecStop=/etc/init.d/networking stop (code=exited, 
status=0/SUCCESS)
      Process: 31528 ExecStart=/etc/init.d/networking start (code=exited, 
status=0/SUCCESS)
       CGroup: /system.slice/networking.service
               ├─31551 /sbin/wpa_supplicant -s -B -P 
/run/wpa_supplicant.wlan0.pid -i wlan0 -W -D nl80211,w...
               └─31625 /sbin/wpa_cli -B -P /run/wpa_action.wlan0.pid -i wlan0 
-p /var/run/wpa_supplicant -a...

    Sep 18 22:10:46 reiji.sgf.un networking[31528]: run-parts: executing 
/etc/network/if-up.d/wpasupplicant
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: done.
    Sep 18 22:10:47 reiji.sgf.un wpa_supplicant[31551]: wlan0: SME: Trying to 
authenticate with 4c:5e:0c...Hz)
    Sep 18 22:10:47 reiji.sgf.un wpa_supplicant[31551]: wlan0: Trying to 
associate with 4c:5e:0c:70:f9:b...Hz)
    Sep 18 22:10:47 reiji.sgf.un wpa_supplicant[31551]: wlan0: Associated with 
4c:5e:0c:70:f9:b4
    Sep 18 22:10:47 reiji.sgf.un wpa_supplicant[31551]: wlan0: WPA: Key 
negotiation completed with 4c:5e...MP]
    Sep 18 22:10:47 reiji.sgf.un wpa_supplicant[31551]: wlan0: 
CTRL-EVENT-CONNECTED - Connection to 4c:5...un]
    Sep 18 22:10:47 reiji.sgf.un wpa_action[31753]: bssid=4c:5e:0c:70:f9:b4
    Sep 18 22:10:47 reiji.sgf.un wpa_action[31753]: freq=2412
    Sep 18 22:10:47 reiji.sgf.un wpa_action[31753]: ssid=sgf.un
    Hint: Some lines were ellipsized, use -l to show in full.

    # journalctl -f _SYSTEMD_UNIT=networking.service
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: Configuring network 
interfaces...run-parts --exit-on-error --verbose /etc/network/if-pre-up.d
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: run-parts: executing 
/etc/network/if-pre-up.d/wireless-tools
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: run-parts: executing 
/etc/network/if-pre-up.d/wpasupplicant
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: Configuring interface 
wlan0=wlan0 (inet)
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: run-parts --exit-on-error 
--verbose /etc/network/if-pre-up.d
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: run-parts: executing 
/etc/network/if-pre-up.d/wireless-tools
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: run-parts: executing 
/etc/network/if-pre-up.d/wpasupplicant
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: wpa_supplicant: wait for 
wpa_cli to attach
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: wpa_supplicant: wpa-driver 
nl80211,wext (default)
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: wpa_supplicant: 
/sbin/wpa_supplicant -s -B -P /run/wpa_supplicant.wlan0.pid -i wlan0 -W -D 
nl80211,wext -c /etc/wpa_supplicant.conf
    Sep 18 22:10:46 reiji.sgf.un wpa_supplicant[31550]: Successfully 
initialized wpa_supplicant
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: wpa_supplicant: creating 
sendsigs omission pidfile: 
/run/sendsigs.omit.d/wpasupplicant.wpa_supplicant.wlan0.pid
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: wpa_supplicant: 
ctrl_interface socket located at /var/run/wpa_supplicant/wlan0
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: run-parts --exit-on-error 
--verbose /etc/network/if-up.d
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: run-parts: executing 
/etc/network/if-up.d/000resolvconf
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: run-parts: executing 
/etc/network/if-up.d/avahi-daemon
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: run-parts: executing 
/etc/network/if-up.d/bind9
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: run-parts: executing 
/etc/network/if-up.d/mountnfs
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: run-parts: executing 
/etc/network/if-up.d/ntpdate
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: run-parts: executing 
/etc/network/if-up.d/openssh-server
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: run-parts: executing 
/etc/network/if-up.d/upstart
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: run-parts: executing 
/etc/network/if-up.d/wpasupplicant
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: wpa_supplicant: 
/sbin/wpa_cli -B -P /run/wpa_action.wlan0.pid -i wlan0 -p 
/var/run/wpa_supplicant -a /sbin/wpa_action
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: run-parts --exit-on-error 
--verbose /etc/network/if-up.d
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: run-parts: executing 
/etc/network/if-up.d/000resolvconf
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: run-parts: executing 
/etc/network/if-up.d/avahi-daemon
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: run-parts: executing 
/etc/network/if-up.d/bind9
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: run-parts: executing 
/etc/network/if-up.d/mountnfs
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: run-parts: executing 
/etc/network/if-up.d/ntpdate
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: run-parts: executing 
/etc/network/if-up.d/openssh-server
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: run-parts: executing 
/etc/network/if-up.d/upstart
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: run-parts: executing 
/etc/network/if-up.d/wpasupplicant
    Sep 18 22:10:46 reiji.sgf.un networking[31528]: done.
    Sep 18 22:10:47 reiji.sgf.un wpa_supplicant[31551]: wlan0: SME: Trying to 
authenticate with 4c:5e:0c:70:f9:b4 (SSID='sgf.un' freq=2412 MHz)
    Sep 18 22:10:47 reiji.sgf.un wpa_supplicant[31551]: wlan0: Trying to 
associate with 4c:5e:0c:70:f9:b4 (SSID='sgf.un' freq=2412 MHz)
    Sep 18 22:10:47 reiji.sgf.un wpa_supplicant[31551]: wlan0: Associated with 
4c:5e:0c:70:f9:b4
    Sep 18 22:10:47 reiji.sgf.un wpa_supplicant[31551]: wlan0: WPA: Key 
negotiation completed with 4c:5e:0c:70:f9:b4 [PTK=CCMP GTK=CCMP]
    Sep 18 22:10:47 reiji.sgf.un wpa_supplicant[31551]: wlan0: 
CTRL-EVENT-CONNECTED - Connection to 4c:5e:0c:70:f9:b4 completed [id=0 
id_str=sgf.un]
    Sep 18 22:10:47 reiji.sgf.un wpa_action[31753]: bssid=4c:5e:0c:70:f9:b4
    Sep 18 22:10:47 reiji.sgf.un wpa_action[31753]: freq=2412
    Sep 18 22:10:47 reiji.sgf.un wpa_action[31753]: ssid=sgf.un

    # ip link show wlan0
    3: wlan0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc mq state UP mode 
DORMANT group default qlen 1000
        link/ether e8:de:27:e8:47:b1 brd ff:ff:ff:ff:ff:ff
    # ip addr show wlan0
    3: wlan0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc mq state UP 
group default qlen 1000
        link/ether e8:de:27:e8:47:b1 brd ff:ff:ff:ff:ff:ff
        inet 192.168.2.7/24 brd 192.168.2.255 scope global wlan0
           valid_lft forever preferred_lft forever

Now it works.

[1]: https://lists.freedesktop.org/archives/systemd-devel/2015-April/031184.html

-- System Information:
Debian Release: 8.6
  APT prefers stable-updates
  APT policy: (990, 'stable-updates'), (990, 'stable'), (400, 'testing'), (300, 
'unstable')
Architecture: amd64 (x86_64)
Foreign Architectures: i386

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

Versions of packages wpasupplicant depends on:
ii  adduser           3.113+nmu3
ii  libc6             2.19-18+deb8u6
ii  libdbus-1-3       1.8.20-0+deb8u1
ii  libnl-3-200       3.2.24-2
ii  libnl-genl-3-200  3.2.24-2
ii  libpcsclite1      1.8.13-1
ii  libreadline6      6.3-8+b3
ii  libssl1.0.0       1.0.1t-1+deb8u3
ii  lsb-base          4.1+Debian13+nmu1

wpasupplicant recommends no packages.

Versions of packages wpasupplicant suggests:
pn  libengine-pkcs11-openssl  <none>
ii  wpagui                    2.3-1+deb8u4

-- no debconf information
diff --git a/wpa_supplicant/functions.sh b/wpa_supplicant/functions.sh
index 48f2480..8d61ea8 100755
--- a/wpa_supplicant/functions.sh
+++ b/wpa_supplicant/functions.sh
@@ -109,15 +109,15 @@ wpa_msg () {
 	case "$1" in 
 		"verbose")
 			shift
-			echo "$WPA_SUP_PNAME: $@" >$TO_NULL
+			echo "$WPA_SUP_PNAME: $@"
 			;;
 		"action")
 			shift
-			echo -n "$WPA_SUP_PNAME: $@ -- " >$TO_NULL
+			echo -n "$WPA_SUP_PNAME: $@ -- "
 			;;
 		"stderr")
 			shift
-			echo "$WPA_SUP_PNAME: $@" >/dev/stderr
+			echo "$WPA_SUP_PNAME: $@" 1>&2
 			;;
 		*)
 			;;
@@ -458,7 +458,7 @@ wpa_cli_do () {
 
 	wpa_msg action "$WPACLISET_DESC"
 	
-	wpa_cli $WPACLISET_VARIABLE "$WPACLISET_VALUE" >$TO_NULL
+	wpa_cli $WPACLISET_VARIABLE "$WPACLISET_VALUE"
 
 	if [ "$?" -ne 0 ]; then
 		wpa_msg stderr "$WPACLISET_DESC failed!"

Reply via email to