Segmentation Fault bei Voicemail

[astrakid]

Hi,
Asterisk läuft auf meinem SOHO-Router (Tomato Firmware, ähnlich DD-WRT).
Folgendes Problem habe ich dabei mit Asterisk 1.8.4: Sobald die Voicemail-Applikation anlaufen soll, erhalte ich die Fehlermeldung "Segmentation Fault".

Hat hier jemand ein ähnliches Problem oder noch besser, kennt jemand die Lösung?

gruß und danke,
astrakid

edit: Der Fehler trat mit Aufruf der Funktion Playback() auf. Genaueres kann ich momentan nich tliefern, da die Logs gestern überschrieben wurden und ich mich aus der Ferne momentan nicht einloggen kann, um den Fehler zu reproduzieren.

 

[chaos2000]

die frage ist, welche asterisk version du verwendest.
Fehlt vielleicht ein sound file?

 

[astrakid]

Asterisk 1.8.4 ist im Einsatz, Soundfiles sind vorhanden. Wenn das Soundfile fehlt, erhalte ich ein Busy und in Asterisk eine zu erwartende Fehlermeldung, dass die datei nicht gefunden werden konnte.

 

[astrakid]

Debug-logs

so, hier ist nun die ausgabe im debug-log:

*CLI> [May 23 17:50:24] DEBUG[8545]: chan_sip.c:7603 find_call: = Looking for  Call ID: [email protected] (Checking From) --From tag 2003203917 --To-tag
[May 23 17:50:24] DEBUG[8545]: acl.c:725 ast_ouraddrfor: For destination '10.10.10.12', our source address is '10.10.10.2'.
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:3384 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 10.10.10.2:5060
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:7360 sip_alloc: Allocating new SIP dialog for [email protected] - INVITE (No RTP)
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:23874 handle_incoming: **** Received INVITE (5) - Command in SIP INVITE
[May 23 17:50:24] DEBUG[8545]: sip/reqresp_parser.c:1584 parse_sip_options: Begin: parsing SIP "Supported: 100rel, replaces, from-change"
[May 23 17:50:24] DEBUG[8545]: sip/reqresp_parser.c:1600 parse_sip_options: Found SIP option: -100rel-
[May 23 17:50:24] DEBUG[8545]: sip/reqresp_parser.c:1608 parse_sip_options: Matched SIP option: 100rel
[May 23 17:50:24] DEBUG[8545]: sip/reqresp_parser.c:1600 parse_sip_options: Found SIP option: -replaces-
[May 23 17:50:24] DEBUG[8545]: sip/reqresp_parser.c:1608 parse_sip_options: Matched SIP option: replaces
[May 23 17:50:24] DEBUG[8545]: sip/reqresp_parser.c:1600 parse_sip_options: Found SIP option: -from-change-
[May 23 17:50:24] DEBUG[8545]: sip/reqresp_parser.c:1608 parse_sip_options: Matched SIP option: from-change
[May 23 17:50:24] DEBUG[8545]: netsock2.c:125 ast_sockaddr_split_hostport: Splitting '10.10.10.12:5060' gives...
[May 23 17:50:24] DEBUG[8545]: netsock2.c:155 ast_sockaddr_split_hostport: ...host '10.10.10.12' and port '5060'.
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:3230 __sip_xmit: Trying to put 'SIP/2.0 401' onto UDP socket destined for 10.10.10.12:5060
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:7603 find_call: = Looking for  Call ID: [email protected] (Checking From) --From tag 2003203917 --To-tag as48e9101c
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:23874 handle_incoming: **** Received ACK (6) - Command in SIP ACK
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:3922 __sip_ack: Stopping retransmission on '[email protected]' of Response 8: Match Found
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:7603 find_call: = Looking for  Call ID: [email protected] (Checking From) --From tag 2003203917 --To-tag
[May 23 17:50:24] DEBUG[8545]: netsock2.c:125 ast_sockaddr_split_hostport: Splitting '10.10.10.2' gives...
[May 23 17:50:24] DEBUG[8545]: netsock2.c:155 ast_sockaddr_split_hostport: ...host '10.10.10.2' and port '(null)'.
[May 23 17:50:24] DEBUG[8545]: netsock2.c:125 ast_sockaddr_split_hostport: Splitting '10.10.10.2' gives...
[May 23 17:50:24] DEBUG[8545]: netsock2.c:155 ast_sockaddr_split_hostport: ...host '10.10.10.2' and port '(null)'.
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:23874 handle_incoming: **** Received INVITE (5) - Command in SIP INVITE
[May 23 17:50:24] DEBUG[8545]: netsock2.c:125 ast_sockaddr_split_hostport: Splitting '10.10.10.12:5060' gives...
[May 23 17:50:24] DEBUG[8545]: netsock2.c:155 ast_sockaddr_split_hostport: ...host '10.10.10.12' and port '5060'.
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:344 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x76d100'
[May 23 17:50:24] DEBUG[8545]: res_rtp_asterisk.c:472 ast_rtp_new: Allocated port 16614 for RTP instance '0x76d100'
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:353 ast_rtp_instance_new: RTP instance '0x76d100' is setup and ready to go
[May 23 17:50:24] DEBUG[8545]: res_rtp_asterisk.c:2370 ast_rtp_prop_set: Setup RTCP on RTP instance '0x76d100'
  == Using SIP RTP CoS mark 5
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:4825 do_setnat: Setting NAT on RTP to On
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:8398 process_sdp: Processing session-level SDP v=0... UNSUPPORTED.
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:8398 process_sdp: Processing session-level SDP o=- 1752266231 0 IN IP4 10.10.10.12... UNSUPPORTED.
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:8398 process_sdp: Processing session-level SDP s=SIPPER for phoner... UNSUPPORTED.
[May 23 17:50:24] DEBUG[8545]: netsock2.c:125 ast_sockaddr_split_hostport: Splitting '10.10.10.12' gives...
[May 23 17:50:24] DEBUG[8545]: netsock2.c:155 ast_sockaddr_split_hostport: ...host '10.10.10.12' and port '(null)'.
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:8398 process_sdp: Processing session-level SDP c=IN IP4 10.10.10.12... OK.
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:8398 process_sdp: Processing session-level SDP t=0 0... UNSUPPORTED.
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:535 ast_rtp_codecs_payloads_set_m_type: Setting payload 8 based on m type on 0x7dbfaac8
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:535 ast_rtp_codecs_payloads_set_m_type: Setting payload 0 based on m type on 0x7dbfaac8
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:535 ast_rtp_codecs_payloads_set_m_type: Setting payload 3 based on m type on 0x7dbfaac8
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:535 ast_rtp_codecs_payloads_set_m_type: Setting payload 97 based on m type on 0x7dbfaac8
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:535 ast_rtp_codecs_payloads_set_m_type: Setting payload 9 based on m type on 0x7dbfaac8
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:535 ast_rtp_codecs_payloads_set_m_type: Setting payload 111 based on m type on 0x7dbfaac8
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:535 ast_rtp_codecs_payloads_set_m_type: Setting payload 112 based on m type on 0x7dbfaac8
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:535 ast_rtp_codecs_payloads_set_m_type: Setting payload 101 based on m type on 0x7dbfaac8
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:8585 process_sdp: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK.
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:8585 process_sdp: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK.
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:8585 process_sdp: Processing media-level (audio) SDP a=rtpmap:2 G726-32/8000... OK.
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:8585 process_sdp: Processing media-level (audio) SDP a=rtpmap:3 GSM/8000... OK.
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:8585 process_sdp: Processing media-level (audio) SDP a=rtpmap:97 iLBC/8000... OK.
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:8585 process_sdp: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK.
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:8585 process_sdp: Processing media-level (audio) SDP a=rtpmap:111 speex/16000... OK.
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:8585 process_sdp: Processing media-level (audio) SDP a=rtpmap:112 G726-16/8000... OK.
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:8585 process_sdp: Processing media-level (audio) SDP a=rtpmap:113 G726-24/8000... OK.
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:8585 process_sdp: Processing media-level (audio) SDP a=rtpmap:114 G726-40/8000... OK.
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:8585 process_sdp: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK.
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:8585 process_sdp: Processing media-level (audio) SDP a=fmtp:101 0-16... UNSUPPORTED.
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:8585 process_sdp: Processing media-level (audio) SDP a=sendrecv... OK.
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:638 ast_rtp_codecs_payload_formats: Incorporating payload 0 on 0x7dbfaac8
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:638 ast_rtp_codecs_payload_formats: Incorporating payload 2 on 0x7dbfaac8
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:638 ast_rtp_codecs_payload_formats: Incorporating payload 3 on 0x7dbfaac8
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:638 ast_rtp_codecs_payload_formats: Incorporating payload 8 on 0x7dbfaac8
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:638 ast_rtp_codecs_payload_formats: Incorporating payload 9 on 0x7dbfaac8
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:638 ast_rtp_codecs_payload_formats: Incorporating payload 97 on 0x7dbfaac8
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:638 ast_rtp_codecs_payload_formats: Incorporating payload 101 on 0x7dbfaac8
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:638 ast_rtp_codecs_payload_formats: Incorporating payload 111 on 0x7dbfaac8
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:638 ast_rtp_codecs_payload_formats: Incorporating payload 112 on 0x7dbfaac8
[May 23 17:50:24] DEBUG[8545]: res_rtp_asterisk.c:2391 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x76d100'
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:516 ast_rtp_codecs_payloads_copy: Copying payload 0 from 0x7dbfaac8 to 0x76d2b0
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:516 ast_rtp_codecs_payloads_copy: Copying payload 2 from 0x7dbfaac8 to 0x76d2b0
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:516 ast_rtp_codecs_payloads_copy: Copying payload 3 from 0x7dbfaac8 to 0x76d2b0
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:516 ast_rtp_codecs_payloads_copy: Copying payload 8 from 0x7dbfaac8 to 0x76d2b0
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:516 ast_rtp_codecs_payloads_copy: Copying payload 9 from 0x7dbfaac8 to 0x76d2b0
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:516 ast_rtp_codecs_payloads_copy: Copying payload 97 from 0x7dbfaac8 to 0x76d2b0
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:516 ast_rtp_codecs_payloads_copy: Copying payload 101 from 0x7dbfaac8 to 0x76d2b0
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:516 ast_rtp_codecs_payloads_copy: Copying payload 111 from 0x7dbfaac8 to 0x76d2b0
[May 23 17:50:24] DEBUG[8545]: rtp_engine.c:516 ast_rtp_codecs_payloads_copy: Copying payload 112 from 0x7dbfaac8 to 0x76d2b0
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:8817 process_sdp: We're settling with these formats: 0xe (gsm|ulaw|alaw)
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:21543 handle_request_invite: Checking SIP call limits for device 12
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:5596 update_call_counter: Updating call counter for incoming call
[May 23 17:50:24] DEBUG[8545]: frame.c:1242 ast_codec_choose: Could not find preferred codec - Going for the best codec
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:6699 sip_new: *** Our native formats are 0x4 (ulaw)
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:6700 sip_new: *** Joint capabilities are 0xe (gsm|ulaw|alaw)
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:6701 sip_new: *** Our capabilities are 0x80000008000e (gsm|ulaw|alaw|h263|testlaw)
[May 23 17:50:24] DEBUG[8545]: frame.c:1242 ast_codec_choose: Could not find preferred codec - Going for the best codec
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:6702 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw)
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:6732 sip_new: This channel will not be able to handle video.
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:13497 build_route: build_route: Contact hop: <sip:[email protected]:5060>
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:21835 handle_request_invite: SIP/12-00000000: New call is still down.... Trying...
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:3230 __sip_xmit: Trying to put 'SIP/2.0 100' onto UDP socket destined for 10.10.10.12:5060
[May 23 17:50:24] DEBUG[8553]: pbx.c:4066 pbx_extension_helper: Launching 'NoCDR'
    -- Executing [11@telefone:1] NoCDR("SIP/12-00000000", "") in new stack
[May 23 17:50:24] DEBUG[8553]: pbx.c:3095 ast_str_retrieve_variable: Result of 'EXTEN' is '11'
[May 23 17:50:24] DEBUG[8553]: pbx.c:4066 pbx_extension_helper: Launching 'Dial'
    -- Executing [11@telefone:2] Dial("SIP/12-00000000", "SIP/11,15,Ttr") in new stack
[May 23 17:50:24] DEBUG[8553]: chan_sip.c:25301 sip_request_call: Asked to create a SIP channel with formats: 0x4 (ulaw)
[May 23 17:50:24] DEBUG[8553]: chan_sip.c:7360 sip_alloc: Allocating new SIP dialog for 7248679c66e8d94e11ec273874b3f087@[c0a8:202:780b:867f::]:0 - INVITE (No RTP)
[May 23 17:50:24] DEBUG[8553]: chan_sip.c:25409 sip_request_call: Cant create SIP call - target device not registered
[May 23 17:50:24] DEBUG[8553]: chan_sip.c:5744 sip_destroy: Destroying SIP dialog 7248679c66e8d94e11ec273874b3f087@[c0a8:202:780b:867f::]:0
  == Everyone is busy/congested at this time (1:0/0/1)
[May 23 17:50:24] DEBUG[8553]: app_dial.c:2725 dial_exec_full: Exiting with DIALSTATUS=CHANUNAVAIL.
[May 23 17:50:24] DEBUG[8553]: pbx.c:4066 pbx_extension_helper: Launching 'VoiceMail'
    -- Executing [11@telefone:3] VoiceMail("SIP/12-00000000", "9999,u") in new stack
[May 23 17:50:24] DEBUG[8553]: chan_sip.c:6170 sip_answer: SIP answering channel: SIP/12-00000000
[May 23 17:50:24] DEBUG[8553]: res_rtp_asterisk.c:725 ast_rtp_update_source: Setting the marker bit due to a source update
[May 23 17:50:24] DEBUG[8553]: chan_sip.c:11131 transmit_response_with_sdp: Setting framing from config on incoming call
[May 23 17:50:24] DEBUG[8553]: chan_sip.c:10777 add_sdp: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: True Text flag: True
[May 23 17:50:24] DEBUG[8553]: chan_sip.c:10778 add_sdp: ** Our prefcodec: 0x0 (nothing)
[May 23 17:50:24] DEBUG[8553]: chan_sip.c:10887 add_sdp: -- Done with adding codecs to SDP
[May 23 17:50:24] DEBUG[8553]: chan_sip.c:11026 add_sdp: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw)
[May 23 17:50:24] DEBUG[8553]: chan_sip.c:3230 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 10.10.10.12:5060
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:7603 find_call: = Looking for  Call ID: [email protected] (Checking From) --From tag 2003203917 --To-tag as0a185136
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:23874 handle_incoming: **** Received ACK (6) - Command in SIP ACK
[May 23 17:50:24] DEBUG[8545]: chan_sip.c:3922 __sip_ack: Stopping retransmission on '[email protected]' of Response 9: Match Found
[May 23 17:50:24] DEBUG[8553]: res_rtp_asterisk.c:1673 ast_rtcp_read: Got RTCP report of 28 bytes
[May 23 17:50:24] DEBUG[8553]: chan_sip.c:7069 sip_rtp_read: Oooh, format changed to gsm
[May 23 17:50:24] DEBUG[8553]: channel.c:5048 set_format: Set channel SIP/12-00000000 to read format ulaw
[May 23 17:50:24] DEBUG[8553]: channel.c:5048 set_format: Set channel SIP/12-00000000 to write format ulaw
[May 23 17:50:24] DEBUG[8553]: app_voicemail.c:5541 leave_voicemail: Before find_user
[May 23 17:50:24] DEBUG[8553]: app_voicemail.c:5653 leave_voicemail: /opt/var/spool/asterisk/voicemail/default/9999/unavail doesn't exist, doing what we can
[May 23 17:50:24] DEBUG[8553]: channel.c:5048 set_format: Set channel SIP/12-00000000 to write format gsm
[May 23 17:50:24] DEBUG[8553]: res_rtp_asterisk.c:1239 ast_rtp_write: Ooh, format changed from unknown to gsm
[May 23 17:50:24] DEBUG[8553]: res_rtp_asterisk.c:1270 ast_rtp_write: Created smoother: format: gsm ms: 20 len: 33
[May 23 17:50:24] DEBUG[8553]: channel.c:3427 ast_settimeout: Scheduling timer at (50 requested / 50 actual) timer ticks per second
Segmentation fault
@asus:/tmp/home/root#

das angeblich nicht existierende verzeichnis ist aber vorhanden...:
root@asus:/opt/var/spool/asterisk/voicemail/default# cd /opt/var/spool/asterisk/voicemail/default/9999/unavail
root@asus:/opt/var/spool/asterisk/voicemail/default/9999/unavail#

beim 2. versuch tritt der fehler dann an etwas anderer stelle auf:

*CLI> [May 23 17:55:30] DEBUG[8589]: chan_sip.c:7603 find_call: = Looking for  Call ID: [email protected] (Checking From) --From tag 1434891903 --To-tag
[May 23 17:55:30] DEBUG[8589]: acl.c:725 ast_ouraddrfor: For destination '10.10.10.12', our source address is '10.10.10.2'.
[May 23 17:55:30] DEBUG[8589]: chan_sip.c:3384 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 10.10.10.2:5060
[May 23 17:55:30] DEBUG[8589]: chan_sip.c:7360 sip_alloc: Allocating new SIP dialog for [email protected] - INVITE (No RTP)
[May 23 17:55:30] DEBUG[8589]: chan_sip.c:23874 handle_incoming: **** Received INVITE (5) - Command in SIP INVITE
[May 23 17:55:30] DEBUG[8589]: sip/reqresp_parser.c:1584 parse_sip_options: Begin: parsing SIP "Supported: 100rel, replaces, from-change"
[May 23 17:55:30] DEBUG[8589]: sip/reqresp_parser.c:1600 parse_sip_options: Found SIP option: -100rel-
[May 23 17:55:30] DEBUG[8589]: sip/reqresp_parser.c:1608 parse_sip_options: Matched SIP option: 100rel
[May 23 17:55:30] DEBUG[8589]: sip/reqresp_parser.c:1600 parse_sip_options: Found SIP option: -replaces-
[May 23 17:55:30] DEBUG[8589]: sip/reqresp_parser.c:1608 parse_sip_options: Matched SIP option: replaces
[May 23 17:55:30] DEBUG[8589]: sip/reqresp_parser.c:1600 parse_sip_options: Found SIP option: -from-change-
[May 23 17:55:30] DEBUG[8589]: sip/reqresp_parser.c:1608 parse_sip_options: Matched SIP option: from-change
[May 23 17:55:30] DEBUG[8589]: netsock2.c:125 ast_sockaddr_split_hostport: Splitting '10.10.10.12:5060' gives...
[May 23 17:55:30] DEBUG[8589]: netsock2.c:155 ast_sockaddr_split_hostport: ...host '10.10.10.12' and port '5060'.
[May 23 17:55:30] DEBUG[8589]: chan_sip.c:3230 __sip_xmit: Trying to put 'SIP/2.0 401' onto UDP socket destined for 10.10.10.12:5060
[May 23 17:55:30] DEBUG[8589]: chan_sip.c:7603 find_call: = Looking for  Call ID: [email protected] (Checking From) --From tag 1434891903 --To-tag as3bb183a0
[May 23 17:55:30] DEBUG[8589]: chan_sip.c:23874 handle_incoming: **** Received ACK (6) - Command in SIP ACK
[May 23 17:55:30] DEBUG[8589]: chan_sip.c:3922 __sip_ack: Stopping retransmission on '[email protected]' of Response 7: Match Found
[May 23 17:55:30] DEBUG[8589]: chan_sip.c:7603 find_call: = Looking for  Call ID: [email protected] (Checking From) --From tag 1434891903 --To-tag
[May 23 17:55:30] DEBUG[8589]: netsock2.c:125 ast_sockaddr_split_hostport: Splitting '10.10.10.2' gives...
[May 23 17:55:30] DEBUG[8589]: netsock2.c:155 ast_sockaddr_split_hostport: ...host '10.10.10.2' and port '(null)'.
[May 23 17:55:30] DEBUG[8589]: netsock2.c:125 ast_sockaddr_split_hostport: Splitting '10.10.10.2' gives...
[May 23 17:55:30] DEBUG[8589]: netsock2.c:155 ast_sockaddr_split_hostport: ...host '10.10.10.2' and port '(null)'.
[May 23 17:55:30] DEBUG[8589]: chan_sip.c:23874 handle_incoming: **** Received INVITE (5Segmentation fault
@asus:/tmp/home/root#

Guter Rat wäre hier prima...

gruß und danke,
astrakid

 

[chaos2000]

ein cli log hilft in diesem fall nicht, da die ausgaben durch scheduler gehen.
/opt/var/spool/asterisk/voicemail/default/9999/unavail sollte auch kein verzeichnis, sondern eine Datei sein. Das Verzeichnis ist
/opt/var/spool/asterisk/voicemail/default/9999 und unavail ist die unavail-message.

 

[astrakid]

könnte das der fehler sein? wenn keine unavail-message existiert, muss ja irgendetwas passieren. wobei ich erwarten würde, dass er sie aus dem standard-repertoire abgreift, falls nichts existiert.
werde das später nochmal testen. hab jetzt allerdings mal die 1.6er installiert - die lief nie, ist immer mit segmentation fault beim startup abgebrochen, bis ich die can_iax2.so entfernt habe. vielleicht habe ich da ja diese probleme nicht...

gruß und danke, ich melde mich wieder.
astrakid

 

[chaos2000]

wenn unavail-message nicht existiert kommt eine andere Ansage.
Lass mich raten, du hattest die config fur iax nicht drauf?

 

[astrakid]

jein. die conf-datei existiert, aber es steht im prinzip nichts drin. kann das denn den fehler verursachen? würde mich schon etwas wundern...

 

[chaos2000]

ich glaube ich hatte mal ähnliches verhalten beobachtet

 

[astrakid]

was wäre die lösung? config-file löschen? iax konfigurieren? aber was? es gibt doch Standard-Werte, die dann gesetzt sind?

 

[astrakid]

hi,
hab nun asterisk16ans rennen bekommen (musste chan_iax2.so entfernen). dort tritt das gleiche problem auf.
hier der auszug aus dem log:

[May 24 19:50:03] DEBUG[8219]: chan_sip.c:21788 handle_incoming: **** Received ACK (6) - Command in SIP ACK
[May 24 19:50:03] DEBUG[8219]: chan_sip.c:4144 __sip_ack: Stopping retransmission on '1q3n6vDvXyeaJY6cF6r5wksUEHICBdzt' of Response 12934: Match Found
[May 24 19:50:03] DEBUG[8250]: app_voicemail.c:5255 leave_voicemail: Before find_user
[May 24 19:50:03] DEBUG[8250]: app_voicemail.c:5348 leave_voicemail: /opt/var/spool/asterisk/voicemail/default/9999/unavail doesn't exist, doing what we can
[May 24 19:50:03] DEBUG[8250]: channel.c:3925 set_format: Set channel SIP/11-00000000 to write format gsm
[May 24 19:50:03] DEBUG[8250]: rtp.c:3881 ast_rtp_write: Ooh, format changed from unknown to ulaw
[May 24 19:50:03] DEBUG[8250]: rtp.c:3907 ast_rtp_write: Created smoother: format: 4 ms: 20 len: 160
[May 24 19:50:03] DEBUG[8250]: channel.c:2488 ast_settimeout: Scheduling timer at (50 requested / 50 actual) timer ticks per second

Im Debug-Log sieht es fast genauso aus:

[May 24 19:50:03] DEBUG[8219] chan_sip.c: -- Done with adding codecs to SDP
[May 24 19:50:03] DEBUG[8219] chan_sip.c: Done building SDP. Settling with this capability: 0x4 (ulaw)
[May 24 19:50:03] DEBUG[8219] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.2.22:33364
[May 24 19:50:03] DEBUG[8250] rtp.c: Got RTCP report of 8 bytes
[May 24 19:50:03] DEBUG[8250] rtp.c: Got RTCP report of 32 bytes
[May 24 19:50:03] DEBUG[8219] chan_sip.c: **** Received ACK (6) - Command in SIP ACK
[May 24 19:50:03] DEBUG[8219] chan_sip.c: Stopping retransmission on '1q3n6vDvXyeaJY6cF6r5wksUEHICBdzt' of Response 12934: Match Found
[May 24 19:50:03] DEBUG[8250] app_voicemail.c: Before find_user
[May 24 19:50:03] DEBUG[8250] app_voicemail.c: /opt/var/spool/asterisk/voicemail/default/9999/unavail doesn't exist, doing what we can
[May 24 19:50:03] DEBUG[8250] channel.c: Set channel SIP/11-00000000 to write format gsm
[May 24 19:50:03] DEBUG[8250] rtp.c: Ooh, format changed from unknown to ulaw
[May 24 19:50:03] DEBUG[8250] rtp.c: Created smoother: format: 4 ms: 20 len: 160
[May 24 19:50:03] DEBUG[8250] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second

was ist das??? brauche dringend hilfe...

 

[astrakid]

hab jetzt mal die rechte auf das verzeichnis ..../9999/* auf 777 gesetzt - damit sieht es etwas anders aus:

    -- Nobody picked up in 15000 ms
[May 24 20:03:02] DEBUG[8714]: rtp.c:2148 ast_rtp_early_bridge: Channel '<unspecified>' has no RTP, not doing anything
[May 24 20:03:02] DEBUG[8714]: channel.c:1820 ast_hangup: Hanging up channel 'SIP/11-00000001'
[May 24 20:03:02] DEBUG[8714]: chan_sip.c:6065 sip_hangup: Hangup call SIP/11-00000001, SIP callid [email protected]
[May 24 20:03:02] DEBUG[8714]: chan_sip.c:6084 sip_hangup: Hanging up channel in state Down (not UP)
[May 24 20:03:02] DEBUG[8714]: chan_sip.c:4107 __sip_ack: Acked pending invite 102
[May 24 20:03:02] DEBUG[8714]: chan_sip.c:4144 __sip_ack: Stopping retransmission on '[email protected]' of Request 102: Match Found
[May 24 20:03:02] DEBUG[8714]: app_dial.c:2326 dial_exec_full: Exiting with DIALSTATUS=NOANSWER.
[May 24 20:03:02] DEBUG[8714]: pbx.c:3696 pbx_extension_helper: Launching 'VoiceMail'
    -- Executing [11@telefone:3] VoiceMail("SIP/12-00000000", "9999,u") in new stack
[May 24 20:03:02] DEBUG[8714]: chan_sip.c:6257 sip_answer: SIP answering channel: SIP/12-00000000
[May 24 20:03:02] DEBUG[8714]: rtp.c:2690 ast_rtp_new_source: Setting the marker bit due to a source update
[May 24 20:03:02] DEBUG[8714]: chan_sip.c:10562 transmit_response_with_sdp: Setting framing from config on incoming call
[May 24 20:03:02] DEBUG[8714]: chan_sip.c:10259 add_sdp: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: True Text flag: True
[May 24 20:03:02] DEBUG[8714]: chan_sip.c:10260 add_sdp: ** Our prefcodec: 0x0 (nothing)
[May 24 20:03:02] DEBUG[8714]: chan_sip.c:10371 add_sdp: -- Done with adding codecs to SDP
[May 24 20:03:02] DEBUG[8714]: chan_sip.c:10495 add_sdp: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw)
[May 24 20:03:02] DEBUG[8714]: chan_sip.c:3608 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.2.12:5060
[May 24 20:03:02] DEBUG[8563]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - 11
[May 24 20:03:02] DEBUG[8563]: chan_sip.c:23147 sip_devicestate: Checking device state for peer 11
[May 24 20:03:02] DEBUG[8563]: devicestate.c:462 do_state_change: Changing state for SIP/11 - state 1 (Not in use)
[May 24 20:03:02] DEBUG[8563]: devicestate.c:442 devstate_event: device 'SIP/11' state '1'
[May 24 20:03:02] DEBUG[8563]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - 12
[May 24 20:03:02] DEBUG[8563]: chan_sip.c:23147 sip_devicestate: Checking device state for peer 12
[May 24 20:03:02] DEBUG[8563]: devicestate.c:462 do_state_change: Changing state for SIP/12 - state 1 (Not in use)
[May 24 20:03:02] DEBUG[8563]: devicestate.c:442 devstate_event: device 'SIP/12' state '1'
Rantanplan_Asus*CLI>
Disconnected from Asterisk server
Executing last minute cleanups
Asterisk ending (0).

aber so richtig hilft mir das auch nicht weiter... die mailbox brauche ich halt. anders macht asterisk keinen sinn...

 

[chaos2000]

ohne backtrace keine chance das zu finden.
Welche Asterisk version ist das, gibt es vielleicht ein issue dazu im bugtracker?

 

[astrakid]

Asterisk 1.6.2.13. Im Bugtracker habe ich nichts konkretes finden können.
wie mache ich einen backtrace? gibt es dafür spezielle funktionen in asterisk, oder läuft das nur über den sourcecode?

 

[astrakid]

hab mal versucht, mit gdb ein core-file zu erstellen - klappt nicht. bin jetzt mal wieder auf 1.4 umgestiegen - da läuft alles wie es soll. keine ahnung, warum...?!

 

[chaos2000]

core file erstellst du am schnellsten, wenn du asterisk mit safe_asterisk oder asterisk -gcvvvv startest.

 

[astrakid]

ich weiß, aber das funktioniert leider nicht. es wird einfach kein core-file geschrieben!

 

[astrakid]

Fehler gefunden (stand in einem anderen forum, leider etwas versteckt, daher findet man es nicht sehr schnell):
noload => res_timing_pthread.so
und dann klappt es.

gruß,
astrakid