[Nov 19 16:02:00] WARNING[10056] chan_oss.c: Unable to re-open DSP device /dev/dsp: No such file or directory [Nov 19 16:02:00] DEBUG[10056] pbx.c: Launching 'Dial' [Nov 19 16:02:00] VERBOSE[10056] logger.c: -- Executing [200@desde-usuarios:1] Dial("OSS/dsp", "SIP/200,30,tTA(tt-monkeysintro)") in new stack [Nov 19 16:02:00] DEBUG[10056] chan_sip.c: Asked to create a SIP channel with formats: 0x40 (slin) [Nov 19 16:02:00] VERBOSE[10056] logger.c: == Using TOS bits 0 [Nov 19 16:02:00] VERBOSE[10056] logger.c: == Using CoS mark 5 [Nov 19 16:02:00] DEBUG[10056] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Nov 19 16:02:00] DEBUG[10056] chan_sip.c: Setting NAT on RTP to Off [Nov 19 16:02:00] DEBUG[10056] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Nov 19 16:02:00] DEBUG[10056] acl.c: Found IP address for this socket [Nov 19 16:02:00] DEBUG[10056] chan_sip.c: *** Our native formats are 0x40 (slin) [Nov 19 16:02:00] DEBUG[10056] chan_sip.c: *** Joint capabilities are 0x40 (slin) [Nov 19 16:02:00] DEBUG[10056] chan_sip.c: *** Our capabilities are 0x8000e (gsm|ulaw|alaw|h263) [Nov 19 16:02:00] DEBUG[10056] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x40 (slin) [Nov 19 16:02:00] DEBUG[10056] chan_sip.c: *** Our preferred formats from the incoming channel are 0x40 (slin) [Nov 19 16:02:00] DEBUG[10056] chan_sip.c: This channel will not be able to handle video. [Nov 19 16:02:00] DEBUG[10056] rtp.c: Channel 'OSS/dsp' has no RTP, not doing anything [Nov 19 16:02:00] DEBUG[10056] channel.c: Not copying variable STACK-desde-usuarios-200-1. [Nov 19 16:02:00] DEBUG[10056] chan_sip.c: Outgoing Call for 200 [Nov 19 16:02:00] DEBUG[10056] chan_sip.c: Updating call counter for outgoing call [Nov 19 16:02:00] DEBUG[10056] chan_sip.c: Our T38 capability (0), joint T38 capability (0) [Nov 19 16:02:00] DEBUG[10056] chan_sip.c: ** Our capability: 0x8000e (gsm|ulaw|alaw|h263) Video flag: False Text flag: False [Nov 19 16:02:00] DEBUG[10056] chan_sip.c: ** Our prefcodec: 0x40 (slin) [Nov 19 16:02:00] DEBUG[10056] chan_sip.c: This call needs video offers, but there's no video support enabled! [Nov 19 16:02:00] VERBOSE[10056] logger.c: Audio is at 80.95.0.111 port 10492 [Nov 19 16:02:00] VERBOSE[10056] logger.c: Adding codec 0x2 (gsm) to SDP [Nov 19 16:02:00] VERBOSE[10056] logger.c: Adding codec 0x4 (ulaw) to SDP [Nov 19 16:02:00] VERBOSE[10056] logger.c: Adding codec 0x8 (alaw) to SDP [Nov 19 16:02:00] VERBOSE[10056] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Nov 19 16:02:00] DEBUG[10056] chan_sip.c: -- Done with adding codecs to SDP [Nov 19 16:02:00] DEBUG[10056] chan_sip.c: Done building SDP. Settling with this capability: 0x8000e (gsm|ulaw|alaw|h263) [Nov 19 16:02:00] DEBUG[10056] chan_sip.c: Initializing initreq for method INVITE - callid 5a64a96e4b82585c7e08bd66108a7cd8@80.95.0.111 [Nov 19 16:02:00] VERBOSE[10056] logger.c: Reliably Transmitting (no NAT) to 212.101.235.18:1024: INVITE sip:200@212.101.235.18:1024 SIP/2.0 Via: SIP/2.0/UDP 80.95.0.111:5060;branch=z9hG4bK7378a4e2;rport Max-Forwards: 70 From: "asterisk" ;tag=as533cc37e To: Contact: Call-ID: 5a64a96e4b82585c7e08bd66108a7cd8@80.95.0.111 CSeq: 102 INVITE User-Agent: Asterisk SVN trunk Date: Mon, 19 Nov 2007 15:02:00 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 315 v=0 o=root 210011190 210011190 IN IP4 80.95.0.111 s=Asterisk PBX SVN-trunk-r89407 c=IN IP4 80.95.0.111 t=0 0 m=audio 10492 RTP/AVP 3 0 8 101 a=rtpmap:3 GSM/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Nov 19 16:02:00] VERBOSE[10056] logger.c: -- Called 200 [Nov 19 16:02:00] VERBOSE[10056] logger.c: <--- SIP read from 212.101.235.18:1024 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 80.95.0.111:5060;rport=5060;branch=z9hG4bK7378a4e2 To: From: "asterisk" ;tag=as533cc37e Call-ID: 5a64a96e4b82585c7e08bd66108a7cd8@80.95.0.111 CSeq: 102 INVITE Server: Twinkle/1.1alpha2 Content-Length: 0 <-------------> [Nov 19 16:02:00] VERBOSE[10056] logger.c: --- (8 headers 0 lines) --- [Nov 19 16:02:00] DEBUG[10056] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '5a64a96e4b82585c7e08bd66108a7cd8@80.95.0.111' Request 102: Found [Nov 19 16:02:00] VERBOSE[10056] logger.c: <--- SIP read from 212.101.235.18:1024 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 80.95.0.111:5060;rport=5060;branch=z9hG4bK7378a4e2 To: ;tag=rsdpa From: "asterisk" ;tag=as533cc37e Call-ID: 5a64a96e4b82585c7e08bd66108a7cd8@80.95.0.111 CSeq: 102 INVITE Server: Twinkle/1.1alpha2 Content-Length: 0 <-------------> [Nov 19 16:02:00] VERBOSE[10056] logger.c: --- (8 headers 0 lines) --- [Nov 19 16:02:00] DEBUG[10056] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '5a64a96e4b82585c7e08bd66108a7cd8@80.95.0.111' Request 102: Found [Nov 19 16:02:00] DEBUG[10056] devicestate.c: Notification of state change to be queued on device/channel SIP/200-082155a0 [Nov 19 16:02:00] DEBUG[10056] chan_sip.c: Checking device state for peer 200 [Nov 19 16:02:00] DEBUG[10056] devicestate.c: Changing state for SIP/200 - state 1 (Not in use) [Nov 19 16:02:00] DEBUG[10056] app_queue.c: Device 'SIP/200' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Nov 19 16:02:00] VERBOSE[10056] logger.c: -- SIP/200-082155a0 is ringing [Nov 19 16:02:03] VERBOSE[10056] logger.c: <--- SIP read from 212.101.235.18:1024 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 80.95.0.111:5060;rport=5060;branch=z9hG4bK7378a4e2 To: ;tag=rsdpa From: "asterisk" ;tag=as533cc37e Call-ID: 5a64a96e4b82585c7e08bd66108a7cd8@80.95.0.111 CSeq: 102 INVITE Contact: Content-Type: application/sdp Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,PRACK,REFER,NOTIFY,SUBSCRIBE,INFO,MESSAGE Server: Twinkle/1.1alpha2 Supported: replaces,norefersub Content-Length: 193 v=0 o=200 1940763068 449561456 IN IP4 212.101.235.18 s=- c=IN IP4 212.101.235.18 t=0 0 m=audio 8800 RTP/AVP 3 101 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 <-------------> [Nov 19 16:02:03] VERBOSE[10056] logger.c: --- (12 headers 9 lines) --- [Nov 19 16:02:03] DEBUG[10056] chan_sip.c: Acked pending invite 102 [Nov 19 16:02:03] DEBUG[10056] chan_sip.c: Stopping retransmission on '5a64a96e4b82585c7e08bd66108a7cd8@80.95.0.111' of Request 102: Match Found [Nov 19 16:02:03] VERBOSE[10056] logger.c: Found RTP audio format 3 [Nov 19 16:02:03] VERBOSE[10056] logger.c: Found RTP audio format 101 [Nov 19 16:02:03] VERBOSE[10056] logger.c: Peer audio RTP is at port 212.101.235.18:8800 [Nov 19 16:02:03] VERBOSE[10056] logger.c: Found description format GSM for ID 3 [Nov 19 16:02:03] VERBOSE[10056] logger.c: Found description format telephone-event for ID 101 [Nov 19 16:02:03] VERBOSE[10056] logger.c: Got unsupported a:fmtp in SDP offer [Nov 19 16:02:03] DEBUG[10056] chan_sip.c: T38 state changed to 0 on channel SIP/200-082155a0 [Nov 19 16:02:03] VERBOSE[10056] logger.c: Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x2 (gsm)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x2 (gsm) [Nov 19 16:02:03] VERBOSE[10056] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Nov 19 16:02:03] VERBOSE[10056] logger.c: Peer audio RTP is at port 212.101.235.18:8800 [Nov 19 16:02:03] DEBUG[10056] chan_sip.c: We're settling with these formats: 0x2 (gsm) [Nov 19 16:02:03] DEBUG[10056] chan_sip.c: Oooh, we need to change our audio formats since our peer supports only 0x2 (gsm) and not 0x40 (slin) [Nov 19 16:02:03] DEBUG[10056] channel.c: Set channel SIP/200-082155a0 to read format slin [Nov 19 16:02:03] DEBUG[10056] channel.c: Set channel SIP/200-082155a0 to write format slin [Nov 19 16:02:03] DEBUG[10056] chan_sip.c: Updating call counter for outgoing call [Nov 19 16:02:03] VERBOSE[10056] logger.c: --- set_address_from_contact host '212.101.235.18' [Nov 19 16:02:03] DEBUG[10056] chan_sip.c: build_route: Contact hop: [Nov 19 16:02:03] VERBOSE[10056] logger.c: list_route: hop: [Nov 19 16:02:03] DEBUG[10056] chan_sip.c: Strict routing enforced for session 5a64a96e4b82585c7e08bd66108a7cd8@80.95.0.111 [Nov 19 16:02:03] VERBOSE[10056] logger.c: set_destination: Parsing for address/port to send to [Nov 19 16:02:03] VERBOSE[10056] logger.c: set_destination: set destination to 212.101.235.18, port 1024 [Nov 19 16:02:03] VERBOSE[10056] logger.c: Transmitting (no NAT) to 212.101.235.18:1024: ACK sip:200@212.101.235.18:1024 SIP/2.0 Via: SIP/2.0/UDP 80.95.0.111:5060;branch=z9hG4bK0fb859cb;rport Max-Forwards: 70 From: "asterisk" ;tag=as533cc37e To: ;tag=rsdpa Contact: Call-ID: 5a64a96e4b82585c7e08bd66108a7cd8@80.95.0.111 CSeq: 102 ACK User-Agent: Asterisk SVN trunk Content-Length: 0 --- [Nov 19 16:02:03] DEBUG[10056] devicestate.c: Notification of state change to be queued on device/channel SIP/200-082155a0 [Nov 19 16:02:03] VERBOSE[10056] logger.c: -- SIP/200-082155a0 answered OSS/dsp [Nov 19 16:02:03] DEBUG[10056] channel.c: Set channel SIP/200-082155a0 to write format gsm [Nov 19 16:02:03] DEBUG[10056] rtp.c: Ooh, format changed from unknown to gsm [Nov 19 16:02:03] DEBUG[10056] rtp.c: Created smoother: format: 2 ms: 20 len: 33 [Nov 19 16:02:03] VERBOSE[10056] logger.c: -- Playing 'tt-monkeysintro.gsm' (language 'en') [Nov 19 16:02:03] DEBUG[10056] chan_sip.c: Checking device state for peer 200 [Nov 19 16:02:03] DEBUG[10056] devicestate.c: Changing state for SIP/200 - state 1 (Not in use) [Nov 19 16:02:03] DEBUG[10056] app_queue.c: Device 'SIP/200' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Nov 19 16:02:03] DEBUG[10056] rtp.c: Got RTCP report of 40 bytes [Nov 19 16:02:06] DEBUG[10056] channel.c: Set channel SIP/200-082155a0 to write format slin [Nov 19 16:02:06] VERBOSE[10056] logger.c: << Console call has been answered >> [Nov 19 16:02:06] DEBUG[10056] devicestate.c: Notification of state change to be queued on device/channel OSS/dsp [Nov 19 16:02:06] DEBUG[10056] devicestate.c: Changing state for OSS/dsp - state 4 (Invalid) [Nov 19 16:02:06] DEBUG[10056] app_queue.c: Device 'OSS/dsp' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Nov 19 16:02:06] WARNING[10056] chan_oss.c: Unable to re-open DSP device /dev/dsp: No such file or directory [Nov 19 16:02:07] WARNING[10056] chan_oss.c: Unable to re-open DSP device /dev/dsp: No such file or directory [Nov 19 16:02:08] WARNING[10056] chan_oss.c: Unable to re-open DSP device /dev/dsp: No such file or directory [Nov 19 16:02:09] VERBOSE[10056] logger.c: <--- SIP read from 212.101.235.18:1024 ---> OPTIONS sip:asterisk@80.95.0.111 SIP/2.0 Via: SIP/2.0/UDP 212.101.235.18:1024;rport;branch=z9hG4bKqcwxiiqa Max-Forwards: 70 To: "asterisk" ;tag=as533cc37e From: ;tag=rsdpa Call-ID: 5a64a96e4b82585c7e08bd66108a7cd8@80.95.0.111 CSeq: 705 OPTIONS Accept: application/sdp User-Agent: Twinkle/1.1alpha2 Content-Length: 0 <-------------> [Nov 19 16:02:09] VERBOSE[10056] logger.c: --- (10 headers 0 lines) --- [Nov 19 16:02:09] VERBOSE[10056] logger.c: Looking for asterisk in desde-usuarios (domain 80.95.0.111) [Nov 19 16:02:09] VERBOSE[10056] logger.c: <--- Transmitting (no NAT) to 212.101.235.18:1024 ---> SIP/2.0 404 Not Found Via: SIP/2.0/UDP 212.101.235.18:1024;branch=z9hG4bKqcwxiiqa;received=212.101.235.18;rport=1024 From: ;tag=rsdpa To: "asterisk" ;tag=as533cc37e Call-ID: 5a64a96e4b82585c7e08bd66108a7cd8@80.95.0.111 CSeq: 705 OPTIONS User-Agent: Asterisk SVN trunk Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Accept: application/sdp Content-Length: 0 <------------> [Nov 19 16:02:09] DEBUG[10056] chan_sip.c: SIP message could not be handled, bad request: 5a64a96e4b82585c7e08bd66108a7cd8@80.95.0.111 [Nov 19 16:02:09] WARNING[10056] chan_oss.c: Unable to re-open DSP device /dev/dsp: No such file or directory [Nov 19 16:02:10] DEBUG[10056] rtp.c: Got RTCP report of 84 bytes [Nov 19 16:02:10] WARNING[10056] chan_oss.c: Unable to re-open DSP device /dev/dsp: No such file or directory [Nov 19 16:02:10] VERBOSE[10056] logger.c: <--- SIP read from 212.101.235.18:1024 ---> BYE sip:asterisk@80.95.0.111 SIP/2.0 Via: SIP/2.0/UDP 212.101.235.18:1024;rport;branch=z9hG4bKclrgjfpw Max-Forwards: 70 To: "asterisk" ;tag=as533cc37e From: ;tag=rsdpa Call-ID: 5a64a96e4b82585c7e08bd66108a7cd8@80.95.0.111 CSeq: 706 BYE User-Agent: Twinkle/1.1alpha2 Content-Length: 0 <-------------> [Nov 19 16:02:10] VERBOSE[10056] logger.c: --- (9 headers 0 lines) --- [Nov 19 16:02:10] DEBUG[10056] chan_sip.c: Initializing initreq for method BYE - callid 5a64a96e4b82585c7e08bd66108a7cd8@80.95.0.111 [Nov 19 16:02:10] VERBOSE[10056] logger.c: Sending to 212.101.235.18 : 1024 (NAT) [Nov 19 16:02:10] DEBUG[10056] chan_sip.c: Setting SIP_ALREADYGONE on dialog 5a64a96e4b82585c7e08bd66108a7cd8@80.95.0.111 [Nov 19 16:02:10] DEBUG[10056] chan_sip.c: Received bye, issuing owner hangup [Nov 19 16:02:10] VERBOSE[10056] logger.c: <--- Transmitting (NAT) to 212.101.235.18:1024 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 212.101.235.18:1024;branch=z9hG4bKclrgjfpw;received=212.101.235.18;rport=1024 From: ;tag=rsdpa To: "asterisk" ;tag=as533cc37e Call-ID: 5a64a96e4b82585c7e08bd66108a7cd8@80.95.0.111 CSeq: 706 BYE User-Agent: Asterisk SVN trunk Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Nov 19 16:02:10] DEBUG[10056] channel.c: Didn't get a frame from channel: SIP/200-082155a0 [Nov 19 16:02:10] DEBUG[10056] channel.c: Bridge stops bridging channels OSS/dsp and SIP/200-082155a0 [Nov 19 16:02:10] DEBUG[10056] channel.c: Hanging up channel 'SIP/200-082155a0' [Nov 19 16:02:10] DEBUG[10056] chan_sip.c: Hangup call SIP/200-082155a0, SIP callid 5a64a96e4b82585c7e08bd66108a7cd8@80.95.0.111 [Nov 19 16:02:10] DEBUG[10056] devicestate.c: Notification of state change to be queued on device/channel SIP/200-082155a0 [Nov 19 16:02:10] DEBUG[10056] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Nov 19 16:02:10] DEBUG[10056] pbx.c: Spawn extension (desde-usuarios,200,1) exited non-zero on 'OSS/dsp' [Nov 19 16:02:10] VERBOSE[10056] logger.c: == Spawn extension (desde-usuarios, 200, 1) exited non-zero on 'OSS/dsp' [Nov 19 16:02:10] DEBUG[10056] channel.c: Soft-Hanging up channel 'OSS/dsp' [Nov 19 16:02:10] DEBUG[10056] channel.c: Hanging up channel 'OSS/dsp' [Nov 19 16:02:10] VERBOSE[10056] logger.c: << Hangup on console >> [Nov 19 16:02:10] DEBUG[10056] devicestate.c: Notification of state change to be queued on device/channel OSS/dsp [Nov 19 16:02:10] DEBUG[10056] cdr_radius.c: Unable to create RADIUS record. CDR not recorded! [Nov 19 16:02:10] DEBUG[10056] chan_sip.c: Checking device state for peer 200 [Nov 19 16:02:10] DEBUG[10056] devicestate.c: Changing state for SIP/200 - state 1 (Not in use) [Nov 19 16:02:10] DEBUG[10056] devicestate.c: Changing state for OSS/dsp - state 4 (Invalid) [Nov 19 16:02:10] DEBUG[10056] app_queue.c: Device 'SIP/200' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Nov 19 16:02:10] DEBUG[10056] app_queue.c: Device 'OSS/dsp' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Nov 19 16:02:11] VERBOSE[10056] logger.c: Really destroying SIP dialog '5a64a96e4b82585c7e08bd66108a7cd8@80.95.0.111' Method: BYE [Nov 19 16:02:11] DEBUG[10056] chan_sip.c: ---------- SIP HISTORY for '5a64a96e4b82585c7e08bd66108a7cd8@80.95.0.111' [Nov 19 16:02:11] DEBUG[10056] chan_sip.c: * SIP Call [Nov 19 16:02:11] DEBUG[10056] chan_sip.c: 001. NewChan Channel SIP/200-082155a0 - from 5a64a96e4b82585c7e08bd66108a7cd [Nov 19 16:02:11] DEBUG[10056] chan_sip.c: 002. TxReqRel INVITE / 102 INVITE - -UNKNOWN- [Nov 19 16:02:11] DEBUG[10056] chan_sip.c: 003. Rx SIP/2.0 / 102 INVITE / 100 Trying [Nov 19 16:02:11] DEBUG[10056] chan_sip.c: 004. Rx SIP/2.0 / 102 INVITE / 180 Ringing [Nov 19 16:02:11] DEBUG[10056] chan_sip.c: 005. Rx SIP/2.0 / 102 INVITE / 200 OK [Nov 19 16:02:11] DEBUG[10056] chan_sip.c: 006. TxReq ACK / 102 ACK - -UNKNOWN- [Nov 19 16:02:11] DEBUG[10056] chan_sip.c: 007. Rx OPTIONS / 705 OPTIONS / sip:asterisk@80.95.0.111 [Nov 19 16:02:11] DEBUG[10056] chan_sip.c: 008. TxResp SIP/2.0 / 705 OPTIONS - 404 Not Found [Nov 19 16:02:11] DEBUG[10056] chan_sip.c: 009. Rx BYE / 706 BYE / sip:asterisk@80.95.0.111 [Nov 19 16:02:11] DEBUG[10056] chan_sip.c: 010. RTCPaudio Quality:ssrc=1148418030;themssrc=855715943;lp=0;rxjitter=0.0062 [Nov 19 16:02:11] DEBUG[10056] chan_sip.c: 011. TxResp SIP/2.0 / 706 BYE - 200 OK [Nov 19 16:02:11] DEBUG[10056] chan_sip.c: 012. Hangup Cause Normal Clearing [Nov 19 16:02:11] DEBUG[10056] chan_sip.c: ---------- END SIP HISTORY for '5a64a96e4b82585c7e08bd66108a7cd8@80.95.0.111'