Soft lockup, tdb lockup, etc @ Fedora6/IBM

Isabelle86 · 08-04-2008, 09:52 PM

So, apparently one of the linux box last night...

And I greeted with this message:

log, anyway:

Code:

Aug  4 15:20:40 mail kernel: BUG: unable to handle kernel NULL pointer dereference at virtual address 00000000
Aug  4 15:20:40 mail kernel:  printing eip:
Aug  4 15:20:40 mail kernel: c04e66d1
Aug  4 15:20:40 mail kernel: *pde = 3e1da067
Aug  4 15:20:40 mail kernel: Oops: 0000 [#1]
Aug  4 15:20:40 mail kernel: SMP 
Aug  4 15:20:40 mail kernel: last sysfs file: /devices/system/cpu/cpu0/cpufreq/scaling_setspeed
Aug  4 15:20:40 mail kernel: Modules linked in: autofs4 hidp rfcomm l2cap bluetooth sunrpc ipv6 acpi_cpufreq dm_multipath video sbs i2c_ec button battery asus_acpi ac parport_pc lp parport sg i2c_i801 pcspkr intel_rng i2c_core ide_cd bnx2 cdrom dm_snapshot dm_zero dm_mirror dm_mod ata_piix libata aacraid sd_mod scsi_mod ext3 jbd ehci_hcd ohci_hcd uhci_hcd
Aug  4 15:20:40 mail kernel: CPU:    0
Aug  4 15:20:40 mail kernel: EIP:    0060:[<c04e66d1>]    Not tainted VLI
Aug  4 15:20:40 mail kernel: EFLAGS: 00010246   (2.6.18-1.2798.fc6 #1) 
Aug  4 15:20:40 mail kernel: EIP is at rb_erase+0xf6/0x22f
Aug  4 15:20:40 mail kernel: eax: 00000001   ebx: 00000000   ecx: 00000000   edx: f37d7cc8
Aug  4 15:20:40 mail kernel: esi: f37d7cc8   edi: df2b8648   ebp: c080f8c0   esp: f7feff44
Aug  4 15:20:40 mail kernel: ds: 007b   es: 007b   ss: 0068
Aug  4 15:20:40 mail kernel: Process events/0 (pid: 14, ti=f7fef000 task=f7c09140 task.ti=f7fef000)
Aug  4 15:20:40 mail kernel: Stack: 00000001 df2b8640 df2b8648 f7d68440 00000282 c04bb38f c068b260 c068b264 
Aug  4 15:20:40 mail kernel:        c0433c30 00000246 f7d68440 f7d68460 c04bb348 00000000 f7d68460 f7d68440 
Aug  4 15:20:40 mail kernel:        f7d68458 00000000 c0434520 00000001 00000000 f7c0924c 00010000 00000000 
Aug  4 15:20:40 mail kernel: Call Trace:
Aug  4 15:20:41 mail kernel:  [<c04bb38f>] key_cleanup+0x47/0xd0
Aug  4 15:20:41 mail kernel:  [<c0433c30>] run_workqueue+0x83/0xc5
Aug  4 15:20:41 mail kernel:  [<c0434520>] worker_thread+0xd9/0x10d
Aug  4 15:20:41 mail kernel:  [<c04369f3>] kthread+0xc0/0xed
Aug  4 15:20:41 mail kernel:  [<c0404dab>] kernel_thread_helper+0x7/0x10
Aug  4 15:20:41 mail kernel: DWARF2 unwinder stuck at kernel_thread_helper+0x7/0x10
Aug  4 15:20:41 mail kernel: Leftover inexact backtrace:
Aug  4 15:20:41 mail kernel:  =======================
Aug  4 15:20:41 mail kernel: Code: 05 89 5a 08 eb 08 89 5a 04 eb 03 89 5d 00 83 3c 24 01 0f 85 46 01 00 00 e9 12 01 00 00 8b 4e 08 39 d9 0f 85 85 00 00 00 8b 4e 04 <8b> 01 a8 01 75 14 83 c8 01 89 ea 89 01 89 f0 83 26 fe e8 3c fd 
Aug  4 15:20:41 mail kernel: EIP: [<c04e66d1>] rb_erase+0xf6/0x22f SS:ESP 0068:f7feff44
Aug  4 15:20:50 mail kernel:  <3>BUG: soft lockup detected on CPU#0!
Aug  4 15:20:50 mail kernel:  [<c04051db>] dump_trace+0x69/0x1af
Aug  4 15:20:50 mail kernel:  [<c0405339>] show_trace_log_lvl+0x18/0x2c
Aug  4 15:20:50 mail kernel:  [<c04058ed>] show_trace+0xf/0x11
Aug  4 15:20:50 mail kernel:  [<c04059ea>] dump_stack+0x15/0x17
Aug  4 15:20:50 mail kernel:  [<c044d9b5>] softlockup_tick+0xad/0xc4
Aug  4 15:20:50 mail kernel:  [<c042e596>] update_process_times+0x39/0x5c
Aug  4 15:20:50 mail kernel:  [<c0418914>] smp_apic_timer_interrupt+0x5c/0x64
Aug  4 15:20:50 mail kernel:  [<c0404ad3>] apic_timer_interrupt+0x1f/0x24
Aug  4 15:20:50 mail kernel: DWARF2 unwinder stuck at apic_timer_interrupt+0x1f/0x24
Aug  4 15:20:50 mail kernel: Leftover inexact backtrace:
Aug  4 15:20:50 mail kernel:  [<c052007b>] acpi_platform_notify+0x1a/0x10e
Aug  4 15:20:50 mail kernel:  [<c04e9360>] _raw_spin_lock+0x70/0xdc
Aug  4 15:20:50 mail kernel:  [<c04bb0b7>] key_alloc+0x1d3/0x330
Aug  4 15:20:50 mail kernel:  [<c04bbebc>] keyring_alloc+0x30/0x6a
Aug  4 15:20:50 mail kernel:  [<c04bd55c>] alloc_uid_keyring+0x4c/0xb2
Aug  4 15:20:50 mail kernel:  [<c042ea11>] alloc_uid+0x95/0x13c
Aug  4 15:20:50 mail kernel:  [<c0431870>] set_user+0xb/0x8e
Aug  4 15:20:50 mail kernel:  [<c0433133>] sys_setresuid+0x111/0x1dd
Aug  4 15:20:50 mail kernel:  [<c0404013>] syscall_call+0x7/0xb
Aug  4 15:20:50 mail kernel:  =======================
Aug  4 15:20:55 mail kernel: BUG: soft lockup detected on CPU#1!
Aug  4 15:20:55 mail kernel:  [<c04051db>] dump_trace+0x69/0x1af
Aug  4 15:20:55 mail kernel:  [<c0405339>] show_trace_log_lvl+0x18/0x2c
Aug  4 15:20:55 mail kernel:  [<c04058ed>] show_trace+0xf/0x11
Aug  4 15:20:55 mail kernel:  [<c04059ea>] dump_stack+0x15/0x17
Aug  4 15:20:55 mail kernel:  [<c044d9b5>] softlockup_tick+0xad/0xc4
Aug  4 15:20:55 mail kernel:  [<c042e596>] update_process_times+0x39/0x5c
Aug  4 15:20:55 mail kernel:  [<c0418914>] smp_apic_timer_interrupt+0x5c/0x64
Aug  4 15:20:55 mail kernel:  [<c0404ad3>] apic_timer_interrupt+0x1f/0x24
Aug  4 15:20:55 mail kernel: DWARF2 unwinder stuck at apic_timer_interrupt+0x1f/0x24
Aug  4 15:20:55 mail kernel: Leftover inexact backtrace:
Aug  4 15:20:55 mail kernel:  [<c052007b>] acpi_platform_notify+0x1a/0x10e
Aug  4 15:20:55 mail kernel:  [<c04e935f>] _raw_spin_lock+0x6f/0xdc
Aug  4 15:20:56 mail kernel:  [<c04bb0b7>] key_alloc+0x1d3/0x330
Aug  4 15:20:56 mail kernel:  [<c04bbebc>] keyring_alloc+0x30/0x6a
Aug  4 15:20:56 mail kernel:  [<c04bd55c>] alloc_uid_keyring+0x4c/0xb2
Aug  4 15:20:56 mail kernel:  [<c042ea11>] alloc_uid+0x95/0x13c
Aug  4 15:20:56 mail kernel:  [<c0431870>] set_user+0xb/0x8e
Aug  4 15:20:56 mail kernel:  [<c0433133>] sys_setresuid+0x111/0x1dd
Aug  4 15:20:56 mail kernel:  [<c0404013>] syscall_call+0x7/0xb
Aug  4 15:20:56 mail kernel:  =======================
Aug  4 15:21:02 mail kernel: BUG: soft lockup detected on CPU#3!
Aug  4 15:21:02 mail kernel:  [<c04051db>] dump_trace+0x69/0x1af
Aug  4 15:21:02 mail kernel:  [<c0405339>] show_trace_log_lvl+0x18/0x2c
Aug  4 15:21:02 mail kernel:  [<c04058ed>] show_trace+0xf/0x11
Aug  4 15:21:02 mail kernel:  [<c04059ea>] dump_stack+0x15/0x17
Aug  4 15:21:02 mail kernel:  [<c044d9b5>] softlockup_tick+0xad/0xc4
Aug  4 15:21:02 mail kernel:  [<c042e596>] update_process_times+0x39/0x5c
Aug  4 15:21:02 mail kernel:  [<c0418914>] smp_apic_timer_interrupt+0x5c/0x64
Aug  4 15:21:02 mail kernel:  [<c0404ad3>] apic_timer_interrupt+0x1f/0x24
Aug  4 15:21:02 mail kernel: DWARF2 unwinder stuck at apic_timer_interrupt+0x1f/0x24
Aug  4 15:21:02 mail kernel: Leftover inexact backtrace:
Aug  4 15:21:02 mail kernel:  [<c052007b>] acpi_platform_notify+0x1a/0x10e
Aug  4 15:21:02 mail kernel:  [<c04e935f>] _raw_spin_lock+0x6f/0xdc
Aug  4 15:21:02 mail kernel:  [<c04bb0b7>] key_alloc+0x1d3/0x330
Aug  4 15:21:02 mail kernel:  [<c04bbebc>] keyring_alloc+0x30/0x6a
Aug  4 15:21:02 mail kernel:  [<c04bd55c>] alloc_uid_keyring+0x4c/0xb2
Aug  4 15:21:02 mail kernel:  [<c042ea11>] alloc_uid+0x95/0x13c
Aug  4 15:21:02 mail kernel:  [<c0431870>] set_user+0xb/0x8e
Aug  4 15:21:02 mail kernel:  [<c0433133>] sys_setresuid+0x111/0x1dd
Aug  4 15:21:02 mail kernel:  [<c0404013>] syscall_call+0x7/0xb
Aug  4 15:21:02 mail kernel:  =======================
Aug  4 18:27:12 mail syslogd 1.4.1: restart.
Aug  4 18:27:12 mail kernel: klogd 1.4.1, log source = /proc/kmsg started.
Aug  4 18:27:12 mail kernel: Linux version 2.6.18-1.2798.fc6 (brewbuilder@hs20-bc2-4.build.redhat.com) (gcc version 4.1.1 20061011 (Red Hat 4.1.1-30)) #1 SMP Mon Oct 16 14:37:32 EDT 2006
Aug  4 18:27:12 mail kernel: BIOS-provided physical RAM map:
Aug  4 18:27:12 mail kernel:  BIOS-e820: 0000000000000000 - 000000000009ac00 (usable)
Aug  4 18:27:12 mail kernel:  BIOS-e820: 000000000009ac00 - 00000000000a0000 (reserved)
Aug  4 18:27:12 mail kernel:  BIOS-e820: 00000000000e0000 - 0000000000100000 (reserved)
Aug  4 18:27:12 mail kernel:  BIOS-e820: 0000000000100000 - 000000003ffcb6c0 (usable)
Aug  4 18:27:12 mail kernel:  BIOS-e820: 000000003ffcb6c0 - 000000003ffceac0 (ACPI data)
Aug  4 18:27:12 mail kernel:  BIOS-e820: 000000003ffceac0 - 0000000040000000 (reserved)
Aug  4 18:27:12 mail kernel:  BIOS-e820: 00000000e0000000 - 00000000f0000000 (reserved)
Aug  4 18:27:12 mail kernel:  BIOS-e820: 00000000fec00000 - 0000000100000000 (reserved)

I tried to reproduce the error again, but I can't.

Another thing is samba issue:

Certain part of the log

Code:

Aug  4 08:38:18 mail smbd[4061]: [2008/08/04 08:38:18, 0] tdb/tdbutil.c:tdb_log(783) 
Aug  4 08:38:18 mail smbd[4061]:   tdb(/var/cache/samba/locking.tdb): rec_read bad magic 0x1eb4000 at offset=50084 
Aug  4 08:38:19 mail smbd[4061]: [2008/08/04 08:38:19, 0] tdb/tdbutil.c:tdb_log(783) 
Aug  4 08:38:19 mail smbd[4061]:   tdb(/var/cache/samba/locking.tdb): rec_read bad magic 0x65545f35 at offset=42628 
Aug  4 08:38:20 mail smbd[4061]: [2008/08/04 08:38:20, 0] tdb/tdbutil.c:tdb_log(783) 
Aug  4 08:38:20 mail smbd[4061]:   tdb(/var/cache/samba/locking.tdb): rec_read bad magic 0x1eb4000 at offset=50084 
Aug  4 08:38:21 mail smbd[4061]: [2008/08/04 08:38:21, 0] tdb/tdbutil.c:tdb_log(783) 
Aug  4 08:38:21 mail smbd[4061]:   tdb(/var/cache/samba/locking.tdb): rec_read bad magic 0x65545f35 at offset=42628 
Aug  4 08:38:23 mail smbd[4061]: [2008/08/04 08:38:23, 0] tdb/tdbutil.c:tdb_log(783) 
Aug  4 08:38:23 mail smbd[4061]:   tdb(/var/cache/samba/locking.tdb): rec_read bad magic 0x1eb4000 at offset=50084 
Aug  4 08:38:24 mail smbd[4061]: [2008/08/04 08:38:24, 0] tdb/tdbutil.c:tdb_log(783) 
Aug  4 08:38:24 mail smbd[4061]:   tdb(/var/cache/samba/locking.tdb): rec_read bad magic 0x65545f35 at offset=42628

It happens randomly, when it happens, ppl will not able to browse the server anymore.

I read it on some forums, it says the tdb file is corrupted.

And I'm curious what causing it to happens.

Oh, the system used:
Fedora Core 6 @
IBM X3650
IBM System x3650 - Specifications

Thanks!

hardcorelinux · 08-04-2008, 10:59 PM

This error indicated a corrupted tdb. Stop all instances of smbd, delete locking.tdb, and restart smbd. I am not sure how it is getting corrupted.

tdbbackup utility is a tool that may be used to backup samba tdb files. This tool may also be used to verify the integrity of the tdb files prior to Samba startup or during normal operation. If it finds file damage it will search for a prior backup the backup file from which the damaged tdb file will be restored. The tdbbackup utility can safely be run at any time. It was designed so that it can be used at any time to validate the integrity of tdb files, even during Samba operation.

backup all tdb files as part of the Samba start-up scripts on a Samba server. The following command syntax can be used:

# cd /var/lib/samba
# tdbbackup *.tdb

The default extension is .bak. Any alternate extension can be specified by executing tdbbackup -s 'new_extension' *.tdb as part of your startup script.

Refer man page for more about tdbbackup

http://manpages.unixforum.co.uk/man-...-man-page.html

Isabelle86 · 08-05-2008, 12:32 AM

Thanks for the reply, hardcorelinux.

I'll try out the tdbbackup utility in the server and tries to delete and run the smb service again. Do I need still to reconfigure the settings again? Especially permissions and accounts?

I'm completely confused since this problem occurred randomly, and totally not sure what causing it.

Thanks again!

Isabelle86 · 08-05-2008, 04:44 AM

Just some questions, if I deleted the corrupted tdb file, will samba auto generates the files again? As in previous post, do I need to reconfigure the settings, especially permissions and accounts?

Also anything on my first error log? I'm clueless on what actually happened.

Thanks again.

hardcorelinux · 08-05-2008, 06:47 AM

Samba daemon will simply regenerate new cache files if there are no existing ones when those services are started. However since there are a few side effects of deleting certain .tdb files in /var/cache/samba directory, it is often a good idea to back them up prior to deleting them in order to test whether new .tdb files solves the problem being investigated.

Isabelle86 · 08-05-2008, 08:58 PM

Sure do, and thanks, hardcorelinux!

Eribe · 11-16-2009, 02:16 PM

I've had the same problem in a installation with RHEL 5, kernel 2.6.18-8.el5, samba 3.0.28 and openldap-2.3.27-5

We have had random oops when heavy workloads occurs. In one of this lockups we saw in /var/log/messages logs like:

BUG: soft lockup detected on CPU#1!
[<c0140977>] softlockup_tick+0x9a/0xbc
[<c012575a>] update_process_times+0x56/0x79
[<c010f97e>] smp_apic_timer_interrupt+0x5c/0x62
[<c0104277>] apic_timer_interrupt+0x1f/0x24
[<c022122a>] _raw_spin_lock+0x59/0x7d
[<c01f579e>] key_alloc+0x192/0x34a
[<c01f63b8>] keyring_alloc+0x30/0x72
[<c01f7c48>] alloc_uid_keyring+0x48/0xab
[<c0150daf>] __handle_mm_fault+0x1d6/0x255
[<c0125eac>] alloc_uid+0xc6/0x150
[<c0129874>] set_user+0xb/0x90
[<c0129c65>] sys_setresuid+0x9e/0x1ed
[<c0103741>] sysenter_past_esp+0x56/0x79

After googling a lot we did find this:

http://lkml.indiana.edu/hypermail/li...02.1/0546.html