Stumpy has gotten slow

[Trever]

I've got a Stumpy in normal mode (not dev) and it's gotten really slow during the first few minutes of booting.  I've tried various things, don't see any hardware messages (eg. SSD doesn't seem to be failing), full memory, not extensions.

Anyone know what this means?  It's the output of dmesg at the crosh prompt:

[  239.792217] WARNING: at /mnt/host/source/src/third_party/kernel/v3.8/kernel/hung_task.c:83 kthread+0xc0/0xc8()
[  239.792226] Hardware name: Stumpy
[  239.792231] task dev_debug_vboot:3346 is hung for 60 seconds
[  239.792237] dev_debug_vboot D ffff880117587438     0  3346      1 0x00000002
[  239.792249]  ffff880025637340 0000000000000082 ffff88014b11da00 ffff880025637fd8
[  239.792265]  ffff880025637fd8 0000000000011980 ffff880117587080 ffff88014fb11980
[  239.792279]  ffff88014fdc4f68 ffff8800256373e8 ffffffff9a11e56d 0000000000000002
[  239.792294] Call Trace:
[  239.792303]  [<ffffffff9a11e56d>] ? generic_block_bmap+0x65/0x65
[  239.792312]  [<ffffffff9a4d0117>] schedule+0x64/0x66
[  239.792318]  [<ffffffff9a4d0295>] io_schedule+0x57/0x71
[  239.792325]  [<ffffffff9a11e57b>] sleep_on_buffer+0xe/0x12
[  239.792331]  [<ffffffff9a4ce645>] __wait_on_bit+0x46/0x76
[  239.792338]  [<ffffffff9a4ce6f6>] out_of_line_wait_on_bit+0x81/0xa0
[  239.792345]  [<ffffffff9a11e56d>] ? generic_block_bmap+0x65/0x65
[  239.792352]  [<ffffffff9a051ae9>] ? autoremove_wake_function+0x34/0x34
[  239.792360]  [<ffffffff9a11efe5>] __wait_on_buffer+0x26/0x28
[  239.792366]  [<ffffffff9a11f005>] wait_on_buffer+0x1e/0x20
[  239.792373]  [<ffffffff9a11f213>] bh_submit_read+0x49/0x5b
[  239.792381]  [<ffffffff9a18a65e>] ext4_get_branch+0x94/0x117
[  239.792388]  [<ffffffff9a18a804>] ext4_ind_map_blocks+0x123/0x505
[  239.792397]  [<ffffffff9a1d70f2>] ? drive_stat_acct+0x11e/0x135
[  239.792406]  [<ffffffff9a157646>] ext4_map_blocks+0x68/0x22a
[  239.792413]  [<ffffffff9a159579>] _ext4_get_block+0xd6/0x171
[  239.792420]  [<ffffffff9a15962a>] ext4_get_block+0x16/0x18
[  239.792428]  [<ffffffff9a1272c9>] do_mpage_readpage+0x1b1/0x50c
[  239.792435]  [<ffffffff9a159614>] ? _ext4_get_block+0x171/0x171
[  239.792443]  [<ffffffff9a0c3a9f>] ? get_page+0x19/0x27
[  239.792450]  [<ffffffff9a0c3f20>] ? __lru_cache_add+0x39/0x75
[  239.792457]  [<ffffffff9a159614>] ? _ext4_get_block+0x171/0x171
[  239.792464]  [<ffffffff9a127716>] mpage_readpages+0xf2/0x149
[  239.792471]  [<ffffffff9a159614>] ? _ext4_get_block+0x171/0x171
[  239.792479]  [<ffffffff9a155f86>] ext4_readpages+0x3c/0x43
[  239.792486]  [<ffffffff9a0c2d62>] __do_page_cache_readahead+0x150/0x208
[  239.792494]  [<ffffffff9a0c3034>] ra_submit+0x21/0x25
[  239.792500]  [<ffffffff9a0bb39c>] filemap_fault+0x197/0x381
[  239.792508]  [<ffffffff9a0d7640>] __do_fault+0xb0/0x34a
[  239.792515]  [<ffffffff9a0d977c>] handle_pte_fault+0x136/0x559
[  239.792523]  [<ffffffff9a4d0d20>] ? _raw_spin_unlock+0xe/0x10
[  239.792529]  [<ffffffff9a0daa05>] handle_mm_fault+0x16a/0x193
[  239.792537]  [<ffffffff9a0297ed>] __do_page_fault+0x1be/0x38e
[  239.792544]  [<ffffffff9a0d60ee>] ? vma_interval_tree_insert+0x7e/0x86
[  239.792552]  [<ffffffff9a0dca81>] ? __vma_link_file+0x65/0x67
[  239.792559]  [<ffffffff9a0dd418>] ? vma_link+0x80/0x91
[  239.792565]  [<ffffffff9a0defb2>] ? mmap_region+0x2f8/0x420
[  239.792572]  [<ffffffff9a0299ef>] do_page_fault+0xe/0x10
[  239.792579]  [<ffffffff9a4d1332>] page_fault+0x22/0x30
[  239.792587]  [<ffffffff9a1f3f75>] ? __clear_user+0x25/0x47
[  239.792594]  [<ffffffff9a1f3fca>] clear_user+0x33/0x35
[  239.792601]  [<ffffffff9a1377b2>] padzero+0x23/0x30
[  239.792608]  [<ffffffff9a139436>] load_elf_binary+0x94f/0x1730
[  239.792615]  [<ffffffff9a138ae7>] ? elf_core_dump+0x1136/0x1136
[  239.792623]  [<ffffffff9a0fb272>] search_binary_handler+0xe7/0x2f4
[  239.792630]  [<ffffffff9a1373f5>] ? compat_sys_ioctl+0xd2d/0xd2d
[  239.792637]  [<ffffffff9a1375c3>] load_script+0x1ce/0x1f0
[  239.792643]  [<ffffffff9a0dae5a>] ? get_user_pages+0x42/0x44
[  239.792650]  [<ffffffff9a0c39bb>] ? put_page+0x26/0x35
[  239.792657]  [<ffffffff9a0fb757>] ? copy_strings.isra.19+0x1cf/0x2c2
[  239.792664]  [<ffffffff9a0fb272>] search_binary_handler+0xe7/0x2f4
[  239.792671]  [<ffffffff9a0fc738>] do_execve_common.isra.25+0x2d4/0x3f0
[  239.792678]  [<ffffffff9a0fc86c>] do_execve+0x18/0x1a
[  239.792684]  [<ffffffff9a0fcb13>] sys_execve+0x3a/0x4e
[  239.792692]  [<ffffffff9a4d1fb9>] stub_execve+0x69/0xc0
[  239.792698] ---[ end trace 29da0da793b8590b ]---

[Sonny Rao]

That means that the kernel blocked inside that function for at least
60 seconds -- so that thread is effectively hung.
What version of Chromium OS and/or the kernel are you using?

> --
> --
> Chromium OS Developers mailing list: chromiu...@chromium.org
> View archives, change email options, or unsubscribe:
> http://groups.google.com/a/chromium.org/group/chromium-os-dev?hl=en
>
> ---
> You received this message because you are subscribed to the Google Groups
> "Chromium OS dev" group.
> To unsubscribe from this group and stop receiving emails from it, send an
> email to chromium-os-d...@chromium.org.

[Trever]

I'm on Chrome OS in normal mode (not Chromium OS).

Platform

9901.77.0 (Official Build) stable-channel stumpy

Firmware

Google_Stumpy.2.102.0

Channel

Currently on stable

CHANGE CHANNEL

Blink

537.36 (@)

V8

6.2.414.43

User Agent

Mozilla/5.0 (X11; CrOS x86_64 9901.77.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/62.0.3202.97 Safari/537.36

Command Line

/opt/google/chrome/chrome --ppapi-flash-path=/opt/google/chrome/pepper/libpepflashplayer.so --ppapi-flash-version=27.0.0.187 --ui-prioritize-in-gpu-process --use-gl=egl --gpu-sandbox-failures-fatal=yes --enable-logging --log-level=1 --use-cras --enable-wayland-server --user-data-dir=/home/chronos --max-unused-resource-memory-usage-percentage=5 --disable-lock-screen-apps --login-profile=user --aura-legacy-power-button --default-wallpaper-large=/usr/share/chromeos-assets/wallpaper/default_large.jpg --default-wallpaper-small=/usr/share/chromeos-assets/wallpaper/default_small.jpg --child-wallpaper-large=/usr/share/chromeos-assets/wallpaper/child_large.jpg --child-wallpaper-small=/usr/share/chromeos-assets/wallpaper/child_small.jpg --guest-wallpaper-large=/usr/share/chromeos-assets/wallpaper/guest_large.jpg --guest-wallpaper-small=/usr/share/chromeos-assets/wallpaper/guest_small.jpg --enable-consumer-kiosk --enterprise-enrollment-initial-modulus=15 --enterprise-enrollment-modulus-limit=19 --login-manager --first-exec-after-boot --vmodule=tablet_power_button_controller=1,*chromeos/login/*=1,auto_enrollment_controller=1,*plugin*=2,*zygote*=1,*/ui/ozone/*=1,*/ui/display/manager/chromeos/*=1,power_button_observer=2,webui_login_view=2,lock_state_controller=2,webui_screen_locker=2,screen_locker=2

Build Date

Monday, November 13, 2017

[Mike Frysinger]

can you file feedback using alt+shift+i after such a boot ?  it'll automatically gather system details/logs.

-mike

[Trever]

Okay sent, but if you're saying to do it immediately after boot, I'll have to send again...  

[Mike Frysinger]

don't worry about sending too many reports :)

-mike

[Gwendal Grignou]

For future reference, your feeback report is 84720737643.

Looking at storage_info, attribute 230 [Percentage Total P/E Count
XX.YY] is at 29% out of 100%, you have used the disk for 2792 hours,
written quite a lot of data 3464013831 blocks [1.6TB], so the device
is aging, but nothing abnormal.
Were you doing large file transfers at the time of the hung tasks
[239s after boot]?

Gwendal.

[Trever]

On Wednesday, November 29, 2017 at 7:58:23 PM UTC-5, Gwendal Grignou wrote:

For future reference, your feeback report is 84720737643.

Looking at storage_info, attribute 230 [Percentage Total P/E Count
XX.YY] is at 29% out of 100%, you have used the disk for 2792 hours,
written quite a lot of data 3464013831 blocks [1.6TB], so the device
is aging, but nothing abnormal.
Were you doing large file transfers at the time of the hung tasks
[239s after boot]?

Thanks.

No large file transfers.  Just a handful of tabs re-opening at boot.  I do notice the more data I have locally on disc, the worse it seems to get, but deleting everything and powerwashing never solves the problem, so a correlation there I'm not sure about. (My recollection is the file system is only going to decrypt files as I access, though large numbers of files may slow things because of metadata?  Don't remember.)  Booting with no tabs opening again does not solve the problem.

Could the SSD just be getting slow from my relatively heavy local use over the years (photos, etc.)?  I have never fully understood those possibilities with that tech...  heh- I'm supposed to know for work, oh well.  Lot's of rumors and misinformation about how SSDs age...

I do have another stumpy in dev mode with crouton on it that I use very infrequently and has the VMX bits enabled in the firmware (successfully used instructions for that at http://dev.chromium.org/chromium-os/developer-information-for-chrome-os-devices/samsung-sandy-bridge/coreboot-vmx-hack).  It seems to me that has developed the same problem.

The unit I'm writing about is stock (no firmware alterations).

[Trever]

Basically I wonder if Stumpy is neglected because near End of Life, and so software updates are slowing it down, or if it is something to do with my unit.

Stumpy does not seem to be well tested.  We recently had the whole boot issue with the endless "wait while updating".  So I'm suspicious recent Chromium OS for some reason no longer runs well on this hardware.

[Sonny Rao]

We still look at bugs on Stumpy

Your issue looks a lot like this bug:
https://bugs.chromium.org/p/chromium/issues/detail?id=493301

It's on the 3.8 kernel and we get a hung task in ext4_get_branch -- I
think the problem here is that we don't have a good reproduction case
for this bug, so it's unclear what the problem is.

Is it possible for you to switch to dev mode and then back to
re-create your stateful partition? If it is a ext4 corruption issue
then that would fix it -- if it's an SSD firmware issue then it would
not fix it, but that would give us a data point. Of course you'll
have to save any downloaded files elsewhere as they will be wiped when
you switch to dev mode.

[Trever]

On Thursday, November 30, 2017 at 5:46:36 PM UTC-5, Sonny Rao wrote:

We still look at bugs on Stumpy

Your issue looks a lot like this bug:
https://bugs.chromium.org/p/chromium/issues/detail?id=493301

It's on the 3.8 kernel and we get a hung task in ext4_get_branch -- I
think the problem here is that we don't have a good reproduction case
for this bug, so it's unclear what the problem is.

Is it possible for you to switch to dev mode and then back to
re-create your stateful partition?  If it is a ext4 corruption issue
then that would fix it -- if it's an SSD firmware issue then it would
not fix it, but that would give us a data point.  Of course you'll
have to save any downloaded files elsewhere as they will be wiped when
you switch to dev mode.

I will try this and report back.  

I suppose once file system buffers are loaded, performance would tend to be more normal, so might account for the behavior?

I thought power washing recreated the stateful filesystem, but perhaps that was never the case or has changed since power washing used to take some time and now it happens in a flash.  My notes say the stateful has always been ext4 so that didn't change.  Not sure how I got corruption if I have that.

[Sonny Rao]

On Thu, Nov 30, 2017 at 4:20 PM, Trever <trr...@gmail.com> wrote:
> On Thursday, November 30, 2017 at 5:46:36 PM UTC-5, Sonny Rao wrote:
>>
>> We still look at bugs on Stumpy
>>
>> Your issue looks a lot like this bug:
>> https://bugs.chromium.org/p/chromium/issues/detail?id=493301
>>
>> It's on the 3.8 kernel and we get a hung task in ext4_get_branch -- I
>> think the problem here is that we don't have a good reproduction case
>> for this bug, so it's unclear what the problem is.
>>
>> Is it possible for you to switch to dev mode and then back to
>> re-create your stateful partition? If it is a ext4 corruption issue
>> then that would fix it -- if it's an SSD firmware issue then it would
>> not fix it, but that would give us a data point. Of course you'll
>> have to save any downloaded files elsewhere as they will be wiped when
>> you switch to dev mode.
>
>
> I will try this and report back.
>
> I suppose once file system buffers are loaded, performance would tend to be
> more normal, so might account for the behavior?

Yes that's possible

>
> I thought power washing recreated the stateful filesystem, but perhaps that
> was never the case or has changed since power washing used to take some time
> and now it happens in a flash. My notes say the stateful has always been
> ext4 so that didn't change. Not sure how I got corruption if I have that.

Power washing would do the same thing and re-create the stateful partition.
Your ext4 stateful partition looked to be created several years ago so
that's a long time for things to happen.

[Trever]

If you're sure power washing would re-create the stateful filesystem, then I'm not too hopeful...  I'm not sure why it says several years ago because I just power washed recently (maybe a month ago).

[Trever]

On Thursday, November 30, 2017 at 5:46:36 PM UTC-5, Sonny Rao wrote:

We still look at bugs on Stumpy

Your issue looks a lot like this bug:
https://bugs.chromium.org/p/chromium/issues/detail?id=493301

It's on the 3.8 kernel and we get a hung task in ext4_get_branch -- I
think the problem here is that we don't have a good reproduction case
for this bug, so it's unclear what the problem is.

Is it possible for you to switch to dev mode and then back to
re-create your stateful partition?  If it is a ext4 corruption issue
then that would fix it -- if it's an SSD firmware issue then it would
not fix it, but that would give us a data point.  Of course you'll
have to save any downloaded files elsewhere as they will be wiped when
you switch to dev mode.

Done.

The box is improved for sure, but I've been through this before after a power wash, so time will tell.

One thing:  whereas power wash took seconds, going into dev mode took minutes (seems to be reformatting).  So perhaps with respect to state full filesystem corruption, if that's the problem going through this exercise solves the problem.  I do wonder what could have caused any corruption, if it was there and the cause of the slow downs/freezes.

[Trever Nightingale]

On Mon, Dec 4, 2017 at 4:57 PM Sonny Rao <sonn...@google.com> wrote:

Ok, sounds like it was corruption related.  Usually corruption happens due to unclean shutdowns.  Let us know if it comes back

Thanks sincerely for the help, but just reporting that both of the Stumpies I have are slow as molasses (more like they become "stuck", then unstick, though can be generally slow too).  Any fix after a wipe lasts for a day, more or less.

I use the machines fairly hard and in this context stumpy does crash a fair amount (various scenarios), so I can't rule out that corruption is being almost immediately re-introduced after a wipe/filesystem-rebuild, but I think that's very unlikely unless there is a bug that is making the fs prone to corruption when the system freezes and requires a hard reset (you may have indicated there is a suspicion/active bug about this, I'm not clear on that).  ext4 has always been quite robust in my experience.

Unless someone can say "I still use Stumpy everyday and am not having any slowness problems", my instinct the machine just isn't being optimized for anymore, etc., and so it just is slow now, using the recent versions of Chrome.  (For that reason, what I'd really like to know is when will a Skylake or higher Chromebox (USB C ports) become available...  Apparently the market for Chromeboxes is no where near toothbrushes, too bad, I still love the form factor and feel that Chrome OS is at it's best on the desktop.  But I know I'm in a small minority of users on this.)

Trever

[Luigi Semenzato]

Have you filed a few more feedback reports already? (I'd look it up,
but I am not able to right at this moment.)

I am chasing an unrelated Stumpy bug (crbug.com/792562) and I was
wondering if I can ask a quick favor. Do your stumpies shut down and
reboot normally? More specifically, when you shut down the system,
does the blue LED in the power button turn off?

Thank you.