I am working around this by having the front desk use the "##" transfer.
I am dealing with tech support on the SIP device. (a 24 port SIP to digital handset converter) I am not sure which is at fault, asterisk or the SIP device. -- -- Steven http://www.glimasoutheast.org "Steven" <[EMAIL PROTECTED]> wrote in message news:[EMAIL PROTECTED] > Could there be something going on in asterisk to make the first request fail, > so that the SIP device cancels and retries the > transfer(refer)? > > Could it be manager overuse? > > -- > -- > Steven > > http://www.glimasoutheast.org > > > > "BerkHolz, Steven" <[EMAIL PROTECTED]> wrote in message > news:[EMAIL PROTECTED] > We are having an issue with transferred calls being dropped. > > Looking at the asterisk 1.2.10 logs, it appears that when it is dropped, > the SIP unit send a CANCEL message to the server. > On successful transfers this is not seen. > > The errors logged in the SIP Unit error log, I believe are from the > second attempt to transfer the call, after it has actually been > disconnected. > > Nothing is deferent in the logs above the CANCEL request for successful > or failed transfers. > So, I am not sure why the CANCEL is being sent. > > I can not discern what may be different when it fails. > > > > > Thank You, > > Steven BerkHolz > Board member of > www.glimasoutheast.org > > > > > > ref: from SIP Phone (I think these are the second invite after it is > hung up) > > 2006-OCT-20 17:49:52 GMT +++ Current Timestamp +++ > 2006-OCT-20 17:19:47 GMT NLPA ERROR: sipFailureResponseToRefer: received > 603 response to REFER > 2006-OCT-20 15:56:37 GMT NLPA ERROR: sipFailureResponseToRefer: received > 603 response to REFER > 2006-OCT-20 15:50:00 GMT NLPA ERROR: sipFailureResponseToRefer: received > 603 response to REFER > 2006-OCT-20 15:45:38 GMT NLPA ERROR: sipFailureResponseToRefer: received > 603 response to REFER > 2006-OCT-20 15:11:28 GMT NLPA ERROR: sipFailureResponseToRefer: received > 603 response to REFER > 2006-OCT-20 15:10:58 GMT NLPA ERROR: sipFailureResponseToRefer: received > 603 response to REFER > 2006-OCT-20 14:59:26 GMT NLPA ERROR: sipFailureResponseToRefer: received > 603 response to REFER > 2006-OCT-20 12:45:30 GMT NLPA ERROR: sipFailureResponseToRefer: received > 603 response to REFER > 2006-OCT-19 19:53:25 GMT NLPA ERROR: sipFailureResponseToRefer: received > 603 response to REFER > 2006-OCT-19 18:40:52 GMT NLPA ERROR: sipFailureResponseToRefer: received > 603 response to REFER > 2006-OCT-19 18:03:45 GMT NLPA ERROR: sipFailureResponseToRefer: received > 603 response to REFER > 2006-OCT-19 17:55:55 GMT NLPA ERROR: sipFailureResponseToRefer: received > 603 response to REFER > 2006-OCT-19 15:09:13 GMT NLPA ERROR: sipFailureResponseToRefer: received > 603 response to REFER > 2006-OCT-19 15:04:33 GMT NLPA ERROR: sipFailureResponseToRefer: received > 603 response to REFER > 2006-OCT-19 14:52:12 GMT NLPA ERROR: sipFailureResponseToRefer: received > 603 response to REFER > 2006-OCT-19 14:34:35 GMT NLPA ERROR: sipFailureResponseToRefer: received > 603 response to REFER > 2006-OCT-19 14:20:17 GMT NLPA ERROR: sipFailureResponseToRefer: received > 603 response to REFER > 2006-OCT-19 13:45:33 GMT NLPA ERROR: sipFailureResponseToRefer: received > 603 response to REFER > > > > > > ref. from asterisk 1.2.10 logs: > > Oct 20 13:19:45 VERBOSE[10652] logger.c: -- Requested transfer > capability: 0x00 - SPEECH > Oct 20 13:19:45 DEBUG[8159] channel.c: Avoiding initial deadlock for > 'Zap/25-1' > Oct 20 13:19:45 VERBOSE[10652] logger.c: -- Called g2/5155 > Oct 20 13:19:45 VERBOSE[10652] logger.c: Transmitting (no NAT) to > 172.16.8.200:5065: > SIP/2.0 180 Ringing > Via: SIP/2.0/UDP > 172.16.8.200:5065;branch=z9hG4bKline0-2425957956;received=172.16.8.200 > From: "From Desk"<sip:[EMAIL PROTECTED]>;tag=2425948795 > To: <sip:[EMAIL PROTECTED]>;tag=as279eb184 > Call-ID: [EMAIL PROTECTED] > CSeq: 2 INVITE > User-Agent: Asterisk PBX > Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY > Contact: <sip:[EMAIL PROTECTED]> > Content-Length: 0 > > > --- > Oct 20 13:19:45 DEBUG[10658] app_queue.c: Device 'Zap/25' changed to > state '2' (In use) but we don't care because they're not a member of any > queue. > Oct 20 13:19:45 DEBUG[8159] devicestate.c: Changing state for Zap/25 - > state 2 (In use) > Oct 20 13:19:45 DEBUG[10659] app_queue.c: Device 'Zap/25' changed to > state '2' (In use) but we don't care because they're not a member of any > queue. > Oct 20 13:19:45 DEBUG[8167] chan_zap.c: Enabled echo cancellation on > channel 25 > Oct 20 13:19:45 VERBOSE[10652] logger.c: -- Zap/25-1 is ringing > Oct 20 13:19:45 DEBUG[8159] devicestate.c: Changing state for Zap/25 - > state 6 (Ringing) > Oct 20 13:19:45 DEBUG[10660] app_queue.c: Device 'Zap/25' changed to > state '6' (Ringing) but we don't care because they're not a member of > any queue. > Oct 20 13:19:45 DEBUG[8171] chan_sip.c: Header 0: (0) > Oct 20 13:19:46 VERBOSE[8171] logger.c: > <-- SIP read from 172.16.8.200:5065: > CANCEL sip:[EMAIL PROTECTED] SIP/2.0 > Via: SIP/2.0/UDP 172.16.8.200:5065;branch=z9hG4bKline0-2425957956 > To: <sip:[EMAIL PROTECTED]> > From: "From Desk"<sip:[EMAIL PROTECTED]>;tag=2425948795 > Call-Id: [EMAIL PROTECTED] > Max-Forwards: 70 > CSeq: 2 CANCEL > Content-Length: 0 > > > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 0: CANCEL > sip:[EMAIL PROTECTED] SIP/2.0 (36) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 1: Via: SIP/2.0/UDP > 172.16.8.200:5065;branch=z9hG4bKline0-2425957956 (65) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 2: To: > <sip:[EMAIL PROTECTED]> (27) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 3: From: "From > Desk"<sip:[EMAIL PROTECTED]>;tag=2425948795 (55) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 4: Call-Id: > [EMAIL PROTECTED] (43) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 5: Max-Forwards: 70 (16) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 6: CSeq: 2 CANCEL (14) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 7: Content-Length: 0 (17) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 8: (0) > Oct 20 13:19:46 VERBOSE[8171] logger.c: --- (8 headers 0 lines)Oct 20 > 13:19:46 VERBOSE[8171] logger.c: --- (8 headers 0 lines)--- > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: **** Received CANCEL (14) - > Command in SIP CANCEL > Oct 20 13:19:46 VERBOSE[8171] logger.c: Sending to 172.16.8.200 : 5065 > (non-NAT) > Oct 20 13:19:46 VERBOSE[8171] logger.c: Reliably Transmitting (no NAT) > to 172.16.8.200:5065: > SIP/2.0 487 Request Terminated > Via: SIP/2.0/UDP > 172.16.8.200:5065;branch=z9hG4bKline0-2425957956;received=172.16.8.200 > From: "From Desk"<sip:[EMAIL PROTECTED]>;tag=2425948795 > To: <sip:[EMAIL PROTECTED]>;tag=as279eb184 > Call-ID: [EMAIL PROTECTED] > CSeq: 2 INVITE > User-Agent: Asterisk PBX > Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY > Contact: <sip:[EMAIL PROTECTED]> > Content-Length: 0 > > > --- > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: *** SIP TIMER: Initalizing > retransmit timer on packet: Id #51636 > Oct 20 13:19:46 VERBOSE[8171] logger.c: Transmitting (no NAT) to > 172.16.8.200:5065: > SIP/2.0 200 OK > Via: SIP/2.0/UDP > 172.16.8.200:5065;branch=z9hG4bKline0-2425957956;received=172.16.8.200 > From: "From Desk"<sip:[EMAIL PROTECTED]>;tag=2425948795 > To: <sip:[EMAIL PROTECTED]>;tag=as279eb184 > Call-ID: [EMAIL PROTECTED] > CSeq: 2 CANCEL > User-Agent: Asterisk PBX > Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY > Contact: <sip:[EMAIL PROTECTED]> > Content-Length: 0 > > > --- > Oct 20 13:19:46 DEBUG[10652] channel.c: Hanging up channel 'Zap/25-1' > Oct 20 13:19:46 DEBUG[10652] chan_zap.c: zt_hangup(Zap/25-1) > Oct 20 13:19:46 DEBUG[10652] chan_zap.c: Set option AUDIO MODE, value: > ON(1) on Zap/25-1 > Oct 20 13:19:46 DEBUG[10652] chan_zap.c: Hangup: channel: 25 index = 0, > normal = 38, callwait = -1, thirdcall = -1 > Oct 20 13:19:46 DEBUG[10652] chan_zap.c: Not yet hungup... Calling > hangup once with icause, and clearing call > Oct 20 13:19:46 DEBUG[10652] chan_zap.c: disabled echo cancellation on > channel 25 > Oct 20 13:19:46 DEBUG[10652] chan_zap.c: Set option TDD MODE, value: > OFF(0) on Zap/25-1 > Oct 20 13:19:46 DEBUG[10652] chan_zap.c: Updated conferencing on 25, > with 0 conference users > Oct 20 13:19:46 DEBUG[10652] chan_zap.c: Set option AUDIO MODE, value: > OFF(0) on Zap/25-1 > Oct 20 13:19:46 DEBUG[10652] chan_zap.c: disabled echo cancellation on > channel 25 > Oct 20 13:19:46 VERBOSE[10652] logger.c: -- Hungup 'Zap/25-1' > Oct 20 13:19:46 DEBUG[10652] app_dial.c: Exiting with DIALSTATUS=CANCEL. > Oct 20 13:19:46 DEBUG[10652] app_macro.c: Spawn extension > (macro-dial,s,12) exited non-zero on 'SIP/5100-9f70a9b0' in macro 'dial' > Oct 20 13:19:46 DEBUG[10652] app_macro.c: Spawn extension > (macro-dial,s,12) exited non-zero on 'SIP/5100-9f70a9b0' in macro > 'exten-vm' > Oct 20 13:19:46 DEBUG[10652] pbx.c: Spawn extension (macro-dial,s,12) > exited non-zero on 'SIP/5100-9f70a9b0' > Oct 20 13:19:46 DEBUG[8159] devicestate.c: Changing state for Zap/25 - > state 0 (Unknown) > Oct 20 13:19:46 DEBUG[10652] cdr_addon_mysql.c: cdr_mysql: inserting a > CDR record. > Oct 20 13:19:46 DEBUG[10652] cdr_addon_mysql.c: cdr_mysql: SQL command > as follows: INSERT INTO cdr > (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,dura > tion,billsec,disposition,amaflags,accountcode,uniqueid) VALUES > ('2006-10-20 13:19:44','5100','5100','5155','from-internal', > 'SIP/5100-9f70a9b0','Zap/25-1','Dial','zap/g2/5155|15|r',2,0,'NO > ANSWER',3,'','1161364784.6637') > Oct 20 13:19:46 DEBUG[10652] pbx.c: Function result is '5100' > Oct 20 13:19:46 DEBUG[10652] pbx.c: Function result is '5100' > Oct 20 13:19:46 DEBUG[10652] pbx.c: Function result is '5155' > Oct 20 13:19:46 DEBUG[10652] pbx.c: Function result is 'from-internal' > Oct 20 13:19:46 DEBUG[10652] pbx.c: Function result is > 'SIP/5100-9f70a9b0' > Oct 20 13:19:46 DEBUG[10652] pbx.c: Function result is 'Zap/25-1' > Oct 20 13:19:46 DEBUG[10652] pbx.c: Function result is 'Dial' > Oct 20 13:19:46 DEBUG[10652] pbx.c: Function result is > 'zap/g2/5155|15|r' > Oct 20 13:19:46 DEBUG[10652] pbx.c: Function result is '2006-10-20 > 13:19:44' > Oct 20 13:19:46 DEBUG[10652] pbx.c: Function result is '(null)' > Oct 20 13:19:46 DEBUG[10652] pbx.c: Function result is '2006-10-20 > 13:19:46' > Oct 20 13:19:46 DEBUG[10652] pbx.c: Function result is '2' > Oct 20 13:19:46 DEBUG[10652] pbx.c: Function result is '0' > Oct 20 13:19:46 DEBUG[10652] pbx.c: Function result is 'NO ANSWER' > Oct 20 13:19:46 DEBUG[10652] pbx.c: Function result is 'DOCUMENTATION' > Oct 20 13:19:46 DEBUG[10652] pbx.c: Function result is '(null)' > Oct 20 13:19:46 DEBUG[10652] pbx.c: Function result is '1161364784.6637' > Oct 20 13:19:46 DEBUG[10652] pbx.c: Function result is '(null)' > Oct 20 13:19:46 DEBUG[10652] channel.c: Hanging up channel > 'SIP/5100-9f70a9b0' > Oct 20 13:19:46 DEBUG[10652] chan_sip.c: Hangup call SIP/5100-9f70a9b0, > SIP callid [EMAIL PROTECTED]) > Oct 20 13:19:46 DEBUG[10652] chan_sip.c: update_call_counter(5100) - > decrement call limit counter > Oct 20 13:19:46 DEBUG[10652] chan_sip.c: Updating call counter for > incoming call > Oct 20 13:19:46 DEBUG[8159] chan_sip.c: Checking device state for peer > 5100 > Oct 20 13:19:46 DEBUG[8159] devicestate.c: Changing state for SIP/5100 - > state 2 (In use) > Oct 20 13:19:46 DEBUG[8159] chan_sip.c: Checking device state for peer > 5100 > Oct 20 13:19:46 DEBUG[10661] app_queue.c: Device 'Zap/25' changed to > state '0' (Unknown) but we don't care because they're not a member of > any queue. > Oct 20 13:19:46 DEBUG[10662] app_queue.c: Device 'SIP/5100' changed to > state '2' (In use) but we don't care because they're not a member of any > queue. > Oct 20 13:19:46 VERBOSE[8171] logger.c: > <-- SIP read from 172.16.8.200:5065: > ACK sip:[EMAIL PROTECTED] SIP/2.0 > Via: SIP/2.0/UDP 172.16.8.200:5065;branch=z9hG4bKline0-2425957956 > To: <sip:[EMAIL PROTECTED]>;tag=as279eb184 > From: "From Desk"<sip:[EMAIL PROTECTED]>;tag=2425948795 > Call-Id: [EMAIL PROTECTED] > Max-Forwards: 70 > CSeq: 2 ACK > Contact: sip:[EMAIL PROTECTED]:5065 > Content-Length: 0 > > > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 0: ACK > sip:[EMAIL PROTECTED] SIP/2.0 (33) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 1: Via: SIP/2.0/UDP > 172.16.8.200:5065;branch=z9hG4bKline0-2425957956 (65) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 2: To: > <sip:[EMAIL PROTECTED]>;tag=as279eb184 (42) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 3: From: "From > Desk"<sip:[EMAIL PROTECTED]>;tag=2425948795 (55) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 4: Call-Id: > [EMAIL PROTECTED] (43) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 5: Max-Forwards: 70 (16) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 6: CSeq: 2 ACK (11) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 7: Contact: > sip:[EMAIL PROTECTED]:5065 (35) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 8: Content-Length: 0 (17) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 9: (0) > Oct 20 13:19:46 VERBOSE[8171] logger.c: --- (9 headers 0 lines)Oct 20 > 13:19:46 VERBOSE[8171] logger.c: --- (9 headers 0 lines)--- > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: **** Received ACK (6) - Command > in SIP ACK > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: ** SIP TIMER: Cancelling > retransmit of packet (reply received) Retransid #51636 > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Stopping retransmission on > '[EMAIL PROTECTED]' of Response 2: Match Found > Oct 20 13:19:46 VERBOSE[8171] logger.c: Destroying call > '[EMAIL PROTECTED]' > Oct 20 13:19:46 VERBOSE[8171] logger.c: > <-- SIP read from 172.16.8.200:5065: > REFER sip:[EMAIL PROTECTED] SIP/2.0 > Via: SIP/2.0/UDP 172.16.8.200:5065;branch=z9hG4bKline0-2425953069 > To: "Unknown" <sip:[EMAIL PROTECTED]>;tag=as25d7f97e > From: <sip:[EMAIL PROTECTED]:5065>;tag=2425967614 > Call-Id: [EMAIL PROTECTED] > Max-Forwards: 70 > CSeq: 2 REFER > Contact: sip:[EMAIL PROTECTED]:5065 > Refer-To: > Referred-By: sip:[EMAIL PROTECTED]:5065 > User-Agent: Citel-Handset-Gateway (DTS_E_DTP_32D) > Allow: INVITE, ACK, CANCEL, BYE, OPTIONS, NOTIFY, PRACK, REFER > Content-Length: 0 > > > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 0: REFER > sip:[EMAIL PROTECTED] SIP/2.0 (38) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 1: Via: SIP/2.0/UDP > 172.16.8.200:5065;branch=z9hG4bKline0-2425953069 (65) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 2: To: "Unknown" > <sip:[EMAIL PROTECTED]>;tag=as25d7f97e (55) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 3: From: > <sip:[EMAIL PROTECTED]:5065>;tag=2425967614 (49) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 4: Call-Id: > [EMAIL PROTECTED] (54) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 5: Max-Forwards: 70 (16) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 6: CSeq: 2 REFER (13) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 7: Contact: > sip:[EMAIL PROTECTED]:5065 (35) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 8: Refer-To: (10) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 9: Referred-By: > sip:[EMAIL PROTECTED]:5065 (39) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 10: User-Agent: > Citel-Handset-Gateway (DTS_E_DTP_32D) (49) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 11: Allow: INVITE, ACK, > CANCEL, BYE, OPTIONS, NOTIFY, PRACK, REFER (62) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 12: Content-Length: 0 > (17) > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: Header 13: (0) > Oct 20 13:19:46 VERBOSE[8171] logger.c: --- (13 headers 0 lines)Oct 20 > 13:19:46 VERBOSE[8171] logger.c: --- (13 headers 0 lines)--- > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: **** Received REFER (9) - > Command in SIP REFER > Oct 20 13:19:46 DEBUG[8171] chan_sip.c: SIP call transfer received for > call [EMAIL PROTECTED] (REFER)! > Oct 20 13:19:46 WARNING[8171] chan_sip.c: Refer-to: Huh? Not a SIP > header ()? > Oct 20 13:19:46 VERBOSE[8171] logger.c: Transmitting (no NAT) to > 172.16.8.200:5065: > SIP/2.0 603 Declined > Via: SIP/2.0/UDP > 172.16.8.200:5065;branch=z9hG4bKline0-2425953069;received=172.16.8.200 > From: <sip:[EMAIL PROTECTED]:5065>;tag=2425967614 > To: "Unknown" <sip:[EMAIL PROTECTED]>;tag=as25d7f97e > Call-ID: [EMAIL PROTECTED] > CSeq: 2 REFER > User-Agent: Asterisk PBX > Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY > Contact: <sip:[EMAIL PROTECTED]> > Content-Length: 0 > X-Asterisk-HangupCause: Normal Clearing > > _______________________________________________ > --Bandwidth and Colocation provided by Easynews.com -- > > asterisk-users mailing list > To UNSUBSCRIBE or update options visit: > http://lists.digium.com/mailman/listinfo/asterisk-users > > > > _______________________________________________ > --Bandwidth and Colocation provided by Easynews.com -- > > asterisk-users mailing list > To UNSUBSCRIBE or update options visit: > http://lists.digium.com/mailman/listinfo/asterisk-users > _______________________________________________ --Bandwidth and Colocation provided by Easynews.com -- asterisk-users mailing list To UNSUBSCRIBE or update options visit: http://lists.digium.com/mailman/listinfo/asterisk-users
