Re: [Linux-ATM-General] Fwd: Re: [PATCH] pppoatm carrier status

SourceForge Headquarters 225 Broadway Suite 1600 San Diego, CA 92101 +1 (858) 422-6466

  On 10/6/10 10:26 AM, Philip Prindeville wrote:
>    On 9/23/10 3:22 PM, Karl Hiramoto wrote:
>> On 09/23/10 23:57, Philip Prindeville wrote:
>>> Ok, now I'm seeing:
>>>
>>>>>>>    Plugged in and trained up
>>> 10: ppp0:<POINTOPOINT,MULTICAST,NOARP,UP,LOWER_UP>    mtu 1500 qdisc
>>> pfifo_fast state UNKNOWN qlen 3
>>>       link/ppp
>>>
>>>
>>>>>>>    Unplugged
>>> 10: ppp0:<POINTOPOINT,MULTICAST,NOARP,UP,LOWER_UP>    mtu 1500 qdisc
>>> pfifo_fast state UNKNOWN qlen 3
>>>       link/ppp
>>>
>>>
>>> Still no difference.  And yes, I have the carrier patch for the
>>> solos-pci.c driver.
>> The strange thing is that the printk in pppoatm_dev_event() did not show
>> up, so I'm wondering if the solos-pci driver is calling
>> atm_dev_signal_change() when the line goes up/down.
> Well, it turns out that it isn't.  We built a module with lots of pr_info()'s liberally sprinkled, and we see:
>
>                   card->atmdev[i]->ci_range.vpi_bits = 8;
>                   card->atmdev[i]->ci_range.vci_bits = 16;
>                   card->atmdev[i]->dev_data = card;
>                   card->atmdev[i]->phy_data = (void *)(unsigned long)i;
>                   pr_info("%s:%d unknown %d\n", __func__, __LINE__, card->atmdev[i]);
>                   atm_dev_signal_change(card->atmdev[i], ATM_PHY_SIG_UNKNOWN);
>
>
>
> being hit inside atm_init(), but not any of the other calls to atm_dev_signal_change().
>
> process_status() calls atm_dev_signal_change() as well, but doesn't get compiled-in unless SolosParameterSysfs is defined, which I really don't understand.

Ok, part of the above is true: process_status() doesn't get compiled unless SolosParameterSysfs() is turned on, but for kernels 2.6.25 it *is* turned on.

So that's not the problem for us.  In my case, it seems we're never seeing a PKT_STATUS being indicated.

-Philip

> The card should be handling status updates regardless of whether we're using /sys or not, right?
>
> What am I missing here?
>
> I'm trying to get some optimizations done in PPP at the process-level based on watching carrier state when using the pppoatm and pppoe plugins, but I'm blocked on the card not handling link-state indications properly.
>
>> if you add "#define DEBUG 1" at the top of net/atm/common.c  hopefully
>> we should see the pr_debug() in atm_dev_signal_change() show up in the
>> logs.   Otherwise the problem is in the solos-pci driver.
> Yup.  We have a smoking gun.
>
> Actually, code inspection would have revealed this... if I suspected that enabling the sysfs support would make a basic difference, which didn't seem likely.
>
> -Philip
>
>>> Sep 23 14:52:19 pbx2 user.warn kernel: eth1: Transmit timeout, status
>>> c   2b  484    0
>>> Sep 23 14:52:19 pbx2 user.warn kernel: ------------[ cut here ]------------
>>> Sep 23 14:52:19 pbx2 user.warn kernel: WARNING: at kernel/softirq.c:136
>>> local_bh_enable+0x2f/0x76()
>>> Sep 23 14:52:19 pbx2 user.warn kernel: Modules linked in: binfmt_misc
>>> aes_i586 aes_generic xt_tcpudp ipt_MASQUERADE iptable_nat nf_nat_ftp
>>> nf_nat nf_conntrack_ipv4 xt_TCPMSS ipt_LOG ipt_REJECT iptable_mangle
>>> iptable_filter xt_multiport xt_state xt_limit xt_conntrack
>>> Sep 23 14:52:19 pbx2 user.warn kernel: Pid: 0, comm: swapper Tainted:
>>> P        W 2.6.27.49-astlinux #1
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  [<c01153de>]
>>> warn_on_slowpath+0x40/0x63
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  [<c01be378>]
>>> cipher_crypt_unaligned+0x6f/0xa7
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  [<c01065e8>] read_tsc+0x6/0x22
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  [<c012899e>]
>>> getnstimeofday+0x4a/0xc7
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  [<c01267c2>] ktime_get_ts+0x1d/0x3f
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  [<c012604e>]
>>> hrtimer_forward+0xe2/0xfe
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  [<c014d80e>] free_block+0xb3/0xef
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  [<c02aa0e1>]
>>> __atomic_notifier_call_chain+0x19/0x36
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  [<c011915d>]
>>> local_bh_enable+0x2f/0x76
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  [<e01a8f8a>]
>>> destroy_conntrack+0xb8/0xd7 [nf_conntrack]
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  [<c0266262>]
>>> nf_conntrack_destroy+0x1e/0x34
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  [<c024da41>]
>>> skb_release_all+0x80/0xbd
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  [<c024da9c>] __kfree_skb+0x8/0x61
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  [<e0017589>]
>>> cp_clean_rings+0xbb/0xf8 [8139cp]
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  [<e0018b58>]
>>> cp_tx_timeout+0x6b/0xca [8139cp]
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  [<c025df4b>] dev_watchdog+0x0/0x176
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  [<c025e051>]
>>> dev_watchdog+0x106/0x176
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  [<e0097f3c>]
>>> coretimer_func+0xb1/0x133 [dahdi]
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  [<c011c052>]
>>> run_timer_softirq+0x116/0x17a
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  [<c0118cdc>] __do_softirq+0x35/0x75
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  [<c0118d3e>] do_softirq+0x22/0x26
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  [<c0118f18>] irq_exit+0x25/0x30
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  [<c010477c>] do_IRQ+0x4d/0x5d
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  [<c010394b>]
>>> common_interrupt+0x23/0x28
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  [<c0106f3d>] default_idle+0x25/0x38
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  [<c010254b>] cpu_idle+0x37/0x5f
>>> Sep 23 14:52:19 pbx2 user.warn kernel:  =======================
>>> Sep 23 14:52:19 pbx2 user.warn kernel: ---[ end trace 4f9198b05afcf39f ]---
>>> Sep 23 14:52:19 pbx2 user.debug kernel: pppoatm push
>>> Sep 23 14:52:19 pbx2 user.debug kernel: pppoatm_send (skb=0xde660c00,
>>> vcc=0xde741800)
>>> Sep 23 14:52:19 pbx2 user.debug kernel:
>> An ugly warning from a tainted kernel that looks like it has nothing to
>> do with the atm stack.
>>
>>> bytes.
>>> Sep 23 14:54:13 pbx2 daemon.debug pppd[1606]: sent [LCP TermReq id=0x3
>>> "Peer not responding"]
>>> Sep 23 14:54:13 pbx2 user.debug kernel: pppoatm_send (skb=0xde660a80,
>>> vcc=0xde741800)
>>> Sep 23 14:54:13 pbx2 user.debug kernel:
>>> atm_skb(de660a80)->vcc(de741800)->dev(de639000)
>>> Sep 23 14:54:16 pbx2 daemon.debug pppd[1606]: sent [LCP TermReq id=0x4
>>> "Peer not responding"]
>>> Sep 23 14:54:16 pbx2 user.debug kernel: pppoatm_send (skb=0xde74a980,
>>> vcc=0xde741800)
>>> Sep 23 14:54:16 pbx2 user.debug kernel:
>>> atm_skb(de74a980)->vcc(de741800)->dev(de639000)
>>> Sep 23 14:54:19 pbx2 daemon.notice pppd[1606]: Connection terminated.
>>> Sep 23 14:54:19 pbx2 daemon.notice pppd[1606]: Modem hangup
>>> Sep 23 14:54:19 pbx2 user.debug kernel: pppoatm push
>>> Sep 23 14:54:19 pbx2 user.debug kernel: removing ATMPPP VCC de7752a0
>>>
>