Log when connecting to EAP SSID with internal DHCP client

wpa-eap.txt (text/plain), 14.58 KB, created by Ferry on 2018-04-10 15:07:55 UTC

-- Logs begin at Tue 2017-12-26 16:26:37 CET. --
apr 10 16:55:58 flaptoppy NetworkManager[11263]: <info>  [1523372158.7391] dhcp6 (wlp2s0): state changed unknown -> done
apr 10 16:55:58 flaptoppy wpa_supplicant[386]: wlp2s0: CTRL-EVENT-DISCONNECTED bssid=82:2a:a8:8b:df:67 reason=3 locally_generated=1
apr 10 16:55:58 flaptoppy kernel: brcmfmac: brcmf_inetaddr_changed: fail to get arp ip table err:-52
apr 10 16:55:59 flaptoppy NetworkManager[11263]: <info>  [1523372159.2508] device (wlp2s0): set-hw-addr: set MAC address to E2:92:F9:0D:E1:02 (scanning)
apr 10 16:55:59 flaptoppy kernel: IPv6: ADDRCONF(NETDEV_UP): wlp2s0: link is not ready
apr 10 16:55:59 flaptoppy NetworkManager[11263]: <info>  [1523372159.2531] manager: NetworkManager state is now DISCONNECTED
apr 10 16:55:59 flaptoppy NetworkManager[11263]: <warn>  [1523372159.2541] sup-iface[0x555845a10970,wlp2s0]: connection disconnected (reason -3)
apr 10 16:55:59 flaptoppy NetworkManager[11263]: <info>  [1523372159.2542] device (wlp2s0): supplicant interface state: completed -> disconnected
apr 10 16:55:59 flaptoppy nm-dispatcher[12510]: req:4 'down' [wlp2s0]: new request (1 scripts)
apr 10 16:55:59 flaptoppy nm-dispatcher[12510]: req:4 'down' [wlp2s0]: start running ordered scripts...
apr 10 16:56:13 flaptoppy kwin_x11[12309]: QXcbConnection: XCB error: 3 (BadWindow), sequence: 9282, resource id: 27264512, major code: 3 (GetWindowAttributes), minor code: 0
apr 10 16:56:13 flaptoppy kwin_x11[12309]: QXcbConnection: XCB error: 9 (BadDrawable), sequence: 9283, resource id: 27264512, major code: 14 (GetGeometry), minor code: 0
apr 10 16:56:15 flaptoppy plasmashell[12315]: org.kde.plasmaquick: Applet "Networks" loaded after 0 msec
apr 10 16:56:15 flaptoppy plasmashell[12315]: org.kde.plasmaquick: Increasing score for "Networks" to 51
apr 10 16:56:15 flaptoppy plasmashell[12315]: org.kde.plasmaquick: Applet "System Tray" loaded after 0 msec
apr 10 16:56:15 flaptoppy plasmashell[12315]: org.kde.plasmaquick: Applet "System Tray" loaded after 0 msec
apr 10 16:56:15 flaptoppy plasmashell[12315]: org.kde.plasmaquick: Increasing score for "System Tray" to 57
apr 10 16:56:16 flaptoppy NetworkManager[11263]: <info>  [1523372176.8178] device (wlp2s0): Activation: starting connection 'BCLD-Test-EAP' (29530c20-a303-4c99-b888-d8e23289d219)
apr 10 16:56:16 flaptoppy NetworkManager[11263]: <info>  [1523372176.8179] audit: op="connection-activate" uuid="29530c20-a303-4c99-b888-d8e23289d219" name="BCLD-Test-EAP" pid=12315 uid=1000 result="success"
apr 10 16:56:16 flaptoppy NetworkManager[11263]: <info>  [1523372176.8180] device (wlp2s0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
apr 10 16:56:16 flaptoppy NetworkManager[11263]: <info>  [1523372176.8182] manager: NetworkManager state is now CONNECTING
apr 10 16:56:17 flaptoppy NetworkManager[11263]: <info>  [1523372177.3262] device (wlp2s0): set-hw-addr: reset MAC address to 44:1C:A8:E1:72:A9 (preserve)
apr 10 16:56:17 flaptoppy kernel: IPv6: ADDRCONF(NETDEV_UP): wlp2s0: link is not ready
apr 10 16:56:17 flaptoppy NetworkManager[11263]: <info>  [1523372177.3318] device (wlp2s0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
apr 10 16:56:17 flaptoppy NetworkManager[11263]: <info>  [1523372177.3320] device (wlp2s0): Activation: (wifi) access point 'BCLD-Test-EAP' has security, but secrets are required.
apr 10 16:56:17 flaptoppy NetworkManager[11263]: <info>  [1523372177.3320] device (wlp2s0): state change: config -> need-auth (reason 'none', sys-iface-state: 'managed')
apr 10 16:56:17 flaptoppy kdeinit5[12264]: networkmanager-qt: virtual void NetworkManager::ActiveConnectionPrivate::propertyChanged(const QString&, const QVariant&) Unhandled property "StateFlags"
apr 10 16:56:17 flaptoppy plasmashell[12315]: networkmanager-qt: virtual void NetworkManager::ActiveConnectionPrivate::propertyChanged(const QString&, const QVariant&) Unhandled property "StateFlags"
apr 10 16:56:17 flaptoppy kdeinit5[12264]: plasma-nm: Unhandled active connection state change:  1
apr 10 16:56:17 flaptoppy kdeinit5[12264]: plasma-nm: virtual NMVariantMapMap SecretAgent::GetSecrets(const NMVariantMapMap&, const QDBusObjectPath&, const QString&, const QStringList&, uint)
apr 10 16:56:17 flaptoppy kdeinit5[12264]: plasma-nm: Path: "/org/freedesktop/NetworkManager/Settings/9"
apr 10 16:56:17 flaptoppy kdeinit5[12264]: plasma-nm: Setting name: "802-1x"
apr 10 16:56:17 flaptoppy kdeinit5[12264]: plasma-nm: Hints: ()
apr 10 16:56:17 flaptoppy kdeinit5[12264]: plasma-nm: Flags: 5
apr 10 16:56:17 flaptoppy NetworkManager[11263]: <info>  [1523372177.3472] device (wlp2s0): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
apr 10 16:56:17 flaptoppy NetworkManager[11263]: <info>  [1523372177.3475] device (wlp2s0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
apr 10 16:56:17 flaptoppy NetworkManager[11263]: <info>  [1523372177.3477] device (wlp2s0): Activation: (wifi) connection 'BCLD-Test-EAP' has security, and secrets exist.  No new secrets needed.
apr 10 16:56:17 flaptoppy NetworkManager[11263]: <info>  [1523372177.3477] Config: added 'ssid' value 'BCLD-Test-EAP'
apr 10 16:56:17 flaptoppy NetworkManager[11263]: <info>  [1523372177.3478] Config: added 'scan_ssid' value '1'
apr 10 16:56:17 flaptoppy NetworkManager[11263]: <info>  [1523372177.3478] Config: added 'bgscan' value 'simple:30:-65:300'
apr 10 16:56:17 flaptoppy NetworkManager[11263]: <info>  [1523372177.3478] Config: added 'key_mgmt' value 'WPA-EAP'
apr 10 16:56:17 flaptoppy NetworkManager[11263]: <info>  [1523372177.3478] Config: added 'password' value '<hidden>'
apr 10 16:56:17 flaptoppy NetworkManager[11263]: <info>  [1523372177.3478] Config: added 'eap' value 'PEAP'
apr 10 16:56:17 flaptoppy NetworkManager[11263]: <info>  [1523372177.3478] Config: added 'fragment_size' value '1266'
apr 10 16:56:17 flaptoppy NetworkManager[11263]: <info>  [1523372177.3478] Config: added 'phase2' value 'auth=MSCHAPV2'
apr 10 16:56:17 flaptoppy NetworkManager[11263]: <info>  [1523372177.3478] Config: added 'identity' value 'testing'
apr 10 16:56:17 flaptoppy NetworkManager[11263]: <info>  [1523372177.3478] Config: added 'anonymous_identity' value 'anon'
apr 10 16:56:17 flaptoppy NetworkManager[11263]: <info>  [1523372177.3479] Config: added 'proactive_key_caching' value '1'
apr 10 16:56:17 flaptoppy NetworkManager[11263]: <info>  [1523372177.3548] device (wlp2s0): supplicant interface state: disconnected -> scanning
apr 10 16:56:20 flaptoppy wpa_supplicant[386]: wlp2s0: Trying to associate with SSID 'BCLD-Test-EAP'
apr 10 16:56:20 flaptoppy NetworkManager[11263]: <info>  [1523372180.5403] device (wlp2s0): supplicant interface state: scanning -> associating
apr 10 16:56:23 flaptoppy wpa_supplicant[386]: wlp2s0: Associated with 82:2a:a8:8b:df:67
apr 10 16:56:23 flaptoppy wpa_supplicant[386]: wlp2s0: CTRL-EVENT-EAP-STARTED EAP authentication started
apr 10 16:56:23 flaptoppy wpa_supplicant[386]: wlp2s0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
apr 10 16:56:23 flaptoppy wpa_supplicant[386]: wlp2s0: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=4 -> NAK
apr 10 16:56:23 flaptoppy wpa_supplicant[386]: wlp2s0: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=25
apr 10 16:56:23 flaptoppy wpa_supplicant[386]: wlp2s0: CTRL-EVENT-EAP-METHOD EAP vendor 0 method 25 (PEAP) selected
apr 10 16:56:23 flaptoppy NetworkManager[11263]: <info>  [1523372183.7352] device (wlp2s0): supplicant interface state: associating -> associated
apr 10 16:56:23 flaptoppy wpa_supplicant[386]: wlp2s0: CTRL-EVENT-EAP-PEER-CERT depth=0 subject='/CN=radius' hash=e93bd58fd395fb05d3a3626ba1ee7be217f54b16a18fe4620e7f537d80dc792d
apr 10 16:56:23 flaptoppy wpa_supplicant[386]: wlp2s0: CTRL-EVENT-EAP-PEER-CERT depth=0 subject='/CN=radius' hash=e93bd58fd395fb05d3a3626ba1ee7be217f54b16a18fe4620e7f537d80dc792d
apr 10 16:56:23 flaptoppy wpa_supplicant[386]: EAP-MSCHAPV2: Authentication succeeded
apr 10 16:56:23 flaptoppy wpa_supplicant[386]: EAP-TLV: TLV Result - Success - EAP-TLV/Phase2 Completed
apr 10 16:56:23 flaptoppy wpa_supplicant[386]: wlp2s0: CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully
apr 10 16:56:23 flaptoppy wpa_supplicant[386]: wlp2s0: WPA: Key negotiation completed with 82:2a:a8:8b:df:67 [PTK=CCMP GTK=CCMP]
apr 10 16:56:23 flaptoppy wpa_supplicant[386]: wlp2s0: CTRL-EVENT-CONNECTED - Connection to 82:2a:a8:8b:df:67 completed [id=0 id_str=]
apr 10 16:56:23 flaptoppy NetworkManager[11263]: <info>  [1523372183.7698] device (wlp2s0): supplicant interface state: associated -> completed
apr 10 16:56:23 flaptoppy kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlp2s0: link becomes ready
apr 10 16:56:23 flaptoppy NetworkManager[11263]: <info>  [1523372183.7699] device (wlp2s0): Activation: (wifi) Stage 2 of 5 (Device Configure) successful.  Connected to wireless network 'BCLD-Test-EAP'.
apr 10 16:56:23 flaptoppy NetworkManager[11263]: <info>  [1523372183.7699] device (wlp2s0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
apr 10 16:56:23 flaptoppy NetworkManager[11263]: <info>  [1523372183.7703] dhcp4 (wlp2s0): activation: beginning transaction (timeout in 45 seconds)
apr 10 16:56:23 flaptoppy kdeinit5[12264]: networkmanager-qt: virtual void NetworkManager::ActiveConnectionPrivate::propertyChanged(const QString&, const QVariant&) Unhandled property "StateFlags"
apr 10 16:56:23 flaptoppy NetworkManager[11263]: <info>  [1523372183.7840] dhcp4 (wlp2s0):   address 10.234.234.61
apr 10 16:56:23 flaptoppy NetworkManager[11263]: <info>  [1523372183.7840] dhcp4 (wlp2s0):   plen 24
apr 10 16:56:23 flaptoppy NetworkManager[11263]: <info>  [1523372183.7840] dhcp4 (wlp2s0):   expires in 300 seconds
apr 10 16:56:23 flaptoppy NetworkManager[11263]: <info>  [1523372183.7840] dhcp4 (wlp2s0):   nameserver '10.234.234.11'
apr 10 16:56:23 flaptoppy NetworkManager[11263]: <info>  [1523372183.7841] dhcp4 (wlp2s0):   domain name 'test.local'
apr 10 16:56:23 flaptoppy NetworkManager[11263]: <info>  [1523372183.7841] dhcp4 (wlp2s0):   gateway 10.234.234.254
apr 10 16:56:23 flaptoppy NetworkManager[11263]: <info>  [1523372183.7841] dhcp4 (wlp2s0):   ntp server '10.234.234.11'
apr 10 16:56:23 flaptoppy NetworkManager[11263]: <info>  [1523372183.7841] dhcp4 (wlp2s0):   ntp server '10.0.0.10'
apr 10 16:56:23 flaptoppy NetworkManager[11263]: <info>  [1523372183.7841] dhcp4 (wlp2s0):   ntp server '10.0.0.11'
apr 10 16:56:23 flaptoppy NetworkManager[11263]: <info>  [1523372183.7843] dhcp4 (wlp2s0): state changed unknown -> bound
apr 10 16:56:23 flaptoppy kernel: brcmfmac: brcmf_inetaddr_changed: fail to get arp ip table err:-52
apr 10 16:56:23 flaptoppy NetworkManager[11263]: <info>  [1523372183.7869] device (wlp2s0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
apr 10 16:56:23 flaptoppy NetworkManager[11263]: <info>  [1523372183.7875] device (wlp2s0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
apr 10 16:56:23 flaptoppy kdeinit5[12264]: networkmanager-qt: virtual void NetworkManager::ActiveConnectionPrivate::propertyChanged(const QString&, const QVariant&) Unhandled property "StateFlags"
apr 10 16:56:23 flaptoppy NetworkManager[11263]: <info>  [1523372183.7877] device (wlp2s0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
apr 10 16:56:23 flaptoppy NetworkManager[11263]: <info>  [1523372183.7879] manager: NetworkManager state is now CONNECTED_LOCAL
apr 10 16:56:23 flaptoppy NetworkManager[11263]: <info>  [1523372183.7910] manager: NetworkManager state is now CONNECTED_SITE
apr 10 16:56:23 flaptoppy NetworkManager[11263]: <info>  [1523372183.7910] policy: set 'BCLD-Test-EAP' (wlp2s0) as default for IPv4 routing and DNS
apr 10 16:56:23 flaptoppy NetworkManager[11263]: <info>  [1523372183.7914] device (wlp2s0): Activation: successful, device activated.
apr 10 16:56:23 flaptoppy dbus-daemon[346]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.223' (uid=0 pid=11263 comm="/usr/sbin/NetworkManager --no-daemon ")
apr 10 16:56:23 flaptoppy systemd[1]: Starting Network Manager Script Dispatcher Service...
apr 10 16:56:23 flaptoppy NetworkManager[11263]: <info>  [1523372183.7965] manager: NetworkManager state is now CONNECTED_GLOBAL
apr 10 16:56:23 flaptoppy dbus-daemon[346]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
apr 10 16:56:23 flaptoppy systemd[1]: Started Network Manager Script Dispatcher Service.
apr 10 16:56:23 flaptoppy nm-dispatcher[12532]: req:1 'up' [wlp2s0]: new request (1 scripts)
apr 10 16:56:23 flaptoppy nm-dispatcher[12532]: req:1 'up' [wlp2s0]: start running ordered scripts...
apr 10 16:56:23 flaptoppy nm-dispatcher[12532]: req:2 'connectivity-change': new request (1 scripts)
apr 10 16:56:23 flaptoppy nm-dispatcher[12532]: req:2 'connectivity-change': start running ordered scripts...
apr 10 16:56:23 flaptoppy plasmashell[12315]: networkmanager-qt: virtual void NetworkManager::ActiveConnectionPrivate::propertyChanged(const QString&, const QVariant&) Unhandled property "StateFlags"
apr 10 16:56:23 flaptoppy plasmashell[12315]: networkmanager-qt: virtual void NetworkManager::ActiveConnectionPrivate::propertyChanged(const QString&, const QVariant&) Unhandled property "StateFlags"
apr 10 16:56:25 flaptoppy NetworkManager[11263]: <info>  [1523372185.3604] dhcp6 (wlp2s0): activation: beginning transaction (timeout in 45 seconds)
apr 10 16:56:55 flaptoppy plasmashell[12315]: Currrent active notifications: QHash()
apr 10 16:56:55 flaptoppy plasmashell[12315]: Guessing partOf as: 0
apr 10 16:57:02 flaptoppy plasmashell[12315]: Currrent active notifications: QHash()
apr 10 16:57:02 flaptoppy plasmashell[12315]: Guessing partOf as: 0
apr 10 16:57:10 flaptoppy NetworkManager[11263]: <warn>  [1523372230.2868] dhcp6 (wlp2s0): request timed out
apr 10 16:57:10 flaptoppy NetworkManager[11263]: <info>  [1523372230.2868] dhcp6 (wlp2s0): state changed unknown -> timeout
apr 10 16:57:10 flaptoppy NetworkManager[11263]: <info>  [1523372230.2869] dhcp6 (wlp2s0): canceled DHCP transaction
apr 10 16:57:10 flaptoppy NetworkManager[11263]: <info>  [1523372230.2869] dhcp6 (wlp2s0): state changed timeout -> done
apr 10 16:57:10 flaptoppy kdeinit5[12264]: networkmanager-qt: virtual void NetworkManager::ActiveConnectionPrivate::propertyChanged(const QString&, const QVariant&) Unhandled property "StateFlags"
apr 10 16:57:10 flaptoppy plasmashell[12315]: networkmanager-qt: virtual void NetworkManager::ActiveConnectionPrivate::propertyChanged(const QString&, const QVariant&) Unhandled property "StateFlags"
apr 10 16:57:14 flaptoppy plasmashell[12315]: Currrent active notifications: QHash()
apr 10 16:57:14 flaptoppy plasmashell[12315]: Guessing partOf as: 0