Bug 10455

i have no idea on this, so I bounced it to Saul for re-assignment.

Probably related with bug 10424.

can you try other USB hardware?  Does the Blk# move around?

I have some knowledge on this:
* Seems to have been introduced with the 4.8 kernel
* Does not occur on every boot. Sometimes occurs multiple times per boot. More likely to occur with larger images.
* The blk# is not consistent. It changes between boots with the exact same hardware.
* Happens with all USB and microSD cards I have tried.

It also doesn't seem to occur on an installed image.

This issue was also reproducible on 2.2 rc6:

STATUS: FAILED
BUILD: 2.2.rc6: dc8508f609974cc99606b9042bfa7f870ce80228
ENVIRONMENT: genericx86 - on MMAX32bit

I have attached the log for further reference.

Created attachment 3501 [details]
results-bitbake-worker_x86_MM32_2.2rc6.log

Created attachment 3503 [details]
results-bitbake-worker_x86-64_MMAX64_2.2rc6.log

This issue is also reproducible on 2.2 rc6 (MMAX64):

STATUS: FAILED
BUILD: 2.2.rc6: dc8508f609974cc99606b9042bfa7f870ce80228
ENVIRONMENT: genericx86-64 - on MMAX64bit

I have attached the log for further reference.

More information:
* Always on /dev/loop0
* Only occurs on live images, not .wic or installed images

I think a likely culprit is the init-live.sh script, but it could also be a kernel issue.

With a little work I was able to reproduce this on a qemu live image as well:

root@qemux86-64:~# dmesg | grep blk
[   26.008900] blk_update_request: I/O error, dev loop0, sector 390150
[   59.298164] blk_update_request: I/O error, dev loop0, sector 390152

Looks like its not a hardware issue. It only occurs on live images, and only seems to occur on writes as well. If qemu boots the live image with the rootfs as read only it does not occur.

Bisect log of the kernel:

git bisect start
# good: [afd2ff9b7e1b367172f18ba7f693dfb62bdcb2dc] Linux 4.4
git bisect good afd2ff9b7e1b367172f18ba7f693dfb62bdcb2dc
# bad: [b562e44f507e863c6792946e4e1b1449fbbac85d] Linux 4.5
git bisect bad b562e44f507e863c6792946e4e1b1449fbbac85d
# good: [e535d74bc50df2357d3253f8f3ca48c66d0d892a] Merge tag 'docs-4.5' of git://git.lwn.net/linux
git bisect good e535d74bc50df2357d3253f8f3ca48c66d0d892a
# good: [62c79bb3a99fb46a8624f9c7e86fa5ee2f936360] Merge tag 'armsoc-dt64' of git://git.kernel.org/pub/scm/linux/kernel/git/arm/arm-soc
git bisect good 62c79bb3a99fb46a8624f9c7e86fa5ee2f936360
# bad: [d5bfb96bdad3588961f49a6eff89a625fbaa12bf] Merge tag 'for-linus-4.5-2' of git://git.code.sf.net/p/openipmi/linux-ipmi
git bisect bad d5bfb96bdad3588961f49a6eff89a625fbaa12bf
# bad: [d0e5fbb01a67e400e82fefe4896ea40c6447ab98] block: fix bio splitting on max sectors
git bisect bad d0e5fbb01a67e400e82fefe4896ea40c6447ab98
# bad: [eae21770b4fed5597623aad0d618190fa60426ff] Merge branch 'akpm' (patches from Andrew)
git bisect bad eae21770b4fed5597623aad0d618190fa60426ff
# good: [96461fdb3ace6753d29eaa43387bcd6d540710e9] Merge tag 'cris-for-4.5' of git://git.kernel.org/pub/scm/linux/kernel/git/jesper/cris
git bisect good 96461fdb3ace6753d29eaa43387bcd6d540710e9
# bad: [d8b38438a0bcb362c396f49d8279ef7b505917f4] mm: vmscan: do not scan anon pages if memcg swap limit is hit
git bisect bad d8b38438a0bcb362c396f49d8279ef7b505917f4
# bad: [cdf4b3fa03bab157d2d70d4de65bb7ae319b084f] kexec: set KEXEC_TYPE_CRASH before sanity_check_segment_list()
git bisect bad cdf4b3fa03bab157d2d70d4de65bb7ae319b084f
# good: [938224b5e596c1c30d968ffd927a578ea7c4f45b] checkpatch: warn when casting constants to c90 int or longer types
git bisect good 938224b5e596c1c30d968ffd927a578ea7c4f45b
# bad: [8992de4cec126c6703ece0747239d071dbce725f] fat: constify fatent_operations structures
git bisect bad 8992de4cec126c6703ece0747239d071dbce725f
# good: [2c35dea279351f2ad74a99126b29f9f5394ccc04] fs/hfs/catalog.c: use list_for_each_entry in hfs_cat_delete
git bisect good 2c35dea279351f2ad74a99126b29f9f5394ccc04
# bad: [b13bb33eacb7266d66a3adf03adaa0886d091789] fat: add fat_fallocate operation
git bisect bad b13bb33eacb7266d66a3adf03adaa0886d091789
# good: [a3082d526f2d406d4b488e49a508a0062a23314f] fat: add simple validation for directory inode
git bisect good a3082d526f2d406d4b488e49a508a0062a23314f
# first bad commit: [b13bb33eacb7266d66a3adf03adaa0886d091789] fat: add fat_fallocate operation

This bus is still present on 

SATATUS: FAILED
BB_VERSION        = "1.34.0"
BUILD_SYS         = "x86_64-linux"
NATIVELSBSTRING   = "universal"
TARGET_SYS        = "x86_64-poky-linux"
MACHINE           = "genericx86-64"
DISTRO            = "poky"
DISTRO_VERSION    = "2.3"
TUNE_FEATURES     = "m64 core2"
COMMIT:7a0e795373653886452a7a2992ced10080711c26
ENVIRONMENT: genericx86-64 - on NUC6i5SYH

STEPS TO REPRODUCE:

1. Parse dmesg log and all log files in /var/log for keywords like: "error" , "failed" , "cannot", "can't" etc.
2. Filter out the known and invalid errors or errors that appear in certain situations and need to be ignored.

EXPECTED OUTCOME: 
  
 No errors or fails should be present in logs

ACTUAL:
-----------------------
Central error: [    5.760179] blk_update_request: I/O error, dev loop0, sector 727736
***********************

I have attached the log for further reference.

Created attachment 3749 [details]
I/O error, dev loop0

Fixing bug info and moving to a later date.

This occurs with any hddimg, even qemu. This has to do with the mounting options we use with the rootfs.img. It seems to not like being in read/write mode during a live boot. This error should go away once we move away from hddimgs.

Changing to the initramfs-framework scripts has resolved this issue for meta-intel. Genericx86(-64) will be fixed when OE-core changes.

https://git.yoctoproject.org/cgit/cgit.cgi/meta-intel/commit/?id=f9e95940fb8c5769113a53d2494185b389299926

Changing the initramfs scripts fixed this for meta-intel and should fix it for OE-core as well.

in FAIL failure: test_parselogs (parselogs.ParseLogsTest) a central bug in error fails, central error: [1.457891] snd_hda_codec_hdmi: hdaudioC0D2 probe failed with error -16
===========================================================================
NOTE: FAIL: test_parselogs (parselogs.ParseLogsTest)
NOTE: ----------------------------------------------------------------------
NOTE: Traceback (most recent call last):
  File "/home/oscar/NUC/meta/lib/oeqa/core/decorator/__init__.py", line 32, in wrapped_f
    return func(*args, **kwargs)
  File "/home/oscar/NUC/meta/lib/oeqa/core/decorator/__init__.py", line 32, in wrapped_f
    return func(*args, **kwargs)
  File "/home/oscar/NUC/meta/lib/oeqa/runtime/cases/parselogs.py", line 363, in test_parselogs
    self.assertEqual(errcount, 0, msg=self.msg)
AssertionError: 6 != 0 : Log: /home/oscar/NUC/build/tmp/work/genericx86_64-poky-linux/core-image-sato-sdk/1.0-r0/dmesg_output.log
-----------------------
Central error: [    1.457891] snd_hda_codec_hdmi: probe of hdaudioC0D2 failed with error -16
***********************
[    1.453286] snd_hda_intel 0000:00:1f.3: Consider building the kernel with CONFIG_SND_DYNAMIC_MINORS=y
[    1.454341] snd_hda_intel 0000:00:1f.3: control 3:0:0:ELD:0 is already present
[    1.454386] snd_hda_codec_hdmi: probe of hdaudioC0D2 failed with error -16
================================================================================
Build Configuration:
BUILD_SYS         = "x86_64-linux"
NATIVELSBSTRING   = "universal-4.8"
TARGET_SYS        = "i586-poky-linux"
MACHINE           = "genericx86-64" and genericx86-64-WIC on NUC 6i5SYH
DISTRO            = "poky"
DISTRO_VERSION    = "2.4"
TUNE_FEATURES     = "m32 i586"
meta-yocto-bsp    = "HEAD:da05a01423a60a23cd1073eb0ad3776e5bf4f2a8"

    NOTE: full-log in attachment

Created attachment 4066 [details]
full_log

fails in test_parselogs (parselogs.ParseLogsTest) and in central error: Direct firmware load for rtl_nic/rtl8168g-2.fw failed with error -2

Build Configuration:
BUILD_SYS         = "x86_64-linux"
NATIVELSBSTRING   = "universal-4.8"
TARGET_SYS        = "i586-poky-linux"
MACHINE           = "genericx86" and genericx86-WIC on Minnowmax32
DISTRO            = "poky"
DISTRO_VERSION    = "2.4"
TUNE_FEATURES     = "m32 i586"
meta-yocto-bsp    = "HEAD:da05a01423a60a23cd1073eb0ad3776e5bf4f2a8"

 -----------------------
Central error: [   16.824370] r8169 0000:03:00.0: Direct firmware load for rtl_nic/rtl8168g-2.fw failed with error -2
***********************
[   15.640259] udevd[142]: starting eudev-3.2.2

   NOTE: full-log in attachment

Created attachment 4075 [details]
2.4_M4_rc2

by running a Joule x64 platform, meta-intel 2.4 rc1, and a image 
core-image-sato-sdk.wic is getting the error previously mentioned 

config:
====
Build Configuration:
BB_VERSION        = "1.35.0"
BUILD_SYS         = "x86_64-linux"
NATIVELSBSTRING   = "universal"
TARGET_SYS        = "x86_64-poky-linux"
MACHINE           = "intel-corei7-64"
DISTRO            = "poky"
DISTRO_VERSION    = "2.4"
TUNE_FEATURES     = "m64 corei7"
TARGET_FPU        = ""
meta              
meta-poky         
meta-yocto-bsp    = "HEAD:65d23bd7986615fdfb0f1717b615534a2a14ab80"
meta-intel        = "master:863590f9bc7104fef698ce6b89ec24dfce542df1"
====


Error:
NOTE: core-image-sato-sdk-1.0-r0 do_testimage: ======================================================================
NOTE: core-image-sato-sdk-1.0-r0 do_testimage: FAIL: test_parselogs (parselogs.ParseLogsTest)
NOTE: core-image-sato-sdk-1.0-r0 do_testimage: ----------------------------------------------------------------------
NOTE: core-image-sato-sdk-1.0-r0 do_testimage: Traceback (most recent call last):
  File "/home/jzepeda/2.4rc3/poky/meta/lib/oeqa/core/decorator/__init__.py", line 32, in wrapped_f
    return func(*args, **kwargs)
  File "/home/jzepeda/2.4rc3/poky/meta/lib/oeqa/core/decorator/__init__.py", line 32, in wrapped_f
    return func(*args, **kwargs)
  File "/home/jzepeda/2.4rc3/poky/meta/lib/oeqa/runtime/cases/parselogs.py", line 363, in test_parselogs
    self.assertEqual(errcount, 0, msg=self.msg)
AssertionError: 4 != 0 : Log: /home/jzepeda/2.4rc3/poky/automated/tmp/work/intel_corei7_64-poky-linux/core-image-sato-sdk/1.0-r0/dmesg_output.log
-----------------------
Central error: [    0.722850] i915 0000:00:02.0: Direct firmware load for i915/bxt_dmc_ver1_07.bin failed with error -2
***********************
[    0.710602] button: probe of LNXPWRBN:00 failed with error -22
[    0.714445] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
[    0.716199] Linux agpgart interface v0.103
[    0.719092] [drm] Memory usable by graphics device = 4096M
[    0.719612] checking generic (80000000 7e9000) vs  File "/home/jzepeda/2.4rc3/poky/meta/lib/oeqa/core/decorator/__init__.py", line 32, in wrapped_f
    return func(*args, **kwargs)
  File "/home/jzepeda/2.4rc3/poky/meta/lib/oeqa/runtime/cases/parselogs.py", line 363, in test_parselogs
    self.assertEqual(errcount, 0, msg=self.msg)
AssertionError: 4 != 0 : Log: /home/jzepeda/2.4rc3/poky/automated/tmp/work/intel_corei7_64-poky-linux/core-image-sato-sdk/1.0-r0/dmesg_output.log
-----------------------
Central error: [    0.722850] i915 0000:00:02.0: Direct firmware load for i915/bxt_dmc_ver1_07.bin failed with error -2
***********************
[    0.710602] button: probe of LNXPWRBN:00 failed with error -22
[    0.714445] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
[    0.716199] Linux agpgart interface v0.103
[    0.719092] [drm] Memory usable by graphics device = 4096M
[    0.719612] checking generic (80000000 7e9000) vs hw (8 File "/home/jzepeda/2.4rc3/poky/meta/lib/oeqa/core/decorator/__init__.py", line 32, in wrapped_f
    return func(*args, **kwargs)
  File "/home/jzepeda/2.4rc3/poky/meta/lib/oeqa/runtime/cases/parselogs.py", line 363, in test_parselogs
    self.assertEqual(errcount, 0, msg=self.msg)
AssertionError: 4 != 0 : Log: /home/jzepeda/2.4rc3/poky/automated/tmp/work/intel_corei7_64-poky-linux/core-image-sato-sdk/1.0-r0/dmesg_output.log
-----------------------
Central error: [    0.722850] i915 0000:00:02.0: Direct firmware load for i915/bxt_dmc_ver1_07.bin failed with error -2
***********************
[    0.710602] button: probe of LNXPWRBN:00 failed with error -22
[    0.714445] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
[    0.716199] Linux agpgart interface v0.103
[    0.719092] [drm] Memory usable by graphics device = 4096M
[    0.719612] checking generic (80000000 7e9000) vs hw (80000000 10000000)
[    0.719613] fb: switching to inteldrmfb from EFI VGA
[    0.720110] Console: switching to colour dummy device 80x25
[    0.720697] [drm] Replacing VGA console driver
[    0.721434] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
[    0.722009] [drm] Driver supports precise vblank timestamp query.
[    0.722850] i915 0000:00:02.0: Direct firmware load for i915/bxt_dmc_ver1_07.bin failed with error -2
===========================
the full logs are attached:
0000000 10000000)
[    0.719613] fb: switching to inteldrmfb from EFI VGA
[    0.720110] Console: switching to colour dummy device 80x25
[    0.720697] [drm] Replacing VGA console driver
[    0.721434] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
[    0.722009] [drm] Driver supports precise vblank timestamp query.
[    0.722850] i915 0000:00:02.0: Direct firmware load for i915/bxt_dmc_ver1_07.bin failed with error -2
===========================
the full logs are attached:
hw (80000000 10000000)
[    0.719613] fb: switching to inteldrmfb from EFI VGA
[    0.720110] Console: switching to colour dummy device 80x25
[    0.720697] [drm] Replacing VGA console driver
[    0.721434] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
[    0.722009] [drm] Driver supports precise vblank timestamp query.
[    0.722850] i915 0000:00:02.0: Direct firmware load for i915/bxt_dmc_ver1_07.bin failed with error -2
===========================
the full logs are attached

Regards!

Created attachment 4107 [details]
joule64

Created attachment 4108 [details]
parselogs.ParseLogsTest.test_parselogs-JOULE

This fixes it: https://git.yoctoproject.org/cgit/cgit.cgi/poky/commit/?h=sumo&id=53078a00ceab5d6aaa61c77fcb73f0d4aa788e00