Summary:	DAHLIN-00252: wct4xxp messages
Reporter:	agustina (agustina)	Labels:
Date Opened:	2011-08-31 15:11:05	Date Closed:	2011-08-31 15:40:27
Priority:	Major	Regression?
Status:	Closed/Complete	Components:
Versions:		Frequency of Occurrence
Related Issues:
Environment:		Attachments:
Description:	I have: dahdi-linux-complete-2.4.1+2.4.1 libpri-1.4.11.5 Two E1 PRI Connections, one to a Alcatel OXE. Once or twice a week the asterisk service restarts automatically. And in the log /var/log/messages I see the following message at the time of the restart: Aug 26 11:50:56 localhost kernel: wct4xxp 0000:11:08.0: Need to increase latency.  Estimated latency should be 5 Aug 26 11:50:56 localhost kernel: wct4xxp 0000:11:08.0: DMA memory base of size 10240 at f5394000.  Read: f5395400 and Write f5394000 Aug 26 11:50:56 localhost kernel: wct4xxp 0000:11:08.0: Increased latency to 5 Other messages I see are: Aug 26 17:48:25 localhost kernel: wct4xxp 0000:11:08.0: TE2XXP: Span 1 configured for CCS/HDB3 Aug 26 17:48:25 localhost kernel: wct4xxp 0000:11:08.0: RCLK source set to span 2 Aug 26 17:48:25 localhost kernel: wct4xxp 0000:11:08.0: Recovered timing mode, RCLK set to span 2 Aug 26 17:48:25 localhost kernel: wct4xxp 0000:11:08.0: TE2XXP: Span 2 configured for CCS/HDB3 Aug 26 17:48:25 localhost kernel: wct4xxp 0000:11:08.0: RCLK source set to span 2 Aug 26 17:48:25 localhost kernel: wct4xxp 0000:11:08.0: Recovered timing mode, RCLK set to span 2 Aug 26 17:48:25 localhost kernel: wct4xxp 0000:11:08.0: SPAN 2: Primary Sync Source Can anybody tell me what do this messages mean?
Comments:	By: Michael Spiceland (mspiceland) 2011-08-31 15:40:15.877-0500 If you have further questions like this, it is probably best to ask on the asterisk-users list or IRC. {quote} Can anybody tell me what do this messages mean? {quote} I'll give it a shot.  None of those messages look to be anything to worry about. {quote} Once or twice a week the asterisk service restarts automatically. And in the log /var/log/messages I see the following message at the time of the restart: Aug 26 11:50:56 localhost kernel: wct4xxp 0000:11:08.0: Need to increase latency. Estimated latency should be 5 Aug 26 11:50:56 localhost kernel: wct4xxp 0000:11:08.0: DMA memory base of size 10240 at f5394000. Read: f5395400 and Write f5394000 Aug 26 11:50:56 localhost kernel: wct4xxp 0000:11:08.0: Increased latency to 5 {quote} This means that your wct4xxp card detected that it needed 5ms of buffering due to system latency.  If it doesn't increase beyond that, it shouldn't be an indication that anything is wrong. System "latency" refers to the delay of the system when processing interrupts.  When the card has data for the system, it asserts an interrupt saying that it is ready to be processed.  Due to lots of different criteria including the speed of the system, the configuration of the kernel, the version of the kernel, BIOS for the motherboard, and non-maskable interrupts, this delay can vary.  Most of the DAHDI hardware interrupts at once every 1ms.  If the interrupt handler does not run within that time, some sort of buffering is required between the times the interrupt is serviced.  For most all of the Digium cards, they have a feature called dynamic buffering.  This allows them to perform without data loss, even on systems they otherwise could not work well in.  This is because adding additionally buffering ads a delay.  Once that delay is large enough, it can become a problem.  In your case, 5ms is nothing to worry about.  The Digium dynamic buffering mechanisms attempt to keep the delay as small as possible but increase it when it detects that it is needed.  This message is simply an indication that it detected your system needed 5ms of buffering. {quote} Other messages I see are: Aug 26 17:48:25 localhost kernel: wct4xxp 0000:11:08.0: TE2XXP: Span 1 configured for CCS/HDB3 Aug 26 17:48:25 localhost kernel: wct4xxp 0000:11:08.0: RCLK source set to span 2 Aug 26 17:48:25 localhost kernel: wct4xxp 0000:11:08.0: Recovered timing mode, RCLK set to span 2 Aug 26 17:48:25 localhost kernel: wct4xxp 0000:11:08.0: TE2XXP: Span 2 configured for CCS/HDB3 Aug 26 17:48:25 localhost kernel: wct4xxp 0000:11:08.0: RCLK source set to span 2 Aug 26 17:48:25 localhost kernel: wct4xxp 0000:11:08.0: Recovered timing mode, RCLK set to span 2 Aug 26 17:48:25 localhost kernel: wct4xxp 0000:11:08.0: SPAN 2: Primary Sync Source {quote} Those messages refer to the chosen clock source for your card.  Each card has one overall timing source.  It is chosen based on your configuration and which spans are not in alarm (making them available as a timing source).  At any given time, the timing for the card is either set to the internal clock or a recovered clock from one of the spans.  For TE mode, normally you will configure the spans to recover the clock from the network.  This is done in one of the "span=..." lines in /etc/dahdi/system.conf.  To configure a span to be considered as a source of timing, you sent the timing variable to 1 or above.  This tells it the order to consider the spans as a source of timing.  1 will be the primary source of timing, 2 will be the second, and so on.  The lowest numbered span that is not in alarm will be used.  If all spans are set to 0, then the internal timing source will be used.  This is normally only done when you are in NT mode. The messages above are printed out as it is selecting a timing source.  It looks like it landed on span 2 as the timing source. I hope that helps.