Gentoo Forums
Gentoo Forums
Gentoo Forums
Quick Search: in
iwd+dhcpcd take 3 minutes to acquire ip address
View unanswered posts
View posts from last 24 hours

 
Reply to topic    Gentoo Forums Forum Index Networking & Security
View previous topic :: View next topic  
Author Message
smartding
Tux's lil' helper
Tux's lil' helper


Joined: 22 Jan 2021
Posts: 129

PostPosted: Tue Mar 02, 2021 4:51 am    Post subject: iwd+dhcpcd take 3 minutes to acquire ip address Reply with quote

I'm working in a wifi only environment with dhcp, and I have a Ethernet card with no network cable plugged in.

I'm using iwd+dhcpcd to manage my network. I've added both iwd and dhcpced to default run level as suggested by the iwd wiki: https://wiki.gentoo.org/wiki/Iwd#dhcpcd, and rc-status shows both service have started.

It can take around 3 minutes for iwd+dhcpcd to acquire an ip address for wlan0. Although after that, the network works flawlessly.

I wonder if I can reduce the 3 minutes' waiting. Is dhcpcd trying to acquire ip address for the unplugged eth0?

The dmeg shows
Code:

[  166.159100] wlan0: authenticate with 32:0d:9e:87:b3:5b
[  166.179272] wlan0: send auth to 32:0d:9e:87:b3:5b (try 1/3)
[  166.283867] wlan0: send auth to 32:0d:9e:87:b3:5b (try 2/3)
[  166.286815] wlan0: authenticated
[  166.287716] wlan0: associate with 32:0d:9e:87:b3:5b (try 1/3)
[  166.294255] wlan0: RX AssocResp from 32:0d:9e:87:b3:5b (capab=0x1c31 status=0 aid=11)
[  166.294514] wlan0: associated
[  166.321043] wlan0: Limiting TX power to 27 (27 - 0) dBm as advertised by 32:0d:9e:87:b3:5b
[  166.409665] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready


Does the 166 in square bracket mean the number of seconds since boot?

BTW, I added the "net.ifnames=0" to GRUB_CMDLINE_LINUX, so my network interface is wlan0 intead of wl*
Back to top
View user's profile Send private message
OmamoriIchika
n00b
n00b


Joined: 27 Jan 2021
Posts: 61

PostPosted: Tue Mar 02, 2021 6:09 am    Post subject: Reply with quote

Did you add both iwd and dhcpcd in runlevel? If you do, it may cause some problem.
Back to top
View user's profile Send private message
smartding
Tux's lil' helper
Tux's lil' helper


Joined: 22 Jan 2021
Posts: 129

PostPosted: Tue Mar 02, 2021 6:20 am    Post subject: Reply with quote

OmamoriIchika wrote:
Did you add both iwd and dhcpcd in runlevel? If you do, it may cause some problem.


The gentoo wiki https://wiki.gentoo.org/wiki/Iwd#dhcpcd suggests I should add both the dhcpcd and then iwd service to the default runlevel
Back to top
View user's profile Send private message
NeddySeagoon
Administrator
Administrator


Joined: 05 Jul 2003
Posts: 54237
Location: 56N 3W

PostPosted: Tue Mar 02, 2021 9:58 am    Post subject: Reply with quote

smartding,

Code:
[  166.159100]
is the time since kernel system time started.
That's shortly after boot.

That's a detail that mostly doesn't matter, unless you have problems before kernel system time is started.

Your wifi becomes ready in about 0.250 sec.
What takes up the 166 sec before that?

Please put all of dmesg onto a pastebin so we can see where the time goes.
I suspect its timeouts waiting for firmware loading, or something like that.
_________________
Regards,

NeddySeagoon

Computer users fall into two groups:-
those that do backups
those that have never had a hard drive fail.
Back to top
View user's profile Send private message
smartding
Tux's lil' helper
Tux's lil' helper


Joined: 22 Jan 2021
Posts: 129

PostPosted: Wed Mar 03, 2021 2:57 am    Post subject: Reply with quote

NeddySeagoon wrote:
smartding,

Code:
[  166.159100]
is the time since kernel system time started.
That's shortly after boot.

That's a detail that mostly doesn't matter, unless you have problems before kernel system time is started.

Your wifi becomes ready in about 0.250 sec.
What takes up the 166 sec before that?

Please put all of dmesg onto a pastebin so we can see where the time goes.
I suspect its timeouts waiting for firmware loading, or something like that.


Thank you for your reply, here's the whole dmesg:

https://pastebin.com/raw/0mRdVBdW
Back to top
View user's profile Send private message
NeddySeagoon
Administrator
Administrator


Joined: 05 Jul 2003
Posts: 54237
Location: 56N 3W

PostPosted: Wed Mar 03, 2021 11:45 am    Post subject: Reply with quote

smartding,

Code:
[    6.678490] caller _nv000707rm+0x1af/0x200 [nvidia] mapping multiple BARs
[  165.927273] wlan0: authenticate with 32:0d:9e:87:b3:5b


The problem is here, what is happening it that huge gap ?

The is another oddity. That's the first entry in dmesg for wlan0
Normally there is driver initialisation and sometimes firmware loading. Those entries are missing.
Its something like
Code:
 [    0.331037] r8169 0000:04:00.0 eth0: RTL8168g/8111g,
but for wlan0.

What Wifi device do you have and how is is connected?
It should either be is
Code:
lspci -nnk
or in
Code:
lsusb

_________________
Regards,

NeddySeagoon

Computer users fall into two groups:-
those that do backups
those that have never had a hard drive fail.
Back to top
View user's profile Send private message
smartding
Tux's lil' helper
Tux's lil' helper


Joined: 22 Jan 2021
Posts: 129

PostPosted: Wed Mar 03, 2021 1:30 pm    Post subject: Reply with quote

NeddySeagoon wrote:
smartding,

Code:
[    6.678490] caller _nv000707rm+0x1af/0x200 [nvidia] mapping multiple BARs
[  165.927273] wlan0: authenticate with 32:0d:9e:87:b3:5b


The problem is here, what is happening it that huge gap ?

The is another oddity. That's the first entry in dmesg for wlan0
Normally there is driver initialisation and sometimes firmware loading. Those entries are missing.
Its something like
Code:
 [    0.331037] r8169 0000:04:00.0 eth0: RTL8168g/8111g,
but for wlan0.

What Wifi device do you have and how is is connected?
It should either be is
Code:
lspci -nnk
or in
Code:
lsusb


lspci -k shows I have the following wifi card:
Code:

   03:00.0 Network controller: Realtek Semiconductor Co., Ltd. RTL8723BE PCIe Wireless Network Adapter
   Subsystem: Lenovo Device b728
   Kernel driver in use: rtl8723be


I've compiled the rtl8723be driver as a kernel module: CONFIG_RTL8723BE=m


And I have installed the sys-kernel/linux-firmware package
Back to top
View user's profile Send private message
NeddySeagoon
Administrator
Administrator


Joined: 05 Jul 2003
Posts: 54237
Location: 56N 3W

PostPosted: Wed Mar 03, 2021 1:57 pm    Post subject: Reply with quote

smartding,

Code:
[    1.497039] rtl8723be 0000:03:00.0: enabling device (0000 -> 0003)
...
[    1.512964] rtl8723be: Using firmware rtlwifi/rtl8723befw_36.bin
[    1.513606] ieee80211 phy0: Selected rate control algorithm 'rtl_rc'
[    1.513890] rtlwifi: rtlwifi: wireless switch is on


That's here but there is no wlan0 device.

That's after
Code:
[    0.659835] EXT4-fs (sda4): mounted filesystem with ordered data mode. Opts: (null)
[    0.660529] VFS: Mounted root (ext4 filesystem) readonly on device 8:4.
That after root is mounted.

Code:
[  165.927273] wlan0: authenticate with 32:0d:9e:87:b3:5b
[  165.947463] wlan0: send auth to 32:0d:9e:87:b3:5b (try 1/3)
[  166.054874] wlan0: send auth to 32:0d:9e:87:b3:5b (try 2/3)
[  166.062498] wlan0: authenticated
[  166.062808] wlan0: associate with 32:0d:9e:87:b3:5b (try 1/3)
[  166.069155] wlan0: RX AssocResp from 32:0d:9e:87:b3:5b (capab=0x1c31 status=0 aid=14)
[  166.069407] wlan0: associated

Is all required before dhcp can do its thing.

There are two questions, where is the wlan0 annoucement?

How do you start wlan0?
Code:
[  165.927273] wlan0: authenticate with 32:0d:9e:87:b3:5b
is the start of that process. What happens before it?

-- edit --
If you use OpenRC, edit /etc/rc.conf to enable logging
Code:
# rc_logger launches a logging daemon to log the entire rc process to
# /var/log/rc.log
# NOTE: Linux systems require the devfs service to be started before
# logging can take place and as such cannot log the sysinit runlevel.
#rc_logger="YES"

reboot and pastebin the log.
_________________
Regards,

NeddySeagoon

Computer users fall into two groups:-
those that do backups
those that have never had a hard drive fail.
Back to top
View user's profile Send private message
smartding
Tux's lil' helper
Tux's lil' helper


Joined: 22 Jan 2021
Posts: 129

PostPosted: Wed Mar 03, 2021 3:01 pm    Post subject: Reply with quote

NeddySeagoon

I don't have the computer with me at the moment, I will post the log tomorrow.

But I have another laptop, which can acquire IP address very fast, no 3 minutes' delay.

It has a Qualcomm Atheros QCA6174 802.11ac Wireless Network Adapter.

As a comparison, I ran dmesg | grep wlan0, it shows

Code:

[    4.823867] wlan0: authenticate with 24:7e:51:eb:7f:70
[    4.891488] wlan0: send auth to 24:7e:51:eb:7f:70 (try 1/3)
[    4.893149] wlan0: authenticated
[    4.893959] wlan0: associate with 24:7e:51:eb:7f:70 (try 1/3)
[    4.897791] wlan0: RX AssocResp from 24:7e:51:eb:7f:70 (capab=0x431 status=0 aid=8)
[    4.900194] wlan0: associated
[    5.880385] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready


We can see that it also begins with wlan0: authenticate with 24:7e:51:eb:7f:70, nothing before that.
Back to top
View user's profile Send private message
NeddySeagoon
Administrator
Administrator


Joined: 05 Jul 2003
Posts: 54237
Location: 56N 3W

PostPosted: Wed Mar 03, 2021 3:09 pm    Post subject: Reply with quote

smartding,

Your
Code:
[    4.823867] wlan0: authenticate with 24:7e:51:eb:7f:70
[    4.891488] wlan0: send auth to 24:7e:51:eb:7f:70 (try 1/3)
[    4.893149] wlan0: authenticated
[    4.893959] wlan0: associate with 24:7e:51:eb:7f:70 (try 1/3)
[    4.897791] wlan0: RX AssocResp from 24:7e:51:eb:7f:70 (capab=0x431 status=0 aid=8)
[    4.900194] wlan0: associated
[    5.880385] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready

That's the Wifi becoming authenticated then associated, so that the radio link is ready. That has to happen before dhcpcd can ask for an IP address.

It effect, once authentication and association are complete, the interface can be used as if it was wired.

What starts wlan0 here and why does it run sooner?
It would be useful to compare the two.
_________________
Regards,

NeddySeagoon

Computer users fall into two groups:-
those that do backups
those that have never had a hard drive fail.
Back to top
View user's profile Send private message
smartding
Tux's lil' helper
Tux's lil' helper


Joined: 22 Jan 2021
Posts: 129

PostPosted: Thu Mar 04, 2021 3:16 am    Post subject: Reply with quote

NeddySeagoon wrote:
smartding,

Code:
[    1.497039] rtl8723be 0000:03:00.0: enabling device (0000 -> 0003)
...
[    1.512964] rtl8723be: Using firmware rtlwifi/rtl8723befw_36.bin
[    1.513606] ieee80211 phy0: Selected rate control algorithm 'rtl_rc'
[    1.513890] rtlwifi: rtlwifi: wireless switch is on


That's here but there is no wlan0 device.

That's after
Code:
[    0.659835] EXT4-fs (sda4): mounted filesystem with ordered data mode. Opts: (null)
[    0.660529] VFS: Mounted root (ext4 filesystem) readonly on device 8:4.
That after root is mounted.

Code:
[  165.927273] wlan0: authenticate with 32:0d:9e:87:b3:5b
[  165.947463] wlan0: send auth to 32:0d:9e:87:b3:5b (try 1/3)
[  166.054874] wlan0: send auth to 32:0d:9e:87:b3:5b (try 2/3)
[  166.062498] wlan0: authenticated
[  166.062808] wlan0: associate with 32:0d:9e:87:b3:5b (try 1/3)
[  166.069155] wlan0: RX AssocResp from 32:0d:9e:87:b3:5b (capab=0x1c31 status=0 aid=14)
[  166.069407] wlan0: associated

Is all required before dhcp can do its thing.

There are two questions, where is the wlan0 annoucement?

How do you start wlan0?
Code:
[  165.927273] wlan0: authenticate with 32:0d:9e:87:b3:5b
is the start of that process. What happens before it?

-- edit --
If you use OpenRC, edit /etc/rc.conf to enable logging
Code:
# rc_logger launches a logging daemon to log the entire rc process to
# /var/log/rc.log
# NOTE: Linux systems require the devfs service to be started before
# logging can take place and as such cannot log the sysinit runlevel.
#rc_logger="YES"

reboot and pastebin the log.


Here's my OpenRC log: https://pastebin.com/raw/LjJnFTLz

This time I waited like 10 minutes, still no ip address, then I manually ran "iwctl station wlan0 scan" 2-3 times, and I have an IP address!
There's the output of "dmesg | grep wlan"

Code:

[  615.922865] wlan0: authenticate with 32:0d:9e:87:b3:5b
[  615.943057] wlan0: send auth to 32:0d:9e:87:b3:5b (try 1/3)
[  615.945748] wlan0: authenticated
[  615.946483] wlan0: associate with 32:0d:9e:87:b3:5b (try 1/3)
[  615.952573] wlan0: RX AssocResp from 32:0d:9e:87:b3:5b (capab=0x1c31 status=0 aid=20)
[  615.952827] wlan0: associated
[  616.066022] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[  619.210957] wlan0: Limiting TX power to 27 (27 - 0) dBm as advertised by 32:0d:9e:87:b3:5b


Here's the complete dmesg: https://pastebin.com/raw/5pV6e8v3

Is wlan0's authentication and association triggered by iwd's scan command? I don't have anything in /etc/iwd/main.conf that disables iwd's automatic periodic scan. So why wasn't iwd scanning earlier?

BTW, I booted the computer with archlinux, there's no delay when acquiring IP address. So there's nothing wrong with the hardware.
Back to top
View user's profile Send private message
halcon
l33t
l33t


Joined: 15 Dec 2019
Posts: 629

PostPosted: Thu Mar 04, 2021 3:21 pm    Post subject: Reply with quote

Hi smartding,

I've been using iwd + dhcpcd on my laptop for more than a year. But I haven't added them to any runlevels, I always start them manually (because I also connect the laptop to a wired network).

I think your issue may be related to that the desired wifi network is not found for these minutes (it happens to me too). Please try (by user)
Code:
$ iwctl adapter list
$ iwctl station list
$ iwctl station wlan0 scan
$ iwctl station wlan0 get-networks

If there is no the desired wifi network in the output of the last command, than my guess is right.
_________________
A wife asks her husband, a programmer:
- Could you please go shopping for me and buy one carton of milk, and if they have eggs, get 6?
He comes back with 6 cartons of milk.
- Why did you buy 6 cartons of milk?
- They had eggs.
Back to top
View user's profile Send private message
smartding
Tux's lil' helper
Tux's lil' helper


Joined: 22 Jan 2021
Posts: 129

PostPosted: Fri Mar 05, 2021 2:47 am    Post subject: Reply with quote

halcon wrote:
Hi smartding,

I've been using iwd + dhcpcd on my laptop for more than a year. But I haven't added them to any runlevels, I always start them manually (because I also connect the laptop to a wired network).

I think your issue may be related to that the desired wifi network is not found for these minutes (it happens to me too). Please try (by user)
Code:
$ iwctl adapter list
$ iwctl station list
$ iwctl station wlan0 scan
$ iwctl station wlan0 get-networks

If there is no the desired wifi network in the output of the last command, than my guess is right.


Thanks for sharing your experience.

The 3-10 minutes' delay is unlikely due to the wifi network being unavailable. Because every time I run "iwctl station wlan0 scan", I can always find it.
Back to top
View user's profile Send private message
UberLord
Retired Dev
Retired Dev


Joined: 18 Sep 2003
Posts: 6835
Location: Blighty

PostPosted: Mon Mar 08, 2021 10:41 am    Post subject: Reply with quote

halcon wrote:
I've been using iwd + dhcpcd on my laptop for more than a year. But I haven't added them to any runlevels, I always start them manually (because I also connect the laptop to a wired network).


dhcpcd will automatically prefer wired over wireless and swap between the two mostly seamlessly on Linux, so adding dhcpcd to the default runlevel is fine.
It's designed so that it should just be plug and play.
_________________
Use dhcpcd for all your automated network configuration needs
Use dhcpcd-ui (GTK+/Qt) as your System Tray Network tool
Back to top
View user's profile Send private message
halcon
l33t
l33t


Joined: 15 Dec 2019
Posts: 629

PostPosted: Mon Mar 08, 2021 2:52 pm    Post subject: Reply with quote

Hi Uberlord,

UberLord wrote:
dhcpcd will automatically prefer wired over wireless and swap between the two mostly seamlessly on Linux, so adding dhcpcd to the default runlevel is fine.
It's designed so that it should just be plug and play.

"Just plug and play" and "swap between the two mostly seamlessly" is not that I need.

halcon wrote:
because I also connect the laptop to a wired network

Evidently, I haven't expressed myself clearly. I didn't mean that I connect to both networks at the same time. I connect the laptop or to wireless, or to wired. In wireless, I get IP automatically via dhcpcd. In wired, I get a static IP via netifrc. So, I don't add dhcpcd to any runlevel and start it manually after connecting to wireless. Simple.
_________________
A wife asks her husband, a programmer:
- Could you please go shopping for me and buy one carton of milk, and if they have eggs, get 6?
He comes back with 6 cartons of milk.
- Why did you buy 6 cartons of milk?
- They had eggs.
Back to top
View user's profile Send private message
UberLord
Retired Dev
Retired Dev


Joined: 18 Sep 2003
Posts: 6835
Location: Blighty

PostPosted: Tue Mar 09, 2021 11:22 am    Post subject: Reply with quote

halcon wrote:
Evidently, I haven't expressed myself clearly. I didn't mean that I connect to both networks at the same time. I connect the laptop or to wireless, or to wired. In wireless, I get IP automatically via dhcpcd. In wired, I get a static IP via netifrc. So, I don't add dhcpcd to any runlevel and start it manually after connecting to wireless. Simple.


So I like to use one tool for the job, keeping it simple.
While dhcpcd won't setup bridging for example, it can setup static IP when you plug the cable in and remove it when you unplug.
You don't need netifrc for that.

Code:

# /etc/dhcpcd.conf
interface eth0
    static ip_address=192.168.1.101/24
    static routers=192.168.1.1
    static domain_name_servers=192.168.1.1



But let me also be clear - you always have the freedom to setup your system how you like, I am just highlighting a way of hopefully making it simpler.
_________________
Use dhcpcd for all your automated network configuration needs
Use dhcpcd-ui (GTK+/Qt) as your System Tray Network tool
Back to top
View user's profile Send private message
halcon
l33t
l33t


Joined: 15 Dec 2019
Posts: 629

PostPosted: Tue Mar 09, 2021 6:26 pm    Post subject: Reply with quote

UberLord wrote:
Code:
# /etc/dhcpcd.conf
interface eth0
    static ip_address=192.168.1.101/24
    static routers=192.168.1.1
    static domain_name_servers=192.168.1.1

Thank you for this example. I'll keep it in mind.

UberLord wrote:
So I like to use one tool for the job, keeping it simple.
While dhcpcd won't setup bridging for example, it can setup static IP when you plug the cable in and remove it when you unplug.
You don't need netifrc for that.

From this point of view, one tool would be simpler, yes. But I think of netifrc not as a (additional) tool, but as a part of the (base) system :)

UberLord wrote:
But let me also be clear - you always have the freedom to setup your system how you like, I am just highlighting a way of hopefully making it simpler

Sure, I realized that! It's useful to hear opinions of others. Sometimes I find out that I haven't been aware of something important for a long time. For example, I didn't know about existence /usr/src/linux/scripts/diffconfig :)
_________________
A wife asks her husband, a programmer:
- Could you please go shopping for me and buy one carton of milk, and if they have eggs, get 6?
He comes back with 6 cartons of milk.
- Why did you buy 6 cartons of milk?
- They had eggs.
Back to top
View user's profile Send private message
Display posts from previous:   
Reply to topic    Gentoo Forums Forum Index Networking & Security All times are GMT
Page 1 of 1

 
Jump to:  
You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot vote in polls in this forum