dpkg in uninterruptible sleep

[Florian Mayer]

Binary package hint: dpkg

dpkg got in a state of uninterruptible sleep when I tried to install `pv`. It is unkillable by any means I tried to (what is characteristic of processes in a state of uninterruptible sleep).

output from `ps aux` (shortened):

USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
root 8891 0.0 1.6 111880 98576 pts/4 Ds+ 17:16 0:01 /usr/bin/dpkg --status-fd 21 --unpack --auto-deconfigure /var/cache/apt/archives/pv_1.1.4-1_amd64.deb

[vak (khamenya)]

In my case the last message in console was "Unpacking some-package-name-was-here ..."

P.S. I can't restart my machine approximatelly next 5 hours (I have my reasons) and can't kill this uninterruptible process to find a work-around. Quite unpleasant :-/

[vak (khamenya)]

my ps aux string:

root 5337 0.0 0.7 73376 60272 ? Ds 10:50 0:00 /usr/bin/dpkg --status-fd 24 --unpack --auto-deconfigure /var/cache/apt/archives/x11proto-core-dev_7.0.16-1_all.deb /var/cache/apt/archives/libice-dev_2%3a1.0.6-1_amd64.deb /var/cache/apt/archives/libxau-dev_1%3a1.0.5-1_amd64.deb /var/cache/apt/archives/libxdmcp-dev_1%3a1.0.3-1_amd64.deb /var/cache/apt/archives/x11proto-input-dev_2.0-2_all.deb /var/cache/apt/archives/x11proto-kb-dev_1.0.4-1_all.deb /var/cache/apt/archives/xtrans-dev_1.2.5-1_all.deb /var/cache/apt/archives/libpthread-stubs0_0.3-2_amd64.deb /var/cache/apt/archives/libpthread-stubs0-dev_0.3-2_amd64.deb /var/cache/apt/archives/libxcb1-dev_1.5-2_amd64.deb /var/cache/apt/archives/libx11-dev_2%3a1.3.2-1ubuntu3_amd64.deb /var/cache/apt/archives/libgdbm-dev_1.8.3-9_amd64.deb /var/cache/apt/archives/libncursesw5-dev_5.7+20090803-2ubuntu3_amd64.deb /var/cache/apt/archives/libreadline5_5.2-7build1_amd64.deb /var/cache/apt/archives/libreadline5-dev_5.2-7build1_amd64.deb /var/cache/apt/archives/libsm-dev_2%3a1.1.1-1_amd64.deb /var/cache/apt/archives/libsqlite3-dev_3.6.22-1_amd64.deb /var/cache/apt/archives/libssl-dev_0.9.8k-7ubuntu8_amd64.deb /var/cache/apt/archives/libxt-dev_1%3a1.0.7-1_amd64.deb /var/cache/apt/archives/tcl_8.4.16-2_all.deb /var/cache/apt/archives/tcl8.4-dev_8.4.19-4_amd64.deb /var/cache/apt/archives/tcl-dev_8.4.16-2_all.deb /var/cache/apt/archives/tk_8.4.16-2_all.deb /var/cache/apt/archives/tk8.4-dev_8.4.19-4_amd64.deb /var/cache/apt/archives/tk-dev_8.4.16-2_all.deb

[Y. Leretaille (yleretaille)]

Same thing just happened to me.
Installed some pakages via apt-get in the console and it freezed while unpacking. I tried everything to kill it but its uninterruptible (even i was able to kill the parent process [gnome-terminal]). Gnome-System-Monitor says that the waiting channel is call_rwsem_down_read_failed.
ps:
UID PID PPID C STIME TTY TIME CMD
root 31738 1 0 02:19 ? 00:00:00 /usr/bin/dpkg --status-fd 35 --unpack --auto-deconfigure /var/cache/apt/archives/libpam0g-dev_1.1.1-2ubuntu5_amd64.deb

[Mihai Capotă (mihaic)]

Here's my ps output on Ubuntu 10.10 after killing the parent process:

mihai@dutier:~$ ps -eF | grep dpkg
root 17321 1 0 23092 79128 0 11:05 ? 00:00:00 /usr/bin/dpkg --status-fd 41 --unpack --auto-deconfigure /var/cache/apt/archives/tzdata-java_2010m-0ubuntu0.10.04_all.deb /var/cache/apt/archives/tzdata_2010m-0ubuntu0.10.04_all.deb

gnome-system-monitor says it's stuck in call_rwsem_down_read_failed.

[Mihai Capotă (mihaic)]

And some dmesg info:

[827521.940076] INFO: task dpkg:17321 blocked for more than 120 seconds.
[827521.940080] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[827521.940083] dpkg D 0000000000000000 0 17321 17127 0x00000000
[827521.940088] ffff8801db145e30 0000000000000086 0000000000015bc0 0000000000015bc0
[827521.940093] ffff88010002b1a0 ffff8801db145fd8 0000000000015bc0 ffff88010002ade0
[827521.940097] 0000000000015bc0 ffff8801db145fd8 0000000000015bc0 ffff88010002b1a0
[827521.940101] Call Trace:
[827521.940111] [<ffffffff81543435>] rwsem_down_failed_common+0x95/0x1f0
[827521.940115] [<ffffffff815435e6>] rwsem_down_read_failed+0x26/0x30
[827521.940119] [<ffffffff812bd024>] call_rwsem_down_read_failed+0x14/0x30
[827521.940123] [<ffffffff81542884>] ? down_read+0x24/0x30
[827521.940128] [<ffffffff8116a757>] sync_filesystems+0xb7/0x130
[827521.940131] [<ffffffff8116a827>] sys_sync+0x17/0x40
[827521.940135] [<ffffffff810121b2>] system_call_fastpath+0x16/0x1b

[Filiprino (filiprino)]

I have the very same bug.

root@kiwi64:~# ps aux | grep dpkg
root 6457 0.0 1.1 68628 47572 ? Ds 01:10 0:00 /usr/bin/dpkg --status-fd 46 --unpack --auto-deconfigure /var/cache/apt/archives/libgnomedesktop2.20-cil_2.26.0-3_all.deb /var/cache/apt/archives/libnotify0.4-cil_0.4.0~r3032-2ubuntu1_all.deb /var/cache/apt/archives/libwnck2.20-cil_2.26.0-3_amd64.deb /var/cache/apt/archives/gnome-do_0.8.3.1+dfsg-2ubuntu1_amd64.deb /var/cache/apt/archives/libgdata1.4-cil_1.4.0.2-3_all.deb /var/cache/apt/archives/gnome-do-plugins_0.8.2.1+dfsg-2ubuntu1_all.deb

dmesg output:

[86400.881321] INFO: task dpkg:6457 blocked for more than 120 seconds.
[86400.881325] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[86400.881328] dpkg D 00000001008308b2 0 6457 1 0x00000004
[86400.881333] ffff8801283dbdf0 0000000000000086 ffffffff00000000 0000000000015980
[86400.881338] ffff8801283dbfd8 0000000000015980 ffff8801283dbfd8 ffff8800062d44a0
[86400.881342] 0000000000015980 0000000000015980 ffff8801283dbfd8 0000000000015980
[86400.881346] Call Trace:
[86400.881353] [<ffffffff81588fbd>] rwsem_down_failed_common+0x9d/0x210
[86400.881358] [<ffffffff8117a660>] ? sync_one_sb+0x0/0x30
[86400.881362] [<ffffffff81589186>] rwsem_down_read_failed+0x26/0x30
[86400.881366] [<ffffffff812c2644>] call_rwsem_down_read_failed+0x14/0x30
[86400.881370] [<ffffffff815883e4>] ? down_read+0x24/0x30
[86400.881374] [<ffffffff81154f4b>] iterate_supers+0x7b/0xd0
[86400.881379] [<ffffffff8117a6bf>] sys_sync+0x2f/0x70
[86400.881384] [<ffffffff8100a0f2>] system_call_fastpath+0x16/0x1b
[86520.881163] INFO: task dpkg:6457 blocked for more than 120 seconds.
[86520.881167] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[86520.881169] dpkg D 00000001008308b2 0 6457 1 0x00000004
[86520.881174] ffff8801283dbdf0 0000000000000086 ffffffff00000000 0000000000015980
[86520.881187] ffff8801283dbfd8 0000000000015980 ffff8801283dbfd8 ffff8800062d44a0
[86520.881190] 0000000000015980 0000000000015980 ffff8801283dbfd8 0000000000015980
[86520.881193] Call Trace:
[86520.881199] [<ffffffff81588fbd>] rwsem_down_failed_common+0x9d/0x210
[86520.881203] [<ffffffff8117a660>] ? sync_one_sb+0x0/0x30
[86520.881205] [<ffffffff81589186>] rwsem_down_read_failed+0x26/0x30
[86520.881209] [<ffffffff812c2644>] call_rwsem_down_read_failed+0x14/0x30
[86520.881211] [<ffffffff815883e4>] ? down_read+0x24/0x30
[86520.881214] [<ffffffff81154f4b>] iterate_supers+0x7b/0xd0
[86520.881216] [<ffffffff8117a6bf>] sys_sync+0x2f/0x70
[86520.881219] [<ffffffff8100a0f2>] system_call_fastpath+0x16/0x1b
[86640.880317] INFO: task dpkg:6457 blocked for more than 120 seconds.
[86640.880320] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[86640.880323] dpkg D 00000001008308b2 0 6457 1 0x00000004
[86640.880327] ffff8801283dbdf0 0000000000000086 ffffffff00000000 0000000000015980
[86640.880332] ffff8801283dbfd8 0000000000015980 ffff8801283dbfd8 ffff8800062d44a0
[86640.880336] 0000000000015980 0000000000015980 ffff8801283dbfd8 0000000000015980
[86640.880340] Call Trace:
[86640.880347] ...

[Filiprino (filiprino)]

In a fresh session start there's no problem.

[Filiprino (filiprino)]

I'm experiencing this bug on the AMD64 Kernel. I have Ubuntu installed in a netbook with i386 kernel and I have not experienced it yet :S

Both Ubuntu's (AMD64 and i386 desktop) are Maverick Meerkat (10.10).

[Filiprino (filiprino)]

It's nice to have a bug tracking system, but it's better if bugs are solved. I'm still having this issue. Every time dkpg hangs I have to reboot the computer so I can continue installing and configuring packages.

[John Kounis (ubuntu-pilotgetaways)]

I have had the same bug. I did some troubleshooting and it only occurs when I am doing heavy disk activity (potentially on another volume). Whenever this occurs, if I try to issue a "sync" it also hangs for a very long time.

Maybe dpkg tries to sync the discs?

In any case, if I wait until the disk activity ends, and the system is idle, then I issue a sync, I have to wait a long time (sometimes 10 minutes) for the sync to complete. Once it's done, the dpkg gets unstuck and continues.

Of course, on a heavily-loaded system it's not an option to wait until the sync completes, so this bug needs to be fixed. It's very annoying.

BTW I tried the 2.6.37rc1 from kernel.org, and I had the same problem.

[John Kounis (ubuntu-pilotgetaways)]

As a workaround, I'll bet if you typed "sync" before you ran dpkg, and waited for it to complete, it would work. That works for me.

[Filiprino (filiprino)]

Thanks. I have to say I usually have bittorrent downloads running on
an USB hard disk. I'll try to sync filesystems before trying to update
or install packages.

[Filiprino (filiprino)]

I'm executing now a sync, but seems that it won't complete. Dmesg
reports the following messages:

[413401.080062] INFO: task sync:30871 blocked for more than 120 seconds.
[413401.080066] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[413401.080069] sync D 0000000102761f1d 0 30871 30852 0x00000000
[413401.080074] ffff88002ef3ddf0 0000000000000086 ffff880000000000
0000000000015980
[413401.080079] ffff88002ef3dfd8 0000000000015980 ffff88002ef3dfd8
ffff8801687b96e0
[413401.080083] 0000000000015980 0000000000015980 ffff88002ef3dfd8
0000000000015980
[413401.080087] Call Trace:
[413401.080094] [<ffffffff81588fbd>] rwsem_down_failed_common+0x9d/0x210
[413401.080099] [<ffffffff8117a660>] ? sync_one_sb+0x0/0x30
[413401.080102] [<ffffffff8117a660>] ? sync_one_sb+0x0/0x30
[413401.080106] [<ffffffff81589186>] rwsem_down_read_failed+0x26/0x30
[413401.080110] [<ffffffff812c2644>] call_rwsem_down_read_failed+0x14/0x30
[413401.080114] [<ffffffff815883e4>] ? down_read+0x24/0x30
[413401.080117] [<ffffffff81154f4b>] iterate_supers+0x7b/0xd0
[413401.080120] [<ffffffff8117a6bf>] sys_sync+0x2f/0x70
[413401.080125] [<ffffffff8100a0f2>] system_call_fastpath+0x16/0x1b
[413521.080063] INFO: task sync:30871 blocked for more than 120 seconds.
[413521.080066] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[413521.080069] sync D 0000000102761f1d 0 30871 30852 0x00000000
[413521.080074] ffff88002ef3ddf0 0000000000000086 ffff880000000000
0000000000015980
[413521.080078] ffff88002ef3dfd8 0000000000015980 ffff88002ef3dfd8
ffff8801687b96e0
[413521.080083] 0000000000015980 0000000000015980 ffff88002ef3dfd8
0000000000015980
[413521.080087] Call Trace:
[413521.080094] [<ffffffff81588fbd>] rwsem_down_failed_common+0x9d/0x210
[413521.080099] [<ffffffff8117a660>] ? sync_one_sb+0x0/0x30
[413521.080102] [<ffffffff8117a660>] ? sync_one_sb+0x0/0x30
[413521.080105] [<ffffffff81589186>] rwsem_down_read_failed+0x26/0x30
[413521.080110] [<ffffffff812c2644>] call_rwsem_down_read_failed+0x14/0x30
[413521.080113] [<ffffffff815883e4>] ? down_read+0x24/0x30
[413521.080117] [<ffffffff81154f4b>] iterate_supers+0x7b/0xd0
[413521.080120] [<ffffffff8117a6bf>] sys_sync+0x2f/0x70
[413521.080124] [<ffffffff8100a0f2>] system_call_fastpath+0x16/0x1b

[Francisco Villar (villarf)]

Also happened to me right now while copying large files from one USB-hd to another USB-hd.
It really seems to be related to heavy disk activity.

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.