VoIP Mailing List Archives

[mike at loop.com.br]

Hello, I am trying to get a Wildcard TE110P to work in a relatively
modern HP Proliant DL385p Gen8 server. Being a potent 12 core Opteron
server I expected no problems.

Much to my dismay the dahdi_test results are constantly terrible:

# dahdi_test
Opened pseudo dahdi interface, measuring accuracy...
89.101% 89.195% 89.142% 88.957% 88.953% 89.115% 89.089% 89.134%
89.066% 89.021% 88.933% 89.044% 89.200% 89.017% 89.425% 89.014%
89.140% 89.814% 89.379% 89.185% 88.943% 89.000% 89.090% 89.067%
88.975% 88.875% 89.095% 89.130% 89.049% 89.046% 89.040% 88.945%
89.211% 89.021% 89.091% 88.972% 88.973% 89.147% 89.003% 88.970%
--- Results after 40 passes ---
Best: 89.814% -- Worst: 88.875% -- Average: 89.089184%
Cummulative Accuracy (not per pass): 89.089

Trying to use the card results in constant 'HDLC Bad FCS' and
consequent 'HDLC Abort'.

As far as I can tell everything should be fine. The card has its
own IO-APIC interrupt (2. I tried setting its smp_affinity to
one cpu, changed the pci card latency... to no avail, always
the same terrible dahdi_test results.

Some info:

# uname -a
Linux mundau 3.2.0-4-amd64 #1 SMP Debian 3.2.51-1 x86_64 GNU/Linux

# dmesg | egrep -i 'dahdi|te110|wcop|wcte1'
[ 39.054098] dahdi: Version: 2.7.0.1
[ 39.054775] dahdi: Telephony Interface Registered on major 196
[ 39.128206] TE110P: Setting up global serial parameters for E1 FALC V1.2
[ 39.128376] TE110P: Successfully initialized serial bus for card
[ 39.131355] Found a Wildcard: Digium Wildcard TE110P T1/E1
[ 39.223031] wcopenpci: Module loaded
[ 39.714308] dahdi_echocan_oslec: Registered echo canceler 'OSLEC'
[ 39.716015] TE110P: Span configured for CCS/HDB3/CRC4
[ 39.751770] wcte1xxp: Setting yellow alarm

# dahdi_hardware
pci:0000:06:00.0 wcte11xp+ e159:0001 Digium Wildcard TE110P T1/E1 Board

# dahdi_scan
[1]
active=yes
alarms=RED
description=Digium Wildcard TE110P T1/E1 Card 0
name=WCT1/0
manufacturer=Digium
devicetype=Digium Wildcard TE110P T1/E1
location=PCI Bus 06 Slot 01
basechan=1
totchans=31
irq=0
type=digital-E1
syncsrc=0
lbo=0 db (CSU)/0-133 feet (DSX-1)
coding_opts=HDB3
framing_opts=CCS,CRC4
coding=HDB3
framing=CCS/CRC4

Here is the /proc/interrupt info with CPU1-CPU10 removed for space:

CPU0 ... CPU11
0: 71 0 IO-APIC-edge timer
1: 3 0 IO-APIC-edge i8042
3: 8 0 IO-APIC-edge serial
7: 1 0 IO-APIC-edge
8: 1 0 IO-APIC-edge rtc0
9: 0 0 IO-APIC-fasteoi acpi
12: 5 0 IO-APIC-edge i8042
14: 0 0 IO-APIC-edge pata_atiixp
15: 0 0 IO-APIC-edge pata_atiixp
16: 52 0 IO-APIC-fasteoi ahci
22: 1189 0 IO-APIC-fasteoi ehci_hcd:usb2, ohci_hcd:usb4, ohci_hcd:usb5
23: 157 0 IO-APIC-fasteoi ehci_hcd:usb1, ohci_hcd:usb6, ohci_hcd:usb7
28: 6217028 0 IO-APIC-fasteoi wcte11xp
44: 0 0 IO-APIC-fasteoi uhci_hcd:usb3, hpilo
72: 0 0 PCI-MSI-edge AMD-Vi
73: 29799 0 PCI-MSI-edge hpsa0
77: 2 0 PCI-MSI-edge eth1-0
78: 17413 0 PCI-MSI-edge eth1-1
79: 3502 0 PCI-MSI-edge eth1-2
80: 10967 0 PCI-MSI-edge eth1-3
81: 3765 0 PCI-MSI-edge eth1-4
82: 1 0 PCI-MSI-edge eth2-0
83: 1 0 PCI-MSI-edge eth2-1
84: 1 0 PCI-MSI-edge eth2-2
85: 1 0 PCI-MSI-edge eth2-3
86: 1 0 PCI-MSI-edge eth2-4
87: 1 0 PCI-MSI-edge eth3-0
88: 1 0 PCI-MSI-edge eth3-1
89: 1 0 PCI-MSI-edge eth3-2
90: 1 0 PCI-MSI-edge eth3-3
91: 1 0 PCI-MSI-edge eth3-4
NMI: 0 0 Non-maskable interrupts
LOC: 36381 6631 Local timer interrupts
SPU: 0 0 Spurious interrupts
PMI: 0 0 Performance monitoring interrupts
IWI: 0 0 IRQ work interrupts
RES: 36124 8213 Rescheduling interrupts
CAL: 599 671 Function call interrupts
TLB: 157 226 TLB shootdowns
TRM: 0 0 Thermal event interrupts
THR: 0 0 Threshold APIC interrupts
MCE: 0 0 Machine check exceptions
MCP: 24 24 Machine check polls
ERR: 1
MIS: 0

Should I just give up on using the card in this server ?
Is there anything else I can try ?
What other information may be relevant ?

Many thanks in advance.

Mike


--
_____________________________________________________________________
-- Bandwidth and Colocation Provided by http://www.api-digital.com --
New to Asterisk? Join us for a live introductory webinar every Thurs:
http://www.asterisk.org/hello

asterisk-users mailing list
To UNSUBSCRIBE or update options visit:
http://lists.digium.com/mailman/listinfo/asterisk-users

[rmeyerriecks at digium...]

On Mon, May 12, 2014 at 4:57 PM, Mike Leddy <mike@loop.com.br (mike@loop.com.br)> wrote:

[mike at loop.com.br]

Thanks Russ,

I blacklisted wcopenpci, and i noticed an improvement:

# dahdi_test
Opened pseudo dahdi interface, measuring accuracy...
91.973% 96.242% 94.423% 77.932% 97.654% 87.114% 68.750% 87.417%
75.768% 95.693% 93.086% 77.936% 87.283% 92.996% 77.942% 77.926%
77.943% 89.545% 93.949% 87.032% 91.939% 71.877% 90.648% 88.163%
77.173% 97.651% 77.932% 77.942% 77.929% 76.548% 80.922% 90.292%
81.977% 89.354% 79.203% 76.665% 77.935% 91.000% 68.182% 95.018%
--- Results after 40 passes ---
Best: 97.654% -- Worst: 68.182% -- Average: 84.673880%
Cummulative Accuracy (not per pass): 86.629

But on examination the /etc/init.d/dahdi start was only loading
the dahdi module.

# lsmod | egrep 'wc|dahdi'
dahdi 192295 0
crc_ccitt 12347 1 dahdi

After a modprobe wcte11xp the situation is:

# lsmod | egrep 'wc|dahdi'
dahdi_echocan_oslec 12578 30
echo 12652 1 dahdi_echocan_oslec
wcte11xp 21535 0
dahdi 192295 2 wcte11xp,dahdi_echocan_oslec
crc_ccitt 12347 1 dahdi

The test returns to as it was before:

# dahdi_test
Opened pseudo dahdi interface, measuring accuracy...
89.100% 89.212% 88.871% 89.078% 89.286% 89.559% 89.358% 89.423%
89.184% 89.083% 88.931% 89.070% 89.110% 88.818% 88.573% 89.091%
89.006% 88.978% 89.157% 89.069% 89.112% 88.890% 89.374% 88.900%
89.042% 89.043% 88.946% 88.786% 88.865% 89.259% 88.951% 88.763%
88.944% 89.123% 88.956% 88.976% 89.044% 89.040% 88.970% 89.148%
--- Results after 40 passes ---
Best: 89.559% -- Worst: 88.573% -- Average: 89.052215%
Cummulative Accuracy (not per pass): 89.052

Still experimenting.....

Best regards,

Mike


On Mon, 2014-05-12 at 17:23 -0500, Russ Meyerriecks wrote:

[rmeyerriecks at digium...]

On Tue, May 13, 2014 at 7:28 AM, Mike Leddy <mike@loop.com.br (mike@loop.com.br)> wrote:

[mike at loop.com.br]

Thanks again Russ,

Just a quick reply for now.

No virtualization, but yes I am running a tickless kernel:

#
# Processor type and features
#
CONFIG_NO_HZ=y

Standard for debian kernels. I booted with nohz=off and the behaviour
changed. Unfortunately for the worse:

# dahdi_test
Opened pseudo dahdi interface, measuring accuracy...
66.653% 66.683% 66.683% 66.807% 67.705% 66.666% 66.651% 66.679%
67.516% 66.882% 66.649% 66.657% 66.678% 66.668% 66.672% 66.664%
66.675% 66.675% 66.659% 66.692% 66.631% 66.187% 66.650% 66.710%
66.648% 66.633% 66.714% 66.638% 66.688% 66.794% 66.645% 66.696%
--- Results after 32 passes ---
Best: 67.705% -- Worst: 66.187% -- Average: 66.726523%

Comparing the boot messages without nohz=off:

[ 0.000000] hpet clockevent registered
[ 0.000000] Fast TSC calibration failed
[ 0.000000] TSC: Unable to calibrate against PIT
[ 0.000000] TSC: using HPET reference calibration
[ 0.000000] Detected 2593.456 MHz processor.

and with nohz=off:

[ 0.000000] hpet clockevent registered
[ 0.000000] Fast TSC calibration using PIT
[ 0.000000] Detected 2593.225 MHz processor.

I am encouraged that we seem to be homing in on the problem. I need to
read up a bit more on the subject.... and look at possible power
saving issues on this machine.

Best regards,

Mike


On Tue, 2014-05-13 at 15:26 -0500, Russ Meyerriecks wrote:

[mike at loop.com.br]

I remembered I have an older box with a Wildcard TE12xP that
uses the wcte12xp module with a newer 3.9.11 kernel that works
perfectly.

I setup the problematic machine with the same kernel in the hope
that this might be relevant. Unfortunately the same situation
persists.

I used the /proc/timer_stats to see how the timers were used:

Timer Stats Version: v0.2
Sample period: 10.002 s
....
311, 15081 kworker/u:0 mod_timer (te12xp_timer)
....

With the TE110P I couldn't find any entry.... It seems that the
timing mechanism is different, it doesn't use mod_timer.

I'm running out of ideas. Please help.

Thanks,

Mike

On Tue, 2014-05-13 at 17:56 -0300, Mike Leddy wrote:

[EWieling at nyigc.com]

Try the card in another machine with a different brand of motherboard. If it works you know it is a hardware issue.

Do you have an actual T-1 plugged into your card? If not, try that and see if there is any difference.

-----Original Message-----
From: asterisk-users-bounces@lists.digium.com [mailto:asterisk-users-bounces@lists.digium.com] On Behalf Of Mike Leddy
Sent: Wednesday, May 14, 2014 3:43 PM
To: asterisk-users@lists.digium.com
Subject: Re: [asterisk-users] Terrible dahdi_test results


I remembered I have an older box with a Wildcard TE12xP that uses the wcte12xp module with a newer 3.9.11 kernel that works perfectly.

I setup the problematic machine with the same kernel in the hope that this might be relevant. Unfortunately the same situation persists.

I used the /proc/timer_stats to see how the timers were used:

Timer Stats Version: v0.2
Sample period: 10.002 s
....
311, 15081 kworker/u:0 mod_timer (te12xp_timer)
....

With the TE110P I couldn't find any entry.... It seems that the timing mechanism is different, it doesn't use mod_timer.

I'm running out of ideas. Please help.

Thanks,

Mike

On Tue, 2014-05-13 at 17:56 -0300, Mike Leddy wrote:

[mike at loop.com.br]

Hi Eric,

I plugged an E1 into the card and it doesn't make any difference.

# dahdi_test
Opened pseudo dahdi interface, measuring accuracy...
88.829% 87.806% 88.988% 88.854% 88.944% 88.952% 88.967% 88.841%
88.889% 88.946% 88.933% 88.841% 88.885% 89.050% 88.904% 87.933%
88.912% 88.949% 88.913% 88.886% 88.891% 88.798% 88.746% 89.009%
88.934% 88.870% 88.875% 89.003% 88.925% 88.863% 89.018% 88.093%
88.447% 88.691% 89.034% 88.703% 88.815% 89.011% 88.919% 88.825%
etc.

I will try the card in an older machine tomorrow.

Ironic is that i bought this card because it has a PCI express
interface so I can use it in recent servers.... but it uses an
older chipset and driver than I was using.

Thanks for the help,

Mike


On Wed, 2014-05-14 at 15:54 -0400, Eric Wieling wrote:

[rmeyerriecks at digium...]

On Wed, May 14, 2014 at 3:41 PM, Mike Leddy <mike@loop.com.br (mike@loop.com.br)> wrote:

[mike at loop.com.br]

Thanks again Russ,

I did as you described:

[ 1777.393179] dahdi: Version: 2.7.0.1
[ 1777.393995] dahdi: Telephony Interface Registered on major 196
[ 1789.943167] dahdi: Warning: Span DAHDI_DUMMY/1 didn't specify a
spantype. Please fix driver!
[ 1789.943865] dahdi_dummy: Trying to load High Resolution Timer
[ 1789.943869] dahdi_dummy: Initialized High Resolution Timer
[ 1789.943872] dahdi_dummy: Starting High Resolution Timer
[ 1789.943876] dahdi_dummy: High Resolution Timer started, good to go
[ 2816.078038] Setting up DMA (write/read = 00002000/00002200)
[ 2816.078054] Controller version: 24
[ 2816.079999] FALC version: 00000000
[ 2816.080284] TE110P: Setting up global serial parameters for E1 FALC
V1.2
[ 2816.080775] TE110P: Successfully initialized serial bus for card
[ 2816.084698] Found a Wildcard: Digium Wildcard TE110P T1/E1

There is a significant improvement:

# dahdi_test
Opened pseudo dahdi interface, measuring accuracy...
79.256% 99.401% 86.288% 95.736% 77.951% 94.636% 87.010% 97.638%
90.234% 97.651% 97.648% 91.744% 90.541% 92.671% 91.090% 91.118%
95.832% 96.503% 83.753% 97.642% 98.419% 81.845% 92.441% 99.142%
96.645% 88.332% 77.918% 97.651% 87.029% 69.357% 98.153% 89.980%
93.939% 86.579% 78.785% 98.497% 77.916% 82.414% 96.838% 97.061%
99.392% 94.414% 97.094% 99.095% 90.329% 97.678% 90.087% 93.631%
99.130% 97.379% 94.361% 97.653% 97.670% 77.946% 78.312% 95.465%
84.429% 97.640% 78.185% 97.910% 77.938% 78.314% 89.535% 83.030%
85.246% 84.128% 74.614% 87.055% 90.382% 79.477% 97.096% 90.822% ^C
--- Results after 72 passes ---
Best: 99.401% -- Worst: 69.357% -- Average: 90.260025%
Cummulative Accuracy (not per pass): 92.402

I suspect it may not be good enough yet for production but a
step in the right direction

Timer Stats Version: v0.2
Sample period: 10.013 s
....
10014, 9027 modprobe init_module (dahdi_dummy_hr_int)
....

I will test it on a live E1 soon.

Best regards,

Mike


On Wed, 2014-05-14 at 16:53 -0500, Russ Meyerriecks wrote:

[rmeyerriecks at digium...]

On Thu, May 15, 2014 at 9:10 AM, Mike Leddy <mike@loop.com.br (mike@loop.com.br)> wrote:

[mike at loop.com.br]

Hi Russ,

I rebooted the machine loading dahdi_dummy in /etc/modules before
the /etc/init.d/dahdi.

Now dahdi_test shows a nearly perfect score:

# dahdi_test
Opened pseudo dahdi interface, measuring accuracy...
99.998% 99.990% 99.998% 99.996% 99.998% 99.998% 99.997% 99.997%
99.998% 99.997% 99.998% 99.997% 99.998% 99.998% 99.997% 99.998%
99.997% 99.997% 99.997% 99.998% 99.997% 99.998% 99.998% 99.997% ^C
--- Results after 24 passes ---
Best: 99.998% -- Worst: 99.990% -- Average: 99.997188%
Cummulative Accuracy (not per pass): 99.997

When I connect a live E1 to the card it does work but I get a fair
number of:

[May 15 15:10:39] NOTICE[4017] chan_dahdi.c: PRI got event: HDLC Bad FCS ( on D-channel of span 1
[May 15 15:10:42] NOTICE[4017] chan_dahdi.c: PRI got event: HDLC Bad FCS ( on D-channel of span 1
[May 15 15:10:43] NOTICE[4017] chan_dahdi.c: PRI got event: HDLC Bad FCS ( on D-channel of span 1
[May 15 15:10:43] NOTICE[4017] chan_dahdi.c: PRI got event: HDLC Bad FCS ( on D-channel of span 1
[May 15 15:10:43] NOTICE[4017] chan_dahdi.c: PRI got event: HDLC Bad FCS ( on D-channel of span 1
[May 15 15:10:45] NOTICE[4017] chan_dahdi.c: PRI got event: HDLC Bad FCS ( on D-channel of span 1
[May 15 15:11:01] NOTICE[4017] chan_dahdi.c: PRI got event: HDLC Bad FCS ( on D-channel of span 1
[May 15 15:11:01] NOTICE[4017] chan_dahdi.c: PRI got event: HDLC Bad FCS ( on D-channel of span 1
[May 15 15:11:06] NOTICE[4017] chan_dahdi.c: PRI got event: HDLC Bad FCS ( on D-channel of span 1
[May 15 15:11:12] NOTICE[4017] chan_dahdi.c: PRI got event: HDLC Bad FCS ( on D-channel of span 1
[May 15 15:11:12] NOTICE[4017] chan_dahdi.c: PRI got event: HDLC Bad FCS ( on D-channel of span 1
[May 15 15:11:12] NOTICE[4017] chan_dahdi.c: PRI got event: HDLC Bad FCS ( on D-channel of span 1
[May 15 15:11:13] NOTICE[4017] chan_dahdi.c: PRI got event: HDLC Bad FCS ( on D-channel of span 1

Resulting in:

[May 15 15:10:34] NOTICE[4017] chan_dahdi.c: PRI got event: Alarm (4) on D-channel of span 1
[May 15 15:10:39] NOTICE[4017] chan_dahdi.c: PRI got event: Alarm (4) on D-channel of span 1
[May 15 15:10:43] NOTICE[4017] chan_dahdi.c: PRI got event: Alarm (4) on D-channel of span 1
[May 15 15:10:44] NOTICE[4017] chan_dahdi.c: PRI got event: Alarm (4) on D-channel of span 1
[May 15 15:10:45] NOTICE[4017] chan_dahdi.c: PRI got event: Alarm (4) on D-channel of span 1
[May 15 15:11:13] NOTICE[4017] chan_dahdi.c: PRI got event: Alarm (4) on D-channel of span 1
[May 15 15:11:17] NOTICE[4017] chan_dahdi.c: PRI got event: Alarm (4) on D-channel of span 1
[May 15 15:11:22] NOTICE[4017] chan_dahdi.c: PRI got event: Alarm (4) on D-channel of span 1

Not usable in production but getting a lot closer.

Is there anything else that can be done to improve this ?

Best regards,

Mike


--
_____________________________________________________________________
-- Bandwidth and Colocation Provided by http://www.api-digital.com --
New to Asterisk? Join us for a live introductory webinar every Thurs:
http://www.asterisk.org/hello

asterisk-users mailing list
To UNSUBSCRIBE or update options visit:
http://lists.digium.com/mailman/listinfo/asterisk-users

[mike at loop.com.br]

Hi Russ,

Sorry I didn't send that... Here's a few runs:

# cat /proc/interrupts | grep wc && sleep 1 && cat /proc/interrupts | grep wc
28: 1682906 0 0 0 0 0 0 0 0 0 0 0 IR-IO-APIC-fasteoi wcte11xp
28: 1683913 0 0 0 0 0 0 0 0 0 0 0 IR-IO-APIC-fasteoi wcte11xp

= 1007

# cat /proc/interrupts | grep wc && sleep 1 && cat /proc/interrupts | grep wc
28: 1690587 0 0 0 0 0 0 0 0 0 0 0 IR-IO-APIC-fasteoi wcte11xp
28: 1691594 0 0 0 0 0 0 0 0 0 0 0 IR-IO-APIC-fasteoi wcte11xp

= 1007

# cat /proc/interrupts | grep wc && sleep 1 && cat /proc/interrupts | grep wc
28: 1695091 0 0 0 0 0 0 0 0 0 0 0 IR-IO-APIC-fasteoi wcte11xp
28: 1696100 0 0 0 0 0 0 0 0 0 0 0 IR-IO-APIC-fasteoi wcte11xp

= 1009

# cat /proc/interrupts | grep wc && sleep 1 && cat /proc/interrupts | grep wc
28: 1700363 0 0 0 0 0 0 0 0 0 0 0 IR-IO-APIC-fasteoi wcte11xp
28: 1701370 0 0 0 0 0 0 0 0 0 0 0 IR-IO-APIC-fasteoi wcte11xp

= 1007


Best regards,

Mike

On Thu, 2014-05-15 at 10:13 -0500, Russ Meyerriecks wrote:

[mailinglist+asterisk a...]

On 15/05/14 16:28, Mike Leddy wrote:

[mike at loop.com.br]

Thanks for the suggestion Gareth,

The span line I'm using is:

span=1,1,0,ccs,hdb3,crc4

Its the same as used with the TE12xP that is normally used on this
E1 line in production which is extremely stable.

I did as you suggested using:

span=1,0,0,ccs,hdb3,crc4

After a dahdi_cfg pretty much the same results:

[May 15 17:35:24] NOTICE[4017] chan_dahdi.c: PRI got event: Alarm (4) on D-channel of span 1
[May 15 17:35:24] NOTICE[4017] chan_dahdi.c: PRI got event: Alarm (4) on D-channel of span 1
[May 15 17:35:32] NOTICE[4017] chan_dahdi.c: PRI got event: Alarm (4) on D-channel of span 1
[May 15 17:35:36] NOTICE[4017] chan_dahdi.c: PRI got event: Alarm (4) on D-channel of span 1
[May 15 17:36:01] NOTICE[4017] chan_dahdi.c: PRI got event: Alarm (4) on D-channel of span 1
[May 15 17:36:05] NOTICE[4017] chan_dahdi.c: PRI got event: Alarm (4) on D-channel of span 1
[May 15 17:36:12] NOTICE[4017] chan_dahdi.c: PRI got event: Alarm (4) on D-channel of span 1
[May 15 17:36:13] NOTICE[4017] chan_dahdi.c: PRI got event: Alarm (4) on D-channel of span 1
[May 15 17:36:21] NOTICE[4017] chan_dahdi.c: PRI got event: Alarm (4) on D-channel of span 1
[May 15 17:36:21] NOTICE[4017] chan_dahdi.c: PRI got event: Alarm (4) on D-channel of span 1
[May 15 17:36:25] NOTICE[4017] chan_dahdi.c: PRI got event: Alarm (4) on D-channel of span 1

Best regards,

Mike

On Thu, 2014-05-15 at 17:53 +0100, Gareth Blades wrote: