You are not logged in.

#1 2015-09-08 12:44:38

esa
Member
Registered: 2011-12-29
Posts: 143
Website

Different times when connecting to wifi

Heyas

I wanted to get rid of NetworkManager and netctl since i only use wlan and use scripts to use the plain basics: dhcpcd & wpa_supplicant.
Somehow i once achieved 3 seconds when started as a service (NM took ~11, not during the same boot!), so i permamently changed it.

That was about 2 kernels ago, but with current kernel i can close and open the lid and continue writing, without several closings until the keyboard lets me enter my password again....
Anyway, so recently i've figured that the service started to take longer.

I could speed it up (again), by copying the creds off the encrypted  /home, and installed the staring script, so it was not located on /home either.
So, i'm 'down' to ~15-17 vs. ~19-21 of previous boots -- during boot!
When i start the service manually, it takes roughly 7 secs.
When i start the script directly, it takes roughly 3-5 secs.
The script is called anyway - all the times, so i wonder why does it take so long for the script to get started?

systemctl status wifi-home
● wifi-home.service - Wifi-home
   Loaded: loaded (/etc/systemd/system/wifi-home.service; enabled; vendor preset: disabled)
   Active: active (exited) since Mon 2015-09-07 19:33:41 CEST; 35s ago
  Process: 842 ExecStart=/usr/bin/connect wifi home (code=exited, status=0/SUCCESS)
 Main PID: 842 (code=exited, status=0/SUCCESS)
   CGroup: /system.slice/wifi-home.service
           ├─1012 bash /usr/share/connect/to/wifi home
           ├─1015 dhcpcd -B
           └─1751 wpa_supplicant -B -iwlp3s0 -c/root/.config/connect/wifi/home -f/var/log/connect/wifi.log

Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable.
blame
The time after the unit is active or started is printed after the "@" character.
The time the unit takes to start is printed after the "+" character.

graphical.target @34.901s
└─multi-user.target @34.901s
  └─wifi-home.service @17.381s +17.519s
    └─basic.target @17.380s
      └─sockets.target @17.380s
        └─dbus.socket @17.380s
          └─sysinit.target @17.339s
            └─systemd-update-utmp.service @17.225s +113ms
              └─systemd-tmpfiles-setup.service @17.185s +40ms
                └─local-fs.target @17.184s
                  └─home.mount @16.884s +299ms
                    └─dev-mapper-home.device @16.768s
         17.519s wifi-home.service
          9.609s dev-sda12.device
          7.896s systemd-journal-flush.service
          5.802s systemd-cryptsetup@home.service
          3.571s udisks2.service
          2.513s polkit.service
          1.970s avahi-daemon.service
          1.853s alsa-restore.service
          1.812s systemd-user-sessions.service
          1.573s mnt-shared.mount
          1.245s systemd-vconsole-setup.service
          1.129s systemd-fsck-root.service
           948ms boot-efi.mount
           858ms systemd-udevd.service
           827ms user@1000.service
           713ms systemd-journald.service
           638ms boot.mount
           572ms systemd-tmpfiles-setup-dev.service
           437ms systemd-logind.service
           403ms systemd-ask-password-wall.service
           304ms tmp.mount
           303ms dev-hugepages.mount
           302ms dev-mqueue.mount
           299ms home.mount
           298ms systemd-modules-load.service
           294ms sys-kernel-debug.mount
           282ms systemd-sysctl.service
           279ms systemd-rfkill@rfkill1.service
           234ms systemd-fsck@dev-sda11.service
           134ms systemd-random-seed.service
           113ms systemd-update-utmp.service
           107ms systemd-rfkill@rfkill2.service
            97ms sys-kernel-config.mount
            93ms kmod-static-nodes.service
            71ms systemd-remount-fs.service
            56ms systemd-backlight@backlight:intel_backlight.service
            56ms systemd-udev-trigger.service
            40ms systemd-tmpfiles-setup.service
             2ms sys-fs-fuse-connections.mount
Startup finished in 2.073s (firmware) + 3.980s (loader) + 3.084s (kernel) + 34.901s (userspace) = 44.040s
systemctl cat wifi-home
# /etc/systemd/system/wifi-home.service
[Unit]
Description=Wifi-home

[Service]
Type=oneshot
RemainAfterExit=yes
ExecStart=/usr/bin/connect wifi home
ExecStop=/usr/bin/connect wifi halt

[Install]
WantedBy=multi-user.target

Without timecodes it is kind of hard to figure out what when happened... sad

cat /var/log/connect/wifi.log
Successfully initialized wpa_supplicant
wlp3s0: starting wpa_supplicant
wlp3s0: SME: Trying to authenticate with 14:49:e0:81:1b:a8 (SSID='UPC246850344' freq=2462 MHz)
wlp3s0: Trying to associate with 14:49:e0:81:1b:a8 (SSID='UPC246850344' freq=2462 MHz)
wlp3s0: Associated with 14:49:e0:81:1b:a8
wlp3s0: WPA: Key negotiation completed with 14:49:e0:81:1b:a8 [PTK=CCMP GTK=TKIP]
wlp3s0: CTRL-EVENT-CONNECTED - Connection to 14:49:e0:81:1b:a8 completed [id=0 id_str=]
wlp3s0: CTRL-EVENT-DISCONNECTED bssid=14:49:e0:81:1b:a8 reason=3 locally_generated=1
enp4s0: adding address fe80::fac0:81bf:5bb0:c86a
wlp3s0: adding address fe80::f1af:256a:737a:4ed4
no interfaces have a carrier
enp4s0: waiting for carrier
wlp3s0: waiting for carrier
wlp3s0: carrier acquired
DUID 00:01:00:01:1d:04:b5:89:54:be:f7:53:f0:f8
wlp3s0: IAID 66:cb:61:cd
wlp3s0: soliciting an IPv6 router
wlp3s0: rebinding lease of 192.168.10.15
wlp3s0: leased 192.168.10.15 for 86400 seconds
wlp3s0: adding route to 192.168.10.0/24
wlp3s0: adding default route via 192.168.10.1
wlp3s0: no IPv6 Routers available
wlp3s0: carrier lost
wlp3s0: deleting route to 192.168.10.0/24
wlp3s0: deleting default route via 192.168.10.1
received SIGTERM, stopping
enp4s0: removing interface
wlp3s0: removing interface
dhcpcd exited
wlp3s0: CTRL-EVENT-TERMINATING 
Successfully initialized wpa_supplicant
wlp3s0: starting wpa_supplicant
wlp3s0: SME: Trying to authenticate with 14:49:e0:81:1b:a8 (SSID='UPC246850344' freq=2462 MHz)
wlp3s0: Trying to associate with 14:49:e0:81:1b:a8 (SSID='UPC246850344' freq=2462 MHz)
wlp3s0: Associated with 14:49:e0:81:1b:a8
wlp3s0: WPA: Key negotiation completed with 14:49:e0:81:1b:a8 [PTK=CCMP GTK=TKIP]
wlp3s0: CTRL-EVENT-CONNECTED - Connection to 14:49:e0:81:1b:a8 completed [id=0 id_str=]

So i tried to figure out why it is taking over 15 secs to connect to my wifi spot...

0 ~ # p
Pinging mint.org... 
64 bytes from 74.117.222.18: icmp_seq=1 ttl=49 time=155 ms
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 155.704/155.704/155.704/0.000 ms
0 ~ # time systemctl stop wifi-home

real	0m6.074s
user	0m0.000s
sys	0m0.003s

0 ~ # p
Pinging facebook.com... 
ping: unknown host facebook.com

1 ~ # time connect wifi home
# | Connect (0.4)                                                           sea @ 2015-09-07 19:42:41 | #
# |                                     Wifi (0.4) (wlp3s0) Start                                     | #
# | Connecting to: home...     [======                                                              ] | #
# | Connecting to: home...     [===========                                                         ] | #
# | Connect (0.4) wifi home                                                                  [  ✓   ] | #

real	0m5.748s
user	0m0.497s
sys	0m0.087s

If you should happen to have THE answer, i'd happy hear about it.
But actualy i'd just like to get a hint about where to dig/read, as i currently have no clue what might be the cause.
If you need more info, just let me know.

Thank you in advance.


Author of: TUI (Text User Interface for scripts), VHS (Video Handler Script, using ffmpeg) and YASSI (Yet Another Simple Script Installer)

Offline

Board footer

Powered by FluxBB