<--- SIP read from UDP:xx.xx.xx.xx:5060 ---> INVITE sip:+441612bbbbb@yy.yy.yy.yy SIP/2.0^M Via: SIP/2.0/UDP xx.xx.xx.xx:5060;branch=z9hG4bK2de1622b;rport^M From: "+441614aaaaaa" ;tag=as4d1b64a5^M To: ^M Contact: ^M Call-ID: 40ba23336c75c0954f3e282a4ace12b1@domain.co.uk^M CSeq: 102 INVITE^M User-Agent: Asterisk PBX^M Max-Forwards: 70^M Date: Wed, 12 May 2010 15:42:32 GMT^M Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY^M Supported: replaces^M Content-Type: application/sdp^M Content-Length: 289^M ^M v=0^M o=root 14419 14419 IN IP4 xx.xx.xx.xx^M s=session^M c=IN IP4 xx.xx.xx.xx^M t=0 0^M m=audio 14464 RTP/AVP 0 3 8 101^M a=rtpmap:0 PCMU/8000^M a=rtpmap:3 GSM/8000^M a=rtpmap:8 PCMA/8000^M a=rtpmap:101 telephone-event/8000^M a=fmtp:101 0-16^M a=silenceSupp:off - - - -^M a=ptime:20^M a=sendrecv^M <-------------> [May 12 16:42:32] DEBUG[27260] chan_sip.c: Header 0 [ 46]: INVITE sip:+441612bbbbb@yy.yy.yy.yy SIP/2.0 [May 12 16:42:32] DEBUG[27260] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/UDP xx.xx.xx.xx:5060;branch=z9hG4bK2de1622b;rport [May 12 16:42:32] DEBUG[27260] chan_sip.c: Header 2 [ 69]: From: "+441614aaaaaa" ;tag=as4d1b64a5 [May 12 16:42:32] DEBUG[27260] chan_sip.c: Header 3 [ 37]: To: [May 12 16:42:32] DEBUG[27260] chan_sip.c: Header 4 [ 42]: Contact: [May 12 16:42:32] DEBUG[27260] chan_sip.c: Header 5 [ 54]: Call-ID: 40ba23336c75c0954f3e282a4ace12b1@domain.co.uk [May 12 16:42:32] DEBUG[27260] chan_sip.c: Header 6 [ 16]: CSeq: 102 INVITE [May 12 16:42:32] DEBUG[27260] chan_sip.c: Header 7 [ 24]: User-Agent: Asterisk PBX [May 12 16:42:32] DEBUG[27260] chan_sip.c: Header 8 [ 16]: Max-Forwards: 70 [May 12 16:42:32] DEBUG[27260] chan_sip.c: Header 9 [ 35]: Date: Wed, 12 May 2010 15:42:32 GMT [May 12 16:42:32] DEBUG[27260] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [May 12 16:42:32] DEBUG[27260] chan_sip.c: Header 11 [ 19]: Supported: replaces [May 12 16:42:32] DEBUG[27260] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [May 12 16:42:32] DEBUG[27260] chan_sip.c: Header 13 [ 19]: Content-Length: 289 [May 12 16:42:32] DEBUG[27260] chan_sip.c: Header 14 [ 0]: [May 12 16:42:32] DEBUG[27260] chan_sip.c: Body 0 [ 3]: v=0 [May 12 16:42:32] DEBUG[27260] chan_sip.c: Body 1 [ 39]: o=root 14419 14419 IN IP4 xx.xx.xx.xx [May 12 16:42:32] DEBUG[27260] chan_sip.c: Body 2 [ 9]: s=session [May 12 16:42:32] DEBUG[27260] chan_sip.c: Body 3 [ 22]: c=IN IP4 xx.xx.xx.xx [May 12 16:42:32] DEBUG[27260] chan_sip.c: Body 4 [ 5]: t=0 0 [May 12 16:42:32] DEBUG[27260] chan_sip.c: Body 5 [ 31]: m=audio 14464 RTP/AVP 0 3 8 101 [May 12 16:42:32] DEBUG[27260] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [May 12 16:42:32] DEBUG[27260] chan_sip.c: Body 7 [ 19]: a=rtpmap:3 GSM/8000 [May 12 16:42:32] DEBUG[27260] chan_sip.c: Body 8 [ 20]: a=rtpmap:8 PCMA/8000 [May 12 16:42:32] DEBUG[27260] chan_sip.c: Body 9 [ 33]: a=rtpmap:101 telephone-event/8000 [May 12 16:42:32] DEBUG[27260] chan_sip.c: Body 10 [ 15]: a=fmtp:101 0-16 [May 12 16:42:32] DEBUG[27260] chan_sip.c: Body 11 [ 25]: a=silenceSupp:off - - - - [May 12 16:42:32] DEBUG[27260] chan_sip.c: Body 12 [ 10]: a=ptime:20 [May 12 16:42:32] DEBUG[27260] chan_sip.c: Body 13 [ 10]: a=sendrecv [May 12 16:42:32] VERBOSE[27260] chan_sip.c: --- (14 headers 14 lines) --- [May 12 16:42:32] DEBUG[27260] acl.c: Found IP address for this socket [May 12 16:42:32] DEBUG[27260] chan_sip.c: Setting SIP_TRANSPORT_UDP with address yy.yy.yy.yy:5060 [May 12 16:42:32] DEBUG[18802] audiohook.c: Write factory 0xb3489b80 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[19430] audiohook.c: Read factory 0x9f03e28 was pretty quick last time, waiting for them. [May 12 16:42:32] VERBOSE[27260] netsock.c: == Using SIP RTP CoS mark 5 [May 12 16:42:32] DEBUG[27260] chan_sip.c: Setting NAT on RTP to Off [May 12 16:42:32] DEBUG[27260] chan_sip.c: Allocating new SIP dialog for 40ba23336c75c0954f3e282a4ace12b1@domain.co.uk - INVITE (With RTP) [May 12 16:42:32] DEBUG[27260] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [May 12 16:42:32] DEBUG[27260] chan_sip.c: Begin: parsing SIP "Supported: replaces" [May 12 16:42:32] DEBUG[27260] chan_sip.c: Found SIP option: -replaces- [May 12 16:42:32] DEBUG[27260] chan_sip.c: Matched SIP option: replaces [May 12 16:42:32] DEBUG[7361] audiohook.c: Read factory 0xa030450 was pretty quick last time, waiting for them. [May 12 16:42:32] VERBOSE[27260] chan_sip.c: Sending to xx.xx.xx.xx : 5060 (no NAT) [May 12 16:42:32] DEBUG[27260] chan_sip.c: Initializing initreq for method INVITE - callid 40ba23336c75c0954f3e282a4ace12b1@domain.co.uk [May 12 16:42:32] VERBOSE[27260] chan_sip.c: Using INVITE request as basis request - 40ba23336c75c0954f3e282a4ace12b1@domain.co.uk [May 12 16:42:32] VERBOSE[27260] chan_sip.c: Found peer 'openser' for '+441614aaaaaa' from xx.xx.xx.xx:5060 [May 12 16:42:32] DEBUG[27260] chan_sip.c: Setting NAT on RTP to Off [May 12 16:42:32] DEBUG[19965] audiohook.c: Write factory 0x9e52310 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[27260] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [May 12 16:42:32] DEBUG[27260] chan_sip.c: Processing session-level SDP o=root 14419 14419 IN IP4 xx.xx.xx.xx... UNSUPPORTED. [May 12 16:42:32] DEBUG[27260] chan_sip.c: Processing session-level SDP s=session... UNSUPPORTED. [May 12 16:42:32] DEBUG[27260] chan_sip.c: Processing session-level SDP c=IN IP4 xx.xx.xx.xx... OK. [May 12 16:42:32] DEBUG[27260] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [May 12 16:42:32] DEBUG[18788] audiohook.c: Write factory 0x9f28c78 was pretty quick last time, waiting for them. [May 12 16:42:32] VERBOSE[27260] chan_sip.c: Found RTP audio format 0 [May 12 16:42:32] VERBOSE[27260] chan_sip.c: Found RTP audio format 3 [May 12 16:42:32] VERBOSE[27260] chan_sip.c: Found RTP audio format 8 [May 12 16:42:32] VERBOSE[27260] chan_sip.c: Found RTP audio format 101 [May 12 16:42:32] VERBOSE[27260] chan_sip.c: Found audio description format PCMU for ID 0 [May 12 16:42:32] DEBUG[27260] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [May 12 16:42:32] VERBOSE[27260] chan_sip.c: Found audio description format GSM for ID 3 [May 12 16:42:32] DEBUG[27260] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:3 GSM/8000... OK. [May 12 16:42:32] VERBOSE[27260] chan_sip.c: Found audio description format PCMA for ID 8 [May 12 16:42:32] DEBUG[27260] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [May 12 16:42:32] VERBOSE[27260] chan_sip.c: Found audio description format telephone-event for ID 101 [May 12 16:42:32] DEBUG[27260] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [May 12 16:42:32] DEBUG[27260] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-16... UNSUPPORTED. [May 12 16:42:32] DEBUG[27260] chan_sip.c: Processing media-level (audio) SDP a=silenceSupp:off - - - -... UNSUPPORTED. [May 12 16:42:32] DEBUG[27260] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [May 12 16:42:32] DEBUG[27260] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [May 12 16:42:32] VERBOSE[27260] chan_sip.c: Capabilities: us - 0x8 (alaw), peer - audio=0xe (gsm|ulaw|alaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x8 (alaw) [May 12 16:42:32] VERBOSE[27260] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [May 12 16:42:32] VERBOSE[27260] chan_sip.c: Peer audio RTP is at port xx.xx.xx.xx:14464 [May 12 16:42:32] DEBUG[27260] chan_sip.c: We're settling with these formats: 0x8 (alaw) [May 12 16:42:32] DEBUG[27260] chan_sip.c: Checking SIP call limits for device [May 12 16:42:32] DEBUG[27260] chan_sip.c: Updating call counter for incoming call [May 12 16:42:32] VERBOSE[27260] chan_sip.c: Looking for +441612bbbbb in default (domain yy.yy.yy.yy) [May 12 16:42:32] DEBUG[27260] chan_sip.c: *** Our native formats are 0x8 (alaw) [May 12 16:42:32] DEBUG[20767] audiohook.c: Read factory 0xb348c5b0 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[27260] chan_sip.c: *** Joint capabilities are 0x8 (alaw) [May 12 16:42:32] DEBUG[27260] chan_sip.c: *** Our capabilities are 0x8 (alaw) [May 12 16:42:32] DEBUG[27260] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [May 12 16:42:32] DEBUG[27260] chan_sip.c: This channel will not be able to handle video. [May 12 16:42:32] DEBUG[27260] chan_sip.c: build_route: Contact hop: [May 12 16:42:32] VERBOSE[27260] chan_sip.c: list_route: hop: [May 12 16:42:32] DEBUG[27260] chan_sip.c: SIP/openser-0004335f: New call is still down.... Trying... [May 12 16:42:32] VERBOSE[27260] chan_sip.c: <--- Transmitting (no NAT) to xx.xx.xx.xx:5060 ---> SIP/2.0 100 Trying^M Via: SIP/2.0/UDP xx.xx.xx.xx:5060;branch=z9hG4bK2de1622b;received=xx.xx.xx.xx;rport=5060^M From: "+441614aaaaaa" ;tag=as4d1b64a5^M To: ^M Call-ID: 40ba23336c75c0954f3e282a4ace12b1@domain.co.uk^M CSeq: 102 INVITE^M Server: Asterisk PBX 1.6.2.7^M Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO^M Supported: replaces, timer^M Contact: ^M Content-Length: 0^M <------------> [May 12 16:42:32] DEBUG[27260] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for xx.xx.xx.xx:5060 [May 12 16:42:32] DEBUG[27236] devicestate.c: No provider found, checking channel drivers for SIP - openser [May 12 16:42:32] DEBUG[27236] chan_sip.c: Checking device state for peer openser [May 12 16:42:32] DEBUG[27236] devicestate.c: Changing state for SIP/openser - state 1 (Not in use) [May 12 16:42:32] DEBUG[27236] devicestate.c: device 'SIP/openser' state '1' [May 12 16:42:32] DEBUG[19943] audiohook.c: Read factory 0xa034ea8 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[20764] audiohook.c: Write factory 0xb34ee040 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[21269] pbx.c: Launching 'AGI' [May 12 16:42:32] VERBOSE[21269] pbx.c: -- Executing [+441612bbbbb@default:1] AGI("SIP/openser-0004335f", "incomingrouter.php") in new stack [May 12 16:42:32] DEBUG[27254] app_queue.c: Device 'SIP/openser' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [May 12 16:42:32] DEBUG[19443] audiohook.c: Read factory 0x9eb30f0 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[20097] audiohook.c: Read factory 0xb3538b50 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[20687] audiohook.c: Write factory 0xb3413320 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[20085] audiohook.c: Write factory 0xb342ab70 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[20631] audiohook.c: Write factory 0x9f69c20 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[20696] audiohook.c: Read factory 0xb3425a08 was pretty quick last time, waiting for them. [May 12 16:42:32] VERBOSE[21269] res_agi.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/incomingrouter.php [May 12 16:42:32] DEBUG[19993] audiohook.c: Read factory 0xb34ebfd0 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[18802] audiohook.c: Write factory 0xb3489b80 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[20755] audiohook.c: Read factory 0x9f57b20 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[18183] audiohook.c: Write factory 0x9ff2670 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[7361] audiohook.c: Read factory 0xa030450 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[19965] audiohook.c: Write factory 0x9e52310 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[18788] audiohook.c: Write factory 0x9f28c78 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[20767] audiohook.c: Read factory 0xb348c5b0 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[20764] audiohook.c: Write factory 0xb34ee040 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[19943] audiohook.c: Read factory 0xa034ea8 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[20085] audiohook.c: Write factory 0xb342ab70 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[17422] audiohook.c: Write factory 0x9e41d70 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[20755] audiohook.c: Read factory 0x9f57b20 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[20717] audiohook.c: Write factory 0xb350b9b0 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[20696] audiohook.c: Read factory 0xb3425a08 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[20631] audiohook.c: Write factory 0x9f69c20 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[19993] audiohook.c: Read factory 0xb34ebfd0 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[13856] audiohook.c: Write factory 0x9ecb670 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[18183] audiohook.c: Write factory 0x9ff2670 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[18755] audiohook.c: Write factory 0x9e406c8 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[19443] audiohook.c: Read factory 0x9eb30f0 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[20097] audiohook.c: Read factory 0xb3538b50 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[20708] audiohook.c: Read factory 0xb3454908 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[20687] audiohook.c: Write factory 0xb3413320 was pretty quick last time, waiting for them. [May 12 16:42:32] VERBOSE[21273] pbx.c: -- Executing [+441618bbbbbbb@keybm-incoming:1] Goto("SIP/openser-00043361", "keybm-internal,202,1") in new stack [May 12 16:42:32] VERBOSE[21273] pbx.c: -- Goto (keybm-internal,202,1) [May 12 16:42:32] DEBUG[21273] pbx.c: Launching 'Dial' [May 12 16:42:32] VERBOSE[21273] pbx.c: -- Executing [202@keybm-internal:1] Dial("SIP/openser-00043361", "SIP/keybm-202,15") in new stack [May 12 16:42:32] DEBUG[21273] chan_sip.c: Asked to create a SIP channel with formats: 0x8 (alaw) [May 12 16:42:32] VERBOSE[21273] netsock.c: == Using SIP RTP CoS mark 5 [May 12 16:42:32] DEBUG[21273] chan_sip.c: Allocating new SIP dialog for 35856d527478be3e76f43cf00b216e2c@yy.yy.yy.yy - INVITE (With RTP) [May 12 16:42:32] DEBUG[21273] chan_sip.c: Setting NAT on RTP to On [May 12 16:42:32] DEBUG[21273] chan_sip.c: OBPROXY: Not applying OBproxy to this call [May 12 16:42:32] DEBUG[21273] acl.c: Found IP address for this socket [May 12 16:42:32] DEBUG[21273] chan_sip.c: Setting SIP_TRANSPORT_UDP with address yy.yy.yy.yy:5060 [May 12 16:42:32] DEBUG[21273] frame.c: Could not find preferred codec - Going for the best codec [May 12 16:42:32] DEBUG[21273] chan_sip.c: *** Our native formats are 0x8 (alaw) [May 12 16:42:32] DEBUG[21273] chan_sip.c: *** Joint capabilities are 0x8 (alaw) [May 12 16:42:32] DEBUG[21273] chan_sip.c: *** Our capabilities are 0x100 (g729) [May 12 16:42:32] DEBUG[20767] audiohook.c: Read factory 0xb348c5b0 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[21273] frame.c: Could not find preferred codec - Going for the best codec [May 12 16:42:32] DEBUG[21273] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [May 12 16:42:32] DEBUG[21273] chan_sip.c: *** Our preferred formats from the incoming channel are 0x8 (alaw) [May 12 16:42:32] DEBUG[21273] chan_sip.c: This channel will not be able to handle video. [May 12 16:42:32] DEBUG[21273] channel.c: Not copying variable DIALEDTIME. [May 12 16:42:32] DEBUG[21273] channel.c: Not copying variable ANSWEREDTIME. [May 12 16:42:32] DEBUG[21273] channel.c: Not copying variable DIALEDPEERNAME. [May 12 16:42:32] DEBUG[21273] channel.c: Not copying variable DIALEDPEERNUMBER. [May 12 16:42:32] DEBUG[21273] channel.c: Not copying variable DIALSTATUS. [May 12 16:42:32] DEBUG[21273] channel.c: Not copying variable AGISTATUS. [May 12 16:42:32] DEBUG[21273] channel.c: Not copying variable MIXMONITOR_FILENAME. [May 12 16:42:32] DEBUG[21273] channel.c: Not copying variable SIPCALLID. [May 12 16:42:32] DEBUG[21273] channel.c: Not copying variable SIPDOMAIN. [May 12 16:42:32] DEBUG[21273] channel.c: Not copying variable SIPURI. [May 12 16:42:32] DEBUG[21273] chan_sip.c: Outgoing Call for keybm-202 [May 12 16:42:32] DEBUG[21273] chan_sip.c: Updating call counter for outgoing call [May 12 16:42:32] DEBUG[21273] chan_sip.c: Call to peer 'keybm-202' is 1 out of 5 [May 12 16:42:32] WARNING[21273] chan_sip.c: No audio format found to offer. Cancelling call to keybm-202 [May 12 16:42:32] DEBUG[21273] app_dial.c: ast call on peer returned -1 [May 12 16:42:32] VERBOSE[21273] app_dial.c: -- Couldn't call keybm-202 [May 12 16:42:32] DEBUG[27236] devicestate.c: No provider found, checking channel drivers for SIP - keybm-202 [May 12 16:42:32] DEBUG[21273] channel.c: Hanging up channel 'SIP/keybm-202-00043362' [May 12 16:42:32] DEBUG[27236] chan_sip.c: Checking device state for peer keybm-202 [May 12 16:42:32] DEBUG[21273] chan_sip.c: Hangup call SIP/keybm-202-00043362, SIP callid 0aaa14515bc05cb110c4b27e51b18f84@yy.yy.yy.yy [May 12 16:42:32] DEBUG[27236] devicestate.c: Changing state for SIP/keybm-202 - state 6 (Ringing) [May 12 16:42:32] DEBUG[27236] devicestate.c: device 'SIP/keybm-202' state '6' [May 12 16:42:32] DEBUG[21273] chan_sip.c: update_call_counter(keybm-202) - decrement call limit counter on hangup [May 12 16:42:32] DEBUG[21273] chan_sip.c: Updating call counter for outgoing call [May 12 16:42:32] DEBUG[21273] chan_sip.c: Call to peer 'keybm-202' removed from call limit 5 [May 12 16:42:32] DEBUG[21273] chan_sip.c: Hanging up channel in state Down (not UP) [May 12 16:42:32] DEBUG[27236] devicestate.c: No provider found, checking channel drivers for SIP - keybm-202 [May 12 16:42:32] DEBUG[27236] chan_sip.c: Checking device state for peer keybm-202 [May 12 16:42:32] DEBUG[27236] devicestate.c: Changing state for SIP/keybm-202 - state 1 (Not in use) [May 12 16:42:32] DEBUG[27254] app_queue.c: Device 'SIP/keybm-202' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [May 12 16:42:32] DEBUG[27236] devicestate.c: device 'SIP/keybm-202' state '1' [May 12 16:42:32] DEBUG[20764] audiohook.c: Write factory 0xb34ee040 was pretty quick last time, waiting for them. [May 12 16:42:32] DEBUG[27254] app_queue.c: Device 'SIP/keybm-202' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [May 12 16:42:32] VERBOSE[21273] chan_sip.c: Scheduling destruction of SIP dialog '0aaa14515bc05cb110c4b27e51b18f84@yy.yy.yy.yy' in 6400 ms (Method: INVITE) [May 12 16:42:32] DEBUG[19943] audiohook.c: Read factory 0xa034ea8 was pretty quick last time, waiting for them. [May 12 16:42:32] VERBOSE[21273] app_dial.c: == Everyone is busy/congested at this time (0:0/0/0) [May 12 16:42:32] DEBUG[21273] rtp.c: Channel '' has no RTP, not doing anything [May 12 16:42:32] DEBUG[21273] app_dial.c: Exiting with DIALSTATUS=CHANUNAVAIL. [May 12 16:42:32] VERBOSE[21273] pbx.c: -- Auto fallthrough, channel 'SIP/openser-00043361' status is 'CHANUNAVAIL' [May 12 16:42:32] DEBUG[27236] devicestate.c: No provider found, checking channel drivers for SIP - keybm-202 [May 12 16:42:32] DEBUG[27236] chan_sip.c: Checking device state for peer keybm-202 [May 12 16:42:32] DEBUG[27236] devicestate.c: Changing state for SIP/keybm-202 - state 1 (Not in use) [May 12 16:42:32] DEBUG[27236] devicestate.c: device 'SIP/keybm-202' state '1' [May 12 16:42:32] DEBUG[27254] app_queue.c: Device 'SIP/keybm-202' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [May 12 16:42:32] VERBOSE[21273] chan_sip.c: <--- Reliably Transmitting (no NAT) to xx.xx.xx.xx:5060 ---> SIP/2.0 503 Service Unavailable^M Via: SIP/2.0/UDP xx.xx.xx.xx:5060;branch=z9hG4bK5f0f0f11;received=xx.xx.xx.xx;rport=5060^M From: "+441614aaaaaa" ;tag=as6970ffcd^M To: ;tag=as1469ba00^M Call-ID: 0998c4726d039d76508d8abd1a271f00@domain.co.uk^M CSeq: 102 INVITE^M Server: Asterisk PBX 1.6.2.7^M Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO^M Supported: replaces, timer^M Content-Length: 0^M ^M <------------>