# How to use MCELOG?

## TomWouters

Hi all,

I've been getting Machine Check Exceptions on my fresh install of Gentoo 2008.0 on my fileserver (previously working fine on 2006.x). I've emerged mcelog but I can't seem to be able to use it. When I get the MCE I have no choice but to reboot and after reboot I try any of the following commands

```
mcelog

mcelog --k8

mcelog --k8 --ascii

mcelog --k8 /dev/mcelog

mcelog --ascii /dev/mcelog

mcelog --ascii > changelog.txt

```

It gives me nothing (or, when I use --ascii, it gives me usage info on the mcelog command).

Any idea how I can get it working? AMD Sempron64 2800+ CPU on Asus K8N4-E Deluxe motherboard with 5x 1TB SATAII.

Here's the MCE I'm getting:

```

HARDWARE ERROR

CPU 0: Machine Check Exception:       4 Bank 4: b200000000070f0f

TSC 184d3324ebb

This is not a software problem!

Run through mcelog --ascii to decode and contact your hardware vendor

Kernel panic - not syncing: Machine check

```

Greetz

Tom

EDIT: mcelog version 0.7 is installed...

----------

## poly_poly-man

I think you're supposed to keep mcelog running as a daemon so that you get the /dev/mcelog output when the MCE actually happens...

..not sure.

EDIT: BTW, this seems like it's most likely a ram issue - have you tried running memtest86 for a while on your box?

poly-p man

----------

## TomWouters

I've thought about that but you can't just add it through rc-update like samba or dns. I found on the web that you have to use CRON to make it work, but I don't know what that is, so I'll have a look at that tomorrow.

With regards to the RAM, I've replaced the 512MB DIMM with a brand new 1GB DIMM and I still get the errors, so I don't think it's the memory but I'll do a memtest tomorrow as well. I did have a broken memory DIMM a few months back after a power outage so it could be that somehow the motherboard was also damaged. I always get the error during disk operation (writing filesystem or copying data to the server). It worked without problems with the previous drives though (I went from 6*320GB to 5*1TB in RAID5).

Greetz

Tom

----------

## poly_poly-man

oof.. you said you're k8?

could be a problem with the processor - keep in mind all memory goes through the processor (I love the design  :Very Happy:  ).

Run a memtest, and that'll tell you if it's disk-related or not.

poly-p man

----------

## TomWouters

OK, I ran memtest for about 5 hours today and it passed 10 error-free runs, so I'm guessing the memory's not broken. 

I've looked on Google for some information on mcelog and cron, but I can't really figure it out. Do I have to write a script myself to let cron run mcelog, or can I just 'add it' to cron. Can anyone shed some light on that?

Thanks,

Tom

----------

## poly_poly-man

 *TomWouters wrote:*   

> OK, I ran memtest for about 5 hours today and it passed 10 error-free runs, so I'm guessing the memory's not broken. 
> 
> I've looked on Google for some information on mcelog and cron, but I can't really figure it out. Do I have to write a script myself to let cron run mcelog, or can I just 'add it' to cron. Can anyone shed some light on that?
> 
> Thanks,
> ...

 

looks like it would be pointless, in your case. Keep in mind that you need to know what happens *after* the kernel dies - nothing can happen then. Your system is in limbo.

Since the kernel panics like this, you will need to deduce the problem another way.

what kind of ide/sata/whatever card do you have?

poly-p man

----------

## TomWouters

The motherboard has 2 onboard controllers. 1 Nvidia SATA controller with 4 ports (3 used) and 1 Silicon Image SATA controller with 4 ports (2 used). Both SATA_NV and SATA_SIL are properly loaded at boot. 

I did notice that sometimes, when I try to open a file on the server, it hangs for about 10-15 seconds or longer (with the disks spinned up, not in standby). Last time this happens, I looked at top and it had 100% wa (waiting for I/O) during the 'hang'. Another thing I noticed is that sometimes, dmesg gives a bunch of ADMA errors on some of the Nvidia ATA connections, like this:

```

dmesg | grep ADMA

sata_nv 0000:00:07.0: Using ADMA mode

sata_nv 0000:00:08.0: Using ADMA mode

ata5: EH in ADMA mode, notifier 0x0 notifier_error 0x0 gen_ctl 0x1501000 status 0x400 next cpb count 0x9 next cpb idx 0x0

ata5: timeout waiting for ADMA IDLE, stat=0x400

ata5: timeout waiting for ADMA LEGACY, stat=0x400

ata5: EH in ADMA mode, notifier 0x0 notifier_error 0x0 gen_ctl 0x1501000 status 0x400 next cpb count 0xF next cpb idx 0x0

ata5: timeout waiting for ADMA IDLE, stat=0x400

ata5: timeout waiting for ADMA LEGACY, stat=0x400

ata8: EH in ADMA mode, notifier 0x0 notifier_error 0x0 gen_ctl 0x1501000 status 0x400 next cpb count 0xB next cpb idx 0x0

ata8: timeout waiting for ADMA IDLE, stat=0x400

ata8: timeout waiting for ADMA LEGACY, stat=0x400

ata8: EH in ADMA mode, notifier 0x0 notifier_error 0x0 gen_ctl 0x1501000 status 0x400 next cpb count 0xF next cpb idx 0x0

ata8: timeout waiting for ADMA IDLE, stat=0x400

ata8: timeout waiting for ADMA LEGACY, stat=0x400

dmesg | grep ata5

ata5: SATA max UDMA/133 cmd 0x9f0 ctl 0xbf0 bmdma 0xd800 irq 22

ata5: SATA link up 1.5 Gbps (SStatus 113 SControl 300)

ata5.00: ATA-7: SAMSUNG HD103UJ, 1AA01110, max UDMA7

ata5.00: 1953525168 sectors, multi 1: LBA48 NCQ (depth 31/32)

ata5.00: configured for UDMA/133

ata5: bounce limit 0xFFFFFFFFFFFFFFFF, segment boundary 0xFFFFFFFF, hw segs 61

ata5: EH in ADMA mode, notifier 0x0 notifier_error 0x0 gen_ctl 0x1501000 status                                                                                                                                                              0x400 next cpb count 0x9 next cpb idx 0x0

ata5: CPB 0: ctl_flags 0x1f, resp_flags 0x2

ata5: CPB 1: ctl_flags 0x1f, resp_flags 0x2

ata5: CPB 2: ctl_flags 0x1f, resp_flags 0x2

ata5: CPB 3: ctl_flags 0x1f, resp_flags 0x2

ata5: CPB 4: ctl_flags 0x1f, resp_flags 0x0

ata5: CPB 5: ctl_flags 0x1f, resp_flags 0x2

ata5: CPB 6: ctl_flags 0x1f, resp_flags 0x2

ata5: CPB 7: ctl_flags 0x1f, resp_flags 0x2

ata5: CPB 8: ctl_flags 0x1f, resp_flags 0x2

ata5: CPB 9: ctl_flags 0x1f, resp_flags 0x2

ata5: CPB 10: ctl_flags 0x1f, resp_flags 0x2

ata5: CPB 11: ctl_flags 0x1f, resp_flags 0x2

ata5: CPB 12: ctl_flags 0x1f, resp_flags 0x0

ata5: CPB 13: ctl_flags 0x1f, resp_flags 0x0

ata5: CPB 14: ctl_flags 0x1f, resp_flags 0x0

ata5: CPB 15: ctl_flags 0x1f, resp_flags 0x0

ata5: CPB 16: ctl_flags 0x1f, resp_flags 0x0

ata5: CPB 17: ctl_flags 0x1f, resp_flags 0x0

ata5: CPB 18: ctl_flags 0x1f, resp_flags 0x0

ata5: CPB 19: ctl_flags 0x1f, resp_flags 0x0

ata5: timeout waiting for ADMA IDLE, stat=0x400

ata5: timeout waiting for ADMA LEGACY, stat=0x400

ata5.00: exception Emask 0x0 SAct 0xfffff SErr 0x0 action 0x2 frozen

ata5.00: cmd 61/08:00:bf:28:f8/00:00:43:00:00/40 tag 0 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:08:c7:28:f8/00:00:43:00:00/40 tag 1 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:10:cf:28:f8/00:00:43:00:00/40 tag 2 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:18:df:28:f8/00:00:43:00:00/40 tag 3 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:20:e7:28:f8/00:00:43:00:00/40 tag 4 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:28:8f:28:f8/00:00:43:00:00/40 tag 5 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:30:97:28:f8/00:00:43:00:00/40 tag 6 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:38:9f:28:f8/00:00:43:00:00/40 tag 7 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:40:a7:28:f8/00:00:43:00:00/40 tag 8 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:48:af:28:f8/00:00:43:00:00/40 tag 9 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:50:b7:28:f8/00:00:43:00:00/40 tag 10 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:58:d7:28:f8/00:00:43:00:00/40 tag 11 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:60:ef:28:f8/00:00:43:00:00/40 tag 12 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:68:f7:28:f8/00:00:43:00:00/40 tag 13 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:70:ff:28:f8/00:00:43:00:00/40 tag 14 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:78:07:29:f8/00:00:43:00:00/40 tag 15 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 60/08:80:3f:2b:f8/00:00:43:00:00/40 tag 16 ncq 4096 in

ata5.00: status: { DRDY }

ata5.00: cmd 60/08:88:47:2b:f8/00:00:43:00:00/40 tag 17 ncq 4096 in

ata5.00: status: { DRDY }

ata5.00: cmd 60/08:90:4f:2b:f8/00:00:43:00:00/40 tag 18 ncq 4096 in

ata5.00: status: { DRDY }

ata5.00: cmd 60/08:98:57:2b:f8/00:00:43:00:00/40 tag 19 ncq 4096 in

ata5.00: status: { DRDY }

ata5: soft resetting link

ata5: SATA link up 1.5 Gbps (SStatus 113 SControl 300)

ata5.00: configured for UDMA/133

ata5: EH complete

ata5: EH in ADMA mode, notifier 0x0 notifier_error 0x0 gen_ctl 0x1501000 status                                                                                                                                                              0x400 next cpb count 0xF next cpb idx 0x0

ata5: CPB 0: ctl_flags 0x1f, resp_flags 0x2

ata5: CPB 1: ctl_flags 0x1f, resp_flags 0x2

ata5: CPB 2: ctl_flags 0x1f, resp_flags 0x2

ata5: CPB 3: ctl_flags 0x1f, resp_flags 0x2

ata5: CPB 4: ctl_flags 0x1f, resp_flags 0x2

ata5: CPB 5: ctl_flags 0x1f, resp_flags 0x0

ata5: CPB 6: ctl_flags 0x1f, resp_flags 0x0

ata5: CPB 7: ctl_flags 0x1f, resp_flags 0x0

ata5: CPB 8: ctl_flags 0x1f, resp_flags 0x0

ata5: CPB 9: ctl_flags 0x1f, resp_flags 0x0

ata5: CPB 10: ctl_flags 0x1f, resp_flags 0x0

ata5: CPB 11: ctl_flags 0x1f, resp_flags 0x0

ata5: CPB 12: ctl_flags 0x1f, resp_flags 0x0

ata5: CPB 13: ctl_flags 0x1f, resp_flags 0x0

ata5: CPB 14: ctl_flags 0x1f, resp_flags 0x0

ata5: CPB 15: ctl_flags 0x1f, resp_flags 0x0

ata5: CPB 16: ctl_flags 0x1f, resp_flags 0x0

ata5: CPB 17: ctl_flags 0x1f, resp_flags 0x0

ata5: CPB 18: ctl_flags 0x1f, resp_flags 0x0

ata5: CPB 19: ctl_flags 0x1f, resp_flags 0x0

ata5: timeout waiting for ADMA IDLE, stat=0x400

ata5: timeout waiting for ADMA LEGACY, stat=0x400

ata5.00: exception Emask 0x0 SAct 0xfffff SErr 0x0 action 0x2 frozen

ata5.00: cmd 61/08:00:ef:47:f9/00:00:43:00:00/40 tag 0 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:08:0f:48:f9/00:00:43:00:00/40 tag 1 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:10:ff:47:f9/00:00:43:00:00/40 tag 2 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:18:07:48:f9/00:00:43:00:00/40 tag 3 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:20:f7:47:f9/00:00:43:00:00/40 tag 4 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:28:17:48:f9/00:00:43:00:00/40 tag 5 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:30:1f:48:f9/00:00:43:00:00/40 tag 6 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:38:27:48:f9/00:00:43:00:00/40 tag 7 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:40:2f:48:f9/00:00:43:00:00/40 tag 8 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:48:37:48:f9/00:00:43:00:00/40 tag 9 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:50:3f:48:f9/00:00:43:00:00/40 tag 10 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:58:47:48:f9/00:00:43:00:00/40 tag 11 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:60:4f:48:f9/00:00:43:00:00/40 tag 12 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:68:57:48:f9/00:00:43:00:00/40 tag 13 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:70:5f:48:f9/00:00:43:00:00/40 tag 14 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 61/08:78:67:48:f9/00:00:43:00:00/40 tag 15 ncq 4096 out

ata5.00: status: { DRDY }

ata5.00: cmd 60/08:80:3f:49:f9/00:00:43:00:00/40 tag 16 ncq 4096 in

ata5.00: status: { DRDY }

ata5.00: cmd 60/08:88:47:49:f9/00:00:43:00:00/40 tag 17 ncq 4096 in

ata5.00: status: { DRDY }

ata5.00: cmd 60/08:90:4f:49:f9/00:00:43:00:00/40 tag 18 ncq 4096 in

ata5.00: status: { DRDY }

ata5.00: cmd 60/08:98:57:49:f9/00:00:43:00:00/40 tag 19 ncq 4096 in

ata5.00: status: { DRDY }

ata5: soft resetting link

ata5: SATA link up 1.5 Gbps (SStatus 113 SControl 300)

ata5.00: configured for UDMA/133

ata5: EH complete

```

It doesn't happen all the time and it's not always on the same ATA's, but never on the Silicon Image ATA's. Don't really know what it means, some google searches tell me this does happen on NForce chipsets (something to do with ADMA obviously) but doesn't really give much of an explanation or solution (other than disabling ADMA, which I don't know how to do).

Greetz

Tom

EDIT: I ran vmstat after seeing the 100% wa load, and this is what it showed[/code]:

```

vmstat

procs -----------memory---------- ---swap-- -----io---- -system-- ----cpu----

 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa

 2  0    180   9328   4960 971960    0    0   504    18 1279   86  0  1 96  3

```

----------

## TomWouters

Another interesting thing is the ouput of vmstat -d:

```
 vmstat -d

disk- ------------reads------------ ------------writes----------- -----IO------

       total merged sectors      ms  total merged sectors      ms    cur    sec

hda     1459  10128   67985    9908    717    438    9221    3916      0      8

hdc        0      0       0       0      0      0       0       0      0      0

sda    55122 2976312 24251498  432432  11502 129744 1131488  101012      0    235

sdb    54475 2976778 24250136  457072  11271 129792 1130048  115952      0    235

sdc   181174 2850484 24252576 1596764  37211 104258 1131680 4157240      0    377

sdd   176816 2855585 24259352 1551000  23627 117741 1131944 4052312      0    362

sde   177675 2854363 24256408 1359592  26130 115032 1130184 3204664      0    360

md0        0      0       0       0      0      0       0       0      0      0

md1     2693      0   21538       0 559051      0 4472408       0      0      0

```

It appears that there is a big difference in value for some of the parameters between the disks connected to the SATA_NV controller (sdc - sdd - sde) and those connected to the SATA_SIL (sda-sdb). The output suggests the 'nvidia disks' spend a lot more time reading, writing and waiting for input than the 'SIL disks'. I will check my kernel again to see I've loaded all the proper drivers for the Nvidia chipset, but maybe it does have something to do with the ADMA giving errors on these disks...

Tom

----------

