mbox series

[v2,00/10] sysupgrade: reword and organize log lines

Message ID 20201110022223.41175-1-yszhou4tech@gmail.com
Headers show
Series sysupgrade: reword and organize log lines | expand

Message

Yousong Zhou Nov. 10, 2020, 2:22 a.m. UTC
The series mainly aims to make sysupgrade log output more organized and
less disturbing, in the following aspects

 - Hide "write error: Broken pipe" from cat command and its friends
 - Hide "F+P records in/out" lines from dd command
 - Make log lines from sysupgrade command itself more distinguishable
   than other commands by using common.sh function "v"

The series should at least partially address concerns raised at FS#3140

Ref: https://bugs.openwrt.org/index.php?do=details&task_id=3140

v2 <- v1

 - Make date command available in ramdisk and prefix log lines with datetime
 - Hide "F+P records in/out" stderr output from dd command

Sysupgrade stdio dumps attached below for comparison

v2

  Tue Nov 10 02:04:04 UTC 2020 upgrade: Image metadata not present
  Tue Nov 10 02:04:04 UTC 2020 upgrade: Reading partition table from bootdisk...
  Tue Nov 10 02:04:04 UTC 2020 upgrade: Extract boot sector from the image
  Tue Nov 10 02:04:05 UTC 2020 upgrade: Reading partition table from image...
  Tue Nov 10 02:04:05 UTC 2020 upgrade: Commencing upgrade. Closing all shell sessions.
  killall: telnetd: no process killed
  Sending TERM to remaining processes ... ubusd askfirst urngd logd netifd odhcpd xl2tpd ntpd dnsmasq
  Sending KILL to remaining processes ...
  Tue Nov 10 02:04:09 UTC 2020 upgrade: Switching to ramdisk...
  [   25.995408] EXT4-fs (vda2): re-mounted. Opts: (null)
  Tue Nov 10 02:04:09 UTC 2020 upgrade: Performing system upgrade...
  Tue Nov 10 02:04:09 UTC 2020 upgrade: Reading partition table from bootdisk...
  Tue Nov 10 02:04:10 UTC 2020 upgrade: Extract boot sector from the image
  Tue Nov 10 02:04:10 UTC 2020 upgrade: Reading partition table from image...
  Tue Nov 10 02:04:10 UTC 2020 upgrade: Writing image to /dev/vda1...
  Tue Nov 10 02:04:11 UTC 2020 upgrade: Writing image to /dev/vda2...
  Tue Nov 10 02:04:15 UTC 2020 upgrade: Writing new UUID to /dev/vda...
  [   31.582751] F2FS-fs (vda1): Magic Mismatch, valid(0xf2f52010) - read(0x0)
  [   31.598842] F2FS-fs (vda1): Can't find valid F2FS filesystem in 1th superblock
  [   31.613440] F2FS-fs (vda1): Magic Mismatch, valid(0xf2f52010) - read(0x6020601)
  [   31.623241] F2FS-fs (vda1): Can't find valid F2FS filesystem in 2th superblock
  Tue Nov 10 02:04:15 UTC 2020 upgrade: Upgrading bootloader on /dev/vda...
  Tue Nov 10 02:04:22 UTC 2020 upgrade: Upgrade completed
  Tue Nov 10 02:04:23 UTC 2020 upgrade: Rebooting system...
  umount: can't unmount /dev: Resource busy
  umount: can't unmount /tmp: Resource busy
  [   39.168155] Unregister pv shared memory for cpu 0
  [   39.177657] reboot: Restarting system
  [   39.183596] reboot: machine restart

v1

  root@OpenWrt:/# sysupgrade -n -v /tmp/x86.gz
  == upgrade: Image metadata not present
  == upgrade: Reading partition table from bootdisk...
  == upgrade: Extract boot sector from the image
  54+9 records in
  54+9 records out
  == upgrade: Reading partition table from image...
  == upgrade: Commencing upgrade. Closing all shell sessions.
  killall: telnetd: no process killed
  Sending TERM to remaining processes ... ubusd askfirst urngd logd netifd odhcpd xl2tpd ntpd dnsmasq
  Sending KILL to remaining processes ...
  == upgrade: Switching to ramdisk...
  == upgrade: Performing system upgrade...
  == upgrade: Reading partition table from bootdisk...
  == upgrade: Extract boot sector from the image
  0+63 records in
  0+63 records out
  == upgrade: Reading partition table from image...
  == upgrade: Writing image to /dev/vda1...
  65535+0 records in
  31+1 records out
  == upgrade: Writing image to /dev/vda2...
  262143+0 records in
  127+1 records out
  == upgrade: Writing new UUID to /dev/vda...
  4+0 records in
  4+0 records out
  [   98.737664] F2FS-fs (vda1): Magic Mismatch, valid(0xf2f52010) - read(0x0)
  [   98.747115] F2FS-fs (vda1): Can't find valid F2FS filesystem in 1th superblock
  [   98.757250] F2FS-fs (vda1): Magic Mismatch, valid(0xf2f52010) - read(0x6020601)
  [   98.770807] F2FS-fs (vda1): Can't find valid F2FS filesystem in 2th superblock
  == upgrade: Upgrading bootloader on /dev/vda...
  == upgrade: Upgrade completed
  == upgrade: Rebooting system...
  umount: can't unmount /dev: Resource busy
  umount: can't unmount /tmp: Resource busy
  [  106.922638] Unregister pv shared memory for cpu 0
  [  106.931062] reboot: Restarting system
  [  106.936009] reboot: machine restart

Original

  root@(none):/# sysupgrade -n -v /tmp/x86.gz
  Image metadata not found
  Reading partition table from bootdisk...
  zcat: write error: Broken pipe
  zcat: write: Broken pipe
  Reading partition table from image...
  Commencing upgrade. Closing all shell sessions.
  killall: telnetd: no process killed
  Sending TERM to remaining processes ... ubusd askfirst urngd logd netifd odhcpd ntpd dnsmasq
  Sending KILL to remaining processes ...
  Switching to ramdisk...
  Performing system upgrade...
  Reading partition table from bootdisk...
  0+63 records in
  0+63 records out
  zcat: write error: Broken pipe
  zcat: write: Broken pipe
  Reading partition table from image...
  Writing image to /dev/vda1...
  zcat: write error: Broken pipe
  zcat: write: Broken pipe
  32767+0 records in
  15+1 records out
  Writing image to /dev/vda2...
  212991+0 records in
  103+1 records out
  Writing new UUID to /dev/vda...
  4+0 records in
  4+0 records out
  zcat: write error: Broken pipe
  zcat: write: Broken pipe
  [   31.461949] F2FS-fs (vda1): Magic Mismatch, valid(0xf2f52010) - read(0x0)
  [   31.470274] F2FS-fs (vda1): Can't find valid F2FS filesystem in 1th superblock
  [   31.480216] F2FS-fs (vda1): Magic Mismatch, valid(0xf2f52010) - read(0x6020601)
  [   31.491775] F2FS-fs (vda1): Can't find valid F2FS filesystem in 2th superblock
  Upgrading bootloader on /dev/vda...
  Upgrade completed
  Rebooting system...
  umount: can't unmount /dev: Resource busy
  umount: can't unmount /tmp: Resource busy
  [   38.511806] Unregister pv shared memory for cpu 0
  [   38.519259] reboot: Restarting system
  [   38.523725] reboot: machine restart

Yousong Zhou (10):
  base-files: upgrade: log with date prefix
  base-files: upgrade: use stdin redirection to replace cat command
  base-files: upgrade: add get_image_dd()
  base-files: upgrade: fwtool.sh: use v for log lines
  base-files: upgrade: fwtool.sh: rewording logs
  base-files: upgrade: stage2: rework log lines
  base-files: bump PKG_RELEASE
  x86: upgrade: use v function for writting logs
  x86: upgrade: use get_image_dd
  x86: upgrade: make code comment appear as log lines

 package/base-files/Makefile                   |  2 +-
 .../base-files/files/lib/upgrade/common.sh    | 10 ++++--
 .../base-files/files/lib/upgrade/fwtool.sh    | 24 +++++++-------
 package/base-files/files/lib/upgrade/stage2   | 12 +++----
 .../x86/base-files/lib/upgrade/platform.sh    | 32 +++++++++----------
 5 files changed, 42 insertions(+), 38 deletions(-)

Comments

Adrian Schmutzler Nov. 10, 2020, 12:03 p.m. UTC | #1
Hi,

> -----Original Message-----
> From: openwrt-devel [mailto:openwrt-devel-bounces@lists.openwrt.org]
> On Behalf Of Yousong Zhou
> Sent: Dienstag, 10. November 2020 03:22
> To: Adrian Schmutzler <mail@adrianschmutzler.de>; Philip Prindeville
> <philipp@redfish-solutions.com>
> Cc: Yousong Zhou <yszhou4tech@gmail.com>; OpenWrt Development List
> <openwrt-devel@lists.openwrt.org>
> Subject: [PATCH v2 00/10] sysupgrade: reword and organize log lines
> 
> The series mainly aims to make sysupgrade log output more organized and
> less disturbing, in the following aspects
> 
>  - Hide "write error: Broken pipe" from cat command and its friends
>  - Hide "F+P records in/out" lines from dd command
>  - Make log lines from sysupgrade command itself more distinguishable
>    than other commands by using common.sh function "v"

Thanks, this patchset should be an improvement to the process.

I'm still unsure what's the best variant for the output prefix (having seen the "date variant", the "==" actually seems more pronounced to me).
However, since we can change this by altering one line now, I would just ignore that matter and not delay the patchset due to that question.

Note my separate comments on two individual patches.

Thanks

Adrian

> 
> The series should at least partially address concerns raised at FS#3140
> 
> Ref: https://bugs.openwrt.org/index.php?do=details&task_id=3140
> 
> v2 <- v1
> 
>  - Make date command available in ramdisk and prefix log lines with datetime
>  - Hide "F+P records in/out" stderr output from dd command
> 
> Sysupgrade stdio dumps attached below for comparison
> 
> v2
> 
>   Tue Nov 10 02:04:04 UTC 2020 upgrade: Image metadata not present
>   Tue Nov 10 02:04:04 UTC 2020 upgrade: Reading partition table from
> bootdisk...
>   Tue Nov 10 02:04:04 UTC 2020 upgrade: Extract boot sector from the image
>   Tue Nov 10 02:04:05 UTC 2020 upgrade: Reading partition table from image...
>   Tue Nov 10 02:04:05 UTC 2020 upgrade: Commencing upgrade. Closing all
> shell sessions.
>   killall: telnetd: no process killed
>   Sending TERM to remaining processes ... ubusd askfirst urngd logd netifd
> odhcpd xl2tpd ntpd dnsmasq
>   Sending KILL to remaining processes ...
>   Tue Nov 10 02:04:09 UTC 2020 upgrade: Switching to ramdisk...
>   [   25.995408] EXT4-fs (vda2): re-mounted. Opts: (null)
>   Tue Nov 10 02:04:09 UTC 2020 upgrade: Performing system upgrade...
>   Tue Nov 10 02:04:09 UTC 2020 upgrade: Reading partition table from
> bootdisk...
>   Tue Nov 10 02:04:10 UTC 2020 upgrade: Extract boot sector from the image
>   Tue Nov 10 02:04:10 UTC 2020 upgrade: Reading partition table from image...
>   Tue Nov 10 02:04:10 UTC 2020 upgrade: Writing image to /dev/vda1...
>   Tue Nov 10 02:04:11 UTC 2020 upgrade: Writing image to /dev/vda2...
>   Tue Nov 10 02:04:15 UTC 2020 upgrade: Writing new UUID to /dev/vda...
>   [   31.582751] F2FS-fs (vda1): Magic Mismatch, valid(0xf2f52010) - read(0x0)
>   [   31.598842] F2FS-fs (vda1): Can't find valid F2FS filesystem in 1th
> superblock
>   [   31.613440] F2FS-fs (vda1): Magic Mismatch, valid(0xf2f52010) -
> read(0x6020601)
>   [   31.623241] F2FS-fs (vda1): Can't find valid F2FS filesystem in 2th
> superblock
>   Tue Nov 10 02:04:15 UTC 2020 upgrade: Upgrading bootloader on
> /dev/vda...
>   Tue Nov 10 02:04:22 UTC 2020 upgrade: Upgrade completed
>   Tue Nov 10 02:04:23 UTC 2020 upgrade: Rebooting system...
>   umount: can't unmount /dev: Resource busy
>   umount: can't unmount /tmp: Resource busy
>   [   39.168155] Unregister pv shared memory for cpu 0
>   [   39.177657] reboot: Restarting system
>   [   39.183596] reboot: machine restart
> 
> v1
> 
>   root@OpenWrt:/# sysupgrade -n -v /tmp/x86.gz
>   == upgrade: Image metadata not present
>   == upgrade: Reading partition table from bootdisk...
>   == upgrade: Extract boot sector from the image
>   54+9 records in
>   54+9 records out
>   == upgrade: Reading partition table from image...
>   == upgrade: Commencing upgrade. Closing all shell sessions.
>   killall: telnetd: no process killed
>   Sending TERM to remaining processes ... ubusd askfirst urngd logd netifd
> odhcpd xl2tpd ntpd dnsmasq
>   Sending KILL to remaining processes ...
>   == upgrade: Switching to ramdisk...
>   == upgrade: Performing system upgrade...
>   == upgrade: Reading partition table from bootdisk...
>   == upgrade: Extract boot sector from the image
>   0+63 records in
>   0+63 records out
>   == upgrade: Reading partition table from image...
>   == upgrade: Writing image to /dev/vda1...
>   65535+0 records in
>   31+1 records out
>   == upgrade: Writing image to /dev/vda2...
>   262143+0 records in
>   127+1 records out
>   == upgrade: Writing new UUID to /dev/vda...
>   4+0 records in
>   4+0 records out
>   [   98.737664] F2FS-fs (vda1): Magic Mismatch, valid(0xf2f52010) - read(0x0)
>   [   98.747115] F2FS-fs (vda1): Can't find valid F2FS filesystem in 1th
> superblock
>   [   98.757250] F2FS-fs (vda1): Magic Mismatch, valid(0xf2f52010) -
> read(0x6020601)
>   [   98.770807] F2FS-fs (vda1): Can't find valid F2FS filesystem in 2th
> superblock
>   == upgrade: Upgrading bootloader on /dev/vda...
>   == upgrade: Upgrade completed
>   == upgrade: Rebooting system...
>   umount: can't unmount /dev: Resource busy
>   umount: can't unmount /tmp: Resource busy
>   [  106.922638] Unregister pv shared memory for cpu 0
>   [  106.931062] reboot: Restarting system
>   [  106.936009] reboot: machine restart
> 
> Original
> 
>   root@(none):/# sysupgrade -n -v /tmp/x86.gz
>   Image metadata not found
>   Reading partition table from bootdisk...
>   zcat: write error: Broken pipe
>   zcat: write: Broken pipe
>   Reading partition table from image...
>   Commencing upgrade. Closing all shell sessions.
>   killall: telnetd: no process killed
>   Sending TERM to remaining processes ... ubusd askfirst urngd logd netifd
> odhcpd ntpd dnsmasq
>   Sending KILL to remaining processes ...
>   Switching to ramdisk...
>   Performing system upgrade...
>   Reading partition table from bootdisk...
>   0+63 records in
>   0+63 records out
>   zcat: write error: Broken pipe
>   zcat: write: Broken pipe
>   Reading partition table from image...
>   Writing image to /dev/vda1...
>   zcat: write error: Broken pipe
>   zcat: write: Broken pipe
>   32767+0 records in
>   15+1 records out
>   Writing image to /dev/vda2...
>   212991+0 records in
>   103+1 records out
>   Writing new UUID to /dev/vda...
>   4+0 records in
>   4+0 records out
>   zcat: write error: Broken pipe
>   zcat: write: Broken pipe
>   [   31.461949] F2FS-fs (vda1): Magic Mismatch, valid(0xf2f52010) - read(0x0)
>   [   31.470274] F2FS-fs (vda1): Can't find valid F2FS filesystem in 1th
> superblock
>   [   31.480216] F2FS-fs (vda1): Magic Mismatch, valid(0xf2f52010) -
> read(0x6020601)
>   [   31.491775] F2FS-fs (vda1): Can't find valid F2FS filesystem in 2th
> superblock
>   Upgrading bootloader on /dev/vda...
>   Upgrade completed
>   Rebooting system...
>   umount: can't unmount /dev: Resource busy
>   umount: can't unmount /tmp: Resource busy
>   [   38.511806] Unregister pv shared memory for cpu 0
>   [   38.519259] reboot: Restarting system
>   [   38.523725] reboot: machine restart
> 
> Yousong Zhou (10):
>   base-files: upgrade: log with date prefix
>   base-files: upgrade: use stdin redirection to replace cat command
>   base-files: upgrade: add get_image_dd()
>   base-files: upgrade: fwtool.sh: use v for log lines
>   base-files: upgrade: fwtool.sh: rewording logs
>   base-files: upgrade: stage2: rework log lines
>   base-files: bump PKG_RELEASE
>   x86: upgrade: use v function for writting logs
>   x86: upgrade: use get_image_dd
>   x86: upgrade: make code comment appear as log lines
> 
>  package/base-files/Makefile                   |  2 +-
>  .../base-files/files/lib/upgrade/common.sh    | 10 ++++--
>  .../base-files/files/lib/upgrade/fwtool.sh    | 24 +++++++-------
>  package/base-files/files/lib/upgrade/stage2   | 12 +++----
>  .../x86/base-files/lib/upgrade/platform.sh    | 32 +++++++++----------
>  5 files changed, 42 insertions(+), 38 deletions(-)
> 
> 
> _______________________________________________
> openwrt-devel mailing list
> openwrt-devel@lists.openwrt.org
> https://lists.openwrt.org/mailman/listinfo/openwrt-devel