Yun Boot time after hitting [YUN RST] averages 1:02

While working to document the UCI system, I rebooted my Yun to have it connect to the local AP (jack in the box in my case). The wifi can be unreliable especially when the restaurant is full, but tonight it was just me. So when it did not responded as expected I connected the YunSerialTerminal I notice it had gone into a reset of the wifi connection.

So, with this I hit the [YUN RST] button (see image). As I watched reboot I notice it stalled just as it was loading the ExtRoot (the SD). When it finished at 55.290000, I decide to see it that was the actual boot time, so I pulled out my stopwatch, hit the [YUN RST] button, and started the stopwatch. Three (3) times I did this. The consistent reboot time was about 1:02 - one (1) minute and two (2) seconds.

Please note I have a BLE (bluetooth) driver installed. This likely affected the boot time. How much, I am not sure.

In any case, if you have your Yun nearby please try this and time the reboot, and I will post it in the next few days in my public documentation.

A record of the boot log will be in the next message.

Jesse

root@Arduino:/# dmesg
[    0.000000] Linux version 3.3.8 (jenkins@jenkins) (gcc version 4.6.3 20120201 (prerelease) (Linaro GCC 4.6-2012.02) ) #1 Fri Nov 14 08:57:34 CET 2014
::::SNIP - everything in here was set between 0.000000 and 2.960000 ::::
[    2.960000] Freeing unused kernel memory: 180k freed
[    3.260000] usb 1-1: new high-speed USB device number 2 using ehci-platform
[    3.540000] usb 1-1: New USB device found, idVendor=058f, idProduct=6254
[    3.540000] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
[    3.540000] usb 1-1: Product: USB2.0Hub
[    3.710000] hub 1-1:1.0: USB hub found
[    3.710000] hub 1-1:1.0: 4 ports detected
[    4.020000] usb 1-1.4: new high-speed USB device number 3 using ehci-platform
[    4.190000] usb 1-1.4: New USB device found, idVendor=058f, idProduct=6366
[    4.190000] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[    4.200000] usb 1-1.4: Product: Mass Storage Device
[    4.200000] usb 1-1.4: Manufacturer: Generic
[    4.200000] usb 1-1.4: SerialNumber: 058F0O1111B1
[    4.240000] scsi0 : usb-storage 1-1.4:1.0
[    4.990000] Error: Driver 'gpio-keys-polled' is already registered, aborting...
[    5.240000] scsi 0:0:0:0: Direct-Access     Multi    Flash Reader     1.00 PQ: 0 ANSI: 0
[    6.220000] Registered led device: ds:green:usb
[    6.220000] Registered led device: ds:green:wlan
[    9.550000] JFFS2 notice: (526) jffs2_build_xattr_subsystem: complete building xattr subsystem, 1 of xdatum (1 unchecked, 0 orphan) and 11 of xref (0 dead, 0 orphan) found.
[   11.350000] sd 0:0:0:0: [sda] 15523840 512-byte logical blocks: (7.94 GB/7.40 GiB)
[   11.350000] sd 0:0:0:0: [sda] Write Protect is off
[   11.350000] sd 0:0:0:0: [sda] Mode Sense: 03 00 00 00
[   11.350000] sd 0:0:0:0: [sda] No Caching mode page present
[   11.350000] sd 0:0:0:0: [sda] Assuming drive cache: write through
[   11.360000] sd 0:0:0:0: [sda] No Caching mode page present
[   11.360000] sd 0:0:0:0: [sda] Assuming drive cache: write through
[   11.380000]  sda: sda1 sda2
[   11.380000] sd 0:0:0:0: [sda] No Caching mode page present
[   11.380000] sd 0:0:0:0: [sda] Assuming drive cache: write through
[   11.390000] sd 0:0:0:0: [sda] Attached SCSI removable disk
[   31.980000] EXT4-fs (sda2): recovery complete
[   31.980000] EXT4-fs (sda2): mounted filesystem with ordered data mode. Opts: (null)
[   39.010000] Loading modules backported from Linux version master-2014-05-22-0-gf2032ea
[   39.010000] Backport generated by backports.git backports-20140320-37-g5c33da0
[   39.190000] cfg80211: Calling CRDA to update world regulatory domain
[   39.190000] cfg80211: World regulatory domain updated:
[   39.190000] cfg80211:  DFS Master region: unset
[   39.190000] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time)
[   39.200000] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
[   39.200000] cfg80211:   (2457000 KHz - 2482000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
[   39.200000] cfg80211:   (2474000 KHz - 2494000 KHz @ 20000 KHz), (N/A, 2000 mBm), (N/A)
[   39.210000] cfg80211:   (5170000 KHz - 5250000 KHz @ 80000 KHz), (N/A, 2000 mBm), (N/A)
[   39.210000] cfg80211:   (5735000 KHz - 5835000 KHz @ 80000 KHz), (N/A, 2000 mBm), (N/A)
[   39.210000] cfg80211:   (57240000 KHz - 63720000 KHz @ 2160000 KHz), (N/A, 0 mBm), (N/A)
[   40.180000] ath: EEPROM regdomain: 0x0
[   40.180000] ath: EEPROM indicates default country code should be used
[   40.180000] ath: doing EEPROM country->regdmn map search
[   40.180000] ath: country maps to regdmn code: 0x3a
[   40.180000] ath: Country alpha2 being used: US
[   40.180000] ath: Regpair used: 0x3a
[   40.200000] ieee80211 phy0: Selected rate control algorithm 'minstrel_ht'
[   40.200000] Registered led device: ath9k-phy0
[   40.200000] ieee80211 phy0: Atheros AR9330 Rev:1 mem=0xb8100000, irq=2
[   40.200000] cfg80211: Calling CRDA for country: US
[   40.210000] cfg80211: Regulatory domain changed to country: US
[   40.210000] cfg80211:  DFS Master region: FCC
[   40.210000] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time)
[   40.210000] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (N/A, 3000 mBm), (N/A)
[   40.220000] cfg80211:   (5170000 KHz - 5250000 KHz @ 80000 KHz), (N/A, 1700 mBm), (N/A)
[   40.220000] cfg80211:   (5250000 KHz - 5330000 KHz @ 80000 KHz), (N/A, 2300 mBm), (0 s)
[   40.230000] cfg80211:   (5735000 KHz - 5835000 KHz @ 80000 KHz), (N/A, 3000 mBm), (N/A)
[   40.230000] cfg80211:   (57240000 KHz - 63720000 KHz @ 2160000 KHz), (N/A, 4000 mBm), (N/A)
[   40.660000] NTFS driver 2.1.30 [Flags: R/O MODULE].
[   40.700000] Error: Driver 'gpio-keys-polled' is already registered, aborting...
[   40.720000] loop: module loaded
[   40.860000] PPP generic driver version 2.4.2
[   40.920000] ip_tables: (C) 2000-2006 Netfilter Core Team
[   41.040000] NET: Registered protocol family 24
[   41.080000] nf_conntrack version 0.5.0 (954 buckets, 3816 max)
[   41.530000] i2c /dev entries driver
[   41.570000] Linux video capture interface: v2.00
[   41.720000] fuse init (API version 7.18)
[   41.760000] Bluetooth: Core ver 2.16
[   41.760000] NET: Registered protocol family 31
[   41.760000] Bluetooth: HCI device and connection manager initialized
[   41.770000] Bluetooth: HCI socket layer initialized
[   41.770000] Bluetooth: L2CAP socket layer initialized
[   41.770000] Bluetooth: SCO socket layer initialized
[   41.790000] Bluetooth: RFCOMM TTY layer initialized
[   41.790000] Bluetooth: RFCOMM socket layer initialized
[   41.800000] Bluetooth: RFCOMM ver 1.11
[   41.810000] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[   41.810000] Bluetooth: BNEP filters: protocol multicast
[   41.830000] Bluetooth: HIDP (Human Interface Emulation) ver 1.2
[   41.850000] Bluetooth: HCI UART driver ver 2.2
[   41.850000] Bluetooth: HCI H4 protocol initialized
[   41.850000] Bluetooth: HCI BCSP protocol initialized
[   41.870000] usbcore: registered new interface driver btusb
[   51.870000] cfg80211: Calling CRDA for country: MX
[   51.870000] cfg80211: Regulatory domain changed to country: MX
[   51.870000] cfg80211:  DFS Master region: FCC
[   51.870000] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time)
[   51.880000] cfg80211:   (2402000 KHz - 2482000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
[   51.880000] cfg80211:   (5170000 KHz - 5250000 KHz @ 80000 KHz), (N/A, 1700 mBm), (N/A)
[   51.880000] cfg80211:   (5250000 KHz - 5330000 KHz @ 80000 KHz), (N/A, 2400 mBm), (0 s)
[   51.890000] cfg80211:   (5490000 KHz - 5730000 KHz @ 80000 KHz), (N/A, 2400 mBm), (0 s)
[   51.890000] cfg80211:   (5735000 KHz - 5835000 KHz @ 80000 KHz), (N/A, 3000 mBm), (N/A)
[   55.250000] wlan0: authenticate with 00:25:9c:28:49:cd
[   55.250000] wlan0: send auth to 00:25:9c:28:49:cd (try 1/3)
[   55.260000] wlan0: authenticated
[   55.270000] ath9k ar933x_wmac: wlan0: disabling HT as WMM/QoS is not supported by the AP
[   55.280000] ath9k ar933x_wmac: wlan0: disabling VHT as WMM/QoS is not supported by the AP
[   55.290000] wlan0: associate with 00:25:9c:28:49:cd (try 1/3)
[   55.290000] wlan0: RX AssocResp from 00:25:9c:28:49:cd (capab=0x401 status=0 aid=7)
[   55.290000] wlan0: associated
root@Arduino:/#

Tried with mine, 1 minute and 1 second until

[   53.950000] wlan0: associated

I never got out a stop watch, but right around one minute sounds like what I’ve been experiencing with my Yuns.

This is also consistent with my results, sorry I don't have accurate numbers to hand. One thing I spot from the logs is that there's plenty of time spent checking the external disks so possibly a faster class of SDCard or possibly formatting it with less space might improve boot times, as that's 20s of your time right there.

[ 11.390000] sd 0:0:0:0: [sda] Attached SCSI removable disk [ 31.980000] EXT4-fs (sda2): recovery complete

also it's possible that different file systems might make a difference, I've got jffs2 on mine (which is a side effect of using the expand script)

Angelo9999: Tried with mine, 1 minute and 1 second until

[   53.950000] wlan0: associated

Isn't the number 53.95 the Yun's own estimate of the elapsed time ?

...R

Robin2: Isn't the number 53.95 the Yun's own estimate of the elapsed time ?

...R

I think that's the main boot process tracking the time. The missing seven seconds is probably the time it takes uboot and pre-init to run?

ShapeShifter: I think that's the main boot process tracking the time. The missing seven seconds is probably the time it takes uboot and pre-init to run?

@ShapeShifter, Yep. That's it. If you look at my log it shows [   55.290000] wlan0: associated I think it is actually UPTIME in seconds.

@Robin2, give it a try. I assume you have a smartphone. Download a stopwatch and give it a try. Give us your numbers, if you get them. The more measurements, the better. ;)

Jesse

jessemonroy650: @Robin2, give it a try. I assume you have a smartphone. Download a stopwatch and give it a try. Give us your numbers, if you get them. The more measurements, the better. ;)

I'm not sure what you are trying to do.

Are you trying to figure out the difference between the actual time and the time reported by the Yun ?

...R

Robin2: I'm not sure what you are trying to do.

Are you trying to figure out the difference between the actual time and the time reported by the Yun ?

...R

@Robin2,

The purpose of this is to have an average expected boot time. This will assist both new people using the Yun and Designers. For instance, I'm working on a system truck trailers. One constant question is, should I tap power from a 12V system, should I provide my own power generator (maybe solar), or should I run on batteries.

This help me, IF run a 5% duty cycle to extend my battery life. So now if that is acceptable, should I use store and forward on my sensors? and how much will that increase my BOM (Bill of Materials)?

This recent post, Low power Yún, by Workshopshed shows how some planning and information like this helps.

Jesse

jessemonroy650: The purpose of this is to have an average expected boot time.

I will do some tests in the morning. What level of accuracy are you interested in - for example is the Yun's own timing sufficient?

Is there any reason to suspect that there is significant variation between individual Yuns ?

...R

Robin2: I will do some tests in the morning. 1) What level of accuracy are you interested in - for example is the Yun's own timing sufficient?

2) Is there any reason to suspect that there is significant variation between individual Yuns ?

...R

On #1, plus or minus a few seconds is okay. For this a stopwatch has plenty of accuracy.

On #2, No reason to suspect any variation. However, starting extra software, like an Apache Server or some type of Database engine (mySQL for example), or added hardware like an external HD, will likely have some affect.

Respectfully Jesse

Here are my results - hope they are properly explained.

My Yun has been updated and has had the disk space extended.

It seems to take about 8 seconds before the Yun's own timer starts counting - so that 0secs on the Yun clock represents about 8secs on the stopwatch.

My Yun is set up to connect to a HotSpot on my phone.

I have the impression that the Yun is not accessible over WiFi until the bright white USB light comes on - which seems to be about 10 secs after the Yun stops counting. On the other hand it shows up connected on my Phone when it gets to the end of its own count.

With a number of tries the Yun finished counting showing just over 57secs on its own clock - that corresponds to 1:05 secs on the stopwatch. And the USB light would come on at about 1:15 secs (stopwatch time).

When I removed the SD Card the startup time was about 3 seconds shorter.

When I switched off the phone HotSpot the Yun reboooted after 134secs (its own time) and the reboot took about 43 secs. At that stage I could connect to it using its own Access Point.

I had assumed that following a failed attempt to connect that it would then stay using its own AP for subsequent reboots - but that did not happen. It again tried to connect to the phone and rebooted after 134 secs. On a 3rd reboot (with the phone HotSpot renabled) it connected to the phone in the normal way with the normal timing.

Inadvertantly all of these tests were done with the bridge command shell on ttyATH0 disabled - the line ttyATH0::askfirst:/bin/ash --login in the file /etc/inittab was commented out.

Re-enabling the bridge command shell made no difference to the startup time.

...R

Robin2: Inadvertantly all of these tests were done with the bridge disabled - the line ttyATH0::askfirst:/bin/ash --login in the file /etc/inittab was commented out.

A minor nit, but commenting out that line doesn't really disable the bridge. It disables the command shell on that serial port. That, of course, has the effect of not allowing a sketch to later start the bridge communications, but it has other implications as well.

As Jesse will no doubt agree, I tend to be stickler for using the proper terminology -- it helps to prevent confusion. ;)

ShapeShifter: I tend to be stickler for using the proper terminology -- it helps to prevent confusion. ;)

I have no problem with that - I will edit my Post.

...R

@Robin2, The work that you did with those measurement was more than I could ask for. And, yes ShapeShifter can be a stickler about proper terminology Jesse