solution to printk() blocking interrupts?

Started by Jon Smirl on Sep 21, 2008 · 16 messages from 3 authors · Last reply Sep 23, 2008

Does anyone have a solution to the problem of printk() to a serial
console blocking interrupts for too long? I'm losing interrupts I need
because my hardware is getting overrun.

-- 
Jon Smirl
jonsmirl@gmail.com

Jon Smirl replied to Jon Smirl Sep 21, 21:43 #

On Sun, Sep 21, 2008 at 4:53 PM, Jon Smirl [off-list ref] wrote:

Does anyone have a solution to the problem of printk() to a serial
console blocking interrupts for too long? I'm losing interrupts I need
because my hardware is getting overrun.

netconsole is not an option on mpc5200....

Kernel command line: console=ttyPSC0,115200 rw debug root=/dev/nfs
ip=dhcp nfsroot=192.168.1.4:/home/OSELAS.BSP-Phytec-phyCORE-MPC5200B-tiny-6/root,v3,tcp
netconsole=6666@192.168.1.11/eth0,514@192.168.1.4/00:19:d1:e4:0f:8d
netconsole: local port 6666
netconsole: local IP 192.168.1.11
netconsole: interface eth0
netconsole: remote port 514
netconsole: remote IP 192.168.1.4
netconsole: remote ethernet address 00:19:d1:e4:0f:8d
netconsole: eth0 doesn't support polling, aborting.
netconsole: cleaning up

-- 
Jon Smirl
jonsmirl@gmail.com

Sergei Shtylyov replied to Jon Smirl Sep 21, 22:21 #

Hello.

Jon Smirl wrote:

On Sun, Sep 21, 2008 at 4:53 PM, Jon Smirl [off-list ref] wrote:

quoted

Does anyone have a solution to the problem of printk() to a serial
console blocking interrupts for too long? I'm losing interrupts I need
because my hardware is getting overrun.

netconsole is not an option on mpc5200....

Kernel command line: console=ttyPSC0,115200 rw debug root=/dev/nfs
ip=dhcp nfsroot=192.168.1.4:/home/OSELAS.BSP-Phytec-phyCORE-MPC5200B-tiny-6/root,v3,tcp
netconsole=6666@192.168.1.11/eth0,514@192.168.1.4/00:19:d1:e4:0f:8d
netconsole: local port 6666
netconsole: local IP 192.168.1.11
netconsole: interface eth0
netconsole: remote port 514
netconsole: remote IP 192.168.1.4
netconsole: remote ethernet address 00:19:d1:e4:0f:8d
netconsole: eth0 doesn't support polling, aborting.
netconsole: cleaning up

  Implementing the poll_controller() method in the network driver is usually staightforward.

WBR, Sergei

Jon Smirl replied to Sergei Shtylyov Sep 21, 23:34 #

On Sun, Sep 21, 2008 at 6:21 PM, Sergei Shtylyov
[off-list ref] wrote:

 Implementing the poll_controller() method in the network driver is usually
staightforward.

Good tip, the simple implementation worked.

What controls this? "carrier detect appears untrustworthy, waiting 4 seconds"
Get that fixed and this patch could be useful,

root@phyCORE-MPC5200B-tiny:~ dmesg | grep netconsole
Kernel command line: console=ttyPSC0,115200 rw debug root=/dev/nfs
ip=dhcp nfsroot=192.168.1.4:/home/OSELAS.BSP-Phytec-phyCORE-MPC5200B-tiny-6/root,v3,tcp
netconsole=6666@192.168.1.11/eth0,514@192.168.1.4/00:19:d1:e4:0f:8d
netconsole: local port 6666
netconsole: local IP 192.168.1.11
netconsole: interface eth0
netconsole: remote port 514
netconsole: remote IP 192.168.1.4
netconsole: remote ethernet address 00:19:d1:e4:0f:8d
netconsole: device eth0 not up yet, forcing it
netconsole: carrier detect appears untrustworthy, waiting 4 seconds
netconsole: network logging started
root@phyCORE-MPC5200B-tiny:~

diff --git a/drivers/net/fec_mpc52xx.c b/drivers/net/fec_mpc52xx.c
index 4e4f683..72541b5 100644
--- a/drivers/net/fec_mpc52xx.c
+++ b/drivers/net/fec_mpc52xx.c

@@ -401,6 +401,16 @@ static int mpc52xx_fec_hard_start_xmit(struct

sk_buff *skb, struct net_device *d
        return 0;
 }

+#ifdef CONFIG_NET_POLL_CONTROLLER
+static void mpc52xx_fec_poll_controller(struct net_device *dev)
+{
+        disable_irq(dev->irq);
+        mpc52xx_fec_tx_interrupt(dev->irq, dev);
+        enable_irq(dev->irq);
+}
+#endif
+
+
 /* This handles BestComm transmit task interrupts
  */
 static irqreturn_t mpc52xx_fec_tx_interrupt(int irq, void *dev_id)

@@ -926,6 +936,9 @@ mpc52xx_fec_probe(struct of_device *op, const

struct of_device_id *match)
        ndev->tx_timeout        = mpc52xx_fec_tx_timeout;
        ndev->watchdog_timeo    = FEC_WATCHDOG_TIMEOUT;
        ndev->base_addr         = mem.start;
+#ifdef CONFIG_NET_POLL_CONTROLLER
+       ndev->poll_controller = mpc52xx_fec_poll_controller;
+#endif

        priv->t_irq = priv->r_irq = ndev->irq = NO_IRQ; /* IRQ are
free for now */




-- 
Jon Smirl
jonsmirl@gmail.com

Benjamin Herrenschmidt replied to Jon Smirl Sep 22, 05:17 #

On Sun, 2008-09-21 at 19:34 -0400, Jon Smirl wrote:

On Sun, Sep 21, 2008 at 6:21 PM, Sergei Shtylyov
[off-list ref] wrote:

quoted

 Implementing the poll_controller() method in the network driver is usually
staightforward.

Good tip, the simple implementation worked.

What controls this? "carrier detect appears untrustworthy, waiting 4 seconds"
Get that fixed and this patch could be useful,

Does the driver properly uses netif_carrier_on/off to signal the
system when the link is up/down ?

Cheers,
Ben.

Sergei Shtylyov replied to Jon Smirl Sep 22, 10:03 #

Hello.

Jon Smirl wrote:

quoted

 Implementing the poll_controller() method in the network driver is usually
staightforward.

Good tip, the simple implementation worked.

What controls this? "carrier detect appears untrustworthy, waiting 4 seconds"

  IIRC, it happens if netpoll code sees the carrier OK right ast the first time it checks it. Look for this message in net/core/netpoll.c...

Get that fixed and this patch could be useful,

   How that hinders using netconsole?

quoted hunk

root@phyCORE-MPC5200B-tiny:~ dmesg | grep netconsole
Kernel command line: console=ttyPSC0,115200 rw debug root=/dev/nfs
ip=dhcp nfsroot=192.168.1.4:/home/OSELAS.BSP-Phytec-phyCORE-MPC5200B-tiny-6/root,v3,tcp
netconsole=6666@192.168.1.11/eth0,514@192.168.1.4/00:19:d1:e4:0f:8d
netconsole: local port 6666
netconsole: local IP 192.168.1.11
netconsole: interface eth0
netconsole: remote port 514
netconsole: remote IP 192.168.1.4
netconsole: remote ethernet address 00:19:d1:e4:0f:8d
netconsole: device eth0 not up yet, forcing it
netconsole: carrier detect appears untrustworthy, waiting 4 seconds
netconsole: network logging started
root@phyCORE-MPC5200B-tiny:~

diff --git a/drivers/net/fec_mpc52xx.c b/drivers/net/fec_mpc52xx.c
index 4e4f683..72541b5 100644
--- a/drivers/net/fec_mpc52xx.c
+++ b/drivers/net/fec_mpc52xx.c

@@ -401,6 +401,16 @@ static int mpc52xx_fec_hard_start_xmit(struct

sk_buff *skb, struct net_device *d
        return 0;
 }

+#ifdef CONFIG_NET_POLL_CONTROLLER
+static void mpc52xx_fec_poll_controller(struct net_device *dev)
+{
+        disable_irq(dev->irq);
+        mpc52xx_fec_tx_interrupt(dev->irq, dev);

  The interrupt nu,ber seems wrong, although the handler doesn't care anyway...

quoted hunk

+        enable_irq(dev->irq);
+}
+#endif
  

  Hey, how about the Rx interrupt? And I'm seeing mcp52xx_fec_interrupt() on separate IRQ too -- looks like for for this driver this is not as straightforward as it usually is.
You need to call all the handlers -- netconsole is not the only user of the netpoll API, so not only Tx should be handled.

WBR, Sergei

Sergei Shtylyov replied to Sergei Shtylyov Sep 22, 11:01 #

Hello, I wrote:

quoted

diff --git a/drivers/net/fec_mpc52xx.c b/drivers/net/fec_mpc52xx.c
index 4e4f683..72541b5 100644
--- a/drivers/net/fec_mpc52xx.c
+++ b/drivers/net/fec_mpc52xx.c

@@ -401,6 +401,16 @@ static int mpc52xx_fec_hard_start_xmit(struct

sk_buff *skb, struct net_device *d
        return 0;
 }

+#ifdef CONFIG_NET_POLL_CONTROLLER
+static void mpc52xx_fec_poll_controller(struct net_device *dev)
+{
+        disable_irq(dev->irq);
+        mpc52xx_fec_tx_interrupt(dev->irq, dev);

  The interrupt nu,ber seems wrong, although the handler doesn't care anyway...

quoted

+        enable_irq(dev->irq);

  Ah, you're also dis/enabling the wrong IRQ -- it should be priv->t_irq. No, this patch won't do.

WBR, Sergei

Sergei Shtylyov replied to Benjamin Herrenschmidt Sep 22, 11:04 #

Hello.

Benjamin Herrenschmidt wrote:

quoted

 Implementing the poll_controller() method in the network driver is usually
staightforward.

Good tip, the simple implementation worked.

What controls this? "carrier detect appears untrustworthy, waiting 4 seconds"
Get that fixed and this patch could be useful,

Does the driver properly uses netif_carrier_on/off to signal the
system when the link is up/down ?

  Looks like the answer is "no"...

WBR, Sergei

Sergei Shtylyov replied to Sergei Shtylyov Sep 22, 11:11 #

Hello, I wrote:

quoted

What controls this? "carrier detect appears untrustworthy, waiting 4 seconds"
Get that fixed and this patch could be useful,

Does the driver properly uses netif_carrier_on/off to signal the
system when the link is up/down ?

 Implementing the poll_controller() method in the network driver is usually

  Looks like the answer is "no"...

  Hm... it uses phylib, so probably it does that. That message and a 4 s pause appears if the carrier is seen in <10 ms after opening the device. Maybe this threshold needs to be changed?

WBR, Sergei

Sergei Shtylyov replied to Jon Smirl Sep 22, 11:21 #

Hello.

Jon Smirl wrote:

quoted

Does anyone have a solution to the problem of printk() to a serial
console blocking interrupts for too long? I'm losing interrupts I need
because my hardware is getting overrun.

  It's a strange piece of hardware that loses interrupts on getting overrun. :-)

WBR, Sergei

Jon Smirl replied to Sergei Shtylyov Sep 22, 13:45 #

On Mon, Sep 22, 2008 at 7:21 AM, Sergei Shtylyov
[off-list ref] wrote:

Hello.

Jon Smirl wrote:

quoted

Does anyone have a solution to the problem of printk() to a serial
console blocking interrupts for too long? I'm losing interrupts I need
because my hardware is getting overrun.

 It's a strange piece of hardware that loses interrupts on getting overrun.
:-)

The 4 second pause slows down the debug/test cycle a lot. I'm using a
net booted monolithic kernel on the hardware and using the reset
button every time I make a change.

When you boot there are two classes of output, printk() output and
users space generated output. Right now I'm getting the printk()
output. Is there some way to see the user space output so that I can
tell if a user space server failed to start?

I changed poll to this code, but I don't know how network drivers
work. I can make changes and test them if you tell me what needs to be
fixed.


#ifdef CONFIG_NET_POLL_CONTROLLER
static void mpc52xx_fec_poll_controller(struct net_device *dev)
{
	struct mpc52xx_fec_priv *priv = netdev_priv(dev);

	disable_irq(priv->t_irq);
	mpc52xx_fec_tx_interrupt(priv->t_irq, dev);
	enable_irq(priv->t_irq);
	disable_irq(priv->r_irq);
	mpc52xx_fec_rx_interrupt(priv->r_irq, dev);
	enable_irq(priv->r_irq);
}
#endif






-- 
Jon Smirl
jonsmirl@gmail.com

Sergei Shtylyov replied to Sergei Shtylyov Sep 22, 14:39 #

Hello, I wrote:

  Not sure if Stephen was the right person to CC, including Matt now...

quoted

What controls this? "carrier detect appears untrustworthy, waiting 4 seconds"
Get that fixed and this patch could be useful,

quoted

Does the driver properly uses netif_carrier_on/off to signal the
system when the link is up/down ?

quoted

 Implementing the poll_controller() method in the network driver is usually

quoted

  Looks like the answer is "no"...

  Hm... it uses phylib, so probably it does that. That message and a 4 s pause appears if the carrier is seen in <10 ms after opening the device.

   Oops, not 10 -- 100 ms (HZ / 10).

Maybe this threshold needs to be changed?

   Seems like too much indeed.

WBR, Sergei

Jon Smirl replied to Sergei Shtylyov Sep 22, 14:45 #

On Mon, Sep 22, 2008 at 10:39 AM, Sergei Shtylyov
[off-list ref] wrote:

Hello, I wrote:

 Not sure if Stephen was the right person to CC, including Matt now...

quoted

What controls this? "carrier detect appears untrustworthy, waiting 4
seconds"
Get that fixed and this patch could be useful,

quoted

Does the driver properly uses netif_carrier_on/off to signal the
system when the link is up/down ?

quoted

 Implementing the poll_controller() method in the network driver is
usually

quoted

 Looks like the answer is "no"...

quoted

 Hm... it uses phylib, so probably it does that. That message and a 4 s
pause appears if the carrier is seen in <10 ms after opening the device.

  Oops, not 10 -- 100 ms (HZ / 10).

quoted

Maybe this threshold needs to be changed?

  Seems like too much indeed.

The link is coming up, but it appears that netconsole has already
decided to wait 4s.

mpc52xx MII bus: probed
net eth0: Using PHY at MDIO address 0
netconsole: local port 6666
netconsole: local IP 192.168.1.11
netconsole: interface eth0
netconsole: remote port 514
netconsole: remote IP 192.168.1.4
netconsole: remote ethernet address 00:19:d1:e4:0f:8d
netconsole: device eth0 not up yet, forcing it
net eth0: attached phy 0 to driver Generic PHY
netconsole: carrier detect appears untrustworthy, waiting 4 seconds
PHY: f0003000:00 - Link is Up - 100/Full
console [netcon0] enabled
netconsole: network logging started

WBR, Sergei



-- 
Jon Smirl
jonsmirl@gmail.com

Sergei Shtylyov replied to Jon Smirl Sep 22, 14:59 #

Jon Smirl wrote:

quoted

Not sure if Stephen was the right person to CC, including Matt now...

quoted

What controls this? "carrier detect appears untrustworthy, waiting 4
seconds"
Get that fixed and this patch could be useful,

quoted

Does the driver properly uses netif_carrier_on/off to signal the
system when the link is up/down ?

quoted

Implementing the poll_controller() method in the network driver is
usually

quoted
quoted
quoted
Looks like the answer is "no"...

quoted

Hm... it uses phylib, so probably it does that. That message and a 4 s
pause appears if the carrier is seen in <10 ms after opening the device.

quoted

 Oops, not 10 -- 100 ms (HZ / 10).

quoted

Maybe this threshold needs to be changed?

quoted

 Seems like too much indeed.

The link is coming up, but it appears that netconsole has already
decided to wait 4s.
mpc52xx MII bus: probed
net eth0: Using PHY at MDIO address 0
netconsole: local port 6666
netconsole: local IP 192.168.1.11
netconsole: interface eth0
netconsole: remote port 514
netconsole: remote IP 192.168.1.4
netconsole: remote ethernet address 00:19:d1:e4:0f:8d
netconsole: device eth0 not up yet, forcing it
net eth0: attached phy 0 to driver Generic PHY
netconsole: carrier detect appears untrustworthy, waiting 4 seconds

   Netpoll code decides to wait 4 secs after seeing that carrier is OK before 100 ms passed...

PHY: f0003000:00 - Link is Up - 100/Full

   ...but it's only reported to be OK later. So indeed, the carrier reported by the driver appears untrustworthy. ;-)

WBR, Sergei

Benjamin Herrenschmidt replied to Sergei Shtylyov Sep 22, 21:27 #

On Mon, 2008-09-22 at 15:11 +0400, Sergei Shtylyov wrote:

Hello, I wrote:

quoted

What controls this? "carrier detect appears untrustworthy, waiting 4 
seconds"
Get that fixed and this patch could be useful,

Does the driver properly uses netif_carrier_on/off to signal the
system when the link is up/down ?

 Implementing the poll_controller() method in the network driver is 
usually

  Looks like the answer is "no"...

   Hm... it uses phylib, so probably it does that. That message and a 4 
s pause appears if the carrier is seen in <10 ms after opening the 
device. Maybe this threshold needs to be changed?

This sounds fishy, some devices can setup the carrier before open...

Ben.

Benjamin Herrenschmidt replied to Jon Smirl Sep 23, 05:46 #

quoted

 It's a strange piece of hardware that loses interrupts on getting overrun.
:-)

The 4 second pause slows down the debug/test cycle a lot. I'm using a
net booted monolithic kernel on the hardware and using the reset
button every time I make a change.

I'm not going to have much feelings for you here... I've debugged the
kernel on setups that need 30mn to reboot :-)

Ben.

`h`	back out one level
`j`	next message in thread
`k`	previous message in thread
`l`	drill in
`Esc`	close help / fold thread tree
`?`	toggle this help