[Pkg-utopia-maintainers] Bug#855187: network-manager: Connection to WPA2 enterprise network (eduroam) is dysfunctional

Ralf Jung post at ralfj.de
Wed Feb 15 08:56:07 UTC 2017


Package: network-manager
Version: 1.6.0-1
Severity: normal

Dear Maintainer,

when I try to connect to the eduroam network of my institution, the resulting
connection does not actuall work.  NetworkManager considers the network to be
"connected" if I enter my credentials correctly (whereas it times out during
connection if I do not).  I even obtain an IPv4 address via DHCP.  However, the
resulting connection does not work: I cannot even ping my router ("Destination
Host Unreachable"), let alone anything on the internet.  I have two eduroam
logins, and this issues occurs with both of them.  At the same time, the network
works fine with my phone and for everyone else around me, so I am pretty sure
the network itself is not at fault here.  This started happening some time
during the last two or three weeks -- previously, the network worked fine.
Other WiFi networks (WPA2 Personal) work mostly fine (the driver is sometimes
making trouble and restarting the device during association, but then NM doesn't
even get to say that a connection was established, let alone obtain an IP via
DHCP).

Here's a log from connecting to eduroam:

Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.0743] device (wlp6s0): Activation: starting connection 'eduroam (MPI)' (54e9f63c-67f0-457a-84cb-99739079a842)
Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.0747] audit: op="connection-activate" uuid="54e9f63c-67f0-457a-84cb-99739079a842" name="eduroam (MPI)" pid=4988 uid=1000 result="success"
Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.0752] device (wlp6s0): state change: disconnected -> prepare (reason 'none') [30 40 0]
Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.0755] manager: NetworkManager state is now CONNECTING
Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.0792] device (wlp6s0): set-hw-addr: reset MAC address to 94:E9:79:7B:A3:43 (preserve)
Feb 15 09:49:37 r-schwarzschild kernel: IPv6: ADDRCONF(NETDEV_UP): wlp6s0: link is not ready
Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.1075] device (wlp6s0): supplicant interface state: disconnected -> disabled
Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.1080] device (wlp6s0): state change: prepare -> config (reason 'none') [40 50 0]
Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.1082] device (wlp6s0): Activation: (wifi) access point 'eduroam (MPI)' has security, but secrets are required.
Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.1082] device (wlp6s0): state change: config -> need-auth (reason 'none') [50 60 0]
Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.1222] device (wlp6s0): supplicant interface state: disabled -> disconnected
Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.1246] device (wlp6s0): state change: need-auth -> prepare (reason 'none') [60 40 0]
Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.1249] device (wlp6s0): state change: prepare -> config (reason 'none') [40 50 0]
Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.1250] device (wlp6s0): Activation: (wifi) connection 'eduroam (MPI)' has security, and secrets exist.  No new secrets needed.
Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.1251] Config: added 'ssid' value 'eduroam'
Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.1251] Config: added 'scan_ssid' value '1'
Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.1251] Config: added 'key_mgmt' value 'WPA-EAP'
Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.1251] Config: added 'password' value '<hidden>'
Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.1251] Config: added 'eap' value 'TTLS'
Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.1251] Config: added 'fragment_size' value '1266'
Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.1251] Config: added 'phase2' value 'auth=PAP'
Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.1251] Config: added 'ca_cert' value '/home/r/<REDACTED>/MPI_eduroam_cert.crt'
Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.1252] Config: added 'identity' value '<REDACTED>'
Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.1252] Config: added 'anonymous_identity' value 'anonymous at mpi-sws.org'
Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.1252] Config: added 'bgscan' value 'simple:30:-65:300'
Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.1252] Config: added 'proactive_key_caching' value '1'
Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.1258] sup-iface[0x55a89a403830,wlp6s0]: config: set interface ap_scan to 1
Feb 15 09:49:37 r-schwarzschild NetworkManager[947]: <info>  [1487148577.1324] device (wlp6s0): supplicant interface state: disconnected -> scanning
Feb 15 09:49:41 r-schwarzschild wpa_supplicant[1216]: wlp6s0: SME: Trying to authenticate with cc:d5:39:ba:83:8c (SSID='eduroam' freq=5180 MHz)
Feb 15 09:49:41 r-schwarzschild kernel: wlp6s0: authenticate with cc:d5:39:ba:83:8c
Feb 15 09:49:41 r-schwarzschild NetworkManager[947]: <info>  [1487148581.9023] device (wlp6s0): supplicant interface state: scanning -> authenticating
Feb 15 09:49:41 r-schwarzschild kernel: wlp6s0: send auth to cc:d5:39:ba:83:8c (try 1/3)
Feb 15 09:49:41 r-schwarzschild kernel: wlp6s0: authenticated
Feb 15 09:49:41 r-schwarzschild wpa_supplicant[1216]: wlp6s0: Trying to associate with cc:d5:39:ba:83:8c (SSID='eduroam' freq=5180 MHz)
Feb 15 09:49:41 r-schwarzschild kernel: ath10k_pci 0000:06:00.0 wlp6s0: disabling HT as WMM/QoS is not supported by the AP
Feb 15 09:49:41 r-schwarzschild kernel: ath10k_pci 0000:06:00.0 wlp6s0: disabling VHT as WMM/QoS is not supported by the AP
Feb 15 09:49:41 r-schwarzschild kernel: wlp6s0: associate with cc:d5:39:ba:83:8c (try 1/3)
Feb 15 09:49:41 r-schwarzschild kernel: wlp6s0: RX AssocResp from cc:d5:39:ba:83:8c (capab=0x1111 status=0 aid=7)
Feb 15 09:49:41 r-schwarzschild wpa_supplicant[1216]: wlp6s0: Associated with cc:d5:39:ba:83:8c
Feb 15 09:49:41 r-schwarzschild wpa_supplicant[1216]: wlp6s0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
Feb 15 09:49:41 r-schwarzschild kernel: wlp6s0: associated
Feb 15 09:49:41 r-schwarzschild kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlp6s0: link becomes ready
Feb 15 09:49:41 r-schwarzschild wpa_supplicant[1216]: wlp6s0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=DE
Feb 15 09:49:41 r-schwarzschild wpa_supplicant[1216]: wlp6s0: CTRL-EVENT-EAP-STARTED EAP authentication started
Feb 15 09:49:41 r-schwarzschild kernel: ath: EEPROM regdomain: 0x8114
Feb 15 09:49:41 r-schwarzschild kernel: ath: EEPROM indicates we should expect a country code
Feb 15 09:49:41 r-schwarzschild kernel: ath: doing EEPROM country->regdmn map search
Feb 15 09:49:41 r-schwarzschild kernel: ath: country maps to regdmn code: 0x37
Feb 15 09:49:41 r-schwarzschild kernel: ath: Country alpha2 being used: DE
Feb 15 09:49:41 r-schwarzschild kernel: ath: Regpair used: 0x37
Feb 15 09:49:41 r-schwarzschild kernel: ath: regdomain 0x8114 dynamically updated by country IE
Feb 15 09:49:41 r-schwarzschild NetworkManager[947]: <info>  [1487148581.9378] device (wlp6s0): supplicant interface state: authenticating -> associating
Feb 15 09:49:41 r-schwarzschild wpa_supplicant[1216]: wlp6s0: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=21
Feb 15 09:49:41 r-schwarzschild wpa_supplicant[1216]: wlp6s0: CTRL-EVENT-EAP-METHOD EAP vendor 0 method 21 (TTLS) selected
Feb 15 09:49:41 r-schwarzschild NetworkManager[947]: <info>  [1487148581.9599] device (wlp6s0): supplicant interface state: associating -> associated
Feb 15 09:49:41 r-schwarzschild wpa_supplicant[1216]: wlp6s0: CTRL-EVENT-EAP-PEER-CERT depth=1 subject='<REDACTED>' hash=ad85f8b1fa991371efb1b61c69328ede93078ab3fefaa2b184ecf73b623771b3
Feb 15 09:49:41 r-schwarzschild wpa_supplicant[1216]: wlp6s0: CTRL-EVENT-EAP-PEER-CERT depth=0 subject='<REDACTED>' hash=50d8a3127b94bbf9d3dad81acb999d3a9a66e2152f795ba176fbbe4978acfd00
Feb 15 09:49:41 r-schwarzschild wpa_supplicant[1216]: wlp6s0: CTRL-EVENT-EAP-PEER-ALT depth=0 DNS:<REDACTED>
Feb 15 09:49:42 r-schwarzschild kernel: wlp6s0: Limiting TX power to 17 dBm as advertised by cc:d5:39:ba:83:8c
Feb 15 09:49:42 r-schwarzschild nm-dispatcher[7379]: req:2 'connectivity-change': start running ordered scripts...
Feb 15 09:49:42 r-schwarzschild nm-dispatcher[7379]: req:3 'down' [enp7s0]: start running ordered scripts...
Feb 15 09:49:42 r-schwarzschild wpa_supplicant[1216]: wlp6s0: CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully
Feb 15 09:49:42 r-schwarzschild wpa_supplicant[1216]: wlp6s0: WPA: Key negotiation completed with cc:d5:39:ba:83:8c [PTK=CCMP GTK=CCMP]
Feb 15 09:49:42 r-schwarzschild wpa_supplicant[1216]: wlp6s0: CTRL-EVENT-CONNECTED - Connection to cc:d5:39:ba:83:8c completed [id=0 id_str=]
Feb 15 09:49:42 r-schwarzschild NetworkManager[947]: <info>  [1487148582.1257] device (wlp6s0): supplicant interface state: associated -> completed
Feb 15 09:49:42 r-schwarzschild NetworkManager[947]: <info>  [1487148582.1259] device (wlp6s0): Activation: (wifi) Stage 2 of 5 (Device Configure) successful.  Connected to wireless network 'eduroam'.
Feb 15 09:49:42 r-schwarzschild NetworkManager[947]: <info>  [1487148582.1647] device (wlp6s0): state change: config -> ip-config (reason 'none') [50 70 0]
Feb 15 09:49:42 r-schwarzschild NetworkManager[947]: <info>  [1487148582.1650] dhcp4 (wlp6s0): activation: beginning transaction (timeout in 45 seconds)
Feb 15 09:49:42 r-schwarzschild NetworkManager[947]: <info>  [1487148582.1667] dhcp4 (wlp6s0): dhclient started with pid 7428
Feb 15 09:49:42 r-schwarzschild dhclient[7428]: DHCPREQUEST of 139.19.250.88 on wlp6s0 to 255.255.255.255 port 67
Feb 15 09:49:42 r-schwarzschild dhclient[7428]: DHCPACK of 139.19.250.88 from 10.10.10.10
Feb 15 09:49:42 r-schwarzschild NetworkManager[947]: <info>  [1487148582.2407] dhcp4 (wlp6s0):   address 139.19.250.88
Feb 15 09:49:42 r-schwarzschild NetworkManager[947]: <info>  [1487148582.2407] dhcp4 (wlp6s0):   plen 24 (255.255.255.0)
Feb 15 09:49:42 r-schwarzschild NetworkManager[947]: <info>  [1487148582.2407] dhcp4 (wlp6s0):   gateway 139.19.250.254
Feb 15 09:49:42 r-schwarzschild NetworkManager[947]: <info>  [1487148582.2407] dhcp4 (wlp6s0):   server identifier 10.10.10.10
Feb 15 09:49:42 r-schwarzschild NetworkManager[947]: <info>  [1487148582.2407] dhcp4 (wlp6s0):   lease time 1200
Feb 15 09:49:42 r-schwarzschild NetworkManager[947]: <info>  [1487148582.2407] dhcp4 (wlp6s0):   nameserver '139.19.205.2'
Feb 15 09:49:42 r-schwarzschild NetworkManager[947]: <info>  [1487148582.2407] dhcp4 (wlp6s0):   nameserver '139.19.86.2'
Feb 15 09:49:42 r-schwarzschild avahi-daemon[667]: Joining mDNS multicast group on interface wlp6s0.IPv4 with address 139.19.250.88.
Feb 15 09:49:42 r-schwarzschild NetworkManager[947]: <info>  [1487148582.2408] dhcp (wlp6s0):   domain search '<REDACTED>'
Feb 15 09:49:42 r-schwarzschild avahi-daemon[667]: New relevant interface wlp6s0.IPv4 for mDNS.
Feb 15 09:49:42 r-schwarzschild NetworkManager[947]: <info>  [1487148582.2408] dhcp (wlp6s0):   domain search '<REDACTED>'
Feb 15 09:49:42 r-schwarzschild avahi-daemon[667]: Registering new address record for 139.19.250.88 on wlp6s0.IPv4.
Feb 15 09:49:42 r-schwarzschild NetworkManager[947]: <info>  [1487148582.2408] dhcp (wlp6s0):   domain search '<REDACTED>'
Feb 15 09:49:42 r-schwarzschild NetworkManager[947]: <info>  [1487148582.2408] dhcp (wlp6s0):   domain search '<REDACTED>'
Feb 15 09:49:42 r-schwarzschild NetworkManager[947]: <info>  [1487148582.2408] dhcp (wlp6s0):   domain search '<REDACTED>'
Feb 15 09:49:42 r-schwarzschild NetworkManager[947]: <info>  [1487148582.2408] dhcp4 (wlp6s0): state changed unknown -> bound
Feb 15 09:49:42 r-schwarzschild NetworkManager[947]: <info>  [1487148582.2419] device (wlp6s0): state change: ip-config -> ip-check (reason 'none') [70 80 0]
Feb 15 09:49:42 r-schwarzschild NetworkManager[947]: <info>  [1487148582.2445] device (wlp6s0): state change: ip-check -> secondaries (reason 'none') [80 90 0]
Feb 15 09:49:42 r-schwarzschild NetworkManager[947]: <info>  [1487148582.2451] device (wlp6s0): state change: secondaries -> activated (reason 'none') [90 100 0]
Feb 15 09:49:42 r-schwarzschild NetworkManager[947]: <info>  [1487148582.2452] manager: NetworkManager state is now CONNECTED_LOCAL
Feb 15 09:49:42 r-schwarzschild nm-dispatcher[7379]: req:4 'connectivity-change': new request (1 scripts)
Feb 15 09:49:42 r-schwarzschild nm-dispatcher[7379]: req:4 'connectivity-change': start running ordered scripts...
Feb 15 09:49:42 r-schwarzschild dhclient[7428]: bound to 139.19.250.88 -- renewal in 521 seconds.
Feb 15 09:49:42 r-schwarzschild NetworkManager[947]: <info>  [1487148582.2506] manager: NetworkManager state is now CONNECTED_GLOBAL
Feb 15 09:49:42 r-schwarzschild NetworkManager[947]: <info>  [1487148582.2507] policy: set 'eduroam (MPI)' (wlp6s0) as default for IPv4 routing and DNS
Feb 15 09:49:42 r-schwarzschild NetworkManager[947]: <info>  [1487148582.2510] device (wlp6s0): Activation: successful, device activated.
Feb 15 09:49:42 r-schwarzschild nm-dispatcher[7379]: req:5 'up' [wlp6s0]: new request (1 scripts)
Feb 15 09:49:42 r-schwarzschild nm-dispatcher[7379]: req:5 'up' [wlp6s0]: start running ordered scripts...
Feb 15 09:49:42 r-schwarzschild wpa_supplicant[1216]: wlp6s0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-63 noise=-101 txrate=6000
Feb 15 09:49:43 r-schwarzschild avahi-daemon[667]: Joining mDNS multicast group on interface wlp6s0.IPv6 with address fe80::e3b1:c00c:6f0a:619d.
Feb 15 09:49:43 r-schwarzschild avahi-daemon[667]: New relevant interface wlp6s0.IPv6 for mDNS.
Feb 15 09:49:43 r-schwarzschild avahi-daemon[667]: Registering new address record for fe80::e3b1:c00c:6f0a:619d on wlp6s0.*.
Feb 15 09:49:43 r-schwarzschild PackageKit[1748]: get-updates transaction /793_eacedbcb from uid 1000 finished with success after 734ms
Feb 15 09:49:48 r-schwarzschild sudo[7465]:        r : TTY=pts/7 ; PWD=/usr/share/doc/network-manager ; USER=root ; COMMAND=/usr/bin/journalctl -e
Feb 15 09:49:48 r-schwarzschild sudo[7465]: pam_unix(sudo:session): session opened for user root by r(uid=0)
Feb 15 09:49:52 r-schwarzschild sudo[7465]: pam_unix(sudo:session): session closed for user root
Feb 15 09:49:54 r-schwarzschild systemd[1]: Reloading Postfix Mail Transport Agent (instance -).
Feb 15 09:49:54 r-schwarzschild systemd[1]: Reloading Postfix Mail Transport Agent.
Feb 15 09:49:54 r-schwarzschild systemd[1]: Reloaded Postfix Mail Transport Agent.
Feb 15 09:49:54 r-schwarzschild postfix/postfix-script[7524]: refreshing the Postfix mail system
Feb 15 09:49:54 r-schwarzschild postfix/master[943]: reload -- version 3.1.4, configuration /etc/postfix
Feb 15 09:49:54 r-schwarzschild systemd[1]: Reloaded Postfix Mail Transport Agent (instance -).
Feb 15 09:50:06 r-schwarzschild systemd[1]: Reloading Postfix Mail Transport Agent (instance -).
Feb 15 09:50:06 r-schwarzschild systemd[1]: Reloading Postfix Mail Transport Agent.
Feb 15 09:50:06 r-schwarzschild systemd[1]: Reloaded Postfix Mail Transport Agent.
Feb 15 09:50:06 r-schwarzschild postfix/postfix-script[7577]: refreshing the Postfix mail system
Feb 15 09:50:06 r-schwarzschild postfix/master[943]: reload -- version 3.1.4, configuration /etc/postfix
Feb 15 09:50:06 r-schwarzschild systemd[1]: Reloaded Postfix Mail Transport Agent (instance -).
Feb 15 09:50:17 r-schwarzschild sudo[7587]:        r : TTY=pts/7 ; PWD=/home/r ; USER=root ; COMMAND=/usr/bin/journalctl -b 0
Feb 15 09:50:17 r-schwarzschild sudo[7587]: pam_unix(sudo:session): session opened for user root by r(uid=0)


Kind regards,
Ralf

-- System Information:
Debian Release: 9.0
  APT prefers testing
  APT policy: (990, 'testing'), (500, 'testing-debug'), (100, 'unstable')
Architecture: amd64 (x86_64)
Foreign Architectures: i386

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

Versions of packages network-manager depends on:
ii  adduser                3.115
ii  dbus                   1.10.14-1
ii  init-system-helpers    1.47
ii  libaudit1              1:2.6.7-1
ii  libbluetooth3          5.43-1
ii  libc6                  2.24-9
ii  libglib2.0-0           2.50.2-2
ii  libgnutls30            3.5.8-3
ii  libgudev-1.0-0         230-3
ii  libjansson4            2.9-1
ii  libmm-glib0            1.6.4-1
ii  libndp0                1.6-1
ii  libnewt0.52            0.52.19-1
ii  libnl-3-200            3.2.27-1
ii  libnm0                 1.6.0-1
ii  libpam-systemd         232-15
ii  libpolkit-agent-1-0    0.105-17
ii  libpolkit-gobject-1-0  0.105-17
ii  libreadline7           7.0-2
ii  libselinux1            2.6-3
ii  libsoup2.4-1           2.56.0-2
ii  libsystemd0            232-15
ii  libteamdctl0           1.26-1
ii  libuuid1               2.29.1-1
ii  lsb-base               9.20161125
ii  policykit-1            0.105-17
ii  udev                   232-15
ii  wpasupplicant          2.6-3

Versions of packages network-manager recommends:
ii  crda             3.18-1
ii  dnsmasq-base     2.76-5
ii  iptables         1.6.0+snapshot20161117-5
ii  iputils-arping   3:20161105-1
ii  isc-dhcp-client  4.3.5-3
ii  modemmanager     1.6.4-1
ii  ppp              2.4.7-1+4

Versions of packages network-manager suggests:
pn  libteam-utils  <none>

-- no debconf information



More information about the Pkg-utopia-maintainers mailing list