Trying to understand the delay


 
Thread Tools Search this Thread
Top Forums UNIX for Advanced & Expert Users Trying to understand the delay
# 1  
Old 09-07-2015
Trying to understand the delay

Heyas

As you know me, i have scripts for about almost every aspect of my IT life.
This time, i'm having issues to figure out why my script to connect to my wifi spots takes so long when started as service.

The service file (the after:local-fs.target is for 'home installations'):
Code:
cat /etc/systemd/system/wifi-home.service 
[Unit]
Description=Wifi-home
After=local-fs.target

[Service]
Type=oneshot
RemainAfterExit=yes
ExecStart=/home/sea/prjs/connect/connect wifi home
ExecStop=/home/sea/prjs/connect/connect wifi restart

[Install]
WantedBy=multi-user.target

Now, when i connect to my wifi spots using the script, it is 'quite fast'..
Code:
0 sea # time connect wifi home
# | Connect (0.4)                                                           sea @ 2015-09-07 00:36:21 | #
# |                                     Wifi (0.4) (wlp3s0) Start                                     | #
# | Connect (0.4) wifi home                                                                  [  ✓   ] | #

real	0m6.444s
user	0m0.590s
sys	0m0.113s

But during boot, it takes like the tripple time... Smilie
Code:
alias blame ; blame
alias blame='systemd-analyze critical-chain;systemd-analyze blame;systemd-analyze'

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 @19.308s
└─multi-user.target @19.306s
  └─systemd-logind.service @18.423s +882ms
    └─basic.target @16.236s
      └─sockets.target @16.236s
        └─dbus.socket @16.236s
          └─sysinit.target @16.216s
            └─systemd-update-utmp.service @16.014s +201ms
              └─systemd-tmpfiles-setup.service @15.918s +95ms
                └─local-fs.target @15.918s
                  └─home.mount @15.669s +247ms
                    └─dev-mapper-home.device @15.668s
         16.485s wifi-home.service
          8.050s dev-sda12.device
          6.247s systemd-cryptsetup@home.service
          4.673s systemd-journal-flush.service
          1.683s udisks2.service
          1.321s systemd-vconsole-setup.service
          1.273s polkit.service
          1.085s systemd-fsck-root.service
           959ms avahi-daemon.service
           938ms user@1000.service
           920ms systemd-udevd.service
           882ms systemd-logind.service
           746ms boot-efi.mount
           727ms systemd-ask-password-wall.service
           712ms systemd-journald.service
           661ms systemd-tmpfiles-setup-dev.service
           579ms tmp.mount
           495ms systemd-backlight@backlight:intel_backlight.service
           482ms sys-kernel-debug.mount
           470ms dev-hugepages.mount
           470ms dev-mqueue.mount
           460ms systemd-sysctl.service
           342ms systemd-modules-load.service
           331ms systemd-rfkill@rfkill2.service
           262ms systemd-user-sessions.service
           255ms mnt-shared.mount
           247ms home.mount
           201ms systemd-update-utmp.service
           174ms kmod-static-nodes.service
           157ms systemd-fsck@dev-sda11.service
           133ms boot.mount
           110ms systemd-random-seed.service
            95ms systemd-tmpfiles-setup.service
            87ms sys-kernel-config.mount
            70ms systemd-rfkill@rfkill1.service
            69ms systemd-remount-fs.service
            65ms systemd-udev-trigger.service
             2ms alsa-restore.service
             2ms sys-fs-fuse-connections.mount
Startup finished in 2.370s (firmware) + 2.920s (loader) + 3.160s (kernel) + 34.909s (userspace) = 43.361s

From here on i have not much of an idea where to dig.
The systemd-analyze plot > boot.png only showed that the service is loaded properly after local-fs.target was reached, and that it took until graphical.target was loaded.

So my question is, any idea why there is such a time difference, or how i could figure out more myself?
Thank you in advance.

---------- Post updated at 13:46 ---------- Previous update was at 00:51 ----------

Code:
time su -c "systemctl start wifi-home"
Passwort: 

real	0m9.077s
user	0m0.033s
sys	0m0.010s

Code:
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 13:33:36 CEST; 33s ago
  Process: 12702 ExecStop=/home/sea/prjs/connect/connect wifi restart
  Process: 16625 ExecStart=/home/sea/prjs/connect/connect wifi home (code=exited, status=0/SUCCESS)
 Main PID: 16625 (code=exited, status=0/SUCCESS)
   CGroup: /system.slice/wifi-home.service
           ├─16689 bash /usr/share/connect/to/wifi home
           ├─16692 dhcpcd -B
           └─16737 wpa_supplicant -B -iwlp3s0 -c/root/.config/connect/wifi/home -f/connect/wifi.log

I even removed the After=local-fs.target as i had moved the creds to root account, and restarted (stop,disable,enable,start) the service in the hope to speed up the process, as i would not need to wait for /home decryption.

So, i'm actualy getting 3 different times, ~6 secs when calling the programm directly, ~9 secs when calling the service directly, but ~16-18secs when booting.

Any ideas please why i might getting such different times for the same command?
Where to dig now?
What info do you need to tell me where to look?

tia
# 2  
Old 09-08-2015
Which OS ?
# 3  
Old 09-08-2015
You might want to ask on the systemd mailing list. They are very responsive usually.

I don't want to guess. Systemd behavior is not necessarily my friend.
# 4  
Old 10-05-2015
Sorry for the delay, but since its not breaking usability i forgot about it, as i had more urgent matters.
@ brij123: Arch
@ cjox, good idea, did so now: https://github.com/systemd/systemd/issues
Thanks for your replies.
Login or Register to Ask a Question

Previous Thread | Next Thread

10 More Discussions You Might Find Interesting

1. Shell Programming and Scripting

Loop without a delay

Hi, I am trying to understand what would happen if ther is a loop without any delay like sleep statement, I feel that would add a lot of load onto the CPU. Trying to understand how the load is reduced by the introduction of sleep(). Thanks and regards Zulfi (3 Replies)
Discussion started by: zulfi123786
3 Replies

2. UNIX for Dummies Questions & Answers

Delay with Wget

I have a list of URLs that I need to download in a file. I know I can use the -i option to load the URLs from the file, but how can I make Wget wait a couple secs between each URL download? (4 Replies)
Discussion started by: rlopes
4 Replies

3. SCO

Openserver 5.0.5 - logon delay

We have an OpenServer 5.0.5 system that has worked forever, but I'm hearing complaints of logon delays for users now. Normally they would telnet in and the logon screen would pop up, but now it sometimes takes a minute or more, and the user must hit the enter key to get it to appear. Everything... (11 Replies)
Discussion started by: citygov
11 Replies

4. Shell Programming and Scripting

How to delay the process for few seconds

Hi, In my shell script, (as per the requirement), I am creating few files, and the processes are launched parallelly . (by using "&" at the end of the command line). As per the logic, I need to remove these files as well, after creating. But, the problem is, due to parallel processing,... (3 Replies)
Discussion started by: jitendriya.dash
3 Replies

5. Shell Programming and Scripting

while loop and delay

Dear all, if we want to run a command every 5 mins to check if the process is working fine or not... like in c, we can use a simple while loop with a delay for 5 mins... how can we accomplish this is solaris 8/9 thanks br/asad (5 Replies)
Discussion started by: asadlone
5 Replies

6. Programming

Delay a process.

How to delay a process. I need to to delay a process from 3sec. At that 3sec other back ground processes also should stop. (just sit 3sec for idle & then starts execution as normally) I use sleep(3)-But it not stop the bg processes I try to use loop but it not gurantee to wait 3sec. ... (2 Replies)
Discussion started by: ugp
2 Replies

7. Programming

Introducing Delay less then a second.

Hi, I have a doubt in introducing a delay in the programs. We know that we do have a sleep() function/api using which we can bring a delay in terms of seconds. A minimum delay can be atleast 1 second. Now I'm bothered about how to introduce a delay that is just less than a second. Like... (3 Replies)
Discussion started by: S.Vishwanath
3 Replies

8. UNIX for Dummies Questions & Answers

Delay in mv

Working on AIX 4.3 I have an active exe that accepts files for processing on our RS6000. Day to day i store these files in a secure place and at the end of the day I mv them one by one. After some reading and ofcourse trial and error i figured out that this helps... mv `ls -l |head -l | awk... (2 Replies)
Discussion started by: buRst
2 Replies

9. Programming

Keyboard Strokes w/o Delay...

Hello(again), but I was wondering how you would obtain a keyboard stroke from a user with no delay(they don't have to hit enter) and then place that stroke into a variable? Lets say you tell the user to hit, on the numpad, a number. Then that number is placed into a variable w/o the user hitting... (2 Replies)
Discussion started by: mbolthouse
2 Replies

10. UNIX for Dummies Questions & Answers

Login Delay

When telneting to a SUN box and incorrectly spelling your password, there is a delay of approx. 5 seconds. Is there any way to shorten this time? OS solaris 7 (1 Reply)
Discussion started by: SmartJuniorUnix
1 Replies
Login or Register to Ask a Question