Stuttering audio on UIO play

Symptom

Occasionally, callers may hear stuttering audio when a UIO play is issued (i.e. Music on hold). 

Reason for this issue

One possible root cause is a slow 'fetching cycle' of the application user-defined read() callbacks

Solution

The solution is to investigate the application 'fetch cycle' of the play buffers. If the application is doing a UIO play, and the application is NOT fetching its' 'uio_reads' fast enough, users can experience stuttering audio.

These are two example cases where it is possible a user can experience stuttering audio.

  1. The UIO play is being done over a network drive and the playing data (or file) is on a remote drive and there is a possible bandwidth issues on the network.

a. Move the play data (file) to the local system and retest for issue.

  1. Something on the system is causing system level saturation slowing down the application callbacks.

a. Stop all Non-Dialogic related processes and retest for issue
b. Or apply System level internal software (Processor Explorer - SysInternal Tool) to determine and isolate the process saturating the system
 
The following sequence shows an application's 'fetch cycles' slowing down, resulting in the data in the buffer not being updated fast enough by the application:
Data in buffer: AAAAAAAA 
Data played: AAAAAAAA 

Data in buffer: BBBBBBBB 
Data played: BBBBBBBB

Data in buffer: CCCCCCCC 
Data played: CCCCCCCC

<<< At this point the buffer is not being updated with new data; the application has stopped fetching new buffer data for the play >>> 

Data in buffer: CCCCCCCC <<<<< This is the same data as before, the data has not changed
Data played: CCCCCCCC

Data in buffer: CCCCCCCC <<<<< This is the same data as before, the data has not changed
Data played: CCCCCCCC

<<< Now, the application has fetched the next buffer and is updating it >>>> 

Data in buffer: DDDDDDDD 
Data played: DDDDDDDD 

Data in buffer: EEEEEEEE 
Data played: EEEEEEEE 

Data in buffer: FFFFFFFF 
Data played: FFFFFFFF

Discussion

When using UIO for a play/record, the application provides the addresses of user-defined read( ), write( ) and lseek( ) functions by initializing the DX_UIO structure. These functions are used to play or record (read and/or write) to a non-standard storage media.

Two points to keep in mind when using UIO for a play/record:

  • The storage location, which affects the access speed for retrieving and storing audio data.

  • The application fetch cycle (delta between reads or writes), which affects the output of audio data that is retrieved and stored

 

When a play is issued, the play will continue to play what is in the buffers at the current time until told to stop (via tpt or application dx_stopch). The internals of the play does not check the data it is playing out of the buffers. When using user-defined read() and write(), it is up to the application to provide proper data as well as make sure their read() and write() callbacks are issued without delays. 

This is an example of an application's 'fetch cycles' slowing done in a production environment:

The deltas between reads within RTF logs for this visual is as followed:

START OF THE PLAY

11/05/2009 11:21:18.313 7016 7088 voice APPL libdxx dxxxB1C1 <:::: dx_playiottdata(0x7, 0x703be00, 0x0, 0x7033b7c, 0x8000)
11/05/2009 11:21:18.313 7016 7088 low DEBG StreamSource dxxxB1C1 ==<== ReadNextBuffer (m_TotalSize=2147483647)(m_RemainingLength=2147483647)
11/05/2009 11:21:18.313 7016 7088 voice APPL libdxx dxxxB1C1 ::::> dx_playiottdata returns 0

 

................ (delta is normal here)

11/05/2009 11:21:19.344 7016 7340 low DEBG Stream dxxxB1C1 SWRIT ProcessStreamEvent O=0 E=0x0
11/05/2009 11:21:19.344 7016 7340 low DEBG Stream dxxxB1C1 ==<== Write 16384 F=0x00 D=0000 (0) 0xce050f8
11/05/2009 11:21:19.344 7016 7340 low DEBG StreamSource dxxxB1C1 ==<== ReadNextBuffer (m_TotalSize=2147483647)(m_RemainingLength=2147434495)
11/05/2009 11:21:19.344 7016 10816 low DEBG Stream dxxxB1C1 ==<== SourceReady (0xce19390,16384,0) in StreamWritingWaitSource

Delta: ~6 second

11/05/2009 11:21:25.250 7016 7340 low DEBG Stream dxxxB1C1 SWRIT ProcessStreamEvent O=0 E=0x0
11/05/2009 11:21:25.250 7016 7340 low DEBG Stream dxxxB1C1 ==<== Write 16384 F=0x00 D=0000 (0) 0xce19390
11/05/2009 11:21:25.250 7016 7340 low DEBG StreamSource dxxxB1C1 ==<== ReadNextBuffer (m_TotalSize=2147483647)(m_RemainingLength=2147418111)
11/05/2009 11:21:25.250 7016 10816 low DEBG Stream dxxxB1C1 ==<== SourceReady (0xce050f8,16384,0) in StreamWritingWaitSource

Delta: ~4 second

11/05/2009 11:21:29.672 7016 7340 low DEBG Stream dxxxB1C1 SWRIT ProcessStreamEvent O=0 E=0x0
11/05/2009 11:21:29.672 7016 7340 low DEBG Stream dxxxB1C1 ==<== Write 16384 F=0x00 D=0000 (0) 0xce050f8
11/05/2009 11:21:29.672 7016 7340 low DEBG StreamSource dxxxB1C1 ==<== ReadNextBuffer (m_TotalSize=2147483647)(m_RemainingLength=2147401727)
11/05/2009 11:21:29.672 7016 10816 low DEBG Stream dxxxB1C1 ==<== SourceReady (0xce19390,16384,0) in StreamWritingWaitSource

................ (delta is normal here)

11/05/2009 11:21:32.672 7016 7340 low DEBG Stream dxxxB1C1 SWRIT ProcessStreamEvent O=0 E=0x0
11/05/2009 11:21:32.672 7016 7340 low DEBG Stream dxxxB1C1 ==<== Write 16384 F=0x00 D=0000 (0) 0xce050f8
11/05/2009 11:21:32.672 7016 7340 low DEBG StreamSource dxxxB1C1 ==<== ReadNextBuffer (m_TotalSize=2147483647)(m_RemainingLength=2147368959)
11/05/2009 11:21:32.672 7016 10816 low DEBG Stream dxxxB1C1 ==<== SourceReady (0xce19390,16384,0) in StreamWritingWaitSource

Delta: ~4 second

11/05/2009 11:21:35.453 7016 7340 low DEBG Stream dxxxB1C1 SWRIT ProcessStreamEvent O=0 E=0x0
11/05/2009 11:21:35.453 7016 7340 low DEBG Stream dxxxB1C1 ==<== Write 16384 F=0x00 D=0000 (0) 0xce19390
11/05/2009 11:21:35.453 7016 7340 low DEBG StreamSource dxxxB1C1 ==<== ReadNextBuffer (m_TotalSize=2147483647)(m_RemainingLength=2147352575)
11/05/2009 11:21:35.453 7016 10816 low DEBG Stream dxxxB1C1 ==<== SourceReady (0xce050f8,16384,0) in StreamWritingWaitSource

................ (delta is normal here)

11/05/2009 11:21:49.047 7016 7340 low DEBG Stream dxxxB1C1 SWRIT ProcessStreamEvent O=0 E=0x0
11/05/2009 11:21:49.047 7016 7340 low DEBG Stream dxxxB1C1 ==<== Write 16384 F=0x00 D=0000 (0) 0xce050f8
11/05/2009 11:21:49.047 7016 7340 low DEBG StreamSource dxxxB1C1 ==<== ReadNextBuffer (m_TotalSize=2147483647)(m_RemainingLength=2147237887)
11/05/2009 11:21:49.047 7016 10816 low DEBG Stream dxxxB1C1 ==<== SourceReady (0xce19390,16384,0) in StreamWritingWaitSource

Delta: ~5 second

11/05/2009 11:21:54.875 7016 7340 low DEBG Stream dxxxB1C1 SWRIT ProcessStreamEvent O=0 E=0x0
11/05/2009 11:21:54.875 7016 7340 low DEBG Stream dxxxB1C1 ==<== Write 16384 F=0x00 D=0000 (0) 0xce19390
11/05/2009 11:21:54.875 7016 7340 low DEBG StreamSource dxxxB1C1 ==<== ReadNextBuffer (m_TotalSize=2147483647)(m_RemainingLength=2147221503)
11/05/2009 11:21:54.875 7016 10816 low DEBG Stream dxxxB1C1 ==<== SourceReady (0xce050f8,16384,0) in StreamWritingWaitSource

................ (delta is normal here)

11/05/2009 11:22:16.359 7016 7340 low DEBG Stream dxxxB1C1 SWRIT ProcessStreamEvent O=0 E=0x0
11/05/2009 11:22:16.359 7016 7340 low DEBG Stream dxxxB1C1 ==<== Write 16384 F=0x00 D=0000 (0) 0xce19390
11/05/2009 11:22:16.359 7016 7340 low DEBG StreamSource dxxxB1C1 ==<== ReadNextBuffer (m_TotalSize=2147483647)(m_RemainingLength=2147024895)
11/05/2009 11:22:16.359 7016 10816 low DEBG Stream dxxxB1C1 ==<== SourceReady (0xce050f8,16384,0) in StreamWritingWaitSource

Delta: ~13 second

11/05/2009 11:22:29.422 7016 7340 low DEBG Stream dxxxB1C1 SWRIT ProcessStreamEvent O=0 E=0x0
11/05/2009 11:22:29.422 7016 7340 low DEBG Stream dxxxB1C1 ==<== Write 16384 F=0x00 D=0000 (0) 0xce050f8
11/05/2009 11:22:29.422 7016 7340 low DEBG StreamSource dxxxB1C1 ==<== ReadNextBuffer (m_TotalSize=2147483647)(m_RemainingLength=2147008511)
11/05/2009 11:22:29.422 7016 10816 low DEBG Stream dxxxB1C1 ==<== SourceReady (0xce19390,16384,0) in StreamWritingWaitSource

................ (delta is normal here)

11/05/2009 11:22:35.531 7016 7340 low DEBG Stream dxxxB1C1 SWRIT ProcessStreamEvent O=0 E=0x0
11/05/2009 11:22:35.531 7016 7340 low DEBG Stream dxxxB1C1 ==<== Write 16384 F=0x00 D=0000 (0) 0xce19390
11/05/2009 11:22:35.531 7016 7340 low DEBG StreamSource dxxxB1C1 ==<== ReadNextBuffer (m_TotalSize=2147483647)(m_RemainingLength=2146926591)
11/05/2009 11:22:35.531 7016 10816 low DEBG Stream dxxxB1C1 ==<== SourceReady (0xce050f8,16384,0) in StreamWritingWaitSource

Delta: ~5 second

11/05/2009 11:22:40.219 7016 7340 low DEBG Stream dxxxB1C1 SWRIT ProcessStreamEvent O=0 E=0x0
11/05/2009 11:22:40.219 7016 7340 low DEBG Stream dxxxB1C1 ==<== Write 16384 F=0x00 D=0000 (0) 0xce050f8
11/05/2009 11:22:40.219 7016 7340 low DEBG StreamSource dxxxB1C1 ==<== ReadNextBuffer (m_TotalSize=2147483647)(m_RemainingLength=2146910207)
11/05/2009 11:22:40.219 7016 10816 low DEBG Stream dxxxB1C1 ==<== SourceReady (0xce19390,16384,0) in StreamWritingWaitSource

................ (delta is normal here)

11/05/2009 11:22:51.031 7016 7088 voice APPL libdxx dxxxB1C1 <:::: dx_stopch(0x7, 0x8000)
11/05/2009 11:22:51.031 7016 7088 voice APPL libdxx dxxxB1C1 ::::> dx_stopch

 

11/05/2009 11:22:51.344 7016 7340 voice APPL VoiceDevice dxxxB1C1 ::::> SendEvent TDX_PLAY
In this live site example, it was discovered the application was waiting between their uio_read() callbacks. This delay within the application was the root cause of the stuttering play effect.

Product list

  • Dialogic JCT-series Media Boards

Return to Documentation Home I Return to Sangoma Support