Hello!

Im experiencing some problem that I don't understand. Please help!

FreeRadius server is working fine. It shows that device, which tries to connect to AP, was authenticated
( Feeradius -X output)
Also, it was tested with radtest utility on localhost and from different pc.

Access points work fine when set up to anything but not Enterprise / Radius. (Wpa-eap / wpa2-eap)
My phone can connect to it with no problem.

So when I set up openwrt to WPA2-EAP and I attempt to connect with my phone, radius server shows that device was accepted but will not getting bind or fully connect with the access point and it keeps re-trying to connect. Then Radius returns accept agin and this is happening in a loop but connection never happen.

Here is my config: 

config wifi-device 'radio0'                                                     
        option type 'mac80211'                                                 
        option hwmode '11g'                                                     
        option path 'platform/soc/3f300000.mmc/mmc_host/mmc1/mmc1:0001/mmc1:0001
        option country '00'                                                     
        option channel '1'                                                     
        option txpower '15'                                                     
                                                                               
config wifi-iface                                                               
        option device 'radio0'                                                 
        option mode 'ap'                                                       
        option network 'lan'                                                   
        option ssid 'roaming'                                                   
        option encryption 'wpa2'                                               
        option auth_server '192.168.200.1'                                     
        option auth_port '1812'                                                 
        option auth_secret 'Pass1234'                                           
        option acct_server '192.168.200.1'                                     
        option acct_port '1813'                                                 
        option acct_secret 'Pass1234'                                           
                                                                               
Please give any ideas for troubleshooting this!

output from Radius server:

(5485) Finished request
Waking up in 4.8 seconds.
(5486) Received Access-Request Id 4 from 192.168.200.100:55920 to 192.168.200.1:1812 length 234
(5486)   User-Name = "user1"
(5486)   Called-Station-Id = "B8-27-EB-91-FB-17:roaming"
(5486)   NAS-Port-Type = Wireless-802.11
(5486)   Service-Type = Framed-User
(5486)   Calling-Station-Id = "B0-70-2D-CB-65-9B"
(5486)   Connect-Info = "CONNECT 0Mbps 802.11g"
(5486)   Acct-Session-Id = "0F3281D7558374A6"
(5486)   WLAN-Pairwise-Cipher = 1027076
(5486)   WLAN-Group-Cipher = 1027076
(5486)   WLAN-AKM-Suite = 1027073
(5486)   Framed-MTU = 1400
(5486)   EAP-Message = 0x029b002e19001703030023310ecdc5752e3b3babc16f230f499288c3faffdad4c3017c80e3269f56bd1d657cbd92
(5486)   State = 0x315c8e9836c797fd7138dcc18654d7ab
(5486)   Message-Authenticator = 0x043c388701c8bdeb4c9b04fdf2659c33
(5486) session-state: No cached attributes
(5486) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default
(5486)   authorize {
(5486)     policy filter_username {
(5486)       if (&User-Name) {
(5486)       if (&User-Name)  -> TRUE
(5486)       if (&User-Name)  {
(5486)         if (&User-Name =~ / /) {
(5486)         if (&User-Name =~ / /)  -> FALSE
(5486)         if (&User-Name =~ /@[^@]*@/ ) {
(5486)         if (&User-Name =~ /@[^@]*@/ )  -> FALSE
(5486)         if (&User-Name =~ /\.\./ ) {
(5486)         if (&User-Name =~ /\.\./ )  -> FALSE
(5486)         if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(5486)         if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(5486)         if (&User-Name =~ /\.$/)  {
(5486)         if (&User-Name =~ /\.$/)   -> FALSE
(5486)         if (&User-Name =~ /@\./)  {
(5486)         if (&User-Name =~ /@\./)   -> FALSE
(5486)       } # if (&User-Name)  = notfound
(5486)     } # policy filter_username = notfound
(5486)     [preprocess] = ok
(5486)     [chap] = noop
(5486)     [mschap] = noop
(5486)     [digest] = noop
(5486) eap: Peer sent EAP Response (code 2) ID 155 length 46
(5486) eap: Continuing tunnel setup
(5486)     [eap] = ok
(5486)   } # authorize = ok
(5486) Found Auth-Type = eap
(5486) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
(5486)   authenticate {
(5486) eap: Expiring EAP session with state 0x315c8e9836c797fd
(5486) eap: Finished EAP session with state 0x315c8e9836c797fd
(5486) eap: Previous EAP request found for state 0x315c8e9836c797fd, released from the list
(5486) eap: Peer sent packet with method EAP PEAP (25)
(5486) eap: Calling submodule eap_peap to process data
(5486) eap_peap: Continuing EAP-TLS
(5486) eap_peap: [eaptls verify] = ok
(5486) eap_peap: Done initial handshake
(5486) eap_peap: [eaptls process] = ok
(5486) eap_peap: Session established.  Decoding tunneled attributes
(5486) eap_peap: PEAP state send tlv success
(5486) eap_peap: Received EAP-TLV response
(5486) eap_peap: Success
(5486) eap: Sending EAP Success (code 3) ID 155 length 4
(5486) eap: Freeing handler
(5486)     [eap] = ok
(5486)   } # authenticate = ok
(5486) # Executing section post-auth from file /etc/freeradius/3.0/sites-enabled/default
(5486)   post-auth {
(5486)     update {
(5486)       No attributes updated
(5486)     } # update = noop
(5486)     [exec] = noop
(5486)     policy remove_reply_message_if_eap {
(5486)       if (&reply:EAP-Message && &reply:Reply-Message) {
(5486)       if (&reply:EAP-Message && &reply:Reply-Message)  -> FALSE
(5486)       else {
(5486)         [noop] = noop
(5486)       } # else = noop
(5486)     } # policy remove_reply_message_if_eap = noop
(5486)   } # post-auth = noop
(5486) Sent Access-Accept Id 4 from 192.168.200.1:1812 to 192.168.200.100:55920 length 0
(5486)   MS-MPPE-Recv-Key = 0x6f7ea742f8d1a7ab5c7c43c2f37486b3f83ef8c9120784a3cdc1ed5ecfc4b02a
(5486)   MS-MPPE-Send-Key = 0xc1a6e7ed383b46c9aec97bfaa662392852157c5fe627ca04e67e0250f4440880
(5486)   EAP-Message = 0x039b0004
(5486)   Message-Authenticator = 0x00000000000000000000000000000000
(5486)   User-Name = "user1"
(5486) Finished request
Waking up in 4.8 seconds.
(5478) Cleaning up request packet ID 252 with timestamp +7435
(5479) Cleaning up request packet ID 253 with timestamp +7435
(5480) Cleaning up request packet ID 254 with timestamp +7435
(5481) Cleaning up request packet ID 255 with timestamp +7435
(5482) Cleaning up request packet ID 0 with timestamp +7435
(5483) Cleaning up request packet ID 1 with timestamp +7435
(5484) Cleaning up request packet ID 2 with timestamp +7435
(5485) Cleaning up request packet ID 3 with timestamp +7435
(5486) Cleaning up request packet ID 4 with timestamp +7435

Check the AP logs.  After an Access-Accept is received, you should see the user being bound to the LAN interface, issued an EAPOL key, and authorized on the port.

Apparently this is not happening, and I ve no idea why ... my other device, Alfa r36, is authenticating on this set up . raspberry pi is not. I can only see system and kernel logs but there are no entries about wireless / AP operations Where should I look for those AP logs?

Set option log_level 0 in the wifi-device section of /etc/config/wireless for more verbose logging from hostapd.

hostapd messages will be posted to the system log which you can access from the GUI or using logread on the CLI.  Look for messages tagged hostapd.

Oh Great, thanks! Im guessing it will work same with wpad, gonna try it now.

This is the log:

Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.000000] Booting Linux on physical CPU 0x0
Sun Mar 18 15:23:31 2018 kern.notice kernel: [    0.000000] Linux version 4.4.92 (buildbot@debian8) (gcc version 5.4.0 (LEDE GCC 5.4.0 r3557-a5e1f7f) ) #0 SMP Mon Oct 16 22:57:05 2017
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.000000] CPU: ARMv7 Processor [410fd034] revision 4 (ARMv7), cr=10c5383d
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.000000] Machine model: Raspberry Pi 3 Model B Rev 1.2
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.000000] cma: Reserved 16 MiB at 0x3a000000
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.000000] Memory policy: Data cache writealloc
Sun Mar 18 15:23:31 2018 kern.debug kernel: [    0.000000] On node 0 totalpages: 241664
Sun Mar 18 15:23:31 2018 kern.debug kernel: [    0.000000] free_area_init_node: node 0, pgdat 804f1000, node_mem_map b988e000
Sun Mar 18 15:23:31 2018 kern.debug kernel: [    0.000000]   Normal zone: 1888 pages used for memmap
Sun Mar 18 15:23:31 2018 kern.debug kernel: [    0.000000]   Normal zone: 0 pages reserved
Sun Mar 18 15:23:31 2018 kern.debug kernel: [    0.000000]   Normal zone: 241664 pages, LIFO batch:31
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    0.000000] [bcm2709_smp_init_cpus] enter (9480->f3003010)
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    0.000000] [bcm2709_smp_init_cpus] ncores=4
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.000000] PERCPU: Embedded 12 pages/cpu @b984e000 s17984 r8192 d22976 u49152
Sun Mar 18 15:23:31 2018 kern.debug kernel: [    0.000000] pcpu-alloc: s17984 r8192 d22976 u49152 alloc=12*4096
Sun Mar 18 15:23:31 2018 kern.debug kernel: [    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 239776
Sun Mar 18 15:23:31 2018 kern.notice kernel: [    0.000000] Kernel command line: 8250.nr_uarts=1 bcm2708_fb.fbwidth=656 bcm2708_fb.fbheight=416 bcm2708_fb.fbswap=1 smsc95xx.macaddr=B8:27:EB:22:2F:00 vc_mem.mem_base=0x3dc00000 vc_mem.mem_size=0x3f000000  dwc_otg.lpm_enable=0 console=ttyS0,115200 kgdboc=ttyS0,115200 console=tty1 root=/dev/mmcblk0p2 rootfstype=ext4 rootwait
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.000000] PID hash table entries: 4096 (order: 2, 16384 bytes)
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.000000] Memory: 936044K/966656K available (4091K kernel code, 135K rwdata, 684K rodata, 228K init, 373K bss, 14228K reserved, 16384K cma-reserved)
Sun Mar 18 15:23:31 2018 kern.notice kernel: [    0.000000] Virtual kernel memory layout:
Sun Mar 18 15:23:31 2018 kern.notice kernel: [    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
Sun Mar 18 15:23:31 2018 kern.notice kernel: [    0.000000]     fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
Sun Mar 18 15:23:31 2018 kern.notice kernel: [    0.000000]     vmalloc : 0xbb800000 - 0xff800000   (1088 MB)
Sun Mar 18 15:23:31 2018 kern.notice kernel: [    0.000000]     lowmem  : 0x80000000 - 0xbb000000   ( 944 MB)
Sun Mar 18 15:23:31 2018 kern.notice kernel: [    0.000000]     modules : 0x7f000000 - 0x80000000   (  16 MB)
Sun Mar 18 15:23:31 2018 kern.notice kernel: [    0.000000]       .text : 0x80008000 - 0x804b207c   (4777 kB)
Sun Mar 18 15:23:31 2018 kern.notice kernel: [    0.000000]       .init : 0x804b3000 - 0x804ec000   ( 228 kB)
Sun Mar 18 15:23:31 2018 kern.notice kernel: [    0.000000]       .data : 0x804ec000 - 0x8050dc88   ( 136 kB)
Sun Mar 18 15:23:31 2018 kern.notice kernel: [    0.000000]        .bss : 0x8050dc88 - 0x8056b2b8   ( 374 kB)
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.000000] Hierarchical RCU implementation.
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.000000] NR_IRQS:16 nr_irqs:16 16
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.000000] Architected cp15 timer(s) running at 19.20MHz (phys).
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.000007] sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.000022] Switching to timer-based delay loop, resolution 52ns
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.000199] Console: colour dummy device 80x30
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.000815] console [tty1] enabled
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.000857] Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=192000)
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.000911] pid_max: default: 32768 minimum: 301
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.001041] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.001073] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.001769] CPU: Testing write buffer coherency: ok
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.002191] CPU0: update cpu_capacity 1024
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.002221] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    0.002249] [bcm2709_smp_prepare_cpus] enter
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.002319] Setting up static identity map for 0x8240 - 0x8298
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    0.003444] [bcm2709_boot_secondary] cpu:1 started (0) 17
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    0.003735] [bcm2709_secondary_init] enter cpu:1
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.003766] CPU1: update cpu_capacity 1024
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.003772] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    0.004073] [bcm2709_boot_secondary] cpu:2 started (0) 18
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    0.004277] [bcm2709_secondary_init] enter cpu:2
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.004295] CPU2: update cpu_capacity 1024
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.004301] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    0.004582] [bcm2709_boot_secondary] cpu:3 started (0) 15
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    0.004762] [bcm2709_secondary_init] enter cpu:3
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.004781] CPU3: update cpu_capacity 1024
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.004787] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.004839] Brought up 4 CPUs
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.004929] SMP: Total of 4 processors activated (153.60 BogoMIPS).
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.004955] CPU: All CPU(s) started in HYP mode.
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.004978] CPU: Virtualization extensions available.
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.013661] VFP support v0.3: implementor 41 architecture 3 part 40 variant 3 rev 4
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.013916] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.013971] futex hash table entries: 1024 (order: 4, 65536 bytes)
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.014601] pinctrl core: initialized pinctrl subsystem
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.015156] NET: Registered protocol family 16
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.020084] DMA: preallocated 4096 KiB pool for atomic coherent allocations
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.049927] cpuidle: using governor ladder
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.079945] cpuidle: using governor menu
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.085763] bcm2709: Mini UART enabled
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.085847] Serial: AMBA PL011 UART driver
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.085989] uart-pl011 3f201000.uart: could not find pctldev for node /soc/gpio@7e200000/uart0_pins, deferring probe
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.086162] bcm2835-mbox 3f00b880.mailbox: mailbox enabled
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.141966] bcm2835-dma 3f007000.dma: DMA legacy API manager at f3007000, dmachans=0x1
Sun Mar 18 15:23:31 2018 kern.notice kernel: [    0.142389] SCSI subsystem initialized
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.142558] usbcore: registered new interface driver usbfs
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.142655] usbcore: registered new interface driver hub
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.142739] usbcore: registered new device driver usb
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.150022] raspberrypi-firmware soc:firmware: Attached to firmware from 2017-03-02 15:32
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.176839] clocksource: Switched to clocksource arch_sys_counter
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.184330] NET: Registered protocol family 2
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.184959] TCP established hash table entries: 8192 (order: 3, 32768 bytes)
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.185092] TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.185299] TCP: Hash tables configured (established 8192 bind 8192)
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.185402] UDP hash table entries: 512 (order: 2, 16384 bytes)
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.185467] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.185653] NET: Registered protocol family 1
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    0.187118] Crashlog allocated RAM at address 0x3f00000
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.195843] io scheduler noop registered
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.195874] io scheduler deadline registered
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.195922] io scheduler cfq registered (default)
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.198291] BCM2708FB: allocated DMA memory fa410000
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.198336] BCM2708FB: allocated DMA channel 0 @ f3007000
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.206169] Console: switching to colour frame buffer device 82x26
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.212388] Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.215169] console [ttyS0] disabled
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.217224] 3f215040.uart: ttyS0 at MMIO 0x3f215040 (irq = 59, base_baud = 31250000) is a 16550
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.810974] console [ttyS0] enabled
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.817140] vc-cma: Videocore CMA driver
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.823089] vc-cma: vc_cma_base      = 0x00000000
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.829817] vc-cma: vc_cma_size      = 0x00000000 (0 MiB)
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.837179] vc-cma: vc_cma_initial   = 0x00000000 (0 MiB)
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.844580] vc-mem: phys_addr:0x00000000 mem_base=0x3dc00000 mem_size:0x3f000000(1008 MiB)
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.867717] brd: module loaded
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.879302] loop: module loaded
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.884947] vchiq: vchiq_init_state: slot_zero = 0xba480000, is_master = 0
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.895291] usbcore: registered new interface driver smsc95xx
Sun Mar 18 15:23:31 2018 kern.info kernel: [    0.903006] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    1.110985] Core Release: 2.80a
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    1.116055] Setting default values for core params
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    1.122853] Finished setting default values for core params
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    1.330774] Using Buffer DMA mode
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    1.336045] Periodic Transfer Interrupt Enhancement - disabled
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    1.343918] Multiprocessor Interrupt Enhancement - disabled
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    1.351521] OTG VER PARAM: 0, OTG VER FLAG: 0
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    1.357841] Dedicated Tx FIFOs mode
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    1.363439] WARN::dwc_otg_hcd_init:1047: FIQ DMA bounce buffers: virt = 0xba404000 dma = 0xfa404000 len=9024
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    1.377280] FIQ FSM acceleration enabled for :
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    1.377280] Non-periodic Split Transactions
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    1.377280] Periodic Split Transactions
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    1.377280] High-Speed Isochronous Endpoints
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    1.377280] Interrupt/Control Split Transaction hack enabled
Sun Mar 18 15:23:31 2018 kern.debug kernel: [    1.409837] dwc_otg: Microframe scheduler enabled
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    1.409884] WARN::hcd_init_fiq:415: FIQ on core 1 at 0x802a4350
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    1.417890] WARN::hcd_init_fiq:416: FIQ ASM at 0x8000ee60 length 36
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    1.426259] WARN::hcd_init_fiq:441: MPHI regs_base at 0xbb87a000
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.434355] dwc_otg 3f980000.usb: DWC OTG Controller
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.441353] dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.450767] dwc_otg 3f980000.usb: irq 62, io mem 0x00000000
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    1.458379] Init: Port Power? op_state=1
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    1.464246] Init: Power Port (0)
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.469546] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.478381] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.487647] usb usb1: Product: DWC OTG Controller
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.494300] usb usb1: Manufacturer: Linux 4.4.92 dwc_otg_hcd
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.501945] usb usb1: SerialNumber: 3f980000.usb
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.509120] hub 1-0:1.0: USB hub found
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.514760] hub 1-0:1.0: 1 port detected
Sun Mar 18 15:23:31 2018 kern.debug kernel: [    1.520967] dwc_otg: FIQ enabled
Sun Mar 18 15:23:31 2018 kern.debug kernel: [    1.520976] dwc_otg: NAK holdoff enabled
Sun Mar 18 15:23:31 2018 kern.debug kernel: [    1.520983] dwc_otg: FIQ split-transaction FSM enabled
Sun Mar 18 15:23:31 2018 kern.debug kernel: [    1.520997] Module dwc_common_port init
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.521129] usbcore: registered new interface driver uas
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.528366] usbcore: registered new interface driver usb-storage
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.536296] mousedev: PS/2 mouse device common for all mice
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.544420] bcm2835-wdt 3f100000.watchdog: Broadcom BCM2835 watchdog timer
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.553368] sdhci: Secure Digital Host Controller Interface driver
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.561507] sdhci: Copyright(c) Pierre Ossman
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.567989] sdhost: log_buf @ ba407000 (fa407000)
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.626848] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.636472] mmc-bcm2835 3f300000.mmc: mmc_debug:0 mmc_debug2:0
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.644278] mmc-bcm2835 3f300000.mmc: DMA channel allocated
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.686916] sdhci-pltfm: SDHCI platform and OF driver helper
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.696094] NET: Registered protocol family 10
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.703236] NET: Registered protocol family 17
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.709589] bridge: automatic filtering via arp/ip/ip6tables has been deprecated. Update your scripts to load br_netfilter if you need this.
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    1.717033] Indeed it is in host mode hprt0 = 00021501
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    1.726521] mmc0: host does not support reading read-only switch, assuming write-enable
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.729984] mmc0: new high speed SDHC card at address aaaa
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.730464] mmcblk0: mmc0:aaaa SL32G 28.8 GiB
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.734036]  mmcblk0: p1 p2
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    1.750555] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    1.752075] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    1.753600] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    1.756334] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.794138] 8021q: 802.1Q VLAN Support v1.8
Sun Mar 18 15:23:31 2018 kern.notice kernel: [    1.800517] Registering SWP/SWPB emulation handler
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.807654] vc-sm: Videocore shared memory driver
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.814203] [vc_sm_connected_init]: start
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.820385] [vc_sm_connected_init]: end - returning 0
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.828499] 3f201000.uart: ttyAMA0 at MMIO 0x3f201000 (irq = 87, base_baud = 0) is a PL011 rev2
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.841212] of_cfs_init
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.844464] mmc1: new high speed SDIO card at address 0001
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.852946] of_cfs_init: OK
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.864464] EXT4-fs (mmcblk0p2): mounted filesystem without journal. Opts: (null)
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.875667] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.884733] Freeing unused kernel memory: 228K
Sun Mar 18 15:23:31 2018 kern.info kernel: [    1.886861] usb 1-1: new high-speed USB device number 2 using dwc_otg
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    1.886982] Indeed it is in host mode hprt0 = 00001101
Sun Mar 18 15:23:31 2018 user.info kernel: [    1.971820] init: Console is alive
Sun Mar 18 15:23:31 2018 user.info kernel: [    1.977293] init: - watchdog -
Sun Mar 18 15:23:31 2018 kern.info kernel: [    2.087093] usb 1-1: New USB device found, idVendor=0424, idProduct=9514
Sun Mar 18 15:23:31 2018 kern.info kernel: [    2.095951] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
Sun Mar 18 15:23:31 2018 kern.info kernel: [    2.105950] hub 1-1:1.0: USB hub found
Sun Mar 18 15:23:31 2018 kern.info kernel: [    2.111919] hub 1-1:1.0: 5 ports detected
Sun Mar 18 15:23:31 2018 user.info kernel: [    2.144805] kmodloader: loading kernel modules from /etc/modules-boot.d/*
Sun Mar 18 15:23:31 2018 user.info kernel: [    2.159072] kmodloader: done loading kernel modules from /etc/modules-boot.d/*
Sun Mar 18 15:23:31 2018 user.info kernel: [    2.173989] init: - preinit -
Sun Mar 18 15:23:31 2018 kern.info kernel: [    2.396862] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
Sun Mar 18 15:23:31 2018 kern.info kernel: [    2.517067] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00
Sun Mar 18 15:23:31 2018 kern.info kernel: [    2.526312] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
Sun Mar 18 15:23:31 2018 kern.notice kernel: [    2.537471] random: procd: uninitialized urandom read (4 bytes read, 71 bits of entropy available)
Sun Mar 18 15:23:31 2018 kern.info kernel: [    2.551349] smsc95xx v1.0.4
Sun Mar 18 15:23:31 2018 kern.info kernel: [    2.619723] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:22:2f:00
Sun Mar 18 15:23:31 2018 user.notice kernel: [    4.297378] mount_root: mounting /dev/root
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    4.304217] EXT4-fs (mmcblk0p2): warning: mounting unchecked fs, running e2fsck is recommended
Sun Mar 18 15:23:31 2018 kern.info kernel: [    4.320433] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
Sun Mar 18 15:23:31 2018 kern.warn kernel: [    4.359379] FAT-fs (mmcblk0p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
Sun Mar 18 15:23:31 2018 user.warn kernel: [    4.375736] urandom-seed: Seeding with /etc/urandom.seed
Sun Mar 18 15:23:31 2018 user.info kernel: [    4.407599] procd: - early -
Sun Mar 18 15:23:31 2018 user.info kernel: [    4.412973] procd: - watchdog -
Sun Mar 18 15:23:31 2018 user.info kernel: [    5.005929] procd: - watchdog -
Sun Mar 18 15:23:31 2018 user.info kernel: [    5.011514] procd: - ubus -
Sun Mar 18 15:23:31 2018 kern.notice kernel: [    5.023588] random: ubusd: uninitialized urandom read (4 bytes read, 77 bits of entropy available)
Sun Mar 18 15:23:31 2018 kern.notice kernel: [    5.067637] random: ubusd: uninitialized urandom read (4 bytes read, 77 bits of entropy available)
Sun Mar 18 15:23:31 2018 kern.notice kernel: [    5.081413] random: ubusd: uninitialized urandom read (4 bytes read, 77 bits of entropy available)
Sun Mar 18 15:23:31 2018 kern.notice kernel: [    5.095114] random: ubusd: uninitialized urandom read (4 bytes read, 77 bits of entropy available)
Sun Mar 18 15:23:31 2018 kern.notice kernel: [    5.109130] random: ubusd: uninitialized urandom read (4 bytes read, 77 bits of entropy available)
Sun Mar 18 15:23:31 2018 kern.notice kernel: [    5.123121] random: ubusd: uninitialized urandom read (4 bytes read, 77 bits of entropy available)
Sun Mar 18 15:23:31 2018 kern.notice kernel: [    5.137232] random: ubusd: uninitialized urandom read (4 bytes read, 77 bits of entropy available)
Sun Mar 18 15:23:31 2018 kern.notice kernel: [    5.151429] random: ubusd: uninitialized urandom read (4 bytes read, 77 bits of entropy available)
Sun Mar 18 15:23:31 2018 user.info kernel: [    5.165767] procd: - init -
Sun Mar 18 15:23:31 2018 user.info kernel: [    5.270165] kmodloader: loading kernel modules from /etc/modules.d/*
Sun Mar 18 15:23:31 2018 kern.info kernel: [    5.296768] ip6_tables: (C) 2000-2006 Netfilter Core Team
Sun Mar 18 15:23:31 2018 kern.info kernel: [    5.559304] hidraw: raw HID events driver (C) Jiri Kosina
Sun Mar 18 15:23:31 2018 kern.info kernel: [    5.770528] usbcore: registered new interface driver ax88179_178a
Sun Mar 18 15:23:31 2018 kern.info kernel: [    5.781099] Loading modules backported from Linux version wt-2017-01-31-0-ge882dff19e7f
Sun Mar 18 15:23:31 2018 kern.info kernel: [    5.794523] Backport generated by backports.git backports-20160324-13-g24da7d3c
Sun Mar 18 15:23:31 2018 kern.info kernel: [    5.858006] ip_tables: (C) 2000-2006 Netfilter Core Team
Sun Mar 18 15:23:31 2018 kern.info kernel: [    5.870782] nf_conntrack version 0.5.0 (14885 buckets, 59540 max)
Sun Mar 18 15:23:31 2018 kern.info kernel: [    6.009869] usbcore: registered new interface driver usbhid
Sun Mar 18 15:23:31 2018 kern.info kernel: [    6.018232] usbhid: USB HID core driver
Sun Mar 18 15:23:31 2018 kern.info kernel: [    6.030436] xt_time: kernel timezone is -0000
Sun Mar 18 15:23:31 2018 kern.info kernel: [    6.140949] PPP generic driver version 2.4.2
Sun Mar 18 15:23:31 2018 kern.info kernel: [    6.148480] NET: Registered protocol family 24
Sun Mar 18 15:23:31 2018 kern.info kernel: [    6.160311] usbcore: registered new interface driver rtl8187
Sun Mar 18 15:23:31 2018 kern.notice kernel: [    6.265991] random: nonblocking pool is initialized
Sun Mar 18 15:23:31 2018 kern.err kernel: [    6.284487] brcmfmac: brcmf_c_preinit_dcmds: Firmware version = wl0: Aug 29 2016 20:48:16 version 7.45.41.26 (r640327) FWID 01-4527cfab
Sun Mar 18 15:23:31 2018 kern.err kernel: [    6.315662] brcmfmac: brcmf_cfg80211_reg_notifier: not a ISO3166 code (0x30 0x30)
Sun Mar 18 15:23:31 2018 kern.info kernel: [    6.349820] usbcore: registered new interface driver brcmfmac
Sun Mar 18 15:23:31 2018 kern.info kernel: [    6.452621] usbcore: registered new interface driver rt2800usb
Sun Mar 18 15:23:31 2018 user.err kernel: [    6.536936] kmodloader: 1 module could not be probed
Sun Mar 18 15:23:31 2018 user.err kernel: [    6.544341] kmodloader: - g_ether - 0
Sun Mar 18 15:23:32 2018 user.notice : Added device handler type: tunnel
Sun Mar 18 15:23:32 2018 user.notice : Added device handler type: Network device
Sun Mar 18 15:23:32 2018 user.notice : Added device handler type: bridge
Sun Mar 18 15:23:32 2018 user.notice : Added device handler type: macvlan
Sun Mar 18 15:23:32 2018 user.notice : Added device handler type: 8021ad
Sun Mar 18 15:23:32 2018 user.notice : Added device handler type: 8021q
Sun Mar 18 15:23:32 2018 daemon.warn netifd: You have delegated IPv6-prefixes but haven't assigned them to any interface. Did you forget to set option ip6assign on your lan-interfaces?
Sun Mar 18 15:23:32 2018 kern.info kernel: [    8.048540] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
Sun Mar 18 15:23:32 2018 kern.info kernel: [    8.060051] device eth0 entered promiscuous mode
Sun Mar 18 15:23:32 2018 kern.info kernel: [    8.070037] IPv6: ADDRCONF(NETDEV_UP): br-lan: link is not ready
Sun Mar 18 15:23:32 2018 daemon.notice netifd: Interface 'lan' is enabled
Sun Mar 18 15:23:32 2018 daemon.notice netifd: Interface 'loopback' is enabled
Sun Mar 18 15:23:32 2018 daemon.notice netifd: Interface 'loopback' is setting up now
Sun Mar 18 15:23:32 2018 daemon.notice netifd: Interface 'loopback' is now up
Sun Mar 18 15:23:32 2018 daemon.notice netifd: Network device 'lo' link is up
Sun Mar 18 15:23:32 2018 daemon.notice netifd: Interface 'loopback' has link connectivity
Sun Mar 18 15:23:32 2018 daemon.notice procd: /etc/rc.d/S50dropbear: interface lan has no physdev or physdev has no suitable ip
Sun Mar 18 15:23:32 2018 daemon.notice netifd: radio0 (362): command failed: No error information (-524)
Sun Mar 18 15:23:33 2018 daemon.info procd: - init complete -
Sun Mar 18 15:23:34 2018 daemon.notice netifd: radio0 (362): command failed: Not supported (-95)
Sun Mar 18 15:23:34 2018 daemon.notice netifd: radio0 (362): command failed: I/O error (-5)
Sun Mar 18 15:23:34 2018 daemon.err hostapd: Configuration file: /var/run/hostapd-phy0.conf
Sun Mar 18 15:23:34 2018 daemon.err hostapd: Invalid R1KH-ID: 'B827EB777A55'
Sun Mar 18 15:23:34 2018 daemon.err hostapd: Invalid R1KH-ID: 'B827EB91FB17'
Sun Mar 18 15:23:34 2018 daemon.err hostapd: 2 errors found in configuration file '/var/run/hostapd-phy0.conf'
Sun Mar 18 15:23:34 2018 daemon.err hostapd: Failed to set up interface with /var/run/hostapd-phy0.conf
Sun Mar 18 15:23:34 2018 daemon.err hostapd: Failed to initialize interface
Sun Mar 18 15:23:34 2018 daemon.notice netifd: radio0 (362): cat: can't open '/var/run/wifi-phy0.pid': No such file or directory
Sun Mar 18 15:23:34 2018 daemon.notice netifd: radio0 (362): Command failed: Invalid argument
Sun Mar 18 15:23:34 2018 daemon.notice netifd: radio0 (362): Device setup failed: HOSTAPD_START_FAILED
Sun Mar 18 15:23:34 2018 daemon.notice netifd: radio0 (532): command failed: No error information (-524)
Sun Mar 18 15:23:34 2018 kern.err kernel: [    9.519694] brcmfmac: brcmf_cfg80211_get_channel: chanspec failed (-1)
Sun Mar 18 15:23:34 2018 kern.info kernel: [    9.684070] smsc95xx 1-1.1:1.0 eth0: link up, 100Mbps, full-duplex, lpa 0xC5E1
Sun Mar 18 15:23:34 2018 daemon.notice netifd: Network device 'eth0' link is up
Sun Mar 18 15:23:34 2018 kern.info kernel: [    9.697028] br-lan: port 1(eth0) entered forwarding state
Sun Mar 18 15:23:34 2018 kern.info kernel: [    9.704756] br-lan: port 1(eth0) entered forwarding state
Sun Mar 18 15:23:34 2018 kern.info kernel: [    9.712535] IPv6: ADDRCONF(NETDEV_CHANGE): br-lan: link becomes ready
Sun Mar 18 15:23:34 2018 daemon.notice netifd: bridge 'br-lan' link is up
Sun Mar 18 15:23:34 2018 daemon.notice netifd: Interface 'lan' has link connectivity
Sun Mar 18 15:23:34 2018 daemon.notice netifd: Interface 'lan' is setting up now
Sun Mar 18 15:23:34 2018 daemon.notice netifd: lan (552): udhcpc: started, v1.25.1
Sun Mar 18 15:23:34 2018 daemon.notice netifd: lan (552): udhcpc: sending discover
Sun Mar 18 15:23:34 2018 daemon.notice netifd: lan (552): udhcpc: sending select for 192.168.200.100
Sun Mar 18 15:23:34 2018 daemon.notice netifd: lan (552): udhcpc: lease of 192.168.200.100 obtained, lease time 604800
Sun Mar 18 15:23:34 2018 daemon.notice netifd: Interface 'lan' is now up
Sun Mar 18 15:23:34 2018 user.notice firewall: Reloading firewall due to ifup of lan (br-lan)
Sun Mar 18 15:23:35 2018 daemon.info odhcpd[315]: Using a RA lifetime of 0 seconds on br-lan
Sun Mar 18 15:23:35 2018 daemon.notice odhcpd[315]: Failed to send to ff02::1%br-lan (Address not available)
Sun Mar 18 15:23:36 2018 authpriv.info dropbear[613]: Not backgrounding
Sun Mar 18 15:23:36 2018 kern.info kernel: [   11.696836] br-lan: port 1(eth0) entered forwarding state
Sun Mar 18 15:23:37 2018 daemon.info dnsmasq[656]: started, version 2.78 cachesize 150
Sun Mar 18 15:23:37 2018 daemon.info dnsmasq[656]: DNS service limited to local subnets
Sun Mar 18 15:23:37 2018 daemon.info dnsmasq[656]: compile time options: IPv6 GNU-getopt no-DBus no-i18n no-IDN DHCP no-DHCPv6 no-Lua TFTP no-conntrack no-ipset no-auth no-DNSSEC no-ID loop-detect inotify
Sun Mar 18 15:23:37 2018 daemon.info dnsmasq[656]: using local addresses only for domain lan
Sun Mar 18 15:23:37 2018 daemon.info dnsmasq[656]: reading /tmp/resolv.conf.auto
Sun Mar 18 15:23:37 2018 daemon.info dnsmasq[656]: using local addresses only for domain lan
Sun Mar 18 15:23:37 2018 daemon.info dnsmasq[656]: using nameserver 192.168.200.2#53
Sun Mar 18 15:23:37 2018 daemon.info dnsmasq[656]: using nameserver 192.168.200.2#53
Sun Mar 18 15:23:37 2018 daemon.info dnsmasq[656]: read /etc/hosts - 4 addresses
Sun Mar 18 15:23:37 2018 daemon.info dnsmasq[656]: read /tmp/hosts/dhcp.cfg02411c - 1 addresses
Sun Mar 18 15:24:03 2018 daemon.info dnsmasq[656]: read /etc/hosts - 4 addresses
Sun Mar 18 15:24:03 2018 daemon.info dnsmasq[656]: read /tmp/hosts/dhcp.cfg02411c - 1 addresses
Sun Mar 18 15:26:42 2018 daemon.info odhcpd[315]: Using a RA lifetime of 0 seconds on br-lan

okay, i fixed R1KD-ID stuff but there is still a problem ... with some kernel driver?

Sun Mar 18 15:51:44 2018 user.notice : Added device handler type: tunnel
Sun Mar 18 15:51:44 2018 user.notice : Added device handler type: Network device
Sun Mar 18 15:51:44 2018 user.notice : Added device handler type: bridge
Sun Mar 18 15:51:44 2018 user.notice : Added device handler type: macvlan
Sun Mar 18 15:51:44 2018 user.notice : Added device handler type: 8021ad
Sun Mar 18 15:51:44 2018 user.notice : Added device handler type: 8021q
Sun Mar 18 15:51:45 2018 daemon.warn netifd: You have delegated IPv6-prefixes but haven't assigned them to any interface. Did you forget to set option ip6assign on your lan-interfaces?
Sun Mar 18 15:51:45 2018 kern.info kernel: [    7.978517] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
Sun Mar 18 15:51:45 2018 kern.info kernel: [    7.989973] device eth0 entered promiscuous mode
Sun Mar 18 15:51:45 2018 kern.info kernel: [    7.999929] IPv6: ADDRCONF(NETDEV_UP): br-lan: link is not ready
Sun Mar 18 15:51:45 2018 daemon.notice netifd: Interface 'lan' is enabled
Sun Mar 18 15:51:45 2018 daemon.notice netifd: Interface 'loopback' is enabled
Sun Mar 18 15:51:45 2018 daemon.notice netifd: Interface 'loopback' is setting up now
Sun Mar 18 15:51:45 2018 daemon.notice netifd: Interface 'loopback' is now up
Sun Mar 18 15:51:45 2018 daemon.notice netifd: Network device 'lo' link is up
Sun Mar 18 15:51:45 2018 daemon.notice netifd: Interface 'loopback' has link connectivity
Sun Mar 18 15:51:45 2018 daemon.notice procd: /etc/rc.d/S50dropbear: interface lan has no physdev or physdev has no suitable ip
Sun Mar 18 15:51:45 2018 daemon.notice netifd: wlan0 (362): command failed: No error information (-524)
Sun Mar 18 15:51:46 2018 daemon.info procd: - init complete -
Sun Mar 18 15:51:46 2018 daemon.notice netifd: wlan0 (362): command failed: Not supported (-95)
Sun Mar 18 15:51:46 2018 daemon.notice netifd: wlan0 (362): command failed: I/O error (-5)
Sun Mar 18 15:51:47 2018 daemon.notice netifd: wlan0 (362): command failed: Too many open files in system (-23)
Sun Mar 18 15:51:47 2018 daemon.err hostapd: Configuration file: /var/run/hostapd-phy0.conf
Sun Mar 18 15:51:47 2018 daemon.err hostapd: Failed to create interface mon.wlan0: -95 (Not supported)
Sun Mar 18 15:51:47 2018 kern.info kernel: [    9.371668] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
Sun Mar 18 15:51:47 2018 kern.info kernel: [    9.382920] device wlan0 entered promiscuous mode
Sun Mar 18 15:51:47 2018 daemon.notice hostapd: wlan0: interface state UNINITIALIZED->COUNTRY_UPDATE
Sun Mar 18 15:51:47 2018 daemon.warn hostapd: wlan0: Could not connect to kernel driver
Sun Mar 18 15:51:47 2018 daemon.err hostapd: Using interface wlan0 with hwaddr b8:27:eb:77:7a:55 and ssid "roaming"
Sun Mar 18 15:51:47 2018 daemon.info hostapd: wlan0: RADIUS Authentication server 192.168.200.1:1812
Sun Mar 18 15:51:47 2018 daemon.notice hostapd: connect[radius]: Network unreachable
Sun Mar 18 15:51:47 2018 daemon.info hostapd: wlan0: RADIUS Accounting server 192.168.200.1:1813
Sun Mar 18 15:51:47 2018 daemon.notice hostapd: connect[radius]: Network unreachable
Sun Mar 18 15:51:47 2018 daemon.info hostapd: wlan0: RADIUS Accounting server 192.168.200.1:1813
Sun Mar 18 15:51:47 2018 daemon.notice hostapd: connect[radius]: Network unreachable
Sun Mar 18 15:51:47 2018 daemon.info hostapd: wlan0: RADIUS No accounting server configured
Sun Mar 18 15:51:47 2018 kern.err kernel: [    9.433446] brcmfmac: brcmf_configure_wpaie: Invalid key mgmt info
Sun Mar 18 15:51:47 2018 kern.info kernel: [    9.543274] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Sun Mar 18 15:51:47 2018 kern.info kernel: [    9.552050] br-lan: port 2(wlan0) entered forwarding state
Sun Mar 18 15:51:47 2018 kern.info kernel: [    9.559836] br-lan: port 2(wlan0) entered forwarding state
Sun Mar 18 15:51:47 2018 kern.info kernel: [    9.566372] smsc95xx 1-1.1:1.0 eth0: link up, 100Mbps, full-duplex, lpa 0xC5E1
Sun Mar 18 15:51:47 2018 daemon.notice netifd: bridge 'br-lan' link is up
Sun Mar 18 15:51:47 2018 daemon.notice netifd: Interface 'lan' has link connectivity
Sun Mar 18 15:51:47 2018 daemon.notice netifd: Interface 'lan' is setting up now
Sun Mar 18 15:51:47 2018 kern.info kernel: [    9.577308] IPv6: ADDRCONF(NETDEV_CHANGE): br-lan: link becomes ready
Sun Mar 18 15:51:47 2018 daemon.notice netifd: Network device 'eth0' link is up
Sun Mar 18 15:51:47 2018 kern.info kernel: [    9.588142] br-lan: port 1(eth0) entered forwarding state
Sun Mar 18 15:51:47 2018 kern.info kernel: [    9.596084] br-lan: port 1(eth0) entered forwarding state
Sun Mar 18 15:51:47 2018 daemon.warn hostapd: wlan0: Could not connect to kernel driver
Sun Mar 18 15:51:47 2018 daemon.info hostapd: wlan0: RADIUS Accounting server 192.168.200.1:1813
Sun Mar 18 15:51:47 2018 daemon.notice hostapd: connect[radius]: Network unreachable
Sun Mar 18 15:51:47 2018 daemon.info hostapd: wlan0: RADIUS No accounting server configured
Sun Mar 18 15:51:47 2018 daemon.notice netifd: lan (522): udhcpc: started, v1.25.1
Sun Mar 18 15:51:47 2018 daemon.err hostapd: Interface initialization failed
Sun Mar 18 15:51:47 2018 daemon.notice hostapd: wlan0: interface state COUNTRY_UPDATE->DISABLED
Sun Mar 18 15:51:47 2018 daemon.notice hostapd: wlan0: AP-DISABLED
Sun Mar 18 15:51:47 2018 daemon.err hostapd: wlan0: Unable to setup interface.
Sun Mar 18 15:51:47 2018 daemon.notice hostapd: wlan0: interface state DISABLED->DISABLED
Sun Mar 18 15:51:47 2018 daemon.notice hostapd: wlan0: AP-DISABLED
Sun Mar 18 15:51:47 2018 daemon.notice hostapd: wlan0: CTRL-EVENT-TERMINATING
Sun Mar 18 15:51:47 2018 daemon.err hostapd: hostapd_free_hapd_data: Interface wlan0 wasn't started
Sun Mar 18 15:51:47 2018 daemon.notice hostapd: nl80211: deinit ifname=wlan0 disabled_11b_rates=0
Sun Mar 18 15:51:47 2018 daemon.notice netifd: lan (522): udhcpc: sending discover
Sun Mar 18 15:51:47 2018 kern.info kernel: [    9.706954] device wlan0 left promiscuous mode
Sun Mar 18 15:51:47 2018 kern.info kernel: [    9.713586] br-lan: port 2(wlan0) entered disabled state
Sun Mar 18 15:51:47 2018 daemon.notice netifd: lan (522): udhcpc: sending select for 192.168.200.100
Sun Mar 18 15:51:47 2018 daemon.notice netifd: lan (522): udhcpc: lease of 192.168.200.100 obtained, lease time 604800
Sun Mar 18 15:51:48 2018 daemon.notice hostapd: ELOOP: remaining socket: sock=19 eloop_data=0x76e95c60 user_data=0 handler=0x3e654
Sun Mar 18 15:51:48 2018 daemon.notice netifd: Interface 'lan' is now up
Sun Mar 18 15:51:48 2018 daemon.notice netifd: wlan0 (362): cat: can't open '/var/run/wifi-phy0.pid': No such file or directory
Sun Mar 18 15:51:48 2018 daemon.notice netifd: wlan0 (362): Command failed: Invalid argument
Sun Mar 18 15:51:48 2018 daemon.notice netifd: wlan0 (362): Device setup failed: HOSTAPD_START_FAILED
Sun Mar 18 15:51:48 2018 user.notice firewall: Reloading firewall due to ifup of lan (br-lan)
Sun Mar 18 15:51:48 2018 daemon.notice netifd: wlan0 (579): command failed: No error information (-524)
Sun Mar 18 15:51:48 2018 daemon.info dnsmasq[607]: started, version 2.78 cachesize 150
Sun Mar 18 15:51:48 2018 daemon.info dnsmasq[607]: DNS service limited to local subnets
Sun Mar 18 15:51:48 2018 daemon.info dnsmasq[607]: compile time options: IPv6 GNU-getopt no-DBus no-i18n no-IDN DHCP no-DHCPv6 no-Lua TFTP no-conntrack no-ipset no-auth no-DNSSEC no-ID loop-detect inotify
Sun Mar 18 15:51:48 2018 daemon.info dnsmasq[607]: using local addresses only for domain lan
Sun Mar 18 15:51:48 2018 daemon.info dnsmasq[607]: reading /tmp/resolv.conf.auto
Sun Mar 18 15:51:48 2018 daemon.info dnsmasq[607]: using local addresses only for domain lan
Sun Mar 18 15:51:48 2018 daemon.info dnsmasq[607]: using nameserver 192.168.200.2#53
Sun Mar 18 15:51:48 2018 daemon.info dnsmasq[607]: using nameserver 192.168.200.2#53
Sun Mar 18 15:51:48 2018 daemon.info dnsmasq[607]: read /etc/hosts - 4 addresses
Sun Mar 18 15:51:48 2018 daemon.info dnsmasq[607]: read /tmp/hosts/dhcp.cfg02411c - 1 addresses
Sun Mar 18 15:51:49 2018 kern.info kernel: [   11.586845] br-lan: port 1(eth0) entered forwarding state
Sun Mar 18 15:51:49 2018 daemon.info odhcpd[310]: Using a RA lifetime of 0 seconds on br-lan
Sun Mar 18 15:51:49 2018 authpriv.info dropbear[684]: Not backgrounding
Sun Mar 18 16:00:46 2018 daemon.info dnsmasq[607]: read /etc/hosts - 4 addresses
Sun Mar 18 16:00:46 2018 daemon.info dnsmasq[607]: read /tmp/hosts/dhcp.cfg02411c - 1 addresses

and I can ping radius server from open wrt ...

(Last edited by arti107 on 18 Mar 2018, 17:11)

is there any other way to get more detailed log outputs?

Sun Mar 18 15:51:48 2018 daemon.notice netifd: wlan0 (362): Device setup failed: HOSTAPD_START_FAILED

That is seriously bad.

It appears that you have a Broadcom wifi device and driver.  Support for these is limited.  802.11x may be one of the things that is not possible.

neh ... 802.11x is suported by many cards with this chip. it supports WPA2 so

however this spec is not mentioning it at all   but it mention 802.11r

http://www.cypress.com/file/298076/download
my main goal is 802.11r ... it actually gives very same error output ...

Rasbery pi3 B have build in wi-fi with Access-Point so it should work

there is a problem with my config, 4 sure. I dont know what im doing wrong  
Im just wondering how i can get more granular output of them logs and see exactly what command is not executed

if you read earlier, prior to HOSTAPD_START_FAILED ... you will see numer of things that leaded to filed interface, it starts with failed command than Country update which has something to do with radio frequencies settings, apparently this is crucial for interface to start but resources and information online is very limited  :

Sun Mar 18 15:51:45 2018 daemon.notice netifd: wlan0 (362): command failed: No error information (-524)
Sun Mar 18 15:51:46 2018 daemon.info procd: - init complete -
Sun Mar 18 15:51:46 2018 daemon.notice netifd: wlan0 (362): command failed: Not supported (-95)
Sun Mar 18 15:51:46 2018 daemon.notice netifd: wlan0 (362): command failed: I/O error (-5)
...
Sun Mar 18 15:51:47 2018 daemon.err hostapd: Configuration file: /var/run/hostapd-phy0.conf
...
Sun Mar 18 15:51:47 2018 daemon.notice hostapd: wlan0: interface state UNINITIALIZED->COUNTRY_UPDATE
Sun Mar 18 15:51:47 2018 daemon.warn hostapd: wlan0: Could not connect to kernel driver
Sun Mar 18 15:51:47 2018 daemon.err hostapd: Interface initialization failed
Sun Mar 18 15:51:47 2018 daemon.notice hostapd: wlan0: interface state COUNTRY_UPDATE->DISABLED
Sun Mar 18 15:51:47 2018 daemon.notice hostapd: wlan0: AP-DISABLED
Sun Mar 18 15:51:47 2018 daemon.err hostapd: wlan0: Unable to setup interface.
Sun Mar 18 15:51:47 2018 daemon.notice hostapd: wlan0: interface state DISABLED->DISABLED
Sun Mar 18 15:51:47 2018 daemon.notice hostapd: wlan0: AP-DISABLED
Sun Mar 18 15:51:47 2018 daemon.notice hostapd: wlan0: CTRL-EVENT-TERMINATING
Sun Mar 18 15:51:47 2018 daemon.err hostapd: hostapd_free_hapd_data: Interface wlan0 wasn't started
Sun Mar 18 15:51:47 2018 daemon.notice hostapd: nl80211: deinit ifname=wlan0 disabled_11b_rates=0
Sun Mar 18 15:51:47 2018 daemon.notice netifd: lan (522): udhcpc: sending discover
Sun Mar 18 15:51:47 2018 kern.info kernel: [    9.706954] device wlan0 left promiscuous mode
Sun Mar 18 15:51:47 2018 kern.info kernel: [    9.713586] br-lan: port 2(wlan0) entered disabled state
Sun Mar 18 15:51:47 2018 daemon.notice netifd: lan (522): udhcpc: sending select for 192.168.200.100
Sun Mar 18 15:51:47 2018 daemon.notice netifd: lan (522): udhcpc: lease of 192.168.200.100 obtained, lease time 604800
Sun Mar 18 15:51:48 2018 daemon.notice hostapd: ELOOP: remaining socket: sock=19 eloop_data=0x76e95c60 user_data=0 handler=0x3e654
Sun Mar 18 15:51:48 2018 daemon.notice netifd: Interface 'lan' is now up
Sun Mar 18 15:51:48 2018 daemon.notice netifd: wlan0 (362): cat: can't open '/var/run/wifi-phy0.pid': No such file or directory
Sun Mar 18 15:51:48 2018 daemon.notice netifd: wlan0 (362): Command failed: Invalid argument
Sun Mar 18 15:51:48 2018 daemon.notice netifd: wlan0 (362): Device setup failed: HOSTAPD_START_FAILED

https://www.bunver.com/connecting-raspb … s-network/
https://raspberrypi.stackexchange.com/q … ss-hotspot

well there are few others that had similar problems with raspberry + radius, Im not sure if there is a difference between connecting only and being the AP (authenticator)  ... and they weren't using openWrt but just hostapd on jessie, would it make a difference?

It gave me a small hint: problem with Radius server connectivity might have something to do with the lack of EAPOverLan setting, which is the configuration problem. 

since I got wpad instead of (hostapd + wpa_supp) and wpad is onle the warper.  how do I input commands? What is the correct syntax? can I use exactly same commands for my /etc/config/wireless as I would with hostapd but with 'option' as a prefix for each command?

##################

okay I got it ... everything is here

https://wiki.openwrt.org/doc/uci/wirele … ccesspoint
https://wiki.openwrt.org/doc/howto/wire … rity.8021x

(Last edited by arti107 on 20 Mar 2018, 04:40)

okay so Im back to connection problems ... device is connecting and not holding connection. Maybe logs will help to identify the problem ...

Wed Mar 21 16:08:06 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:08:06 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.11: binding station to interface 'wlan0'
Wed Mar 21 16:08:06 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: old identity 'user1' updated with User-Name from Access-Accept 'user1'
Wed Mar 21 16:08:06 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=3 id=238 len=4) from RADIUS server: EAP Success
Wed Mar 21 16:08:06 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 238)
Wed Mar 21 16:08:06 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 WPA: sending 1/4 msg of 4-Way Handshake
Wed Mar 21 16:08:06 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 WPA: received EAPOL-Key frame (2/4 Pairwise)
Wed Mar 21 16:08:06 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 WPA: sending 3/4 msg of 4-Way Handshake
Wed Mar 21 16:08:06 2018 daemon.info hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.11: disassociated
Wed Mar 21 16:08:06 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 WPA: event 2 notification
Wed Mar 21 16:08:14 2018 daemon.info hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.11: associated
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 WPA: event 1 notification
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: start authentication
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 WPA: start authentication
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: unauthorizing port
Wed Mar 21 16:08:14 2018 daemon.notice hostapd: wlan0: CTRL-EVENT-EAP-STARTED 7c:0b:c6:32:93:e7
Wed Mar 21 16:08:14 2018 daemon.notice hostapd: wlan0: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=1
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 164)
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=164 len=10) from STA: EAP Response-Identity (1)
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: STA identity 'user1'
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: RADIUS Received 64 bytes from RADIUS server
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=1 id=165 len=6) from RADIUS server: EAP-Request-PEAP (25)
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 165)
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=165 len=196) from STA: EAP Response-PEAP (25)
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: RADIUS Received 1068 bytes from RADIUS server
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=1 id=166 len=1004) from RADIUS server: EAP-Request-PEAP (25)
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 166)
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=166 len=6) from STA: EAP Response-PEAP (25)
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: RADIUS Received 199 bytes from RADIUS server
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=1 id=167 len=141) from RADIUS server: EAP-Request-PEAP (25)
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 167)
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=167 len=144) from STA: EAP Response-PEAP (25)
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: RADIUS Received 123 bytes from RADIUS server
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=1 id=168 len=65) from RADIUS server: EAP-Request-PEAP (25)
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 168)
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=168 len=6) from STA: EAP Response-PEAP (25)
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: RADIUS Received 101 bytes from RADIUS server
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=1 id=169 len=43) from RADIUS server: EAP-Request-PEAP (25)
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 169)
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=169 len=43) from STA: EAP Response-PEAP (25)
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: RADIUS Received 133 bytes from RADIUS server
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=1 id=170 len=75) from RADIUS server: EAP-Request-PEAP (25)
Wed Mar 21 16:08:14 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 170)
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=170 len=107) from STA: EAP Response-PEAP (25)
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: RADIUS Received 149 bytes from RADIUS server
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=1 id=171 len=91) from RADIUS server: EAP-Request-PEAP (25)
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 171)
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=171 len=43) from STA: EAP Response-PEAP (25)
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: RADIUS Received 101 bytes from RADIUS server
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=1 id=172 len=43) from RADIUS server: EAP-Request-PEAP (25)
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 172)
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=172 len=43) from STA: EAP Response-PEAP (25)
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: RADIUS Received 167 bytes from RADIUS server
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.11: binding station to interface 'wlan0'
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: old identity 'user1' updated with User-Name from Access-Accept 'user1'
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=3 id=172 len=4) from RADIUS server: EAP Success
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 172)
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 WPA: sending 1/4 msg of 4-Way Handshake
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 WPA: received EAPOL-Key frame (2/4 Pairwise)
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 WPA: sending 3/4 msg of 4-Way Handshake
Wed Mar 21 16:08:15 2018 daemon.info hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.11: disassociated
Wed Mar 21 16:08:15 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 WPA: event 2 notification
Wed Mar 21 16:08:30 2018 daemon.info hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.11: associated
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 WPA: event 1 notification
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: start authentication
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 WPA: start authentication
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: unauthorizing port
Wed Mar 21 16:08:30 2018 daemon.notice hostapd: wlan0: CTRL-EVENT-EAP-STARTED 7c:0b:c6:32:93:e7
Wed Mar 21 16:08:30 2018 daemon.notice hostapd: wlan0: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=1
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 107)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=107 len=10) from STA: EAP Response-Identity (1)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: STA identity 'user1'
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Received 64 bytes from RADIUS server
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=1 id=108 len=6) from RADIUS server: EAP-Request-PEAP (25)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 108)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=108 len=196) from STA: EAP Response-PEAP (25)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Received 1068 bytes from RADIUS server
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=1 id=109 len=1004) from RADIUS server: EAP-Request-PEAP (25)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 109)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=109 len=6) from STA: EAP Response-PEAP (25)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Received 199 bytes from RADIUS server
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=1 id=110 len=141) from RADIUS server: EAP-Request-PEAP (25)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 110)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=110 len=144) from STA: EAP Response-PEAP (25)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Received 123 bytes from RADIUS server
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=1 id=111 len=65) from RADIUS server: EAP-Request-PEAP (25)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 111)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=111 len=6) from STA: EAP Response-PEAP (25)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Received 101 bytes from RADIUS server
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=1 id=112 len=43) from RADIUS server: EAP-Request-PEAP (25)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 112)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=112 len=43) from STA: EAP Response-PEAP (25)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Received 133 bytes from RADIUS server
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=1 id=113 len=75) from RADIUS server: EAP-Request-PEAP (25)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 113)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=113 len=107) from STA: EAP Response-PEAP (25)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Received 149 bytes from RADIUS server
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=1 id=114 len=91) from RADIUS server: EAP-Request-PEAP (25)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 114)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=114 len=43) from STA: EAP Response-PEAP (25)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Received 101 bytes from RADIUS server
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=1 id=115 len=43) from RADIUS server: EAP-Request-PEAP (25)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 115)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=115 len=43) from STA: EAP Response-PEAP (25)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Received 167 bytes from RADIUS server
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.11: binding station to interface 'wlan0'
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: old identity 'user1' updated with User-Name from Access-Accept 'user1'
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=3 id=115 len=4) from RADIUS server: EAP Success
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 115)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 WPA: sending 1/4 msg of 4-Way Handshake
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 WPA: received EAPOL-Key frame (2/4 Pairwise)
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 WPA: sending 3/4 msg of 4-Way Handshake
Wed Mar 21 16:08:30 2018 daemon.info hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.11: disassociated
Wed Mar 21 16:08:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 WPA: event 2 notification
Wed Mar 21 16:08:57 2018 daemon.info odhcpd[317]: Using a RA lifetime of 0 seconds on br-lan
Wed Mar 21 16:09:16 2018 user.info autossh[416]: starting ssh (count 19)
Wed Mar 21 16:09:16 2018 user.info autossh[416]: ssh child pid is 1048
Wed Mar 21 16:09:16 2018 user.info autossh[416]: ssh exited with error status 1; restarting ssh
Wed Mar 21 16:09:23 2018 daemon.debug hostapd: wlan0: WPA rekeying GTK
Wed Mar 21 16:09:30 2018 daemon.info hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.11: associated
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 WPA: event 1 notification
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: start authentication
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 WPA: start authentication
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: unauthorizing port
Wed Mar 21 16:09:30 2018 daemon.notice hostapd: wlan0: CTRL-EVENT-EAP-STARTED 7c:0b:c6:32:93:e7
Wed Mar 21 16:09:30 2018 daemon.notice hostapd: wlan0: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=1
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 65)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=65 len=10) from STA: EAP Response-Identity (1)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: STA identity 'user1'
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Received 64 bytes from RADIUS server
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=1 id=66 len=6) from RADIUS server: EAP-Request-PEAP (25)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 66)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=66 len=196) from STA: EAP Response-PEAP (25)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Received 1068 bytes from RADIUS server
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=1 id=67 len=1004) from RADIUS server: EAP-Request-PEAP (25)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 67)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=67 len=6) from STA: EAP Response-PEAP (25)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Received 199 bytes from RADIUS server
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=1 id=68 len=141) from RADIUS server: EAP-Request-PEAP (25)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 68)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=68 len=144) from STA: EAP Response-PEAP (25)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Received 123 bytes from RADIUS server
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=1 id=69 len=65) from RADIUS server: EAP-Request-PEAP (25)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 69)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=69 len=6) from STA: EAP Response-PEAP (25)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Received 101 bytes from RADIUS server
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=1 id=70 len=43) from RADIUS server: EAP-Request-PEAP (25)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 70)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=70 len=43) from STA: EAP Response-PEAP (25)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Received 133 bytes from RADIUS server
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=1 id=71 len=75) from RADIUS server: EAP-Request-PEAP (25)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 71)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=71 len=107) from STA: EAP Response-PEAP (25)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Received 149 bytes from RADIUS server
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=1 id=72 len=91) from RADIUS server: EAP-Request-PEAP (25)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 72)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=72 len=43) from STA: EAP Response-PEAP (25)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Received 101 bytes from RADIUS server
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=1 id=73 len=43) from RADIUS server: EAP-Request-PEAP (25)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 73)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: received EAP packet (code=2 id=73 len=43) from STA: EAP Response-PEAP (25)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Sending RADIUS message to authentication server
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Next RADIUS client retransmit in 3 seconds
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Received 167 bytes from RADIUS server
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: RADIUS Received RADIUS message
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.11: binding station to interface 'wlan0'
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: old identity 'user1' updated with User-Name from Access-Accept 'user1'
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: decapsulated EAP packet (code=3 id=73 len=4) from RADIUS server: EAP Success
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.1X: Sending EAP Packet (identifier 73)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 WPA: sending 1/4 msg of 4-Way Handshake
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 WPA: received EAPOL-Key frame (2/4 Pairwise)
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 WPA: sending 3/4 msg of 4-Way Handshake
Wed Mar 21 16:09:30 2018 daemon.info hostapd: wlan0: STA 7c:0b:c6:32:93:e7 IEEE 802.11: disassociated
Wed Mar 21 16:09:30 2018 daemon.debug hostapd: wlan0: STA 7c:0b:c6:32:93:e7 WPA: event 2 notification

Apparently, winRadius is showing that password is wrong, is there any other loction in freeradius than clients.conf where secret can be altered?

continuing this uneven fight

current situation ... connecting clients are not binding with the interface due to lack of replay from radius server, doing wireshark testing revealed that message 4/4 is not being send back to authenticator (AP). and message 3/4 is being trnasported many times which causes this "bouncing" effect .

So this answers The main question. This can be closed.

(Last edited by arti107 on 22 Mar 2018, 01:10)