Hangup after 4 minuts

Asterisk Asterisk Support
1

Hello,

Here is my extension.conf:

exten => XXXXXXXXXX,1,Ringing
exten => XXXXXXXXXX,2,Wait
exten => XXXXXXXXXX,3,Answer
exten => XXXXXXXXXX,4,SET(CDR(userfield)=${EPOCH})
exten => XXXXXXXXXX,5,Dial(SIP/XXXXXXXXXX/YYYYYYYYYY,20,mA(/var/lib/asterisk/sounds/message))
exten => XXXXXXXXXX,6,Playback(/var/lib/asterisk/sounds/vm)
exten => XXXXXXXXXX,7,Record(/var/spool/asterisk/vm/${UNIQUEID}.wav, 0, 0, k)
exten => XXXXXXXXXX,8,Hangup()

I call the num XXXXXXXXXX, the number YYYYYYYYYY is ringing. When the called party answers, he listen the audio message /var/lib/asterisk/sounds/message. If nobody answers, the server plays the audio file /var/lib/asterisk/sounds/vm and record a message.

My problem is the server hangs up after 4 minuts and the record stops. Have you got an idea to resolve this problem?

This is the log when the server hangs up:

[Jul 26 12:00:13] DEBUG[10728] chan_sip.c: = Looking for Call ID: 06781-OL-00224875-7d96985b0@sip.ovh.net (Checking From) --From tag 06781-JU-00224876-524ea 9983 --To-tag as66c9db4b [Jul 26 12:00:13] DEBUG[10728] chan_sip.c: **** Received BYE (8) - Command in SIP BYE [Jul 26 12:00:13] DEBUG[10728] netsock2.c: Splitting '91.121.129.17:5060' gives... [Jul 26 12:00:13] DEBUG[10728] netsock2.c: ...host '91.121.129.17' and port '5060'. [Jul 26 12:00:13] DEBUG[10728] chan_sip.c: Setting SIP_ALREADYGONE on dialog 06781-OL-00224875-7d96985b0@sip.ovh.net [Jul 26 12:00:13] DEBUG[10728] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xd63ac8' [Jul 26 12:00:13] DEBUG[10728] chan_sip.c: Received bye, issuing owner hangup [Jul 26 12:00:13] DEBUG[10728] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 91.121.129.17:5060 [Jul 26 12:00:13] DEBUG[13334] app_record.c: Got hangup [Jul 26 12:00:13] DEBUG[13334] pbx.c: Spawn extension (home,0183629259,7) exited non-zero on 'SIP/ovh-00000228' [Jul 26 12:00:13] VERBOSE[13334] pbx.c: == Spawn extension (home, 0183629259, 7) exited non-zero on 'SIP/ovh-00000228' [Jul 26 12:00:13] DEBUG[13334] channel.c: Soft-Hanging up channel 'SIP/ovh-00000228' [Jul 26 12:00:13] DEBUG[13334] channel.c: Hanging up channel 'SIP/ovh-00000228' [Jul 26 12:00:13] DEBUG[13334] chan_sip.c: Hangup call SIP/ovh-00000228, SIP callid 06781-OL-00224875-7d96985b0@sip.ovh.net [Jul 26 12:00:13] DEBUG[13334] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xd63ac8' [Jul 26 12:00:13] DEBUG[13334] cdr_addon_mysql.c: Inserting a CDR record.

Thanks

2

Check your SIP debug to see what’s going on that results in:

3

This is my SIP debug log:

[code]<— SIP read from UDP:91.121.129.17:5060 —>
Cirpack KeepAlive Packet
<------------->

<— SIP read from UDP:91.121.129.17:5060 —>
BYE sip:XXXXXXXXXX@94.23.22.108:5060 SIP/2.0
Call-ID: 19709-HV-00285190-29cd08a14@sip.ovh.net
CSeq: 2634558 BYE
From: “ZZZZZZZZZZ” sip:ZZZZZZZZZZ@sip.ovh.net;user=phone;tag=19709-XN-00285191-774678bc7
Max-Forwards: 30
To: sip:XXXXXXXXXX@91.121.129.17;user=phone;tag=as252df827
User-Agent: Cirpack/v4.42g (gw_sip)
Via: SIP/2.0/UDP 91.121.129.17:5060;branch=z9hG4bK-7661-2D74A
Content-Length: 0

<------------->
— (9 headers 0 lines) —
Sending to 91.121.129.17:5060 (NAT)
Scheduling destruction of SIP dialog ‘19709-HV-00285190-29cd08a14@sip.ovh.net’ in 32000 ms (Method: BYE)

<— Transmitting (NAT) to 91.121.129.17:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 91.121.129.17:5060;branch=z9hG4bK-7661-2D74A;received=91.121.129.17;rport=5060
From: “ZZZZZZZZZZ” sip:ZZZZZZZZZZ@sip.ovh.net;user=phone;tag=19709-XN-00285191-774678bc7
To: sip:XXXXXXXXXX@91.121.129.17;user=phone;tag=as252df827
Call-ID: 19709-HV-00285190-29cd08a14@sip.ovh.net
CSeq: 2634558 BYE
Server: Asterisk PBX 1.8.3
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

<------------>
– User hung up
== Spawn extension (home, XXXXXXXXXX, 6) exited non-zero on ‘SIP/ovh-00000297’

<— SIP read from UDP:91.121.129.17:5060 —>
Cirpack KeepAlive Packet
<------------->
[/code]

I tried to make a call from different phones, the problem is the same.
I’ve change my extension. Now, the extension.conf contains:
exten => XXXXXXXXXX,1,Ringing
exten => XXXXXXXXXX,2,Wait
exten => XXXXXXXXXX,3,Answer
exten => XXXXXXXXXX,4,SET(CDR(userfield)=${EPOCH})
exten => XXXXXXXXXX,5,Dial(SIP/XXXXXXXXXX/YYYYYYYYYY,20,mA(/var/lib/asterisk/sounds/message))
exten => XXXXXXXXXX,6,Voicemail(1000@default)
exten => XXXXXXXXXX,7,Hangup()

4

Try the suggestion here:
issues.asterisk.org/view.php?id=7261

Also looks like someone made some patches here:
lists.digium.com/pipermail/aster … 05617.html

But they were never pushed properly through the issue tracker:
issues.asterisk.org/view.php?id=9816

5

The patch is for Asterisk 1.4
My version of Asterisk is 1.8.3. Can I patch the source files?

6

Probably not without forward-porting the patch; I haven’t looked at it.

You could try the iptables suggestion without making any patches.

7

The iptables command didn’t work.

This one is ok for me:
iptables -I INPUT -p udp --src 91.121.129.17 --dport 5060 -m string --algo bm --string “Cirpack KeepAlive Packet” -j DROP

(IP source is my provider’s trunk)

But my problem stills, the server hangs up after 4 min

8

This is my complete log starting at Voicemail recording. The number XXXXXXXXXX is my called num, ZZZZZZZZZZ is my source num. home is my exten.

[code]The log has changed:

[code][Jul 28 09:32:28] VERBOSE[12057] app_voicemail.c: – Recording the message
[Jul 28 09:32:28] DEBUG[12057] app.c: play_and_record: , /var/spool/asterisk/voicemail/default/XXXXXXXXXX/tmp/lfyMDc, ‘wav’
[Jul 28 09:32:28] DEBUG[12057] app.c: Recording Formats: sfmts=wav
[Jul 28 09:32:28] VERBOSE[12057] app.c: – x=0, open writing: /var/spool/asterisk/voicemail/default/XXXXXXXXXX/tmp/lfyMDc format: wav, 0x7f88d803d208
[Jul 28 09:32:28] DEBUG[12057] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21
[Jul 28 09:32:28] DEBUG[12057] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116
[Jul 28 09:32:28] DEBUG[12057] channel.c: Set channel SIP/ovh-000002b5 to read format slin
[Jul 28 09:35:52] VERBOSE[10728] chan_sip.c:
<— SIP read from UDP:91.121.129.17:5060 —>
BYE sip:XXXXXXXXXX@94.23.22.108:5060 SIP/2.0
Call-ID: 23506-GD-013aab7a-686683c64@sip.ovh.net
CSeq: 20600969 BYE
From: “Me” sip:ZZZZZZZZZZ@sip.ovh.net;user=phone;tag=23506-MX-013aab7b-4b785c442
Max-Forwards: 29
Reason: q.850;cause=41
To: sip:XXXXXXXXXX@91.121.129.17;user=phone;tag=as660b67b5
User-Agent: Cirpack/v4.42g (gw_sip)
Via: SIP/2.0/UDP 91.121.129.17:5060;branch=z9hG4bK-3BF8-AE08D
Content-Length: 0

<------------->
[Jul 28 09:35:52] DEBUG[10728] chan_sip.c: Header 0 [ 44]: BYE sip:XXXXXXXXXX@94.23.22.108:5060 SIP/2.0
[Jul 28 09:35:52] DEBUG[10728] chan_sip.c: Header 1 [ 48]: Call-ID: 23506-GD-013aab7a-686683c64@sip.ovh.net
[Jul 28 09:35:52] DEBUG[10728] chan_sip.c: Header 2 [ 18]: CSeq: 20600969 BYE
[Jul 28 09:35:52] DEBUG[10728] chan_sip.c: Header 3 [ 95]: From: “Me” sip:ZZZZZZZZZZ@sip.ovh.net;user=phone;tag=23506-MX-013aab7b-4b785c442
[Jul 28 09:35:52] DEBUG[10728] chan_sip.c: Header 4 [ 16]: Max-Forwards: 29
[Jul 28 09:35:52] DEBUG[10728] chan_sip.c: Header 5 [ 22]: Reason: q.850;cause=41
[Jul 28 09:35:52] DEBUG[10728] chan_sip.c: Header 6 [ 60]: To: sip:XXXXXXXXXX@91.121.129.17;user=phone;tag=as660b67b5
[Jul 28 09:35:52] DEBUG[10728] chan_sip.c: Header 7 [ 35]: User-Agent: Cirpack/v4.42g (gw_sip)
[Jul 28 09:35:52] DEBUG[10728] chan_sip.c: Header 8 [ 61]: Via: SIP/2.0/UDP 91.121.129.17:5060;branch=z9hG4bK-3BF8-AE08D
[Jul 28 09:35:52] DEBUG[10728] chan_sip.c: Header 9 [ 17]: Content-Length: 0
[Jul 28 09:35:52] VERBOSE[10728] chan_sip.c: — (10 headers 0 lines) —
[Jul 28 09:35:52] DEBUG[10728] chan_sip.c: = Looking for Call ID: 23506-GD-013aab7a-686683c64@sip.ovh.net (Checking From) --From tag 23506-MX-013aab7b-4b785c442 --To-tag as660b67b5
[Jul 28 09:35:52] DEBUG[10728] chan_sip.c: **** Received BYE (8) - Command in SIP BYE
[Jul 28 09:35:52] DEBUG[10728] chan_sip.c: Initializing initreq for method BYE - callid 23506-GD-013aab7a-686683c64@sip.ovh.net
[Jul 28 09:35:52] DEBUG[10728] netsock2.c: Splitting ‘91.121.129.17:5060’ gives…
[Jul 28 09:35:52] DEBUG[10728] netsock2.c: …host ‘91.121.129.17’ and port ‘5060’.
[Jul 28 09:35:52] VERBOSE[10728] chan_sip.c: Sending to 91.121.129.17:5060 (NAT)
[Jul 28 09:35:52] DEBUG[10728] chan_sip.c: Setting SIP_ALREADYGONE on dialog 23506-GD-013aab7a-686683c64@sip.ovh.net
[Jul 28 09:35:52] DEBUG[10728] res_rtp_asterisk.c: Setting RTCP address on RTP instance ‘0xe96a18’
[Jul 28 09:35:52] VERBOSE[10728] chan_sip.c: Scheduling destruction of SIP dialog ‘23506-GD-013aab7a-686683c64@sip.ovh.net’ in 32000 ms (Method: BYE)
[Jul 28 09:35:52] DEBUG[10728] chan_sip.c: Received bye, issuing owner hangup
[Jul 28 09:35:52] VERBOSE[10728] chan_sip.c:
<— Transmitting (NAT) to 91.121.129.17:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 91.121.129.17:5060;branch=z9hG4bK-3BF8-AE08D;received=91.121.129.17;rport=5060
From: “Me” sip:ZZZZZZZZZZ@sip.ovh.net;user=phone;tag=23506-MX-013aab7b-4b785c442
To: sip:XXXXXXXXXX@91.121.129.17;user=phone;tag=as660b67b5
Call-ID: 23506-GD-013aab7a-686683c64@sip.ovh.net
CSeq: 20600969 BYE
Server: Asterisk PBX 1.8.3
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

<------------>
[Jul 28 09:35:52] DEBUG[10728] chan_sip.c: Trying to put ‘SIP/2.0 200’ onto UDP socket destined for 91.121.129.17:5060
[Jul 28 09:35:52] VERBOSE[12057] app.c: – User hung up
[Jul 28 09:35:52] DEBUG[12057] channel.c: Set channel SIP/ovh-000002b5 to read format alaw
[Jul 28 09:35:52] DEBUG[12057] app.c: Locked path ‘/var/spool/asterisk/voicemail/default/XXXXXXXXXX/INBOX’
[Jul 28 09:35:52] DEBUG[12057] app.c: Unlocked path ‘/var/spool/asterisk/voicemail/default/XXXXXXXXXX/INBOX’
[Jul 28 09:35:52] DEBUG[12057] app_voicemail.c: Attaching file ‘/var/spool/asterisk/voicemail/default/XXXXXXXXXX/INBOX/msg0000’, format ‘wav’, uservm is ‘0’, global is 0
[Jul 28 09:35:52] DEBUG[12057] app_voicemail.c: Sent mail to with command ‘/usr/sbin/sendmailmp3’
[Jul 28 09:35:52] DEBUG[12057] app_voicemail.c: Sent page to with command ‘/usr/sbin/sendmailmp3’
[Jul 28 09:35:52] DEBUG[12057] pbx.c: Spawn extension (home,XXXXXXXXXX,6) exited non-zero on ‘SIP/ovh-000002b5’
[Jul 28 09:35:52] VERBOSE[12057] pbx.c: == Spawn extension (home, XXXXXXXXXX, 6) exited non-zero on ‘SIP/ovh-000002b5’
[Jul 28 09:35:52] DEBUG[12057] channel.c: Soft-Hanging up channel ‘SIP/ovh-000002b5’
[Jul 28 09:35:52] DEBUG[12057] channel.c: Hanging up channel ‘SIP/ovh-000002b5’
[Jul 28 09:35:52] DEBUG[12057] chan_sip.c: Hangup call SIP/ovh-000002b5, SIP callid 23506-GD-013aab7a-686683c64@sip.ovh.net
[Jul 28 09:35:52] DEBUG[12057] res_rtp_asterisk.c: Setting RTCP address on RTP instance ‘0xe96a18’
[Jul 28 09:35:52] DEBUG[12057] cdr_addon_mysql.c: Inserting a CDR record.
[Jul 28 09:35:52] DEBUG[12057] cdr_addon_mysql.c: SQL command as follows: INSERT INTO cdr (calldate,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,userfield,uniqueid) VALUES (‘2011-07-28 09:31:51’,‘ZZZZZZZZZZ’,‘XXXXXXXXXX’,‘home’,‘SIP/ovh-000002b5’,‘SIP/XXXXXXXXXX-000002b6’,‘VoiceMail’,‘XXXXXXXXXX@default’,‘241’,‘241’,‘NO ANSWER’,‘3’,‘1311838312’,‘1311838311.693’)
[Jul 28 09:35:52] DEBUG[12057] pbx.c: Function result is ‘2011-07-28 09:31:51’
[Jul 28 09:35:52] DEBUG[12057] pbx.c: Function result is ‘“Me” ‘
[Jul 28 09:35:52] DEBUG[12057] pbx.c: Function result is ‘home’
[Jul 28 09:35:52] DEBUG[12057] pbx.c: Function result is ‘SIP/ovh-000002b5’
[Jul 28 09:35:52] DEBUG[12057] pbx.c: Function result is ‘SIP/XXXXXXXXXX-000002b6’
[Jul 28 09:35:52] DEBUG[12057] pbx.c: Function result is ‘VoiceMail’
[Jul 28 09:35:52] DEBUG[12057] pbx.c: Function result is ‘XXXXXXXXXX@default’
[Jul 28 09:35:52] DEBUG[12057] pbx.c: Function result is ‘241’
[Jul 28 09:35:52] DEBUG[12057] pbx.c: Function result is ‘241’
[Jul 28 09:35:52] DEBUG[12057] pbx.c: Function result is ‘NO ANSWER’
[Jul 28 09:35:52] DEBUG[12057] pbx.c: Function result is ‘DOCUMENTATION’
[Jul 28 09:35:52] DEBUG[12057] pbx.c: Function result is ‘(null)’
[Jul 28 09:35:52] DEBUG[12057] pbx.c: Function result is ‘1311838311.693’
[Jul 28 09:35:52] DEBUG[12057] pbx.c: Function result is ‘1311838312’
[Jul 28 09:35:52] DEBUG[12057] pbx.c: Function result is ‘(null)’
[Jul 28 09:35:52] DEBUG[12057] cdr_sqlite3_custom.c: About to log: INSERT INTO cdr (calldate,clid,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield,test) VALUES (‘2011-07-28 09:31:51’,’“Me” ‘,‘home’,‘SIP/ovh-000002b5’,‘SIP/XXXXXXXXXX-000002b6’,‘VoiceMail’,‘XXXXXXXXXX@default’,‘241’,‘241’,‘NO ANSWER’,‘DOCUMENTATION’,’’,‘1311838311.693’,‘1311838312’,’’)
[Jul 28 09:35:52] DEBUG[10717] devicestate.c: No provider found, checking channel drivers for SIP - ovh
[Jul 28 09:35:52] DEBUG[10717] chan_sip.c: Checking device state for peer ovh
[Jul 28 09:35:52] DEBUG[10717] devicestate.c: Changing state for SIP/ovh - state 1 (Not in use)
[Jul 28 09:35:52] DEBUG[10717] devicestate.c: device ‘SIP/ovh’ state ‘1’
[Jul 28 09:35:52] DEBUG[10755] app_queue.c: Device ‘SIP/ovh’ changed to state ‘1’ (Not in use) but we don’t care because they’re not a member of any queue.
[Jul 28 09:36:24] DEBUG[10728] chan_sip.c: Auto destroying SIP dialog ‘23506-GD-013aab7a-686683c64@sip.ovh.net’
[Jul 28 09:36:24] DEBUG[10728] chan_sip.c: Destroying SIP dialog 23506-GD-013aab7a-686683c64@sip.ovh.net
[Jul 28 09:36:24] VERBOSE[10728] chan_sip.c: Really destroying SIP dialog ‘23506-GD-013aab7a-686683c64@sip.ovh.net’ Method: BYE
[Jul 28 09:36:24] DEBUG[10728] rtp_engine.c: Destroyed RTP instance ‘0xe96a18’
[/code]
[/code]

9

I’d ask your provider if they can disable the Cirpack keepalive packet. Presumably they’re expecting some reply to it that Asterisk isn’t generating, and they’re sending the BYE. They’re hanging up on you.

10

Have you got an answer from OVH?
Thank you for your help!

11

You need to ask your provider. Malcom did not say that he would ask for you.

12

heheh