Wifi problem on RPI B+ V1.0x running stretch (race condition?)

[vthielen]

I am trying to use my RPI B+ V1.0x as a WiFi access point, using a WiPi USB stick.
System info is: Linux 4.9.59+ #1047 armv6l GNU/Linux

I followed the instructions on:
https://github.com/SurferTim/documentat ... s-point.md
But that didn't work (ifconfig shows wlan0 doesn't get any IP address)

Then I followed the advice of David Pooley and Pierz on this page:
https://raspberrypi.stackexchange.com/q ... ng-stretch

After rebooting, ifconfig shows wlan0 gets the IP address mentioned in dhcpcd.conf, the wifi shows up with name and pasword mentioned in hostapd.conf, And I can surf to the simpleHttpServer that is running on it.

The problem is that after rebooting, it doen't work any more (ifconfig shows no IP for wlan0 and my phone doesn't find the access point any more)

I think I read something about a race condition in one of the many related solutions (I've been looking for a solution for 2 days) that I found using google.
Might this be the case here?

Thanks for any help!

Changes to the files that I touched are shown below:

[email protected]:~# cat /etc/dhcpcd.conf
interface eth0

static ip_address=30.0.0.39/8
static routers=30.0.0.1
static domain_name_servers=30.0.0.76 8.8.8.8 8.8.4.4

#for Wifi access point
interface wlan0

static ip_address=192.168.4.1/24
static routers=192.168.0.1
static domain_name_servers=192.168.0.1


[email protected]:~# cat /etc/network/interfaces
# interfaces(5) file used by ifup(8) and ifdown(8)

# Please note that this file is written to be used with dhcpcd
# For static IP, consult /etc/dhcpcd.conf and 'man dhcpcd.conf'

# Include files from /etc/network/interfaces.d:
source-directory /etc/network/interfaces.d
allow-hotplug wlan0
iface wlan0 inet manual
wpa-conf /etc/wpa_supplicant/wpa_supplicant.conf


[email protected]:~# cat /etc/wpa_supplicant/wpa_supplicant.conf
country=BE
ctrl_interface=DIR=/var/run/wpa_supplicant GROUP=netdev
update_config=1
network={
ssid="nameB"
psk="passwdB"
}


[email protected]:~# cat /etc/hostapd/hostapd.conf
interface=wlan0
driver=nl80211
ssid=nameA
hw_mode=g
channel=7
wmm_enabled=0
macaddr_acl=0
auth_algs=1
ignore_broadcast_ssid=0
wpa=2
wpa_passphrase=passwdA
wpa_key_mgmt=WPA-PSK
wpa_pairwise=TKIP
rsn_pairwise=CCMP


[email protected]:~# cat /etc/dnsmasq.conf
interface=wlan0 # Use the require wireless interface - usually wlan0
dhcp-range=192.168.4.2,192.168.4.20,255.255.255.0,24h


uncommented this line in in /etc/sysctl.conf
# Uncomment the next line to enable packet forwarding for IPv4
net.ipv4.ip_forward=1


Changed to this line in /etc/default/hostapd:
DAEMON_CONF="/etc/hostapd/hostapd.conf"


Added this line to /etc/rc.local:
iptables-restore < /etc/iptables.ipv4.nat

[vthielen]

After a few reboots, with WIFI seemingly randomly ending up working or not working, I compared the output of 'service --status-all' in both cases: They are exactly the same

I also dumped the output of 'dmesg' in both cases: output is below for both cases:

NOT WORKING:

[ 0.000000] Booting Linux on physical CPU 0x0
[ 0.000000] Linux version 4.9.59+ ([email protected]) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611) ) #1047 Sun Oct 29 11:47:10 GMT 2017
[ 0.000000] CPU: ARMv6-compatible processor [410fb767] revision 7 (ARMv7), cr=00c5387d
[ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT nonaliasing instruction cache
[ 0.000000] OF: fdt:Machine model: Raspberry Pi Model B Plus Rev 1.2
[ 0.000000] cma: Reserved 8 MiB at 0x1b400000
[ 0.000000] Memory policy: Data cache writeback
[ 0.000000] On node 0 totalpages: 114688
[ 0.000000] free_area_init_node: node 0, pgdat c0914e10, node_mem_map db010000
[ 0.000000] Normal zone: 1008 pages used for memmap
[ 0.000000] Normal zone: 0 pages reserved
[ 0.000000] Normal zone: 114688 pages, LIFO batch:31
[ 0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
[ 0.000000] pcpu-alloc: [0] 0
[ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 113680
[ 0.000000] Kernel command line: bcm2708_fb.fbwidth=656 bcm2708_fb.fbheight=416 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x1ec00000 vc_mem.mem_size=0x20000000 dwc_otg.lpm_enable=0 console=ttyAMA0,115200 console=tty1 root=PARTUUID=f3a2a455-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait
[ 0.000000] PID hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
[ 0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
[ 0.000000] Memory: 435944K/458752K available (5950K kernel code, 491K rwdata, 1948K rodata, 396K init, 725K bss, 14616K reserved, 8192K cma-reserved)
[ 0.000000] Virtual kernel memory layout:
vector : 0xffff0000 - 0xffff1000 ( 4 kB)
fixmap : 0xffc00000 - 0xfff00000 (3072 kB)
vmalloc : 0xdc800000 - 0xff800000 ( 560 MB)
lowmem : 0xc0000000 - 0xdc000000 ( 448 MB)
modules : 0xbf000000 - 0xc0000000 ( 16 MB)
.text : 0xc0008000 - 0xc05d7a48 (5951 kB)
.init : 0xc0841000 - 0xc08a4000 ( 396 kB)
.data : 0xc08a4000 - 0xc091ef48 ( 492 kB)
.bss : 0xc091ef48 - 0xc09d4648 ( 726 kB)
[ 0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[ 0.000000] NR_IRQS:16 nr_irqs:16 16
[ 0.000031] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483647500ns
[ 0.000075] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275 ns
[ 0.000176] bcm2835: system timer (irq = 27)
[ 0.000646] Console: colour dummy device 80x30
[ 0.001386] console [tty1] enabled
[ 0.001441] Calibrating delay loop... 697.95 BogoMIPS (lpj=3489792)
[ 0.060364] pid_max: default: 32768 minimum: 301
[ 0.060828] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[ 0.060899] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[ 0.062192] Disabling memory control group subsystem
[ 0.062400] CPU: Testing write buffer coherency: ok
[ 0.062504] ftrace: allocating 21715 entries in 64 pages
[ 0.180776] Setting up static identity map for 0x8200 - 0x8238
[ 0.182852] devtmpfs: initialized
[ 0.192339] VFP support v0.3: implementor 41 architecture 1 part 20 variant b rev 5
[ 0.192865] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[ 0.192965] futex hash table entries: 256 (order: -1, 3072 bytes)
[ 0.194291] pinctrl core: initialized pinctrl subsystem
[ 0.195794] NET: Registered protocol family 16
[ 0.198244] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[ 0.207851] hw-breakpoint: found 6 breakpoint and 1 watchpoint registers.
[ 0.207943] hw-breakpoint: maximum watchpoint size is 4 bytes.
[ 0.208083] Serial: AMBA PL011 UART driver
[ 0.211037] bcm2835-mbox 2000b880.mailbox: mailbox enabled
[ 0.261413] bcm2835-dma 20007000.dma: DMA legacy API manager at dc80d000, dmachans=0x1
[ 0.264175] SCSI subsystem initialized
[ 0.264506] usbcore: registered new interface driver usbfs
[ 0.264678] usbcore: registered new interface driver hub
[ 0.264917] usbcore: registered new device driver usb
[ 0.270865] raspberrypi-firmware soc:firmware: Attached to firmware from 2017-10-24 17:09
[ 0.272812] clocksource: Switched to clocksource timer
[ 0.327007] VFS: Disk quotas dquot_6.6.0
[ 0.327209] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[ 0.327580] FS-Cache: Loaded
[ 0.327975] CacheFiles: Loaded
[ 0.347399] NET: Registered protocol family 2
[ 0.348829] TCP established hash table entries: 4096 (order: 2, 16384 bytes)
[ 0.348987] TCP bind hash table entries: 4096 (order: 2, 16384 bytes)
[ 0.349120] TCP: Hash tables configured (established 4096 bind 4096)
[ 0.349256] UDP hash table entries: 256 (order: 0, 4096 bytes)
[ 0.349323] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
[ 0.349681] NET: Registered protocol family 1
[ 0.350490] RPC: Registered named UNIX socket transport module.
[ 0.350565] RPC: Registered udp transport module.
[ 0.350605] RPC: Registered tcp transport module.
[ 0.350640] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 0.351769] hw perfevents: enabled with armv6_1176 PMU driver, 3 counters available
[ 0.354405] workingset: timestamp_bits=14 max_order=17 bucket_order=3
[ 0.375161] FS-Cache: Netfs 'nfs' registered for caching
[ 0.377009] NFS: Registering the id_resolver key type
[ 0.377121] Key type id_resolver registered
[ 0.377166] Key type id_legacy registered
[ 0.381652] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
[ 0.382124] io scheduler noop registered
[ 0.382189] io scheduler deadline registered (default)
[ 0.382695] io scheduler cfq registered
[ 0.388724] BCM2708FB: allocated DMA memory 5b500000
[ 0.388857] BCM2708FB: allocated DMA channel 0 @ dc80d000
[ 0.397166] Console: switching to colour frame buffer device 82x26
[ 0.407553] bcm2835-rng 20104000.rng: hwrng registered
[ 0.410345] vc-mem: phys_addr:0x00000000 mem_base=0x1ec00000 mem_size:0x20000000(512 MiB)
[ 0.416766] vc-sm: Videocore shared memory driver
[ 0.444352] brd: module loaded
[ 0.459730] loop: module loaded
[ 0.462503] Loading iSCSI transport class v2.0-870.
[ 0.466180] usbcore: registered new interface driver smsc95xx
[ 0.468928] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[ 0.699833] Core Release: 2.80a
[ 0.702508] Setting default values for core params
[ 0.705225] Finished setting default values for core params
[ 0.908344] Using Buffer DMA mode
[ 0.910954] Periodic Transfer Interrupt Enhancement - disabled
[ 0.913605] Multiprocessor Interrupt Enhancement - disabled
[ 0.916253] OTG VER PARAM: 0, OTG VER FLAG: 0
[ 0.918936] Dedicated Tx FIFOs mode
[ 0.922210] WARN::dwc_otg_hcd_init:1032: FIQ DMA bounce buffers: virt = 0xdb514000 dma = 0x5b514000 len=9024
[ 0.927838] FIQ FSM acceleration enabled for :
Non-periodic Split Transactions
Periodic Split Transactions
High-Speed Isochronous Endpoints
Interrupt/Control Split Transaction hack enabled
[ 0.941012] dwc_otg: Microframe scheduler enabled
[ 0.941150] WARN::hcd_init_fiq:459: FIQ on core 0 at 0xc0451694
[ 0.943768] WARN::hcd_init_fiq:460: FIQ ASM at 0xc0451970 length 36
[ 0.946399] WARN::hcd_init_fiq:486: MPHI regs_base at 0xdc8a5000
[ 0.949180] dwc_otg 20980000.usb: DWC OTG Controller
[ 0.951881] dwc_otg 20980000.usb: new USB bus registered, assigned bus number 1
[ 0.954737] dwc_otg 20980000.usb: irq 56, io mem 0x00000000
[ 0.957427] Init: Port Power? op_state=1
[ 0.959959] Init: Power Port (0)
[ 0.962879] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[ 0.965552] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 0.968166] usb usb1: Product: DWC OTG Controller
[ 0.970724] usb usb1: Manufacturer: Linux 4.9.59+ dwc_otg_hcd
[ 0.973357] usb usb1: SerialNumber: 20980000.usb
[ 0.977081] hub 1-0:1.0: USB hub found
[ 0.979693] hub 1-0:1.0: 1 port detected
[ 0.983123] dwc_otg: FIQ enabled
[ 0.983136] dwc_otg: NAK holdoff enabled
[ 0.983142] dwc_otg: FIQ split-transaction FSM enabled
[ 0.983162] Module dwc_common_port init
[ 0.983670] usbcore: registered new interface driver usb-storage
[ 0.986669] mousedev: PS/2 mouse device common for all mice
[ 0.990838] bcm2835-wdt 20100000.watchdog: Broadcom BCM2835 watchdog timer
[ 0.994080] bcm2835-cpufreq: min=700000 max=700000
[ 0.997332] sdhci: Secure Digital Host Controller Interface driver
[ 1.000016] sdhci: Copyright(c) Pierre Ossman
[ 1.003162] sdhost-bcm2835 20202000.sdhost: could not get clk, deferring probe
[ 1.006274] sdhci-pltfm: SDHCI platform and OF driver helper
[ 1.009759] ledtrig-cpu: registered to indicate activity on CPUs
[ 1.012731] hidraw: raw HID events driver (C) Jiri Kosina
[ 1.016010] usbcore: registered new interface driver usbhid
[ 1.018805] usbhid: USB HID core driver
[ 1.022758] vchiq: vchiq_init_state: slot_zero = 0xdb580000, is_master = 0
[ 1.027654] [vc_sm_connected_init]: start
[ 1.038049] [vc_sm_connected_init]: end - returning 0
[ 1.041500] Initializing XFRM netlink socket
[ 1.044359] NET: Registered protocol family 17
[ 1.047246] Key type dns_resolver registered
[ 1.051664] registered taskstats version 1
[ 1.061732] uart-pl011 20201000.serial: cts_event_workaround enabled
[ 1.065006] 20201000.serial: ttyAMA0 at MMIO 0x20201000 (irq = 81, base_baud = 0) is a PL011 rev2
[ 1.890340] console [ttyAMA0] enabled
[ 1.899379] sdhost: log_buf @ db513000 (5b513000)
[ 1.982895] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
[ 1.991411] of_cfs_init
[ 2.016909] of_cfs_init: OK
[ 2.023377] Waiting for root device PARTUUID=f3a2a455-02...
[ 2.033203] Indeed it is in host mode hprt0 = 00021501
[ 2.102049] random: fast init done
[ 2.150750] mmc0: host does not support reading read-only switch, assuming write-enable
[ 2.166495] mmc0: new high speed SDHC card at address 59b4
[ 2.176390] mmcblk0: mmc0:59b4 USD 3.75 GiB
[ 2.185900] mmcblk0: p1 p2
[ 2.242901] usb 1-1: new high-speed USB device number 2 using dwc_otg
[ 2.252410] Indeed it is in host mode hprt0 = 00001101
[ 2.334558] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[ 2.348746] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[ 2.369624] devtmpfs: mounted
[ 2.377029] Freeing unused kernel memory: 396K
[ 2.384471] This architecture does not have kernel memory protection.
[ 2.493404] usb 1-1: New USB device found, idVendor=0424, idProduct=9514
[ 2.503570] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[ 2.515632] hub 1-1:1.0: USB hub found
[ 2.522951] hub 1-1:1.0: 5 ports detected
[ 2.852929] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
[ 2.966229] systemd[1]: System time before build time, advancing clock.
[ 2.993417] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00
[ 3.003927] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[ 3.020376] smsc95xx v1.0.5
[ 3.127582] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-20980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:48:41:45
[ 3.151798] NET: Registered protocol family 10
[ 3.183904] ip_tables: (C) 2000-2006 Netfilter Core Team
[ 3.236163] systemd[1]: systemd 232 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN)
[ 3.263843] usb 1-1.4: new high-speed USB device number 4 using dwc_otg
[ 3.274997] systemd[1]: Detected architecture arm.
[ 3.305014] systemd[1]: Set hostname to <CM0019>.
[ 3.431580] usb 1-1.4: New USB device found, idVendor=148f, idProduct=5370
[ 3.441829] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 3.452418] usb 1-1.4: Product: 802.11 n WLAN
[ 3.459981] usb 1-1.4: Manufacturer: Ralink
[ 3.467244] usb 1-1.4: SerialNumber: 1.0
[ 3.652499] uart-pl011 20201000.serial: no DMA platform data
[ 4.410050] systemd[1]: [email protected]: Cannot add dependency job, ignoring: Unit [email protected] is masked.
[ 4.440782] systemd[1]: Listening on /dev/initctl Compatibility Named Pipe.
[ 4.456688] systemd[1]: Listening on fsck to fsckd communication Socket.
[ 4.471425] systemd[1]: Listening on udev Kernel Socket.
[ 4.484810] systemd[1]: Listening on udev Control Socket.
[ 4.498871] systemd[1]: Created slice User and Session Slice.
[ 4.512708] systemd[1]: Listening on Journal Socket.
[ 6.868030] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[ 8.992716] systemd-journald[114]: Received request to flush runtime journal from PID 1
[ 9.892576] gpiomem-bcm2835 20200000.gpiomem: Initialised: Registers at 0x20200000
[ 15.537951] usb 1-1.4: reset high-speed USB device number 4 using dwc_otg
[ 15.738025] ieee80211 phy0: rt2x00_set_rt: Info - RT chipset 5390, rev 0502 detected
[ 16.358952] Adding 102396k swap on /var/swap. Priority:-1 extents:1 across:102396k SSFS
[ 16.523697] ieee80211 phy0: rt2x00_set_rf: Info - RF chipset 5370 detected
[ 16.663359] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
[ 16.693343] ieee80211 phy0: Selected rate control algorithm 'minstrel_ht'
[ 16.696453] usbcore: registered new interface driver rt2800usb
[ 18.251728] smsc95xx 1-1.1:1.0 eth0: link up, 100Mbps, full-duplex, lpa 0x43E1
[ 18.907607] ieee80211 phy0: rt2x00lib_request_firmware: Info - Loading firmware file 'rt2870.bin'
[ 18.919621] ieee80211 phy0: rt2x00lib_request_firmware: Info - Firmware detected - version: 0.36
[ 19.395664] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[ 26.245393] nf_conntrack version 0.5.0 (7168 buckets, 28672 max)
[ 28.607416] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[ 29.245471] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[ 57.062339] random: crng init done


WORKING:

[ 0.000000] Booting Linux on physical CPU 0x0
[ 0.000000] Linux version 4.9.59+ ([email protected]) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611) ) #1047 Sun Oct 29 11:47:10 GMT 2017
[ 0.000000] CPU: ARMv6-compatible processor [410fb767] revision 7 (ARMv7), cr=00c5387d
[ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT nonaliasing instruction cache
[ 0.000000] OF: fdt:Machine model: Raspberry Pi Model B Plus Rev 1.2
[ 0.000000] cma: Reserved 8 MiB at 0x1b400000
[ 0.000000] Memory policy: Data cache writeback
[ 0.000000] On node 0 totalpages: 114688
[ 0.000000] free_area_init_node: node 0, pgdat c0914e10, node_mem_map db010000
[ 0.000000] Normal zone: 1008 pages used for memmap
[ 0.000000] Normal zone: 0 pages reserved
[ 0.000000] Normal zone: 114688 pages, LIFO batch:31
[ 0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
[ 0.000000] pcpu-alloc: [0] 0
[ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 113680
[ 0.000000] Kernel command line: bcm2708_fb.fbwidth=656 bcm2708_fb.fbheight=416 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x1ec00000 vc_mem.mem_size=0x20000000 dwc_otg.lpm_enable=0 console=ttyAMA0,115200 console=tty1 root=PARTUUID=f3a2a455-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait
[ 0.000000] PID hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
[ 0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
[ 0.000000] Memory: 435944K/458752K available (5950K kernel code, 491K rwdata, 1948K rodata, 396K init, 725K bss, 14616K reserved, 8192K cma-reserved)
[ 0.000000] Virtual kernel memory layout:
vector : 0xffff0000 - 0xffff1000 ( 4 kB)
fixmap : 0xffc00000 - 0xfff00000 (3072 kB)
vmalloc : 0xdc800000 - 0xff800000 ( 560 MB)
lowmem : 0xc0000000 - 0xdc000000 ( 448 MB)
modules : 0xbf000000 - 0xc0000000 ( 16 MB)
.text : 0xc0008000 - 0xc05d7a48 (5951 kB)
.init : 0xc0841000 - 0xc08a4000 ( 396 kB)
.data : 0xc08a4000 - 0xc091ef48 ( 492 kB)
.bss : 0xc091ef48 - 0xc09d4648 ( 726 kB)
[ 0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[ 0.000000] NR_IRQS:16 nr_irqs:16 16
[ 0.000032] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483647500ns
[ 0.000077] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275 ns
[ 0.000179] bcm2835: system timer (irq = 27)
[ 0.000646] Console: colour dummy device 80x30
[ 0.001390] console [tty1] enabled
[ 0.001446] Calibrating delay loop... 697.95 BogoMIPS (lpj=3489792)
[ 0.060367] pid_max: default: 32768 minimum: 301
[ 0.060832] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[ 0.060906] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[ 0.062205] Disabling memory control group subsystem
[ 0.062414] CPU: Testing write buffer coherency: ok
[ 0.062517] ftrace: allocating 21715 entries in 64 pages
[ 0.180790] Setting up static identity map for 0x8200 - 0x8238
[ 0.182864] devtmpfs: initialized
[ 0.192366] VFP support v0.3: implementor 41 architecture 1 part 20 variant b rev 5
[ 0.192891] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[ 0.192992] futex hash table entries: 256 (order: -1, 3072 bytes)
[ 0.194308] pinctrl core: initialized pinctrl subsystem
[ 0.195815] NET: Registered protocol family 16
[ 0.198271] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[ 0.207836] hw-breakpoint: found 6 breakpoint and 1 watchpoint registers.
[ 0.207931] hw-breakpoint: maximum watchpoint size is 4 bytes.
[ 0.208070] Serial: AMBA PL011 UART driver
[ 0.211015] bcm2835-mbox 2000b880.mailbox: mailbox enabled
[ 0.261407] bcm2835-dma 20007000.dma: DMA legacy API manager at dc80d000, dmachans=0x1
[ 0.264160] SCSI subsystem initialized
[ 0.264488] usbcore: registered new interface driver usbfs
[ 0.264661] usbcore: registered new interface driver hub
[ 0.264900] usbcore: registered new device driver usb
[ 0.270870] raspberrypi-firmware soc:firmware: Attached to firmware from 2017-10-24 17:09
[ 0.272819] clocksource: Switched to clocksource timer
[ 0.327014] VFS: Disk quotas dquot_6.6.0
[ 0.327216] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[ 0.327587] FS-Cache: Loaded
[ 0.327977] CacheFiles: Loaded
[ 0.347367] NET: Registered protocol family 2
[ 0.348784] TCP established hash table entries: 4096 (order: 2, 16384 bytes)
[ 0.348942] TCP bind hash table entries: 4096 (order: 2, 16384 bytes)
[ 0.349075] TCP: Hash tables configured (established 4096 bind 4096)
[ 0.349212] UDP hash table entries: 256 (order: 0, 4096 bytes)
[ 0.349280] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
[ 0.349634] NET: Registered protocol family 1
[ 0.350444] RPC: Registered named UNIX socket transport module.
[ 0.350520] RPC: Registered udp transport module.
[ 0.350558] RPC: Registered tcp transport module.
[ 0.350595] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 0.351726] hw perfevents: enabled with armv6_1176 PMU driver, 3 counters available
[ 0.354373] workingset: timestamp_bits=14 max_order=17 bucket_order=3
[ 0.375129] FS-Cache: Netfs 'nfs' registered for caching
[ 0.376966] NFS: Registering the id_resolver key type
[ 0.377077] Key type id_resolver registered
[ 0.377120] Key type id_legacy registered
[ 0.381609] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
[ 0.382077] io scheduler noop registered
[ 0.382143] io scheduler deadline registered (default)
[ 0.382651] io scheduler cfq registered
[ 0.388695] BCM2708FB: allocated DMA memory 5b500000
[ 0.388830] BCM2708FB: allocated DMA channel 0 @ dc80d000
[ 0.397140] Console: switching to colour frame buffer device 82x26
[ 0.407532] bcm2835-rng 20104000.rng: hwrng registered
[ 0.410323] vc-mem: phys_addr:0x00000000 mem_base=0x1ec00000 mem_size:0x20000000(512 MiB)
[ 0.416762] vc-sm: Videocore shared memory driver
[ 0.444354] brd: module loaded
[ 0.459723] loop: module loaded
[ 0.462514] Loading iSCSI transport class v2.0-870.
[ 0.466200] usbcore: registered new interface driver smsc95xx
[ 0.468948] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[ 0.699842] Core Release: 2.80a
[ 0.702517] Setting default values for core params
[ 0.705234] Finished setting default values for core params
[ 0.908343] Using Buffer DMA mode
[ 0.910948] Periodic Transfer Interrupt Enhancement - disabled
[ 0.913608] Multiprocessor Interrupt Enhancement - disabled
[ 0.916255] OTG VER PARAM: 0, OTG VER FLAG: 0
[ 0.918942] Dedicated Tx FIFOs mode
[ 0.922222] WARN::dwc_otg_hcd_init:1032: FIQ DMA bounce buffers: virt = 0xdb514000 dma = 0x5b514000 len=9024
[ 0.927829] FIQ FSM acceleration enabled for :
Non-periodic Split Transactions
Periodic Split Transactions
High-Speed Isochronous Endpoints
Interrupt/Control Split Transaction hack enabled
[ 0.940986] dwc_otg: Microframe scheduler enabled
[ 0.941124] WARN::hcd_init_fiq:459: FIQ on core 0 at 0xc0451694
[ 0.943732] WARN::hcd_init_fiq:460: FIQ ASM at 0xc0451970 length 36
[ 0.946365] WARN::hcd_init_fiq:486: MPHI regs_base at 0xdc8a5000
[ 0.949143] dwc_otg 20980000.usb: DWC OTG Controller
[ 0.951850] dwc_otg 20980000.usb: new USB bus registered, assigned bus number 1
[ 0.954701] dwc_otg 20980000.usb: irq 56, io mem 0x00000000
[ 0.957380] Init: Port Power? op_state=1
[ 0.959910] Init: Power Port (0)
[ 0.962758] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[ 0.965502] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 0.968140] usb usb1: Product: DWC OTG Controller
[ 0.970703] usb usb1: Manufacturer: Linux 4.9.59+ dwc_otg_hcd
[ 0.973331] usb usb1: SerialNumber: 20980000.usb
[ 0.977044] hub 1-0:1.0: USB hub found
[ 0.979667] hub 1-0:1.0: 1 port detected
[ 0.983088] dwc_otg: FIQ enabled
[ 0.983100] dwc_otg: NAK holdoff enabled
[ 0.983106] dwc_otg: FIQ split-transaction FSM enabled
[ 0.983126] Module dwc_common_port init
[ 0.983628] usbcore: registered new interface driver usb-storage
[ 0.986634] mousedev: PS/2 mouse device common for all mice
[ 0.990849] bcm2835-wdt 20100000.watchdog: Broadcom BCM2835 watchdog timer
[ 0.994079] bcm2835-cpufreq: min=700000 max=700000
[ 0.997344] sdhci: Secure Digital Host Controller Interface driver
[ 1.000026] sdhci: Copyright(c) Pierre Ossman
[ 1.003175] sdhost-bcm2835 20202000.sdhost: could not get clk, deferring probe
[ 1.006286] sdhci-pltfm: SDHCI platform and OF driver helper
[ 1.009773] ledtrig-cpu: registered to indicate activity on CPUs
[ 1.012745] hidraw: raw HID events driver (C) Jiri Kosina
[ 1.016022] usbcore: registered new interface driver usbhid
[ 1.018821] usbhid: USB HID core driver
[ 1.022769] vchiq: vchiq_init_state: slot_zero = 0xdb580000, is_master = 0
[ 1.027647] [vc_sm_connected_init]: start
[ 1.038064] [vc_sm_connected_init]: end - returning 0
[ 1.041514] Initializing XFRM netlink socket
[ 1.044372] NET: Registered protocol family 17
[ 1.047261] Key type dns_resolver registered
[ 1.051690] registered taskstats version 1
[ 1.061741] uart-pl011 20201000.serial: cts_event_workaround enabled
[ 1.065013] 20201000.serial: ttyAMA0 at MMIO 0x20201000 (irq = 81, base_baud = 0) is a PL011 rev2
[ 1.890330] console [ttyAMA0] enabled
[ 1.899352] sdhost: log_buf @ db513000 (5b513000)
[ 1.982906] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
[ 1.991408] of_cfs_init
[ 2.016888] of_cfs_init: OK
[ 2.023349] Waiting for root device PARTUUID=f3a2a455-02...
[ 2.033227] Indeed it is in host mode hprt0 = 00021501
[ 2.101813] random: fast init done
[ 2.150766] mmc0: host does not support reading read-only switch, assuming write-enable
[ 2.166502] mmc0: new high speed SDHC card at address 59b4
[ 2.176368] mmcblk0: mmc0:59b4 USD 3.75 GiB
[ 2.185850] mmcblk0: p1 p2
[ 2.242916] usb 1-1: new high-speed USB device number 2 using dwc_otg
[ 2.252417] Indeed it is in host mode hprt0 = 00001101
[ 2.334704] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[ 2.348894] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[ 2.369669] devtmpfs: mounted
[ 2.377066] Freeing unused kernel memory: 396K
[ 2.384512] This architecture does not have kernel memory protection.
[ 2.493404] usb 1-1: New USB device found, idVendor=0424, idProduct=9514
[ 2.503584] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[ 2.515639] hub 1-1:1.0: USB hub found
[ 2.522993] hub 1-1:1.0: 5 ports detected
[ 2.852945] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
[ 2.968191] systemd[1]: System time before build time, advancing clock.
[ 2.993454] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00
[ 3.003760] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[ 3.017877] smsc95xx v1.0.5
[ 3.128985] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-20980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:48:41:45
[ 3.153420] NET: Registered protocol family 10
[ 3.186123] ip_tables: (C) 2000-2006 Netfilter Core Team
[ 3.238403] systemd[1]: systemd 232 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN)
[ 3.266092] usb 1-1.4: new high-speed USB device number 4 using dwc_otg
[ 3.277347] systemd[1]: Detected architecture arm.
[ 3.306711] systemd[1]: Set hostname to <CM0019>.
[ 3.431513] usb 1-1.4: New USB device found, idVendor=148f, idProduct=5370
[ 3.441764] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 3.452349] usb 1-1.4: Product: 802.11 n WLAN
[ 3.459925] usb 1-1.4: Manufacturer: Ralink
[ 3.467168] usb 1-1.4: SerialNumber: 1.0
[ 3.651571] uart-pl011 20201000.serial: no DMA platform data
[ 4.409206] systemd[1]: [email protected]: Cannot add dependency job, ignoring: Unit [email protected] is masked.
[ 4.440781] systemd[1]: Listening on Journal Socket (/dev/log).
[ 4.455463] systemd[1]: Listening on fsck to fsckd communication Socket.
[ 4.470090] systemd[1]: Listening on Syslog Socket.
[ 4.483792] systemd[1]: Created slice System Slice.
[ 4.497171] systemd[1]: Created slice system-systemd\x2dfsck.slice.
[ 4.516214] systemd[1]: Mounting RPC Pipe File System...
[ 6.822997] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[ 9.210135] systemd-journald[95]: Received request to flush runtime journal from PID 1
[ 9.943067] gpiomem-bcm2835 20200000.gpiomem: Initialised: Registers at 0x20200000
[ 15.256308] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
[ 16.163063] usb 1-1.4: reset high-speed USB device number 4 using dwc_otg
[ 16.354042] ieee80211 phy0: rt2x00_set_rt: Info - RT chipset 5390, rev 0502 detected
[ 16.808354] Adding 102396k swap on /var/swap. Priority:-1 extents:1 across:102396k SSFS
[ 16.820688] smsc95xx 1-1.1:1.0 eth0: link up, 100Mbps, full-duplex, lpa 0x43E1
[ 17.003090] ieee80211 phy0: rt2x00_set_rf: Info - RF chipset 5370 detected
[ 17.069652] ieee80211 phy0: Selected rate control algorithm 'minstrel_ht'
[ 17.076353] usbcore: registered new interface driver rt2800usb
[ 19.115910] ieee80211 phy0: rt2x00lib_request_firmware: Info - Loading firmware file 'rt2870.bin'
[ 19.127818] ieee80211 phy0: rt2x00lib_request_firmware: Info - Firmware detected - version: 0.36
[ 19.625598] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[ 20.585688] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[ 25.663559] nf_conntrack version 0.5.0 (7168 buckets, 28672 max)
[ 27.526434] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[ 28.568739] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[ 179.018477] random: crng init done

[jamesh]

Might be worth moving to 4.14, or just updating to the latest wireless firmware (rpi-update).

Also, have you tried the instructions here? https://www.raspberrypi.org/documentati ... s-point.md

[vthielen]

Hello James,

I noticed that, in my original post, I messed up the link that described the procedure that I followed first. (corrected it now).
It's the link below, and it describes exactly the same procedure as the one you sent me, so I have already tried that.

https://github.com/SurferTim/documentat ... s-point.md

In the steps described in the link, there is already an 'apt-get update && sudo apt-get upgrade', so that was already done.

I ran rpi-update and it successfully installed the 4.14 kernel.

The problem is still the same though: sometimes wlan0 gets an IP address after reboot, sometimes not.

Is there anything else I could try?

[vthielen]

I had a more detailed look on the differences in the dmesg after booting in working (right) and non-working (left) state.
It seems that the systemd has different behavior in both cases. (see attachment)

[vthielen]

I seem to get an IP address each time after I run "service hostapd restart"
So as a workaround, I can already put that in /etc/rc.local so it gets run at boot time.