4/03/2017

dmesg 와 systemd-analyze 비교

systemd에서는 각각의 실행시간을 분석해주는 Tool이 존재하며 이를 이용하여 각각의 실행시간을 알수가 있지만, 정확한 사용방법을 알아야한다.

아래의 결과는 Raspberry Pi에서 동일하게 실행한 결과이지만, 아래와 같이 시간이 제각각이다.


  • dmseg와 비교 
$ dmesg 
[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 4.14.34-v7+ (dc4@dc4-XPS13-9333) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611)) #1110 SMP Mon Apr 16 15:18:51 BST 2018
[    0.000000] CPU: ARMv7 Processor [410fd034] revision 4 (ARMv7), cr=10c5383d
[    0.000000] CPU: div instructions available: patching division code
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[    0.000000] OF: fdt: Machine model: Raspberry Pi 3 Model B Rev 1.2
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] cma: Reserved 8 MiB at 0x37800000
[    0.000000] On node 0 totalpages: 229376
[    0.000000] free_area_init_node: node 0, pgdat 80c84e40, node_mem_map b7016000
[    0.000000]   Normal zone: 2016 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 229376 pages, LIFO batch:31
[    0.000000] random: fast init done
[    0.000000] percpu: Embedded 17 pages/cpu @b6fbf000 s38720 r8192 d22720 u69632
[    0.000000] pcpu-alloc: s38720 r8192 d22720 u69632 alloc=17*4096
[    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 227360
[    0.000000] Kernel command line: 8250.nr_uarts=0 bcm2708_fb.fbwidth=1920 bcm2708_fb.fbheight=1080 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000  dwc_otg.lpm_enable=0 console=ttyS0,115200 console=tty1 root=PARTUUID=0c830106-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait quiet splash plymouth.ignore-serial-consoles
[    0.000000] PID hash table entries: 4096 (order: 2, 16384 bytes)
[    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
[    0.000000] Memory: 887456K/917504K available (7168K kernel code, 575K rwdata, 2072K rodata, 1024K init, 706K bss, 21856K reserved, 8192K cma-reserved)
[    0.000000] Virtual kernel memory layout:
                   vector  : 0xffff0000 - 0xffff1000   (   4 kB)
                   fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
                   vmalloc : 0xb8800000 - 0xff800000   (1136 MB)
                   lowmem  : 0x80000000 - 0xb8000000   ( 896 MB)
                   modules : 0x7f000000 - 0x80000000   (  16 MB)
                     .text : 0x80008000 - 0x80800000   (8160 kB)
                     .init : 0x80b00000 - 0x80c00000   (1024 kB)
                     .data : 0x80c00000 - 0x80c8fd4c   ( 576 kB)
                      .bss : 0x80c96f4c - 0x80d478b4   ( 707 kB)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] ftrace: allocating 25231 entries in 74 pages
[    0.000000] Hierarchical RCU implementation.
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000000] arch_timer: cp15 timer(s) running at 19.20MHz (phys).
[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns
[    0.000007] sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns
[    0.000019] Switching to timer-based delay loop, resolution 52ns
[    0.000267] Console: colour dummy device 80x30
[    0.000285] console [tty1] enabled
[    0.000310] Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=192000)
[    0.000324] pid_max: default: 32768 minimum: 301
[    0.000640] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.000654] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.001589] Disabling memory control group subsystem
[    0.001669] CPU: Testing write buffer coherency: ok
[    0.002060] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[    0.002435] Setting up static identity map for 0x100000 - 0x10003c
[    0.002553] Hierarchical SRCU implementation.
[    0.003188] smp: Bringing up secondary CPUs ...
[    0.003869] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[    0.004618] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[    0.005346] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[    0.005449] smp: Brought up 1 node, 4 CPUs
[    0.005460] SMP: Total of 4 processors activated (153.60 BogoMIPS).
[    0.005465] CPU: All CPU(s) started in HYP mode.
[    0.005469] CPU: Virtualization extensions available.
[    0.006311] devtmpfs: initialized
[    0.016951] VFP support v0.3: implementor 41 architecture 3 part 40 variant 3 rev 4
[    0.017174] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.017192] futex hash table entries: 1024 (order: 4, 65536 bytes)
[    0.017748] pinctrl core: initialized pinctrl subsystem
[    0.018490] NET: Registered protocol family 16
[    0.021211] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[    0.026008] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[    0.026015] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.026219] Serial: AMBA PL011 UART driver
[    0.027834] bcm2835-mbox 3f00b880.mailbox: mailbox enabled
[    0.028291] uart-pl011 3f201000.serial: could not find pctldev for node /soc/gpio@7e200000/uart0_pins, deferring probe
[    0.059383] bcm2835-dma 3f007000.dma: DMA legacy API manager at b8813000, dmachans=0x1
[    0.060908] SCSI subsystem initialized
[    0.061128] usbcore: registered new interface driver usbfs
[    0.061179] usbcore: registered new interface driver hub
[    0.061261] usbcore: registered new device driver usb
[    0.070088] raspberrypi-firmware soc:firmware: Attached to firmware from 2018-04-16 18:21
[    0.071505] clocksource: Switched to clocksource arch_sys_counter
[    0.148883] VFS: Disk quotas dquot_6.6.0
[    0.148967] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    0.149154] FS-Cache: Loaded
[    0.149351] CacheFiles: Loaded
[    0.158152] NET: Registered protocol family 2
[    0.158874] TCP established hash table entries: 8192 (order: 3, 32768 bytes)
[    0.158984] TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
[    0.159170] TCP: Hash tables configured (established 8192 bind 8192)
[    0.159299] UDP hash table entries: 512 (order: 2, 16384 bytes)
[    0.159343] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
[    0.159571] NET: Registered protocol family 1
[    0.160016] RPC: Registered named UNIX socket transport module.
[    0.160022] RPC: Registered udp transport module.
[    0.160027] RPC: Registered tcp transport module.
[    0.160032] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    0.161625] hw perfevents: enabled with armv7_cortex_a7 PMU driver, 7 counters available
[    0.164360] workingset: timestamp_bits=14 max_order=18 bucket_order=4
[    0.172272] FS-Cache: Netfs 'nfs' registered for caching
[    0.172862] NFS: Registering the id_resolver key type
[    0.172900] Key type id_resolver registered
[    0.172906] Key type id_legacy registered
[    0.172921] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[    0.174757] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
[    0.174881] io scheduler noop registered
[    0.174887] io scheduler deadline registered (default)
[    0.175165] io scheduler cfq registered
[    0.175173] io scheduler mq-deadline registered
[    0.175179] io scheduler kyber registered
[    0.177875] BCM2708FB: allocated DMA memory f7910000
[    0.177903] BCM2708FB: allocated DMA channel 0 @ b8813000
[    0.235713] Console: switching to colour frame buffer device 240x67
[    0.270742] bcm2835-rng 3f104000.rng: hwrng registered
[    0.270873] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB)
[    0.271359] vc-sm: Videocore shared memory driver
[    0.271668] gpiomem-bcm2835 3f200000.gpiomem: Initialised: Registers at 0x3f200000
[    0.281295] brd: module loaded
[    0.290358] loop: module loaded
[    0.290371] Loading iSCSI transport class v2.0-870.
[    0.291045] libphy: Fixed MDIO Bus: probed
[    0.291140] usbcore: registered new interface driver lan78xx
[    0.291196] usbcore: registered new interface driver smsc95xx
[    0.291213] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    0.519375] Core Release: 2.80a
[    0.519387] Setting default values for core params
[    0.519418] Finished setting default values for core params
[    0.719681] Using Buffer DMA mode
[    0.719687] Periodic Transfer Interrupt Enhancement - disabled
[    0.719693] Multiprocessor Interrupt Enhancement - disabled
[    0.719699] OTG VER PARAM: 0, OTG VER FLAG: 0
[    0.719710] Dedicated Tx FIFOs mode
[    0.720068] WARN::dwc_otg_hcd_init:1046: FIQ DMA bounce buffers: virt = 0xb7904000 dma = 0xf7904000 len=9024
[    0.720095] FIQ FSM acceleration enabled for :
               Non-periodic Split Transactions
               Periodic Split Transactions
               High-Speed Isochronous Endpoints
               Interrupt/Control Split Transaction hack enabled
[    0.720102] dwc_otg: Microframe scheduler enabled
[    0.720158] WARN::hcd_init_fiq:459: FIQ on core 1 at 0x805e6a40
[    0.720169] WARN::hcd_init_fiq:460: FIQ ASM at 0x805e6da8 length 36
[    0.720182] WARN::hcd_init_fiq:486: MPHI regs_base at 0xb887e000
[    0.720238] dwc_otg 3f980000.usb: DWC OTG Controller
[    0.720273] dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1
[    0.720305] dwc_otg 3f980000.usb: irq 62, io mem 0x00000000
[    0.720350] Init: Port Power? op_state=1
[    0.720355] Init: Power Port (0)
[    0.720566] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[    0.720577] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    0.720585] usb usb1: Product: DWC OTG Controller
[    0.720594] usb usb1: Manufacturer: Linux 4.14.34-v7+ dwc_otg_hcd
[    0.720602] usb usb1: SerialNumber: 3f980000.usb
[    0.721235] hub 1-0:1.0: USB hub found
[    0.721274] hub 1-0:1.0: 1 port detected
[    0.721851] dwc_otg: FIQ enabled
[    0.721857] dwc_otg: NAK holdoff enabled
[    0.721862] dwc_otg: FIQ split-transaction FSM enabled
[    0.721872] Module dwc_common_port init
[    0.722108] usbcore: registered new interface driver usb-storage
[    0.722280] mousedev: PS/2 mouse device common for all mice
[    0.722356] IR NEC protocol handler initialized
[    0.722361] IR RC5(x/sz) protocol handler initialized
[    0.722367] IR RC6 protocol handler initialized
[    0.722372] IR JVC protocol handler initialized
[    0.722377] IR Sony protocol handler initialized
[    0.722382] IR SANYO protocol handler initialized
[    0.722388] IR Sharp protocol handler initialized
[    0.722393] IR MCE Keyboard/mouse protocol handler initialized
[    0.722398] IR XMP protocol handler initialized
[    0.723081] bcm2835-wdt 3f100000.watchdog: Broadcom BCM2835 watchdog timer
[    0.723342] bcm2835-cpufreq: min=600000 max=1200000
[    0.723695] sdhci: Secure Digital Host Controller Interface driver
[    0.723700] sdhci: Copyright(c) Pierre Ossman
[    0.724059] mmc-bcm2835 3f300000.mmc: could not get clk, deferring probe
[    0.724384] sdhost-bcm2835 3f202000.mmc: could not get clk, deferring probe
[    0.724475] sdhci-pltfm: SDHCI platform and OF driver helper
[    0.725899] ledtrig-cpu: registered to indicate activity on CPUs
[    0.726080] hidraw: raw HID events driver (C) Jiri Kosina
[    0.726204] usbcore: registered new interface driver usbhid
[    0.726210] usbhid: USB HID core driver
[    0.726986] vchiq: vchiq_init_state: slot_zero = b7980000, is_master = 0
[    0.728438] [vc_sm_connected_init]: start
[    0.738907] [vc_sm_connected_init]: end - returning 0
[    0.739490] Initializing XFRM netlink socket
[    0.739515] NET: Registered protocol family 17
[    0.739614] Key type dns_resolver registered
[    0.740155] Registering SWP/SWPB emulation handler
[    0.740743] registered taskstats version 1
[    0.746682] uart-pl011 3f201000.serial: cts_event_workaround enabled
[    0.746760] 3f201000.serial: ttyAMA0 at MMIO 0x3f201000 (irq = 87, base_baud = 0) is a PL011 rev2
[    0.748563] mmc-bcm2835 3f300000.mmc: mmc_debug:0 mmc_debug2:0
[    0.748573] mmc-bcm2835 3f300000.mmc: DMA channel allocated
[    0.802145] sdhost: log_buf @ b7907000 (f7907000)
[    0.841999] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
[    0.843546] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    0.845094] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    0.847873] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
[    0.881525] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
[    0.882587] of_cfs_init
[    0.882674] of_cfs_init: OK
[    0.883263] Waiting for root device PARTUUID=0c830106-02...
[    0.931645] Indeed it is in host mode hprt0 = 00021501
[    1.025154] mmc1: new high speed SDIO card at address 0001
[    1.062700] mmc0: host does not support reading read-only switch, assuming write-enable
[    1.066145] mmc0: new high speed SDHC card at address aaaa
[    1.066597] mmcblk0: mmc0:aaaa SL16G 14.8 GiB
[    1.068991]  mmcblk0: p1 p2
[    1.082349] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[    1.082407] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[    1.090094] devtmpfs: mounted
[    1.093347] Freeing unused kernel memory: 1024K
[    1.141555] usb 1-1: new high-speed USB device number 2 using dwc_otg
[    1.141709] Indeed it is in host mode hprt0 = 00001101
[    1.381850] usb 1-1: New USB device found, idVendor=0424, idProduct=9514
[    1.381866] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    1.382646] hub 1-1:1.0: USB hub found
[    1.382738] hub 1-1:1.0: 5 ports detected
[    1.467302] systemd[1]: System time before build time, advancing clock.
[    1.593629] NET: Registered protocol family 10
[    1.594870] Segment Routing with IPv6
[    1.607961] ip_tables: (C) 2000-2006 Netfilter Core Team
[    1.630555] 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)
[    1.631146] systemd[1]: Detected architecture arm.
[    1.636234] systemd[1]: Set hostname to .
[    1.701617] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
[    1.831917] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00
[    1.831933] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    1.834693] smsc95xx v1.0.6
[    1.935161] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:ef:b7:f8
[    2.088664] systemd[1]: Listening on fsck to fsckd communication Socket.
[    2.089776] systemd[1]: Created slice User and Session Slice.
[    2.090066] systemd[1]: Listening on Journal Socket (/dev/log).
[    2.090367] systemd[1]: Listening on Journal Socket.
[    2.090623] systemd[1]: Listening on udev Kernel Socket.
[    2.090869] systemd[1]: Listening on /dev/initctl Compatibility Named Pipe.
[    2.091802] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
[    2.213886] i2c /dev entries driver
[    2.550410] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[    2.636913] systemd-journald[85]: Received request to flush runtime journal from PID 1
[    3.188170] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned.
[    3.193560] bcm2835_alsa bcm2835_alsa: card created with 8 channels
[    3.324525] brcmfmac: F1 signature read @0x18000000=0x1541a9a6
[    3.335237] brcmfmac: brcmf_fw_map_chip_to_name: using brcm/brcmfmac43430-sdio.bin for chip 0x00a9a6(43430) rev 0x000001
[    3.335531] usbcore: registered new interface driver brcmfmac
[    3.586694] brcmfmac: brcmf_c_preinit_dcmds: Firmware version = wl0: Oct 23 2017 03:55:53 version 7.45.98.38 (r674442 CY) FWID 01-e58d219f
[    3.587608] brcmfmac: brcmf_c_preinit_dcmds: CLM version = API: 12.2 Data: 7.11.15 Compiler: 1.24.2 ClmImport: 1.24.1 Creation: 2014-05-26 10:53:55 Inc Data: 9.10.39 Inc Compiler: 1.29.4 Inc ClmImport: 1.36.3 Creation: 2017-10-23 03:47:14 
[    4.653711] uart-pl011 3f201000.serial: no DMA platform data
[    5.262444] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[    5.262495] brcmfmac: power management disabled
[    5.553997] Process accounting resumed
[    5.788790] Adding 102396k swap on /var/swap.  Priority:-2 extents:1 across:102396k SSFS
[    5.827103] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
[    5.827305] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[    7.266908] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[    9.231593] Bluetooth: Core ver 2.22
[    9.231749] NET: Registered protocol family 31
[    9.231756] Bluetooth: HCI device and connection manager initialized
[    9.233499] Bluetooth: HCI socket layer initialized
[    9.233524] Bluetooth: L2CAP socket layer initialized
[    9.233588] Bluetooth: SCO socket layer initialized
[    9.263519] Bluetooth: HCI UART driver ver 2.3
[    9.263534] Bluetooth: HCI UART protocol H4 registered
[    9.263541] Bluetooth: HCI UART protocol Three-wire (H5) registered
[    9.263800] Bluetooth: HCI UART protocol Broadcom registered
[    9.463472] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[    9.463481] Bluetooth: BNEP filters: protocol multicast
[    9.463503] Bluetooth: BNEP socket layer initialized
[    9.519323] Bluetooth: RFCOMM TTY layer initialized
[    9.519370] Bluetooth: RFCOMM socket layer initialized
[    9.519398] Bluetooth: RFCOMM ver 1.11
[   10.458720] fuse init (API version 7.26)


  • 전체시간- dmesg 비교 
dmesg의 정보와 비교해보면 각각의 시간차이가 존재하며, 이부분은 어쩔수 없는 것 같다.
일단 비교를 해보자.

$ systemd-analyze 
Startup finished in 1.422s (kernel) + 8.050s (userspace) = 9.472s

상위에서 Kernel이라고 생각하는 부분이 systemd의 첫번째 실행시간 같으며, 그전의 시간을 Kernel이라고 생각하는 것 같다.

요즘 Filesystem의 구조를 보면 sysvInit 구성에서 systemd의 구성으로 변경이 되고 있지만,혼재되어 사용되어지기 때문에 이를 가지고 정확한  데이타로 보기는 힘들것 같다.



  • Service 실행시간 비교 
아래부분은 systemd의 시간비교이기 때문에, Kernel 제외를 해야겠지만, init부분도 포함되어지는 것 같다.

$ systemd-analyze blame   // 상위가 마지막으로 실행된 서비스 
          4.893s hciuart.service
          1.917s networking.service
          1.600s dphys-swapfile.service
          1.210s bootchart.service
          1.200s bootchart-done.service
          1.186s dev-mmcblk0p2.device
          1.149s acct.service
          1.139s raspi-config.service
           719ms lightdm.service
           704ms keyboard-setup.service
           603ms systemd-logind.service
           368ms polkit.service
           359ms ssh.service
           329ms avahi-daemon.service
           322ms systemd-timesyncd.service
           314ms systemd-fsck@dev-disk-by\x2dpartuuid-0c830106\x2d01.service
           304ms systemd-udev-trigger.service
           291ms udisks2.service
           270ms systemd-fsck-root.service
           265ms systemd-udevd.service
           229ms rsyslog.service
           219ms dhcpcd.service
           201ms systemd-journald.service
           169ms fake-hwclock.service
           167ms gldriver-test.service
           160ms wifi-country.service
           156ms systemd-tmpfiles-setup-dev.service
           148ms triggerhappy.service
           144ms systemd-tmpfiles-setup.service
           134ms user@1000.service
           132ms bluetooth.service
           114ms plymouth-start.service
           112ms systemd-remount-fs.service
           105ms alsa-restore.service
           103ms sys-kernel-debug.mount
            97ms run-rpc_pipefs.mount
            90ms systemd-journal-flush.service
            81ms dev-mqueue.mount
            78ms systemd-update-utmp.service
            74ms kmod-static-nodes.service
            71ms systemd-random-seed.service
            70ms systemd-modules-load.service
            67ms boot.mount
            57ms systemd-sysctl.service
            53ms plymouth-read-write.service
            49ms console-setup.service
            48ms plymouth-quit-wait.service
            43ms systemd-update-utmp-runlevel.service
            34ms rc-local.service
            34ms nfs-config.service
            33ms systemd-rfkill.service
            32ms plymouth-quit.service
            27ms systemd-user-sessions.service
            26ms sys-kernel-config.mount
            17ms sys-fs-fuse-connections.mount



  • Target 분석 

Unit 단위로 Tree형태로 @와  offset 시간을 제공을 해주고 잇다.

$  systemd-analyze critical-chain
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 @7.995s
└─multi-user.target @7.994s
  └─bluealsa.service @7.994s
    └─bluetooth.service @7.858s +132ms
      └─hciuart.service @2.958s +4.893s
        └─basic.target @2.768s
          └─sockets.target @2.768s
            └─avahi-daemon.socket @2.768s
              └─sysinit.target @2.766s
                └─systemd-timesyncd.service @2.442s +322ms
                  └─systemd-tmpfiles-setup.service @2.283s +144ms
                    └─local-fs.target @2.275s
                      └─run-user-1000.mount @6.960s
                        └─local-fs-pre.target @1.468s
                          └─keyboard-setup.service @760ms +704ms
                            └─system.slice @688ms
                              └─-.slice @568ms



  • 전체시간을 그림표현 

$ systemd-analyze plot > plot.svg   // svg 그림파일로 변경 
$ eog plot.svg   // svg 파일 확인 or 브라우저 확인 

기본이 Kernel Boot 부터 본인의 boot mode의 target (e.g multi-user.target)까지 의 분석이며, 착각하지 말아야 할거이 부팅때마다 다를 수 있다는 것을 명심하자




좀더 자세한 분석 방법은 아래의 메뉴얼참조
  https://jlk.fjfi.cvut.cz/arch/manpages/man/systemd-analyze.1
  https://wiki.archlinux.org/index.php/Improving_performance/Boot_process
  http://man7.org/linux/man-pages/man1/systemd-analyze.1.html