[asterisk-bugs] [Asterisk 0014387]: mpg123 crashes when trying to play stream.

Asterisk Bug Tracker noreply at bugs.digium.com
Thu Feb 5 15:27:10 CST 2009


A NOTE has been added to this issue. 
====================================================================== 
http://bugs.digium.com/view.php?id=14387 
====================================================================== 
Reported By:                jonnt
Assigned To:                
====================================================================== 
Project:                    Asterisk
Issue ID:                   14387
Category:                   Resources/res_musiconhold
Reproducibility:            always
Severity:                   minor
Priority:                   normal
Status:                     feedback
Asterisk Version:           1.6.0.5 
Regression:                 No 
SVN Branch (only for SVN checkouts, not tarball releases): N/A 
SVN Revision (number only!):  
Request Review:              
====================================================================== 
Date Submitted:             2009-02-02 16:05 CST
Last Modified:              2009-02-05 15:27 CST
====================================================================== 
Summary:                    mpg123 crashes when trying to play stream.
Description: 
mpg123 crashes when trying to play stream. Also seems that format_mp3 loads
but does to work.
====================================================================== 

---------------------------------------------------------------------- 
 (0099559) jonnt (reporter) - 2009-02-05 15:27
 http://bugs.digium.com/view.php?id=14387#c99559 
---------------------------------------------------------------------- 
[Feb  5 15:23:36] DEBUG[30965] acl.c: Found IP address for this socket
[Feb  5 15:23:36] WARNING[30965] netsock.c: Unable to set SIP RTP TOS to
184, may be you have no root privileges
[Feb  5 15:23:36] VERBOSE[30965] logger.c:   == Using SIP RTP CoS mark 5
[Feb  5 15:23:36] DEBUG[30965] chan_sip.c: Setting NAT on RTP to Off
[Feb  5 15:23:36] DEBUG[30965] chan_sip.c: Allocating new SIP dialog for
aswtzhypjvtjwsg at localhost.localdomain - INVITE (With RTP)
[Feb  5 15:23:36] DEBUG[30965] chan_sip.c: **** Received INVITE (5) -
Command in SIP INVITE
[Feb  5 15:23:36] DEBUG[30965] chan_sip.c: Setting NAT on RTP to On
[Feb  5 15:23:36] DEBUG[30965] chan_sip.c: Trying to put 'SIP/2.0 40' onto
UDP socket destined for 192.168.173.41:5060
[Feb  5 15:23:36] DEBUG[30965] chan_sip.c: = Found Their Call ID:
aswtzhypjvtjwsg at localhost.localdomain Their Tag zclnm Our tag: as34e8a04b
[Feb  5 15:23:36] DEBUG[30965] chan_sip.c: **** Received ACK (6) - Command
in SIP ACK
[Feb  5 15:23:36] DEBUG[30965] chan_sip.c: Stopping retransmission on
'aswtzhypjvtjwsg at localhost.localdomain' of Response 312: Match Found
[Feb  5 15:23:36] DEBUG[30965] chan_sip.c: = Found Their Call ID:
aswtzhypjvtjwsg at localhost.localdomain Their Tag zclnm Our tag: as34e8a04b
[Feb  5 15:23:36] DEBUG[30965] chan_sip.c: **** Received INVITE (5) -
Command in SIP INVITE
[Feb  5 15:23:36] DEBUG[30965] chan_sip.c: Setting NAT on RTP to On
[Feb  5 15:23:36] DEBUG[30965] chan_sip.c: We're settling with these
formats: 0xc (ulaw|alaw)
[Feb  5 15:23:36] DEBUG[30965] chan_sip.c: Checking SIP call limits for
device 4002
[Feb  5 15:23:36] DEBUG[30965] chan_sip.c: Updating call counter for
incoming call
[Feb  5 15:23:36] DEBUG[30965] devicestate.c: Notification of state change
to be queued on device/channel SIP/4002
[Feb  5 15:23:36] DEBUG[30937] devicestate.c: No provider found, checking
channel drivers for SIP - 4002
[Feb  5 15:23:36] DEBUG[30937] chan_sip.c: Checking device state for peer
4002
[Feb  5 15:23:36] DEBUG[30937] devicestate.c: Changing state for SIP/4002
- state 2 (In use)
[Feb  5 15:23:36] DEBUG[30965] chan_sip.c: *** Our native formats are 0x4
(ulaw) 
[Feb  5 15:23:36] DEBUG[30965] chan_sip.c: *** Joint capabilities are 0xc
(ulaw|alaw) 
[Feb  5 15:23:36] DEBUG[30965] chan_sip.c: *** Our capabilities are 0xc
(ulaw|alaw) 
[Feb  5 15:23:36] DEBUG[30965] chan_sip.c: *** AST_CODEC_CHOOSE formats
are 0x4 (ulaw) 
[Feb  5 15:23:36] DEBUG[30965] chan_sip.c: This channel will not be able
to handle video.
[Feb  5 15:23:36] DEBUG[30965] chan_sip.c: build_route: Contact hop:
<sip:4002 at 192.168.254.120>
[Feb  5 15:23:36] DEBUG[30965] chan_sip.c: SIP/4002-08b63848: New call is
still down.... Trying... 
[Feb  5 15:23:36] DEBUG[30965] chan_sip.c: Trying to put 'SIP/2.0 10' onto
UDP socket destined for 192.168.173.41:5060
[Feb  5 15:23:36] DEBUG[30965] devicestate.c: Notification of state change
to be queued on device/channel SIP/4002
[Feb  5 15:23:36] DEBUG[30939] devicestate.c: No provider found, checking
channel drivers for SIP - 4002
[Feb  5 15:23:36] DEBUG[30939] chan_sip.c: Checking device state for peer
4002
[Feb  5 15:23:36] DEBUG[30969] app_queue.c: Device 'SIP/4002' changed to
state '2' (In use) but we don't care because they're not a member of any
queue.
[Feb  5 15:23:36] DEBUG[30937] devicestate.c: No provider found, checking
channel drivers for SIP - 4002
[Feb  5 15:23:36] DEBUG[30937] chan_sip.c: Checking device state for peer
4002
[Feb  5 15:23:36] DEBUG[30937] devicestate.c: Changing state for SIP/4002
- state 2 (In use)
[Feb  5 15:23:36] DEBUG[31125] pbx.c: Launching 'Answer'
[Feb  5 15:23:36] VERBOSE[31125] logger.c:     -- Executing
[68742 at from-internal:1] Answer("SIP/4002-08b63848", "") in new stack
[Feb  5 15:23:36] DEBUG[31125] devicestate.c: Notification of state change
to be queued on device/channel SIP/4002
[Feb  5 15:23:36] DEBUG[31125] chan_sip.c: SIP answering channel:
SIP/4002-08b63848
[Feb  5 15:23:36] DEBUG[31125] chan_sip.c: Setting framing from config on
incoming call
[Feb  5 15:23:36] DEBUG[31125] chan_sip.c: ** Our capability: 0xc
(ulaw|alaw) Video flag: True Text flag: True
[Feb  5 15:23:36] DEBUG[31125] chan_sip.c: ** Our prefcodec: 0x0 (nothing)

[Feb  5 15:23:36] DEBUG[31125] chan_sip.c: -- Done with adding codecs to
SDP
[Feb  5 15:23:36] DEBUG[31125] channel.c: Internal timing is enabled
(option_internal_timing=1048576 chan->timingfd=32)
[Feb  5 15:23:36] DEBUG[31125] chan_sip.c: Done building SDP. Settling
with this capability: 0xc (ulaw|alaw)
[Feb  5 15:23:36] DEBUG[31125] chan_sip.c: Trying to put 'SIP/2.0 20' onto
UDP socket destined for 192.168.173.41:5060
[Feb  5 15:23:36] DEBUG[30937] devicestate.c: No provider found, checking
channel drivers for SIP - 4002
[Feb  5 15:23:36] DEBUG[30937] chan_sip.c: Checking device state for peer
4002
[Feb  5 15:23:36] DEBUG[30937] devicestate.c: Changing state for SIP/4002
- state 2 (In use)
[Feb  5 15:23:36] DEBUG[30969] app_queue.c: Device 'SIP/4002' changed to
state '2' (In use) but we don't care because they're not a member of any
queue.
[Feb  5 15:23:36] DEBUG[30969] app_queue.c: Device 'SIP/4002' changed to
state '2' (In use) but we don't care because they're not a member of any
queue.
[Feb  5 15:23:36] DEBUG[30939] devicestate.c: No provider found, checking
channel drivers for SIP - 4002
[Feb  5 15:23:36] DEBUG[30939] chan_sip.c: Checking device state for peer
4002
[Feb  5 15:23:36] DEBUG[30939] devicestate.c: No provider found, checking
channel drivers for SIP - 4002
[Feb  5 15:23:36] DEBUG[30939] chan_sip.c: Checking device state for peer
4002
[Feb  5 15:23:36] DEBUG[31125] rtp.c: RTCP NAT: Got RTCP from other end.
Now sending to address 192.168.173.41:8001
[Feb  5 15:23:36] DEBUG[31125] rtp.c: Got RTCP report of 48 bytes
[Feb  5 15:23:36] DEBUG[30965] chan_sip.c: = Found Their Call ID:
aswtzhypjvtjwsg at localhost.localdomain Their Tag zclnm Our tag: as37f0ca44
[Feb  5 15:23:36] DEBUG[30965] chan_sip.c: **** Received ACK (6) - Command
in SIP ACK
[Feb  5 15:23:36] DEBUG[30965] chan_sip.c: Stopping retransmission on
'aswtzhypjvtjwsg at localhost.localdomain' of Response 313: Match Found
[Feb  5 15:23:36] DEBUG[31125] rtp.c: RTP NAT: Got audio from other end.
Now sending to address 192.168.173.41:8000
[Feb  5 15:23:36] DEBUG[31125] pbx.c: Launching 'MusicOnHold'
[Feb  5 15:23:36] VERBOSE[31125] logger.c:     -- Executing
[68742 at from-internal:2] MusicOnHold("SIP/4002-08b63848", "default") in new
stack
[Feb  5 15:23:36] DEBUG[31125] channel.c: Set channel SIP/4002-08b63848 to
write format slin
[Feb  5 15:23:36] VERBOSE[31125] logger.c:     -- Started music on hold,
class 'default', on channel 'SIP/4002-08b63848'
[Feb  5 15:23:36] DEBUG[31125] channel.c: Scheduling timer at 160 sample
intervals
[Feb  5 15:23:36] DEBUG[31125] channel.c: Internal timing is enabled
(option_internal_timing=1048576 chan->timingfd=32)
[Feb  5 15:23:36] DEBUG[31125] channel.c: Internal timing is enabled
(option_internal_timing=1048576 chan->timingfd=32)
[Feb  5 15:23:36] DEBUG[31125] channel.c: Internal timing is enabled
(option_internal_timing=1048576 chan->timingfd=32)
[Feb  5 15:23:36] DEBUG[31125] channel.c: Internal timing is enabled
(option_internal_timing=1048576 chan->timingfd=32)
[Feb  5 15:23:36] DEBUG[31125] channel.c: Internal timing is enabled
(option_internal_timing=1048576 chan->timingfd=32)
[Feb  5 15:23:36] DEBUG[31125] channel.c: Internal timing is enabled
(option_internal_timing=1048576 chan->timingfd=32)
[Feb  5 15:23:36] DEBUG[31125] channel.c: Internal timing is enabled
(option_internal_timing=1048576 chan->timingfd=32)
[Feb  5 15:23:36] DEBUG[31125] channel.c: Internal timing is enabled
(option_internal_timing=1048576 chan->timingfd=32)
[Feb  5 15:23:36] DEBUG[31125] channel.c: Internal timing is enabled
(option_internal_timing=1048576 chan->timingfd=32)
[Feb  5 15:23:36] DEBUG[31125] channel.c: Internal timing is enabled
(option_internal_timing=1048576 chan->timingfd=32)
[Feb  5 15:23:36] DEBUG[31125] channel.c: Internal timing is enabled
(option_internal_timing=1048576 chan->timingfd=32)
[Feb  5 15:23:36] DEBUG[31125] channel.c: Internal timing is enabled
(option_internal_timing=1048576 chan->timingfd=32)
[Feb  5 15:23:36] DEBUG[31125] channel.c: Internal timing is enabled
(option_internal_timing=1048576 chan->timingfd=32)
[Feb  5 15:23:36] DEBUG[31125] channel.c: Internal timing is enabled
(option_internal_timing=1048576 chan->timingfd=32)
[Feb  5 15:23:36] DEBUG[31125] channel.c: Internal timing is enabled
(option_internal_timing=1048576 chan->timingfd=32)
[Feb  5 15:23:36] DEBUG[31125] channel.c: Internal timing is enabled
(option_internal_timing=1048576 chan->timingfd=32)
[Feb  5 15:23:36] DEBUG[31125] channel.c: Internal timing is enabled
(option_internal_timing=1048576 chan->timingfd=32)
[Feb  5 15:23:36] DEBUG[31125] channel.c: Internal timing is enabled
(option_internal_timing=1048576 chan->timingfd=32)
[Feb  5 15:23:36] DEBUG[31125] channel.c: Internal timing is enabled
(option_internal_timing=1048576 chan->timingfd=32)
[Feb  5 15:23:36] DEBUG[31125] channel.c: Internal timing is enabled
(option_internal_timing=1048576 chan->timingfd=32)
[Feb  5 15:23:36] DEBUG[31125] channel.c: Internal timing is enabled
(option_internal_timing=1048576 chan->timingfd=32)
[Feb  5 15:23:36] DEBUG[31125] channel.c: Internal timing is enabled
(option_internal_timing=1048576 chan->timingfd=32)
[Feb  5 15:23:36] DEBUG[31125] channel.c: Internal timing is enabled
(option_internal_timing=1048576 chan->timingfd=32)
[Feb  5 15:23:36] DEBUG[31125] channel.c: Auto-deactivating generator
[Feb  5 15:23:36] DEBUG[31125] channel.c: Set channel SIP/4002-08b63848 to
write format ulaw
[Feb  5 15:23:36] VERBOSE[31125] logger.c:     -- Stopped music on hold on
SIP/4002-08b63848
[Feb  5 15:23:36] DEBUG[31125] channel.c: Scheduling timer at 0 sample
intervals
[Feb  5 15:23:39] DEBUG[30965] chan_sip.c: = Found Their Call ID:
aswtzhypjvtjwsg at localhost.localdomain Their Tag zclnm Our tag: as37f0ca44
[Feb  5 15:23:39] DEBUG[30965] chan_sip.c: **** Received BYE (8) - Command
in SIP BYE
[Feb  5 15:23:39] DEBUG[30965] chan_sip.c: Setting SIP_ALREADYGONE on
dialog aswtzhypjvtjwsg at localhost.localdomain
[Feb  5 15:23:39] DEBUG[30965] chan_sip.c: Received bye, issuing owner
hangup
[Feb  5 15:23:39] DEBUG[30965] chan_sip.c: Trying to put 'SIP/2.0 20' onto
UDP socket destined for 192.168.173.41:5060
[Feb  5 15:23:39] DEBUG[31125] pbx.c: Spawn extension
(from-internal,68742,2) exited non-zero on 'SIP/4002-08b63848'
[Feb  5 15:23:39] VERBOSE[31125] logger.c:   == Spawn extension
(from-internal, 68742, 2) exited non-zero on 'SIP/4002-08b63848'
[Feb  5 15:23:39] DEBUG[31125] channel.c: Soft-Hanging up channel
'SIP/4002-08b63848'
[Feb  5 15:23:39] DEBUG[31125] pbx.c: Launching 'Macro'
[Feb  5 15:23:39] VERBOSE[31125] logger.c:     -- Executing
[h at from-internal:1] Macro("SIP/4002-08b63848", "hangupcall") in new stack
[Feb  5 15:23:39] DEBUG[31125] pbx.c: Launching 'ResetCDR'
[Feb  5 15:23:39] VERBOSE[31125] logger.c:     -- Executing
[s at macro-hangupcall:1] ResetCDR("SIP/4002-08b63848", "w") in new stack
[Feb  5 15:23:39] DEBUG[31125] cdr_addon_mysql.c: Inserting a CDR record.
[Feb  5 15:23:39] DEBUG[31125] cdr_addon_mysql.c: SQL command as follows:
INSERT INTO cdr
(calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield)
VALUES ('2009-02-05 15:23:36','"device"
<4002>','4002','68742','from-internal','SIP/4002-08b63848','','MusicOnHold','default','3','3','ANSWERED','3','','1233869016.0','')
[Feb  5 15:23:39] DEBUG[31125] app_macro.c: Executed application:
ResetCDR
[Feb  5 15:23:39] DEBUG[31125] pbx.c: Launching 'NoCDR'
[Feb  5 15:23:39] VERBOSE[31125] logger.c:     -- Executing
[s at macro-hangupcall:2] NoCDR("SIP/4002-08b63848", "") in new stack
[Feb  5 15:23:39] DEBUG[31125] app_macro.c: Executed application: NoCDR
[Feb  5 15:23:39] DEBUG[31125] pbx.c: Expression result is '1'
[Feb  5 15:23:39] DEBUG[31125] pbx.c: Launching 'GotoIf'
[Feb  5 15:23:39] VERBOSE[31125] logger.c:     -- Executing
[s at macro-hangupcall:3] GotoIf("SIP/4002-08b63848", "1?skiprg") in new
stack
[Feb  5 15:23:39] VERBOSE[31125] logger.c:     -- Goto
(macro-hangupcall,s,6)
[Feb  5 15:23:39] DEBUG[31125] app_macro.c: Executed application: GotoIf
[Feb  5 15:23:39] DEBUG[31125] pbx.c: Expression result is '1'
[Feb  5 15:23:39] DEBUG[31125] pbx.c: Launching 'GotoIf'
[Feb  5 15:23:39] VERBOSE[31125] logger.c:     -- Executing
[s at macro-hangupcall:6] GotoIf("SIP/4002-08b63848", "1?skipblkvm") in new
stack
[Feb  5 15:23:39] VERBOSE[31125] logger.c:     -- Goto
(macro-hangupcall,s,9)
[Feb  5 15:23:39] DEBUG[31125] app_macro.c: Executed application: GotoIf
[Feb  5 15:23:39] DEBUG[31125] pbx.c: Expression result is '1'
[Feb  5 15:23:39] DEBUG[31125] pbx.c: Launching 'GotoIf'
[Feb  5 15:23:39] VERBOSE[31125] logger.c:     -- Executing
[s at macro-hangupcall:9] GotoIf("SIP/4002-08b63848", "1?theend") in new
stack
[Feb  5 15:23:39] VERBOSE[31125] logger.c:     -- Goto
(macro-hangupcall,s,11)
[Feb  5 15:23:39] DEBUG[31125] app_macro.c: Executed application: GotoIf
[Feb  5 15:23:39] DEBUG[31125] pbx.c: Launching 'Hangup'
[Feb  5 15:23:39] VERBOSE[31125] logger.c:     -- Executing
[s at macro-hangupcall:11] Hangup("SIP/4002-08b63848", "") in new stack
[Feb  5 15:23:39] DEBUG[31125] app_macro.c: Spawn extension
(macro-hangupcall,s,11) exited non-zero on 'SIP/4002-08b63848' in macro
'hangupcall'
[Feb  5 15:23:39] VERBOSE[31125] logger.c:   == Spawn extension
(macro-hangupcall, s, 11) exited non-zero on 'SIP/4002-08b63848' in macro
'hangupcall'
[Feb  5 15:23:39] DEBUG[31125] pbx.c: Spawn extension
(macro-hangupcall,s,11) exited non-zero on 'SIP/4002-08b63848'
[Feb  5 15:23:39] VERBOSE[31125] logger.c:   == Spawn extension
(macro-hangupcall, s, 11) exited non-zero on 'SIP/4002-08b63848'
[Feb  5 15:23:39] DEBUG[31125] channel.c: Hanging up channel
'SIP/4002-08b63848'
[Feb  5 15:23:39] DEBUG[31125] chan_sip.c: Hangup call SIP/4002-08b63848,
SIP callid aswtzhypjvtjwsg at localhost.localdomain
[Feb  5 15:23:39] DEBUG[31125] chan_sip.c: Updating call counter for
incoming call
[Feb  5 15:23:39] DEBUG[31125] devicestate.c: Notification of state change
to be queued on device/channel SIP/4002
[Feb  5 15:23:39] DEBUG[30937] devicestate.c: No provider found, checking
channel drivers for SIP - 4002
[Feb  5 15:23:39] DEBUG[31125] devicestate.c: Notification of state change
to be queued on device/channel SIP/4002
[Feb  5 15:23:39] DEBUG[30937] chan_sip.c: Checking device state for peer
4002
[Feb  5 15:23:39] DEBUG[30937] devicestate.c: Changing state for SIP/4002
- state 1 (Not in use)
[Feb  5 15:23:39] DEBUG[30937] devicestate.c: No provider found, checking
channel drivers for SIP - 4002
[Feb  5 15:23:39] DEBUG[30937] chan_sip.c: Checking device state for peer
4002
[Feb  5 15:23:39] DEBUG[30937] devicestate.c: Changing state for SIP/4002
- state 1 (Not in use)
[Feb  5 15:23:39] DEBUG[30939] devicestate.c: No provider found, checking
channel drivers for SIP - 4002
[Feb  5 15:23:39] DEBUG[30939] chan_sip.c: Checking device state for peer
4002
[Feb  5 15:23:39] DEBUG[30969] app_queue.c: Device 'SIP/4002' changed to
state '1' (Not in use) but we don't care because they're not a member of
any queue.
[Feb  5 15:23:39] DEBUG[30969] app_queue.c: Device 'SIP/4002' changed to
state '1' (Not in use) but we don't care because they're not a member of
any queue.
[Feb  5 15:23:39] DEBUG[30939] devicestate.c: No provider found, checking
channel drivers for SIP - 4002
[Feb  5 15:23:39] DEBUG[30939] chan_sip.c: Checking device state for peer
4002 

Issue History 
Date Modified    Username       Field                    Change               
====================================================================== 
2009-02-05 15:27 jonnt          Note Added: 0099559                          
======================================================================




More information about the asterisk-bugs mailing list