beta-tester
Posts: 1206
Joined: Fri Jan 04, 2013 1:57 pm
Location: de_DE

Raspbian Stretch 2017-11-29 performs always intensive disk check when booting w/o network.

Fri Dec 01, 2017 11:44 am

i just installed Raspbian Stretck Lite 2017-11-29.
by checking the issue viewtopic.php?f=66&t=192960, i found out, that every reboot will perform an intensive disk check,
when there is no network cable connected to RPi2.

when a network cable is connected, then there is no message
"Checking in progress on 1 disk (0...100% complete)"

was it like that on previous Raspbian Stretch versions already as well?
why is booting without network performing an intensive disk check?
{ I only give negative feedback }
RPi Model B (rev1, 256MB) & B (rev2, 512MB) & B+, RPi2B (1GB), 64GB microSDXC1 class 10, HDMI 1920x1080, keyboard-mouse-combo (wireless), PiCamera, ethernet-cable, 5V/1.2A power supply, Wifi dongle (rt5370)

ShiftPlusOne
Raspberry Pi Engineer & Forum Moderator
Raspberry Pi Engineer & Forum Moderator
Posts: 5113
Joined: Fri Jul 29, 2011 5:36 pm
Location: The unfashionable end of the western spiral arm of the Galaxy

Re: Raspbian Stretch 2017-11-29 performs always intensive disk check when booting w/o network.

Fri Dec 01, 2017 2:27 pm

Might have something to do with fake-hwclock and the last time the disk was accessed. Will take a closer look later.

beta-tester
Posts: 1206
Joined: Fri Jan 04, 2013 1:57 pm
Location: de_DE

Re: Raspbian Stretch 2017-11-29 performs always intensive disk check when booting w/o network.

Fri Dec 01, 2017 3:46 pm

ok, that makes sense... that is something, i didn't thought about it...
no idea if that is fixable when there is no time source available.
{ I only give negative feedback }
RPi Model B (rev1, 256MB) & B (rev2, 512MB) & B+, RPi2B (1GB), 64GB microSDXC1 class 10, HDMI 1920x1080, keyboard-mouse-combo (wireless), PiCamera, ethernet-cable, 5V/1.2A power supply, Wifi dongle (rt5370)

ShiftPlusOne
Raspberry Pi Engineer & Forum Moderator
Raspberry Pi Engineer & Forum Moderator
Posts: 5113
Joined: Fri Jul 29, 2011 5:36 pm
Location: The unfashionable end of the western spiral arm of the Galaxy

Re: Raspbian Stretch 2017-11-29 performs always intensive disk check when booting w/o network.

Fri Dec 01, 2017 3:49 pm

The idea is that fake-hwclock saves the time of shutdown and restores it on next boot to avoid this exact kind of thing. Maybe systemd-fsckd runs before fake-hwclock, so systemd-fsckd thinks it's 1970. If that's the case, the fix shouldn't be too difficult.

User avatar
HawaiianPi
Posts: 2433
Joined: Mon Apr 08, 2013 4:53 am
Location: Aloha, Oregon USA

Re: Raspbian Stretch 2017-11-29 performs always intensive disk check when booting w/o network.

Sat Dec 02, 2017 1:01 pm

I didn't notice any such thing when I tested the 2017-11-29 image on my Pi Zero. ¯\_(ツ)_/¯

Can anyone else confirm this?
My mind is like a browser. 27 tabs are open, 9 aren't responding,
lots of pop-ups...and where is that annoying music coming from?

beta-tester
Posts: 1206
Joined: Fri Jan 04, 2013 1:57 pm
Location: de_DE

Re: Raspbian Stretch 2017-11-29 performs always intensive disk check when booting w/o network.

Sat Dec 02, 2017 6:45 pm

maybe it is a false report of me.

it happened also with a network connection, that multiple times an intensive disk check was performed.
it happened where i was booting the system multiple times in a short time. but the behavior disappeared after some few reboots.
i rebooted the system with "sudo reboot".

is it possible, that by coincenense i catched a regular intensive disk check at boot time, but because of i was rebooting the system after few seconds, the last shutdown time was too close to the boot time so a new turn of regular intensive disk check was triggered - and not enough time was left to skipp the check...?

i was testing some settings and rebooted the system multiple times in a short interval.
changing settings, reboot, changing settings, reboot, ...
that was also the case at my initial report.

is that possible?

or does the shutdown time interfere with chrony time server/client?
{ I only give negative feedback }
RPi Model B (rev1, 256MB) & B (rev2, 512MB) & B+, RPi2B (1GB), 64GB microSDXC1 class 10, HDMI 1920x1080, keyboard-mouse-combo (wireless), PiCamera, ethernet-cable, 5V/1.2A power supply, Wifi dongle (rt5370)


glcos
Posts: 1
Joined: Sat Dec 23, 2017 8:29 pm
Location: Italy

Re: Raspbian Stretch 2017-11-29 performs always intensive disk check when booting w/o network.

Sat Dec 23, 2017 8:35 pm

I'm having exactly the same issue.
Raspberry 3 booting from SSD, no SD card inserted.

beta-tester
Posts: 1206
Joined: Fri Jan 04, 2013 1:57 pm
Location: de_DE

Re: Raspbian Stretch 2017-11-29 performs always intensive disk check when booting w/o network.

Sun Dec 24, 2017 8:28 am

i have also an external USB memory stick (SanDisk 64GB UltraFit, with ext4 file system) attached to my RPi, but i have it only for extra data storage permanently plugged in and not for boot or root file system.

is it possible, that the shutdown process isn't clearing and flushing the "dirty bit" properbly.
as far as i know do the RPi2 and RPi 3 power down its usb ports at shutdown - maybe the cleaned dirty bit is left unflushed in some write back buffer, before it reaches the USB device to get stored.

is there a way to see, which device causes an intensive disk check?
{ I only give negative feedback }
RPi Model B (rev1, 256MB) & B (rev2, 512MB) & B+, RPi2B (1GB), 64GB microSDXC1 class 10, HDMI 1920x1080, keyboard-mouse-combo (wireless), PiCamera, ethernet-cable, 5V/1.2A power supply, Wifi dongle (rt5370)

ShiftPlusOne
Raspberry Pi Engineer & Forum Moderator
Raspberry Pi Engineer & Forum Moderator
Posts: 5113
Joined: Fri Jul 29, 2011 5:36 pm
Location: The unfashionable end of the western spiral arm of the Galaxy

Re: Raspbian Stretch 2017-11-29 performs always intensive disk check when booting w/o network.

Sun Dec 24, 2017 6:20 pm

I think 'sudo journalctl' should show all the relevant information - why fsck is running and how long it takes.

beta-tester
Posts: 1206
Joined: Fri Jan 04, 2013 1:57 pm
Location: de_DE

Re: Raspbian Stretch 2017-11-29 performs always intensive disk check when booting w/o network.

Sun Dec 24, 2017 8:56 pm

stupid me, why i didn't looked into the journalctl before... :oops:
the reason is "Superblock last mount time (Sun Dec 24 21:32:48 2017, now = Thu Nov 3 18:16:44 2016) is in the future."
that's, what you already told...
in those cases the disk check starts running before the kernel got the correct or fake time of last shutdown.

Code: Select all

$ sudo journalctl -xb | grep -E "fsck|clock"

Dec 24 21:34:23 pxe-server kernel: Kernel command line: bcm2708_fb.fbwidth=3840 bcm2708_fb.fbheight=2160 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000  dwc_otg.lpm_enable=0 console=ttyAMA0,115200 console=tty1 root=PARTUUID=a754701d-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait plymouth.ignore-serial-consoles max_loop=64 net.ifnames=0 logo.nologo
Dec 24 21:34:23 pxe-server kernel: clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns
Dec 24 21:34:23 pxe-server kernel: sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns
Dec 24 21:34:23 pxe-server kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
Dec 24 21:34:23 pxe-server kernel: clocksource: Switched to clocksource arch_sys_counter
Dec 24 21:34:23 pxe-server systemd[1]: System time before build time, advancing clock.
Dec 24 21:34:23 pxe-server systemd-fsck[168]: e2fsck 1.43.4 (31-Jan-2017)
Dec 24 21:34:23 pxe-server systemd-fsck[168]: Superblock last mount time (Sun Dec 24 21:32:48 2017,
Dec 24 21:34:23 pxe-server systemd-fsck[168]:         now = Thu Nov  3 18:16:44 2016) is in the future.
Dec 24 21:34:23 pxe-server systemd-fsck[168]: Fix? yes
Dec 24 21:34:23 pxe-server systemd-fsck[168]: Pass 1: Checking inodes, blocks, and sizes
Dec 24 21:34:23 pxe-server fake-hwclock[178]: Sun Dec 24 20:34:23 UTC 2017
Dec 24 21:34:23 pxe-server systemd[1]: Started Restore / save the current clock.
-- Subject: Unit fake-hwclock.service has finished start-up
-- Unit fake-hwclock.service has finished starting up.
-- The system clock has been changed to REALTIME microseconds after January 1st, 1970.
-- Subject: Unit systemd-fsckd.service has finished start-up
-- Unit systemd-fsckd.service has finished starting up.
Dec 24 21:35:13 pxe-server systemd-fsck[168]: Pass 2: Checking directory structure
Dec 24 21:35:18 pxe-server systemd-fsck[168]: Pass 3: Checking directory connectivity
Dec 24 21:35:19 pxe-server systemd-fsck[168]: Pass 4: Checking reference counts
Dec 24 21:35:21 pxe-server systemd-fsck[168]: Pass 5: Checking group summary information
Dec 24 21:35:24 pxe-server systemd-fsck[168]: rootfs: 141578/3830848 files (0.2% non-contiguous), 11419217/15580160 blocks
-- Subject: Unit systemd-fsck-root.service has finished start-up
-- Unit systemd-fsck-root.service has finished starting up.
-- Subject: Unit [email protected]\x2dpartuuid-a754701d\x2d01.service has begun start-up
-- Unit [email protected]\x2dpartuuid-a754701d\x2d01.service has begun starting up.
Dec 24 21:35:28 pxe-server systemd-fsck[379]: fsck.fat 4.1 (2017-01-24)
Dec 24 21:35:28 pxe-server systemd-fsck[379]: /dev/mmcblk0p1: 144 files, 42653/83705 clusters
-- Subject: Unit [email protected]\x2dpartuuid-a754701d\x2d01.service has finished start-up
-- Unit [email protected]\x2dpartuuid-a754701d\x2d01.service has finished starting up.
-- The system clock has been changed to REALTIME microseconds after January 1st, 1970.
Dec 24 21:35:42 pxe-server chronyd[583]: System clock wrong by 11.039131 seconds, adjustment started
-- The system clock has been changed to REALTIME microseconds after January 1st, 1970.
Dec 24 21:35:53 pxe-server chronyd[583]: System clock was stepped by 11.039131 seconds
the scan itself takes about a minute - the SD card is 64GB. it is very annoying when the scan starts without a real reason...
{ I only give negative feedback }
RPi Model B (rev1, 256MB) & B (rev2, 512MB) & B+, RPi2B (1GB), 64GB microSDXC1 class 10, HDMI 1920x1080, keyboard-mouse-combo (wireless), PiCamera, ethernet-cable, 5V/1.2A power supply, Wifi dongle (rt5370)

User avatar
DougieLawson
Posts: 33018
Joined: Sun Jun 16, 2013 11:19 pm
Location: Basingstoke, UK
Contact: Website

Re: Raspbian Stretch 2017-11-29 performs always intensive disk check when booting w/o network.

Sun Dec 24, 2017 9:35 pm

You don't have a stable clock. Is it always going back to November 2016? Whatever syncs your clock starts too late.

What's in /etc/fstab?
Microprocessor, Raspberry Pi & Arduino Hacker
Mainframe database troubleshooter
MQTT Evangelist
Twitter: @DougieLawson

2012-18: 1B*5, 2B*2, B+, A+, Z, ZW, 3Bs*3, 3B+

Any DMs sent on Twitter will be answered next month.

beta-tester
Posts: 1206
Joined: Fri Jan 04, 2013 1:57 pm
Location: de_DE

Re: Raspbian Stretch 2017-11-29 performs always intensive disk check when booting w/o network.

Sun Dec 24, 2017 10:06 pm

DougieLawson wrote:
Sun Dec 24, 2017 9:35 pm
You don't have a stable clock. Is it always going back to November 2016? Whatever syncs your clock starts too late.

What's in /etc/fstab?
on that specific RPi it is a bit special:

Code: Select all

proc            /proc           proc    defaults          0       0
PARTUUID=a754701d-01  /boot           vfat    defaults          0       2
PARTUUID=a754701d-02  /               ext4    defaults,noatime  0       1
# a swapfile is not a swap partition, no line here
#   use  dphys-swapfile swap[on|off]  for that

## mod_install_server
LABEL=PXE-Server  /media/server  auto  noatime,nofail,auto,x-systemd.automount,x-systemd.device-timeout=5,x-systemd.mount-timeout=5  0  0

/srv/iso/win-pe-x86.iso  /srv/nfs/win-pe-x86  auto  ro,nofail,auto,loop  0  10
/srv/iso/ubuntu-lts-x64.iso  /srv/nfs/ubuntu-lts-x64  auto  ro,nofail,auto,loop  0  10
/srv/iso/ubuntu-lts-x86.iso  /srv/nfs/ubuntu-lts-x86  auto  ro,nofail,auto,loop  0  10
/srv/iso/ubuntu-x64.iso  /srv/nfs/ubuntu-x64  auto  ro,nofail,auto,loop  0  10
/srv/iso/ubuntu-x86.iso  /srv/nfs/ubuntu-x86  auto  ro,nofail,auto,loop  0  10
/srv/iso/ubuntu-nopae.iso  /srv/nfs/ubuntu-nopae  auto  ro,nofail,auto,loop  0  10
/srv/iso/debian-x64.iso  /srv/nfs/debian-x64  auto  ro,nofail,auto,loop  0  10
/srv/iso/debian-x86.iso  /srv/nfs/debian-x86  auto  ro,nofail,auto,loop  0  10
/srv/iso/gnuradio-x64.iso  /srv/nfs/gnuradio-x64  auto  ro,nofail,auto,loop  0  10
/srv/iso/deft-x64.iso  /srv/nfs/deft-x64  auto  ro,nofail,auto,loop  0  10
/srv/iso/deftz-x64.iso  /srv/tmp/original/deftz-x64  auto  ro,nofail,auto,loop  0  10
/srv/tmp/original/deftz-x64  /srv/nfs/deftz-x64  fuse.bindfs  ro,auto,force-user=root,force-group=root,perms=a+rX  0  11
/srv/iso/kali-x64.iso  /srv/nfs/kali-x64  auto  ro,nofail,auto,loop  0  10
/srv/iso/pentoo-x64.iso  /srv/nfs/pentoo-x64  auto  ro,nofail,auto,loop  0  10
/srv/iso/systemrescue-x86.iso  /srv/nfs/systemrescue-x86  auto  ro,nofail,auto,loop  0  10
/srv/iso/desinfect-x86.iso  /srv/nfs/desinfect-x86  auto  ro,nofail,auto,loop  0  10
/srv/iso/tinycore-x64.iso  /srv/nfs/tinycore-x64  auto  ro,nofail,auto,loop  0  10
/srv/iso/tinycore-x86.iso  /srv/nfs/tinycore-x86  auto  ro,nofail,auto,loop  0  10
/srv/iso/rpdesktop-x86.iso  /srv/nfs/rpdesktop-x86  auto  ro,nofail,auto,loop  0  10
/srv/iso/clonezilla-x64.iso  /srv/nfs/clonezilla-x64  auto  ro,nofail,auto,loop  0  10
/srv/iso/clonezilla-x86.iso  /srv/nfs/clonezilla-x86  auto  ro,nofail,auto,loop  0  10
/srv/iso/centos-x64.iso  /srv/nfs/centos-x64  auto  ro,nofail,auto,loop  0  10
/srv/iso/fedora-x64.iso  /srv/nfs/fedora-x64  auto  ro,nofail,auto,loop  0  10
/srv/iso/tails-x64.iso  /srv/nfs/tails-x64  auto  ro,nofail,auto,loop  0  10
/srv/img/pi-core.img  /srv/nfs/pi-core-boot  auto  ro,nofail,auto,loop,offset=4194304,sizelimit=35651584  0  11
/srv/img/pi-core.img  /srv/nfs/pi-core-root  auto  ro,nofail,auto,loop,offset=39845888,sizelimit=11534336  0  11
/srv/img/rpi-raspbian-lite.img  /srv/nfs/rpi-raspbian-lite-boot  auto  ro,nofail,auto,loop,offset=4194304,sizelimit=43543040  0  11
/srv/img/rpi-raspbian-lite.img  /srv/nfs/rpi-raspbian-lite-root  auto  ro,nofail,auto,loop,offset=48234496,sizelimit=1809842176  0  11
/srv/img/rpi-raspbian-full.img  /srv/nfs/rpi-raspbian-full-boot  auto  ro,nofail,auto,loop,offset=4194304,sizelimit=43543040  0  11
/srv/img/rpi-raspbian-full.img  /srv/nfs/rpi-raspbian-full-root  auto  ro,nofail,auto,loop,offset=48234496,sizelimit=4871684096  0  11
but the mount of the other stuff goes just quick... and at those times, when the scan does not happen at boot, the Rpi boots up in one minute less.

but this RPi configuration is an extreme special one. but the scan also happen randomly on pure virgine Raspbian-Stretch installation on other RPi, when i "sudo reboot" those.
with and without a local NTP server on my local network.
{ I only give negative feedback }
RPi Model B (rev1, 256MB) & B (rev2, 512MB) & B+, RPi2B (1GB), 64GB microSDXC1 class 10, HDMI 1920x1080, keyboard-mouse-combo (wireless), PiCamera, ethernet-cable, 5V/1.2A power supply, Wifi dongle (rt5370)

User avatar
DougieLawson
Posts: 33018
Joined: Sun Jun 16, 2013 11:19 pm
Location: Basingstoke, UK
Contact: Website

Re: Raspbian Stretch 2017-11-29 performs always intensive disk check when booting w/o network.

Mon Dec 25, 2017 8:27 am

You could suppress fsck from /etc/fstab by setting the last field to 0 for filesystems where you don't need any automatic fsck.
Microprocessor, Raspberry Pi & Arduino Hacker
Mainframe database troubleshooter
MQTT Evangelist
Twitter: @DougieLawson

2012-18: 1B*5, 2B*2, B+, A+, Z, ZW, 3Bs*3, 3B+

Any DMs sent on Twitter will be answered next month.

beta-tester
Posts: 1206
Joined: Fri Jan 04, 2013 1:57 pm
Location: de_DE

Re: Raspbian Stretch 2017-11-29 performs always intensive disk check when booting w/o network.

Tue Dec 26, 2017 10:16 am

thinking about that you are asking for fstab,
i went back to a pure virgine actual Raspbian-Stretch-lite (2017-11-29) installation on a RPi3
with nothing connected but SD card (16GB), TV, ethernet cable and power supply (yes, good and strong enough for RPi3).
the only modification were, enabling SSH (via ssh file on boot partition) and ssh-copy-id (from remote).
so from remote, i rebooted that RPi3 over and over , without could reproducing the fsck issue at boot time (* see EDIT below).

Code: Select all

ssh [email protected] "sudo reboot"
then i just plugged a usb-memory-stick to the RPI and did some reboots from remote.
then, fsck was triggered to run a scan at boot time.

but the fstab isn't touched at all.
the usb-memory-stick first had an ext4 file system that was just formated.
the usb-memory-stick isn't even mounted - no mountpoint listed in "mount".
still fsck happened from time to time for the same time reason - on this specific test, with a chance of lets say >20% (sometimes multiple times in a row).
and also when the plugged usb-memory-stick is completely zeroed - no file system, no superblock, no partition, no partition table.

Code: Select all

sudo dd if=/dev/zero of=/dev/sda bs=16M oflag=dsync status=progress
same issue...

Code: Select all

Dec 26 10:06:17 raspberrypi systemd-fsck[110]: Superblock last mount time (Tue Dec 26 10:05:53 2017,
Dec 26 10:06:17 raspberrypi systemd-fsck[110]:         now = Thu Nov  3 17:16:43 2016) is in the future.
fsck seems to check the internal sd card then and how long it takes depends on the file structure off that sd card.
(on my pxe-server with ~1minute, it is a 64GB sd card [77% used]. on this test RPi3 it is a 16GB sd card [8% used] and scanned quicker)

how is the relationship between usb device, booting and fsck scan then?
something is delaying the process of restoring the last shutdown time at boot,
or storing the last time at shutdown to restore at next boot.

EDIT: forget all about the usb-memory-stick part stuff i wrote before.
wihtout an usb stick there is as well a chance to run into the issue for time issue reason - but way less than with usb stick.
{ I only give negative feedback }
RPi Model B (rev1, 256MB) & B (rev2, 512MB) & B+, RPi2B (1GB), 64GB microSDXC1 class 10, HDMI 1920x1080, keyboard-mouse-combo (wireless), PiCamera, ethernet-cable, 5V/1.2A power supply, Wifi dongle (rt5370)

d_older
Posts: 100
Joined: Mon Jun 25, 2012 5:04 pm
Location: East Yorkshire, UK

Re: Raspbian Stretch 2017-11-29 performs always intensive disk check when booting w/o network.

Tue May 15, 2018 7:40 pm

Hi all,

Has any progress been made in this area?

I am seeing a very similar issue, but only on my pi zeroW and not on my 3.

Logs - including where the various times have an effect - are in post viewtopic.php?f=28&t=212208&p=1309065#p1309065

(ignore the link at the end - that refers back here)

Regards,
Dave

User avatar
DougieLawson
Posts: 33018
Joined: Sun Jun 16, 2013 11:19 pm
Location: Basingstoke, UK
Contact: Website

Re: Raspbian Stretch 2017-11-29 performs always intensive disk check when booting w/o network.

Tue May 15, 2018 10:04 pm

Re-test with Raspbian 2018-04-18.
Microprocessor, Raspberry Pi & Arduino Hacker
Mainframe database troubleshooter
MQTT Evangelist
Twitter: @DougieLawson

2012-18: 1B*5, 2B*2, B+, A+, Z, ZW, 3Bs*3, 3B+

Any DMs sent on Twitter will be answered next month.

d_older
Posts: 100
Joined: Mon Jun 25, 2012 5:04 pm
Location: East Yorkshire, UK

Re: Raspbian Stretch 2017-11-29 performs always intensive disk check when booting w/o network.

Wed May 16, 2018 7:11 am

Hi Dougie,

I did - the linked post contains the results from 2018-04-18 rasbian (full) release.

Cheers,

Dave

User avatar
HawaiianPi
Posts: 2433
Joined: Mon Apr 08, 2013 4:53 am
Location: Aloha, Oregon USA

Re: Raspbian Stretch 2017-11-29 performs always intensive disk check when booting w/o network.

Thu May 17, 2018 11:45 am

d_older wrote:
Tue May 15, 2018 7:40 pm
Hi all,

Has any progress been made in this area?

I am seeing a very similar issue, but only on my pi zeroW and not on my 3.
Have you tried swapping cards between systems?

How was the SD card prepared?

What brand SD cards?
My mind is like a browser. 27 tabs are open, 9 aren't responding,
lots of pop-ups...and where is that annoying music coming from?

d_older
Posts: 100
Joined: Mon Jun 25, 2012 5:04 pm
Location: East Yorkshire, UK

Re: Raspbian Stretch 2017-11-29 performs always intensive disk check when booting w/o network.

Thu May 17, 2018 9:55 pm

HI,

The card was a dd from the 2018_04 full image and full "apt upgraded" (ssh and wireless enabled)

The card was swapped between the pi-zero-W and the pi-3B

It's an 8GB retail SanDisk Ultra (Red/Grey) marked as Class 10 and microSDHC I .

TL;DR Fresh copy: now getting inconsistent results - 3 x good Pi3 - move card to zeroW 1 x good , 1 x full fsck, 2 x good :?:


This evening I've put the card back to the original 2018_04_18 image (added ssh and wpa_supplicant.conf - for the zero-W) and tried it again and am now getting inconsistent results.

1) 3 boots in the pi 3 (ethernet connection) (to ensure that a current fake time is written to the card and used subsequently ) Normal boot each time. 3rd boot has the expected
-
- Logs begin at Thu 2016-11-03 17:16:42 UTC, end at Thu 2018-05-17 18:48:24 UTC. --
Nov 03 17:16:42.797246 raspberrypi kernel: Booting Linux on physical CPU 0x0
Nov 03 17:16:42.797705 raspberrypi kernel: Linux version 4.14.34-v7+ ([email protected]) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611)) #1110 SMP Mon Apr 16 15:18:51 BST 2018
Nov 03 17:16:42.797937 raspberrypi kernel: CPU: ARMv7 Processor [410fd034] revision 4 (ARMv7), cr=10c5383d
and the log time changing earlier (line 73 than fake-hwclock is reported (line 239) (approx 60ms between the entries)
Nov 03 17:16:42.809083 raspberrypi kernel: Serial: AMBA PL011 UART driver
Nov 03 17:16:42.810234 raspberrypi kernel: bcm2835-mbox 3f00b880.mailbox: mailbox enabled
May 17 17:43:24.014761 raspberrypi kernel: uart-pl011 3f201000.serial: could not find pctldev for node /soc/[email protected]/uart0_pins, deferring probe
May 17 17:43:24.025132 raspberrypi kernel: bcm2835-dma 3f007000.dma: DMA legacy API manager at bb813000, dmachans=0x1
....
....
....
May 17 17:43:24.082834 raspberrypi systemd-modules-load[84]: Inserted module 'i2c_dev'
May 17 17:43:24.085877 raspberrypi fake-hwclock[87]: Thu 17 May 17:43:24 UTC 2018
May 17 17:43:24.086544 raspberrypi systemd-fsck[88]: e2fsck 1.43.4 (31-Jan-2017)
May 17 17:43:24.111642 raspberrypi systemd[1]: Started Create Static Device Nodes in /dev.
May 17 17:43:24.116558 raspberrypi systemd[1]: Starting udev Kernel Device Manager...
May 17 17:43:24.145479 raspberrypi systemd-fsck[88]: rootfs: clean, 137601/963424 files, 1164347/3877248 blocks
May 17 17:43:24.151425 raspberrypi systemd[1]: Started File System Check on Root Device.
May 17 17:43:24.155598 raspberrypi systemd[1]: Starting Remount Root and Kernel File Systems...
May 17 17:43:24.257402 raspberrypi systemd[1]: Started Remount Root and Kernel File Systems.
May 17 17:43:24.260340 raspberrypi kernel: EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
May 17 17:43:24.262515 raspberrypi systemd[1]: Starting udev Coldplug all Devices...
Note: systemd-timesyncd updates the clock at the end of the boot sequence


Then moved the card to the zero-W

1st boot surprising initial entry - using fake-hwclock value and not Nov 03 2106
then, even with fake-hwclock after e2fsck 1.43.4 no full check.
-- Logs begin at Thu 2018-05-17 18:53:32 UTC, end at Thu 2018-05-17 19:26:58 UTC. --
May 17 18:53:32.007359 raspberrypi kernel: Booting Linux on physical CPU 0x0
May 17 18:53:32.008641 raspberrypi kernel: Linux version 4.14.34+ ([email protected]) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611)) #1110 Mon Apr 16 14:51:42 BST 2018
May 17 18:53:32.009300 raspberrypi kernel: CPU: ARMv6-compatible processor [410fb767] revision 7 (ARMv7), cr=00c5387d
......
......
......
May 17 18:53:33.152848 raspberrypi systemd-modules-load[70]: Inserted module 'i2c_dev'
May 17 18:53:33.183020 raspberrypi systemd-fsck[73]: e2fsck 1.43.4 (31-Jan-2017)
May 17 18:53:33.183020 raspberrypi systemd-fsck[73]: rootfs: clean, 137604/963424 files, 1164395/3877248 blocks
May 17 18:53:33.222757 raspberrypi fake-hwclock[78]: Thu 17 May 18:53:32 UTC 2018
May 17 18:53:33.422309 raspberrypi kernel: EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)

2nd zero W boot - full fsck
Log starts at Nov 03 2106
Log time changes at line 102
e2fsck at line 228
fake-hwclock at line 237
-- Logs begin at Thu 2016-11-03 17:16:43 UTC, end at Thu 2018-05-17 19:44:37 UTC. --
Nov 03 17:16:43.774715 raspberrypi kernel: Booting Linux on physical CPU 0x0
Nov 03 17:16:43.776048 raspberrypi kernel: Linux version 4.14.34+ ([email protected]) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611)) #1110 Mon Apr 16 14:51:42 BST 2018
Nov 03 17:16:43.776733 raspberrypi kernel: CPU: ARMv6-compatible processor [410fb767] revision 7 (ARMv7), cr=00c5387d
.....
.....
....
Nov 03 17:16:44.119792 raspberrypi kernel: vc-mem: phys_addr:0x00000000 mem_base=0x1ec00000 mem_size:0x20000000(512 MiB)
Nov 03 17:16:44.120448 raspberrypi kernel: vc-sm: Videocore shared memory driver
May 17 19:27:19.018539 raspberrypi kernel: gpiomem-bcm2835 20200000.gpiomem: Initialised: Registers at 0x20200000
May 17 19:27:19.026500 raspberrypi kernel: brd: module loaded
...
...
...
May 17 19:27:19.908109 raspberrypi systemd-fsck[68]: e2fsck 1.43.4 (31-Jan-2017)
May 17 19:27:19.908109 raspberrypi systemd-fsck[68]: Superblock last mount time (Thu May 17 18:53:33 2018,
May 17 19:27:19.908109 raspberrypi systemd-fsck[68]: now = Thu Nov 3 17:16:44 2016) is in the future.
May 17 19:27:19.908109 raspberrypi systemd-fsck[68]: Fix? yes
May 17 19:27:19.908109 raspberrypi systemd-fsck[68]: Superblock last write time (Wed Apr 18 01:24:23 2018,
May 17 19:27:19.908109 raspberrypi systemd-fsck[68]: now = Thu Nov 3 17:16:44 2016) is in the future.
May 17 19:27:19.908109 raspberrypi systemd-fsck[68]: Fix? yes
May 17 19:27:19.908109 raspberrypi systemd-fsck[68]: Pass 1: Checking inodes, blocks, and sizes
May 17 19:27:19.919007 raspberrypi systemd[1]: Starting udev Kernel Device Manager...
May 17 19:27:20.146456 raspberrypi fake-hwclock[79]: Thu 17 May 19:27:19 UTC 2018
May 17 19:27:20.832099 raspberrypi systemd[1]: Started udev Kernel Device Manager.

3rd boot No full fsck
Log starts at Nov 03 2106
Log time changes at line 13
e2fsck at line 226
fake-hwclock at line 229
-- Logs begin at Thu 2016-11-03 17:16:44 UTC, end at Thu 2018-05-17 20:53:45 UTC. --
Nov 03 17:16:44.144634 raspberrypi kernel: Booting Linux on physical CPU 0x0
Nov 03 17:16:44.145960 raspberrypi kernel: Linux version 4.14.34+ ([email protected]) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611)) #1110 Mon Apr 16 14:51:42 BST 2018
Nov 03 17:16:44.146631 raspberrypi kernel: CPU: ARMv6-compatible processor [410fb767] revision 7 (ARMv7), cr=00c5387d
....
....
....
Nov 03 17:16:44.150133 raspberrypi kernel: Normal zone: 1008 pages used for memmap
Nov 03 17:16:44.150641 raspberrypi kernel: Normal zone: 0 pages reserved
May 17 20:51:29.021123 raspberrypi kernel: Normal zone: 114688 pages, LIFO batch:31
May 17 20:51:29.075991 raspberrypi kernel: random: fast init done
...
...
...
May 17 20:51:30.151250 raspberrypi systemd-modules-load[69]: Inserted module 'i2c_dev'
May 17 20:51:30.210836 raspberrypi systemd-fsck[73]: e2fsck 1.43.4 (31-Jan-2017)
May 17 20:51:30.210836 raspberrypi systemd-fsck[73]: rootfs: clean, 137459/963424 files, 1144263/3877248 blocks
May 17 20:51:30.230869 raspberrypi fake-hwclock[79]: Thu 17 May 20:51:29 UTC 2018
May 17 20:51:30.480722 raspberrypi kernel: EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)

4th as per third

Looking back at my April post it had a fsck daemon mentioned
"Apr 28 17:00:00 pizero-W-1 systemd[1]: Started File System Check Daemon to report status."
which does not appear in these logs so I'm going to update and try again


Regards
Dave
"Confused of East Yorkshire"

d_older
Posts: 100
Joined: Mon Jun 25, 2012 5:04 pm
Location: East Yorkshire, UK

Re: Raspbian Stretch 2017-11-29 performs always intensive disk check when booting w/o network.

Sat May 19, 2018 5:12 pm

Hi

Updated system (2018-05-17) and re-tested with 7 boots.

There does appear to be race condition between the file system check on the root file system and the time read from the SD card being made available to is (via fske-hwclock)
6 boots (varying time on and varying times between) 5 no full fsck (OK), 2 full fsck.
For each of the 2 full checks, it is triggers by time "now" being "Thu Nov 3 17:16:44 2016)"
In these test only the "Superblock last mount time" triggered the check, in the last tests both Superblock mount time and Superblock last write time caused a "Fix ? = yes"
(The times used for mounting may well be affected by this issue as well, hence giving an acceptable check with a 2016 date)


If journalctl entries would help please let me know - I have themsaved

Regards
Dave

Return to “Raspbian”

Who is online

Users browsing this forum: No registered users and 47 guests