Linux - Software This forum is for Software issues.
Having a problem installing a new program? Want to know which application is best for the job? Post your question in this forum. |
Notices |
Welcome to LinuxQuestions.org, a friendly and active Linux Community.
You are currently viewing LQ as a guest. By joining our community you will have the ability to post topics, receive our newsletter, use the advanced search, subscribe to threads and access many other special features. Registration is quick, simple and absolutely free. Join our community today!
Note that registered members see fewer ads, and ContentLink is completely disabled once you log in.
Are you new to LinuxQuestions.org? Visit the following links:
Site Howto |
Site FAQ |
Sitemap |
Register Now
If you have any problems with the registration process or your account login, please contact us. If you need to reset your password, click here.
Having a problem logging in? Please visit this page to clear all LQ-related cookies.
Get a virtual cloud desktop with the Linux distro that you want in less than five minutes with Shells! With over 10 pre-installed distros to choose from, the worry-free installation life is here! Whether you are a digital nomad or just looking for flexibility, Shells can put your Linux machine on the device that you want to use.
Exclusive for LQ members, get up to 45% off per month. Click here for more info.
|
|
07-05-2015, 04:30 PM
|
#1
|
Senior Member
Registered: Jul 2012
Location: Aachen, Germany
Distribution: Void, Debian
Posts: 1,019
|
Boot sometimes hangs: kworker/0:1:42 blocked for more than 120 seconds
On my Arch laptop the boot process sometimes hangs several minutes.
When that happens, typically also the shutdown will hang.
This is what gets printed to the journal log in these cases:
Code:
Jul 05 20:58:55 ideapad kernel: INFO: task kworker/0:1:42 blocked for more than 120 seconds.
Jul 05 20:58:55 ideapad kernel: Not tainted 4.0.7-2-ARCH #1
Jul 05 20:58:55 ideapad kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jul 05 20:58:55 ideapad kernel: kworker/0:1 D ffff88015989b678 0 42 2 0x00000000
Jul 05 20:58:55 ideapad kernel: Workqueue: kacpid acpi_os_execute_deferred
Jul 05 20:58:55 ideapad kernel: ffff88015989b678 ffffffff818124c0 ffff880159890000 fffffffffff7ffff
Jul 05 20:58:55 ideapad kernel: ffff88015989bfd8 ffff880159efb4bc ffff880159890000 00000000ffffffff
Jul 05 20:58:55 ideapad kernel: ffff880159efb4c0 ffff88015989b698 ffffffff81576a87 00000000000000ed
Jul 05 20:58:55 ideapad kernel: Call Trace:
Jul 05 20:58:55 ideapad kernel: [<ffffffff81576a87>] schedule+0x37/0x90
Jul 05 20:58:55 ideapad kernel: [<ffffffff81576e55>] schedule_preempt_disabled+0x15/0x20
Jul 05 20:58:55 ideapad kernel: [<ffffffff81578395>] __mutex_lock_slowpath+0xd5/0x150
Jul 05 20:58:55 ideapad kernel: [<ffffffff8157842b>] mutex_lock+0x1b/0x30
Jul 05 20:58:55 ideapad kernel: [<ffffffff8134cae2>] acpi_ec_transaction+0x84/0x438
Jul 05 20:58:55 ideapad kernel: [<ffffffff8134cef0>] acpi_ec_read+0x5a/0x7a
Jul 05 20:58:55 ideapad kernel: [<ffffffff8134d0c1>] acpi_ec_space_handler+0xde/0x1ff
Jul 05 20:58:55 ideapad kernel: [<ffffffff810bdca2>] ? up+0x32/0x50
Jul 05 20:58:55 ideapad kernel: [<ffffffff8134cfe3>] ? ec_transaction+0x70/0x70
Jul 05 20:58:55 ideapad kernel: [<ffffffff8135a2ff>] acpi_ev_address_space_dispatch+0x201/0x262
Jul 05 20:58:55 ideapad kernel: [<ffffffff8135de09>] acpi_ex_access_region+0x1ea/0x27a
Jul 05 20:58:55 ideapad kernel: [<ffffffff8135a2ff>] ? acpi_ev_address_space_dispatch+0x201/0x262
Jul 05 20:58:55 ideapad kernel: [<ffffffff8135e1d0>] acpi_ex_field_datum_io+0x10a/0x198
Jul 05 20:58:55 ideapad kernel: [<ffffffff8135e2d4>] acpi_ex_write_with_update_rule+0x76/0xf2
Jul 05 20:58:55 ideapad kernel: [<ffffffff8135e08a>] acpi_ex_insert_into_field+0x1f1/0x22d
Jul 05 20:58:55 ideapad kernel: [<ffffffff8135dbab>] acpi_ex_write_data_to_field+0x1e7/0x212
Jul 05 20:58:55 ideapad kernel: [<ffffffff81361d06>] acpi_ex_store_object_to_node+0xc1/0xf1
Jul 05 20:58:55 ideapad kernel: [<ffffffff81361e06>] acpi_ex_store+0xd0/0x261
Jul 05 20:58:55 ideapad kernel: [<ffffffff8135f28d>] acpi_ex_opcode_1A_1T_1R+0x3ef/0x528
Jul 05 20:58:55 ideapad kernel: [<ffffffff81361905>] ? acpi_ex_resolve_operands+0x212/0x4ed
Jul 05 20:58:55 ideapad kernel: [<ffffffff81356f1a>] acpi_ds_exec_end_op+0xd0/0x3ef
Jul 05 20:58:55 ideapad kernel: [<ffffffff813698e4>] acpi_ps_parse_loop+0x532/0x598
Jul 05 20:58:55 ideapad kernel: [<ffffffff81371e1b>] ? acpi_ut_create_generic_state+0x37/0x42
Jul 05 20:58:55 ideapad kernel: [<ffffffff8136a3e7>] acpi_ps_parse_aml+0x99/0x271
Jul 05 20:58:55 ideapad kernel: [<ffffffff8136ac3e>] acpi_ps_execute_method+0x1c0/0x264
Jul 05 20:58:55 ideapad kernel: [<ffffffff813652a1>] acpi_ns_evaluate+0x1c3/0x24f
Jul 05 20:58:55 ideapad kernel: [<ffffffff81367d37>] acpi_evaluate_object+0x196/0x2a6
Jul 05 20:58:55 ideapad kernel: [<ffffffff810145a8>] ? __switch_to+0xe8/0x610
Jul 05 20:58:55 ideapad kernel: [<ffffffff8134c12c>] acpi_ec_run+0x5a/0x88
Jul 05 20:58:55 ideapad kernel: [<ffffffff81342f19>] acpi_os_execute_deferred+0x15/0x22
Jul 05 20:58:55 ideapad kernel: [<ffffffff8108dadb>] process_one_work+0x14b/0x470
Jul 05 20:58:55 ideapad kernel: [<ffffffff8108e228>] worker_thread+0x48/0x4b0
Jul 05 20:58:55 ideapad kernel: [<ffffffff8108e1e0>] ? init_pwq.part.7+0x10/0x10
Jul 05 20:58:55 ideapad kernel: [<ffffffff8108e1e0>] ? init_pwq.part.7+0x10/0x10
Jul 05 20:58:55 ideapad kernel: [<ffffffff810934b8>] kthread+0xd8/0xf0
Jul 05 20:58:55 ideapad kernel: [<ffffffff810933e0>] ? kthread_worker_fn+0x170/0x170
Jul 05 20:58:55 ideapad kernel: [<ffffffff8157a718>] ret_from_fork+0x58/0x90
Jul 05 20:58:55 ideapad kernel: [<ffffffff810933e0>] ? kthread_worker_fn+0x170/0x170
And one example message where it blocked at shutdown:
Code:
Jul 05 21:00:16 ideapad systemd[1]: Stopping Local File Systems.
Jul 05 21:00:16 ideapad systemd[1]: Unmounting /run/user/1000...
Jul 05 21:00:16 ideapad systemd[1]: Unmounting /srv/edr-data...
Jul 05 21:00:16 ideapad umount[997]: umount: /srv/edr-data: target is busy
Jul 05 21:00:16 ideapad umount[997]: (In some cases useful info about processes that
Jul 05 21:00:16 ideapad umount[997]: use the device is found by lsof(8) or fuser(1).)
Jul 05 21:00:16 ideapad systemd[1]: Unmounting Temporary Directory...
Jul 05 21:00:16 ideapad umount[998]: umount: /tmp: target is busy
Jul 05 21:00:16 ideapad umount[998]: (In some cases useful info about processes that
Jul 05 21:00:16 ideapad umount[998]: use the device is found by lsof(8) or fuser(1).)
Jul 05 21:00:16 ideapad systemd[1]: srv-edr\x2ddata.mount: Mount process exited, code=exited status=32
Jul 05 21:00:16 ideapad systemd[1]: Failed unmounting /srv/edr-data.
Jul 05 21:00:16 ideapad systemd[1]: tmp.mount: Mount process exited, code=exited status=32
Jul 05 21:00:16 ideapad systemd[1]: Failed unmounting Temporary Directory.
Jul 05 21:00:16 ideapad systemd[1]: Unmounted /run/user/1000.
Jul 05 21:00:16 ideapad systemd[1]: Reached target Unmount All Filesystems.
Jul 05 21:00:16 ideapad systemd[1]: Starting Unmount All Filesystems.
Jul 05 21:00:16 ideapad systemd[1]: Stopped target Local File Systems (Pre).
Jul 05 21:00:16 ideapad systemd[1]: Stopping Local File Systems (Pre).
Jul 05 21:00:16 ideapad systemd[1]: Stopped Create Static Device Nodes in /dev.
Jul 05 21:00:16 ideapad systemd[1]: Stopping Create Static Device Nodes in /dev...
Jul 05 21:00:16 ideapad systemd[1]: Stopped Remount Root and Kernel File Systems.
Jul 05 21:00:16 ideapad systemd[1]: Stopping Remount Root and Kernel File Systems...
Jul 05 21:00:16 ideapad systemd[1]: Reached target Shutdown.
Jul 05 21:00:16 ideapad systemd[1]: Starting Shutdown.
Jul 05 21:00:16 ideapad systemd[1]: Reached target Final Step.
Jul 05 21:00:16 ideapad systemd[1]: Starting Final Step.
Jul 05 21:00:16 ideapad systemd[1]: Starting Reboot...
Jul 05 21:00:16 ideapad systemd[1]: Shutting down.
Jul 05 21:00:16 ideapad systemd[1]: Hardware watchdog 'iTCO_wdt', version 0
Jul 05 21:00:16 ideapad systemd[1]: Set hardware watchdog to 10min.
Jul 05 21:00:16 ideapad kernel: watchdog watchdog0: watchdog did not stop!
Jul 05 21:00:17 ideapad systemd-shutdown[1]: Sending SIGTERM to remaining processes...
Jul 05 21:00:17 ideapad systemd-journal[256]: Journal stopped
I'd say this happens maybe in 1 out of 10 boots. The system layout is based on this full disk encryption guide in case that's relevant.
If I read the stack traces right, this has to do with acpi, right? How can I fix this?
|
|
|
07-06-2015, 06:35 AM
|
#2
|
Senior Member
Registered: Jan 2009
Location: RHELtopia....
Distribution: Solaris 11.2/Slackware/RHEL/
Posts: 1,491
Rep:
|
Um... you could try turning off ACPI in you bios or you could pass the kernel a
switch as a boot parameter.
Course, that might lock out your power management software and just end up causing you a different problem, however fortune favors the bold
|
|
1 members found this post helpful.
|
07-06-2015, 07:09 AM
|
#3
|
Senior Member
Registered: Jul 2012
Location: Aachen, Germany
Distribution: Void, Debian
Posts: 1,019
Original Poster
|
Quote:
Originally Posted by dijetlo
Um... you could try turning off ACPI in you bios or you could pass the kernel a
switch as a boot parameter.
Course, that might lock out your power management software and just end up causing you a different problem, however fortune favors the bold
|
Thanks for the suggestion. I refrained from doing so because I read that this might also turn off temperature control and thus lead to overheating. Not sure if I am bold enough for such a move :-)
|
|
|
07-06-2015, 03:35 PM
|
#4
|
Senior Member
Registered: Dec 2014
Location: London, England
Distribution: Debian stable (and OpenBSD-current)
Posts: 1,187
|
|
|
1 members found this post helpful.
|
07-06-2015, 04:46 PM
|
#5
|
Senior Member
Registered: Jul 2012
Location: Aachen, Germany
Distribution: Void, Debian
Posts: 1,019
Original Poster
|
Quote:
Originally Posted by Head_on_a_Stick
|
Thanks for the idea. One of the things I find most exciting about Arch is running a bleeding edge kernel. But I agree with you, this is worth trying to see if it makes the problem go away. I'll give this a shot and report back.
Meanwhile I am happy for any further input on how to debug this...
|
|
|
07-06-2015, 05:04 PM
|
#6
|
Senior Member
Registered: Jul 2012
Location: Aachen, Germany
Distribution: Void, Debian
Posts: 1,019
Original Poster
|
Quote:
Originally Posted by Head_on_a_Stick
|
Ok, I tried this, but it seems even worse. The boot freezed completely when trying to bring up udev. After 5 minutes without any output whatsoever I killed it by hard reset.
System back up and running with the standard kernel now. Crash message from the previous (failed) boot with the lts-kernel is this:
Code:
Jul 06 22:50:54 ideapad kernel: iwlwifi 0000:02:00.0: Detected Intel(R) Wireless N 7260, REV=0x144
Jul 06 22:50:54 ideapad kernel: iwlwifi 0000:02:00.0: L1 Disabled - LTR Enabled
Jul 06 22:50:54 ideapad kernel: iwlwifi 0000:02:00.0: L1 Disabled - LTR Enabled
Jul 06 22:50:54 ideapad systemd-udevd[282]: Process '/usr/lib/systemd/systemd-vconsole-setup' failed with exit code 1.
Jul 06 22:50:54 ideapad systemd-udevd[281]: Process '/sbin/modprobe -r psmouse' failed with exit code 1.
Jul 06 22:51:53 ideapad systemd-udevd[270]: seq 1376 '/devices/pci0000:00/0000:00:03.0' is taking a long time
Jul 06 22:51:53 ideapad systemd-udevd[270]: seq 1375 '/devices/pci0000:00/0000:00:02.0' is taking a long time
Jul 06 22:51:53 ideapad systemd-udevd[270]: seq 1394 '/devices/pci0000:00/0000:00:1b.0' is taking a long time
Jul 06 22:51:54 ideapad systemd-udevd[270]: seq 1616 '/devices/virtual/vtconsole/vtcon1' is taking a long time
Jul 06 22:53:53 ideapad systemd-udevd[270]: seq 1375 '/devices/pci0000:00/0000:00:02.0' killed
Jul 06 22:53:53 ideapad systemd-udevd[270]: seq 1376 '/devices/pci0000:00/0000:00:03.0' killed
Jul 06 22:53:53 ideapad systemd-udevd[270]: seq 1394 '/devices/pci0000:00/0000:00:1b.0' killed
Jul 06 22:53:53 ideapad systemd-udevd[270]: worker [274] terminated by signal 9 (Killed)
Jul 06 22:53:53 ideapad systemd-udevd[270]: worker [274] failed while handling '/devices/pci0000:00/0000:00:1b.0'
Jul 06 22:53:54 ideapad systemd-udevd[270]: seq 1616 '/devices/virtual/vtconsole/vtcon1' killed
Jul 06 22:53:54 ideapad systemd-udevd[270]: worker [286] terminated by signal 9 (Killed)
Jul 06 22:53:54 ideapad systemd-udevd[270]: worker [286] failed while handling '/devices/virtual/vtconsole/vtcon1'
|
|
|
08-26-2015, 05:04 PM
|
#7
|
Senior Member
Registered: Jul 2012
Location: Aachen, Germany
Distribution: Void, Debian
Posts: 1,019
Original Poster
|
After changing the init system, the initial ramdisk creation tool and even the distro (none of this helped) I now finally seem to have found a solution to this.
Sometimes in the dmesg.log the last line before hangs of approximately a minute would be
Code:
Switched to clocksource tsc
So I tried changing the clocksource to hpet using the following kernel parameter:
I have now booted about 10 times and no hangs... Will mark as solved.
|
|
|
All times are GMT -5. The time now is 11:17 PM.
|
LinuxQuestions.org is looking for people interested in writing
Editorials, Articles, Reviews, and more. If you'd like to contribute
content, let us know.
|
Latest Threads
LQ News
|
|