Netgate Discussion Forum
    • Categories
    • Recent
    • Tags
    • Popular
    • Users
    • Search
    • Register
    • Login

    Nano slow to mount Read-Only

    Scheduled Pinned Locked Moved 2.2 Snapshot Feedback and Problems - RETIRED
    22 Posts 4 Posters 3.6k Views
    Loading More Posts
    • Oldest to Newest
    • Newest to Oldest
    • Most Votes
    Reply
    • Reply as topic
    Log in to reply
    This topic has been deleted. Only users with topic management privileges can see it.
    • stephenw10S
      stephenw10 Netgate Administrator
      last edited by

      Ctrl-T shows:

      [2.2-ALPHA][root@pfsense.localdomain]/tmp(19): /etc/rc.conf_mount_ro
load: 0.07  cmd: mount 87137 [biowr] 0.36r 0.00u 0.00s 0% 2068k
load: 0.07  cmd: mount 87137 [biowr] 4.31r 0.00u 0.23s 2% 2068k
load: 0.07  cmd: mount 87137 [biowr] 5.10r 0.00u 0.28s 2% 2068k
load: 0.06  cmd: mount 87137 [biowr] 5.88r 0.00u 0.28s 2% 2068k
load: 0.06  cmd: mount 87137 [biowr] 6.79r 0.00u 0.31s 2% 2068k
load: 0.06  cmd: mount 87137 [biowr] 8.09r 0.00u 0.32s 1% 2068k
load: 0.06  cmd: mount 87137 [biowr] 9.04r 0.00u 0.56s 4% 2068k
load: 0.06  cmd: mount 87137 [biowr] 9.98r 0.00u 0.65s 4% 2068k
load: 0.06  cmd: mount 87137 [biowr] 10.91r 0.00u 0.69s 4% 2068k
load: 0.06  cmd: mount 87137 [biowr] 11.48r 0.00u 0.81s 5% 2068k
load: 0.06  cmd: mount 87137 [biowr] 11.72r 0.00u 0.81s 5% 2068k
load: 0.06  cmd: mount 87137 [biowr] 11.91r 0.00u 0.81s 4% 2068k
load: 0.06  cmd: mount 87137 [running] 12.08r 0.00u 0.88s 5% 2068k
load: 0.06  cmd: mount 87137 [running] 13.73r 0.00u 1.40s 10% 2068k
load: 0.05  cmd: mount 87137 [biowr] 14.42r 0.00u 1.57s 10% 2068k
load: 0.05  cmd: mount 87137 [biowr] 15.26r 0.00u 1.63s 10% 2068k
load: 0.05  cmd: mount 87137 [biowr] 16.04r 0.00u 1.63s 9% 2068k
load: 0.05  cmd: mount 87137 [biowr] 16.92r 0.00u 1.73s 9% 2068k
load: 0.05  cmd: mount 87137 [biowr] 17.66r 0.00u 1.79s 9% 2068k
load: 0.05  cmd: mount 87137 [biowr] 18.39r 0.00u 1.84s 9% 2068k
load: 0.05  cmd: mount 87137 [biowr] 19.17r 0.00u 1.86s 8% 2068k
load: 0.05  cmd: mount 87137 [biowr] 20.22r 0.00u 1.90s 8% 2068k
load: 0.05  cmd: mount 87137 [running] 21.02r 0.00u 1.90s 7% 2068k
load: 0.05  cmd: mount 87137 [biowr] 22.14r 0.00u 2.01s 7% 2068k
load: 0.05  cmd: mount 87137 [biowr] 23.01r 0.00u 2.02s 7% 2068k
load: 0.04  cmd: mount 87137 [biowr] 23.81r 0.00u 2.15s 8% 2068k
load: 0.04  cmd: mount 87137 [biowr] 24.60r 0.00u 2.27s 8% 2068k
load: 0.04  cmd: mount 87137 [biowr] 25.39r 0.00u 2.29s 8% 2068k
load: 0.04  cmd: mount 87137 [biowr] 26.20r 0.00u 2.29s 7% 2068k
load: 0.04  cmd: mount 87137 [biowr] 27.01r 0.00u 2.30s 7% 2068k
load: 0.04  cmd: mount 87137 [biowr] 27.77r 0.00u 2.30s 6% 2068k
load: 0.04  cmd: mount 87137 [biowr] 28.75r 0.00u 2.30s 5% 2068k
      1 Reply Last reply Reply Quote 0
      • stephenw10S
        stephenw10 Netgate Administrator
        last edited by

        Ok. I could be mistaken on this. Different system, different card, much older snap:

        [2.2-ALPHA][root@testbox.localdomain]/root(1): uname -a
FreeBSD testbox.localdomain 10.0-STABLE FreeBSD 10.0-STABLE #0 fde2f5e(HEAD)-dirty: Sat Apr 12 14:04:38 CDT 2014     root@builder-10-0-b3-i386:/usr/obj.pfSense/usr/pfSensesrc/src/sys/pfSense_wrap.10.i386  i386
[2.2-ALPHA][root@testbox.localdomain]/root(2): time /etc/rc.conf_mount_rw
0.150u 0.075s 0:03.79 5.8%      3447+428k 1768+35io 0pf+0w
[2.2-ALPHA][root@testbox.localdomain]/root(3): time /etc/rc.conf_mount_ro
0.091u 0.010s 0:00.12 83.3%     4595+431k 0+29io 0pf+0w

        I'll try updating both.

        Steve

        1 Reply Last reply Reply Quote 0
        • stephenw10S
          stephenw10 Netgate Administrator
          last edited by

          Or maybe not. Same box but updated to latest snap:

          [2.2-ALPHA][root@testbox.localdomain]/root(12): uname -a
FreeBSD testbox.localdomain 10.0-STABLE FreeBSD 10.0-STABLE #28 e852cd6(HEAD)-dirty: Tue May 27 11:01:10 CDT 2014     root@pf22-i386-snap:/usr/obj.i386/usr/pfSensesrc/src/sys/pfSense_wrap.10.i386  i386
[2.2-ALPHA][root@testbox.localdomain]/root(13): time /etc/rc.conf_mount_rw
0.080u 0.048s 0:00.41 29.2%     3347+293k 0+30io 0pf+0w
[2.2-ALPHA][root@testbox.localdomain]/root(14): time /etc/rc.conf_mount_ro
0.085u 1.249s 0:22.28 5.9%      348+187k 0+589io 0pf+0w

          However on this latest snap I have check_reload_status eating 100% CPU so this may not be a fair test.  ;)

          Steve

          1 Reply Last reply Reply Quote 0
          • stephenw10S
            stephenw10 Netgate Administrator
            last edited by

            Latest snap on the original box seems to show no delay:

            
[2.2-ALPHA][root@pfsense.localdomain]/root(4): uname -a
FreeBSD pfsense.localdomain 10.0-STABLE FreeBSD 10.0-STABLE #73 e852cd6(HEAD)-dirty: Tue May 27 10:51:27 CDT 2014     root@pf22-amd64-snap:/usr/obj.amd64/usr/pfSensesrc/src/sys/pfSense_SMP.10  amd64
[2.2-ALPHA][root@pfsense.localdomain]/root(5): time /etc/rc.conf_mount_rw
0.063u 0.015s 0:00.07 100.0%    4668+360k 0+18io 0pf+0w
[2.2-ALPHA][root@pfsense.localdomain]/root(6): time /etc/rc.conf_mount_ro
0.047u 0.031s 0:00.07 100.0%    4668+360k 0+18io 0pf+0w

            Steve

            1 Reply Last reply Reply Quote 0
            • stephenw10S
              stephenw10 Netgate Administrator
              last edited by

              Hmm, so it showed no delay imediately after the update but this morning:

              [2.2-ALPHA][root@pfsense.localdomain]/root(3): time /etc/rc.conf_mount_rw
0.076u 0.016s 0:00.59 13.5%	4087+332k 0+30io 0pf+0w
[2.2-ALPHA][root@pfsense.localdomain]/root(4): time /etc/rc.conf_mount_ro
load: 0.00  cmd: mount 79567 [biowr] 11.22r 0.00u 0.55s 3% 2068k
load: 0.00  cmd: mount 79567 [biowr] 12.15r 0.00u 0.68s 4% 2068k
load: 0.00  cmd: mount 79567 [biowr] 13.14r 0.00u 0.70s 4% 2068k
load: 0.08  cmd: mount 79567 [biowr] 14.33r 0.00u 0.82s 4% 2068k
load: 0.08  cmd: mount 79567 [biowr] 15.35r 0.00u 0.86s 4% 2068k
load: 0.08  cmd: mount 79567 [biowr] 16.29r 0.00u 0.93s 4% 2068k
load: 0.08  cmd: mount 79567 [biowr] 17.45r 0.00u 0.97s 4% 2068k
load: 0.08  cmd: mount 79567 [biowr] 17.91r 0.00u 1.02s 5% 2068k
load: 0.08  cmd: mount 79567 [biowr] 18.92r 0.00u 1.07s 5% 2068k
load: 0.08  cmd: mount 79567 [biowr] 19.90r 0.00u 1.11s 5% 2068k
load: 0.07  cmd: mount 79567 [biowr] 20.88r 0.00u 1.14s 4% 2068k
load: 0.07  cmd: mount 79567 [biowr] 21.89r 0.00u 1.20s 4% 2068k
load: 0.07  cmd: mount 79567 [biowr] 22.82r 0.00u 1.23s 4% 2068k
load: 0.07  cmd: mount 79567 [running] 23.80r 0.00u 1.35s 5% 2068k
load: 0.07  cmd: mount 79567 [biowr] 24.80r 0.00u 1.39s 4% 2068k
load: 0.07  cmd: mount 79567 [biowr] 26.03r 0.00u 1.48s 5% 2068k
load: 0.07  cmd: mount 79567 [biowr] 27.01r 0.00u 1.50s 4% 2068k
load: 0.07  cmd: mount 79567 [biowr] 27.96r 0.00u 1.56s 5% 2068k
0.040u 1.638s 0:29.00 5.7%	219+174k 0+643io 0pf+0w
[2.2-ALPHA][root@pfsense.localdomain]/root(5): uname -a
FreeBSD pfsense.localdomain 10.0-STABLE FreeBSD 10.0-STABLE #73 e852cd6(HEAD)-dirty: Tue May 27 10:51:27 CDT 2014     root@pf22-amd64-snap:/usr/obj.amd64/usr/pfSensesrc/src/sys/pfSense_SMP.10  amd64

              The only thing I have done since then is removed a static DHCP lease. Doesn't seem too arduous.  ;)

              Since nobody else has complained about this it's likely a problem with my particular setup so this thread is more for my own documentation that anything else. Of course any suggestions are always welcome.

              Steve

              1 Reply Last reply Reply Quote 0
              • stephenw10S
                stephenw10 Netgate Administrator
                last edited by

                Upgraded to latest snap. Imediately after upgrade, longest delay yet:

                
[2.2-ALPHA][root@pfsense.localdomain]/root(2): uname -a
FreeBSD pfsense.localdomain 10.0-STABLE FreeBSD 10.0-STABLE #74 e852cd6(HEAD)-dirty: Tue May 27 19:39:44 CDT 2014     root@pf22-amd64-snap:/usr/obj.amd64/usr/pfSensesrc/src/sys/pfSense_SMP.10  amd64
[2.2-ALPHA][root@pfsense.localdomain]/root(3): time /etc/rc.conf_mount_rw
0.070u 0.023s 0:00.58 15.5%	3996+323k 0+30io 0pf+0w
[2.2-ALPHA][root@pfsense.localdomain]/root(4): time /etc/rc.conf_mount_ro
0.063u 3.462s 0:41.48 8.4%	126+175k 0+1244io 0pf+0w

                No CPU load at that time.

                Time to swap out the CF card.

                Steve

                1 Reply Last reply Reply Quote 0
                • C
                  charliem
                  last edited by

                  @stephenw10:

                  Upgraded to latest snap. Imediately after upgrade, longest delay yet:

                  No CPU load at that time.

                  Time to swap out the CF card.

                  Steve

                  I first thought you may be seeing the built-in ECC kicking in as the wear leveling exercises different blocks, but that seems excessive.

                  1 Reply Last reply Reply Quote 0
                  • stephenw10S
                    stephenw10 Netgate Administrator
                    last edited by

                    This only happens when the card is re-mounted as read-only. If it were ware levelling of some sort I would expect to see it even with the card permanently mounted RW.

                    Steve

                    1 Reply Last reply Reply Quote 0
                    • stephenw10S
                      stephenw10 Netgate Administrator
                      last edited by

                      Ok so with i386 snapshots back to full function I had a chance to try a different card. Result, it definitely seems card dependent.
                      Original CF card that was previously slow:

                      
[2.2-ALPHA][root@alphatestbox.localdomain]/root(3): time /etc/rc.conf_mount_rw
0.104u 0.024s 0:00.41 29.2%     3106+274k 0+30io 0pf+0w
[2.2-ALPHA][root@alphatestbox.localdomain]/root(4): time /etc/rc.conf_mount_ro
0.086u 1.261s 0:28.76 4.6%      343+184k 0+639io 0pf+0w
[2.2-ALPHA][root@alphatestbox.localdomain]/root(5): uname -a
FreeBSD alphatestbox.localdomain 10.0-STABLE FreeBSD 10.0-STABLE #51 e852cd6(HEAD)-dirty: Thu Jun  5 07:33:46 CDT 2014     root@pf22-i386-snap:/usr/obj.i386/usr/pfSensesrc/src/sys/pfSense_wrap.10.i386  i386
[2.2-ALPHA][root@alphatestbox.localdomain]/conf(21): dmesg | grep ada0
ada0 at ata0 bus 0 scbus0 target 0 lun 0
ada0: <cf 20100226="">ATA-7 device
ada0: Serial Number 20110613 00000F5C
ada0: 16.700MB/s transfers (PIO4, PIO 512bytes)
ada0: 3831MB (7847280 512 byte sectors: 16H 63S/T 7785C)
ada0: Previously was known as ad0</cf>

                      Different CF card but identical otherwise:

                      
2.2-ALPHA][root@alphatestbox.localdomain]/root(1): uname -a
FreeBSD alphatestbox.localdomain 10.0-STABLE FreeBSD 10.0-STABLE #51 e852cd6(HEAD)-dirty: Thu Jun  5 07:33:46 CDT 2014     root@pf22-i386-snap:/usr/obj.i386/usr/pfSensesrc/src/sys/pfSense_wrap.10.i386  i386
[2.2-ALPHA][root@alphatestbox.localdomain]/root(2): dmesg|grep ada0
ada0 at ata0 bus 0 scbus0 target 0 lun 0
ada0: <sony 20071016="" ncfd2g="">CFA-6 device
ada0: Serial Number 4120382194200660000C
ada0: 16.700MB/s transfers (PIO4, PIO 512bytes)
ada0: 1911MB (3915072 512 byte sectors: 16H 63S/T 3884C)
ada0: Previously was known as ad0
[2.2-ALPHA][root@alphatestbox.localdomain]/root(3): time /etc/rc.conf_mount_rw
0.106u 0.015s 0:00.07 157.1%	4165+337k 0+30io 0pf+0w
[2.2-ALPHA][root@alphatestbox.localdomain]/root(4): time /etc/rc.conf_mount_ro
0.100u 0.109s 0:06.40 3.1%	2156+228k 0+470io 0pf+0w</sony>

                      So a lot faster, 6s vs 28s, but still a very noticeable delay doing a series of config changes in the GUI like the initial wizard for example.

                      I think I have some more cards I can try. Also try 64bit now the snapshots have restarted.

                      Steve

                      1 Reply Last reply Reply Quote 0
                      • stephenw10S
                        stephenw10 Netgate Administrator
                        last edited by

                        Some more data points:

                        Unbranded 2GB Card 41s

                        [2.2-ALPHA][root@pfSense.localdomain]/root(1): uname -a
FreeBSD pfSense.localdomain 10.0-STABLE FreeBSD 10.0-STABLE #51 e852cd6(HEAD)-dirty: Thu Jun  5 07:33:46 CDT 2014     root@pf22-i386-snap:/usr/obj.i386/usr/pfSensesrc/src/sys/pfSense_wrap.10.i386  i386
[2.2-ALPHA][root@pfSense.localdomain]/root(2): dmesg|grep ada0
ada0 at ata0 bus 0 scbus0 target 0 lun 0
ada0: < 20071116> ATA-0uhub1: 2 ports with 2 removable, self powered
ada0: Serial Number ASWIN 00003322
ada0: 16.700MB/s transfers (PIO4, PIO 512bytes)
ada0: 1935MB (3964464 512 byte sectors: 16H 63S/T 3933C)
ada0: Previously was known as ad0
[2.2-ALPHA][root@pfSense.localdomain]/root(3): time /etc/rc.conf_mount_rw
0.076u 0.045s 0:00.08 137.5%    3907+328k 0+31io 0pf+0w
[2.2-ALPHA][root@pfSense.localdomain]/root(4): time /etc/rc.conf_mount_ro
0.098u 0.107s 0:41.54 0.4%      2119+235k 0+466io 0pf+0w

                        Transcend 4GB Card 19s

                        [2.2-ALPHA][root@pfSense.localdomain]/root(1): uname -a
FreeBSD pfSense.localdomain 10.0-STABLE FreeBSD 10.0-STABLE #51 e852cd6(HEAD)-dirty: Thu Jun  5 07:33:46 CDT 2014     root@pf22-i386-snap:/usr/obj.i386/usr/pfSensesrc/src/sys/pfSense_wrap.10.i386  i386
[2.2-ALPHA][root@pfSense.localdomain]/root(2): dmesg|grep ada0
ada0 at ata0 bus 0 scbus0 target 0 lun 0
ada0: <ts4gcf133 20100804=""> ATA-7uhub1: 2 ports with 2 removable, self powered
ada0: Serial Number 20101112 C5130A66
ada0: 16.700MB/s transfers (PIO4, PIO 512bytes)
ada0: 3823MB (7831152 512 byte sectors: 16H 63S/T 7769C)
ada0: Previously was known as ad0
[2.2-ALPHA][root@pfSense.localdomain]/root(3): time /etc/rc.conf_mount_rw
0.089u 0.040s 0:00.59 20.3%     3581+301k 0+30io 0pf+0w
[2.2-ALPHA][root@pfSense.localdomain]/root(4): time /etc/rc.conf_mount_ro
0.095u 1.175s 0:18.85 6.6%      341+182k 0+441io 0pf+0w</ts4gcf133>

                        Kodak 1GB Card 64bit 12s- and that is a _muc_h faster machine.

                        [2.2-ALPHA][root@xtm5.localdomain]/root(1): uname -a
FreeBSD xtm5.localdomain 10.0-STABLE FreeBSD 10.0-STABLE #1 e852cd6(HEAD)-dirty: Fri Jun  6 02:39:07 CDT 2014     root@pf22-amd64-snap:/usr/obj.amd64/usr/pfSensesrc/src/sys/pfSense_SMP.10  amd64
[2.2-ALPHA][root@xtm5.localdomain]/root(2): dmesg|grep ada0
ada0 at ata0 bus 0 scbus0 target 0 lun 0
ada0: <kodak ata="" flash="" v1.01=""> CFA-0 device
ada0: Serial Number 11015111099199091128
ada0: 16.700MB/s transfers (PIO4, PIO 2048bytes)
ada0: 983MB (2014992 512 byte sectors: 16H 63S/T 1999C)
ada0: Previously was known as ad0
[2.2-ALPHA][root@xtm5.localdomain]/root(3): time /etc/rc.conf_mount_rw
0.051u 0.034s 0:00.14 57.1%     4085+315k 0+30io 0pf+0w
[2.2-ALPHA][root@xtm5.localdomain]/root(4): time /etc/rc.conf_mount_ro
0.049u 0.347s 0:12.09 3.1%      794+199k 0+628io 0pf+0w</kodak>

                        Steve

                        1 Reply Last reply Reply Quote 0
                        • Raul RamosR
                          Raul Ramos
                          last edited by

                          SanDisk 4G (i think the Ultra 30MB/s)

                          [2.2-ALPHA][root@pfsense.ramos.local]/root(33): dmesg | grep ada0
ada0 at ata2 bus 0 scbus1 target 1 lun 0
ada0: <sandisk sdcfx-004g="" hdx="" 6.03="">CFA-0 device
ada0: Serial Number ADZ1007XXXXXXXX
ada0: 150.000MB/s transfers (SATA, UDMA4, PIO 512bytes)
ada0: 3815MB (7813120 512 byte sectors: 16H 63S/T 7751C)
ada0: Previously was known as ad5
[2.2-ALPHA][root@pfsense.ramos.local]/root(34): time /etc/rc.conf_mount_rw
0.102u 0.023s 0:00.12 100.0%    4357+336k 0+18io 0pf+0w
[2.2-ALPHA][root@pfsense.ramos.local]/root(35): time /etc/rc.conf_mount_ro
0.089u 0.037s 0:00.13 84.6%     5050+389k 0+18io 0pf+0w</sandisk>

                          pfSense:
                          ASRock -> Wolfdale1333-D667 (2GB TeamElite Ram)
                          Marvell 88SA8040 Sata to CF(Sandisk 4GB) Controller
                          NIC's: RTL8100E (Internal ) and Intel® PRO/1000 PT Dual (Intel 82571GB)

                          1 Reply Last reply Reply Quote 0
                          • stephenw10S
                            stephenw10 Netgate Administrator
                            last edited by

                            0.1s is more like it.  :)
                            I guess you're using a SATA interface, the transfer speed is a lot higher.

                            Steve

                            1 Reply Last reply Reply Quote 0
                            • Raul RamosR
                              Raul Ramos
                              last edited by

                              @stephenw10:

                              0.1s is more like it.  :)
                              I guess you're using a SATA interface, the transfer speed is a lot higher.

                              Steve

                              Sata interface with a Marvel converter to Compact Flash.

                              pfSense:
                              ASRock -> Wolfdale1333-D667 (2GB TeamElite Ram)
                              Marvell 88SA8040 Sata to CF(Sandisk 4GB) Controller
                              NIC's: RTL8100E (Internal ) and Intel® PRO/1000 PT Dual (Intel 82571GB)

                              1 Reply Last reply Reply Quote 0
                              • First post
                                Last post
                              Copyright 2025 Rubicon Communications LLC (Netgate). All rights reserved.