High Drop By Jitters and Choppy Calls on ChanSpy

jingjong · August 5, 2014, 7:42pm

Hi All,

Badly need some help about our current ChanSpy bad audio problem.

Currently when we are doing a ChanSpy on a specific channel/ext or random chanspy using 555 a default FreePBX feature code we are getting high drop by jitters and choppy calls, actual calls from an agent and customers doesn’t have any audio issues and the bad audio is only experienced from the chanspy. And only chanspy to a call with customers through sip trunks and agents. Chanspy to a extension to extension calls doesn’t recreate the problem.

Any help is highly appreciated. Thank you in advance.

Below are some details.

Wireshark RTP Player Screenshot

cpu utilization during testing and when bad audio is experienced.

Some details about the server cpu specs

Asterisk version: 1.8.26.1
FreePBX Version: 2.11.0.38

Codec used: uLaw G711

I can’t remember the distro version we used.

Dialplan used for chanspy
[from-internal-custom]
exten => _*555X.,1,Macro(user-callerid,)
exten => _*555X.,2,Authenticate(1111)
exten => _*555X.,n,Answer
exten => _*555X.,n,Wait(1)
exten => _*555X.,n,ChanSpy(SIP/${EXTEN:4})
exten => _*555X.,n,Hangup

Asterisk Logs during testing

[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [*[email protected]:1] Macro("SIP/4000-00000304", "user-callerid,") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:1] Set("SIP/4000-00000304", "TOUCH_MONITOR=1407267335.2188") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:2] Set("SIP/4000-00000304", "AMPUSER=4000") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:3] GotoIf("SIP/4000-00000304", "0?report") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:4] ExecIf("SIP/4000-00000304", "1?Set(REALCALLERIDNUM=4000)") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:5] Set("SIP/4000-00000304", "AMPUSER=4000") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:6] GotoIf("SIP/4000-00000304", "0?limit") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:7] Set("SIP/4000-00000304", "AMPUSERCIDNAME=ClientAstig 4000") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:8] GotoIf("SIP/4000-00000304", "0?report") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:9] Set("SIP/4000-00000304", "AMPUSERCID=4000") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:10] Set("SIP/4000-00000304", "__DIAL_OPTIONS=Ttr") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:11] Set("SIP/4000-00000304", "CALLERID(all)="ClientAstig 4000" <4000>") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:12] GotoIf("SIP/4000-00000304", "0?limit") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:13] ExecIf("SIP/4000-00000304", "0?Set(GROUP(concurrency_limit)=4000)") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:14] GosubIf("SIP/4000-00000304", "7?sub-ccss,s,1(from-internal,*555653)") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:1] ExecIf("SIP/4000-00000304", "0?Return()") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:2] Set("SIP/4000-00000304", "CCSS_SETUP=TRUE") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:3] GosubIf("SIP/4000-00000304", "0?monitor_config,1(from-internal,*555653):monitor_default,1(from-internal,*555653)") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:1] GotoIf("SIP/4000-00000304", "0?is_exten") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:2] StackPop("SIP/4000-00000304", "") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:3] Return("SIP/4000-00000304", "FALSE") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:15] ExecIf("SIP/4000-00000304", "0?Set(CHANNEL(language)=)") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:16] GotoIf("SIP/4000-00000304", "0?continue") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:17] Set("SIP/4000-00000304", "__TTL=64") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:18] GotoIf("SIP/4000-00000304", "1?continue") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Goto (macro-user-callerid,s,29)
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:29] Set("SIP/4000-00000304", "CALLERID(number)=4000") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:30] Set("SIP/4000-00000304", "CALLERID(name)=ClientAstig 4000") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:31] Set("SIP/4000-00000304", "CDR(cnum)=4000") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:32] Set("SIP/4000-00000304", "CDR(cnam)=ClientAstig 4000") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [[email protected]:33] Set("SIP/4000-00000304", "CHANNEL(language)=en") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] pbx.c: -- Executing [*[email protected]:2] Authenticate("SIP/4000-00000304", "1234") in new stack
[2014-08-05 12:35:35] VERBOSE[16659] file.c: -- <SIP/4000-00000304> Playing 'agent-pass.ulaw' (language 'en')
[2014-08-05 12:35:38] VERBOSE[16659] file.c: -- <SIP/4000-00000304> Playing 'auth-thankyou.ulaw' (language 'en')
[2014-08-05 12:35:39] VERBOSE[16659] pbx.c: -- Executing [*[email protected]:3] Answer("SIP/4000-00000304", "") in new stack
[2014-08-05 12:35:39] VERBOSE[16659] pbx.c: -- Executing [*[email protected]:4] Wait("SIP/4000-00000304", "1") in new stack
[2014-08-05 12:35:40] VERBOSE[16659] pbx.c: -- Executing [*[email protected]:5] ChanSpy("SIP/4000-00000304", "SIP/653") in new stack
[2014-08-05 12:35:40] VERBOSE[16659] file.c: -- <SIP/4000-00000304> Playing 'beep.ulaw' (language 'en')
[2014-08-05 12:35:41] VERBOSE[16659] file.c: -- <SIP/4000-00000304> Playing 'spy-sip.ulaw' (language 'en')
[2014-08-05 12:35:41] VERBOSE[16659] file.c: -- <SIP/4000-00000304> Playing 'digits/6.ulaw' (language 'en')
[2014-08-05 12:35:42] VERBOSE[16659] file.c: -- <SIP/4000-00000304> Playing 'digits/5.ulaw' (language 'en')
[2014-08-05 12:35:43] VERBOSE[16659] file.c: -- <SIP/4000-00000304> Playing 'digits/3.ulaw' (language 'en')
[2014-08-05 12:35:43] VERBOSE[16659] app_chanspy.c: == Spying on channel SIP/653-00000301
[2014-08-05 12:35:43] NOTICE[16659] app_chanspy.c: Attaching SIP/4000-00000304 to SIP/653-00000301
[2014-08-05 12:35:51] VERBOSE[16659] app_chanspy.c: == Done Spying on channel SIP/653-00000301
[2014-08-05 12:35:51] VERBOSE[16659] pbx.c: == Spawn extension (from-internal, *555653, 5) exited non-zero on 'SIP/4000-00000304'
[2014-08-05 12:35:51] VERBOSE[16659] pbx.c: -- Executing [[email protected]:1] Hangup("SIP/4000-00000304", "") in new stack
[2014-08-05 12:35:51] VERBOSE[16659] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/4000-00000304'
[2014-08-05 12:35:52] VERBOSE[6929] netsock2.c: == Using SIP RTP TOS bits 184
[2014-08-05 12:35:52] VERBOSE[6929] netsock2.c: == Using SIP RTP CoS mark 5
[2014-08-05 12:35:52] VERBOSE[16679] pbx.c: -- Executing [[email protected]:1] GotoIf("SIP/4000-00000305", "0?is_exten") in new stack
[2014-08-05 12:35:52] VERBOSE[16679] pbx.c: -- Executing [[email protected]:2] StackPop("SIP/4000-00000305", "") in new stack
[2014-08-05 12:35:52] VERBOSE[16679] pbx.c: -- Executing [[email protected]:3] Return("SIP/4000-00000305", "FALSE") in new stack
[2014-08-05 12:35:52] VERBOSE[16679] pbx.c: -- Executing [[email protected]:15] ExecIf("SIP/4000-00000305", "0?Set(CHANNEL(language)=)") in new stack
[2014-08-05 12:35:52] VERBOSE[16679] pbx.c: -- Executing [[email protected]:16] GotoIf("SIP/4000-00000305", "0?continue") in new stack
[2014-08-05 12:35:52] VERBOSE[16679] pbx.c: -- Executing [[email protected]:17] Set("SIP/4000-00000305", "__TTL=64") in new stack
[2014-08-05 12:35:52] VERBOSE[16679] pbx.c: -- Executing [[email protected]:18] GotoIf("SIP/4000-00000305", "1?continue") in new stack
[2014-08-05 12:35:52] VERBOSE[16679] pbx.c: -- Goto (macro-user-callerid,s,29)
[2014-08-05 12:35:52] VERBOSE[16679] pbx.c: -- Executing [[email protected]:29] Set("SIP/4000-00000305", "CALLERID(number)=4000") in new stack
[2014-08-05 12:35:52] VERBOSE[16679] pbx.c: -- Executing [[email protected]:30] Set("SIP/4000-00000305", "CALLERID(name)=ClientAstig 4000") in new stack
[2014-08-05 12:35:52] VERBOSE[16679] pbx.c: -- Executing [[email protected]:31] Set("SIP/4000-00000305", "CDR(cnum)=4000") in new stack
[2014-08-05 12:35:52] VERBOSE[16679] pbx.c: -- Executing [[email protected]:32] Set("SIP/4000-00000305", "CDR(cnam)=ClientAstig 4000") in new stack
[2014-08-05 12:35:52] VERBOSE[16679] pbx.c: -- Executing [[email protected]:33] Set("SIP/4000-00000305", "CHANNEL(language)=en") in new stack
[2014-08-05 12:35:52] VERBOSE[16679] pbx.c: -- Executing [*[email protected]:2] Authenticate("SIP/4000-00000305", "1234") in new stack
[2014-08-05 12:35:52] VERBOSE[16679] file.c: -- <SIP/4000-00000305> Playing 'agent-pass.ulaw' (language 'en')
[2014-08-05 12:35:55] VERBOSE[16679] file.c: -- <SIP/4000-00000305> Playing 'auth-incorrect.ulaw' (language 'en')
[2014-08-05 12:36:01] VERBOSE[16679] file.c: -- <SIP/4000-00000305> Playing 'auth-thankyou.ulaw' (language 'en')
[2014-08-05 12:36:02] VERBOSE[16679] pbx.c: -- Executing [*[email protected]:3] Answer("SIP/4000-00000305", "") in new stack
[2014-08-05 12:36:02] VERBOSE[16679] pbx.c: -- Executing [*[email protected]:4] Wait("SIP/4000-00000305", "1") in new stack
[2014-08-05 12:36:03] VERBOSE[16679] pbx.c: -- Executing [*[email protected]:5] ChanSpy("SIP/4000-00000305", "SIP/653") in new stack
[2014-08-05 12:36:03] VERBOSE[16679] file.c: -- <SIP/4000-00000305> Playing 'beep.ulaw' (language 'en')
[2014-08-05 12:36:03] VERBOSE[16679] file.c: -- <SIP/4000-00000305> Playing 'spy-sip.ulaw' (language 'en')
[2014-08-05 12:36:04] VERBOSE[16679] file.c: -- <SIP/4000-00000305> Playing 'digits/6.ulaw' (language 'en')
[2014-08-05 12:36:05] VERBOSE[16679] file.c: -- <SIP/4000-00000305> Playing 'digits/5.ulaw' (language 'en')
[2014-08-05 12:36:05] VERBOSE[16679] file.c: -- <SIP/4000-00000305> Playing 'digits/3.ulaw' (language 'en')
[2014-08-05 12:36:06] VERBOSE[16679] app_chanspy.c: == Spying on channel SIP/653-00000301
[2014-08-05 12:36:06] NOTICE[16679] app_chanspy.c: Attaching SIP/4000-00000305 to SIP/653-00000301
[2014-08-05 12:36:27] VERBOSE[16679] app_chanspy.c: == Done Spying on channel SIP/653-00000301
[2014-08-05 12:36:27] VERBOSE[16679] pbx.c: == Spawn extension (from-internal, *555653, 5) exited non-zero on 'SIP/4000-00000305'
[2014-08-05 12:36:27] VERBOSE[16679] pbx.c: -- Executing [[email protected]:1] Hangup("SIP/4000-00000305", "") in new stack
[2014-08-05 12:36:27] VERBOSE[16679] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/4000-00000305'

jfinstrom · August 5, 2014, 7:58pm

Sip debug may be useful… maybe a filtered subset of the pcap?

Is the monitoring phone on the same network?
Can you do a sip show for all 3 channels.

jingjong · August 5, 2014, 8:10pm

Hi jfinstrom,

Thanks a lot for the fast reply.

SIP Debug from WireShark? How would I do that?

Monitoring phone is from same network. Monitored calls on an extension to extension calls doesn’t recreate the problem too.

So far on chanspy experience this type of problem.

Thanks

jfinstrom · August 5, 2014, 8:12pm

Can you provide the output of

sip show channel <call-id> for a call and the trunk

dicko · August 5, 2014, 8:32pm

You don’t say anything about your system, but I believe you will need either dahdi or res_timing_timerfd compiled into asterisk for chanspy to work as it uses audiohooks.

jingjong · August 5, 2014, 8:42pm

Hi jfinstrom,

Inbound Call Through SIP Strunks , sorry I need to mask the IP. Thanks

* SIP Call
  Curr. trans. direction:  Incoming
  Call-ID:                SD88cu502-b1014b5f593610d84dfe9c54daddb04b-06a91i1
  Owner channel ID:       SIP/InboundTrunk-0000039c
  Our Codec Capability:   0x4 (ulaw)
  Non-Codec Capability (DTMF):   1
  Their Codec Capability:   0x104 (ulaw|g729)
  Joint Codec Capability:   0x4 (ulaw)
  Format:                 0x4 (ulaw)
  T.38 support            No
  Video support           No
  MaxCallBR:              384 kbps
  Theoretical Address:    x.x.x.110:5060
  Received Address:       x.x.x.110:5060
  SIP Transfer mode:      open
  Force rport:            No
  Audio IP:               x.x.x.x (local)
  Our Tag:                as56cdd85a
  Their Tag:              SD88cu502-14c02ea8+1+a1890051+a09bb6a4
  SIP User agent:         
  Peername:               InboundTrunk
  Original uri:           sip:[email protected]:5060
  Caller-ID:              14001
  Need Destroy:           No
  Last Message:           Rx: ACK
  Promiscuous Redir:      No
  Route:                  sip:[email protected]:5060;user=phone;transport=udp
  DTMF Mode:              rfc2833
  SIP Options:            (none)
  Session-Timer:          Inactive


Call Monitoring Channel info

* SIP Call
  Curr. trans. direction:  Incoming
  Call-ID:                MmIyZjcyYzIxYjRiMTYyNGFlMjU3YWZiMWRlYzY4M2M.
  Owner channel ID:       SIP/4000-000003ab
  Our Codec Capability:   0x10e (gsm|ulaw|alaw|g729)
  Non-Codec Capability (DTMF):   1
  Their Codec Capability:   0x4 (ulaw)
  Joint Codec Capability:   0x4 (ulaw)
  Format:                 0x4 (ulaw)
  T.38 support            No
  Video support           No
  MaxCallBR:              384 kbps
  Theoretical Address:    x.x.x.6:25332
  Received Address:       x.x.x.0.6:25332
  SIP Transfer mode:      open
  Force rport:            No
  Audio IP:               x.x.x.102 (local)
  Our Tag:                as7c3d48c2
  Their Tag:              3f75900f
  SIP User agent:         eyeBeam release 1102q stamp 51814
  Username:               4000
  Peername:               4000
  Original uri:           sip:[email protected]:25332
  Caller-ID:              4000
  Need Destroy:           No
  Last Message:           Rx: ACK
  Promiscuous Redir:      No
  Route:                  sip:[email protected]:25332
  DTMF Mode:              rfc2833
  SIP Options:            (none)
  Session-Timer:          Inactive

jingjong · August 5, 2014, 8:44pm

Hi dicko,

I am using FreePBX distro. I can’t remember the exact distro version but I think I downloaded the distro around May of this year.

By the way ChanSpy sometimes work with very less Jitters on Agent to Customers(through SIP trunks) but most of the time it doesn’t.

Thanks

dicko · August 5, 2014, 8:47pm

You still don’t say anything about your hardware, are you by any chance “virtualized” ?

(it has nothing to do with the channel technology, SIP, DAHDI, IAX3 all are covered , it works at a lower level on the audio stream, see if any conferences you build are similarly afflicted.)

dicko · August 5, 2014, 8:48pm

(well maybe not IAX3 )

jingjong · August 5, 2014, 8:51pm

Hi Dicko,

This not a virtualized server but a physical server.

CPU

cat /proc/cpuinfo
processor       : 0
vendor_id       : GenuineIntel
cpu family      : 6
model           : 42
model name      : Intel(R) Core(TM) i7-2600 CPU @ 3.40GHz
stepping        : 7
cpu MHz         : 3392.470
cache size      : 8192 KB
physical id     : 0
siblings        : 8
core id         : 0
cpu cores       : 4
apicid          : 0
initial apicid  : 0
fpu             : yes
fpu_exception   : yes
cpuid level     : 13
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx rdtscp lm constant_tsc arch_perfmon pebs bts rep_good xtopology nonstop_tsc aperfmperf pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer aes xsave avx lahf_lm ida arat epb xsaveopt pln pts dts tpr_shadow vnmi flexpriority ept vpid
bogomips        : 6784.94
clflush size    : 64
cache_alignment : 64
address sizes   : 36 bits physical, 48 bits virtual
power management:

processor       : 1
vendor_id       : GenuineIntel
cpu family      : 6
model           : 42
model name      : Intel(R) Core(TM) i7-2600 CPU @ 3.40GHz
stepping        : 7
cpu MHz         : 3392.470
cache size      : 8192 KB
physical id     : 0
siblings        : 8
core id         : 1
cpu cores       : 4
apicid          : 2
initial apicid  : 2
fpu             : yes
fpu_exception   : yes
cpuid level     : 13
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx rdtscp lm constant_tsc arch_perfmon pebs bts rep_good xtopology nonstop_tsc aperfmperf pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer aes xsave avx lahf_lm ida arat epb xsaveopt pln pts dts tpr_shadow vnmi flexpriority ept vpid
bogomips        : 6784.94
clflush size    : 64
cache_alignment : 64
address sizes   : 36 bits physical, 48 bits virtual
power management:

processor       : 2
vendor_id       : GenuineIntel
cpu family      : 6
model           : 42
model name      : Intel(R) Core(TM) i7-2600 CPU @ 3.40GHz
stepping        : 7
cpu MHz         : 3392.470
cache size      : 8192 KB
physical id     : 0
siblings        : 8
core id         : 2
cpu cores       : 4
apicid          : 4
initial apicid  : 4
fpu             : yes
fpu_exception   : yes
cpuid level     : 13
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx rdtscp lm constant_tsc arch_perfmon pebs bts rep_good xtopology nonstop_tsc aperfmperf pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer aes xsave avx lahf_lm ida arat epb xsaveopt pln pts dts tpr_shadow vnmi flexpriority ept vpid
bogomips        : 6784.94
clflush size    : 64
cache_alignment : 64
address sizes   : 36 bits physical, 48 bits virtual
power management:

processor       : 3
vendor_id       : GenuineIntel
cpu family      : 6
model           : 42
model name      : Intel(R) Core(TM) i7-2600 CPU @ 3.40GHz
stepping        : 7
cpu MHz         : 3392.470
cache size      : 8192 KB
physical id     : 0
siblings        : 8
core id         : 3
cpu cores       : 4
apicid          : 6
initial apicid  : 6
fpu             : yes
fpu_exception   : yes
cpuid level     : 13
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx rdtscp lm constant_tsc arch_perfmon pebs bts rep_good xtopology nonstop_tsc aperfmperf pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer aes xsave avx lahf_lm ida arat epb xsaveopt pln pts dts tpr_shadow vnmi flexpriority ept vpid
bogomips        : 6784.94
clflush size    : 64
cache_alignment : 64
address sizes   : 36 bits physical, 48 bits virtual
power management:

processor       : 4
vendor_id       : GenuineIntel
cpu family      : 6
model           : 42
model name      : Intel(R) Core(TM) i7-2600 CPU @ 3.40GHz
stepping        : 7
cpu MHz         : 3392.470
cache size      : 8192 KB
physical id     : 0
siblings        : 8
core id         : 0
cpu cores       : 4
apicid          : 1
initial apicid  : 1
fpu             : yes
fpu_exception   : yes
cpuid level     : 13
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx rdtscp lm constant_tsc arch_perfmon pebs bts rep_good xtopology nonstop_tsc aperfmperf pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer aes xsave avx lahf_lm ida arat epb xsaveopt pln pts dts tpr_shadow vnmi flexpriority ept vpid
bogomips        : 6784.94
clflush size    : 64
cache_alignment : 64
address sizes   : 36 bits physical, 48 bits virtual
power management:

processor       : 5
vendor_id       : GenuineIntel
cpu family      : 6
model           : 42
model name      : Intel(R) Core(TM) i7-2600 CPU @ 3.40GHz
stepping        : 7
cpu MHz         : 3392.470
cache size      : 8192 KB
physical id     : 0
siblings        : 8
core id         : 1
cpu cores       : 4
apicid          : 3
initial apicid  : 3
fpu             : yes
fpu_exception   : yes
cpuid level     : 13
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx rdtscp lm constant_tsc arch_perfmon pebs bts rep_good xtopology nonstop_tsc aperfmperf pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer aes xsave avx lahf_lm ida arat epb xsaveopt pln pts dts tpr_shadow vnmi flexpriority ept vpid
bogomips        : 6784.94
clflush size    : 64
cache_alignment : 64
address sizes   : 36 bits physical, 48 bits virtual
power management:

processor       : 6
vendor_id       : GenuineIntel
cpu family      : 6
model           : 42
model name      : Intel(R) Core(TM) i7-2600 CPU @ 3.40GHz
stepping        : 7
cpu MHz         : 3392.470
cache size      : 8192 KB
physical id     : 0
siblings        : 8
core id         : 2
cpu cores       : 4
apicid          : 5
initial apicid  : 5
fpu             : yes
fpu_exception   : yes
cpuid level     : 13
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx rdtscp lm constant_tsc arch_perfmon pebs bts rep_good xtopology nonstop_tsc aperfmperf pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer aes xsave avx lahf_lm ida arat epb xsaveopt pln pts dts tpr_shadow vnmi flexpriority ept vpid
bogomips        : 6784.94
clflush size    : 64
cache_alignment : 64
address sizes   : 36 bits physical, 48 bits virtual
power management:

processor       : 7
vendor_id       : GenuineIntel
cpu family      : 6
model           : 42
model name      : Intel(R) Core(TM) i7-2600 CPU @ 3.40GHz
stepping        : 7
cpu MHz         : 3392.470
cache size      : 8192 KB
physical id     : 0
siblings        : 8
core id         : 3
cpu cores       : 4
apicid          : 7
initial apicid  : 7
fpu             : yes
fpu_exception   : yes
cpuid level     : 13
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx rdtscp lm constant_tsc arch_perfmon pebs bts rep_good xtopology nonstop_tsc aperfmperf pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer aes xsave avx lahf_lm ida arat epb xsaveopt pln pts dts tpr_shadow vnmi flexpriority ept vpid
bogomips        : 6784.94
clflush size    : 64
cache_alignment : 64
address sizes   : 36 bits physical, 48 bits virtual
power management:

Memory

cat /proc/meminfo
MemTotal:        8004324 kB
MemFree:          129012 kB
Buffers:          203816 kB
Cached:          6602684 kB
SwapCached:         1780 kB
Active:           830752 kB
Inactive:        6649920 kB
Active(anon):     320528 kB
Inactive(anon):   354228 kB
Active(file):     510224 kB
Inactive(file):  6295692 kB
Unevictable:           0 kB
Mlocked:               0 kB
SwapTotal:       8142840 kB
SwapFree:        8118744 kB
Dirty:              4520 kB
Writeback:             0 kB
AnonPages:        676848 kB
Mapped:            32056 kB
Shmem:               536 kB
Slab:             292540 kB
SReclaimable:     254328 kB
SUnreclaim:        38212 kB
KernelStack:        2672 kB
PageTables:        14532 kB
NFS_Unstable:          0 kB
Bounce:                0 kB
WritebackTmp:          0 kB
CommitLimit:    12145000 kB
Committed_AS:    1152980 kB
VmallocTotal:   34359738367 kB
VmallocUsed:      362728 kB
VmallocChunk:   34359336076 kB
HardwareCorrupted:     0 kB
AnonHugePages:    325632 kB
HugePages_Total:       0
HugePages_Free:        0
HugePages_Rsvd:        0
HugePages_Surp:        0
Hugepagesize:       2048 kB
DirectMap4k:        8192 kB
DirectMap2M:     8329216 kB

dicko · August 5, 2014, 8:58pm

Is dahdi installed and working? post the issue of:-

dahdi_test -vv -c 30

jingjong · August 5, 2014, 9:01pm

dahdi_test -vv -c 30

Opened pseudo dahdi interface, measuring accuracy...
8192 samples in 8191.641 system clock sample intervals (99.996%)
8192 samples in 8191.503 system clock sample intervals (99.994%)
8192 samples in 8191.856 system clock sample intervals (99.998%)
8192 samples in 8192.089 system clock sample intervals (99.999%)
8192 samples in 8191.833 system clock sample intervals (99.998%)
8192 samples in 8199.567 system clock sample intervals (99.908%)
8192 samples in 8191.985 system clock sample intervals (100.000%)
8192 samples in 8191.640 system clock sample intervals (99.996%)
8192 samples in 8200.023 system clock sample intervals (99.902%)
8192 samples in 8167.800 system clock sample intervals (99.705%)
8192 samples in 8191.839 system clock sample intervals (99.998%)
8192 samples in 8199.784 system clock sample intervals (99.905%)
8192 samples in 8191.824 system clock sample intervals (99.998%)
8192 samples in 8191.809 system clock sample intervals (99.998%)
8192 samples in 8191.816 system clock sample intervals (99.998%)
8192 samples in 8199.809 system clock sample intervals (99.905%)
8192 samples in 8191.815 system clock sample intervals (99.998%)
8192 samples in 8191.800 system clock sample intervals (99.998%)
8192 samples in 8191.840 system clock sample intervals (99.998%)
8192 samples in 8191.528 system clock sample intervals (99.994%)
8192 samples in 8191.896 system clock sample intervals (99.999%)
8192 samples in 8191.984 system clock sample intervals (100.000%)
8192 samples in 8199.832 system clock sample intervals (99.904%)
8192 samples in 8191.536 system clock sample intervals (99.994%)
8192 samples in 8192.128 system clock sample intervals (99.998%)
8192 samples in 8191.521 system clock sample intervals (99.994%)
8192 samples in 8167.911 system clock sample intervals (99.706%)
8192 samples in 8199.752 system clock sample intervals (99.905%)
8192 samples in 8199.824 system clock sample intervals (99.904%)
8192 samples in 8191.720 system clock sample intervals (99.997%)
--- Results after 30 passes ---
Best: 100.000% -- Worst: 99.705% -- Average: 99.956173%
Cummulative Accuracy (not per pass): 99.999

dicko · August 5, 2014, 9:03pm

Thn that’s probably your problem, peruse

man dahdi_test

jingjong · August 5, 2014, 9:11pm

Hi Dicko,

Not sure what you mean.

dicko · August 5, 2014, 9:14pm

anything less than 99.97% is pretty well guaranteed to cause audio problems, you are failing bout 25% of your tests.

(man in lunux is short for manual, hence

man dahdi_test

will print the manual, Thta will substantiate my claim. does that help tou understand what I mean? )

jingjong · August 5, 2014, 9:20pm

Any idea how to improve this? What are the possible reason about going below 100%?

Thanks

dicko · August 5, 2014, 9:24pm

MotherBoard, BIOS settings, kernel system overload, who knows. you can get a chinese digium knockoff on ebay (no modules needed, so ethically I don’t feel bad about recommending that course ) for $20 on ebay if you can’t get your pseudo-timer working adequately.

jingjong · August 6, 2014, 12:12am

Replaced the intel nic where the ISP is configured with a spare one and looks I am seeing some improvements. It’s too early to celebrate though because it’s already off production hours. Will see tomorrow.

Thanks Dicko and jfinstrom for spending some time…

dicko · August 6, 2014, 1:21am

It might seem better, but I’m pretty sure it’s not, the NIC has no relation to the problem unless it is a completely broken driver (wild guess, an e1000 on Centos ?)

jingjong · August 6, 2014, 1:55am

Yep,

driver: e1000
version: 7.3.21-k8-NAPI
firmware-version:
bus-info: 0000:04:00.0
supports-statistics: yes
supports-test: yes
supports-eeprom-access: yes
supports-register-dump: yes
supports-priv-flags: no

Do you have any reference on how to get updated driver for Centos? If there is one already.

Thanks