AVerTV Volar Black HD: i2c oops in warm state on mips

Hi,

I am trying to get AverMedia AVerTV Volar Black HD (A850) usb dvb-t tuner running on mips32 little endian platform (to stream dvb-t from home router on LAN). I've cross compiled v4l-dvb mercurial sources (revision 11448:d4274bbb8605) and when plugging the tuner stick, I get following kernel oops log on serial console:

dvb-usb: found a 'AverMedia AVerTV Volar Black HD (A850)' in cold state, will try to load a firmware
usb 1-1: firmware: requesting dvb-usb-af9015.fw
dvb-usb: downloading firmware from file 'dvb-usb-af9015.fw'
dvb-usb: found a 'AverMedia AVerTV Volar Black HD (A850)' in warm state.
dvb-usb: will use the device's hardware PID filter (table count: 32).
DVB: registering new adapter (AverMedia AVerTV Volar Black HD (A850))

CPU 0 Unable to handle kernel paging request at virtual address 00000000, epc == 803a4488, ra == c049a1c8
Oops[#1]:
Cpu 0

$ 0   : 00000000 10003c00 00000000 803a4468
$ 4   : 8f17c600 8f067b30 00000002 00000038
$ 8   : 00000001 8faf3e98 11da000d 09010002
$12   : 00000000 00000000 00000000 0000000a
$16   : 8f17c600 8f067b68 8faf3c00 8f067c04
$20   : 8f067b9c 00000100 8f067bf0 80104100
$24   : 00000000 2aba9fb0
$28   : 8f066000 8f067af0 802cbc48 c049a1c8
Hi    : 00000000
Lo    : 00000000
epc   : 803a4488 i2c_transfer+0x20/0x104
    Not tainted
ra    : c049a1c8 af9013_read_reg+0x78/0xc4 [af9013]
Status: 10003c03    KERNEL EXL IE
Cause : 00808008
BadVA : 00000000
PrId  : 03030200 (Au1550)
Modules linked in: af9013 dvb_usb_af9015(+) dvb_usb dvb_core firmware_class
i2c_au1550 au1550_spi
Process modprobe (pid: 2757, threadinfo=8f066000, task=8fade098, tls=2aad6470)
Stack : c049f5e0 80163090 805ba880 00000100 8f067bf0 0000d733 8f067b68 8faf3c00
        8f067c04 c049a1c8 80163bc0 8056a630 8f067b40 80163224 80569fc8 8f0033d7
        00000038 80140003 8f067b2c 00010038 c0420001 8f067b28 c049f5e0 00000004
        00000004 c049a524 c049d5a8 c049d5a8 00000000 803a6700 00000000 8f17c600
        c042a7a4 8f17c600 c042a7a4 c049c924 00000000 00000000 00000002 613a6c00
        ...
Call Trace:
[<803a4488>] i2c_transfer+0x20/0x104
[<c049a1c8>] af9013_read_reg+0x78/0xc4 [af9013]
[<c049a524>] af9013_read_reg_bits+0x2c/0x70 [af9013]
[<c049c924>] af9013_attach+0x98/0x65c [af9013]
[<c04257bc>] af9015_af9013_frontend_attach+0x214/0x67c [dvb_usb_af9015]
[<c03e2428>] dvb_usb_adapter_frontend_init+0x20/0x12c [dvb_usb]
[<c03e1ad8>] dvb_usb_device_init+0x374/0x6b0 [dvb_usb]
[<c0426120>] af9015_usb_probe+0x4fc/0xfcc [dvb_usb_af9015]
[<80381024>] usb_probe_interface+0xbc/0x218
[<803227fc>] driver_probe_device+0x12c/0x30c
[<80322a80>] __driver_attach+0xa4/0xac
[<80321ed0>] bus_for_each_dev+0x60/0xd0
[<8032162c>] bus_add_driver+0x1e8/0x2a8
[<80322cdc>] driver_register+0x7c/0x17c
[<80380d30>] usb_register_driver+0xa0/0x12c
[<c042e030>] af9015_usb_module_init+0x30/0x6c [dvb_usb_af9015]
[<8010d2a4>] __kprobes_text_end+0x3c/0x1f4
[<80167150>] sys_init_module+0xb8/0x1cc
[<80102370>] stack_done+0x20/0x3c

Code: afb10018  7000003f  00808021 <8c430000> 7000003f  1060002d  00c09021

8f830014 3c02efff

The used dvb-t sources work ok on intel x86 platform (used kernel 2.6.24), but on mips, there seems to be some problem with i2c after switch of the tuner into the warm state via firmware load (tested with 2.6.25.17 and 2.6.29-rc7 mips kernels, with the same result) - it seems to me, that adap pointer (or the structure) is not valid (adap->algo is NULL):

(gdb) c
Continuing.

Breakpoint 1, i2c_transfer (adap=0x8f17c600, msgs=0x8f067b30, num=2)

    at /usr/src/linux/drivers/i2c/i2c-core.c:1036

1036 if (adap->algo->master_xfer) {
(gdb) p *msgs
$4 = {addr = 56, flags = 0, len = 3, buf = 0x8f0c9b2c "×3"}
(gdb) p *adap
$2 = {owner = 0x0, id = 0, class = 0, algo = 0x0, algo_data = 0x0, client_register = 0, client_unregister = 0, level = 0 '\0',
bus_lock = {count = {counter = 0}, wait_lock = {raw_lock = {<No data
fields>}}, wait_list = {next = 0xc042a00c, prev = 0x8fb55000}},
clist_lock = {count = {counter = 1}, wait_lock = {raw_lock = {<No data
fields>}}, wait_list = {next = 0x1, prev = 0x1}},
timeout = -1894267336, retries = -1894267336, dev = {klist_children = {k_lock
= {raw_lock = {<No data fields>}}, k_list = {next = 0x1,

        prev = 0x8f17c644}, get = 0x8f17c644, put = 0}, knode_parent = {n_klist
= 0x0, n_node = {next = 0x0, prev = 0x4}, n_ref = {
        refcount = {counter = -1069368724}}}, knode_driver = {n_klist = 0x0,
n_node = {next = 0x0, prev = 0x0}, n_ref = {refcount = {
          counter = 0}}}, knode_bus = {n_klist = 0x1, n_node = {next =
0x8f17c674, prev = 0x8f17c674}, n_ref = {refcount = {
          counter = 1}}}, parent = 0x8f17c680, kobj = {name = 0x8f17c680
"\200Ć\027\217\200Ć\027\217", entry = {next = 0x0, prev = 0x0},
      parent = 0x8fb3f494, kset = 0x8fb3f494, ktype = 0x8031f5b0, sd =
0x8031e8e8, kref = {refcount = {counter = -1883942816}},
      state_initialized = 0, state_in_sysfs = 0, state_add_uevent_sent = 1,
state_remove_uevent_sent = 0},
    bus_id = "\034Đ\004\217\001", '\0' <repeats 14 times>, uevent_suppress = 0,
init_name = 0x0, type = 0x0, sem = {lock = {
        raw_lock = {<No data fields>}}, count = 0, wait_list = {next = 0x0,
prev = 0x8fb55060}}, bus = 0x8f049780, driver = 0x8fb3f4c8,
    driver_data = 0x8f04d050, platform_data = 0x8f9b0988, power = {power_state
= {event = -1887399424}, can_wakeup = 0,
      should_wakeup = 0, status = 2401748540, entry = {next = 0x4, prev =
0x7}}, dma_mask = 0x2d633269, coherent_dma_mask = 0,
    dma_parms = 0x0, dma_pools = {next = 0x0, prev = 0x0}, dma_mem = 0x0,
archdata = {<No data fields>}, devt = 1, devres_lock = {
      raw_lock = {<No data fields>}}, devres_head = {next = 0x8f17c71c, prev =
0x8f17c71c}, knode_class = {n_klist = 0x0, n_node = {
        next = 0x0, prev = 0x8f17c000}, n_ref = {refcount = {counter = 0}}},

class = 0x0, groups = 0x0, release = 0x1},
nr = -1884031696, clients = {next = 0x8f04d0b8, prev = 0x0},
name = '\0' <repeats 16 times>,
"\\Ç\027\217\\Ç\027\217\000\000\000\000\000\000\000\000lÇ\027\217lÇ\027\217°\t\233\217(Ů\004\217",
dev_released = {done = 2399300920, wait = {lock = {raw_lock = {<No data
fields>}}, task_list = {next = 0x1, prev = 0x8058370c}}}}

Tried two mips32 little endian platforms: Broadcom BCM3302 /asus wl500gp router/ and alchemy au1550 with the same result.

Any ideas why this happens?

Thanks and best regards,
Jan

Hi Jan,

At some point in time, someone said, that using stack-allocated buffers for USB transfers is not cross-platform-save. IIRC, it was on MIPS-platforms where this became obvious.

I haven't looked into the af-driver, but I guess that's the problem here.

regards,
Patrick.

--
Mail: [email protected]
WWW: http://www.wi-bw.tfh-wildau.de/~pboettch/

Terve Jan,

[..]

[..]

Looks like it fails when demodulator is attached - af9013_attach(). Unfortunately I am not familiar those Oops dumps or debugs :( And I don't have such hw to reproduce the problem. Is that possible that you can try to examine more and even fix problem?

Lets try first comment out all i2 read / write operations (reg_read, reg_write) from af9013_attach. Then test if any operation can be done without crash. All register operations from af9013 goes to the af9015_i2c_xfer() function. You can try to catch error from there also. I hope this helps you. Good luck! :)

regards
Antti

http://palosaari.fi/

Solved with "[PATCH] af9015: fix stack corruption bug".

Best regards,
Jan

Jan, Thank you very much.

I reviewed your patch and seems to be correct.

This error leads to the zl10353.c and there it was copied to qt1010.c and af9015.c.

Probably you want also fix those and pick up credits :)

regards
Antti

http://palosaari.fi/

This patch fixes stack corruption bug present in dump_regs function of zl10353 and qt1010 drivers:
the buffer buf is one byte smaller than required - there is 4 chars
for address prefix, 16*3 chars for dump of 16 eeprom bytes per line
and 1 byte for zero ending the string required, i.e. 53 bytes, but
only 52 were provided.
The one byte missing in stack based buffer buf can cause stack corruption possibly leading to kernel oops, as discovered originally with af9015 driver.

---

Antti, thanks for pointing out that the same problem was also in zl10353.c and qt1010.c. Include your Sign-off-by, please.

Best regards,
Jan

 linux/drivers/media/common/tuners/qt1010.c  |    2 +-
 linux/drivers/media/dvb/frontends/zl10353.c |    2 +-
 2 files changed, 2 insertions(+), 2 deletions(-)

diff -r cff06234b725 linux/drivers/media/common/tuners/qt1010.c
@@ -65,7 +65,7 @@
 /* dump all registers */
 static void qt1010_dump_regs(struct qt1010_priv *priv)
 {
-	char buf[52], buf2[4];
+	char buf[4+3*16+1], buf2[4];
 	u8 reg, val;
 
 	for (reg = 0; ; reg++) {

diff -r cff06234b725 linux/drivers/media/dvb/frontends/zl10353.c
@@ -102,7 +102,7 @@
 static void zl10353_dump_regs(struct dvb_frontend *fe)
 {
 	struct zl10353_state *state = fe->demodulator_priv;
-	char buf[52], buf2[4];
+	char buf[4+3*16+1], buf2[4];
 	int ret;
 	u8 reg;
 

Hei Jan,

I tried to test that patch (from patchwork) to ensure it is OK before ack, but I found it does not apply for reason or other. It looks correct for my eyes. Please check what's wrong and apply new patch.

[crope@localhost v4l-dvb]$ patch -p1 < af9015-fix-stack-corruption-bug.patch patching file linux/drivers/media/dvb/dvb-usb/af9015.c
[crope@localhost v4l-dvb]$ patch -p1 < zl10353-and-qt1010-fix-stack-corruption-bug.patch patching file linux/drivers/media/common/tuners/qt1010.c
Hunk #1 FAILED at 65.
1 out of 1 hunk FAILED -- saving rejects to file linux/drivers/media/common/tuners/qt1010.c.rej patching file linux/drivers/media/dvb/frontends/zl10353.c
Hunk #1 FAILED at 102.
1 out of 1 hunk FAILED -- saving rejects to file linux/drivers/media/dvb/frontends/zl10353.c.rej [crope@localhost v4l-dvb]$ hg diff

diff -r 148b4c93a728 linux/drivers/media/dvb/dvb-usb/af9015.c
@@ -541,7 +541,7 @@
 /* dump eeprom */
 static int af9015_eeprom_dump(struct dvb_usb_device *d)
 {
-	char buf[52], buf2[4];
+	char buf[4+3*16+1], buf2[4];
 	u8 reg, val;
 
 	for (reg = 0; ; reg++) {

[crope@localhost v4l-dvb]$ hg head

changeset:   11978:148b4c93a728
tag:         tip
parent:      11975:144d8d0cebc5
parent:      11977:8b416ba3ac89
user:        Mauro Carvalho Chehab <[email protected]>
date:        Mon Jun 15 14:15:33 2009 -0300
summary:     merge: http://www.linuxtv.org/hg/~dougsland/em28xx

regards
Antti

http://palosaari.fi/

Em Wed, 10 Jun 2009 08:21:20 +0200
Jan Nikitenko <[email protected]> escreveu:

Cheers,
Mauro

right.

agreed.

I am not sure if that's possible - the buffer is used for sprintf in a loop to store text representation of registers dump, before printk-ing it.

We could put there a comment, suggesting that 4 bytes are required for address prefix of form "00: ", then 16 strings of form "00 " (3 bytes each) and one byte for zero to terminate the string.

Or we could use sizeof, like this:
char buf[sizeof("00: ") - 1 + 16 * (sizeof("00 ") - 1) + 1]
or
char buf[sizeof("00: 00 01 02 03 04 05 06 07 08 09 0a 0b 0c 0d 0e 0f ")]
but it is not very readable in my opinion either.

Maybe the best way would be to avoid the need for temporal buffer completely by directly using printk in a loop, that is only the first printk with KERN_DEBUG, followed by sequence of printk with registers dump and final printk with end of line (but isn't a printk without KERN_ facility coding style problem as well?).

I am not sure, what approach is the best - I just wanted to fix a bug, which did not allow to use my af9015 based tuner on mips platform. After that, Antti pointed out, that the same code with the same bug is also in other two sources, so I send the same fix for them as well...

Best regards,
Jan

Exactly for this case, line continuation, there is KERN_CONT defined.

Regards
Matthias

Em Wed, 17 Jun 2009 14:26:28 +0200
Matthias Schwarzott <[email protected]> escreveu:

There are some functions meant for printing hex dumps at kernel.h:

extern void hex_dump_to_buffer(const void *buf, size_t len,
int rowsize, int groupsize,
char *linebuf, size_t linebuflen, bool ascii);
extern void print_hex_dump(const char *level, const char *prefix_str,
int prefix_type, int rowsize, int groupsize, const void *buf, size_t len, bool ascii);
extern void print_hex_dump_bytes(const char *prefix_str, int prefix_type,

                        const void *buf, size_t len);

Also, it is possible to use kasprintf() to dynamically allocate a temporary buffer. If you use it, you'll need to do a kfree after its usage.

Cheers,
Mauro

This patch fixes stack corruption bug present in dump_regs function of zl10353 and qt1010 drivers:
the buffer buf was one byte smaller than required - there are 4 chars for address prefix, 16 * 3 chars for dump of 16 eeprom bytes per line and 1 byte for zero ending the string required, i.e. 53 bytes, but only 52 were provided. The one byte missing in stack based buffer buf can cause stack corruption possibly leading to kernel oops, as discovered originally with af9015 driver (af9015: fix stack corruption bug).

This is second version of the patch for zl10353 and qt1010 that uses continual printk instead of stack based buffer with proper magic number size.

---

 linux/drivers/media/common/tuners/qt1010.c  |   12 +++++-------
 linux/drivers/media/dvb/frontends/zl10353.c |   12 +++++-------
 2 files changed, 10 insertions(+), 14 deletions(-)

diff -r 722c6faf3ab5 linux/drivers/media/common/tuners/qt1010.c
@@ -65,24 +65,22 @@
 /* dump all registers */
 static void qt1010_dump_regs(struct qt1010_priv *priv)
 {
-	char buf[52], buf2[4];
 	u8 reg, val;
 
 	for (reg = 0; ; reg++) {
 		if (reg % 16 == 0) {
 			if (reg)
-				printk("%s\n", buf);
-			sprintf(buf, "%02x: ", reg);
+				printk(KERN_CONT "\n");
+			printk(KERN_DEBUG "%02x:", reg);
 		}
 		if (qt1010_readreg(priv, reg, &val) == 0)
-			sprintf(buf2, "%02x ", val);
+			printk(KERN_CONT " %02x", val);
 		else
-			strcpy(buf2, "-- ");
-		strcat(buf, buf2);
+			printk(KERN_CONT " --");
 		if (reg == 0x2f)
 			break;
 	}
-	printk("%s\n", buf);
+	printk(KERN_CONT "\n");
 }
 
 static int qt1010_set_params(struct dvb_frontend *fe,

diff -r 722c6faf3ab5 linux/drivers/media/dvb/frontends/zl10353.c
@@ -102,7 +102,6 @@
 static void zl10353_dump_regs(struct dvb_frontend *fe)
 {
 	struct zl10353_state *state = fe->demodulator_priv;
-	char buf[52], buf2[4];
 	int ret;
 	u8 reg;
 

@@ -110,19 +109,18 @@
 	for (reg = 0; ; reg++) {
 		if (reg % 16 == 0) {
 			if (reg)
-				printk(KERN_DEBUG "%s\n", buf);
-			sprintf(buf, "%02x: ", reg);
+				printk(KERN_CONT "\n");
+			printk(KERN_DEBUG "%02x:", reg);
 		}
 		ret = zl10353_read_register(state, reg);
 		if (ret >= 0)
-			sprintf(buf2, "%02x ", (u8)ret);
+			printk(KERN_CONT " %02x", (u8)ret);
 		else
-			strcpy(buf2, "-- ");
-		strcat(buf, buf2);
+			printk(KERN_CONT " --");
 		if (reg == 0xff)
 			break;
 	}
-	printk(KERN_DEBUG "%s\n", buf);
+	printk(KERN_CONT "\n");
 }
 #endif