This thread has been locked.

If you have a related question, please click the "Ask a related question" button in the top right corner. The newly created question will be automatically linked to this question.

AM3352: Kernel booting takes long time

Part Number: AM3352
Other Parts Discussed in Thread: TPS65217

Hello,

I am booting from MMC card.

AM3352 takes nearly about 110 Sec to boot. below is the log for the same.


Starting kernel ...

[ 0.000000] Booting Linux on physical CPU 0x0
[ 0.000000] Linux version 4.19.94-gbe5389fd85 (root@ubuntu) (gcc version 7.5.0 (Linaro GCC 7.5-2019.12)) #20 PREEMPT Fri Oct 1 14:49:01 IST 2021
[ 0.000000] CPU: ARMv7 Processor [413fc082] revision 2 (ARMv7), cr=10c5387d
[ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[ 0.000000] OF: fdt: Machine model: TI AM335x BeagleBone Black
[ 0.000000] Memory policy: Data cache writeback
[ 0.000000] efi: Getting EFI parameters from FDT:
[ 0.000000] efi: UEFI not found.
[ 0.000000] cma: Reserved 48 MiB at 0xbd000000
[ 0.000000] CPU: All CPU(s) started in SVC mode.
[ 0.000000] AM335X ES2.1 (neon)
[ 0.000000] random: get_random_bytes called from start_kernel+0xa4/0x434 with crng_init=0
[ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 260416
[ 0.000000] Kernel command line: console=ttyO0,115200n8 root=/dev/mmcblk0p2 rw rootfstype=ext4 rootwait mem=1024M
[ 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: 975348K/1048576K available (9216K kernel code, 307K rwdata, 2716K rodata, 1024K init, 254K bss, 24076K reserved, 49152K cma-reserved, 212992K highmem)
[ 0.000000] Virtual kernel memory layout:
[ 0.000000] vector : 0xffff0000 - 0xffff1000 ( 4 kB)
[ 0.000000] fixmap : 0xffc00000 - 0xfff00000 (3072 kB)
[ 0.000000] vmalloc : 0xf0800000 - 0xff800000 ( 240 MB)
[ 0.000000] lowmem : 0xc0000000 - 0xf0000000 ( 768 MB)
[ 0.000000] pkmap : 0xbfe00000 - 0xc0000000 ( 2 MB)
[ 0.000000] modules : 0xbf000000 - 0xbfe00000 ( 14 MB)
[ 0.000000] .text : 0x(ptrval) - 0x(ptrval) (10208 kB)
[ 0.000000] .init : 0x(ptrval) - 0x(ptrval) (1024 kB)
[ 0.000000] .data : 0x(ptrval) - 0x(ptrval) ( 308 kB)
[ 0.000000] .bss : 0x(ptrval) - 0x(ptrval) ( 255 kB)
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[ 0.000000] rcu: Preemptible hierarchical RCU implementation.
[ 0.000000] Tasks RCU enabled.
[ 0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[ 0.000000] IRQ: Found an INTC at 0x(ptrval) (revision 5.0) with 128 interrupts
[ 0.000000] OMAP clockevent source: timer2 at 24000000 Hz
[ 0.000035] sched_clock: 32 bits at 24MHz, resolution 41ns, wraps every 89478484971ns
[ 0.000085] clocksource: timer1: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 79635851949 ns
[ 0.000112] OMAP clocksource: timer1 at 24000000 Hz
[ 0.000518] timer_probe: no matching timers found
[ 0.000909] Console: colour dummy device 80x30
[ 0.000969] WARNING: Your 'console=ttyO0' has been replaced by 'ttyS0'
[ 0.000986] This ensures that you still see kernel messages. Please
[ 0.001002] update your kernel commandline.
[ 0.001109] Calibrating delay loop... 298.59 BogoMIPS (lpj=1492992)
[ 0.067596] pid_max: default: 32768 minimum: 301
[ 0.068103] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.068153] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.069944] CPU: Testing write buffer coherency: ok
[ 0.070073] CPU0: Spectre v2: using BPIALL workaround
[ 0.071948] Setting up static identity map for 0x80100000 - 0x80100060
[ 0.072322] rcu: Hierarchical SRCU implementation.
[ 0.073226] EFI services will not be available.
[ 0.076976] devtmpfs: initialized
[ 0.098459] VFP support v0.3: implementor 41 architecture 3 part 30 variant c rev 3
[ 0.099310] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[ 0.099365] futex hash table entries: 256 (order: -1, 3072 bytes)
[ 0.108097] pinctrl core: initialized pinctrl subsystem
[ 0.109672] DMI not present or invalid.
[ 0.110617] NET: Registered protocol family 16
[ 0.116030] DMA: preallocated 256 KiB pool for atomic coherent allocations
[ 0.164290] l4_wkup_cm:clk:0010:0: failed to disable
[ 0.240209] cpuidle: using governor ladder
[ 0.240302] cpuidle: using governor menu
[ 0.253398] OMAP GPIO hardware version 0.1
[ 0.279878] No ATAGs?
[ 0.279899] hw-breakpoint: debug architecture 0x4 unsupported.
[ 0.317913] edma 49000000.edma: TI EDMA DMA engine driver
[ 0.325743] SCSI subsystem initialized
[ 0.326967] media: Linux media interface: v0.10
[ 0.327099] videodev: Linux video capture interface: v2.00
[ 0.327335] pps_core: LinuxPPS API ver. 1 registered
[ 0.327357] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[ 0.327416] PTP clock support registered
[ 0.327509] EDAC MC: Ver: 3.0.0
[ 0.330047] omap-mailbox 480c8000.mailbox: omap mailbox rev 0x400
[ 0.331379] Advanced Linux Sound Architecture Driver Initialized.
[ 0.334012] clocksource: Switched to clocksource timer1
[ 0.356162] NET: Registered protocol family 2
[ 0.357989] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 4096 bytes)
[ 0.358077] TCP established hash table entries: 8192 (order: 3, 32768 bytes)
[ 0.358300] TCP bind hash table entries: 8192 (order: 3, 32768 bytes)
[ 0.358515] TCP: Hash tables configured (established 8192 bind 8192)
[ 0.358803] UDP hash table entries: 512 (order: 1, 8192 bytes)
[ 0.358880] UDP-Lite hash table entries: 512 (order: 1, 8192 bytes)
[ 0.359255] NET: Registered protocol family 1
[ 0.360500] RPC: Registered named UNIX socket transport module.
[ 0.360537] RPC: Registered udp transport module.
[ 0.360554] RPC: Registered tcp transport module.
[ 0.360572] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 0.362581] hw perfevents: enabled with armv7_cortex_a8 PMU driver, 5 counters available
[ 0.366102] Initialise system trusted keyrings
[ 0.366598] workingset: timestamp_bits=14 max_order=18 bucket_order=4
[ 0.379840] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[ 0.381552] NFS: Registering the id_resolver key type
[ 0.381644] Key type id_resolver registered
[ 0.381666] Key type id_legacy registered
[ 0.381770] ntfs: driver 2.1.32 [Flags: R/O].
[ 0.387577] Key type asymmetric registered
[ 0.387620] Asymmetric key parser 'x509' registered
[ 0.387785] bounce: pool size: 64 pages
[ 0.387928] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 245)
[ 0.387957] io scheduler noop registered
[ 0.387978] io scheduler deadline registered
[ 0.388578] io scheduler cfq registered (default)
[ 0.388610] io scheduler mq-deadline registered
[ 0.388631] io scheduler kyber registered
[ 0.393296] pinctrl-single 44e10800.pinmux: 142 pins, size 568
[ 0.530495] Serial: 8250/16550 driver, 10 ports, IRQ sharing enabled
[ 0.540163] 44e09000.serial: ttyS0 at MMIO 0x44e09000 (irq = 30, base_baud = 3000000) is a 8250
[ 1.160605] console [ttyS0] enabled
[ 1.166815] 48022000.serial: ttyS1 at MMIO 0x48022000 (irq = 31, base_baud = 3000000) is a 8250
[ 1.178144] 48024000.serial: ttyS2 at MMIO 0x48024000 (irq = 32, base_baud = 3000000) is a 8250
[ 1.189482] 481a6000.serial: ttyS3 at MMIO 0x481a6000 (irq = 33, base_baud = 3000000) is a 8250
[ 1.200813] 481a8000.serial: ttyS4 at MMIO 0x481a8000 (irq = 34, base_baud = 3000000) is a 8250
[ 1.212129] 481aa000.serial: ttyS5 at MMIO 0x481aa000 (irq = 35, base_baud = 3000000) is a 8250
[ 1.225732] omap_rng 48310000.rng: Random Number Generator ver. 20
[ 1.234307] random: fast init done
[ 1.238175] random: crng init done
[ 1.273258] brd: module loaded
[ 1.293356] loop: module loaded
[ 1.303436] libphy: Fixed MDIO Bus: probed
[ 1.330007] data->bus->name 4a101000.mdio
[ 1.394154] davinci_mdio 4a101000.mdio: davinci mdio revision 1.6, bus freq 500000
[ 1.401799] libphy: 4a101000.mdio: probed
[ 1.408238] davinci_mdio 4a101000.mdio: phy[0]: device 4a101000.mdio:00, driver unknown
[ 1.416529] mdiodev is NULL
[ 1.419441] mdiodev->flags is 0
[ 1.422692] mdiodev is NULL
[ 1.425755] mdiodev is NULL
[ 1.428665] mdiodev is NULL
[ 1.431564] mdiodev is NULL
[ 1.434602] mdiodev is NULL
[ 1.437509] mdiodev is NULL
[ 1.440410] mdiodev is NULL
[ 1.443308] mdiodev is NULL
[ 1.446304] mdiodev is NULL
[ 1.449209] mdiodev is NULL
[ 1.452108] mdiodev is NULL
[ 1.455088] mdiodev is NULL
[ 1.457994] mdiodev is NULL
[ 1.460892] mdiodev is NULL
[ 1.463792] mdiodev is NULL
[ 1.466768] mdiodev is NULL
[ 1.469673] mdiodev is NULL
[ 1.472573] mdiodev is NULL
[ 1.475510] mdiodev is NULL
[ 1.478412] mdiodev is NULL
[ 1.481311] mdiodev is NULL
[ 1.484243] mdiodev is NULL
[ 1.487145] mdiodev is NULL
[ 1.490043] mdiodev is NULL
[ 1.492940] mdiodev is NULL
[ 1.495871] mdiodev is NULL
[ 1.498773] mdiodev is NULL
[ 1.501671] mdiodev is NULL
[ 1.504743] mdiodev is NULL
[ 1.509393] cpsw 4a100000.ethernet: Detected MACID = 14:42:fc:0c:71:bb
[ 1.516132] ### cpsw->bus_freq_mhz :125
[ 1.520285] cpsw 4a100000.ethernet: initialized cpsw ale version 1.4
[ 1.526755] cpsw 4a100000.ethernet: ALE Table size 1024
[ 1.532093] cpsw 4a100000.ethernet: cpts: overflow check period 500 (jiffies)
[ 1.541397] cpsw 4a100000.ethernet: cpsw: Detected MACID = 14:42:fc:0c:71:bd
[ 1.551759] i2c /dev entries driver
[ 1.560269] cpuidle: enable-method property 'ti,am3352' found operations
[ 1.568170] sdhci: Secure Digital Host Controller Interface driver
[ 1.574476] sdhci: Copyright(c) Pierre Ossman
[ 1.580713] omap_gpio 4804c000.gpio: Could not set line 4 debounce to 200000 microseconds (-22)
[ 1.589574] omap_hsmmc 48060000.mmc: Got CD GPIO
[ 1.595314] omap_hsmmc 48060000.mmc: Linked as a consumer to regulator.1
[ 1.629660] omap_hsmmc 481d8000.mmc: Linked as a consumer to regulator.1
[ 1.664611] omap_hsmmc 47810000.mmc: Linked as a consumer to regulator.1
[ 1.695312] mmc0: host does not support reading read-only switch, assuming write-enable
[ 1.703945] sdhci-pltfm: SDHCI platform and OF driver helper
[ 1.712756] ledtrig-cpu: registered to indicate activity on CPUs
[ 1.719233] mmc0: new high speed SDHC card at address aaaa
[ 1.728245] mmcblk0: mmc0:aaaa SC32G 29.7 GiB
[ 1.760149] mmc1: switch to bus width 8 failed
[ 1.796927] mmc1: switch to bus width 4 failed
[ 1.802294] mmc1: new high speed MMC card at address 0001
[ 1.809325] mmc2: queuing unknown CIS tuple 0x80 (2 bytes)
[ 1.823385] mmcblk0: p1 p2 p3 p4 < p5 p6 >
[ 1.828724] mmcblk1: mmc1:0001 MMC02G 1.79 GiB
[ 1.834518] mmc2: queuing unknown CIS tuple 0x80 (3 bytes)
[ 1.840937] NET: Registered protocol family 10
[ 1.850391] mmcblk1boot0: mmc1:0001 MMC02G partition 1 1.00 MiB
[ 1.850793] mmc2: queuing unknown CIS tuple 0x80 (3 bytes)
[ 1.863752] mmcblk1boot1: mmc1:0001 MMC02G partition 2 1.00 MiB
[ 1.872333] Segment Routing with IPv6
[ 1.876539] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
[ 1.883163] mmcblk1rpmb: mmc1:0001 MMC02G partition 3 128 KiB, chardev (244:0)
[ 1.892664] mmc2: queuing unknown CIS tuple 0x80 (7 bytes)
[ 1.898449] NET: Registered protocol family 17
[ 1.903495] Key type dns_resolver registered
[ 1.910436] omap_voltage_late_init: Voltage driver support not added
[ 1.920530] mmc2: queuing unknown CIS tuple 0x80 (6 bytes)
[ 1.929883] Loading compiled-in X.509 certificates
[ 2.000183] mmc2: new high speed SDIO card at address 0001
[ 2.005893] vdd_mpu: Bringing 900000uV into 925000-925000uV
[ 2.019103] vdd_core: Bringing 900000uV into 925000-925000uV
[ 2.035893] vdd_1v8: Bringing 1500000uV into 1800000-1800000uV
[ 2.054462] tps65217 0-002d: TPS65217 ID 0x0 version 1.0
[ 2.060691] omap_i2c 44e0b000.i2c: bus 0 rev0.11 at 400 kHz
[ 2.068812] omap_i2c 4802a000.i2c: bus 1 rev0.11 at 400 kHz
[ 2.075075] pinctrl-single 44e10800.pinmux: pin PIN2 already requested by 44e10800.pinmux; cannot claim for 4819c000.i2c
[ 2.086100] pinctrl-single 44e10800.pinmux: pin-2 (4819c000.i2c) status -22
[ 2.093123] pinctrl-single 44e10800.pinmux: could not request pin 2 (PIN2) from group pinmux_i2c2_pins on device pinctrl-single
[ 2.104830] omap_i2c 4819c000.i2c: Error applying setting, reverse things back
[ 2.112152] omap_i2c: probe of 4819c000.i2c failed with error -22
[ 2.120084] cpu cpu0: Linked as a consumer to regulator.3
[ 2.125767] cpu cpu0: Dropping the link to regulator.3
[ 2.131765] cpu cpu0: Linked as a consumer to regulator.3
[ 2.137793] cpufreq: cpufreq_online: CPU0: Running at unlisted freq: 600000 KHz
[ 2.145360] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 600000000 (-34)
[ 2.159228] cpufreq: cpufreq_online: CPU0: Unlisted initial frequency changed to: 300000 KHz
[ 2.170524] hctosys: unable to open rtc device (rtc0)
[ 2.177895] ALSA device list:
[ 2.180946] No soundcards found.
[ 2.281288] EXT4-fs (mmcblk0p2): recovery complete
[ 2.288087] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[ 2.296641] VFS: Mounted root (ext4 filesystem) on device 179:2.
[ 2.322705] devtmpfs: mounted
[ 2.335372] Freeing unused kernel memory: 1024K
[ 2.342811] Run /sbin/init as init process
[ 2.833539] systemd[1]: System time before build time, advancing clock.
[ 2.941683] systemd[1]: systemd 239 running in system mode. (+PAM -AUDIT -SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP -LIBCRYPTSETUP -GCRYPT -GNUTLS +ACL +XZ -LZ4 -SECCOMP +BLKID -ELFUTILS +KMOD -IDN2 -IDN -PCRE2 default-hierarchy=hybrid)
[ 2.966602] systemd[1]: Detected architecture arm.

Welcome to Arago 2019.11!

[ 3.068981] systemd[1]: Set hostname to <am335x-evm>.
[ 4.104888] systemd[1]: File /lib/systemd/system/systemd-journald.service:36 configures an IP firewall (IPAddressDeny=any), but the local system does not support BPF/cgroup based firewalling.
[ 4.122528] systemd[1]: Proceeding WITHOUT firewalling in effect! (This warning is only shown for the first loaded unit using IP firewalling.)
[ 5.735719] systemd[1]: Reached target Swap.
[ OK ] Reached target Swap.
[ 5.775352] systemd[1]: Reached target Slices.
[ OK ] Reached target Slices.
[ 6.002967] systemd[1]: Listening on Process Core Dump Socket.
[ OK ] Listening on Process Core Dump Socket.
[ 6.054673] systemd[1]: Created slice system-getty.slice.
[ OK ] Created slice system-getty.slice.
[ 6.087551] systemd[1]: Listening on udev Kernel Socket.
[ OK ] Listening on udev Kernel Socket.
[ OK ] Started Forward Password Requests to Wall Directory Watch.
[ OK ] Reached target Remote File Systems.
[ OK ] Created slice system-serial\x2dgetty.slice.
[ OK ] Listening on udev Control Socket.
[ OK ] Started Dispatch Password Requests to Console Directory Watch.
[ OK ] Reached target Paths.
[ OK ] Listening on Journal Socket.
Mounting Kernel Debug File System...
Mounting Temporary Directory (/tmp)...
Starting Create list of required st…ce nodes for the current kernel...
Starting Apply Kernel Variables...
Mounting POSIX Message Queue File System...
Mounting Kernel Configuration File System...
[ OK ] Reached target Containers.
Mounting /media/ram...
Starting udev Coldplug all Devices...
[ OK ] Listening on initctl Compatibility Named Pipe.
[ OK ] Listening on Journal Socket (/dev/log).
Starting Journal Service...
Mounting /var/volatile...
[ OK ] Listening on Network Service Netlink Socket.
[ OK ] Mounted Kernel Debug File System.
[ OK ] Mounted Temporary Directory (/tmp).
[ OK ] Started Create list of required sta…vice nodes for the current kernel.
[ 7.946341] systemd[1]: Started Apply Kernel Variables.
[ OK ] Started Apply Kernel Variables.
[ 7.970224] systemd[1]: Mounted POSIX Message Queue File System.
[ OK ] Mounted POSIX Message Queue File System.
[ 8.019231] systemd[1]: Mounted Kernel Configuration File System.
[ OK ] Mounted Kernel Configuration File System.
[ 8.078578] systemd[1]: Mounted /media/ram.
[ OK ] Mounted /media/ram.
[ 8.138451] systemd[1]: Mounted /var/volatile.
[ OK ] Mounted /var/volatile.
[ 8.290900] systemd[1]: Starting Load/Save Random Seed...
Starting Load/Save Random Seed...
[ 8.470255] systemd[1]: Starting Create Static Device Nodes in /dev...
Starting Create Static Device Nodes in /dev...
[ 8.556031] systemd[1]: Reached target Local File Systems.
[ OK ] Reached target Local File Systems.
[ 8.790995] systemd[1]: Started Load/Save Random Seed.
[ OK ] Started Load/Save Random Seed.
[ 9.115903] systemd[1]: Started Create Static Device Nodes in /dev.
[ OK ] Started Create Static Device Nodes in /dev.
Starting udev Kernel Device Manager...
[ OK ] Started Journal Service.
Starting Flush Journal to Persistent Storage...
[ OK ] Started udev Kernel Device Manager.
[ 10.937391] systemd-journald[81]: Received request to flush runtime journal from PID 1
[ OK ] Started Flush Journal to Persistent Storage.
Starting Create Volatile Files and Directories...
[ OK ] Started Create Volatile Files and Directories.
Starting Network Time Synchronization...
Starting Network Service...
Starting Update UTMP about System Boot/Shutdown...
[ OK ] Started Update UTMP about System Boot/Shutdown.
[ OK ] Started Network Service.
Starting Network Name Resolution...
[ OK ] Started Network Time Synchronization.
[ OK ] Reached target System Time Synchronized.
[ OK ] Started Network Name Resolution.
[ OK ] Reached target Network.
[ OK ] Reached target Network is Online.
[ OK ] Reached target Host and Network Name Lookups.
[ 21.615914] omap_wdt: OMAP Watchdog Timer Rev 0x01: initial timeout 60 sec
[ 21.658880] omap_rtc 44e3e000.rtc: already running
[ 21.780164] omap_rtc 44e3e000.rtc: registered as rtc0
[ 22.866025] at24 0-0050: 65536 byte 24c512 EEPROM, writable, 1 bytes/write
[ OK ] Found device /dev/ttyS0.
[ OK ] Started udev Coldplug all Devices.
[ 24.940637] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[ 26.403285] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[ 26.509328] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2
[ 26.674342] cfg80211: failed to load regulatory.db
[ 27.427182] mmc2: queuing unknown CIS tuple 0x80 (2 bytes)
[ 27.536207] mmc2: queuing unknown CIS tuple 0x80 (3 bytes)
[ 27.645240] mmc2: queuing unknown CIS tuple 0x80 (3 bytes)
[ 27.716891] mmc2: queuing unknown CIS tuple 0x80 (7 bytes)
[ 27.816325] mmc2: queuing unknown CIS tuple 0x80 (6 bytes)
[ 28.299773] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[ 28.402838] brcmfmac mmc2:0001:1: Direct firmware load for brcm/brcmfmac43455-sdio.bin failed with error -2
[ 29.514771] brcmfmac: brcmf_sdio_htclk: HT Avail timeout (1000000): clkctl 0x50
[ 29.579937] omap-sham 53100000.sham: hw accel on OMAP rev 4.3
[ 29.692847] omap-aes 53500000.aes: OMAP AES hw accel rev: 3.2
[ 29.730204] wkup_m3_ipc 44e11324.wkup_m3_ipc: could not get rproc handle
[ 29.904735] omap-aes 53500000.aes: will run requests pump with realtime priority
[ 29.937621] wkup_m3_ipc 44e11324.wkup_m3_ipc: could not get rproc handle
[ 29.959558] PM: Cannot get wkup_m3_ipc handle
[ 30.052895] wkup_m3_ipc 44e11324.wkup_m3_ipc: could not get rproc handle
[ 30.175605] PM: Cannot get wkup_m3_ipc handle
[ 30.182690] wkup_m3_ipc 44e11324.wkup_m3_ipc: could not get rproc handle
[ 30.679815] remoteproc remoteproc0: wkup_m3 is available
[ 30.813844] PM: Cannot get wkup_m3_ipc handle
[ 30.925910] PM: Cannot get wkup_m3_ipc handle
[ 30.930857] remoteproc remoteproc0: powering up wkup_m3
[ 31.016750] remoteproc remoteproc0: Booting fw image am335x-pm-firmware.elf, size 242932
[ 31.146478] wkup_m3_ipc 44e11324.wkup_m3_ipc: CM3 Firmware Version = 0x192
[ 31.153533] remoteproc remoteproc0: remote processor wkup_m3 is now up
[ 31.508330] #######LAN9303 MDIO driver Probing Start
[ 31.635379] Phy Device Ready Reg E000000
[ 31.683165] Phy Status Reg 758
[ 31.686735] net eth1: initializing cpsw version 1.12 (0)
[ 31.725197] Chip Rev Register: 1
[ 31.728535] Shifting: 9353
[ 31.771886] net eth1: phy "/ocp/ethernet@4a100000/mdio@4a101000/switch-phy@2" not found on slave 1
[ 31.803773] Phy Address: 3
[ 31.803809] Phy setup '0-1-2' detected
[ 32.056380] IPv6: ADDRCONF(NETDEV_UP): eth1: link is not ready
[ 32.714730] net eth0: initializing cpsw version 1.12 (0)
[ 32.809734] ###Going to Connect
[ 32.813094] ###Going to Attach Phy
[ 32.904625] ###No Driver Found Using Genric Driver
[ 32.910119] Flow Control: 4D01
[ 32.974411] ###d->driver : -1058834740
[ 32.978271] ###Getting Device Driver Module
[ 32.982513] ### Owner : d->driver->owner : (null)
[ 33.126513] PM: bootloader does not support rtc-only!
[ 33.133846] ###Going to Prepare Link
[ 33.164545] ###Preparing Link
[ 33.167712] ###Starting Phy
[ 33.170650] ###Started Phy
[ 33.173549] Generic PHY 4a101000.mdio:00: attached PHY driver [Generic PHY] (mii_bus:phy_addr=4a101000.mdio:00, irq=POLL)
[ 33.425909] ###CPSW### Reg: c5
[ 33.425936] ###CPSW### Phy Mode: 7
[ 33.431161] Tx Config: 0
[ 33.457739] ###CPSW### Clock Details: 0
[ 33.457764] ###CPSW### Slave: 0
[ 33.461715] ###CPSW### Reg: 85
[ 33.476333] LAN9303_MDIO 4a101000.mdio:02: LAN9303 MDIO driver loaded successfully
[ 33.616331] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[ 33.625058] #######LAN9303 MDIO driver Probed successfully
[* ] A start job is running for dev-ttyO0.device (28s / 1min 30s)[ 34.486052] cpsw 4a100000.ethernet eth0: Link is Up - 100Mbps/Full - flow control off
[ 34.546817] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[** ] A start job is running for dev-ttyO0.device (31s / 1min 30s)[ 39.355943] am335x-phy-driver 47401300.usb-phy: 47401300.usb-phy supply vcc not found, using dummy regulator
[ 39.464948] am335x-phy-driver 47401300.usb-phy: Linked as a consumer to regulator.0
[ 39.823140] usbcore: registered new interface driver usbfs
[ 39.944855] usbcore: registered new interface driver hub
[ 40.005893] usbcore: registered new device driver usb
[ 40.479380] musb-hdrc musb-hdrc.0: MUSB HDRC host driver
[ 40.534668] musb-hdrc musb-hdrc.0: new USB bus registered, assigned bus number 1
[ 40.586467] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.19
[ 40.664498] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 40.671871] usb usb1: Product: MUSB HDRC host driver
[ 40.754568] usb usb1: Manufacturer: Linux 4.19.94-gbe5389fd85 musb-hcd
[ 40.761242] usb usb1: SerialNumber: musb-hdrc.0
[ 40.857777] hub 1-0:1.0: USB hub found
[ 40.914728] hub 1-0:1.0: 1 port detected
[ OK ] Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
[ OK ] Reached target System Initialization.
Starting sshd.socket.
[ OK ] Started Daily Cleanup of Temporary Directories.
[ OK ] Reached target Timers.
[ OK ] Listening on D-Bus System Message Bus Socket.
[ OK ] Listening on sshd.socket.
[ OK ] Reached target Sockets.
[ OK ] Reached target Basic System.
Starting LSB: Start NTP daemon...
Starting Permit User Sessions...
Starting syslog.service...
[ OK ] Started D-Bus System Message Bus.
[ OK ] Started Permit User Sessions.
[ OK ] Started LSB: Start NTP daemon.
[ OK ] Started Serial Getty on ttyS0.
[ OK ] Started Getty on tty1.
[ OK ] Started syslog.service.

_____ _____ _ _
| _ |___ ___ ___ ___ | _ |___ ___ |_|___ ___| |_
| | _| .'| . | . | | __| _| . | | | -_| _| _|
|__|__|_| |__,|_ |___| |__| |_| |___|_| |___|___|_|
|___| |___|

Arago Project http://arago-project.org am335x-evm ttyS0

Arago 2019.11 am335x-evm ttyS0

am335x-evm login:

Start job running for dev-ttyO0 device takes so much time. what is the solution for this.

Below is the systemd-analyze blame log .

35.654s dev-mmcblk0p2.device
16.872s systemd-udev-trigger.service
4.282s systemd-timesyncd.service
3.001s systemd-networkd.service
2.443s systemd-journald.service
2.151s syslog.service
2.133s systemd-update-utmp.service
2.011s systemd-resolved.service
1.458s systemd-tmpfiles-setup.service
1.378s sys-kernel-debug.mount
1.322s tmp.mount
1.304s kmod-static-nodes.service
1.268s systemd-sysctl.service
1.247s systemd-journal-flush.service
1.213s dev-mqueue.mount
1.160s sys-kernel-config.mount
1.129s ntpd.service
1.069s media-ram.mount
982ms systemd-user-sessions.service
854ms systemd-udevd.service
741ms var-volatile.mount
645ms systemd-tmpfiles-setup-dev.service
500ms systemd-random-seed.service
297ms systemd-update-utmp-runlevel.service
252ms sshd.socket
140ms sync-clocks.service

Thanks,

Prerak

  • Hi,

    Boot time reduction is a task that TI can provide a few pointers but not support. I will not be able to look at why SystemD is the TTY0 task is taking so long.

    Apologies since I am not following, how is the 110S being measured? the last kernel message shows about 41 seconds, is the console not active?  Are you booting on a custom board? 

    Best Regards,

    Schuyler

  • Hello,

    Thanks for the quick response.

    We have a custom board.

    When we run  systemd-analyze command it throws below print.

    root@am335x-evm:~# ./systemd-analyze
    Startup finished in 2.681s (kernel) + 1min 18.534s (userspace) = 1min 21.216s
    multi-user.target reached after 1min 17.595s in userspace

    I have disable some services to reduce the bootup time... still it takes 80 sec and stuck at A start job is running for dev-ttyO0.device (31s / 1min 30s) Print.

    Thanks,

    Prerak

  • Hi,

    Unfortunately I will not be able to support slow SystemD start on the ttyO0 interface. Is using SystemD a requirement for your application design? 

    Perhaps as a means of experimentation or elimination of issues with the ttyO0 interface you might try the tiny filesystem that comes with the SDK. You will add the DTB and kernel image to the rootfs /boot directory. This file system does not use SystemD.

    Best Regards,

    Schuyler

  • I am using tiny filesystem only. With Full filesystem, My board takes 3 Min to boot.

    Thanks,

    Prerak