Hi all,
I just have rewritten the driver to do a constant polling. This imply that
the module work in interrupt context.
The driver works for a while but after some time ( 1 to 120 seconds
it
depends ), the driver produce a Oops.
But the oops dont give any error on the driver function but show a page
allocation problem in other part of the kernel
Here the oops is in
usbserial but yesterday before activation kernel debug, it was in the
raid_one module !
Here the code , I tried different spin_lock_irq but without any changes.
If I comment the bulk_write and just do a read polling, The polling is
stable ( but this is normal, because the module will never see any character
coming from the device because the device never receive any data
).
Here is the code that cause the problem: ( It is just a part of the code.
This is enough to see all things related to my problem - All spin_lock are
removed for the moment.. I know it is quite dangerous but the module call
all callback function in a kind of chain order. The oops follow the code )
Some explanations:
The code ( not shown here ) iuu_open do a rxcmd with a completion pointer
equal to iuu_uart_read_callback.
So the polling begin in this function. In the same time, iuu_uart_write is
called in a process context to just fill writebuf.
So we have:
1.From tty: character -> iuu_uart_write -> writebuf
2.Polling: iuu_uart_read_callback ->
if character in device buffer -> read_buf -> rxcmd
if no character in buf and reset is waiting -> iuu_reset ->
rxcmd
if no character in device and no reset is waiting -> rxcmd
rxcmd point at completion to iuu_uart_read_callback....
some question:
1.Is it right to allocate the memory like I do in the code ? ( iuu_alloc_buf
)
2.What I really must care in interrupt context ? I try to always avois any
function that is able to sleep but if you see one .. say me.
3.Sometimes, I have Fatal exception in interrupt...
--------------------------Code------------------------------
/* non interrupt context functions */
static int read_immediate(struct usb_serial_port *port, u8 *buf,
u8 count);
static int iuu_uart_baud(struct usb_serial_port *port, u_int32_t baud,
u_int32_t *actual, u_int8_t parity);
static int bulk_immediate(struct usb_serial_port *port, u8 *buf,
u8 count);
static int iuu_ioctl(struct usb_serial_port *port, struct file *file,
unsigned int cmd, unsigned long arg);
static int iuu_tiocmset(struct usb_serial_port *port, struct file *file,
unsigned int set, unsigned int clear);
static int iuu_tiocmget(struct usb_serial_port *port, struct file *file);
static int iuu_uart_write(struct usb_serial_port *port,
const u8 *buf, int count);
static int iuu_uart_on(struct usb_serial_port *port);
static int iuu_uart_off(struct usb_serial_port *port);
/* polled functions (interrupt context) */
static void iuu_uart_read_callback (struct urb *urb);
static int iuu_read_buf(struct usb_serial_port *port ,u8 len);
static void read_buf_callback (struct urb *urb);
static int iuu_bulk_write(struct usb_serial_port *port);
static void iuu_rxcmd (struct urb *urb);
static void read_rxcmd_callback (struct urb *urb);
static int iuu_status(struct usb_serial_port *port);
static void iuu_status_callback(struct urb *urb);
static void iuu_update_status_callback(struct urb *urb);
static int iuu_reset(struct usb_serial_port *port, u_int8_t wt);
/* structures definitions */
static struct usb_serial_driver iuu_device = {
.driver = {
.owner = THIS_MODULE,
.name = "IUU Phoenix",
},
.id_table = id_table,
.num_interrupt_in = NUM_DONT_CARE,
.num_bulk_in = 1,
.num_bulk_out = 1,
.num_ports = 1,
.open = iuu_open,
.close = iuu_close,
.write = iuu_uart_write,
.read_bulk_callback = iuu_uart_read_callback,
.ioctl = iuu_ioctl,
.tiocmget = iuu_tiocmget,
.tiocmset = iuu_tiocmset,
.attach = iuu_startup,
.shutdown = iuu_shutdown,
};
struct iuu_private {
spinlock_t lock; /* store irq state */
wait_queue_head_t delta_msr_wait;
u8 line_control;
u8 line_status;
u8 termios_initialized;
int TIOSTATUS; /* store IUART SIGNAL for tiocmget call */
u8 reset; /* if 1 reset is needed */
int poll; /* number of poll */
u8 *writebuf; /* buffer for writing to device */
int writelen; /* num of byte to write to device */
u8 *buf; /* used for initialize speed */
u8 *dbgbuf; /* debug buffer */
u8 len;
};
static int iuu_alloc_buf (struct usb_serial_port *port) {
struct iuu_private *priv = usb_get_serial_port_data(port);
priv->buf = kmalloc(256,GFP_KERNEL);
priv->dbgbuf = kmalloc(256,GFP_KERNEL);
priv->writebuf = kmalloc(256,GFP_KERNEL);
if ( !priv->buf || !priv->dbgbuf || !priv->writebuf )
return 1 ;
return 0;
}
static int iuu_free_buf (struct usb_serial_port *port) {
struct iuu_private *priv = usb_get_serial_port_data(port);
kfree(priv->buf);
kfree(priv->dbgbuf);
kfree(priv->writebuf);
return 0;
}
static int iuu_startup(struct usb_serial *serial)
{
struct iuu_private *priv;
priv = kmalloc(sizeof(struct iuu_private), GFP_KERNEL);
if (!priv)
return -ENOMEM;
memset(priv, 0x00, sizeof(struct iuu_private));
spin_lock_init(&priv->lock);
init_waitqueue_head(&priv->delta_msr_wait);
usb_set_serial_port_data(serial->port[0], priv);
if ( iuu_alloc_buf(serial->port[0]) )
dbg ("%s - error on kmalloc buffers",__FUNCTION__);
return 0;
}
static void iuu_uart_read_callback ( struct urb *urb) {
struct usb_serial_port *port = (struct usb_serial_port *)
urb->context;
struct iuu_private *priv = usb_get_serial_port_data(port);
int status;
int error = 0 ;
u8 *len ;
//priv->poll++ ;
dbg("%s - enter", __FUNCTION__ );
if (urb->status) {
dbg("%s - urb->status = %d", __FUNCTION__, urb->status);
/* error stop all */
return ;
}
len = urb->transfer_buffer;
if ( urb->actual_length > 1) {
dbg("%s - urb->actual_length =
%i",__FUNCTION__,urb->actual_length);
error = 1 ;
}
// if len > 0 call readbuf
if (len[0] > 0 && error == 0) {
dbg("%s - call read buf", __FUNCTION__ );
status = iuu_read_buf (port,len[0]);
return ;
}
/* need to update status ? */
if ( priv->poll > 999 ) {
//status = iuu_status(port);
//if (!status)
// priv->poll = 0 ;
//return ;
}
/* reset waiting ? */
if ( priv->reset == 1 ) {
status = iuu_reset(port,0xC);
return ;
}
/* Writebuf is waiting */
if ( priv->writelen > 0 ) {
status = iuu_bulk_write (port);
return ;
}
// if nothing to write call again rxcmd
dbg("%s - rxcmd recall", __FUNCTION__ );
iuu_rxcmd( urb );
return ;
}
static int iuu_read_buf ( struct usb_serial_port *port , u8 len ){
int result;
dbg("%s - enter", __FUNCTION__ );
usb_fill_bulk_urb (port->read_urb,
port->serial->dev,
usb_rcvbulkpipe (port->serial->dev,
port->bulk_in_endpointAddress),
port->read_urb->transfer_buffer, len,
read_buf_callback,
port);
result = usb_submit_urb(port->read_urb, GFP_ATOMIC);
return result ;
}
static void read_buf_callback ( struct urb *urb) {
struct usb_serial_port *port = (struct usb_serial_port *)
urb->context;
unsigned char *data = urb->transfer_buffer;
int i;
struct tty_struct *tty;
dbg("%s - urb->status = %d", __FUNCTION__, urb->status);
if (urb->status) {
dbg("%s - urb->status = %d", __FUNCTION__, urb->status);
if (urb->status == -EPROTO) {
/* reschedule needed */
}
return ;
}
dbg("%s - %i chars to write", __FUNCTION__, urb->actual_length);
tty = port->tty;
if (tty && urb->actual_length) {
tty_buffer_request_room(tty, urb->actual_length+1);
for (i = 0; i < urb->actual_length; ++i)
tty_insert_flip_char(tty, data[i], TTY_NORMAL);
tty_flip_buffer_push(tty);
}
iuu_rxcmd ( urb );
}
static int
iuu_uart_write(struct usb_serial_port *port, const u8 *buf,
int count)
{
struct iuu_private *priv = usb_get_serial_port_data(port);
unsigned int flags;
dbg("%s - enter", __FUNCTION__ );
/* buffer already filled but not commited */
if ( priv->writelen > 0 )
return (0);
/* fill the buffer */
spin_lock_irqsave(&priv->lock, flags);
memcpy(priv->writebuf,buf,count);
priv->writelen = count ;
spin_unlock_irqrestore(&priv->lock, flags);
return (count);
}
static int iuu_bulk_write(struct usb_serial_port *port) {
struct iuu_private *priv = usb_get_serial_port_data(port);
unsigned long flags;
int result ;
dbg("%s - enter", __FUNCTION__ );
memset(port->write_urb->transfer_buffer,IUU_UART_ESC,1);
memset(port->write_urb->transfer_buffer+1,IUU_UART_TX,1);
memset(port->write_urb->transfer_buffer+2,priv->writelen,1);
memcpy (port->write_urb->transfer_buffer+3,priv->writebuf,
priv->writelen);
usb_fill_bulk_urb (port->write_urb, port->serial->dev,
usb_sndbulkpipe (port->serial->dev,
port->bulk_out_endpointAddress),
port->write_urb->transfer_buffer,priv->writelen+3,
iuu_rxcmd,
port);
result = usb_submit_urb(port->write_urb, GFP_ATOMIC);
if (result)
return 0;
priv->writelen = 0 ;
return result ;
}
static void iuu_rxcmd( struct urb *urb) {
struct usb_serial_port *port = (struct usb_serial_port *)
urb->context;
int result ;
dbg("%s - enter", __FUNCTION__ );
memset(port->write_urb->transfer_buffer,IUU_UART_RX,1);
usb_fill_bulk_urb (port->write_urb, port->serial->dev,
usb_sndbulkpipe (port->serial->dev,
port->bulk_out_endpointAddress),
port->write_urb->transfer_buffer, 1,
read_rxcmd_callback,
port);
result = usb_submit_urb(port->write_urb, GFP_ATOMIC);
}
static void read_rxcmd_callback ( struct urb *urb) {
struct usb_serial_port *port = (struct usb_serial_port *)
urb->context;
int result ;
dbg("%s - enter", __FUNCTION__ );
dbg("%s - urb->status = %d", __FUNCTION__, urb->status);
usb_fill_bulk_urb (port->read_urb, port->serial->dev,
usb_rcvbulkpipe (port->serial->dev,
port->bulk_in_endpointAddress),
port->read_urb->transfer_buffer, 256,
iuu_uart_read_callback,
port);
result = usb_submit_urb(port->read_urb, GFP_ATOMIC);
dbg("%s - submit result = %d", __FUNCTION__, result);
return ;
}
static int iuu_reset(struct usb_serial_port *port,u8 wt) {
struct iuu_private *priv = usb_get_serial_port_data(port);
int result ;
dbg("%s - enter", __FUNCTION__ );
/* Prepare the reset sequence */
memset(port->write_urb->transfer_buffer,IUU_RST_SET,1);
memset(port->write_urb->transfer_buffer+1,IUU_DELAY_MS,1);
memset(port->write_urb->transfer_buffer+2,wt,1);
memset(port->write_urb->transfer_buffer+3,IUU_RST_CLEAR,1);
/* send the sequence */
usb_fill_bulk_urb (port->write_urb,
port->serial->dev,
usb_sndbulkpipe (port->serial->dev,
port->bulk_out_endpointAddress),
port->write_urb->transfer_buffer,
4,
iuu_rxcmd,
port);
result = usb_submit_urb(port->write_urb, GFP_ATOMIC);
priv->reset = 0;
return result ;
}
static int
iuu_uart_write(struct usb_serial_port *port, const u8 *buf,
int count)
{
struct iuu_private *priv = usb_get_serial_port_data(port);
unsigned int flags;
dbg("%s - enter", __FUNCTION__ );
/* buffer already filled but not commited */
if ( priv->writelen > 0 )
return (0);
/* fill the buffer */
spin_lock_irqsave(&priv->lock, flags);
memcpy(priv->writebuf,buf,count);
priv->writelen = count ;
spin_unlock_irqrestore(&priv->lock, flags);
return (count);
}
------------------End of Code---------------------------
The Oops:
Jul 26 07:05:25 teo kernel: [ 330.075383]
iuutool-0.0.5/kern_module/iuu_phoenix-0.2/V2.6/iuu_phoenix.c:
read_buf_callback - urb->status = 0
Jul 26 07:05:25 teo kernel: [ 330.075387]
iuutool-0.0.5/kern_module/iuu_phoenix-0.2/V2.6/iuu_phoenix.c:
read_buf_callback - 1 chars to write
Jul 26 07:05:25 teo kernel: [ 330.075396]
iuutool-0.0.5/kern_module/iuu_phoenix-0.2/V2.6/iuu_phoenix.c: iuu_rxcmd -
enter
Jul 26 07:05:25 teo kernel: [ 330.075433]
iuutool-0.0.5/kern_module/iuu_phoenix-0.2/V2.6/iuu_phoenix.c: iuu_uart_write
- enter
Jul 26 07:05:25 teo kernel: [ 330.076332]
iuutool-0.0.5/kern_module/iuu_phoenix-0.2/V2.6/iuu_phoenix.c:
read_rxcmd_callback - enter
Jul 26 07:05:25 teo kernel: [ 330.076336]
iuutool-0.0.5/kern_module/iuu_phoenix-0.2/V2.6/iuu_phoenix.c:
read_rxcmd_callback - urb->status = 0
Jul 26 07:05:25 teo kernel: [ 330.076345]
iuutool-0.0.5/kern_module/iuu_phoenix-0.2/V2.6/iuu_phoenix.c:
read_rxcmd_callback - submit result = 0
Jul 26 07:05:25 teo kernel: [ 330.077331]
iuutool-0.0.5/kern_module/iuu_phoenix-0.2/V2.6/iuu_phoenix.c:
iuu_uart_read_callback - enter
Jul 26 07:05:25 teo kernel: [ 330.077335]
iuutool-0.0.5/kern_module/iuu_phoenix-0.2/V2.6/iuu_phoenix.c: iuu_bulk_write
- enter
Jul 26 07:05:36 teo kernel: [ 339.977148] BUG: unable to handle kernel
paging request at virtual address 6d41acec
Jul 26 07:05:36 teo kernel: [ 339.997006] printing eip:
Jul 26 07:05:36 teo kernel: [ 340.016554] defd7473
Jul 26 07:05:36 teo kernel: [ 340.035729] *pde = 00000000
Jul 26 07:05:36 teo kernel: [ 340.054642] Oops: 0000 [#1]
Jul 26 07:05:36 teo kernel: [ 340.073199] SMP DEBUG_PAGEALLOC
Jul 26 07:05:36 teo kernel: [ 340.091718] Modules linked in: iuu_phoenix
ppdev lp yenta_socket rsrc_nonstatic pcmcia_core bridge ipv6 dm_snapshot
dm_mirr
or dm_mod 8139too tsdev psmouse rtc parport_pc parport floppy serio_raw
pcspkr i2c_i801 usbserial i2c_core usblp shpchp pci_hotplug intel_agp
agpgart st e
vdev ext3 jbd mbcache raid1 md_mod ide_generic ide_cd cdrom ide_disk piix
b44 mii generic aic7xxx scsi_transport_spi uhci_hcd thermal processor fan
ehci_h
cd usb_storage ide_core sd_mod scsi_mod usbcore
Jul 26 07:05:36 teo kernel: [ 340.179144] CPU: 0
Jul 26 07:05:36 teo kernel: [ 340.179145] EIP: 0060:[<defd7473>] Not
tainted VLI
Jul 26 07:05:36 teo kernel: [ 340.179147] EFLAGS: 00010202 (2.6.21 #2)
Jul 26 07:05:36 teo kernel: [ 340.248489] EIP is at
serial_chars_in_buffer+0x72/0x84 [usbserial]
Jul 26 07:05:36 teo kernel: [ 340.272047] eax: c9d11bf8 ebx: c9d11bf8
ecx: 00000000 edx: 6d41ab68
Jul 26 07:05:36 teo kernel: [ 340.296129] esi: 00000000 edi: ca55ff3c
ebp: c90c2804 esp: c9021be8
Jul 26 07:05:36 teo kernel: [ 340.320615] ds: 007b es: 007b fs: 00d8
gs: 0033 ss: 0068
Jul 26 07:05:36 teo kernel: [ 340.345592] Process mpcs-0.8k-rc16- (pid:
3607, ti=c9020000 task=c8e2b5b0 task.ti=c9020000)
Jul 26 07:05:36 teo kernel: [ 340.346616] Stack: c90c27f8 c0211064 00000001
00000000 c90c27f8 c0214fec 00128ab7 c90c27f8
Jul 26 07:05:36 teo kernel: [ 340.372944] c0214ef2 ca55ff3c c0211129
00000000 00000000 00000000 c9021e9c ca55ff3c
Jul 26 07:05:36 teo kernel: [ 340.400052] c9021e94 c0171950 c9021fac
bfd4bc40 bfd4bc48 00000000 c9021e94 c9021e94
Jul 26 07:05:36 teo kernel: [ 340.427769] Call Trace:
Jul 26 07:05:36 teo kernel: [ 340.482820] [<c0211064>]
tty_ldisc_ref_wait+0xc/0x86
Jul 26 07:05:36 teo kernel: [ 340.511235] [<c0214fec>]
normal_poll+0xfa/0x11f
Jul 26 07:05:36 teo kernel: [ 340.539506] [<c0214ef2>]
normal_poll+0x0/0x11f
Jul 26 07:05:36 teo kernel: [ 340.567713] [<c0211129>] tty_poll+0x4b/0x63
Jul 26 07:05:36 teo kernel: [ 340.596168] [<c0171950>]
do_sys_poll+0x19a/0x327
Jul 26 07:05:36 teo kernel: [ 340.624807] [<c017244d>] __pollwait+0x0/0xac
Jul 26 07:05:36 teo kernel: [ 340.653485] [<c011c41d>]
default_wake_function+0x0/0xc
Jul 26 07:05:36 teo kernel: [ 340.682239] [<c011c41d>]
default_wake_function+0x0/0xc
Jul 26 07:05:36 teo kernel: [ 340.710473] [<c022b2a2>]
dma_pool_alloc+0x1c0/0x1ca
Jul 26 07:05:36 teo kernel: [ 340.738530] [<c013aa22>]
__lock_acquire+0xb30/0xbc4
Jul 26 07:05:36 teo kernel: [ 340.766608] [<c013aa22>]
__lock_acquire+0xb30/0xbc4
Jul 26 07:05:36 teo kernel: [ 340.794355] [<c01630a1>]
cache_flusharray+0x3f/0xea
Jul 26 07:05:36 teo kernel: [ 340.822029] [<c013aa22>]
__lock_acquire+0xb30/0xbc4
Jul 26 07:05:36 teo kernel: [ 340.849340] [<c01291c6>]
lock_timer_base+0x15/0x2f
Jul 26 07:05:36 teo kernel: [ 340.876811] [<c0119188>]
change_page_attr+0x1c/0x291
Jul 26 07:05:36 teo kernel: [ 340.904011] [<c013aa22>]
__lock_acquire+0xb30/0xbc4
Jul 26 07:05:36 teo kernel: [ 340.930929] [<deea2f62>]
ide_execute_command+0x2e/0xa5 [ide_core]
Jul 26 07:05:36 teo kernel: [ 340.957918] [<c01292dd>]
__mod_timer+0x9f/0xa9
Jul 26 07:05:36 teo kernel: [ 340.984584] [<c02a674c>]
_spin_lock_irqsave+0x39/0x41
Jul 26 07:05:36 teo kernel: [ 341.011073] [<c01cc56b>]
vsnprintf+0x450/0x48c
Jul 26 07:05:36 teo kernel: [ 341.037479] [<c0121289>]
release_console_sem+0x1a0/0x1b9
Jul 26 07:05:36 teo kernel: [ 341.063968] [<c013aa22>]
__lock_acquire+0xb30/0xbc4
Jul 26 07:05:36 teo kernel: [ 341.090184] [<defcc78e>]
iuu_uart_write+0x47/0x70 [iuu_phoenix]
Jul 26 07:05:36 teo kernel: [ 341.116369] [<c013aa22>]
__lock_acquire+0xb30/0xbc4
Jul 26 07:05:36 teo kernel: [ 341.142298] [<c0191593>]
dnotify_parent+0x1a/0x5d
Jul 26 07:05:36 teo kernel: [ 341.168041] [<c0210299>]
tty_ldisc_deref+0x55/0x64
Jul 26 07:05:36 teo kernel: [ 341.193291] [<c016756e>]
vfs_write+0xef/0x12a
Jul 26 07:05:36 teo kernel: [ 341.218136] [<c0103d20>]
sysenter_past_esp+0x8d/0x99
Jul 26 07:05:36 teo kernel: [ 341.243218] [<c0139ad5>]
trace_hardirqs_on+0x126/0x150
Jul 26 07:05:37 teo kernel: [ 341.268493] [<c0171b11>] sys_poll+0x34/0x37
Jul 26 07:05:37 teo kernel: [ 341.293883] [<c0103cf0>]
sysenter_past_esp+0x5d/0x99
Jul 26 07:05:37 teo kernel: [ 341.319471] =======================
Jul 26 07:05:37 teo kernel: [ 341.344183] Code: ee fd de 00 74 2d c7 44 24
08 cc 9d fd de c7 44 24 04 6d a0 fd de c7 04 24 a2 a0 fd de e8 8e a4 14 e1
eb
0f 8b 03 8b 50 04 89 d8 <ff> 92 84 01 00 00 eb 05 b8 ed ff ff ff 83 c4 10 5b
c3 53 83 ec
Jul 26 07:05:37 teo kernel: [ 341.395493] EIP: [<defd7473>]
serial_chars_in_buffer+0x72/0x84 [usbserial] SS:ESP 0068:c9021be8
I suspect iuu_bulk_write of course
But where exactly ???
Thanks,
Alain
-------------------------------------------------------------------------
This SF.net email is sponsored by: Splunk Inc.
Still grepping through log files to find problems? Stop.
Now Search log events and configuration files using AJAX and a browser.
Download your FREE copy of Splunk now >> http://get.splunk.com/
_______________________________________________
linux-usb-devel@lists.sourceforge.net
To unsubscribe, use the last form field at:
https://lists.sourceforge.net/lists/listinfo/linux-usb-devel
